Add logging framework

.env.example

@@ -1,4 +1,6 @@
 DEBUG='False' # True for development
+LOG_LEVEL='WARNING' # Level enum values: https://docs.djangoproject.com/en/5.1/topics/logging/#loggers
+DJANGO_LOG_LEVEL='WARNING'
 NGINX_IMAGE='lscr.io/linuxserver/swag' # leave unset for development
 NGINX_CONF='./nginx.prod.conf' # leave unset for development
 NGINX_CONF_LOCATION='/config/nginx/site-confs/default.conf' # leave unset for development

.github/scripts/prepare-ci.sh

@@ -1,3 +1,6 @@
 #!/usr/bin/env bash
 
 cp .env.example .env
+
+mkdir logs
+chmod -R 777 logs

.github/workflows/image-builds.yml

@@ -12,7 +12,6 @@ jobs:
       - uses: actions/checkout@v4
       - run: ./.github/scripts/prepare-ci.sh
       - run: docker compose build
-      - run: docker compose up -d
-      - run: sleep 60  # Wait for the container to be up
+      - run: docker compose up --detach --wait --wait-timeout 60
       - run: docker compose exec web python3 manage.py test
       - run: docker compose down

.gitignore

@@ -8,3 +8,4 @@ auctions/templates/ads.txt
 swag/
 mediafiles/
 staticfiles/
+logs/

Dockerfile

@@ -80,6 +80,7 @@ RUN groupadd -r -g ${PUID-1000} app && \
 
 # create the appropriate directories
 ENV APP_HOME=/home/app/web
+RUN mkdir /home/logs
 RUN mkdir /home/user
 RUN mkdir $APP_HOME
 RUN mkdir $APP_HOME/staticfiles
@@ -130,6 +131,7 @@ RUN /tmp/python_file_hack.sh
 
 # chown all the files to the app user
 RUN chown -R app:app $APP_HOME
+RUN chown -R app:app /home/logs
 RUN chown -R app:app /home/user
 RUN chown -R app:app /var/log/
 RUN chown -R app:app /var/log/

auctions/consumers.py

@@ -1,6 +1,7 @@
 # chat/consumers.py
 import datetime
 import json
+import logging
 
 from asgiref.sync import async_to_sync
 from channels.generic.websocket import WebsocketConsumer
@@ -23,6 +24,8 @@
     UserInterestCategory,
 )
 
+logger = logging.getLogger(__name__)
+
 
 def check_bidding_permissions(lot, user):
     """
@@ -177,7 +180,9 @@ def bid_on_lot(lot, user, amount):
             if not created:
                 if amount <= bid.amount:
                     result["message"] = f"Bid more than your proxy bid (${bid.amount})"
-                    # print(f"{user_string} tried to bid on {lot} less than their original bid of ${originalBid}")
+                    logger.debug(
+                        "%s tried to bid on %s less than their original bid of $%s", user_string, lot, originalBid
+                    )
                     return result
                 else:
                     bid.last_bid_time = timezone.now()
@@ -241,7 +246,7 @@ def bid_on_lot(lot, user, amount):
             if bid.amount <= originalBid:  # changing this to < would allow bumping without being the high bidder
                 # there's a high bidder already
                 bid.save()  # save the current bid regardless
-                # print(f"{user_string} tried to bid on {lot} less than the current bid of ${originalBid}")
+                logger.debug("%s tried to bid on %s less than the current bid of $%s", user_string, lot, originalBid)
                 result["message"] = f"You can't bid less than ${originalBid + 1}"
                 return result
             if bid.amount > originalBid + 1:
@@ -261,7 +266,7 @@ def bid_on_lot(lot, user, amount):
                         # user is upping their own price, don't tell other people about it
                         result["type"] = "INFO"
                         result["message"] = f"You've raised your proxy bid to ${bid.amount}"
-                        # print(f"{user_string} has raised their bid on {lot} to ${bid.amount}")
+                        logger.debug("%s has raised their bid on %s to $%s", user_string, lot, bid.amount)
                         return result
                 except:
                     pass
@@ -277,7 +282,7 @@ def bid_on_lot(lot, user, amount):
                 result["send_to"] = "everyone"
                 # email the old one
                 current_site = Site.objects.get_current()
-                # print(f'{originalHighBidder.username} has been outbid!')
+                logger.debug("%s has been outbid!", originalHighBidder.username)
                 mail.send(
                     originalHighBidder.email,
                     template="outbid_notification",
@@ -316,7 +321,7 @@ def bid_on_lot(lot, user, amount):
             )
             return result
     except Exception as e:
-        print(e)
+        logger.exception(e)
 
 
 class LotConsumer(WebsocketConsumer):
@@ -357,7 +362,7 @@ def connect(self):
                         },
                     )
                 except Exception as e:
-                    print(e)
+                    logger.exception(e)
             try:
                 owner_chat_notifications = False
                 if self.lot.user:
@@ -382,10 +387,10 @@ def connect(self):
                         },
                     )
             except Exception as e:
-                print(e)
+                logger.exception(e)
 
         except Exception as e:
-            print(e)
+            logger.exception(e)
 
     def disconnect(self, close_code):
         # Leave room group
@@ -397,22 +402,20 @@ def disconnect(self, close_code):
         if self.lot.auctiontos_seller and self.lot.auctiontos_seller.user:
             user_pk = self.lot.auctiontos_seller.user
         if user_pk and self.user.pk == user_pk:
-            # print("lot owner is leaving the chat, marking all chats as seen")
+            logger.debug("lot owner is leaving the chat, marking all chats as seen")
             LotHistory.objects.filter(lot=self.lot.pk, seen=False).update(seen=True)
         # this is for everyone else
         if self.user.pk:
             existing_subscription = ChatSubscription.objects.filter(lot=self.lot, user=self.user.pk).first()
             if existing_subscription:
-                print(f"Marking all ChatSubscription seen last time now for user {self.user.pk}")
+                logger.info("Marking all ChatSubscription seen last time now for user %s", self.user.pk)
                 existing_subscription.last_seen = timezone.now()
                 existing_subscription.last_notification_sent = timezone.now()
                 existing_subscription.save()
 
     # Receive message from WebSocket
     def receive(self, text_data):
         text_data_json = json.loads(text_data)
-        # print(self.user)
-        # print(text_data_json)
         if self.user.is_authenticated:
             try:
                 error = check_all_permissions(self.lot, self.user)
@@ -430,7 +433,6 @@ def receive(self, text_data):
                                 {"type": "error_message", "error": error},
                             )
                         else:
-                            # try:
                             if True:
                                 LotHistory.objects.create(
                                     lot=self.lot,
@@ -439,8 +441,6 @@ def receive(self, text_data):
                                     changed_price=False,
                                     current_price=self.lot.high_bid,
                                 )
-                            # except Exception as e:
-                            #     print(e)
                             async_to_sync(self.channel_layer.group_send)(
                                 self.room_group_name,
                                 {
@@ -502,10 +502,9 @@ def receive(self, text_data):
                     except:
                         pass
             except Exception as e:
-                print(e)
+                logger.exception(e)
         else:
             pass
-            # print("user is not authorized")
 
     # Send a toast error to a single user
     def error_message(self, event):
@@ -555,18 +554,18 @@ def connect(self):
                 #     {"type": "toast", "message": 'Welcome!', 'bg': 'success'},
                 # )
         except Exception as e:
-            print(e)
+            logger.exception(e)
             self.close()
 
     def disconnect(self, close_code):
         # Leave room group
         async_to_sync(self.channel_layer.group_discard)(self.user_notification_channel, self.channel_name)
-        print("disconnected")
+        logger.debug("disconnected")
 
     # Receive message from WebSocket
     def receive(self, text_data):
         text_data_json = json.loads(text_data)
-        print(text_data_json)
+        logger.info(text_data_json)
 
     def toast(self, event):
         message = event["message"]

auctions/forms.py

@@ -1,5 +1,6 @@
-# from django.core.exceptions import ValidationError
+import logging
 
+# from django.core.exceptions import ValidationError
 from allauth.account.forms import ResetPasswordForm, SignupForm
 
 # from bootstrap_datepicker_plus import DateTimePickerInput
@@ -38,6 +39,8 @@
 # class DateInput(forms.DateInput):
 #     input_type = 'datetime-local'
 
+logger = logging.getLogger(__name__)
+
 
 class QuickAddTOS(forms.ModelForm):
     """Add a new user to an auction by filling out only the most important fields"""
@@ -939,9 +942,9 @@ def __init__(self, *args, **kwargs):
     # def save(self, *args, **kwargs):
     #     kwargs['commit']=False
     #     obj = super().save(*args, **kwargs)
-    #     print(self.req.user.id)
+    #     logger.debug(self.req.user.id)
     #     #obj.user = self.req.user.id
-    #     #print(str(obj.user)+ " has placed a bid on " + str(obj.lot_number))
+    #     #logger.debug(str(obj.user)+ " has placed a bid on " + str(obj.lot_number))
     #     obj.save()
     #     return obj
 
@@ -1456,7 +1459,7 @@ def __init__(self, *args, **kwargs):
 
         if self.instance.pk:
             # editing existing auction
-            print("wait, no, we should never get here!!!")
+            logger.debug("wait, no, we should never get here!!!")
         self.helper = FormHelper()
         self.helper.form_method = "post"
         self.helper.form_id = "auction-form"

auctions/management/commands/auction_emails.py

@@ -1,4 +1,5 @@
 import datetime
+import logging
 
 from django.contrib.sites.models import Site
 from django.core.management.base import BaseCommand
@@ -8,6 +9,8 @@
 
 from auctions.models import Auction, UserData
 
+logger = logging.getLogger(__name__)
+
 
 class Command(BaseCommand):
     help = "Drip marketing style emails send to the creator of an auction.  No emails are sent for in-person auctions right now."
@@ -56,7 +59,7 @@ def handle(self, *args, **options):
                     percentComplete = percentComplete.total_seconds() / runtime.total_seconds() * 100
                     if percentComplete > 70:
                         if not auction.email_second_sent:
-                            # print(f'sending auction_second to {auction.created_by.email} ')
+                            logger.info("sending auction_second to %s ", auction.created_by.email)
                             mail.send(
                                 auction.created_by.email,
                                 template="auction_second",

auctions/management/commands/endauctions.py

@@ -1,4 +1,5 @@
 import datetime
+import logging
 
 from django.contrib.sites.models import Site
 from django.core.management.base import BaseCommand
@@ -8,6 +9,8 @@
 
 from auctions.models import Lot, LotHistory, LotImage
 
+logger = logging.getLogger(__name__)
+
 
 def declare_winners_on_lots(lots):
     """Set the winner and winning price on all lots"""
@@ -133,8 +136,8 @@ def declare_winners_on_lots(lots):
                             newImage.image_source = "REPRESENTATIVE"
                         newImage.save()
             except Exception as e:
-                print(f'Unable to set winner on "{lot}":')
-                print(e)
+                logger.warning('Unable to set winner on "%s":', lot)
+                logger.exception(e)
         else:
             # note: once again, lots that are part of an in-person auction are not included here
             if lot.ending_very_soon and not lot.sold: