diff --git a/docs/implementation/logging.md b/docs/implementation/logging.md index 4f5142be9..12c670382 100644 --- a/docs/implementation/logging.md +++ b/docs/implementation/logging.md @@ -1,6 +1,8 @@ -# Logging +# [SDK Implementation Details](./index.md) - Logging -Logs are configurable by the environment variables `_LOGLEVEL` (preferred) +## Logging levels + +Logging levels are configurable by the environment variables `_LOGLEVEL` (preferred) or `LOGLEVEL`. Use `LOGLEVEL` when you intend to control the log output for all taps and targets running within the environment. In contrast, we recommend setting `_LOGLEVEL` for more granual control of each tap or target individually. @@ -8,6 +10,34 @@ and targets running within the environment. In contrast, we recommend setting From most verbose to least verbose, the accepted values for logging level are `debug`, `info`, `warning`, and `error`. Logging level inputs are case-insensitive. +To use different logging levels for different loggers, see the [custom logging configuration](#custom-logging-configuration) section below. + +## Default log format + +The default log format is `"{asctime:23s} | {levelname:8s} | {name:20s} | {message}"`. + +This produces logs that look like this: + +``` +2022-12-05 19:46:46,744 | INFO | my_tap | Added 'child' as child stream to 'my_stream' +2022-12-05 19:46:46,744 | INFO | my_tap | Beginning incremental sync of 'my_stream'... +2022-12-05 19:46:46,744 | INFO | my_tap | Tap has custom mapper. Using 1 provided map(s). +2022-12-05 19:46:46,745 | INFO | my_tap | Beginning full_table sync of 'child' with context: {'parent_id': 1}... +2022-12-05 19:46:46,745 | INFO | my_tap | Tap has custom mapper. Using 1 provided map(s). +2022-12-05 19:46:46,746 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.0005319118499755859, "tags": {"stream": "child", "context": {"parent_id": 1}, "status": "succeeded"}} +2022-12-05 19:46:46,747 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 3, "tags": {"stream": "child", "context": {"parent_id": 1}}} +2022-12-05 19:46:46,747 | INFO | my_tap | Beginning full_table sync of 'child' with context: {'parent_id': 2}... +2022-12-05 19:46:46,748 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.0004410743713378906, "tags": {"stream": "child", "context": {"parent_id": 2}, "status": "succeeded"}} +2022-12-05 19:46:46,748 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 3, "tags": {"stream": "child", "context": {"parent_id": 2}}} +2022-12-05 19:46:46,749 | INFO | my_tap | Beginning full_table sync of 'child' with context: {'parent_id': 3}... +2022-12-05 19:46:46,749 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.0004508495330810547, "tags": {"stream": "child", "context": {"parent_id": 3}, "status": "succeeded"}} +2022-12-05 19:46:46,750 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 3, "tags": {"stream": "child", "context": {"parent_id": 3}}} +2022-12-05 19:46:46,750 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.0052759647369384766, "tags": {"stream": "my_stream", "context": {}, "status": "succeeded"}} +2022-12-05 19:46:46,750 | INFO | singer_sdk.metrics | INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 3, "tags": {"stream": "my_stream", "context": {}}} +``` + +To use a different log format, see the [custom logging configuration](#custom-logging-configuration) section below. + ## Custom logging configuration Users of a tap can configure the SDK logging by setting the `SINGER_SDK_LOG_CONFIG` diff --git a/poetry.lock b/poetry.lock index 2d7434a9a..48d4c7054 100644 --- a/poetry.lock +++ b/poetry.lock @@ -199,7 +199,7 @@ PyGithub = "^1.55" type = "git" url = "https://github.com/meltano/commitizen-version-bump.git" reference = "main" -resolved_reference = "9279480a75c056262ba56f896ef9bca96c3b0c35" +resolved_reference = "6bbcff841ca62f79a05dc97d2c2175400453e5c2" [[package]] name = "cookiecutter" diff --git a/singer_sdk/default_logging.yml b/singer_sdk/default_logging.yml index c121fb47d..80b08059e 100644 --- a/singer_sdk/default_logging.yml +++ b/singer_sdk/default_logging.yml @@ -2,7 +2,7 @@ version: 1 disable_existing_loggers: false formatters: console: - format: "{asctime} {message}" + format: "{asctime:23s} | {levelname:8s} | {name:20s} | {message}" style: "{" handlers: default: @@ -11,5 +11,4 @@ handlers: stream: ext://sys.stderr root: level: INFO - propagate: true handlers: [default] diff --git a/singer_sdk/plugin_base.py b/singer_sdk/plugin_base.py index 0d4ba30db..561e4c5c3 100644 --- a/singer_sdk/plugin_base.py +++ b/singer_sdk/plugin_base.py @@ -63,17 +63,15 @@ def logger(cls) -> logging.Logger: Plugin logger. """ # Get the level from _LOGLEVEL or LOGLEVEL environment variables - LOGLEVEL = ( - os.environ.get(f"{cls.name.upper()}_LOGLEVEL") - or os.environ.get("LOGLEVEL") - or "INFO" - ).upper() - - assert ( - LOGLEVEL in logging._levelToName.values() - ), f"Invalid LOGLEVEL configuration: {LOGLEVEL}" + LOGLEVEL = os.environ.get(f"{cls.name.upper()}_LOGLEVEL") or os.environ.get( + "LOGLEVEL" + ) + logger = logging.getLogger(cls.name) - logger.setLevel(LOGLEVEL) + + if LOGLEVEL is not None and LOGLEVEL.upper() in logging._levelToName.values(): + logger.setLevel(LOGLEVEL.upper()) + return logger # Constructor