diff --git a/config_app/management/commands/for_test.py b/config_app/management/commands/for_test.py new file mode 100644 index 0000000..64425fe --- /dev/null +++ b/config_app/management/commands/for_test.py @@ -0,0 +1,16 @@ +from django.core.management.base import BaseCommand + + +class Command(BaseCommand): + help = 'Команда для тестов' + + def handle(self, *args, **options): + from finance.loggers import FinanceLogger + logger = FinanceLogger() + try: + 10 / 0 + except Exception as exc: + logger.exception('FinanceLogger test log record', extra={'asdf': 3246523}, + invoice_id=42, exc={'a': 1, 'b': 3, 'привет': 'медвед'} + ) + diff --git a/finance/loggers.py b/finance/loggers.py new file mode 100644 index 0000000..c81ebd0 --- /dev/null +++ b/finance/loggers.py @@ -0,0 +1,56 @@ +# -*- coding: utf-8 -*- + +import logging + +_logger = logging.getLogger('finance_data') + + +class FinanceLogger: + """ + Все kwargs попадют в %(finance_data)s и логируются + 'format': '%(asctime)s - %(levelname)s - %(message)s - %(finance_data)s' + """ + + def __init__(self, prefix=None): + self.prefix = prefix + + def log(self, level, msg, *args, **kwargs): + _logger.log(level=level, msg=self._get_msg(msg), *args, **self._make_kwargs(kwargs)) + + def _get_msg(self, msg): + if self.prefix: + msg = '{}: {}'.format(self.prefix, msg) + return msg + + def _make_kwargs(self, kwargs): + new_kwargs = {} + for inspected_kwarg in ('exc_info', 'stack_info', 'extra'): + try: + new_kwargs[inspected_kwarg] = kwargs.pop(inspected_kwarg) + except KeyError: + pass + if 'extra' in new_kwargs: + new_kwargs['extra']['finance_data'] = kwargs + else: + new_kwargs['extra'] = dict(finance_data=kwargs) + return new_kwargs + + def debug(self, msg, *args, **kwargs): + self.log(level=logging.DEBUG, msg=msg, *args, **kwargs) + + def info(self, msg, *args, **kwargs): + self.log(level=logging.INFO, msg=msg, *args, **kwargs) + + def warning(self, msg, *args, **kwargs): + self.log(level=logging.WARNING, msg=msg, *args, **kwargs) + + # TODO отделить логирование ошибок в другой лог + def error(self, msg, *args, **kwargs): + self.log(level=logging.ERROR, msg=msg, *args, **kwargs) + + def critical(self, msg, *args, **kwargs): + self.log(level=logging.CRITICAL, msg=msg, *args, **kwargs) + + def exception(self, msg, *args, **kwargs): + kwargs['stack_info'] = True + _logger.exception(self._get_msg(msg), *args, **self._make_kwargs(kwargs)) diff --git a/finance/management/commands/yandex_repeat_payment.py b/finance/management/commands/yandex_repeat_payment.py index bba2624..7e2fd49 100644 --- a/finance/management/commands/yandex_repeat_payment.py +++ b/finance/management/commands/yandex_repeat_payment.py @@ -1,15 +1,14 @@ -import logging - from django.core.management.base import BaseCommand +from finance.loggers import FinanceLogger from finance.tasks import periodic_billing -logger_yandex = logging.getLogger('yandex_money') +finance_logger = FinanceLogger() # prefix='YandexMoney' class Command(BaseCommand): def handle(self, *args, **options): - logger_yandex.info("start console repeat payment command") + finance_logger.info("start console repeat payment command") print('Started') periodic_billing() diff --git a/finance/tasks.py b/finance/tasks.py index 33a0615..6977e98 100644 --- a/finance/tasks.py +++ b/finance/tasks.py @@ -1,61 +1,60 @@ import logging - import os + import requests -from dateutil.relativedelta import relativedelta +from django.conf import settings +from django.db import transaction +from django.utils import timezone from yandex_money.models import Payment +from finance.loggers import FinanceLogger from finance.models import InvoiceRebilling from lms import celery_app -from django.conf import settings -from django.utils import timezone - -logger_yandex = logging.getLogger('yandex_money') +finance_logger = FinanceLogger() @celery_app.task def periodic_billing(): - try: - logger_yandex.info("start periodic billing task") + finance_logger.info("start periodic billing task") invoices = InvoiceRebilling.objects.filter(method='Y').exclude(status='F') - - for invoice in invoices.filter( - expected_date__gt=timezone.now(), expected_date__lt=timezone.now() + relativedelta(days=1)): - # TODO выбирать все, даже прошлые неотработанные - что бы не потерять - - user = invoice.bill.user - yandex_pay = Payment.objects.create( - order_amount=invoice.price, - customer_number=user.id, - user=user, - cps_email=user.email, - shop_id=settings.YANDEX_MONEY_REBILLING_SHOP_ID, - scid=settings.YANDEX_MONEY_REBILLING_SCID - ) - invoice.yandex_pay = yandex_pay - invoice.save() - - repeat_card_payment(invoice) - except Exception as exc: - logger_yandex.error('periodic billing Exception', exc_info=True, extra={ - 'exc': exc - }) - # TODO записывать в invoice.comments ошибку яндекса - - -def repeat_card_payment(invoice): - resp = requests.post(settings.YANDEX_MONEY_MWS_URL + 'repeatCardPayment', - data={ - 'clientOrderId': invoice.id, # уникальное возрастающее целое число - 'invoiceId': invoice.key, - 'amount': invoice.price, - 'orderNumber': invoice.yandex_pay.order_number - }, - cert=( - os.path.join(settings.SSL_ROOT, 'skillbox.cer'), - os.path.join(settings.SSL_ROOT, 'skillbox.key') - ), - verify=os.path.join(settings.SSL_ROOT, 'yamoney_chain.cer')) - logger_yandex.info('periodic billing finish', exc_info=True, extra={ - 'response': resp.text, 'code': resp.status_code, - }) + for invoice in invoices.filter(expected_date__lt=timezone.now()): + # выбираем все необработанные из прошлого + with transaction.atomic(): + try: + _yandex_repeat_card_payment(invoice) + except Exception as exc: + finance_logger.exception('YandexMoney repeatCardPayment Exception', invoice_id=invoice.id) + invoice.comment = 'Ошибка при попытке повторного платежа, свяжитесь с клиентской службой' + invoice.save() + + +def _yandex_repeat_card_payment(invoice): + user = invoice.bill.user + yandex_pay = Payment.objects.create( + order_amount=invoice.price, + customer_number=user.id, + user=user, + cps_email=user.email, + shop_id=settings.YANDEX_MONEY_REBILLING_SHOP_ID, + scid=settings.YANDEX_MONEY_REBILLING_SCID + ) + invoice.yandex_pay = yandex_pay + + finance_logger.info('YandexMoney repeatCardPayment start', invoice_id=invoice.id) + resp = requests.post( + url=settings.YANDEX_MONEY_MWS_URL + 'repeatCardPayment', + data={ + 'clientOrderId': invoice.id, # уникальное возрастающее целое число + 'invoiceId': invoice.key, + 'amount': invoice.price, + 'orderNumber': invoice.yandex_pay.order_number + }, + cert=( + os.path.join(settings.SSL_ROOT, 'skillbox.cer'), + os.path.join(settings.SSL_ROOT, 'skillbox.key') + ), + verify=os.path.join(settings.SSL_ROOT, 'yamoney_chain.cer') + ) + # TODO тут проверять нет ли ошибки яндекса (даже при 200 ответе) + finance_logger.info('YandexMoney repeatCardPayment ended', + invoice_id=invoice.id, response=resp.text, code=resp.status_code, ) diff --git a/finance/views.py b/finance/views.py index a79b009..31fdd34 100644 --- a/finance/views.py +++ b/finance/views.py @@ -1,32 +1,32 @@ import csv -import logging +import uuid import requests +from django.conf import settings from django.contrib.auth import get_user_model from django.core.mail import EmailMessage +from django.core.mail import EmailMultiAlternatives from django.db import IntegrityError from django.db.models import Q from django.http import HttpResponse, HttpResponseForbidden from django.shortcuts import redirect, render_to_response +from django.template.loader import render_to_string +from django.utils import timezone +from django.utils.html import strip_tags from rest_framework.renderers import JSONRenderer from rest_framework.response import Response from rest_framework.views import APIView from yandex_money.models import Payment -from django.conf import settings -from django.core.mail import EmailMultiAlternatives -from django.template.loader import render_to_string -from django.utils.html import strip_tags -from courses.models import Course from courses.api import CourseParamsApi +from courses.models import Course +from finance.loggers import FinanceLogger from finance.models import Bill, Invoice, InvoiceRebilling from finance.serializers import BillSerializer, InvoiceSerializer from lms.global_decorators import transaction_decorator from lms.tools import get_real_name -from django.utils import timezone -import uuid -logger_yandex = logging.getLogger('yandex_money') +finance_logger = FinanceLogger() # prefix='YandexMoney' def test_pay(request): @@ -337,9 +337,7 @@ class YandexPay(APIView): msg.send() except Exception as exc: - logger_yandex.error('YandexPay: Email not sended', exc_info=True, extra={ - 'exc': exc - }) + finance_logger.exception('YandexPay: Email not sended') return redirect(r.url) @@ -395,41 +393,35 @@ class YandexCheckView(APIView): val = i.split('=')[1] data[key] = val - logger_yandex.info('Проверка платежа запрос', exc_info=True, extra={ - 'request': data, - }) + finance_logger.info('Проверка платежа запрос', request=data) + order_number = data['orderNumber'] try: - pay = Payment.objects.get(order_number=data['orderNumber']) + pay = Payment.objects.get(order_number=order_number) except Payment.DoesNotExist: - logger_yandex.error('Ошибка проверки платежа', exc_info=True, extra={ - 'request': "Payment with id=%s not found" % data['orderNumber'], - }) + finance_logger.error('Ошибка проверки платежа', exc_info=True, + request="Payment with id=%s not found" % order_number) return Response(status=204) if not pay.status == Payment.STATUS.PROCESSED: - logger_yandex.error('Ошибка проверки платежа', exc_info=True, extra={ - 'request': "Payment with id=%s have status %s" % (data['orderNumber'], pay.status), - }) + finance_logger.error('Ошибка проверки платежа', + order_number=order_number, + request="Payment with id=%s have status %s" % (order_number, pay.status)) return Response(status=204) if not pay.shop_id == int(data['shopId']): - logger_yandex.error('Ошибка проверки платежа', exc_info=True, extra={ - 'request': "ShopId=%s not match" % (data['shopId'],), - }) + finance_logger.error('Ошибка проверки платежа', + request="ShopId=%s not match" % (data['shopId'],)) return Response(status=204) if not pay.scid == int(data['scid']): - logger_yandex.error('Ошибка проверки платежа', exc_info=True, extra={ - 'request': "scid=%s not match" % (data['scid'],) - }) + finance_logger.error('Ошибка проверки платежа', + request="scid=%s not match" % (data['scid'],)) return Response(status=204) if not pay.order_amount == float(data['orderSumAmount']): - logger_yandex.error('Ошибка проверки платежа', exc_info=True, extra={ - 'request': "Expected amount is %s received amount is %s" - % (pay.order_amount, data['orderSumAmount']), - }) + finance_logger.error('Ошибка проверки платежа', + request="Expected amount is %s received amount is %s" % (pay.order_amount, data['orderSumAmount'])) return Response(status=204) now = timezone.now() @@ -439,9 +431,7 @@ class YandexCheckView(APIView): xml_res = """ """ % (pay.performed_datetime, str(data['invoiceId']), str(pay.shop_id)) - logger_yandex.info('Проверка платежа ответ', exc_info=True, extra={ - 'response': xml_res, - }) + finance_logger.info('Проверка платежа ответ', response=xml_res) return HttpResponse(xml_res, content_type='application/xml') @@ -457,17 +447,16 @@ class YandexAvisoView(APIView): val = i.split('=')[1] data[key] = val + order_number = data['orderNumber'] try: - pay = Payment.objects.get(order_number=data['orderNumber']) + pay = Payment.objects.get(order_number=order_number) except Payment.DoesNotExist: - logger_yandex.error('Ошибка подтверждения платежа', exc_info=True, extra={ - 'request': "Payment with invoice_id=%s not found" % data['orderNumber'], - }) + finance_logger.error('Ошибка подтверждения платежа', exc_info=True, + request="Payment with invoice_id=%s not found" % order_number) return Response(status=204) - logger_yandex.info('Подтверждение платежа запрос', exc_info=True, extra={ - 'request': 'Get success pay with invoice_id(yandex) %s' % str(data['invoiceId']), - }) + finance_logger.info('Подтверждение платежа запрос', + request='Get success pay with invoice_id(yandex) %s' % str(data['invoiceId'])) pay.shop_amount = data['shopSumAmount'] # invoice = pay.invoice @@ -481,9 +470,7 @@ class YandexAvisoView(APIView): xml_res = """ """ % (pay.performed_datetime, str(data['invoiceId']), str(pay.shop_id)) - logger_yandex.info('Подтверждение платежа ответ', exc_info=True, extra={ - 'response': xml_res, - }) + finance_logger.info('Подтверждение платежа ответ', response=xml_res) context = { 'user_email': pay.invoice.bill.user.email, @@ -518,7 +505,7 @@ class YandexFailView(APIView): val = i.split('=')[1] data[key] = val - logger_yandex.error(data) + finance_logger.error('YandexFailView', data=data) return redirect(to=settings.DOMAIN) @@ -536,12 +523,10 @@ class DemoYandexCheckView(APIView): val = i.split('=')[1] data[key] = val - logger_yandex.info('Проверка демо платежа запрос', exc_info=True, extra={ - 'request': data, - }) + finance_logger.info('Проверка демо платежа запрос', request=data) except IndexError: - logger_yandex.error("Непредвиденная ошибка проверки тестогого платежа") + finance_logger.exception("Непредвиденная ошибка проверки тестогого платежа") return Response(status=204) now = timezone.now() @@ -552,14 +537,10 @@ class DemoYandexCheckView(APIView): else: xml_res = """""" % (now.isoformat(), str(data['invoiceId']), str(data['shopId'])) - logger_yandex.warning( - "Ошибка проверки тестогого платежа" , exc_info=True, extra={ - "response": xml_res - } - ) + finance_logger.warning("Ошибка проверки тестового платежа", response=xml_res) return HttpResponse(xml_res, content_type='application/xml') except KeyError: - logger_yandex.error('Ошибка в данных checkYandex') + finance_logger.exception('Ошибка в данных checkYandex') return Response(status=204) @@ -567,7 +548,7 @@ class DemoYandexAvisoView(APIView): @staticmethod def post(request): - logger_yandex.info('Начало тестирования avisoYandex') + finance_logger.info('Начало тестирования avisoYandex') data = dict() for i in request.body.decode('utf-8').split('&'): key = i.split('=')[0] @@ -578,17 +559,11 @@ class DemoYandexAvisoView(APIView): if float(data['orderSumAmount']) < 1001: xml_res = """ """ % (now.isoformat(), str(data['invoiceId']), str(data['shopId'])) - logger_yandex.info('Подтверждение демо платежа ответ', exc_info=True, extra={ - 'response': xml_res, - }) + finance_logger.info('Подтверждение демо платежа ответ', response=xml_res) else: xml_res = """""" % (now.isoformat(), str(data['invoiceId']), str(data['shopId'])) - logger_yandex.warning( - "Ошибка подтверждения тестогого платежа", exc_info=True, extra={ - "response": xml_res - } - ) + finance_logger.warning("Ошибка подтверждения тестогого платежа", response=xml_res) return HttpResponse(xml_res, content_type='application/xml') \ No newline at end of file diff --git a/lms/celery.py b/lms/celery.py index 9e37861..4f9d66d 100644 --- a/lms/celery.py +++ b/lms/celery.py @@ -21,9 +21,8 @@ register_signal(client) app.conf.beat_schedule = { 'periodic_billing': { - 'schedule': crontab(day_of_month='1', hour='1', minute='1'), # заглушка на время отладки - # 'schedule': crontab(minute='*/1'), - # crontab(minute='0',hour='*/3',), + # 'schedule': crontab(day_of_month='1', hour='1', minute='1'), # заглушка на время отладки + 'schedule': crontab(minute='0', hour='*/3',), 'task': 'finance.tasks.periodic_billing' } } diff --git a/lms/settings.py b/lms/settings.py index 34493ef..5894e6f 100644 --- a/lms/settings.py +++ b/lms/settings.py @@ -206,6 +206,9 @@ LOGGING = { 'format': '%(levelname)s %(asctime)s %(module)s ' '%(process)d %(thread)d %(message)s' }, + 'finance_data_formatter': { + 'format': '%(asctime)s - %(levelname)s - %(message)s - %(finance_data)s' + }, }, 'handlers': { 'sentry': { @@ -213,15 +216,17 @@ LOGGING = { 'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler', 'tags': {'custom-tag': 'x'}, }, - 'yandex_money': { + 'finance_data': { 'level': 'DEBUG', 'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler', - 'tags': {'custom-tag': 'yandex'}, + 'tags': {'custom-tag': 'yandex'}, # TODO переделать на finance_data }, - 'yandex_money_file': { + 'finance_data_file': { 'level': 'INFO', - 'class': 'logging.FileHandler', - 'filename': os.path.join(BASE_DIR, 'logs', 'yandex_money.log'), + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(BASE_DIR, 'logs', 'finance_data.log'), + 'maxBytes': 1024 * 1024 * 10, + 'formatter': 'finance_data_formatter' }, 'business_rules': { 'level': 'DEBUG', @@ -239,8 +244,8 @@ LOGGING = { 'level': 'WARNING', 'handlers': ['sentry'], }, - 'yandex_money': { - 'handlers': ['yandex_money', 'yandex_money_file', ], + 'finance_data': { + 'handlers': ['finance_data', 'finance_data_file', ], 'level': 'DEBUG', 'propagate': False },