Adopt logging best practices (#23)

* fix: set NullHandler for package logger

* improv: remove root logger logic, lib

* fix: update exception type

* improv: propagate log level if set, null otherwise

* fix: explicit wins over env var

* chore: fix test naming

* fix: exception logging

* improv: shorten log location

* feat: add Logger class wrapper

* improv: add deprecation warning

* BREAKING CHANGE: logger_setup, inject_lambda_ctx

* improv: update tests

* improv: cover duplicated keys edge case

* improv: cover debug package logging

* improv: more coverage, linting

* improv: complete coverage, fix dead code

* docs: update readme to reflect changes

* fix: address jacob's code review feedback

* chore: linting

* fix: metric spillover at 100, not 101

* fix: trace auto-disable, doc edge cases

* chore: linting

* chore: 0.8.0 version bump

Co-authored-by: heitorlessa <[email protected]>

Author: heitorlessa

Diff for: README.md

@@ -1,6 +1,6 @@
 # Lambda Powertools
 
-![PackageStatus](https://img.shields.io/static/v1?label=status&message=beta&color=blueviolet?style=flat-square) ![PythonSupport](https://img.shields.io/static/v1?label=python&message=3.6%20|%203.7|%203.8&color=blue?style=flat-square&logo=python)
+![Python Build](https://github.com/awslabs/aws-lambda-powertools/workflows/Powertools%20Python/badge.svg?branch=master)
 
 A suite of utilities for AWS Lambda Functions that makes tracing with AWS X-Ray, structured logging and creating custom metrics asynchronously easier.
 

Diff for: python/HISTORY.md

@@ -1,5 +1,11 @@
 # HISTORY 
 
+## April 24th
+
+* Introduces `Logger` for stuctured logging as a replacement for `logger_setup`
+* Introduces `Logger.inject_lambda_context` decorator as a replacement for `logger_inject_lambda_context`
+* Raise `DeprecationWarning` exception for both `logger_setup`, `logger_inject_lambda_context`
+
 ## April 20th, 2020
 
 **0.7.0**

Diff for: python/README.md

@@ -13,7 +13,7 @@ A suite of utilities for AWS Lambda Functions that makes tracing with AWS X-Ray,
 > It currently uses AWS X-Ray
 
 * Decorators that capture cold start as annotation, and response and exceptions as metadata
-* Run functions locally without code change to disable tracing
+* Run functions locally with SAM CLI without code change to disable tracing
 * Explicitly disable tracing via env var `POWERTOOLS_TRACE_DISABLED="true"`
 
 **Logging**
@@ -24,6 +24,7 @@ A suite of utilities for AWS Lambda Functions that makes tracing with AWS X-Ray,
 * Logs canonical custom metric line to logs that can be consumed asynchronously
 * Log sampling enables DEBUG log level for a percentage of requests (disabled by default)
     - Enable via `POWERTOOLS_LOGGER_SAMPLE_RATE=0.1`, ranges from 0 to 1, where 0.1 is 10% and 1 is 100%
+* Append additional keys to structured log at any point in time so they're available across log statements
 
 **Metrics**
 
@@ -113,6 +114,8 @@ tracer = Tracer(auto_patch=False) # new instance using existing configuration wi
 
 ### Logging
 
+> **NOTE** `logger_setup` and `logger_inject_lambda_context` are deprecated and will be completely removed once it's GA.
+
 **Example SAM template using supported environment variables**
 
 ```yaml
@@ -128,13 +131,12 @@ Globals:
 **Pseudo Python Lambda code**
 
 ```python
-from aws_lambda_powertools.logging import logger_setup, logger_inject_lambda_context
+from aws_lambda_powertools.logging import Logger
 
-logger = logger_setup()  
-# logger_setup(service="payment") # also accept explicit service name
-# logger_setup(level="INFO") # also accept explicit log level
+logger = Logger()
+# Logger(service="payment", level="INFO") # also accepts explicit service name, log level
 
-@logger_inject_lambda_context
+@logger.inject_lambda_context
 def handler(event, context)
   logger.info("Collecting payment")
   ...
@@ -159,6 +161,7 @@ def handler(event, context)
    "lambda_function_arn":"arn:aws:lambda:eu-west-1:12345678910:function:test",
    "lambda_request_id":"52fdfc07-2182-154f-163f-5f0f9a621d72",
    "cold_start": "true",
+   "sampling_rate": 0.1,
    "message": "Collecting payment"
 }
 
@@ -172,13 +175,48 @@ def handler(event, context)
    "lambda_function_arn":"arn:aws:lambda:eu-west-1:12345678910:function:test",
    "lambda_request_id":"52fdfc07-2182-154f-163f-5f0f9a621d72",
    "cold_start": "true",
+   "sampling_rate": 0.1,
    "message":{  
       "operation":"collect_payment",
       "charge_id": "ch_AZFlk2345C0"
    }
 }
 ```
 
+**Append additional keys to structured log**
+
+```python
+from aws_lambda_powertools.logging import Logger
+
+logger = Logger()
+
+@logger.inject_lambda_context
+def handler(event, context)
+  if "order_id" in event:
+      logger.structure_logs(append=True, order_id=event["order_id"])
+  logger.info("Collecting payment")
+  ...
+```
+
+**Exerpt output in CloudWatch Logs**
+
+```json
+{  
+   "timestamp":"2019-08-22 18:17:33,774",
+   "level":"INFO",
+   "location":"collect.handler:1",
+   "service":"payment",
+   "lambda_function_name":"test",
+   "lambda_function_memory_size":"128",
+   "lambda_function_arn":"arn:aws:lambda:eu-west-1:12345678910:function:test",
+   "lambda_request_id":"52fdfc07-2182-154f-163f-5f0f9a621d72",
+   "cold_start": "true",
+   "sampling_rate": 0.1,
+   "order_id": "order_id_value",
+   "message": "Collecting payment"
+}
+```
+
 ### Custom Metrics async
 
 > **NOTE** `log_metric` will be removed once it's GA.
@@ -229,6 +267,7 @@ with single_metric(name="ColdStart", unit=MetricUnit.Count, value=1) as metric:
     metric.add_dimension(name="function_context", value="$LATEST")
 ```
 
+> **NOTE**: If you want to instantiate Metrics() in multiple places in your code, make sure to use `POWERTOOLS_METRICS_NAMESPACE` env var as we don't keep a copy of that across instances.
 
 ### Utilities
 
@@ -320,12 +359,19 @@ def lambda_handler(event, context):
     return True
 ```
 
-## Beta
 
-> **[Progress towards GA](https://github.com/awslabs/aws-lambda-powertools/projects/1)**
+### Debug mode
+
+By default, all debug log statements from AWS Lambda Powertools package are suppressed. If you'd like to enable them, use `set_package_logger` utility:
+
+```python
+import aws_lambda_powertools
+aws_lambda_powertools.logging.logger.set_package_logger()
+...
+```
+
+## Beta
 
-This library may change its API/methods or environment variables as it receives feedback from customers. Currently looking for ideas in the following areas before making it stable:
+This library may change its API/methods or environment variables as it receives feedback from customers
 
-* **Should Tracer patch all possible imported libraries by default or only AWS SDKs?**
-    - Patching all libraries may have a small performance penalty (~50ms) at cold start
-    - Alternatively, we could patch only AWS SDK if available and to provide a param to patch multiple `Tracer(modules=("boto3", "requests"))` 
+**[Progress towards GA](https://github.com/awslabs/aws-lambda-powertools/projects/1)**

Diff for: python/aws_lambda_powertools/__init__.py

@@ -1,5 +1,10 @@
 # -*- coding: utf-8 -*-
 
 """Top-level package for Lambda Python Powertools."""
+import logging
 
 __author__ = """Amazon Web Services"""
+
+logger = logging.getLogger("aws_lambda_powertools")
+logger.addHandler(logging.NullHandler())
+logger.propagate = False

Diff for: python/aws_lambda_powertools/logging/__init__.py

@@ -1,6 +1,6 @@
 """Logging utility
 """
 from ..helper.models import MetricUnit
-from .logger import log_metric, logger_inject_lambda_context, logger_setup
+from .logger import Logger, log_metric, logger_inject_lambda_context, logger_setup
 
-__all__ = ["logger_setup", "logger_inject_lambda_context", "log_metric", "MetricUnit"]
+__all__ = ["logger_setup", "logger_inject_lambda_context", "log_metric", "MetricUnit", "Logger"]

Diff for: python/aws_lambda_powertools/logging/aws_lambda_logging.py

@@ -0,0 +1,2 @@
+class InvalidLoggerSamplingRateError(Exception):
+    pass