Downloading the user log

You can add log messages in your code. Those messages are sent to a user log file that you can download from the Notifications pane of the Metrics page while the job is running.

A user log is a runtime log. Each running streams flow sends messages to its own log file.

The ability to log messages applies to the following Python code operators.

  • Code (in Sources and Targets)
  • Code and Python Model (in Processing and Analytics)

You cannot log messages from your code in the Filter operator because in Python, log statements within conditional expressions are not valid.

For a summary sheet of Python logging syntax, see Python Logging HOWTO.

Important

Logging something per event can significantly reduce the throughput rate and might result in operator congestion. As a result, logging is most suitable in a testing environment rather than in a production environment.

User message retention

All user messages from a flow’s system logs (app trace) are extracted. Therefore, the app trace rollover policy and the verbosity of logging by a streams flow also impact how far back the user messages go in a downloaded user log.

Known issue

Due to a temporary limitation, only messages that are logged at INFO level or higher (WARN, ERROR) make it into the user log. Therefore, use logger.info(), logger.warn(), or logger.error().

Prerequisites

The streams flow must be in the “Running” state in the Metrics page. If your streams flow cannot run due to errors, then you have compiler errors, other errors in the environment, or errors with services. Those errors do not show up in the user logs.

To download user logs, perform the following steps:

  1. In the canvas of the streams flow, click the operator to which you want to add logging code.

  2. Add logging code. See Example 1.

  3. Repeat step 2 for each Code operator that you need to log messages.

  4. Click the Run button to save the streams flow, run it, and then monitor it in the Metrics page.

  5. When the streams flow is running in the Metrics page, click the Notification icon, and then click the Download user logs icon to download the log. The log is not compressed.

    Notification pane icons

Example 1

Goal: To use a logger for tracing or debugging your code, add a debug message at a specific line of code.

import sys
import logging

# Use this logger for tracing or debugging your code:
logger = logging.getLogger(__name__)
# Example:
      logger.error('INFO: Got to step 2...')

As another example of adding a log message, the following line of logging code logger.info('Hello there') results in this output to the user log 18 Apr 2018 21:13:24.145 [73343] INFO [My Cool Code] - Hello there.

The following table shows each field in the output.

Date Time [PID] Severity [Operator name] Message
18 Apr 2018 21:13:24.145 73343 INFO My Cool Code Hello there

Example 2

Goal: See how user logs from multiple processes in a streams flow are interlaced and ordered by their timestamp in the user log.

Note: User logs from multiple processes are interlaced and ordered by their timestamp. The following snippet from the user log shows output from three processes (PID 73343, 73371, and 73372) of a streams flow.

18 Apr 2018 21:13:24.145 [73343] INFO [Source 1]  - Emitting event: {'bool': True, 'date': datetime.datetime(2017, 7, 7, 12, 55, 16), 'number': 7, 'text': 'today', 'description': 'All valid, int'}
18 Apr 2018 21:13:24.228 [73371] INFO [Source 2]  - Emitting event: {'bool': True, 'date': datetime.datetime(2017, 7, 7, 12, 55, 16), 'number': 7, 'text': 'today', 'description': 'All valid, int'}
18 Apr 2018 21:13:24.229 [73372] INFO [Source 3]  - Emitting event: {'bool': True, 'date': datetime.datetime(2017, 7, 7, 12, 55, 16), 'number': 7, 'text': 'today', 'description': 'All valid, int'}
18 Apr 2018 21:13:25.147 [73343] INFO [Source 1]  - Emitting event: {'bool': True, 'date': datetime.datetime(2017, 7, 7, 12, 55, 16), 'number': 3.14, 'text': 'today', 'description': 'All valid, float'}
18 Apr 2018 21:13:25.229 [73371] INFO [Source 2]  - Emitting event: {'bool': True, 'date': datetime.datetime(2017, 7, 7, 12, 55, 16), 'number': 3.14, 'text': 'today', 'description': 'All valid, float'}

Example 3

Goal: Show how intentional or inadvertent errors are included with logging messages in the user log.

The streams flow has the following structure.

  • One data-producing Code operator from the Sources pane
  • Two data-processing Code operators from the Processing and Analytics pane

The Code (in Processing and Analytics) operator raises an Exception error whenever fruit==melon.

 if (event['fruit'] == 'melon'):
        raise Exception("No melons, please!")

The other Code (in Processing and Analytics) operator raises an inadvertent divide-by-zero error whenever fruit==almond.

 if (event['fruit'] == 'almond'):
        a = 2/0

Note: The errors, in addition to appearing in the Notification pane, also find their way into the user logs. As a result, you are better able to track down the errors.

The following example shows how the previous errors look in the user log.

22 Apr 2018 11:57:55.906 [44742] INFO [Code with errors]  - Passing: {'amount': 4.0, 'unit': 'kg', 'fruit': 'almond', 'counter': 3.0}
22 Apr 2018 11:57:55.910 [44742] WARN [Code-in-the-middle]  - Passing: {'amount': 4.0, 'unit': 'kg', 'fruit': 'almond', 'counter': 3.0}
22 Apr 2018 11:57:55.910 [44742] ERROR [Code with errors]  - ZeroDivisionError: division by zero
22 Apr 2018 11:57:56.828 [44726] INFO [Beacon Code]  - About to submit (debug): {'counter': 4, 'unit': 't', 'fruit': 'melon', 'amount': 5}
22 Apr 2018 11:57:56.828 [44726] INFO [Beacon Code]  - Submitted (info): {'counter': 4, 'unit': 't', 'fruit': 'melon', 'amount': 5}
22 Apr 2018 11:57:56.829 [44726] INFO [Beacon Code]  - Submitted (info): {'counter': 4, 'unit': 't', 'fruit': 'melon', 'amount': 5}
22 Apr 2018 11:57:56.912 [44742] INFO [Code with errors]  - Passing: {'amount': 5.0, 'unit': 't', 'fruit': 'melon', 'counter': 4.0}
22 Apr 2018 11:57:56.915 [44742] WARN [Code-in-the-middle]  - Passing: {'amount': 5.0, 'unit': 't', 'fruit': 'melon', 'counter': 4.0}
22 Apr 2018 11:57:56.915 [44742] ERROR [Code with errors]  - Exception: No melons, please!
22 Apr 2018 11:57:56.916 [44742] WARN [Code-in-the-middle]  - Passing: {'amount': 5.0, 'unit': 't', 'fruit': 'melon', 'counter': 4.0}