# Logging * [Where to Look](logging.md#where-to-look) * [Service Logging](logging.md#service-logging) * [ELB Access Logs](logging.md#elb-access-logs) * [Workstation/OA/VAPI Access Logs](logging.md#php-access-logs-workstationoavapi) * [STDOUT/STDERR Streams](logging.md#stdoutstderr-streams) * [APM](logging.md#apm) * [RUM](logging.md#rum) * [Service Dashboards](logging.md#service-dashboards) * [Timeboard](logging.md#timeboard) * [Screenboard](logging.md#screenboard) * [Application Logs](logging.md#application-logs) * [Filter by service](logging.md#filter-by-service) * [All Services](logging.md#all-services) * [Exception Logs](logging.md#exception-logs) * [Filter by service](logging.md#filter-by-service-1) * [Best Practices](logging.md#best-practices) * [Reduce Noise](logging.md#reduce-noise) * [Avoid Application Logging to Sentry](logging.md#avoid-application-logging-to-sentry) * [Avoid Using Exceptions to Indicate a Falsey Return Value](logging.md#avoid-using-exceptions-to-indicate-a-falsey-return-value) * [Logging in PHP](logging.md#logging-in-php) * [Configuration](logging.md#configuration) * [Usage](logging.md#usage) * [Application logging](logging.md#application-logging) * [Exception logging](logging.md#exception-logging) * [Logging in Python](logging.md#logging-in-python) * [Application logging](logging.md#application-logging-1) * [Exception logging](logging.md#exception-logging-1) ## Where to Look ### Service Logging Service logs are any logs that are not explicitly logged or triggered from within the application #### Load Balancer Access Logs For ows- services behind a load balancer, access logs can be found in Datadog [https://app.datadoghq.com/](https://app.datadoghq.com/). These are raw http requests logs as taken from the load balancer in front of each microservice. Both Elastic Beanstalk & Fargated apps support this. All load balancer logs can be found by going to the Logs tab in Datadog and filtering by service:elb. A saved view can can be found [here](https://app.datadoghq.com/logs?saved_view=48167). #### PHP Access Logs \(Workstation/OA/VAPI\) For our legacy PHP applications, apache access logs are being sent to Datadog and a saved view can be found [`here`](https://app.datadoghq.com/logs?saved_view=81991) #### STDOUT/STDERR Streams Applications that have been setup with Fargate are now also [capturing stdout & stderr I/O streams](https://docs.aws.amazon.com/AmazonECS/latest/developerguide/using_awslogs.html) in Datadog. For our ows- microservices \(e.g `@aws.awslogs.logGroup:prod-ows-users`\), these will be uswgi logs. Example: Go to Logs -> Search and enter `@aws.awslogs.logGroup:prod-ows-users` - this will give you [prod ows-users uwsgi logs](https://app.datadoghq.com/logs?cols=core_host%2Ccore_service&from_ts=1560785607230&index=main&live=true&query=%40aws.awslogs.logGroup%3Aprod-ows-users&stream_sort=desc&to_ts=1560786507230). For our worker/daemons, these will be supervisord output. Example: Go to Logs -> Search and enter `@aws.awslogs.logGroup:qa-swf-itunes-hides` - this will give you [`@aws.awslogs.logGroup:supervisord logs`](https://app.datadoghq.com/logs?cols=core_host%2Ccore_service&from_ts=1560966466974&index=main&live=true&query=%40aws.awslogs.logGroup%3Aqa-swf-itunes-hides&stream_sort=desc&to_ts=1561139266974) #### APM Applications that have the Datadog APM client installed also collect request count & latency statistics, as well as sampled transaction tracing. Example - \(Go to APM->Services section of Datadog\) [here](https://app.datadoghq.com/apm/services). Clicking into the flask drilldown will reveal the most useful debugging info. ##### Finding APM Traces Finding a trace for a specific API call can be made easier by leveraging the `x-datadog-trace-id` HEADER. The value of this header will be the trace ID for this particular call. DataDog recommends a unique 64 bit integer be generated for this id to avoid collisions with other traces. ex. `python -c "import uuid ; print(uuid.uuid4().int & (1<<64)-1)"` To find a specific trace in the APM, one can navigate to https://app.datadoghq.com/apm/trace/xxxxx and "xxxxxx" will need to be replaced with the trace ID. For example, https://app.datadoghq.com/apm/trace/8012309637243338819 Frontend Applications instrumented with RUM (see next sessoin) and with [allowedTracingOrigins]([https://docs.datadoghq.com/real_user_monitoring/connect_rum_and_traces) enabled will automatically inject the `x-datadog-trace-id HEADER` in API calls. Simply open the network tab for these applications and look at the headers sent to any API calls to find the appropriate trace-id HEADER. ![RUM trace-id](/.gitbook/assets/datadog_RUM_trace_id.png) #### RUM Real User Monitoring (RUM) in Datadog gives visibility into real-time activity of individual users in frontend applications. RUM traces can be connected to APM traces to get cohesive logs across the full stack. Example -\(Go to UX Monitoring->RUM Applications section of Datadog [here](https://app.datadoghq.com/rum/list)). ![Datadog RUM link](/.gitbook/assets/datadog_RUM_link.png) ### Service Dashboards Fargated services also come with dashboards summarizing the above logs in a single location. #### Timeboard Microservices migrated to Fargate have a timeboard to show a timeline of different HTTP request types/CPU Utilization/Memory Utilization on a single page. Go to Dashboards -> Dashboard List and search for your service [`prod-ows-users timeboard`](https://app.datadoghq.com/dashboard/zcd-5ir-mne/prod-ows-users-timeboard). #### Screenboard Microservices migrated to Fargate have a screenboard showing ELB logs, STDOUT/STDERR Streams, & APM info on a single page. Go to Dashboards -> Dashboard List and search for your service [`prod-ows-users screenboard`](https://app.datadoghq.com/dashboard/g8g-y4f-sui/prod-ows-users-screenboard?tile_size=m). ### Application Logs Application logs re instances of deliberate logging by a developer from within the application code and include levels such as `info`, `debug`, `error`, `warning` and `critical` with a message and optional JSON vars. These can be found in Datadog, and a good starting point is a saved view can be found [here](https://app.datadoghq.com/logs?saved_view=81395) #### Filter by Service To search for logs from a particular service in Datadog, start from [this saved view](https://app.datadoghq.com/logs?saved_view=81395). From there, you can filter using the `service` tag. Some examples are as follows: * OA: [service:orchadmin](https://app.datadoghq.com/logs?cols=%40service%2C%40tag%2C%40level_name%2C%40environment%2C%40meta.file_name%2C%40meta.function_name%2C%40correlation_id&from_ts=1583187628708&index=main&live=true&messageDisplay=inline&query=source%3Afluentd+%40tag%3Aows1+service%3Aorchadmin&saved_view=81395&stream_sort=desc&to_ts=1583274028708) * vapi: [service:vectorapi](https://app.datadoghq.com/logs?cols=%40service%2C%40tag%2C%40level_name%2C%40environment%2C%40meta.file_name%2C%40meta.function_name%2C%40correlation_id&from_ts=1583187628708&index=main&live=true&messageDisplay=inline&query=source%3Afluentd%20%40tag%3Aows1%20service%3Avectorapi&saved_view=81395&stream_sort=desc&to_ts=1583274028708) * workstation: [service:workstation](https://app.datadoghq.com/logs?cols=%40service%2C%40tag%2C%40level_name%2C%40environment%2C%40meta.file_name%2C%40meta.function_name%2C%40correlation_id&from_ts=1583187628708&index=main&live=true&messageDisplay=inline&query=source%3Afluentd%20%40tag%3Aows1%20service%3Aworkstation&saved_view=81395&stream_sort=desc&to_ts=1583274028708) * ows-assets: [service:ows-assets](https://app.datadoghq.com/logs?cols=%40service%2C%40tag%2C%40level_name%2C%40environment%2C%40meta.file_name%2C%40meta.function_name%2C%40correlation_id&from_ts=1583187628708&index=main&live=true&messageDisplay=inline&query=source%3Afluentd%20%40tag%3Aows1%20service%3Aows-assets&saved_view=81395&stream_sort=desc&to_ts=1583274028708) * daemon-transcoding: [service:daemon-transcoding](https://app.datadoghq.com/logs?cols=%40service%2C%40tag%2C%40level_name%2C%40environment%2C%40meta.file_name%2C%40meta.function_name%2C%40correlation_id&from_ts=1583187628708&index=main&live=true&messageDisplay=inline&query=source%3Afluentd%20%40tag%3Aows1%20service%3Adaemon-transcoding&saved_view=81395&stream_sort=desc&to_ts=1583274028708) Selecting individual log messages will provide other facets that you can either filter or display. ### Exception Logs Exception logs can be found in Sentry. These are for when your application blows up. Uncaught Exceptions are automatically captured by Sentry, but messages can also be manually sent. [https://sentry.io/organizations/the-orchard/](https://sentry.io/organizations/the-orchard/) #### Filter by Service Sentry breaks up logs by project. Go to Projects, then find your project. ## Best Practices ### Reduce Noise We have run into issues where the log service we use gets completely filled up by mid day by too much `info` logging. If you need to trace a function with low visibility, consider using `debug` level logs instead. Once the logs fill up, we lose the rest of the logs for the day. ### Avoid Application Logging to Sentry Application logging should go to Datadog. Keep Sentry for exceptions, this will make it easier to troubleshoot when an application blows up. ### Avoid Using Exceptions to Indicate a Falsey Return Value If there is a method in a class that you need to either return a value or false, do not indicate false by throwing an exception. Our python services for example make use of a `Response` class that returns with a payload and an HTTP status, 200 to indicate OK, or 404 with no payload. ## Logging in PHP Please make use of the [`LoggerFactory()`](https://github.com/theorchard/common/blob/master/src/Logging/LoggerFactory.php) class in [`/common`](https://github.com/theorchard/common) for your PHP application and exception logging. ### Configuration You can use this YML to configure your LoggerFactory. ```text processors: tag_processor: class: Monolog\Processor\TagProcessor introspection_processor: class: Monolog\Processor\IntrospectionProcessor ows1_processor: class: Orchard\Common\Logging\Processor\Ows1Processor formatters: json: class: Monolog\Formatter\JsonFormatter handlers: sentry_handler: class: Monolog\Handler\RavenHandler level: error raven_client: class: Raven_Client options_or_dsn: {{ SENTRY_DSN }} ows1_udp_handler: connectionString: {{ FLUENTD_LOGGER_DSN }} class: Monolog\Handler\SocketHandler processors: [introspection_processor, tag_processor, ows1_processor] formatter: json level: DEBUG fluentd_handler: class: Monolog\Handler\WhatFailureGroupHandler handlers: [ows1_udp_handler] loggers: Logger: handlers: [fluentd_handler] SentryExceptionHandler: handlers: [sentry_handler] ``` ### Usage #### Application logging **Getting an application logger \(basic\)** Getting a logger involves setting some values like service name and version. ```php use Orchard\Common\Logging\LoggerFactory; $applicationLogger = LoggerFactory::getLogger( Yaml::parse(APPLICATION_PATH . '/configs/logger_factory.yml'), 'workstation', # service name '1.0.0', # service version 'Logger', # logger name null, # correlation id 'workstation-' # correlation id prefix ); ``` **Getting an application logger \(OA/Workstation\)** In OA and Workstation, we have the application loggers in `Zend_Registry`, configured in [`Bootstrap.php`](https://github.com/theorchard/orchard/pull/14439/files#diff-d1e285cbe120b2f7d53163b2b22e0478R78). The can be fetched like the following: ```php # in OA $applicationLogger = Zend_Registry::get('applicationLoggerOA'); # in Workstation $applicationLogger = Zend_Registry::get('applicationLoggerWS'); ``` **Getting an application logger \(VAPI\)** The VAPI application logger is also in `Zend_Registry`, configured in [`Bootstrap.php`](https://github.com/theorchard/api/pull/1873/files#diff-d1e285cbe120b2f7d53163b2b22e0478R127). ```php $applicationLogger = Zend_Registry::get('applicationLogger'); ``` **Using the application logger** You can send additional fields in the `custom_fields` array property. ```php $applicationLogger->info('Information message', ['custom_fields' => [ 'key1' => 1623457623154, 'key2' => 'value2' ]]); ``` or a warning ```php $applicationLogger->warning('Warning message', ['custom_fields' => [ 'key1' => 1623457623154, 'key2' => 'value2' ]]); ``` or an error ```php $applicationLogger->error('Error message', ['custom_fields' => [ 'key1' => 1623457623154, 'key2' => 'value2' ]]); ``` The result looks something like: ```javascript { "id": "AQAAAXChFmORqH_okQAAAABBWENoRngyNmM1T2FYbzhLZDBBQQ", "content": { "timestamp": "2020-03-03T15:49:23.985Z", "tags": [ "environment:prod", "location:on_prem", "service_name:fluentd", "source:fluentd" ], "host": "prod-fluentd-applications-i-06be871cbc0a5650e", "service": "orchadmin", "message": "Rejection email sent successfully to vendor {\"contact@fuxcartel.com\":\"Julien Collier\",\"label@fuxcartel.com\":\"Yustina Klapsakis\"} for product 2803801", "attributes": { "environment": "prod", "hostname": "ip-10-10.10.1.ec2.internal", "level_name": "INFO", "service": "orchadmin", "meta": { "file_name": "/var/www/html_oa/application/modules/oa/controllers/RelationshipsController.php", "line": 868, "function_name": "rejectreleaseAction", "logger_name": "Logger" }, "correlation_id": "orchadmin-5e5e7c81e2462", "custom_fields": { "contact_id": "34659", "vendor_id": "2624", "auth0UserId": null }, "tag": "ows1", "client_host": "10.10.10.1", "@timestamp": "2020-03-03T15:49:23.985Z", "level": 200, "fluentd_source": "udp_application", "service_version": "1.0.0", "timestamp": "2020-03-03T10:49:23-0500" } } } ``` ##### Real world example https://github.com/theorchard/orchard/blob/0fd1552531707e4df7078c7d9bc77313937f6827/application/modules/oa/controllers/RelationshipsController.php#L586 It is not only instantiating but also logging at the same time **custom fields caveat - types** The indexing the happens in Datadog takes the type of the value into account. This can cause issues when searching logs if you change from one type to another. If something like that does happen, facets may not be indexed as expected and you may have to search an unindexed log record. #### Exception logging **Raven Exception Handler \(basic\)** The Raven client will NOT halt execution when handleException\(\) is called. ```php use Orchard\Common\Logging\LoggerFactory; $exceptionHandler = LoggerFactory::getRavenExceptionHandler( Yaml::parse(APPLICATION_PATH . '/configs/logger_factory.yml') ); $exceptionHandler->handleException(new Exception('Test exception')); # code will continue ``` **Raven Exception Handler \(OA/Workstation/VAPI\)** This is again, configured in [`Bootstrap.php`](https://github.com/theorchard/api/pull/1873/files#diff-d1e285cbe120b2f7d53163b2b22e0478R144) and set to `Zend_Registry` for the manual handling of exceptions, generally in the `catch` block of a `try/catch`. ```php $exceptionHandler = Zend_Registry::get('ravenExceptionHandler'); $exceptionHandler->handleException(new Exception('Test exception')); ``` ```php # send custom variables to Sentry $exceptionHandler = Zend_Registry::get('ravenExceptionHandler'); $exceptionHandler->handleException(new Exception('Test exception'), false [ 'customKey1' => 'customValue1', 'customKey2' => 'customValue2' ]); ``` **Sentry** The main use for this handler is to catch uncaught exceptions. Therefore, you will find that it is configured in `Bootstrap.php` in OA, Workstation, and VAPI as the default exception handler, but not added to the `Zend_Registry` for manual use. ```php use Orchard\Common\Logging\LoggerFactory; $exceptionHandler = LoggerFactory::getSentryExceptionHandler( Yaml::parse(APPLICATION_PATH . '/configs/logger_factory.yml'), 'SentryExceptionHandler' ); # at this point any uncaught exceptions in the application will be handled and sent to Sentry $exceptionHandler->handleException(new Exception('Test exception')); # ^ you would really never need to do this, you should use the raven exception handler to do this. ``` ## Logging in Python ### Application Logging Logging is done in python microservices using [python-owslogger](https://github.com/theorchard/python-owslogger). #### Setup The most common setup for a flask logger is like [this](https://github.com/theorchard/ows-product/blob/master/product/api.py#L18-L21). Although the [README](https://github.com/theorchard/python-owslogger/blob/master/README.md) in `python-owslogger` has more details. The key thing to note is that in a microservice you will use `owslogger.flask_logger` where as in something like a daemon or a lambda you will use `owslogger.logger`, see the [README](https://github.com/theorchard/python-owslogger/blob/master/README.md) for more details. **Setup example** The logger setup is typically done in [`{service}/api.py`](https://github.com/theorchard/ows-product/blob/bfae0d7649/product/api.py#L18). #### Usage The logger is available in the flask global, which you bring into scope with: ```python from flask import g ``` Then you can use it to call the typical log levels \(info, warn, error, debug, critical\): ```python g.ows.log.warn( 'Error {} copying product (ows-product-physical)'.format( copy_product_response.status)) ``` ### Exception Logging Exception logging is done in Sentry, like it is in PHP. #### Setup A typical setup uses the `connector` pattern, as seen here in [ows-product](https://github.com/theorchard/ows-product/blob/2e5e84eb45/product/connectors/sentry.py). #### Usage As long as Sentry is configured and brought into scope \(as in our [cookiecutter-flask](https://github.com/theorchard/cookiecutter-flask)\), Sentry will automatically capture any uncaught exceptions, nothing further is needed in the code. The only use case for catching an exception and sending it to Sentry is if we want the application to recover from an exception, but still log it. DON'T ```text try: raise Exception('it exploded') except Exception as e: sentry_client.captureException() raise e . # or return 500 ``` OK \(but not required\) ```text try: raise Exception('it exploded') except Exception: print('something exploded but let's not fail) sentry_client.captureException() ``` For more details see [ows-don't-try](https://docs.google.com/presentation/d/1pLK0r2fhL3hyGJMv2Ewqnd0N3kHCdChhztkpdSHpZD0/edit)