diff --git a/combo/apps/lingo/models.py b/combo/apps/lingo/models.py index 1f3b4a81..93f20eb8 100644 --- a/combo/apps/lingo/models.py +++ b/combo/apps/lingo/models.py @@ -60,6 +60,23 @@ except ImportError: UserSAMLIdentifier = None +logger = logging.getLogger('combo.apps.lingo') + + +class PaymentException(Exception): + pass + + +class UnsignedPaymentException(PaymentException): + def __init__(self, transaction, *args, **kwargs): + super(UnsignedPaymentException, self).__init__(*args, **kwargs) + self.transaction = transaction + + +class UnknownPaymentException(PaymentException): + pass + + EXPIRED = 9999 @@ -79,6 +96,19 @@ SERVICES = [ ] +def eopayment_response_to_extra_info(response, **kwargs): + extra_info = dict(kwargs) + extra_info.update( + { + 'eopayment_order_id': response.order_id, + 'eopayment_response': repr(response), + } + ) + for k, v in response.bank_data.items(): + extra_info['eopayment_bank_data_' + k] = v + return extra_info + + class RegieException(Exception): pass @@ -170,6 +200,37 @@ class PaymentBackend(models.Model): backend = next(serializers.deserialize('json', json.dumps([json_backend]), ignorenonexistent=True)) backend.save() + def handle_backend_response(self, response, callback=True): + try: + transaction = Transaction.objects.get(order_id=response.order_id) + except Transaction.DoesNotExist: + logger.warning( + 'lingo: transaction not found for payment response with id %s', + response.order_id, + extra=eopayment_response_to_extra_info(response), + ) + raise UnknownPaymentException('Received unknown payment response') + else: + logger.debug( + 'lingo: backend "%s" received payment response with id %%s' % self, + response.order_id, + extra=eopayment_response_to_extra_info( + response, lingo_transaction_id=transaction.pk, user=transaction.user + ), + ) + + # check if transaction belong to the right payment backend + if not transaction.regie.payment_backend == self: + logger.warning( + 'lingo: backend "%s" received payment for backend "%s"', + self.regie.payment_backend, + self, + extra=eopayment_response_to_extra_info(response), + ) + raise PaymentException('Invalid payment backend') + transaction.handle_backend_response(response, callback=callback) + return transaction + @python_2_unicode_compatible class Regie(models.Model): @@ -346,7 +407,6 @@ class Regie(models.Model): headers={'content-type': 'application/json'}, ) if response.status_code != 200 or response.json().get('err'): - logger = logging.getLogger(__name__) logger.error('failed to compute extra fees (user: %r)', user) return basketitems.filter(extra_fee=True).delete() @@ -645,6 +705,17 @@ class RemoteItem(object): remote_item.payment_date = paid_items[remote_item.id] +def status_label(status): + return { + 0: _('Running'), + eopayment.WAITING: _('Running'), + eopayment.PAID: _('Paid'), + eopayment.ACCEPTED: _('Paid (accepted)'), + eopayment.CANCELLED: _('Cancelled'), + EXPIRED: _('Expired'), + }.get(status) or _('Unknown') + + class Transaction(models.Model): regie = models.ForeignKey(Regie, on_delete=models.CASCADE, null=True) items = models.ManyToManyField(BasketItem, blank=True) @@ -671,14 +742,11 @@ class Transaction(models.Model): def is_paid(self): return self.status in (eopayment.PAID, eopayment.ACCEPTED) + def is_running(self): + return self.status in [0, eopayment.WAITING, eopayment.RECEIVED] + def get_status_label(self): - return { - 0: _('Running'), - eopayment.PAID: _('Paid'), - eopayment.ACCEPTED: _('Paid (accepted)'), - eopayment.CANCELLED: _('Cancelled'), - EXPIRED: _('Expired'), - }.get(self.status) or _('Unknown') + return status_label(self.status) def first_notify_remote_items_of_payments(self): self.notify_remote_items_of_payments(self.remote_items) @@ -687,7 +755,6 @@ class Transaction(models.Model): self.notify_remote_items_of_payments(self.to_be_paid_remote_items) def notify_remote_items_of_payments(self, items): - logger = logging.getLogger(__name__) if not items: return if not self.is_paid(): @@ -734,6 +801,95 @@ class Transaction(models.Model): self.to_be_paid_remote_items = ','.join(to_be_paid_remote_items) or None self.save(update_fields=['to_be_paid_remote_items']) + def handle_backend_response(self, response, callback=True): + logger.debug('lingo: regie "%s" handling response for transaction "%%s"' % self.regie, self.order_id) + if self.status == response.result: + # return early if self status didn't change (it means the + # payment service sent the response both as server to server and + # via the user browser and we already handled one). + return + + if not self.is_running(): + logger.info( + 'lingo: regie "%s" received payment notification on existing ' + 'transaction, status changed, "%%s" (%%s) -> "%%s" (%%s)' % self.regie, + status_label(self.status), + self.status, + status_label(response.result), + response.result, + ) + + if not response.signed and not response.result == eopayment.CANCELLED: + # we accept unsigned cancellation requests as some platforms do + # that :/ + logger.warning( + 'lingo: regie "%s" received unsigned payment response with id %%s' % self.regie, + response.order_id, + ) + raise UnsignedPaymentException(self, 'Received unsigned payment response') + self.status = response.result + self.bank_transaction_id = response.transaction_id + self.bank_data = response.bank_data + self.end_date = timezone.now() + # store transaction_date but prevent multiple updates + if response.transaction_date is None: + logger.warning('lingo: no transaction date') + elif self.bank_transaction_date is None: + self.bank_transaction_date = response.transaction_date + elif response.transaction_date != self.bank_transaction_date: + # XXX: don't know if it can happen, but we would like to know when it does + # as for differed payments there can be multiple notifications. + logger.error( + 'lingo: regie "%s" new transaction_date for transaction %%s(%%s) was %%s, received %%s' + % self.regie, + self.order_id, + self.id, + self.bank_transaction_date, + response.transaction_date, + ) + + self.save() + + logger.info( + 'lingo: regie "%s" received %s payment notification for transaction %%s(%%s)' + % (self.regie, 'synchronous' if callback else 'asynchronous'), + self.order_id, + self.id, + extra=eopayment_response_to_extra_info(response), + ) + + if response.result == eopayment.WAITING: + # mark basket items as waiting for payment confirmation + self.items.all().update(waiting_date=timezone.now()) + return + + if response.result == eopayment.CANCELLED: + # mark basket items as no longer waiting so the user can restart a + # payment. + self.items.all().update(waiting_date=None) + return + + if response.result not in (eopayment.PAID, eopayment.ACCEPTED): + return + + self.items.update(payment_date=self.end_date) + + for item in self.items.all(): + try: + item.notify_payment() + except Exception as e: + # ignore errors, it will be retried later on if it fails + logger.warning( + 'lingo: regie "%s" error in sync notification for basket item %%s ' + 'and transaction %%s, %%s' % self.regie, + item.id, + self.order_id, + e, + ) + + if self.remote_items: + self.first_notify_remote_items_of_payments() + class TransactionOperation(models.Model): OPERATIONS = [ diff --git a/combo/apps/lingo/views.py b/combo/apps/lingo/views.py index b2b12033..2930374a 100644 --- a/combo/apps/lingo/views.py +++ b/combo/apps/lingo/views.py @@ -55,11 +55,14 @@ from .models import ( BasketItem, LingoBasketCell, PaymentBackend, + PaymentException, Regie, RemoteInvoiceException, SelfDeclaredInvoicePayment, Transaction, TransactionOperation, + UnknownPaymentException, + UnsignedPaymentException, ) from .utils import signing_dumps, signing_loads @@ -607,22 +610,8 @@ class BasketItemPayView(PayMixin, View): ) -class PaymentException(Exception): - pass - - -class UnsignedPaymentException(PaymentException): - def __init__(self, transaction, *args, **kwargs): - super(UnsignedPaymentException, self).__init__(*args, **kwargs) - self.transaction = transaction - - -class UnknownPaymentException(PaymentException): - pass - - class PaymentView(View): - def handle_response(self, request, backend_response, **kwargs): + def handle_response(self, request, backend_response, *, callback=True, transaction=None, **kwargs): if 'regie_pk' in kwargs: payment_backend = get_object_or_404(Regie, pk=kwargs['regie_pk']).payment_backend elif 'payment_backend_pk' in kwargs: @@ -632,9 +621,16 @@ class PaymentView(View): payment = get_eopayment_object(request, payment_backend) logger.info(u'received payment response: %r', backend_response) - extra_info = kwargs.pop('payment_extra_info', {}) try: - payment_response = payment.response(backend_response, **extra_info) + eopayment_response_kwargs = {'redirect': not callback} + if transaction is not None: + eopayment_response_kwargs.update( + { + 'order_id_hint': transaction.order_id, + 'order_status_hint': transaction.status, + } + ) + payment_response = payment.response(backend_response, **eopayment_response_kwargs) except eopayment.PaymentException as e: logger.error( u'failed to process payment response: %s', @@ -643,109 +639,7 @@ class PaymentView(View): ) raise PaymentException('Failed to process payment response') - extra_info = { - 'eopayment_order_id': smart_text(payment_response.order_id), - 'eopayment_response': repr(payment_response), - } - for k, v in payment_response.bank_data.items(): - extra_info['eopayment_bank_data_' + k] = smart_text(v) - try: - transaction = Transaction.objects.get(order_id=payment_response.order_id) - except Transaction.DoesNotExist: - logger.warning( - u'received unknown payment response with id %s', - smart_text(payment_response.order_id), - extra=extra_info, - ) - raise UnknownPaymentException('Received unknown payment response') - else: - extra_info['lingo_transaction_id'] = transaction.pk - if transaction.user: - # let hobo logger filter handle the extraction of user's infos - extra_info['user'] = transaction.user - logger.info( - u'received known payment response with id %s', - smart_text(payment_response.order_id), - extra=extra_info, - ) - - if transaction.status == payment_response.result: - # return early if transaction status didn't change (it means the - # payment service sent the response both as server to server and - # via the user browser and we already handled one). - return transaction - - if transaction.status and transaction.status != payment_response.result: - logger.info( - u'received payment notification on existing transaction ' - '(status: %s, new status: %s)' % (transaction.status, payment_response.result) - ) - - # check if transaction belongs to right regie - if not transaction.regie.payment_backend == payment_backend: - logger.warning( - u'received payment for inappropriate payment backend ' - '(expecteds: %s, received: %s)' % (transaction.regie.payment_backend, payment_backend) - ) - raise PaymentException('Invalid payment regie') - - if not payment_response.signed and not payment_response.result == eopayment.CANCELLED: - # we accept unsigned cancellation requests as some platforms do - # that :/ - logger.warning( - u'received unsigned payment response with id %s', - smart_text(payment_response.order_id), - extra=extra_info, - ) - raise UnsignedPaymentException(transaction, 'Received unsigned payment response') - - transaction.status = payment_response.result - transaction.bank_transaction_id = payment_response.transaction_id - transaction.bank_data = payment_response.bank_data - transaction.end_date = timezone.now() - # store transaction_date but prevent multiple updates - if payment_response.transaction_date is None: - logger.warning('no transaction date') - elif transaction.bank_transaction_date is None: - transaction.bank_transaction_date = payment_response.transaction_date - elif payment_response.transaction_date != transaction.bank_transaction_date: - # XXX: don't know if it can happen, but I would like to know when it does - # as for differed payments there can be multiple notifications. - logger.error( - 'new transaction_date for transaction %s was %s, received %s', - transaction.id, - transaction.bank_transaction_date, - payment_response.transaction_date, - ) - transaction.save() - - if payment_response.result == eopayment.WAITING: - # mark basket items as waiting for payment confirmation - transaction.items.all().update(waiting_date=timezone.now()) - return transaction - - if payment_response.result == eopayment.CANCELLED: - # mark basket items as no longer waiting so the user can restart a - # payment. - transaction.items.all().update(waiting_date=None) - return transaction - - if payment_response.result not in (eopayment.PAID, eopayment.ACCEPTED): - return transaction - - transaction.items.update(payment_date=transaction.end_date) - - for item in transaction.items.all(): - try: - item.notify_payment() - except: - # ignore errors, it will be retried later on if it fails - logger.exception('error in sync notification for basket item %s', item.id) - - if transaction.remote_items: - transaction.first_notify_remote_items_of_payments() - - return transaction + return payment_backend.handle_backend_response(payment_response) class CallbackView(PaymentView): @@ -783,8 +677,6 @@ class ReturnView(PaymentView): ) def handle_return(self, request, backend_response, **kwargs): - payment_extra_info = {'redirect': True} - transaction = None transaction_id = kwargs.get('transaction_signature') if transaction_id: @@ -792,31 +684,23 @@ class ReturnView(PaymentView): transaction_id = signing_loads(transaction_id) except signing.BadSignature: transaction_id = None - - if transaction_id: - # retrieve info about previously known state - try: - current_transaction = Transaction.objects.get(pk=transaction_id) - except Transaction.DoesNotExist: - pass else: - payment_extra_info['order_id_hint'] = current_transaction.order_id - payment_extra_info['order_status_hint'] = current_transaction.status + transaction = Transaction.objects.filter(id=transaction_id).first() try: transaction = self.handle_response( - request, backend_response, payment_extra_info=payment_extra_info, **kwargs + request, backend_response, callback=False, transaction=transaction, **kwargs ) - except UnsignedPaymentException as e: + except UnsignedPaymentException: # some payment backends do not sign return URLs, don't mark this as # an error, they will provide a notification to the callback # endpoint. if transaction_id: return HttpResponseRedirect(get_payment_status_view(transaction_id)) return HttpResponseRedirect(get_basket_url()) - except PaymentException as e: + except PaymentException: messages.error( - request, _('We are sorry but the payment service ' 'failed to provide a correct answer.') + request, _('We are sorry but the payment service failed to provide a correct answer.') ) if transaction_id: return HttpResponseRedirect(get_payment_status_view(transaction_id))