From b781c119f8ed42c7b9e99c50af0dec3d039a931c Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Mon, 5 Dec 2022 19:21:12 -0600 Subject: [PATCH 1/3] chore: pre-commit autoupdate (#1244) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit updates: - [github.com/asottile/pyupgrade: v3.2.2 → v3.3.0](https://github.com/asottile/pyupgrade/compare/v3.2.2...v3.3.0) - [github.com/python-poetry/poetry: 1.2.2 → 1.2.0rc1](https://github.com/python-poetry/poetry/compare/1.2.2...1.2.0rc1) Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com> --- .pre-commit-config.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml index e3b92b240..6a6aded72 100644 --- a/.pre-commit-config.yaml +++ b/.pre-commit-config.yaml @@ -63,7 +63,7 @@ repos: files: 'singer_sdk/.*' - repo: https://github.com/asottile/pyupgrade - rev: v3.2.2 + rev: v3.3.0 hooks: - id: pyupgrade args: [--py37-plus] From 48f20f4707cfaaee851e300b8d89255472d39c31 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Tue, 6 Dec 2022 09:34:15 -0600 Subject: [PATCH 2/3] chore(deps): Bump virtualenv from 20.17.0 to 20.17.1 in /.github/workflows (#1248) chore(deps): Bump virtualenv in /.github/workflows Bumps [virtualenv](https://github.com/pypa/virtualenv) from 20.17.0 to 20.17.1. - [Release notes](https://github.com/pypa/virtualenv/releases) - [Changelog](https://github.com/pypa/virtualenv/blob/main/docs/changelog.rst) - [Commits](https://github.com/pypa/virtualenv/compare/20.17.0...20.17.1) --- updated-dependencies: - dependency-name: virtualenv dependency-type: direct:production update-type: version-update:semver-patch ... Signed-off-by: dependabot[bot] Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> --- .github/workflows/constraints.txt | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/constraints.txt b/.github/workflows/constraints.txt index 9407df7e5..a834355a7 100644 --- a/.github/workflows/constraints.txt +++ b/.github/workflows/constraints.txt @@ -1,5 +1,5 @@ pip==22.3.1 poetry==1.2.2 -virtualenv==20.17.0 +virtualenv==20.17.1 nox==2022.11.21 nox-poetry==1.0.2 From c94ae175b4442f6a404c6e2d2663af42d3e634cc Mon Sep 17 00:00:00 2001 From: "Edgar R. M" Date: Tue, 6 Dec 2022 17:00:42 -0600 Subject: [PATCH 3/3] fix: Add level and logger name to default log format (#1233) --- docs/implementation/logging.md | 34 ++++++++++++++++++++++++++++++++-- poetry.lock | 2 +- singer_sdk/default_logging.yml | 3 +-- singer_sdk/plugin_base.py | 18 ++++++++---------- 4 files changed, 42 insertions(+), 15 deletions(-) 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