Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: more logging in tasks in prep for 100% catalog. #254

Merged
merged 2 commits into from
Jul 16, 2024
Merged

fix: more logging in tasks in prep for 100% catalog. #254

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
4584927
fix: more logging in tasks in prep for 100% catalog.
grmartin Jul 15, 2024
c697565
chore: fixing tests, universalizing format strings
grmartin Jul 16, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
59 changes: 40 additions & 19 deletions commerce_coordinator/apps/commercetools/sub_messages/tasks.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -50,27 +50,31 @@ def fulfill_order_placed_message_signal_task(

tag = "fulfill_order_placed_message_signal_task"

logger.info(f'[CT-{tag}] Processing order {order_id}, '
f'line item {line_item_state_id}, source system {source_system}, message id: {message_id}')

client = CommercetoolsAPIClient()

try:
order = client.get_order_by_id(order_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors}')
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors},'
f'message id: {message_id}')
return False

try:
customer = client.get_customer_by_id(order.customer_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Customer not found: {order.customer_id} for order {order_id} with '
f'CT error {err}, {err.errors}')
f'CT error {err}, {err.errors}, message id: {message_id}')
return False

if not (customer and order and is_edx_lms_order(order)):
logger.debug(f'[CT-{tag}] order %s is not an edX order', order_id)
logger.debug(f'[CT-{tag}] order {order_id} is not an edX order, message id: {message_id}')

return True

logger.debug(f'[CT-{tag}] processing edX order %s', order_id)
logger.debug(f'[CT-{tag}] processing edX order {order_id}, message id: {message_id}')

lms_user_id = get_edx_lms_user_id(customer)

Expand All @@ -88,7 +92,8 @@ def fulfill_order_placed_message_signal_task(
canvas_entry_properties.update(extract_ct_order_information_for_braze_canvas(customer, order))

for item in get_edx_items(order):
logger.debug(f'[CT-{tag}] processing edX order %s, line item %s', order_id, item.variant.sku)
logger.debug(f'[CT-{tag}] processing edX order {order_id}, line item {item.variant.sku}, '
f'message id: {message_id}')
updated_order = client.update_line_item_transition_state_on_fulfillment(
order.id,
order.version,
Expand Down Expand Up @@ -132,6 +137,9 @@ def fulfill_order_placed_message_signal_task(
send_order_confirmation_email(lms_user_id, customer.email, canvas_entry_properties)
TieredCache.set_all_tiers(cache_key, value="SENT", django_cache_timeout=EMAIL_NOTIFICATION_CACHE_TTL_SECS)

logger.info(f'[CT-{tag}] Finished order {order_id}, '
f'line item {line_item_state_id}, source system {source_system}, message id: {message_id}')

return True


Expand All @@ -145,38 +153,43 @@ def fulfill_order_sanctioned_message_signal_task(

tag = "fulfill_order_sanctioned_message_signal_task"

logger.info(f'[CT-{tag}] Processing sanctions for {order_id}, message id: {message_id}')

client = CommercetoolsAPIClient()
try:
order = client.get_order_by_id(order_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors}')
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors}, '
f'message id: {message_id}')
return False

order_workflow_state = get_edx_order_workflow_state_key(order)
if not order_workflow_state:
logger.info(f'[CT-{tag}] order {order_id} has no workflow/transition state')
logger.info(f'[CT-{tag}] order {order_id} has no workflow/transition state, message id: {message_id}')

try:
customer = client.get_customer_by_id(order.customer_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Customer not found: {order.customer_id} for order {order_id} with '
f'CT error {err}, {err.errors}')
f'CT error {err}, {err.errors}, message id: {message_id}')
return False

if not (customer and order and is_edx_lms_order(order)):
logger.info(f'[CT-{tag}] order {order_id} is not an edX order')
logger.info(f'[CT-{tag}] order {order_id} is not an edX order, message id: {message_id}')
return True

if get_edx_is_sanctioned(order):
lms_user_name = get_edx_lms_user_name(customer)
logger.info(f'[CT-{tag}] calling lms to deactivate user {lms_user_name}.')
logger.info(f'[CT-{tag}] calling lms to deactivate user {lms_user_name}, message id: {message_id}.')

LMSAPIClient().deactivate_user(lms_user_name, message_id)

logger.info(f'[CT-{tag}] Finished sanctions for {order_id}, message id: {message_id}')
return True
else:
logger.error(
f'[CT-{tag}] order state for order {order_id} is not {TwoUKeys.SDN_SANCTIONED_ORDER_STATE}. '
f'Actual value is {order_workflow_state}'
f'Actual value is {order_workflow_state}, message id: {message_id}'
)
return False

Expand Down Expand Up @@ -230,30 +243,34 @@ def _prepare_segment_event_properties(in_order, return_line_item_return_id):

tag = "fulfill_order_returned_signal_task"

logger.info(f'[CT-{tag}] Processing return for order: {order_id}, line item: {return_line_item_return_id}, '
f'message id: {message_id}')

client = CommercetoolsAPIClient()

try:
order = client.get_order_by_id(order_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors}')
logger.error(f'[CT-{tag}] Order not found: {order_id} with CT error {err}, {err.errors}'
f', message id: {message_id}')
return False

try:
customer = client.get_customer_by_id(order.customer_id)
except CommercetoolsError as err: # pragma no cover
logger.error(f'[CT-{tag}] Customer not found: {order.customer_id} for order {order_id} with '
f'CT error {err}, {err.errors}')
f'CT error {err}, {err.errors}, message id: {message_id}')
return False

if not (customer and order and is_edx_lms_order(order)): # pragma no cover
logger.debug(f'[CT-{tag}] order {order_id} is not an edX order')
logger.debug(f'[CT-{tag}] order {order_id} is not an edX order, message id: {message_id}')
return True

payment_intent_id = get_edx_payment_intent_id(order)
lms_user_name = get_edx_lms_user_name(customer)
lms_user_id = get_edx_lms_user_id(customer)

logger.debug(f'[CT-{tag}] calling stripe to refund payment intent {payment_intent_id}')
logger.info(f'[CT-{tag}] calling stripe to refund payment intent {payment_intent_id}, message id: {message_id}')

# Return payment if payment intent id is set
if payment_intent_id is not None:
Expand All @@ -263,18 +280,19 @@ def _prepare_segment_event_properties(in_order, return_line_item_return_id):

if 'refund_response' in result and result['refund_response']:
if result['refund_response'] == 'charge_already_refunded':
logger.debug(f'[CT-{tag}] payment intent {payment_intent_id} already has refund transaction, '
f'sending Zendesk email')
logger.info(f'[CT-{tag}] payment intent {payment_intent_id} already has refund transaction, '
grmartin marked this conversation as resolved.
Show resolved Hide resolved
f'sending Zendesk email, message id: {message_id}')
send_refund_notification(customer, order_id)
else:
logger.debug(f'[CT-{tag}] payment intent {payment_intent_id} refunded. Message_id: {message_id}')
logger.debug(f'[CT-{tag}] payment intent {payment_intent_id} refunded. message id: {message_id}')
segment_event_properties = _prepare_segment_event_properties(order, return_line_item_return_id)

for line_item in get_edx_items(order):
course_run = get_edx_product_course_run_key(line_item)
# TODO: Remove LMS Enrollment
logger.debug(
f'[CT-{tag}] calling lms to unenroll user {lms_user_name} in {course_run}'
f', message id: {message_id}'
)

product = {
Expand All @@ -301,7 +319,10 @@ def _prepare_segment_event_properties(in_order, return_line_item_return_id):
properties=segment_event_properties
)
else: # pragma no cover
logger.debug(f'[CT-{tag}] payment intent {payment_intent_id} not refunded. Message_id: {message_id}')
logger.info(f'[CT-{tag}] payment intent {payment_intent_id} not refunded. message id: {message_id}')
return send_refund_notification(customer, order_id)

logger.info(f'[CT-{tag}] Finished return for order: {order_id}, line item: {return_line_item_return_id}, '
f'message id: {message_id}')

return True
4 changes: 0 additions & 4 deletions commerce_coordinator/apps/commercetools/tests/sub_messages/test_tasks.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -319,12 +319,10 @@ def test_correct_arguments_passed_valid_stripe_refund(

@patch('commerce_coordinator.apps.commercetools.sub_messages.tasks.send_refund_notification')
@patch('commerce_coordinator.apps.commercetools.sub_messages.tasks.get_edx_payment_intent_id')
@patch('commerce_coordinator.apps.commercetools.sub_messages.tasks.logger.debug')
@patch('commerce_coordinator.apps.commercetools.sub_messages.tasks.OrderRefundRequested.run_filter')
def test_refund_already_charged(
self,
_return_filter_mock: MagicMock,
_mock_logger,
_mock_payment_intent: MagicMock,
_mock_zendesk: MagicMock
):
Expand All @@ -338,6 +336,4 @@ def test_refund_already_charged(
_mock_payment_intent.return_value = 'mock_payment_intent_id'

self.get_uut()(*self.unpack_for_uut(self.mock.example_payload))
_mock_logger.assert_called_with('[CT-fulfill_order_returned_signal_task] payment intent '
'mock_payment_intent_id already has refund transaction, sending Zendesk email')
_mock_zendesk.assert_called_once()
6 changes: 3 additions & 3 deletions commerce_coordinator/apps/commercetools/views.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ def post(self, request):
**request.data
}

logger.debug(f'[CT-{tag}] Message received from commercetools with details: %s', input_data)
logger.debug(f'[CT-{tag}] Message received from commercetools with details: {input_data}')

message_details = OrderLineItemMessageInputSerializer(data=input_data)
message_details.is_valid(raise_exception=True)
Expand Down Expand Up @@ -85,7 +85,7 @@ def post(self, request):
**request.data
}

logger.debug(f'[CT-{tag}] Message received from commercetools with details: %s', input_data)
logger.debug(f'[CT-{tag}] Message received from commercetools with details: {input_data}')

message_details = OrderSanctionedViewMessageInputSerializer(data=input_data)
message_details.is_valid(raise_exception=True)
Expand Down Expand Up @@ -127,7 +127,7 @@ def post(self, request):
**request.data
}

logger.debug(f'[CT-{tag}] Message received from commercetools with details: %s', input_data)
logger.debug(f'[CT-{tag}] Message received from commercetools with details: {input_data}')

message_details = OrderReturnedViewMessageInputSerializer(data=input_data)
message_details.is_valid(raise_exception=True)
Expand Down
Loading