feat: Allow configuring a dedicated metrics logger (#978)

Co-authored-by: Aaron ("AJ") Steers <[email protected]>

docs/implementation/logging.md

@@ -1,5 +1,49 @@
 # Logging
 
-Logs are configurable by the environment variables `<PLUGIN_NAME>_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 `<PLUGIN_NAME>_LOGLEVEL` for more granual control of each tap or target individually.
+Logs are configurable by the environment variables `<PLUGIN_NAME>_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
+`<PLUGIN_NAME>_LOGLEVEL` for more granual control of each tap or target individually.
 
-From most verbose to least verbose, the accepted values for logging level are `debug`, `info`, `warning`, and `error`. Logging level inputs are case insensitive.
+From most verbose to least verbose, the accepted values for logging level are `debug`,
+`info`, `warning`, and `error`. Logging level inputs are case-insensitive.
+
+## Custom logging configuration
+
+Users of a tap can configure the SDK logging by setting the `SINGER_SDK_LOG_CONFIG`
+environment variable. The value of this variable should be a path to a YAML file in the
+[Python logging dict format](https://docs.python.org/3/library/logging.config.html#dictionary-schema-details).
+
+For example, to send [metrics](./metrics.md) (with logger name `singer_sdk.metrics`) to a file, you could use the following config:
+
+```yaml
+version: 1
+disable_existing_loggers: false
+formatters:
+  metrics:
+    format: "{asctime} {message}"
+    style: "{"
+handlers:
+  metrics:
+    class: logging.FileHandler
+    formatter: metrics
+    filename: metrics.log
+loggers:
+  singer_sdk.metrics:
+    level: INFO
+    handlers: [ metrics ]
+    propagate: yes
+```
+
+This will send metrics to a `metrics.log`:
+
+```
+2022-09-29 00:48:52,746 INFO METRIC: {"metric_type": "timer", "metric": "http_request_duration", "value": 0.501743, "tags": {"stream": "continents", "endpoint": "", "http_status_code": 200, "status": "succeeded"}}
+2022-09-29 00:48:52,775 INFO METRIC: {"metric_type": "counter", "metric": "http_request_count", "value": 1, "tags": {"stream": "continents", "endpoint": ""}}
+2022-09-29 00:48:52,776 INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.7397160530090332, "tags": {"stream": "continents", "context": {}, "status": "succeeded"}}
+2022-09-29 00:48:52,776 INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 7, "tags": {"stream": "continents", "context": {}}}
+2022-09-29 00:48:53,225 INFO METRIC: {"metric_type": "timer", "metric": "http_request_duration", "value": 0.392148, "tags": {"stream": "countries", "endpoint": "", "http_status_code": 200, "status": "succeeded"}}
+2022-09-29 00:48:53,302 INFO METRIC: {"metric_type": "counter", "metric": "http_request_count", "value": 1, "tags": {"stream": "countries", "endpoint": ""}}
+2022-09-29 00:48:53,302 INFO METRIC: {"metric_type": "timer", "metric": "sync_duration", "value": 0.5258760452270508, "tags": {"stream": "countries", "context": {}, "status": "succeeded"}}
+2022-09-29 00:48:53,303 INFO METRIC: {"metric_type": "counter", "metric": "record_count", "value": 250, "tags": {"stream": "countries", "context": {}}}
+```

docs/implementation/metrics.md

@@ -2,17 +2,21 @@
 
 Metrics logging is specified in the
 [Singer Spec](https://hub.meltano.com/singer/spec#metrics). The SDK will automatically
-emit two types of metrics `record_count` and `http_request_duration`.
+emit metrics for `record_count`, `http_request_duration` and `sync_duration`.
 
-Customization options:
+## Customization options
 
-Developers may optionally add a `metrics_log_level` config option to their taps,
-which will automatically allow this metrics logging to be customized at runtime.
+### `metrics_log_level`
 
-When `metrics_log_level` is supported, users can then
-set one of these values (case insensitive), `INFO`, `DEBUG`, `NONE`, to override the
-default logging level for metrics. This can be helpful for REST-type sources which use
-make a large number of REST calls can therefor have very noisy metrics.
+Metrics are logged at the `INFO` level. Developers may optionally add a
+`metrics_log_level` config option to their taps, `WARNING` or `ERROR` to disable
+metrics logging.
+
+### `SINGER_SDK_LOG_CONFIG`
+
+Metrics are written by the `singer_sdk.metrics` logger, so the end user can set
+`SINGER_SDK_LOG_CONFIG` to a logging config file that defines the format and output
+for metrics. See the [logging docs](./logging.md) for an example file.
 
 ## Additional Singer Metrics References
 

noxfile.py

@@ -42,6 +42,7 @@ def mypy(session: Session) -> None:
         "types-requests",
         "types-pytz",
         "types-simplejson",
+        "types-PyYAML",
     )
     session.run("mypy", *args)
     if not session.posargs:

pyproject.toml

@@ -44,6 +44,7 @@ PyJWT = "~=2.4"
 requests = "^2.25.1"
 cryptography = ">=3.4.6,<39.0.0"
 importlib-metadata = {version = "*", markers = "python_version < \"3.8\""}
+importlib-resources = {version = "^5.9.0", markers = "python_version < \"3.9\""}
 memoization = ">=0.3.2,<0.5.0"
 jsonpath-ng = "^1.5.3"
 joblib = "^1.0.1"
@@ -54,6 +55,7 @@ typing-extensions = "^4.2.0"
 simplejson = "^3.17.6"
 jsonschema = "^4.16.0"
 pytz = "^2022.2.1"
+PyYAML = "^6.0"
 
 # Sphinx dependencies installed as optional 'docs' extras
 # https://github.com/readthedocs/readthedocs.org/issues/4912#issuecomment-664002569
@@ -89,6 +91,7 @@ types-python-dateutil = "^2.8.19"
 types-pytz = "^2022.2.1.0"
 types-requests = "^2.28.11"
 types-simplejson = "^3.17.7"
+types-PyYAML = "^6.0.12"
 coverage = {extras = ["toml"], version = "^6.5"}
 
 # Cookiecutter tests

singer_sdk/default_logging.yml

@@ -0,0 +1,15 @@
+version: 1
+disable_existing_loggers: false
+formatters:
+  console:
+    format: "{asctime} {message}"
+    style: "{"
+handlers:
+  default:
+    class: logging.StreamHandler
+    formatter: console
+    stream: ext://sys.stderr
+root:
+  level: INFO
+  propagate: true
+  handlers: [default]

singer_sdk/helpers/_resources.py

@@ -0,0 +1,24 @@
+from __future__ import annotations
+
+import sys
+from types import ModuleType
+
+if sys.version_info >= (3, 9):
+    import importlib.resources as importlib_resources
+    from importlib.abc import Traversable
+else:
+    import importlib_resources
+    from importlib_resources.abc import Traversable
+
+
+def get_package_files(package: str | ModuleType) -> Traversable:
+    """Load a file from a package.
+
+    Args:
+        package: The package to load the file from.
+        file: The file to load.
+
+    Returns:
+        The file as a Traversable object.
+    """
+    return importlib_resources.files(package)