Merge branch 'main' into huniafatima/python-and-django-update

commerce_coordinator/apps/commercetools/clients.py

@@ -5,6 +5,7 @@
 import datetime
 import decimal
 import logging
+from types import SimpleNamespace
 from typing import Generic, List, Optional, Tuple, TypeVar, Union
 
 import requests
@@ -235,7 +236,7 @@ def get_order_by_number(self, order_number: str, expand: ExpandList = DEFAULT_OR
         logger.info(f"[CommercetoolsAPIClient] - Attempting to find order with number {order_number}")
         return self.base_client.orders.get_by_order_number(order_number, expand=list(expand))
 
-    def get_orders(self, customer: CTCustomer, offset=0,
+    def get_orders(self, customer_id: str, offset=0,
                    limit=ORDER_HISTORY_PER_SYSTEM_REQ_LIMIT,
                    expand: ExpandList = DEFAULT_ORDER_EXPANSION,
                    order_state="Complete") -> PaginatedResult[CTOrder]:
@@ -256,68 +257,52 @@ def get_orders(self, customer: CTCustomer, offset=0,
 
         """
         logger.info(f"[CommercetoolsAPIClient] - Attempting to find all completed orders for "
-                    f"customer with ID {customer.id}")
+                    f"customer with ID {customer_id}")
         order_where_clause = f"orderState=\"{order_state}\""
 
-        start_time = datetime.datetime.now()
-        logger.info(
-            "[UserOrdersView] Get CT orders query call started at %s", start_time)
         values = self.base_client.orders.query(
             where=["customerId=:cid", order_where_clause],
-            predicate_var={'cid': customer.id},
+            predicate_var={'cid': customer_id},
             sort=["completedAt desc", "lastModifiedAt desc"],
             limit=limit,
             offset=offset,
             expand=list(expand)
         )
-        end_time = datetime.datetime.now()
-        logger.info(
-            "[UserOrdersView] Get CT orders query call finished at %s with total duration: %ss",
-            end_time, (end_time - start_time).total_seconds()
-        )
-
-        start_time = datetime.datetime.now()
-        logger.info('[UserOrdersView] Pagination of CT orders started at %s',
-                    start_time)
-        result = PaginatedResult(values.results, values.total, values.offset)
-        end_time = datetime.datetime.now()
-        logger.info(
-            '[UserOrdersView] Pagination of CT orders finished at %s with total duration: %ss',
-            end_time, (end_time - start_time).total_seconds())
 
-        return result
+        return PaginatedResult(values.results, values.total, values.offset)
 
-    def get_orders_for_customer(self, edx_lms_user_id: int, offset=0,
-                                limit=ORDER_HISTORY_PER_SYSTEM_REQ_LIMIT) -> (PaginatedResult[CTOrder], CTCustomer):
+    def get_orders_for_customer(self, edx_lms_user_id: int, offset=0, limit=ORDER_HISTORY_PER_SYSTEM_REQ_LIMIT,
+                                customer_id=None, email=None,
+                                username=None) -> (PaginatedResult[CTOrder], CTCustomer):
         """
 
         Args:
             edx_lms_user_id (object):
             offset:
             limit:
         """
-        start_time = datetime.datetime.now()
-        logger.info(
-            "[UserOrdersView] For CT orders get customer id from lms id call started at %s",
-            start_time
-        )
-        customer = self.get_customer_by_lms_user_id(edx_lms_user_id)
-        end_time = datetime.datetime.now()
-        logger.info(
-            "[UserOrdersView] For CT orders get customer id from lms id call finished at %s with total duration: %ss",
-            end_time, (end_time - start_time).total_seconds()
-        )
+        if not customer_id:
+            customer = self.get_customer_by_lms_user_id(edx_lms_user_id)
+
+            if customer is None:  # pragma: no cover
+                raise ValueError(f'Unable to locate customer with ID #{edx_lms_user_id}')
 
-        if customer is None:  # pragma: no cover
-            raise ValueError(f'Unable to locate customer with ID #{edx_lms_user_id}')
+            customer_id = customer.id
+        else:
+            if email is None or username is None:  # pragma: no cover
+                raise ValueError("If customer_id is provided, both email and username must be provided")
+
+            customer = SimpleNamespace(
+                id=customer_id,
+                email=email,
+                custom=SimpleNamespace(
+                    fields={
+                        EdXFieldNames.LMS_USER_NAME: username
+                    }
+                )
+            )
 
-        start_time = datetime.datetime.now()
-        logger.info("[UserOrdersView] Get CT orders call started at %s",
-                    start_time)
-        orders = self.get_orders(customer, offset, limit)
-        end_time = datetime.datetime.now()
-        logger.info("[UserOrdersView] Get CT orders call finished at %s with total duration: %ss",
-                    end_time, (end_time - start_time).total_seconds())
+        orders = self.get_orders(customer_id, offset, limit)
 
         return orders, customer
 
@@ -562,7 +547,7 @@ def update_line_item_transition_state_on_fulfillment(self, order_id: str, order_
                 return self.get_order_by_id(order_id)
         except CommercetoolsError as err:
             # Logs & ignores version conflict errors due to duplicate Commercetools messages
-            handle_commercetools_error(err, f"Unable to update LineItemState of order {order_id}")
+            handle_commercetools_error(err, f"Unable to update LineItemState of order {order_id}", True)
             return None
 
     def retire_customer_anonymize_fields(self, customer_id: str, customer_version: int,

commerce_coordinator/apps/commercetools/pipeline.py

@@ -2,7 +2,6 @@
 Commercetools filter pipelines
 """
 import decimal
-from datetime import datetime
 from logging import getLogger
 
 import attrs
@@ -45,48 +44,28 @@ def run_filter(self, request, params, order_data):  # pylint: disable=arguments-
             order_data: any preliminary orders (from an earlier pipeline step) we want to append to
         Returns:
         """
-        method_start_time = datetime.now()
-        log.info("[UserOrdersView] Starting CT orders pipeline step execution at %s", method_start_time)
-
         if not is_redirect_to_commercetools_enabled_for_user(request):
             return PipelineCommand.CONTINUE.value
 
         try:
             ct_api_client = CommercetoolsAPIClient()
             ct_orders = ct_api_client.get_orders_for_customer(
+                customer_id=params["customer_id"],
+                email=params["email"],
+                username=params["username"],
                 edx_lms_user_id=params["edx_lms_user_id"],
                 limit=params["page_size"],
                 offset=params["page"] * params["page_size"]
             )
 
-            start_time = datetime.now()
-            log.info(
-                "[UserOrdersView] CT orders to attrs objects processing started at %s",
-                start_time
-            )
             # noinspection PyTypeChecker
             converted_orders = [attrs.asdict(order_from_commercetools(x, ct_orders[1]))
                                 for x in ct_orders[0].results]
-            end_time = datetime.now()
-            log.info(
-                "[UserOrdersView] CT orders to attrs objects processing finished at %s with total duration: %ss",
-                end_time, (end_time - start_time).total_seconds()
-            )
 
-            start_time = datetime.now()
-            log.info("[UserOrdersView] CT orders rebuild call started at %s", start_time)
             order_data.append(
                 ct_orders[0].rebuild(converted_orders)
             )
-            end_time = datetime.now()
-            log.info("[UserOrdersView] CT orders rebuild call finished at %s with total duration: %ss",
-                     end_time, (end_time - start_time).total_seconds())
-
-            method_end_time = datetime.now()
-            log.info(
-                "[UserOrdersView] Completed CT pipeline step execution at %s with total duration: %ss",
-                method_end_time, (method_end_time - method_start_time).total_seconds()
-            )
+
             return {
                 "order_data": order_data
             }

commerce_coordinator/apps/commercetools/sub_messages/tasks.py

@@ -104,6 +104,8 @@ def fulfill_order_placed_message_signal_task(
             line_item_state_id,
             TwoUKeys.PROCESSING_FULFILMENT_STATE
         )
+        if not updated_order:
+            return True
 
         # from here we will always be transitioning from a 'Fulfillment Processing' state
         line_item_state_id = client.get_state_by_key(TwoUKeys.PROCESSING_FULFILMENT_STATE).id

commerce_coordinator/apps/commercetools/tests/_test_cases.py

@@ -41,7 +41,7 @@ def get_orders_for_customer(self):
         # noinspection PyUnusedLocal
         # pylint: disable=unused-argument # needed for kwargs
         def _get_orders_for_customer(
-            _, edx_lms_user_id: int, offset=0,
+            _, edx_lms_user_id: int, offset=0, customer_id=None, email=None, username=None,
                 limit=ORDER_HISTORY_PER_SYSTEM_REQ_LIMIT
         ) -> (PaginatedResult[CTOrder], CTCustomer):
             return (

commerce_coordinator/apps/commercetools/tests/test_clients.py

@@ -672,7 +672,7 @@ def test_update_line_item_state_exception(self, mock_state_by_id):
                 status_code=409
             )
 
-            with patch('commerce_coordinator.apps.commercetools.clients.logging.Logger.error') as log_mock:
+            with patch('commerce_coordinator.apps.commercetools.clients.logging.Logger.info') as log_mock:
                 self.client_set.client.update_line_item_transition_state_on_fulfillment(
                     "mock_order_id",
                     1,
@@ -689,7 +689,7 @@ def test_update_line_item_state_exception(self, mock_state_by_id):
                     f"Details: {mock_error_response['errors']}"
                 )
 
-                log_mock.assert_called_once_with(expected_message)
+                log_mock.assert_called_with(expected_message)
 
     @patch('commerce_coordinator.apps.commercetools.clients.CommercetoolsAPIClient.get_state_by_id')
     @patch('commerce_coordinator.apps.commercetools.clients.CommercetoolsAPIClient.get_order_by_id')

commerce_coordinator/apps/commercetools/tests/test_pipeline.py

@@ -48,6 +48,9 @@ def test_pipeline(self, is_redirect_mock):
             request,
             {
                 "edx_lms_user_id": 127,
+                "customer_id": None,
+                "email": "[email protected]",
+                "username": "test",
                 "page_size": ORDER_HISTORY_PER_SYSTEM_REQ_LIMIT,
                 "page": 0,
             },

commerce_coordinator/apps/commercetools/utils.py

@@ -35,9 +35,13 @@ def get_braze_client():
     )
 
 
-def handle_commercetools_error(err: CommercetoolsError, context: str):
+def handle_commercetools_error(err: CommercetoolsError, context: str, is_info=False):
+    """Handles commercetools errors."""
     error_message = f"[CommercetoolsError] {context} - Correlation ID: {err.correlation_id}, Details: {err.errors}"
-    logger.error(error_message)
+    if is_info:
+        logger.info(error_message)
+    else:
+        logger.error(error_message)
 
 
 def send_order_confirmation_email(

commerce_coordinator/apps/ecommerce/clients.py

@@ -2,7 +2,6 @@
 API clients for ecommerce app.
 """
 import logging
-from datetime import datetime
 
 from django.conf import settings
 from requests.exceptions import RequestException
@@ -36,17 +35,7 @@ def get_orders(self, query_params):
         """
         try:
             resource_url = urljoin_directory(self.api_base_url, '/orders')
-            start_time = datetime.now()
-            logger.info(
-                '[UserOrdersView] Legacy ecommerce get_orders API called at: %s',
-                start_time
-            )
             response = self.client.get(resource_url, params=query_params)
-            end_time = datetime.now()
-            logger.info(
-                '[UserOrdersView] Legacy ecommerce get_orders API finished at: %s with total duration: %ss',
-                end_time, (end_time - start_time).total_seconds()
-            )
             response.raise_for_status()
             self.log_request_response(logger, response)
         except RequestException as exc:

commerce_coordinator/apps/ecommerce/pipeline.py

@@ -1,7 +1,6 @@
 """
 Ecommerce filter pipelines
 """
-from datetime import datetime
 from logging import getLogger
 
 from django.conf import settings
@@ -40,9 +39,6 @@ def run_filter(self, request, params, order_data):  # pylint: disable=arguments-
             params: arguments passed through from the original order history url querystring
             order_data: any preliminary orders (from an earlier pipeline step) we want to append to
         """
-        start_time = datetime.now()
-        log.info("[UserOrdersView] Starting Ecommerce pipeline step execution at %s", start_time)
-
         new_params = params.copy()
         # Ecommerce starts pagination from 1, other systems from 0, since the invoker assumes 0, we're always 1 off.
         new_params['page'] = params['page'] + 1
@@ -53,10 +49,6 @@ def run_filter(self, request, params, order_data):  # pylint: disable=arguments-
 
             order_data.append(ecommerce_response)
 
-            end_time = datetime.now()
-            log.info(
-                "[UserOrdersView] Completed Ecommerce pipeline step execution at %s with total duration: %ss",
-                end_time, (end_time - start_time).total_seconds())
             return {
                 "order_data": order_data
             }

commerce_coordinator/apps/frontend_app_ecommerce/tests/test_views.py

@@ -44,6 +44,7 @@ class OrdersViewTests(TestCase):
     test_user_username = 'test'  # Different from ORDER_HISTORY_GET_PARAMETERS username.
     test_user_email = '[email protected]'
     test_user_password = 'secret'
+    url = reverse('frontend_app_ecommerce:order_history')
 
     def setUp(self):
         """Create test user before test starts."""
@@ -69,7 +70,7 @@ def test_view_rejects_post(self, _mock_ctorders, _mock_ecommerce_client):
         self.client.login(username=self.test_user_username, password=self.test_user_password)
 
         # Perform POST
-        response = self.client.post(reverse('frontend_app_ecommerce:order_history'), ORDER_HISTORY_GET_PARAMETERS)
+        response = self.client.post(self.url, ORDER_HISTORY_GET_PARAMETERS)
 
         # Check 405 Method Not Allowed
         self.assertEqual(response.status_code, 405)
@@ -78,7 +79,7 @@ def test_view_rejects_unauthorized(self, _mock_ctorders, _mock_ecommerce_client)
         """Check unauthorized users querying orders are redirected to login page."""
 
         # Perform GET without logging in.
-        response = self.client.get(reverse('frontend_app_ecommerce:order_history'), ORDER_HISTORY_GET_PARAMETERS)
+        response = self.client.get(self.url, ORDER_HISTORY_GET_PARAMETERS)
 
         # Check 302 Found with redirect to login page.
         self.assertEqual(response.status_code, 302)
@@ -91,7 +92,7 @@ def test_view_returns_ok(self, _mock_ctorders, _mock_ecommerce_client):
         self.client.login(username=self.test_user_username, password=self.test_user_password)
 
         # Perform GET
-        response = self.client.get(reverse('frontend_app_ecommerce:order_history'), ORDER_HISTORY_GET_PARAMETERS)
+        response = self.client.get(self.url, ORDER_HISTORY_GET_PARAMETERS)
         # Check 200 OK
         self.assertEqual(response.status_code, 200)
 
@@ -104,7 +105,7 @@ def test_view_returns_expected_ecommerce_response(self, is_redirect_mock, _mock_
         self.client.login(username=self.test_user_username, password=self.test_user_password)
 
         # Perform GET
-        response = self.client.get(reverse('frontend_app_ecommerce:order_history'), ORDER_HISTORY_GET_PARAMETERS)
+        response = self.client.get(self.url, ORDER_HISTORY_GET_PARAMETERS)
 
         # Check expected response
         self.assertEqual(response.json()['results'][1], ECOMMERCE_REQUEST_EXPECTED_RESPONSE['results'][0])
@@ -116,14 +117,33 @@ def test_view_passes_username(self, _mock_ctorders, mock_ecommerce_client):
         self.client.login(username=self.test_user_username, password=self.test_user_password)
 
         # Perform GET
-        self.client.get(reverse('frontend_app_ecommerce:order_history'), ORDER_HISTORY_GET_PARAMETERS)
+        self.client.get(self.url, ORDER_HISTORY_GET_PARAMETERS)
 
         # Get username sent to ecommerce client
         request_username = mock_ecommerce_client.call_args.args[0]['username']
 
         # Check username is passed to ecommerce client
         self.assertEqual(request_username, self.test_user_username)
 
+    @patch(
+        'commerce_coordinator.apps.commercetools.pipeline.GetCommercetoolsOrders.run_filter',
+        side_effect=Exception('Something went wrong')
+    )
+    def test_view_crashes_with_some_error(self, _mock_pipeline, _mock_ctorders, _mock_ecommerce_client):
+        """Check exception is handled gracefully if pipeline crashes."""
+
+        # Login
+        self.client.login(username=self.test_user_username, password=self.test_user_password)
+
+        # Perform GET request
+        response = self.client.get(self.url, ORDER_HISTORY_GET_PARAMETERS)
+
+        # Assert the response status is 400
+        self.assertEqual(response.status_code, status.HTTP_400_BAD_REQUEST)
+
+        # Assert the response content matches the error message
+        self.assertEqual(response.data, 'Something went wrong!')
+
 
 @ddt.ddt
 class ReceiptRedirectViewTests(APITestCase):