switched to structured logger (#3017)

.github/workflows/auth-queue-ci.yml

@@ -24,8 +24,10 @@ jobs:
 
     steps:
       - uses: actions/checkout@v4
+      - uses: actions/setup-python@v4
+        with:
+          python-version: 3.12
       - run: "true"
-
   linting:
     needs: setup-job
     runs-on: ubuntu-20.04

queue_services/auth-queue/pyproject.toml

@@ -34,7 +34,6 @@ python-dateutil = "2.9.0.post0"
 pytz = "2024.1"
 rsa = "4.9"
 semver = "3.0.2"
-sentry-sdk = "2.3.1"
 six = "1.16.0"
 threadloop = "1.0.2"
 thrift = "0.20.0"
@@ -47,6 +46,8 @@ zipp = "3.19.1"
 auth-api = { git = "https://github.com/bcgov/sbc-auth.git", rev = "feature-gcp-migration", subdirectory = "auth-api" }
 simple-cloudevent = { git = "https://github.com/daxiom/simple-cloudevent.py.git" }
 build-deps = { git = "https://github.com/bcgov/sbc-auth.git", rev = "feature-gcp-migration", subdirectory = "build-deps" }
+# TODO move this build-deps
+structured-logging = { git = "https://github.com/bcgov/sbc-connect-common.git", subdirectory = "python/structured-logging", branch = "main" }
 
 [tool.poetry.group.dev.dependencies]
 psycopg2 = "^2.9.9"

queue_services/auth-queue/src/auth_queue/__init__.py

@@ -14,23 +14,17 @@
 """Resource package for the auth-queue service."""
 import os
 
-import sentry_sdk
 from auth_api.models import db
 from auth_api.resources.ops import bp as ops_bp
 from auth_api.services.flags import flags
 from auth_api.services.gcp_queue import queue
 from auth_api.utils.cache import cache
-from auth_api.utils.util_logging import setup_logging
 from flask import Flask
-from sentry_sdk.integrations.flask import FlaskIntegration
 
 from auth_queue import config
 from auth_queue.resources.worker import bp as worker_endpoint
 
 
-setup_logging(os.path.join(os.path.abspath(os.path.dirname(__file__)), 'logging.conf'))  # important to do this first
-
-
 def register_endpoints(app: Flask):
     """Register endpoints with the flask application."""
     # Allow base route to match with, and without a trailing slash
@@ -47,13 +41,7 @@ def create_app(run_mode=os.getenv('DEPLOYMENT_ENV', 'production')) -> Flask:
     """Return a configured Flask App using the Factory method."""
     app = Flask(__name__)
     app.config.from_object(config.get_named_config(run_mode))
-
-    if str(app.config.get('SENTRY_ENABLE')).lower() == 'true':
-        if app.config.get('SENTRY_DSN', None):
-            sentry_sdk.init(  # pylint: disable=abstract-class-instantiated
-                dsn=app.config.get('SENTRY_DSN'),
-                integrations=[FlaskIntegration()]
-            )
+    app.config['ENV'] = run_mode
 
     db.init_app(app)
     flags.init_app(app)

queue_services/auth-queue/src/auth_queue/config.py

@@ -59,9 +59,6 @@ class _Config:  # pylint: disable=too-few-public-methods
 
     PROJECT_ROOT = os.path.abspath(os.path.dirname(__file__))
 
-    SENTRY_ENABLE = os.getenv('SENTRY_ENABLE', 'False')
-    SENTRY_DSN = os.getenv('SENTRY_DSN', None)
-
     SQLALCHEMY_TRACK_MODIFICATIONS = False
 
     AUTH_LD_SDK_KEY = os.getenv('AUTH_LD_SDK_KEY', None)
@@ -72,19 +69,19 @@ class _Config:  # pylint: disable=too-few-public-methods
     DB_NAME = os.getenv('DATABASE_NAME', '')
     DB_HOST = os.getenv('DATABASE_HOST', '')
     DB_PORT = os.getenv('DATABASE_PORT', '5432')
-    SQLALCHEMY_DATABASE_URI = f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'
+    SQLALCHEMY_DATABASE_URI = f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'  # noqa: E231
 
     if DB_UNIX_SOCKET := os.getenv('DATABASE_UNIX_SOCKET', None):
-        SQLALCHEMY_DATABASE_URI = f'postgresql+psycopg2://{DB_USER}:{DB_PASSWORD}@/{DB_NAME}?host={DB_UNIX_SOCKET}'
+        SQLALCHEMY_DATABASE_URI = f'postgresql+psycopg2://{DB_USER}:{DB_PASSWORD}@/{DB_NAME}?host={DB_UNIX_SOCKET}'  # noqa: E231, E501
     else:
-        SQLALCHEMY_DATABASE_URI = f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'
+        SQLALCHEMY_DATABASE_URI = f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'  # noqa: E231, E501
 
     # PUB/SUB - PUB: account-mailer-dev, SUB: auth-event-dev and namex-nr-state-dev
     ACCOUNT_MAILER_TOPIC = os.getenv('ACCOUNT_MAILER_TOPIC', 'account-mailer-dev')
     # If blank in PUB/SUB, this should match the https endpoint the subscription is pushing to.
     AUTH_AUDIENCE_SUB = os.getenv('AUTH_QUEUE_AUDIENCE_SUB')
     GCP_AUTH_KEY = os.getenv('AUTHPAY_GCP_AUTH_KEY', None)
-    VERIFY_PUBSUB_EMAILS = f'{os.getenv("AUTHPAY_SERVICE_ACCOUNT")},{os.getenv("BUSINESS_SERVICE_ACCOUNT")}'.split(',')
+    VERIFY_PUBSUB_EMAILS = f'{os.getenv("AUTHPAY_SERVICE_ACCOUNT")},{os.getenv("BUSINESS_SERVICE_ACCOUNT")}'.split(',')  # noqa: E231, E501
 
     PAY_API_URL = os.getenv('PAY_API_URL') + os.getenv('PAY_API_VERSION')
 
@@ -117,7 +114,7 @@ class TestConfig(_Config):  # pylint: disable=too-few-public-methods
     DB_PORT = os.getenv('DATABASE_TEST_PORT', '5432')
     SQLALCHEMY_DATABASE_URI = os.getenv(
         'DATABASE_TEST_URL',
-        default=f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'
+        default=f'postgresql://{DB_USER}:{DB_PASSWORD}@{DB_HOST}:{int(DB_PORT)}/{DB_NAME}'  # noqa: E231
     )
     PAY_API_URL = os.getenv('PAY_API_URL') + os.getenv('PAY_API_VERSION')
 

queue_services/auth-queue/src/auth_queue/resources/worker.py

@@ -32,10 +32,13 @@
 from flask import Blueprint, current_app, request
 from sbc_common_components.utils.enums import QueueMessageTypes
 from simple_cloudevent import SimpleCloudEvent
+from structured_logging import StructuredLogging
 
 
 bp = Blueprint('worker', __name__)
 
+logger = StructuredLogging.get_logger()
+
 
 @bp.route('/', methods=('POST',))
 @ensure_authorized_queue_user
@@ -46,9 +49,9 @@ def worker():
         return {}, HTTPStatus.OK
 
     try:
-        current_app.logger.info('Event message received: %s', json.dumps(dataclasses.asdict(event_message)))
+        logger.info('Event message received: %s', json.dumps(dataclasses.asdict(event_message)))
         if is_message_processed(event_message):
-            current_app.logger.info('Event message already processed, skipping.')
+            logger.info('Event message already processed, skipping.')
             return {}, HTTPStatus.OK
         if event_message.type == QueueMessageTypes.NAMES_EVENT.value:
             process_name_events(event_message)
@@ -58,7 +61,7 @@ def worker():
                                     QueueMessageTypes.NSF_LOCK_ACCOUNT.value]:
             process_pay_lock_unlock_event(event_message)
     except Exception: # NOQA # pylint: disable=broad-except
-        current_app.logger.error('Error processing event:', exc_info=True)
+        logger.error('Error processing event:', exc_info=True)
     # Return a 200, so the event is removed from the Queue
     return {}, HTTPStatus.OK
 
@@ -78,7 +81,7 @@ def is_message_processed(event_message):
 
 def process_activity_log(data):
     """Process activity log events."""
-    current_app.logger.debug('>>>>>>>process_activity_log>>>>>')
+    logger.debug('>>>>>>>process_activity_log>>>>>')
     activity_model = ActivityLogModel(actor_id=data.get('actorId'),
                                       action=data.get('action'),
                                       item_type=data.get('itemType'),
@@ -92,21 +95,21 @@ def process_activity_log(data):
     try:
         activity_model.save()
     except Exception as e:  # NOQA # pylint: disable=broad-except
-        current_app.logger.error('DB Error: %s', e)
+        logger.error('DB Error: %s', e)
         db.session.rollback()
-    current_app.logger.debug('<<<<<<<process_activity_log<<<<<')
+    logger.debug('<<<<<<<process_activity_log<<<<<')
 
 
 def process_pay_lock_unlock_event(event_message: SimpleCloudEvent):
     """Process a pay event to either unlock or lock an account. Source message comes from Pay-api."""
-    current_app.logger.debug('>>>>>>>process_pay_lock_unlock_event>>>>>')
+    logger.debug('>>>>>>>process_pay_lock_unlock_event>>>>>')
     message_type = event_message.type
     queue_data = event_message.data
     skip_notification = queue_data.get('skipNotification', False)
     org_id = queue_data.get('accountId')
     org: OrgModel = OrgModel.find_by_org_id(org_id)
     if org is None:
-        current_app.logger.error('Unknown org for orgid %s', org_id)
+        logger.error('Unknown org for orgid %s', org_id)
         return
 
     data = {
@@ -128,7 +131,7 @@ def process_pay_lock_unlock_event(event_message: SimpleCloudEvent):
 
     org.flush()
     db.session.commit()
-    current_app.logger.debug('<<<<<<<process_pay_lock_unlock_event<<<<<')
+    logger.debug('<<<<<<<process_pay_lock_unlock_event<<<<<')
 
 
 def process_name_events(event_message: SimpleCloudEvent):
@@ -153,13 +156,13 @@ def process_name_events(event_message: SimpleCloudEvent):
                 }
             }
     """
-    current_app.logger.debug('>>>>>>>process_name_events>>>>>')
+    logger.debug('>>>>>>>process_name_events>>>>>')
     request_data = event_message.data.get('request') or event_message.data.get('name')
     nr_number = request_data['nrNum']
     nr_status = request_data['newState']
     nr_entity = EntityModel.find_by_business_identifier(nr_number)
     if nr_entity is None:
-        current_app.logger.info("Entity doesn't exist, creating a new entity.")
+        logger.info("Entity doesn't exist, creating a new entity.")
         nr_entity = EntityModel(
             business_identifier=nr_number,
             corp_type_code=CorpType.NR.value
@@ -171,7 +174,7 @@ def process_name_events(event_message: SimpleCloudEvent):
     nr_entity.last_modified = parser.parse(event_message.time)
     # Future - None needs to be replaced with whatever we decide to fill the data with.
     if nr_status == 'DRAFT' and not AffiliationModel.find_affiliations_by_business_identifier(nr_number, None):
-        current_app.logger.info('Status is DRAFT, getting invoices for account')
+        logger.info('Status is DRAFT, getting invoices for account')
         token = None
         # Find account details for the NR.
         with current_app.test_request_context('service_token'):
@@ -185,13 +188,13 @@ def process_name_events(event_message: SimpleCloudEvent):
         if invoices and invoices['invoices'] \
                 and (auth_account_id := invoices['invoices'][0].get('paymentAccount').get('accountId')) \
                 and str(auth_account_id).isnumeric():
-            current_app.logger.info('Account ID received : %s', auth_account_id)
+            logger.info('Account ID received : %s', auth_account_id)
             # Auth account id can be service account value too, so doing a query lookup than find_by_id
             org: OrgModel = db.session.query(OrgModel).filter(OrgModel.id == auth_account_id).one_or_none()
             # If account is present and is not a gov account, then affiliate.
             if org and org.access_type != AccessType.GOVM.value:
                 nr_entity.pass_code_claimed = True
-                current_app.logger.info('Creating affiliation between Entity : %s and Org : %s', nr_entity, org)
+                logger.info('Creating affiliation between Entity : %s and Org : %s', nr_entity, org)
                 affiliation: AffiliationModel = AffiliationModel(entity=nr_entity, org=org)
                 affiliation.flush()
                 activity: ActivityLogModel = ActivityLogModel(org_id=org.id,
@@ -203,4 +206,4 @@ def process_name_events(event_message: SimpleCloudEvent):
                 activity.flush()
 
     nr_entity.save()
-    current_app.logger.debug('<<<<<<<process_name_events<<<<<<<<<<')
+    logger.debug('<<<<<<<process_name_events<<<<<<<<<<')