diff --git a/.env.example b/.env.example index fd80edc..205c95a 100644 --- a/.env.example +++ b/.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 diff --git a/.github/scripts/prepare-ci.sh b/.github/scripts/prepare-ci.sh index 698a838..e9ca1d5 100755 --- a/.github/scripts/prepare-ci.sh +++ b/.github/scripts/prepare-ci.sh @@ -1,3 +1,6 @@ #!/usr/bin/env bash cp .env.example .env + +mkdir logs +chmod -R 777 logs diff --git a/.github/workflows/image-builds.yml b/.github/workflows/image-builds.yml index da31b14..8537b2b 100644 --- a/.github/workflows/image-builds.yml +++ b/.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 diff --git a/.gitignore b/.gitignore index fd553b4..8e03259 100644 --- a/.gitignore +++ b/.gitignore @@ -8,3 +8,4 @@ auctions/templates/ads.txt swag/ mediafiles/ staticfiles/ +logs/ diff --git a/Dockerfile b/Dockerfile index e77eaba..66d43a1 100644 --- a/Dockerfile +++ b/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/ diff --git a/auctions/consumers.py b/auctions/consumers.py index 37861f8..90f89b8 100755 --- a/auctions/consumers.py +++ b/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,13 +402,13 @@ 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() @@ -411,8 +416,6 @@ def disconnect(self, close_code): # 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"] diff --git a/auctions/forms.py b/auctions/forms.py index 2301947..5d33399 100755 --- a/auctions/forms.py +++ b/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" diff --git a/auctions/management/commands/auction_emails.py b/auctions/management/commands/auction_emails.py index 1205fcd..3fac3a2 100644 --- a/auctions/management/commands/auction_emails.py +++ b/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", diff --git a/auctions/management/commands/endauctions.py b/auctions/management/commands/endauctions.py index af37e07..1253bcb 100644 --- a/auctions/management/commands/endauctions.py +++ b/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: diff --git a/auctions/management/commands/info.py b/auctions/management/commands/info.py index 2f06b48..8aac436 100644 --- a/auctions/management/commands/info.py +++ b/auctions/management/commands/info.py @@ -1,5 +1,9 @@ +import logging + from django.core.management.base import BaseCommand +logger = logging.getLogger(__name__) + def compare_model_instances(instance1, instance2): """ @@ -40,13 +44,13 @@ class Command(BaseCommand): # total = AuctionCampaign.objects.all().count() # total = total-none # joined = joined/total * 100 - # print('joined', joined) + # logger.debug('joined', joined) # no_response = no_response/total * 100 - # print('no response', no_response) + # logger.debug('no response', no_response) # viewed = viewed/total * 100 - # print('viewed', viewed) + # logger.debug('viewed', viewed) # none = none/total * 100 - # print('no email sent', none) + # logger.debug('no email sent', none) # lots_with_buy_now_available = Lot.objects.filter(is_deleted=False, auction__isnull=False, auction__promote_this_auction=True, buy_now_price__isnull=False) # #lots_with_buy_now_used = Lot.objects.filter(is_deleted=False, auction__isnull=False, auction__promote_this_auction=True, buy_now_price__isnull=False, winning_price=F('buy_now_price')) # sum_of_buy_now_used = 0 @@ -69,14 +73,14 @@ class Command(BaseCommand): # if lot.winning_price < lot.buy_now_price: # count_of_lots_that_sold_for_less_than_buy_now += 1 # sum_of_lots_that_sold_for_less_than_buy_now += lot.winning_price - # print(f"buy now is used {count_of_buy_now_used/lots_with_buy_now_available.count()*100}% of the time when it's available") - # print(f"average sell price when buy now is used is ${sum_of_buy_now_used/count_of_buy_now_used}") - # print(f"average sell price when buy now is not used is ${(sum_of_lots_that_sold_for_less_than_buy_now+sum_of_lots_that_sold_for_more_than_buy_now)/(count_of_lots_that_sold_for_less_than_buy_now+count_of_lots_that_sold_for_more_than_buy_now)}") - # print(f"when buy now is not used, the lot sells for more than the buy now price {count_of_lots_that_sold_for_more_than_buy_now/(count_of_lots_that_sold_for_less_than_buy_now+count_of_lots_that_sold_for_more_than_buy_now)*100}% of the time") + # logger.debug(f"buy now is used {count_of_buy_now_used/lots_with_buy_now_available.count()*100}% of the time when it's available") + # logger.debug(f"average sell price when buy now is used is ${sum_of_buy_now_used/count_of_buy_now_used}") + # logger.debug(f"average sell price when buy now is not used is ${(sum_of_lots_that_sold_for_less_than_buy_now+sum_of_lots_that_sold_for_more_than_buy_now)/(count_of_lots_that_sold_for_less_than_buy_now+count_of_lots_that_sold_for_more_than_buy_now)}") + # logger.debug(f"when buy now is not used, the lot sells for more than the buy now price {count_of_lots_that_sold_for_more_than_buy_now/(count_of_lots_that_sold_for_less_than_buy_now+count_of_lots_that_sold_for_more_than_buy_now)*100}% of the time") # lots = Lot.objects.filter(Q(feedback_text__isnull=False)|Q(winner_feedback_text__isnull=False)) # for lot in lots: - # print(lot.winner_feedback_text, lot.feedback_text) + # logger.debug(lot.winner_feedback_text, lot.feedback_text) # # fix auctiontos_user on invoices: # invoices = Invoice.objects.filter(auctiontos_user__isnull=True, auction__isnull=False, user__isnull=False) @@ -105,7 +109,7 @@ class Command(BaseCommand): # if not lot.auctiontos_winner: # corrected_winner = AuctionTOS.objects.filter(user=lot.winner, auction=lot.auction).first() # if not corrected_winner: - # pass#print(lot) + # pass#logger.debug(lot) # else: # lot.auctiontos_winner = corrected_winner # lot.save() @@ -113,22 +117,22 @@ class Command(BaseCommand): # if not lot.auctiontos_seller: # corrected_seller = AuctionTOS.objects.filter(user=lot.user, auction=lot.auction).first() # if not corrected_seller: - # pass#print(lot) + # pass#logger.debug(lot) # else: - # #print(f"setting {corrected_seller} to be the winenr of {lot}") + # #logger.debug(f"setting {corrected_seller} to be the winenr of {lot}") # lot.auctiontos_seller = corrected_seller # lot.save() # # check to make sure that all worked correctly # lots = Lot.objects.filter(auction__isnull=False, auctiontos_seller__isnull=True) # for lot in lots: - # print(lot) + # logger.debug(lot) # auctions with no pickup location # auctions = Auction.objects.all() # for auction in auctions: # locations = PickupLocation.objects.filter(auction=auction) # if not locations: - # print(auction.get_absolute_url()) + # logger.debug(auction.get_absolute_url()) # create a graph of how prices change over time # f = open("views.txt", "a") @@ -145,16 +149,16 @@ class Command(BaseCommand): # some info to add to the dashboard at some point # qs = UserData.objects.filter(user__is_active=True) - # print(qs.exclude(user__lot__isnull=False).distinct().count()) # sellers - # print(qs.exclude(user__winner__isnull=False).distinct().count()) # buyers - # print(qs.exclude(user__bid__isnull=True).distinct().count()) # bidders - # print(qs.exclude(Q(user__lot__isnull=False)|Q(user__winner__isnull=False)|Q(user__bid__isnull=True)).distinct().count()) # bidders + # logger.debug(qs.exclude(user__lot__isnull=False).distinct().count()) # sellers + # logger.debug(qs.exclude(user__winner__isnull=False).distinct().count()) # buyers + # logger.debug(qs.exclude(user__bid__isnull=True).distinct().count()) # bidders + # logger.debug(qs.exclude(Q(user__lot__isnull=False)|Q(user__winner__isnull=False)|Q(user__bid__isnull=True)).distinct().count()) # bidders # list page views by time # views = PageView.objects.filter(user__isnull=False) # f = open("views.txt", "a") # for view in views: - # print(view.total_time) + # logger.debug(view.total_time) # f.write(f"{view.total_time}\n") # f.close() @@ -170,26 +174,26 @@ class Command(BaseCommand): # why are there so many mikes?? # allUsers = User.objects.all().count() # mikes = User.objects.filter(Q(first_name="mike")| Q(first_name="michael")).count() - # print(allUsers) - # print(mikes) + # logger.debug(allUsers) + # logger.debug(mikes) # auction = Auction.objects.get(title="TFCB Annual Auction") # users = User.objects.filter(pageview__lot_number__auction=auction).annotate(dcount=Count('id')) # for user in users: -# print(lot.num_views) -# print(f"{user.first_name} {user.last_name}") +# logger.debug(lot.num_views) +# logger.debug(f"{user.first_name} {user.last_name}") # auction = Auction.objects.get(title="TFCB Annual Auction") -# print(f'{lot.pk}, {bids}, {}') +# logger.debug(f'{lot.pk}, {bids}, {}') # users = User.objects.all() # auction = Auction.objects.get(title="PVAS Fall Auction") # for user in users: # #won = len(Lot.objects.filter(winner=user, auction=auction)) # views = len(PageView.objects.filter(lot_number__auction=auction, user=user)) # if views > 5: -# print(f'"{user.first_name} {user.last_name}", {views}') +# logger.debug(f'"{user.first_name} {user.last_name}", {views}') # lots = Lot.objects.all() # noImageCount = 0 @@ -229,10 +233,10 @@ class Command(BaseCommand): # if lot.winner: # noImageSold += 1 # noImageValue.append(lot.winning_price) -# print("none", noImageSold, noImageCount, sum(noImageValue) / len(noImageValue) ) -# print("internet", internetImageSold, internetImageCount, sum(internetImageValue) / len(internetImageValue) ) -# print("representative", representativeImageSold, representativeImageCount, sum(representativeImageValue) / len(representativeImageValue) ) -# print("actual", actualImageSold, actualImageCount, sum(actualImageValue) / len(actualImageValue) ) +# logger.debug("none", noImageSold, noImageCount, sum(noImageValue) / len(noImageValue) ) +# logger.debug("internet", internetImageSold, internetImageCount, sum(internetImageValue) / len(internetImageValue) ) +# logger.debug("representative", representativeImageSold, representativeImageCount, sum(representativeImageValue) / len(representativeImageValue) ) +# logger.debug("actual", actualImageSold, actualImageCount, sum(actualImageValue) / len(actualImageValue) ) # users = User.objects.all() # for user in users: @@ -243,25 +247,25 @@ class Command(BaseCommand): # #bid = Bid.objects.filter(user=user.pk, lot_number__auction=auction) # won = Lot.objects.filter(winner=user.pk, auction=auction) # #if bid and not userdata.location: -# # print(user.email) +# # logger.debug(user.email) # #viewed = PageView.objects.filter(user=user.pk, lot_number__auction=auction) # if lots or won: #or viewed:# and not lots: # #if user.email == 'cmatuse@gmail.com': -# # print(bid) +# # logger.debug(bid) # confirmed = "" # if user.email not in confirmed: -# print(f"{user.first_name} {user.last_name} {user.email}") +# logger.debug(f"{user.first_name} {user.last_name} {user.email}") # #try: # # userdata = UserData.objects.get(user=user.pk) -# # print(user.email, userdata.phone_number) +# # logger.debug(user.email, userdata.phone_number) # #except: # # pass # # if lots: # # #if not user.first_name: -# # # print(user.email) +# # # logger.debug(user.email) # # #if bids or lots: -# # print(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`Seller") +# # logger.debug(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`Seller") # # elif bid: -# # print(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`Bidder") +# # logger.debug(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`Bidder") # # elif viewed: -# # print(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`No bids or lots sold") +# # logger.debug(f"{user.first_name} {user.last_name}` {user.email}` {userdata.location}`No bids or lots sold") diff --git a/auctions/management/commands/purge_bot_users.py b/auctions/management/commands/purge_bot_users.py index f1d1d89..43853dd 100644 --- a/auctions/management/commands/purge_bot_users.py +++ b/auctions/management/commands/purge_bot_users.py @@ -1,9 +1,13 @@ +import logging + from allauth.account.models import EmailAddress from django.core.management.base import BaseCommand from django.utils import timezone from auctions.models import UserData +logger = logging.getLogger(__name__) + class Command(BaseCommand): help = "Remove users with no verified email" @@ -17,5 +21,5 @@ def handle(self, *args, **options): ) time_difference = email.user.userdata.last_activity - email.user.date_joined if time_difference < timezone.timedelta(hours=24): - print("Deleting", email.user) + logger.info("Deleting %s", email.user) email.user.delete() diff --git a/auctions/management/commands/set_user_location.py b/auctions/management/commands/set_user_location.py index 7424b99..2b17e94 100644 --- a/auctions/management/commands/set_user_location.py +++ b/auctions/management/commands/set_user_location.py @@ -1,4 +1,5 @@ import datetime +import logging import requests from django.core.management.base import BaseCommand @@ -7,6 +8,8 @@ from auctions.models import Location, PageView, UserData +logger = logging.getLogger(__name__) + class Command(BaseCommand): help = "Set user lat/long based on their IP address" @@ -50,18 +53,21 @@ def handle(self, *args, **options): value for value in [continent, country, default] if value is not None ) user.save() - print(f"assigning {user.user.email} with IP {user.last_ip_address} a location") + logger.info( + "assigning %s with IP %s a location", user.user.email, user.last_ip_address + ) break else: - print( - f"IP {user.last_ip_address} may not be valid - verify it and set their location manually" + logger.info( + "IP %s may not be valid - verify it and set their location manually", + user.last_ip_address, ) except Exception as e: - print(e) + logger.exception(e) else: - print("Query failed for this IP list:") - print(ip_list) - print(r["text"]) + logger.warning("Query failed for this IP list:") + logger.warning(ip_list) + logger.warning(r["text"]) # some limitations to note: # we are capped at 100 lookups per query # Looks like the cap on this service is 15 per minute, so it's easily able to meet our needs if the cron job is run more often. @@ -99,8 +105,9 @@ def handle(self, *args, **options): view.save() break else: - print( - f"IP {view.ip_address} may not be valid - verify it and set their location manually" + logger.warning( + "IP %s may not be valid - verify it and set their location manually", + view.ip_address, ) except Exception as e: - print(e) + logger.exception(e) diff --git a/auctions/models.py b/auctions/models.py index a96d5f2..209901c 100755 --- a/auctions/models.py +++ b/auctions/models.py @@ -1,4 +1,5 @@ import datetime +import logging import re import uuid from datetime import time @@ -43,6 +44,8 @@ from markdownfield.validators import VALIDATOR_STANDARD from pytz import timezone as pytz_timezone +logger = logging.getLogger(__name__) + def nearby_auctions( latitude, @@ -399,7 +402,7 @@ def guess_category(text): categories[lot.species_category.pk] = category_total + matches sorted_categories = sorted(categories.items(), key=lambda x: x[1], reverse=True) for key, value in sorted_categories: - # print(Category.objects.filter(pk=key).first(), value) + logger.debug("%s, %s", Category.objects.filter(pk=key).first(), value) return Category.objects.filter(pk=key).first() return None @@ -1633,7 +1636,7 @@ def check_number_in_auction(number): return AuctionTOS.objects.filter(bidder_number=number, auction=self.auction).count() if not self.pk: - # print("new instance of auctionTOS") + logger.debug("new instance of auctionTOS") if self.auction.only_approved_sellers: self.selling_allowed = False if self.auction.only_approved_bidders: @@ -1905,7 +1908,7 @@ def trying_to_avoid_ban(self): if userData.last_ip_address: other_users = UserData.objects.filter(last_ip_address=userData.last_ip_address).exclude(pk=userData.pk) for other_user in other_users: - # print(f"{self.user} is also known as {other_user.user}") + logger.debug("%s is also known as %s", self.user, other_user.user) banned = UserBan.objects.filter(banned_user=other_user.user, user=self.auction.created_by).first() if banned: url = reverse("userpage", kwargs={"slug": other_user.user.username}) @@ -2704,7 +2707,7 @@ def sealed_bid(self): @property def price(self): """Price display""" - print( + logger.warning( "this is most likely safe to remove, it uses max_bid which should never be displayed to normal people. I don't think it's used anywhere." ) if self.winning_price: @@ -2728,7 +2731,6 @@ def max_bid(self): bidPrice = allBids[0].amount return bidPrice except: - # print("no bids for this item") return self.reserve_price @property @@ -2771,7 +2773,6 @@ def high_bid(self): # bidPrice = bids[1].amount return bidPrice except: - # print("no bids for this item") return self.reserve_price @property @@ -3127,7 +3128,6 @@ def user_should_be_paid(self): def rounded_net(self): """Always round in the customer's favor (against the club) to make sure that the club doesn't need to deal with change, only whole dollar amounts""" rounded = round(self.net) - # print(f"{self.net} Rounded to {rounded}") if self.user_should_be_paid: if self.net > rounded: # we rounded down against the customer @@ -3708,7 +3708,9 @@ def total_sold(self): @property def species_sold(self): """Total different species that this user has bred and sold in auctions""" - print("species_sold is is no longer used, there's no way for users to enter species information anymore") + logger.warning( + "species_sold is is no longer used, there's no way for users to enter species information anymore" + ) allLots = ( self.my_lots_qs.filter(i_bred_this_fish=True, winner__isnull=False).values("species").distinct().count() ) @@ -4267,7 +4269,7 @@ def on_save_auction(sender, instance, **kwargs): # if this is an existing auction if instance.pk: - # print('updating date end on lots because this is an existing auction') + logger.info("updating date end on lots because this is an existing auction") # update the date end for all lots associated with this auction # note that we do NOT update the end time if there's a winner! # This means you cannot reopen an auction simply by changing the date end @@ -4292,7 +4294,6 @@ def on_save_auction(sender, instance, **kwargs): else: # logic for new auctions goes here pass - # print(instance.date_start) if not instance.is_online: # for in-person auctions, we need to add a single pickup location # and create it if the user was dumb enough to delete it @@ -4306,7 +4307,7 @@ def on_save_auction(sender, instance, **kwargs): }, ) except: - print("Somehow there's two pickup locations for this auction -- how is this possible?") + logger.warning("Somehow there's two pickup locations for this auction -- how is this possible?") @receiver(pre_save, sender=UserData) diff --git a/auctions/tests.py b/auctions/tests.py index 8fbf9c0..e077414 100644 --- a/auctions/tests.py +++ b/auctions/tests.py @@ -742,7 +742,6 @@ def test_lot_prices(self): self.tos.save() lot = lots.filter(pk=self.lot.pk).first() assert lot.your_cut == 10 - # print(lot.winning_price, lot.your_cut) unsold_lot = lots.filter(pk=self.unsold_lot.pk).first() assert unsold_lot.your_cut == -10 @@ -880,8 +879,6 @@ def test_small_labels(self): user_label_prefs.save() self.client.login(username=self.user, password="testpassword") response = self.client.get(self.url) - # for message in list(response.wsgi_request._messages): - # print(str(message)) assert response.status_code == 200 assert "attachment; filename=" in response.headers["Content-Disposition"] diff --git a/auctions/views.py b/auctions/views.py index db807f6..080d809 100755 --- a/auctions/views.py +++ b/auctions/views.py @@ -1,5 +1,6 @@ import ast import csv +import logging import re from collections import Counter from datetime import datetime, timedelta @@ -152,6 +153,8 @@ ) from .tables import AuctionTOSHTMxTable, LotHTMxTable, LotHTMxTableForUsers +logger = logging.getLogger(__name__) + def bin_data( queryset, @@ -274,13 +277,13 @@ def is_auction_admin(self): result = self.auction.permission_check(self.request.user) if not result: if self.allow_non_admins: + logger.debug("non-admins allowed") pass - # print('non-admins allowed') else: raise PermissionDenied() else: + logger.debug("allowing user %s to view %s", self.request.user, self.auction) pass - # print(f"allowing user {self.request.user} to view {self.auction}") return result @@ -306,13 +309,14 @@ def is_auction_admin(self): result = self.auction.permission_check(self.request.user) if not result: if not self.auction.make_stats_public: + logger.debug("non-admins allowed") pass - # print('non-admins allowed') + else: raise PermissionDenied() else: + logger.debug("allowing user %s to view %s", self.request.user, self.auction) pass - # print(f"allowing user {self.request.user} to view {self.auction}") return result @@ -377,7 +381,8 @@ def get_object(self, *args, **kwargs): campaign.bid = campaign.bid * 2 # Better chance for matching category. Don't save after this if campaign.bid > uniform(0, total - 1): if campaign.number_of_clicks > campaign.max_clicks or campaign.number_of_impressions > campaign.max_ads: - pass # print("not selected -- limit exceeded") + logger.debug("not selected -- limit exceeded") + pass else: return AdCampaignResponse.objects.create( user=user, campaign=campaign @@ -901,7 +906,7 @@ def userBan(request, pk): lot = Lot.objects.get(pk=bid.lot_number.pk, is_deleted=False) if lot.user == user or lot.auction in auctionsList: if not lot.ended: - # print('Deleting bid ' + str(bid)) + logger.info("Deleting bid %s", str(bid)) bid.delete() # ban all lots added by the banned user. These are not deleted, just removed from the auction for auction in auctionsList: @@ -913,7 +918,7 @@ def userBan(request, pk): lots = Lot.objects.exclude(is_deleted=True).filter(user=bannedUser, auction=auction.pk) for lot in lots: if not lot.ended: - # print(f"User {str(user)} has banned lot {lot}") + logger.info("User %s has banned lot %s", str(user), lot) lot.banned = True lot.ban_reason = "The seller of this lot has been banned from this auction" lot.save() @@ -2777,9 +2782,6 @@ def get_object(self): def get_queryset(self): pk = self.kwargs.get(self.pk_url_kwarg) - # print(pk) # this will be set for /lots/1234/ - # print(self.auction_slug) # otherwise, these two will be set for /auctions/abc-def/lots/custom_number/ - # print(self.custom_lot_number) qs = Lot.objects.exclude(is_deleted=True) try: latitude = self.request.COOKIES["latitude"] @@ -3197,8 +3199,7 @@ def form_valid(self, form, **kwargs): newImage.save() # we are only cloning images here, not watchers, views, or other related models except Exception as e: - print(e) - # pass + logger.exception(e) msg = "Created lot!" if not lot.image_count: msg += f"You should probably add an image to this lot. Or, " @@ -3742,8 +3743,9 @@ def form_valid(self, form, **kwargs): # you still don't get to clone auctions that aren't yours... if original_auction.permission_check(self.request.user): clone_from_auction = original_auction - except Exception: - pass # print(e) + except Exception as e: + logger.exception(e) + pass elif "online" in str(self.request.GET): is_online = True else: @@ -4026,7 +4028,7 @@ def post(self, request, *args, **kwargs): userData.save() return self.form_valid(form) else: - # print(form.cleaned_data) + logger.debug(form.cleaned_data) return self.form_invalid(form) @@ -4699,11 +4701,11 @@ def create_labels(self, request, *args, **kwargs): # Check if the current label is the last label in the current row or the last label in the list if (i + 1) % num_cols == 0 or i == len(labels) - 1: - # print(f'we have reached the end, {len(labels)} in total') + logger.debug("we have reached the end, %s in total", len(labels)) # Check if the current label is the last label in the list and labels_row is not full if i == len(labels) - 1 and len(labels_row) < num_cols * 3: # Add empty elements to the labels_row list until it is filled - # print(f"adding {(num_cols*3) - len(labels_row)} extra labels, *3 total columns added") + logger.debug("adding %s extra labels, *3 total columns added", (num_cols * 3) - len(labels_row)) labels_row += [ [ Paragraph("", style), @@ -5976,7 +5978,7 @@ def get_data(self): # #auctiontos = AuctionTOS.objects.filter(auction__promote_this_auction=True, user__isnull=False) # buyer_histogram = bin_data(buyers, 'distance_traveled', number_of_bins=5, start_bin=1, end_bin=51, add_column_for_high_overflow=True,) # #seller_histogram = bin_data(sellers, 'distance_traveled', number_of_bins=5, start_bin=1, end_bin=51, add_column_for_high_overflow=True,) -# print(buyers.count()) +# logger.debug(buyers.count()) # return [buyer_histogram] # def dispatch(self, request, *args, **kwargs): diff --git a/docker-compose.yaml b/docker-compose.yaml index be3e2ac..01b6125 100644 --- a/docker-compose.yaml +++ b/docker-compose.yaml @@ -6,6 +6,7 @@ services: - .:/home/app/web - ./auctions/static:/home/app/web/staticfiles - ./mediafiles:/home/app/web/mediafiles + - ./logs:/home/logs expose: - 8000 env_file: .env diff --git a/fishauctions/settings.py b/fishauctions/settings.py index c7d573e..287a66d 100755 --- a/fishauctions/settings.py +++ b/fishauctions/settings.py @@ -52,6 +52,54 @@ "https://" + os.environ.get("ALLOWED_HOST_3", ""), ] +LOGGING = { + "version": 1, + "disable_existing_loggers": False, + "formatters": { + "verbose": { + "format": "{levelname} {asctime} {module}.{funcName}:{lineno} {message}", + "style": "{", + }, + "simple": { + "format": "{levelname} {message}", + "style": "{", + }, + }, + "handlers": { + "console": { + "class": "logging.StreamHandler", + "formatter": "simple", + }, + "django_file": { + "level": os.getenv("DJANGO_LOG_LEVEL", "INFO"), + "class": "logging.handlers.RotatingFileHandler", + "filename": "/home/logs/django.log", + "maxBytes": 1024 * 1024 * 5, # 5 MB + "backupCount": 5, + "formatter": "verbose", + }, + "root_file": { + "level": os.getenv("LOG_LEVEL", "INFO"), + "class": "logging.handlers.RotatingFileHandler", + "filename": "/home/logs/root.log", + "maxBytes": 1024 * 1024 * 5, # 5 MB + "backupCount": 5, + "formatter": "verbose", + }, + }, + "root": { + "handlers": ["console", "root_file"], + "level": os.getenv("LOG_LEVEL", "INFO"), + }, + "loggers": { + "django": { + "handlers": ["django_file"], + "level": os.getenv("DJANGO_LOG_LEVEL", "INFO"), + "propagate": False, + }, + }, +} + # Channels CHANNEL_LAYERS = { "default": { diff --git a/ruff.toml b/ruff.toml index 5b121e5..4eca5aa 100644 --- a/ruff.toml +++ b/ruff.toml @@ -16,7 +16,6 @@ extend-select = [ # "C90", # McCabe Complexity # "D", # pydocstyle # "DJ", # flake8-django - # "DTZ", # flake8-datetimez "E", # pycodestyle "EM", # flake8-errmsg # "ERA", # eradicate @@ -36,7 +35,7 @@ extend-select = [ # "S", # flake8-bandit # "SIM", # flake8-simplify "TID", # flake8-tidy-imports - # "T20", # flake8-print + "T20", # flake8-print "UP", # pyupgrade "W", # pycodestyle warnings ]