Add each checks' unique ID to logs

[ofek]

Motivation

The ability to correlate a log entry with a specific check instance

Output

[codecov]

Codecov Report

Merging #4410 into master will decrease coverage by 1.94%.
The diff coverage is 76.92%.

Impacted Files	Coverage Δ
datadog_checks_base/datadog_checks/base/log.py	68.85% <71.42%> (+4.14%)	⬆️
...dog_checks_base/datadog_checks/base/checks/base.py	75.22% <90.9%> (+0.62%)	⬆️
datadog_checks_base/tests/conftest.py	71.42% <0%> (-28.58%)	⬇️
...atadog_checks_base/datadog_checks/base/__init__.py	73.33% <0%> (-13.34%)	⬇️
datadog_checks_base/tests/test_winpdh.py	90.69% <0%> (-6.98%)	⬇️
datadog_checks_base/tests/test_pdhbasecheck.py	96% <0%> (-4%)	⬇️
datadog_checks_base/tests/test_http.py	97.33% <0%> (-0.89%)	⬇️
...checks_dev/tests/plugin/test_environment_runner.py
riakcs/datadog_checks/riakcs/riakcs.py
mesos_slave/tests/conftest.py
... and 721 more

[codecov]

Codecov Report

Merging #4410 into master will increase coverage by 4.79%.
The diff coverage is 82.6%.

Impacted Files	Coverage Δ
...tadog_checks_base/datadog_checks/base/stubs/log.py	80% <100%> (-1.82%)	⬇️
datadog_checks_base/datadog_checks/base/log.py	70.21% <78.57%> (+5.5%)	⬆️
...dog_checks_base/datadog_checks/base/checks/base.py	73.65% <80%> (+0.07%)	⬆️
windows_service/tests/common.py
disk/datadog_checks/disk/__init__.py
...checks_dev/tests/plugin/test_environment_runner.py
win32_event_log/tests/test_check.py
...service/datadog_checks/windows_service/__init__.py
...v/tests/tooling/config_validator/test_validator.py
...ent_log/datadog_checks/win32_event_log/__init__.py
... and 93 more

[mfpierre]

the logic LGTM overall 👍

[AlexandreYang]

Seems in this case we could use a logging.Filter instead. Here is an example from the official cookbook:

Using Filters to impart contextual information
You can also add contextual information to log output using a user-defined Filter. Filter instances are allowed to modify the LogRecords passed to them, including adding additional attributes which can then be output using a suitable format string, or if needed a custom Formatter.

https://docs.python.org/3/howto/logging-cookbook.html#adding-contextual-information-to-your-logging-output

That could avoid having to create our own CheckLogger and overriding logging methods (info/critical/warn/debug/etc), IMHO should be avoided if possible.

import logging

class ContextFilter(logging.Filter):
    def __init__(self, check_id):
        super(ContextFilter).__init__()
        self._check_id = check_id

    def filter(self, record):

        record._check_id = self._check_id or "unknown"
        return True

if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)-15s %(name)-5s %(levelname)-8s CheckID: %(_check_id)-15s %(message)s')
    log = logging.getLogger('my logger')

    my_check_id = 1234

    log.addFilter(ContextFilter(my_check_id)) # we can also pass the check instance here if needed
    log.debug('A debug message')


# output
# 2019-08-22 10:51:00,563 my logger DEBUG    CheckID: 1234            A debug message

[ofek]

That won't work https://docs.python.org/3/library/logging.html#logging.getLogger

All calls to this function with a given name return the same logger instance.

integrations-core/datadog_checks_base/datadog_checks/base/checks/base.py

Line 131 in f1c48cd

self.log = logging.getLogger('{}.{}'.format(__name__, self.name))

[AlexandreYang]

How about this by using the logging.LoggerAdapter ? :)

https://gist.github.com/AlexandreYang/c518db4380f2de53d644f17d29523ea8

[AlexandreYang]

[msg deleted]

[AlexandreYang]

Looks good, 👍

Just few comments.

This part is not critical, but few tests to check that the _check_id is correctly transmitted could help. But up to you :)

[AlexandreYang]

Should we inherit from datadog_checks_base/datadog_checks/base/log.py#CheckLoggingAdapter to reduce duplication ?

[ofek]

No since stubs are meant to be isolated