Merge pull request #119 from cloudblue/task-manager-debug

Improve tasks logging. Send pricelist to media

Dockerfile

@@ -1,4 +1,4 @@
-FROM cloudblueconnect/connect-extension-runner:29.0
+FROM cloudblueconnect/connect-extension-runner:29.2
 
 COPY pyproject.toml /install_temp/.
 COPY poetry.* /install_temp/.

connect_ext_ppr/constants.py

@@ -527,8 +527,10 @@
     ],
 }
 PPR_FILE_NAME = "PPR_{product_id}_v{version}_{timestamp}.xlsx"
-PPR_FILE_NAME_DELEGATION_L2 = "{dr_id}-L2Delegation-{ppr_id}-{timestamp}.xlsx"
-PPR_FILE_NAME_UPDATE_MARKETPLACES = "{dr_id}-MkplUpdate-{ppr_id}-{timestamp}.xlsx"
+PPR_FILE_NAME_DELEGATION_L2 = "{dr_id}_L2Delegation_{ppr_id}_{timestamp}.xlsx"
+PPR_FILE_NAME_UPDATE_MARKETPLACES = "{dr_id}_MkplUpdate_{ppr_id}_{timestamp}.xlsx"
+PRICE_APPLY_FILE_NAME = "{dr_id}_PriceApply_{mp_id}_{price_id}.xlsx"
+
 DESCRIPTION_TEMPLATE = """
 **Description**
 {description}

connect_ext_ppr/service.py

@@ -304,7 +304,7 @@ def create_ppr(ppr, user_id, deployment, db, client, logger):
         return new_ppr, file_instance, active_configuration
 
     except DBAPIError as ex:
-        logger.error(ex)
+        logger.exception(ex)
         db.rollback()
         raise ExtensionHttpError.EXT_003()
 
@@ -390,7 +390,7 @@ def add_new_deployment_request(db, dr_data, deployment, account_id, logger):
         db.commit()
         return deployment_request
     except DBAPIError as ex:
-        logger.error(ex)
+        logger.exception(ex)
         db.rollback()
         raise ExtensionHttpError.EXT_003()
 

connect_ext_ppr/services/pricing.py

@@ -8,7 +8,8 @@
 
 from connect_ext_ppr.errors import PriceUpdateError
 from connect_ext_ppr.client.exception import CBCClientError
-from connect_ext_ppr.utils import execute_with_retry
+from connect_ext_ppr.utils import create_ppr_to_media, execute_with_retry
+from connect_ext_ppr.constants import PRICE_APPLY_FILE_NAME
 
 
 PRICELIST_COLUMNS = {
@@ -46,26 +47,52 @@ def apply_pricelist_to_marketplace(
     cbc_service,
     connect_client,
     marketplace,
+    logger,
 ):
     """
     @param DeploymentRequest deployment_request:
     @param CBCService cbc_service:
     @param Client connect_client:
     @param MarketplaceConfiguration marketplace:
+    @param Logger logger:
 
     @returns None
     @raises ClientError, CBCClientError
     """
+    price_filename = PRICE_APPLY_FILE_NAME.format(
+        dr_id=deployment_request.id,
+        mp_id=marketplace.marketplace,
+        price_id=marketplace.pricelist_id,
+    )
+
+    send_log = _get_send_log(logger, f'Pricelist uploading {price_filename}')
+
+    send_log('started')
+
     reseller_id = _identify_reseller_id(
         client=connect_client,
         batch_id=marketplace.pricelist_id,
         marketplace_id=marketplace.marketplace,
         hub_id=deployment_request.deployment.hub_id,
     )
+
+    send_log(f'reseller id "{reseller_id}"')
+
     excel_file, file_name, dataset = _prepare_file(
         client=connect_client,
         batch_id=marketplace.pricelist_id,
     )
+    create_ppr_to_media(
+        client=connect_client,
+        account_id=deployment_request.deployment.account_id,
+        instance_id=deployment_request.id,
+        content=excel_file,
+        filename=price_filename,
+    )
+    excel_file.seek(0)
+
+    send_log(f'filename "{file_name}", dataset "{dataset}".')
+
     try:
         _process_batch(
             cbc_service=cbc_service,
@@ -74,7 +101,9 @@ def apply_pricelist_to_marketplace(
             reseller_id=reseller_id,
             deployment=deployment_request.deployment,
             dataset=dataset,
+            send_log=send_log,
         )
+        send_log('finished')
     finally:
         excel_file.close()
 
@@ -314,6 +343,7 @@ def _process_batch(
     reseller_id,
     deployment,
     dataset,
+    send_log,
 ):
     excel_file.seek(0)
 
@@ -323,6 +353,8 @@ def _process_batch(
         args=(reseller_id, deployment.vendor_id, excel_file),
     )
 
+    send_log(f'parsed price: "{parsed_price}"')
+
     data_id = parsed_price['dataId']
 
     execute_with_retry(
@@ -334,6 +366,8 @@ def _process_batch(
         ),
     )
 
+    send_log('prise proposal sent')
+
     execute_with_retry(
         function=cbc_service.apply_prices,
         exception_class=CBCClientError,
@@ -348,4 +382,13 @@ def _process_batch(
         ),
     )
 
+    send_log(f'prise proposal applied, data id "{data_id}"')
+
     return data_id
+
+
+def _get_send_log(logger, prefix):
+    def f(message):
+        logger.info(f'${prefix}: {message}.')
+
+    return f

connect_ext_ppr/tasks_manager.py

@@ -325,6 +325,7 @@ def apply_pricelist_task(
     connect_client,
     marketplace,
     db,
+    logger,
     **kwargs,
 ):
     """ Applies a price list for a sinle marketplace
@@ -334,6 +335,7 @@ def apply_pricelist_task(
     @param Client connect_client:
     @param MarketplaceConfiguration marketplace:
     @param Session db:
+    @param Logger logger:
 
     @returns bool
     @raises TaskException
@@ -345,6 +347,7 @@ def apply_pricelist_task(
                 cbc_service,
                 connect_client,
                 marketplace,
+                logger,
             )
         except (ClientError, CBCClientError) as e:
             raise TaskException(f'Error while processing pricelist: {e}')
@@ -437,7 +440,7 @@ def execute_tasks(db, config, tasks, connect_client, logger):
                 was_succesfull = False
                 task.error_message = str(ex)[:4000]
             except Exception as ex:
-                logger.error(f'Task ID: {task.id} - {ex}')
+                logger.exception(f'Task ID: {task.id} - {ex}')
                 was_succesfull = False
                 task.error_message = 'Something went wrong.'
 
@@ -482,7 +485,7 @@ def main_process(deployment_request_id, config, connect_client, logger):
             was_succesfull = execute_tasks(db, config, tasks, connect_client, logger)
         except Exception as ex:
             was_succesfull = False
-            logger.error(f'DeploymentRequest ID: {deployment_request_id} - {ex}')
+            logger.exception(f'DeploymentRequest ID: {deployment_request_id} - {ex}')
 
         db.refresh(deployment_request, with_for_update=True)
 

tests/services/test_pricing.py

@@ -1,7 +1,7 @@
 from copy import deepcopy
 from tempfile import NamedTemporaryFile
 from unittest import TestCase
-from unittest.mock import patch
+from unittest.mock import ANY, patch
 
 import openpyxl
 import pytest
@@ -185,6 +185,7 @@ def test_validate_pricelist_negative_invalid_effective_date(mock_fetch_file):
 
 def test_apply_pricelist_to_marketplace_positive(
     mocker,
+    logger,
     marketplace,
     cbc_service,
     batch_output_file,
@@ -222,11 +223,16 @@ def test_apply_pricelist_to_marketplace_positive(
         return_value=None,
     )
 
+    create_ppr_to_media_mock = mocker.patch(
+        'connect_ext_ppr.services.pricing.create_ppr_to_media',
+    )
+
     apply_pricelist_to_marketplace(
         dep_req,
         cbc_service,
         connect_client,
         mp_conf,
+        logger,
     )
 
     reseller_id_mock.assert_called_once_with(
@@ -251,10 +257,19 @@ def test_apply_pricelist_to_marketplace_positive(
             'msrp': True,
             'effective_date': '07/26/2023',
         },
+        send_log=ANY,
     )
 
     assert price_excel_file
 
+    create_ppr_to_media_mock.assert_called_once_with(
+        client=ANY,
+        account_id=dep_req.deployment.account_id,
+        instance_id=dep_req.id,
+        filename=f'{dep_req.id}_PriceApply_MP-123_None.xlsx',
+        content=ANY,
+    )
+
 
 def test_identify_marketplaces_positive(
     connect_client,
@@ -582,6 +597,7 @@ def test_process_batch_positive(
     hub_credentials,
     no_db_deployment,
     batch_dataset,
+    logger,
 ):
     reseller_id = '10000001'
 
@@ -601,6 +617,7 @@ def test_process_batch_positive(
         reseller_id,
         no_db_deployment,
         batch_dataset,
+        logger,
     )
 
     assert data_id == parse_price_file_response['dataId']
@@ -657,6 +674,8 @@ def test_process_batch_positive(
         'MFL-0000-0000-0000.xlsx',
     )
 
+    assert logger.call_count == 3
+
 
 def test_determine_dataset_negative_effective_date_column_not_present():
     wb = load_workbook(

tests/test_tasks_manager.py

@@ -1400,6 +1400,7 @@ def test_apply_pricelist_task_ok(
     marketplace_config_factory,
     mocker,
     dbsession,
+    logger,
 ):
     apply_mock = mocker.patch(
         'connect_ext_ppr.tasks_manager.apply_pricelist_to_marketplace',
@@ -1424,6 +1425,7 @@ def test_apply_pricelist_task_ok(
         connect_client,
         req_mp,
         dbsession,
+        logger=logger,
     )
 
     assert apply_mock.called_once_with(
@@ -1444,6 +1446,7 @@ def test_apply_pricelist_task_ok_manual(
     marketplace_config_factory,
     mocker,
     dbsession,
+    logger,
 ):
     apply_mock = mocker.patch(
         'connect_ext_ppr.tasks_manager.apply_pricelist_to_marketplace',
@@ -1468,6 +1471,7 @@ def test_apply_pricelist_task_ok_manual(
         connect_client,
         req_mp,
         dbsession,
+        logger,
     )
 
     assert apply_mock.call_count == 0
@@ -1480,6 +1484,7 @@ def test_apply_pricelist_task_error(
     marketplace_config_factory,
     mocker,
     dbsession,
+    logger,
 ):
     mocker.patch(
         'connect_ext_ppr.tasks_manager.apply_pricelist_to_marketplace',
@@ -1509,6 +1514,7 @@ def test_apply_pricelist_task_error(
             connect_client,
             req_mp,
             dbsession,
+            logger,
         )
 
     assert str(e.value) == 'Error while processing pricelist: olala'