pengyuthon/odoo_source
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

[IMP] payment(_*): normalize logs across all acquirers

Browse Source 
The logs for payments contain the transaction reference whenever possible.
Before logs for transactions contained the reference or the id of the
transaction in an inconsitent way. No transactions are identified by
reference whenever possible.

The logs for payments for the same function on different acquirers should
have the same format. Same flow step for different acquirers had
information passed in different formats. Now at each step of a transaction
flow log messages have the same format regardless of the acquirer.

Overall the payment logs should have an uniform format. Hopefully
understanding log messages related to transactions should be easier, as
now log format is independent of the acquirer and transaction are easily
identified by reference.

Task - 2545450

closes odoo/odoo#79547

Signed-off-by: Antoine Vandevenne (anv) <anv@odoo.com>
This commit is contained in:
Horacio Tellez
2021-11-29 15:40:54 +00:00
parent e717ccd353
commit 5badb3fca8
26 changed files with 231 additions and 102 deletions
Download Patch File Download Diff File Expand all files Collapse all files
addons/payment/models/payment_transaction.py
+32 -27
View File
@@ -476,8 +476,9 @@ class PaymentTransaction(models.Model):
# Complete generic processing values with acquirer-specific values
processing_values.update(self._get_specific_processing_values(processing_values))
_logger.info(
"generic and acquirer-specific processing values for transaction with id %s:\n%s",
self.id, pprint.pformat(processing_values)
"generic and acquirer-specific processing values for transaction with reference "
"%(ref)s:\n%(values)s",
{'ref': self.reference, 'values': pprint.pformat(processing_values)},
)
# Render the html form for the redirect flow if available
@@ -488,8 +489,9 @@ class PaymentTransaction(models.Model):
if redirect_form_view: # Some acquirer don't need a redirect form
rendering_values = self._get_specific_rendering_values(processing_values)
_logger.info(
"acquirer-specific rendering values for transaction with id %s:\n%s",
self.id, pprint.pformat(rendering_values)
"acquirer-specific rendering values for transaction with reference "
"%(ref)s:\n%(values)s",
{'ref': self.reference, 'values': pprint.pformat(rendering_values)},
)
redirect_form_html = redirect_form_view._render(rendering_values, engine='ir.qweb')
processing_values.update(redirect_form_html=redirect_form_html)
@@ -735,20 +737,21 @@ class PaymentTransaction(models.Model):
txs_to_process, txs_already_processed, txs_wrong_state = _classify_by_state(self)
for tx in txs_already_processed:
_logger.info(
"tried to write tx state with same value (ref: %s, state: %s)",
tx.reference, tx.state
"tried to write on transaction with reference %s with the same value for the "
"state: %s",
tx.reference, tx.state,
)
for tx in txs_wrong_state:
logging_values = {
'reference': tx.reference,
'tx_state': tx.state,
'target_state': target_state,
'allowed_states': allowed_states,
}
_logger.warning(
"tried to write tx state with illegal value (ref: %(reference)s, previous state "
"%(tx_state)s, target state: %(target_state)s, expected previous state to be in: "
"%(allowed_states)s)", logging_values
"tried to write on transaction with reference %(ref)s with illegal value for the "
"state (previous state: %(tx_state)s, target state: %(target_state)s, expected "
"previous state to be in: %(allowed_states)s)",
{
'ref': tx.reference,
'tx_state': tx.state,
'target_state': target_state,
'allowed_states': allowed_states,
},
)
txs_to_process.write({
'state': target_state,
@@ -781,19 +784,21 @@ class PaymentTransaction(models.Model):
valid_callback_hash = self._generate_callback_hash(model_sudo.id, res_id, method)
if not consteq(ustr(valid_callback_hash), callback_hash):
_logger.warning("invalid callback signature for transaction with id %s", tx.id)
_logger.warning(
"invalid callback signature for transaction with reference %s", tx.reference
)
continue # Ignore tampered callbacks
record = self.env[model_sudo.model].browse(res_id).exists()
if not record:
logging_values = {
'model': model_sudo.model,
'record_id': res_id,
'tx_id': tx.id,
}
_logger.warning(
"invalid callback record %(model)s.%(record_id)s for transaction with id "
"%(tx_id)s", logging_values
"invalid callback record %(model)s.%(record_id)s for transaction with "
"reference %(ref)s",
{
'model': model_sudo.model,
'record_id': res_id,
'ref': tx.reference,
}
)
continue # Ignore invalidated callbacks
@@ -838,8 +843,8 @@ class PaymentTransaction(models.Model):
'landing_route': self.landing_route,
}
_logger.debug(
"post-processing values for acquirer with id %s:\n%s",
self.acquirer_id.id, pprint.pformat(post_processing_values)
"post-processing values of transaction with reference %s for acquirer with id %s:\n%s",
self.reference, self.acquirer_id.id, pprint.pformat(post_processing_values)
) # DEBUG level because this can get spammy with transactions in non-final states
return post_processing_values
@@ -879,8 +884,8 @@ class PaymentTransaction(models.Model):
self.env.cr.rollback() # Rollback and try later
except Exception as e:
_logger.exception(
"encountered an error while post-processing transaction with id %s:\n%s",
tx.id, e
"encountered an error while post-processing transaction with reference %s:\n%s",
tx.reference, e
)
self.env.cr.rollback()
addons/payment_adyen/controllers/main.py
+21 -6
View File
@@ -143,7 +143,10 @@ class AdyenController(http.Controller):
)
# Handle the payment request response
_logger.info("payment request response:\n%s", pprint.pformat(response_content))
_logger.info(
"payment request response for transaction with reference %s:\n%s",
reference, pprint.pformat(response_content)
)
request.env['payment.transaction'].sudo()._handle_feedback_data(
'adyen', dict(response_content, merchantReference=reference), # Match the transaction
)
@@ -172,7 +175,10 @@ class AdyenController(http.Controller):
)
# Handle the payment details request response
_logger.info("payment details request response:\n%s", pprint.pformat(response_content))
_logger.info(
"payment details request response for transaction with reference %s:\n%s",
reference, pprint.pformat(response_content)
)
request.env['payment.transaction'].sudo()._handle_feedback_data(
'adyen', dict(response_content, merchantReference=reference), # Match the transaction
)
@@ -206,7 +212,10 @@ class AdyenController(http.Controller):
tx_sudo.operation = 'online_redirect'
# Query and process the result of the additional actions that have been performed
_logger.info("handling redirection from Adyen with data:\n%s", pprint.pformat(data))
_logger.info(
"handling redirection from Adyen for transaction with reference %s with data:\n%s",
tx_sudo.reference, pprint.pformat(data)
)
self.adyen_payment_details(
tx_sudo.acquirer_id.id,
data['merchantReference'],
@@ -238,9 +247,11 @@ class AdyenController(http.Controller):
received_signature = notification_data.get('additionalData', {}).get('hmacSignature')
PaymentTransaction = request.env['payment.transaction']
try:
acquirer_sudo = PaymentTransaction.sudo()._get_tx_from_feedback_data(
tx_sudo = PaymentTransaction.sudo()._get_tx_from_feedback_data(
'adyen', notification_data
).acquirer_id # Find the acquirer based on the transaction
)
acquirer_sudo = tx_sudo.acquirer_id # Find the acquirer based on the transaction
if not self._verify_notification_signature(
received_signature, notification_data, acquirer_sudo.adyen_hmac_key
):
@@ -248,7 +259,11 @@ class AdyenController(http.Controller):
# Check whether the event of the notification succeeded and reshape the notification
# data for parsing
_logger.info("notification received:\n%s", pprint.pformat(notification_data))
_logger.info(
"notification received from Adyen for transaction with reference %s with "
"data:\n%s",
tx_sudo.reference, pprint.pformat(notification_data)
)
success = notification_data['success'] == 'true'
event_code = notification_data['eventCode']
if event_code == 'AUTHORISATION' and success:
addons/payment_adyen/models/payment_transaction.py
+31 -10
View File
@@ -84,7 +84,10 @@ class PaymentTransaction(models.Model):
)
# Handle the payment request response
_logger.info("payment request response:\n%s", pprint.pformat(response_content))
_logger.info(
"payment request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(response_content)
)
self._handle_feedback_data('adyen', response_content)
def _send_refund_request(self, amount_to_refund=None, create_refund_transaction=True):
@@ -127,7 +130,10 @@ class PaymentTransaction(models.Model):
payload=data,
method='POST'
)
_logger.info("refund request response:\n%s", pprint.pformat(response_content))
_logger.info(
"refund request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(response_content)
)
# Handle the refund request response
psp_reference = response_content.get('pspReference')
@@ -232,21 +238,30 @@ class PaymentTransaction(models.Model):
if self.operation == 'refund':
self.env.ref('payment.cron_post_process_payment_tx')._trigger()
elif payment_state in RESULT_CODES_MAPPING['cancel']:
_logger.warning("The transaction with reference %s was cancelled (reason: %s)",
self.reference, refusal_reason)
_logger.warning(
"the transaction with reference %s was cancelled. reason: %s",
self.reference, refusal_reason
)
self._set_canceled()
elif payment_state in RESULT_CODES_MAPPING['error']:
_logger.warning("An error occurred on transaction with reference %s (reason: %s)",
self.reference, refusal_reason)
_logger.warning(
"the transaction with reference %s underwent an error. reason: %s",
self.reference, refusal_reason
)
self._set_error(
_("An error occurred during the processing of your payment. Please try again.")
)
elif payment_state in RESULT_CODES_MAPPING['refused']:
_logger.warning("The transaction with reference %s was refused (reason: %s)",
self.reference, refusal_reason)
_logger.warning(
"the transaction with reference %s was refused. reason: %s",
self.reference, refusal_reason
)
self._set_error(_("Your payment was refused. Please try again."))
else: # Classify unsupported payment state as `error` tx state
_logger.warning("received data with invalid payment state: %s", payment_state)
_logger.warning(
"received data for transaction with reference %s with invalid payment state: %s",
self.reference, payment_state
)
self._set_error(
"Adyen: " + _("Received data with invalid payment state: %s", payment_state)
)
@@ -274,5 +289,11 @@ class PaymentTransaction(models.Model):
'tokenize': False,
})
_logger.info(
"created token with id %s for partner with id %s", token.id, self.partner_id.id
"created token with id %(token_id)s for partner with id %(partner_id)s from "
"transaction with reference %(ref)s",
{
'token_id': token.id,
'partner_id': self.partner_id.id,
'ref': self.reference,
},
)
addons/payment_alipay/controllers/main.py
+2 -2
View File
@@ -19,14 +19,14 @@ class AlipayController(http.Controller):
@http.route(_return_url, type='http', auth="public", methods=['GET'])
def alipay_return_from_redirect(self, **data):
""" Alipay return """
_logger.info("received Alipay return data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from Alipay with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('alipay', data)
return request.redirect('/payment/status')
@http.route(_notify_url, type='http', auth='public', methods=['POST'], csrf=False)
def alipay_notify(self, **post):
""" Alipay Notify """
_logger.info("received Alipay notification data:\n%s", pprint.pformat(post))
_logger.info("notification received from Alipay with data:\n%s", pprint.pformat(post))
self._alipay_validate_notification(**post)
request.env['payment.transaction'].sudo()._handle_feedback_data('alipay', post)
return 'success' # Return 'success' to stop receiving notifications for this tx
addons/payment_alipay/models/payment_transaction.py
+16 -11
View File
@@ -126,15 +126,15 @@ class PaymentTransaction(models.Model):
if float_compare(float(data.get('total_fee', '0.0')), (self.amount + self.fees), 2) != 0:
# mc_gross is amount + fees
logging_values = {
'amount': data.get('total_fee', '0.0'),
'total': self.amount,
'fees': self.fees,
'reference': self.reference,
}
_logger.error(
"the paid amount (%(amount)s) does not match the total + fees (%(total)s + "
"%(fees)s) for the transaction with reference %(reference)s", logging_values
"%(fees)s) for transaction with reference %(ref)s",
{
'amount': data.get('total_fee', '0.0'),
'total': self.amount,
'fees': self.fees,
'ref': self.reference,
}
)
raise ValidationError("Alipay: " + _("The amount does not match the total + fees."))
if self.acquirer_id.alipay_payment_method == 'standard_checkout':
@@ -147,8 +147,13 @@ class PaymentTransaction(models.Model):
)
elif data.get('seller_email') != self.acquirer_id.alipay_seller_email:
_logger.error(
"the seller email (%s) does not match the configured Alipay account (%s).",
data.get('seller_email'), self.acquirer_id.alipay_seller_email
"the seller email (%(email)s) does not match the configured Alipay account "
"(%(acc_email)s) for transaction with reference %(ref)s",
{
'email': data.get('seller_email'),
'acc_email:': self.acquirer_id.alipay_seller_email,
'ref': self.reference,
},
)
raise ValidationError(
"Alipay: " + _("The seller email does not match the configured Alipay account.")
@@ -162,7 +167,7 @@ class PaymentTransaction(models.Model):
self._set_canceled()
else:
_logger.info(
"received invalid transaction status for transaction with reference %s: %s",
self.reference, status
"received data with invalid payment status (%s) for transaction with reference %s",
status, self.reference,
)
self._set_error("Alipay: " + _("received invalid transaction status: %s", status))
addons/payment_authorize/controllers/main.py
+4 -1
View File
@@ -52,7 +52,10 @@ class AuthorizeController(http.Controller):
response_content = tx_sudo._authorize_create_transaction_request(opaque_data)
# Handle the payment request response
_logger.info("make payment response:\n%s", pprint.pformat(response_content))
_logger.info(
"payment request response for transaction with reference %s:\n%s",
reference, pprint.pformat(response_content)
)
# As the API has no redirection flow, we always know the reference of the transaction.
# Still, we prefer to simulate the matching of the transaction by crafting dummy feedback
# data in order to go through the centralized `_handle_feedback_data` method.
addons/payment_authorize/models/authorize_request.py
+6 -2
View File
@@ -109,8 +109,12 @@ class AuthorizeAPI:
if not response.get('customerProfileId'):
_logger.warning(
'Unable to create customer payment profile, data missing from transaction. Transaction_id: %s - Partner_id: %s',
transaction_id, partner,
"unable to create customer payment profile, data missing from transaction with "
"id %(tx_id)s, partner id: %(partner_id)s",
{
'tx_id': transaction_id,
'partner_id': partner,
},
)
return False
addons/payment_authorize/models/payment_transaction.py
+38 -9
View File
@@ -68,10 +68,16 @@ class PaymentTransaction(models.Model):
authorize_API = AuthorizeAPI(self.acquirer_id)
if self.acquirer_id.capture_manually:
res_content = authorize_API.authorize(self, token=self.token_id)
_logger.info("authorize request response:\n%s", pprint.pformat(res_content))
_logger.info(
"authorize request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(res_content)
)
else:
res_content = authorize_API.auth_and_capture(self, token=self.token_id)
_logger.info("auth_and_capture request response:\n%s", pprint.pformat(res_content))
_logger.info(
"auth_and_capture request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(res_content)
)
# As the API has no redirection flow, we always know the reference of the transaction.
# Still, we prefer to simulate the matching of the transaction by crafting dummy feedback
@@ -102,7 +108,10 @@ class PaymentTransaction(models.Model):
authorize_API = AuthorizeAPI(self.acquirer_id)
rounded_amount = round(self.amount, self.currency_id.decimal_places)
res_content = authorize_API.refund(self.acquirer_reference, rounded_amount)
_logger.info("refund request response:\n%s", pprint.pformat(res_content))
_logger.info(
"refund request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(res_content)
)
# As the API has no redirection flow, we always know the reference of the transaction.
# Still, we prefer to simulate the matching of the transaction by crafting dummy feedback
# data in order to go through the centralized `_handle_feedback_data` method.
@@ -125,7 +134,10 @@ class PaymentTransaction(models.Model):
authorize_API = AuthorizeAPI(self.acquirer_id)
rounded_amount = round(self.amount, self.currency_id.decimal_places)
res_content = authorize_API.capture(self.acquirer_reference, rounded_amount)
_logger.info("capture request response:\n%s", pprint.pformat(res_content))
_logger.info(
"capture request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(res_content)
)
# As the API has no redirection flow, we always know the reference of the transaction.
# Still, we prefer to simulate the matching of the transaction by crafting dummy feedback
# data in order to go through the centralized `_handle_feedback_data` method.
@@ -145,7 +157,10 @@ class PaymentTransaction(models.Model):
authorize_API = AuthorizeAPI(self.acquirer_id)
res_content = authorize_API.void(self.acquirer_reference)
_logger.info("void request response:\n%s", pprint.pformat(res_content))
_logger.info(
"void request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(res_content)
)
# As the API has no redirection flow, we always know the reference of the transaction.
# Still, we prefer to simulate the matching of the transaction by crafting dummy feedback
# data in order to go through the centralized `_handle_feedback_data` method.
@@ -214,8 +229,13 @@ class PaymentTransaction(models.Model):
else: # Error / Unknown code
error_code = response_content.get('x_response_reason_text')
_logger.info(
"received data with invalid status code %s and error code %s",
status_code, error_code
"received data with invalid status (%(status)s) and error code (%(err)s) for "
"transaction with reference %(ref)s",
{
'status': status_code,
'err': error_code,
'ref': self.reference,
},
)
self._set_error(
"Authorize.Net: " + _(
@@ -237,7 +257,10 @@ class PaymentTransaction(models.Model):
cust_profile = authorize_API.create_customer_profile(
self.partner_id, self.acquirer_reference
)
_logger.info("create_customer_profile request response:\n%s", pprint.pformat(cust_profile))
_logger.info(
"create_customer_profile request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(cust_profile)
)
if cust_profile:
token = self.env['payment.token'].create({
'acquirer_id': self.acquirer_id.id,
@@ -253,5 +276,11 @@ class PaymentTransaction(models.Model):
'tokenize': False,
})
_logger.info(
"created token with id %s for partner with id %s", token.id, self.partner_id.id
"created token with id %(token_id)s for partner with id %(partner_id)s from "
"transaction with reference %(ref)s",
{
'token_id': token.id,
'partner_id': self.partner_id.id,
'ref': self.reference,
},
)
addons/payment_buckaroo/controllers/main.py
+1 -1
View File
@@ -18,6 +18,6 @@ class BuckarooController(http.Controller):
:param dict data: The feedback data
"""
_logger.info("received notification data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from Buckaroo with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('buckaroo', data)
return request.redirect('/payment/status')
addons/payment_buckaroo/models/payment_transaction.py
+4 -1
View File
@@ -140,5 +140,8 @@ class PaymentTransaction(models.Model):
elif status_code in STATUS_CODES_MAPPING['error']:
self._set_error(_("An error occurred during processing of your payment (code %s). Please try again.", status_code))
else:
_logger.warning("Buckaroo: received unknown status code: %s", status_code)
_logger.warning(
"received data with invalid payment status (%s) for transaction with reference %s",
status_code, self.reference
)
self._set_error("Buckaroo: " + _("Unknown status code: %s", status_code))
addons/payment_mollie/controllers/main.py
+3 -3
View File
@@ -33,7 +33,7 @@ class MollieController(http.Controller):
:param dict data: The feedback data (only `id`) and the transaction reference (`ref`)
embedded in the return URL
"""
_logger.info("Received Mollie return data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from Mollie with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('mollie', data)
return request.redirect('/payment/status')
@@ -46,9 +46,9 @@ class MollieController(http.Controller):
:return: An empty string to acknowledge the notification
:rtype: str
"""
_logger.info("Received Mollie notify data:\n%s", pprint.pformat(data))
_logger.info("notification received from Mollie with data:\n%s", pprint.pformat(data))
try:
request.env['payment.transaction'].sudo()._handle_feedback_data('mollie', data)
except ValidationError: # Acknowledge the notification to avoid getting spammed
_logger.exception("unable to handle the notification data; skipping to acknowledge")
_logger.exception("unable to handle the data; skipping to acknowledge the notification")
return '' # Acknowledge the notification with an HTTP 200 response
addons/payment_mollie/models/payment_acquirer.py
+1 -1
View File
@@ -75,6 +75,6 @@ class PaymentAcquirer(models.Model):
response = requests.request(method, url, json=data, headers=headers, timeout=60)
response.raise_for_status()
except requests.exceptions.RequestException:
_logger.exception("Unable to communicate with Mollie: %s", url)
_logger.exception("unable to communicate with Mollie: %s", url)
raise ValidationError("Mollie: " + _("Could not establish the connection to the API."))
return response.json()
addons/payment_mollie/models/payment_transaction.py
+4 -1
View File
@@ -112,7 +112,10 @@ class PaymentTransaction(models.Model):
elif payment_status in ['expired', 'canceled', 'failed']:
self._set_canceled("Mollie: " + _("Canceled payment with status: %s", payment_status))
else:
_logger.info("Received data with invalid payment status: %s", payment_status)
_logger.info(
"received data with invalid payment status (%s) for transaction with reference %s",
payment_status, self.reference
)
self._set_error(
"Mollie: " + _("Received data with invalid payment status: %s", payment_status)
)
addons/payment_ogone/controllers/main.py
+1 -1
View File
@@ -42,7 +42,7 @@ class OgoneController(http.Controller):
self._verify_signature(feedback_data, data)
# Handle the feedback data
_logger.info("entering _handle_feedback_data with data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from Ogone with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('ogone', data)
return request.redirect('/payment/status')
addons/payment_ogone/models/payment_transaction.py
+19 -7
View File
@@ -135,8 +135,8 @@ class PaymentTransaction(models.Model):
data['SHASIGN'] = self.acquirer_id._ogone_generate_signature(data, incoming=False)
_logger.info(
"making payment request:\n%s",
pprint.pformat({k: v for k, v in data.items() if k != 'PSWD'})
"payment request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat({k: v for k, v in data.items() if k != 'PSWD'})
) # Log the payment request data without the password
response_content = self.acquirer_id._ogone_make_request(data)
try:
@@ -146,11 +146,14 @@ class PaymentTransaction(models.Model):
# Handle the feedback data
_logger.info(
"received payment request response as an etree:\n%s",
etree.tostring(tree, pretty_print=True, encoding='utf-8')
"payment request response (as an etree) for transaction with reference %s:\n%s",
self.reference, etree.tostring(tree, pretty_print=True, encoding='utf-8')
)
feedback_data = {'ORDERID': tree.get('orderID'), 'tree': tree}
_logger.info("entering _handle_feedback_data with data:\n%s", pprint.pformat(feedback_data))
_logger.info(
"handling feedback data from Ogone for transaction with reference %s with data:\n%s",
self.reference, pprint.pformat(feedback_data)
)
self._handle_feedback_data('ogone', feedback_data)
@api.model
@@ -202,7 +205,10 @@ class PaymentTransaction(models.Model):
elif payment_status in const.PAYMENT_STATUS_MAPPING['cancel']:
self._set_canceled()
else: # Classify unknown payment statuses as `error` tx state
_logger.info("received data with invalid payment status: %s", payment_status)
_logger.info(
"received data with invalid payment status (%s) for transaction with reference %s",
payment_status, self.reference
)
self._set_error(
"Ogone: " + _("Received data with invalid payment status: %s", payment_status)
)
@@ -226,5 +232,11 @@ class PaymentTransaction(models.Model):
'tokenize': False,
})
_logger.info(
"created token with id %s for partner with id %s", token.id, self.partner_id.id
"created token with id %(token_id)s for partner with id %(partner_id)s from "
"transaction with reference %(ref)s",
{
'token_id': token.id,
'partner_id': self.partner_id.id,
'ref': self.reference,
},
)
addons/payment_paypal/controllers/main.py
+3 -3
View File
@@ -23,7 +23,7 @@ class PaypalController(http.Controller):
The "PDT notification" is actually POST data sent along the user redirection.
The route also allows the GET method in case the user clicks on "go back to merchant site".
"""
_logger.info("beginning DPN with post data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from Ogone with data:\n%s", pprint.pformat(data))
try:
self._validate_data_authenticity(**data)
except ValidationError:
@@ -38,12 +38,12 @@ class PaypalController(http.Controller):
@http.route(_notify_url, type='http', auth='public', methods=['GET', 'POST'], csrf=False)
def paypal_ipn(self, **data):
""" Route used by the IPN. """
_logger.info("beginning IPN with post data:\n%s", pprint.pformat(data))
_logger.info("notification received from Ogone with data:\n%s", pprint.pformat(data))
try:
self._validate_data_authenticity(**data)
request.env['payment.transaction'].sudo()._handle_feedback_data('paypal', data)
except ValidationError: # Acknowledge the notification to avoid getting spammed
_logger.exception("unable to handle the IPN data; skipping to acknowledge the notif")
_logger.exception("unable to handle the data; skipping to acknowledge the notification")
return ''
def _validate_data_authenticity(self, **data):
addons/payment_paypal/models/payment_transaction.py
+4 -1
View File
@@ -120,7 +120,10 @@ class PaymentTransaction(models.Model):
elif payment_status in PAYMENT_STATUS_MAPPING['cancel']:
self._set_canceled()
else:
_logger.info("received data with invalid payment status: %s", payment_status)
_logger.info(
"received data with invalid payment status (%s) for transaction with reference %s",
payment_status, self.reference
)
self._set_error(
"PayPal: " + _("Received data with invalid payment status: %s", payment_status)
)
addons/payment_payulatam/controllers/main.py
+1 -1
View File
@@ -14,6 +14,6 @@ class PayuLatamController(http.Controller):
@http.route(_return_url, type='http', auth='public', methods=['GET'])
def payulatam_return(self, **data):
_logger.info("entering _handle_feedback_data with data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from PayU Latam with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('payulatam', data)
return request.redirect('/payment/status')
addons/payment_payulatam/models/payment_transaction.py
+1 -1
View File
@@ -151,7 +151,7 @@ class PaymentTransaction(models.Model):
self._set_canceled(state_message=state_message)
else:
_logger.warning(
"received unrecognized payment state %s for transaction with reference %s",
"received data with invalid payment status (%s) for transaction with reference %s",
status, self.reference
)
self._set_error("PayU Latam: " + _("Invalid payment status."))
addons/payment_payumoney/controllers/main.py
+1 -1
View File
@@ -29,6 +29,6 @@ class PayUMoneyController(http.Controller):
:param dict data: The feedback data to process
"""
_logger.info("entering handle_feedback_data with data:\n%s", pprint.pformat(data))
_logger.info("handling redirection from PayU money with data:\n%s", pprint.pformat(data))
request.env['payment.transaction'].sudo()._handle_feedback_data('payumoney', data)
return request.redirect('/payment/status')
addons/payment_sips/controllers/main.py
+12 -5
View File
@@ -31,7 +31,7 @@ class SipsController(http.Controller):
:param dict post: The feedback data to process
"""
_logger.info("beginning Sips DPN _handle_feedback_data with data %s", pprint.pformat(post))
_logger.info("handling redirection from SIPS with data:\n%s", pprint.pformat(post))
try:
if self._sips_validate_data(post):
request.env['payment.transaction'].sudo()._handle_feedback_data('sips', post)
@@ -42,12 +42,12 @@ class SipsController(http.Controller):
@http.route(_notify_url, type='http', auth='public', methods=['POST'], csrf=False)
def sips_ipn(self, **post):
""" Sips IPN. """
_logger.info("beginning Sips IPN _handle_feedback_data with data %s", pprint.pformat(post))
_logger.info("notification received from SIPS with data:\n%s", pprint.pformat(post))
if not post:
# SIPS sometimes sends empty notifications, the reason why is unclear but they tend to
# pollute logs and do not provide any meaningful information; log as a warning instead
# of a traceback.
_logger.warning("received empty notification; skip.")
_logger.warning("unable to handle the data; skipping to acknowledge the notification")
else:
try:
if self._sips_validate_data(post):
@@ -61,8 +61,15 @@ class SipsController(http.Controller):
acquirer_sudo = tx_sudo.acquirer_id
security = acquirer_sudo._sips_generate_shasign(post['Data'])
if security == post['Seal']:
_logger.debug('validated data')
_logger.debug(
"authenticity of notification data verified for transaction with reference %s",
tx_sudo.reference
)
return True
else:
_logger.warning('data are tampered')
_logger.warning(
"unable to verify the authenticity of notification data for transaction with "
"reference %s",
tx_sudo.reference,
)
return False
addons/payment_sips/models/payment_transaction.py
+7 -1
View File
@@ -157,7 +157,13 @@ class PaymentTransaction(models.Model):
status = "error"
self._set_error(_("Unrecognized response received from the payment provider."))
_logger.info(
"ref: %s, got response [%s], set as '%s'.", self.reference, response_code, status
"received data with response %(response)s for transaction with reference %(ref)s, set "
"status as '%(status)s'",
{
'response': response_code,
'ref': self.reference,
'status': status,
},
)
def _sips_data_to_object(self, data):
addons/payment_stripe/controllers/main.py
+1 -1
View File
@@ -115,7 +115,7 @@ class StripeController(http.Controller):
# Handle the feedback data crafted with Stripe API objects as a regular feedback
request.env['payment.transaction'].sudo()._handle_feedback_data('stripe', data)
except ValidationError: # Acknowledge the notification to avoid getting spammed
_logger.exception("unable to handle the event data; skipping to acknowledge")
_logger.exception("unable to handle the data; skipping to acknowledge the notification")
return ''
@staticmethod
addons/payment_stripe/models/payment_transaction.py
+15 -3
View File
@@ -168,7 +168,10 @@ class PaymentTransaction(models.Model):
payment_intent = self._stripe_create_payment_intent()
feedback_data = {'reference': self.reference}
StripeController._include_payment_intent_in_feedback_data(payment_intent, feedback_data)
_logger.info("entering _handle_feedback_data with data:\n%s", pprint.pformat(feedback_data))
_logger.info(
"payment request response for transaction with reference %s:\n%s",
self.reference, pprint.pformat(feedback_data)
)
self._handle_feedback_data('stripe', feedback_data)
def _stripe_create_payment_intent(self):
@@ -273,7 +276,10 @@ class PaymentTransaction(models.Model):
elif intent_status in INTENT_STATUS_MAPPING['cancel']:
self._set_canceled()
else: # Classify unknown intent statuses as `error` tx state
_logger.warning("received data with invalid intent status: %s", intent_status)
_logger.warning(
"received invalid payment status (%s) for transaction with reference %s",
intent_status, self.reference
)
self._set_error(
"Stripe: " + _("Received data with invalid intent status: %s", intent_status)
)
@@ -315,5 +321,11 @@ class PaymentTransaction(models.Model):
'tokenize': False,
})
_logger.info(
"created token with id %s for partner with id %s", token.id, self.partner_id.id
"created token with id %(token_id)s for partner with id %(partner_id)s from "
"transaction with reference %(ref)s",
{
'token_id': token.id,
'partner_id': self.partner_id.id,
'ref': self.reference,
},
)
addons/payment_transfer/controllers/main.py
+1 -1
View File
@@ -14,6 +14,6 @@ class TransferController(http.Controller):
@http.route(_accept_url, type='http', auth='public', methods=['POST'], csrf=False)
def transfer_form_feedback(self, **post):
_logger.info("beginning _handle_feedback_data with post data %s", pprint.pformat(post))
_logger.info("handling redirection from Transfer with data:\n%s", pprint.pformat(post))
request.env['payment.transaction'].sudo()._handle_feedback_data('transfer', post)
return request.redirect('/payment/status')
addons/payment_transfer/models/payment_transaction.py
+2 -1
View File
@@ -66,7 +66,8 @@ class PaymentTransaction(models.Model):
return
_logger.info(
"validated transfer payment for tx with reference %s: set as pending", self.reference
"validated transfer payment for transaction with reference %s: set as pending",
self.reference
)
self._set_pending()