fixup logging

This commit is contained in:
Thomas Steen Rasmussen 2017-03-23 18:32:13 +01:00
parent 4f61a95d83
commit 171553677c
10 changed files with 86 additions and 55 deletions

View File

@ -113,22 +113,30 @@ if DEBUG:
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'handlers': {
'mail_admins': {
'level': 'ERROR',
'class': 'django.utils.log.AdminEmailHandler',
'formatters': {
'syslog': {
'format': '%(levelname)s %(name)s.%(funcName)s(): %(message)s'
},
'console': {
'level':'DEBUG',
'class':'logging.StreamHandler',
'format': '[%(asctime)s] %(name)s.%(funcName)s() %(levelname)s %(message)s',
'datefmt': '%d/%b/%Y %H:%M:%S'
},
},
'handlers': {
'console': {
'level': 'DEBUG',
'class': 'logging.StreamHandler',
'formatter': 'console'
},
},
'loggers': {
'django.request': {
'handlers': ['mail_admins'],
'level': 'ERROR',
'propagate': True,
# send bornhack logger to both console and syslog at DEBUG level, and
# do not propagate bornhack.* messages up to the root logger
'bornhack': {
'handlers': ['console'],
'level': 'DEBUG',
'propagate': False,
},
}
},
}

View File

@ -7,6 +7,9 @@ from django.core.exceptions import ValidationError
from datetime import timedelta
from django.utils import timezone
from django.urls import reverse
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
class Camp(CreatedUpdatedModel, UUIDModel):
@ -98,13 +101,13 @@ class Camp(CreatedUpdatedModel, UUIDModel):
Returns a list of DateTimeTZRanges representing the days during the specified part of the camp.
'''
if not hasattr(self, camppart):
print("nonexistant field/attribute")
logger.error("nonexistant field/attribute")
return False
field = getattr(self, camppart)
if not hasattr(field, '__class__') or not hasattr(field.__class__, '__name__') or not field.__class__.__name__ == 'DateTimeTZRange':
print("this attribute is not a datetimetzrange field: %s" % field)
logger.error("this attribute is not a datetimetzrange field: %s" % field)
return False
daycount = (field.upper - field.lower).days

View File

@ -5,26 +5,35 @@ from django.shortcuts import redirect
from .mixins import CampViewMixin
from django.views import View
from django.conf import settings
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
class CampRedirectView(CampViewMixin, View):
def dispatch(self, request, *args, **kwargs):
# find the closest camp in the past
prevcamp = Camp.objects.filter(camp__endswith__lt=timezone.now()).order_by('-camp')[0]
# find the closest upcoming camp
nextcamp = Camp.objects.filter(camp__startswith__gt=timezone.now()).order_by('camp')[0]
# find the number of days between the two camps
daysbetween = (nextcamp.camp.lower - prevcamp.camp.upper).days
# find the number of days since the last camp ended
dayssinceprevcamp = (timezone.now() - prevcamp.camp.lower).days
# find the percentage of time passed
percentpassed = (dayssinceprevcamp / daysbetween) * 100
print(daysbetween, dayssinceprevcamp, percentpassed)
# do the redirect
if percentpassed > settings.CAMP_REDIRECT_PERCENT:
return redirect(kwargs['page'], camp_slug=nextcamp.slug)
camp = nextcamp
else:
return redirect(kwargs['page'], camp_slug=prevcamp.slug)
camp = prevcamp
logger.debug("Redirecting to camp '%s' for page '%s' because %s%% of the time between the camps passed" % (camp.slug, kwargs['page'], int(percentpassed)))
return redirect(kwargs['page'], camp_slug=camp.slug)
class CampDetailView(DetailView):

View File

@ -2,6 +2,8 @@ import irc3
from ircbot.models import OutgoingIrcMessage
from django.conf import settings
from django.utils import timezone
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
@irc3.plugin
@ -24,20 +26,17 @@ class Plugin(object):
def server_ready(self, **kwargs):
"""triggered after the server sent the MOTD (require core plugin)"""
if settings.DEBUG:
print("inside server_ready(), kwargs: %s" % kwargs)
logger.debug("inside server_ready(), kwargs: %s" % kwargs)
def connection_lost(self, **kwargs):
"""triggered when connection is lost"""
if settings.DEBUG:
print("inside connection_lost(), kwargs: %s" % kwargs)
logger.debug("inside connection_lost(), kwargs: %s" % kwargs)
def connection_made(self, **kwargs):
"""triggered when connection is up"""
if settings.DEBUG:
print("inside connection_made(), kwargs: %s" % kwargs)
logger.debug("inside connection_made(), kwargs: %s" % kwargs)
###############################################################################################
@ -46,8 +45,7 @@ class Plugin(object):
@irc3.event(irc3.rfc.JOIN_PART_QUIT)
def on_join_part_quit(self, **kwargs):
"""triggered when there is a join part or quit on a channel the bot is in"""
if settings.DEBUG:
print("inside on_join_part_quit(), kwargs: %s" % kwargs)
logger.debug("inside on_join_part_quit(), kwargs: %s" % kwargs)
if self.bot.nick == kwargs['mask'].split("!")[0] and kwargs['channel'] == "#tirsdagsfilm":
self.bot.loop.call_later(1, self.bot.get_outgoing_messages)
@ -55,14 +53,12 @@ class Plugin(object):
@irc3.event(irc3.rfc.PRIVMSG)
def on_privmsg(self, **kwargs):
"""triggered when a privmsg is sent to the bot or to a channel the bot is in"""
if settings.DEBUG:
print("inside on_privmsg(), kwargs: %s" % kwargs)
logger.debug("inside on_privmsg(), kwargs: %s" % kwargs)
@irc3.event(irc3.rfc.KICK)
def on_kick(self, **kwargs):
if settings.DEBUG:
print("inside on_kick(), kwargs: %s" % kwargs)
logger.debug("inside on_kick(), kwargs: %s" % kwargs)
###############################################################################################
### custom irc3 methods
@ -73,7 +69,7 @@ class Plugin(object):
This method gets unprocessed OutgoingIrcMessage objects and attempts to send them to
the target channel. Messages are skipped if the bot is not in the channel.
"""
print("inside get_outgoing_messages()")
logger.debug("inside get_outgoing_messages()")
for msg in OutgoingIrcMessage.objects.filter(processed=False).order_by('created'):
# if this message expired mark it as expired and processed without doing anything
if msg.timeout < timezone.now():
@ -85,7 +81,7 @@ class Plugin(object):
# is this message for a channel or a nick?
if msg.target[0] == "#" and msg.target in self.bot.channels:
print("sending privmsg to %s: %s" % (msg.target, msg.message))
logger.debug("sending privmsg to %s: %s" % (msg.target, msg.message))
self.bot.privmsg(msg.target, msg.message)
msg.processed=True
msg.save()
@ -94,7 +90,7 @@ class Plugin(object):
msg.processed=True
msg.save()
else:
print("skipping message to %s" % msg.target)
logger.warning("skipping message to %s" % msg.target)
# call this function again in 60 seconds
self.bot.loop.call_later(settings.IRCBOT_CHECK_MESSAGE_INTERVAL_SECONDS, self.bot.get_outgoing_messages)

View File

@ -8,6 +8,9 @@ from camps.utils import get_current_camp
from django.utils import timezone
from program.models import EventInstance
from datetime import timedelta
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
class Command(BaseCommand):
@ -36,7 +39,7 @@ class Command(BaseCommand):
message="starting soon: %s" % ei,
timeout=ei.when.lower
)
print("added irc message id %s for eventinstance %s" % (oim.id, ei))
logger.info("added irc message id %s for eventinstance %s" % (oim.id, ei))
ei.notifications_sent=True
ei.save()

View File

@ -1,6 +1,9 @@
from django.core.mail import EmailMultiAlternatives
from django.conf import settings
from django.template.loader import render_to_string
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
def send_email(emailtype, recipient, formatdict, subject, sender='BornHack <info@bornhack.dk>', attachment=None):
@ -18,13 +21,13 @@ def send_email(emailtype, recipient, formatdict, subject, sender='BornHack <info
elif emailtype == 'testmail':
text_template = 'emails/testmail.txt'
else:
print('Unknown email type: %s' % emailtype)
logger.error('Unknown email type: %s' % emailtype)
return False
try:
### put the basic email together
msg = EmailMultiAlternatives(subject, render_to_string(text_template, formatdict), sender, [recipient], [settings.ARCHIVE_EMAIL])
### is there a html version of this email?
if html_template:
msg.attach_alternative(render_to_string(html_template, formatdict), 'text/html')
@ -34,9 +37,9 @@ def send_email(emailtype, recipient, formatdict, subject, sender='BornHack <info
msg.attach(attachment_filename, attachment, 'application/pdf')
except Exception as E:
print('exception while rendering email: %s' % E)
logger.exception('exception while rendering email: %s' % E)
return False
### send the email
msg.send()

View File

@ -1,3 +1,7 @@
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
### epay callback function
@require_safe
def api_epay_callback(request):
@ -15,27 +19,24 @@ def api_epay_callback(request):
try:
order = EpayOrder.objects.get(id=request.GET['orderid'][1:])
except EpayOrder.DoesNotExist:
print("epay callback - epayorder %s not found" % request.GET['orderid'])
logger.error("epay callback - epayorder %s not found" % request.GET['orderid'])
return HttpResponse("Not OK")
### check hash here
if 'hash' not in request.GET:
print("epay callback - missing epay hash")
logger.error("epay callback - missing epay hash")
return HttpResponse("Not OK")
### this does not work sometimes, ordering is off maybe?
hashstring = ''
qs = request.META['QUERY_STRING']
print("querystring is %s" % qs)
for kv in qs.split("&"):
print("hashstring is now %s" % hashstring)
if kv.split("=")[0] != "hash":
hashstring += kv.split("=")[1]
print("hashstring is now %s" % hashstring)
hashstring += settings.EPAY_MD5_SECRET
epayhash = hashlib.md5(hashstring).hexdigest()
if epayhash != request.GET['hash']:
print("epay callback - wrong epay hash")
logger.error("epay callback - wrong epay hash")
return HttpResponse("Not OK")
### save callback in epayorder
@ -61,7 +62,7 @@ def api_epay_callback(request):
### save
order.save()
else:
print("epay callback - order %s not recognized" % request.GET['orderid'])
logger.error("epay callback - order %s not recognized" % request.GET['orderid'])
return HttpResponse("Not OK")
return HttpResponse("OK")
@ -103,7 +104,7 @@ def epay_order(request):
### save epay order with commit=False
epayorder = form.save(commit=False)
except Exception as E:
print("unable to save epay order with commit=false")
logger.error("unable to save epay order with commit=false")
return render(request, 'epay_order_fail.html', {
'message': _('Unable to save epay order. Please try again, and please contact us if the problem persists.')
})

View File

@ -3,6 +3,9 @@ from PyPDF2 import PdfFileWriter, PdfFileReader
from django.test.client import RequestFactory
from django.conf import settings
import io
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
def generate_pdf_letter(filename, template, formatdict):
### produce text-only PDF from template
@ -41,7 +44,7 @@ def generate_pdf_letter(filename, template, formatdict):
### save the generated pdf to the archive
with open(settings.PDF_ARCHIVE_PATH+filename, 'wb') as fh:
finalpdf.write(fh)
print(('Saved pdf to archive: %s' % settings.PDF_ARCHIVE_PATH+filename))
logger.info('Saved pdf to archive: %s' % settings.PDF_ARCHIVE_PATH+filename)
### return a file object with the data
returnfile = io.StringIO()

View File

@ -38,6 +38,9 @@ from collections import OrderedDict
from vendor.coinify_api import CoinifyAPI
from vendor.coinify_callback import CoinifyCallback
import json, time
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
#################################################################################
@ -451,16 +454,16 @@ class EpayCallbackView(SingleObjectMixin, View):
)
order = get_object_or_404(Order, pk=query.get('orderid'))
if order.pk != self.get_object().pk:
print("bad epay callback, orders do not match!")
logger.error("bad epay callback, orders do not match!")
return HttpResponse(status=400)
if validate_epay_callback(query):
callback.md5valid=True
callback.save()
else:
print("bad epay callback!")
logger.error("bad epay callback!")
return HttpResponse(status=400)
if order.paid:
### this order is already paid, perhaps we are seeing a double callback?
return HttpResponse('OK')
@ -476,7 +479,7 @@ class EpayCallbackView(SingleObjectMixin, View):
### and mark order as paid (this will create tickets)
order.mark_as_paid()
else:
print("valid epay callback with wrong amount detected")
logger.error("valid epay callback with wrong amount detected")
else:
return HttpResponse(status=400)
@ -538,7 +541,7 @@ class CoinifyRedirectView(LoginRequiredMixin, EnsureUserOwnsOrderMixin, EnsureUn
# check if it expired
if parse_datetime(order.coinifyapiinvoice.invoicejson['expire_time']) < timezone.now():
# this coinifyinvoice expired, delete it
print("deleting expired coinifyinvoice id %s" % order.coinifyapiinvoice.invoicejson['id'])
logger.warning("deleting expired coinifyinvoice id %s" % order.coinifyapiinvoice.invoicejson['id'])
order.coinifyapiinvoice.delete()
order = self.get_object()
@ -565,7 +568,7 @@ class CoinifyRedirectView(LoginRequiredMixin, EnsureUserOwnsOrderMixin, EnsureUn
# Parse response
if not response['success']:
api_error = response['error']
print("API error: %s (%s)" % (
logger.error("API error: %s (%s)" % (
api_error['message'],
api_error['code']
))
@ -577,7 +580,7 @@ class CoinifyRedirectView(LoginRequiredMixin, EnsureUserOwnsOrderMixin, EnsureUn
invoicejson = response['data'],
order = order,
)
print("created new coinifyinvoice id %s" % coinifyinvoice.invoicejson['id'])
logger.info("created new coinifyinvoice id %s" % coinifyinvoice.invoicejson['id'])
return super(CoinifyRedirectView, self).dispatch(
request, *args, **kwargs
)
@ -622,7 +625,7 @@ class CoinifyCallbackView(SingleObjectMixin, View):
try:
coinifyinvoice = CoinifyAPIInvoice.objects.get(invoicejson__id=callbackjson['data']['id'])
except CoinifyAPIInvoice.DoesNotExist:
print("unable to find CoinifyAPIInvoice with id %s" % callbackjson['data']['id'])
logger.error("unable to find CoinifyAPIInvoice with id %s" % callbackjson['data']['id'])
return HttpResponseBadRequest('bad coinifyinvoice id')
# save new coinifyinvoice payload
@ -638,7 +641,7 @@ class CoinifyCallbackView(SingleObjectMixin, View):
else:
return HttpResponseBadRequest('unsupported event')
else:
print("invalid coinify callback detected")
logger.error("invalid coinify callback detected")
return HttpResponseBadRequest('something is fucky')

View File

@ -2,6 +2,8 @@ import uuid
from django.core.exceptions import ValidationError
from django.contrib import messages
from django.db import models
import logging
logger = logging.getLogger("bornhack.%s" % __name__)
class CleanedModel(models.Model):
@ -22,7 +24,7 @@ class CleanedModel(models.Model):
message = "Got ValidationError while saving: %s" % e
if hasattr(self, 'request'):
messages.error(self.request, message)
print(message)
logger.error(message)
# dont save, re-raise the exception
raise
super(CleanedModel, self).save(**kwargs)