Emit logs in JSON format #101

kotyara1005 · 2023-05-15T16:59:51Z

Description:
This PR adds structured logging support for lambda functions.
Log format and level now encoded into message header.
User are able to set format and level through the environment variables AWS_LAMBDA_LOG_FORMAT and AWS_LAMBDA_LOG_LEVEL.

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

kotyara1005 · 2023-05-16T10:38:21Z

ping @luben

luben · 2023-05-16T11:20:10Z

awslambdaric/lambda_runtime_log_utils.py

+    def format_stacktrace(self, exc_info):
+        if not exc_info:
+            return None
+        return self.formatException(exc_info)


I think this should be:

return traceback.format_tb(exc_info[2])

so we get the trace as an array of frames, not as a string

luben · 2023-05-16T11:36:59Z

awslambdaric/lambda_runtime_log_utils.py

+
+
+def lambda_instance_logs_update(key: str, value: str):
+    INSTANCE_LOGGING_CONTEXT[str(key)] = str(value)


why str(value)? I think the value should not be stringified - customer may want to attach an object/dict there that will be rendered as such in JSON

luben · 2023-05-16T13:11:55Z

awslambdaric/bootstrap.py

@@ -367,9 +368,29 @@ def create_log_sink():
        return StandardLogSink()


+AWS_LAMBDA_LOG_FORMAT = os.environ.get("AWS_LAMBDA_LOG_FORMAT", "TEXT")


We should also take into account the AWS_LAMBDA_LOG_LEVEL envvar ans set the logger verbosity accordingly

luben · 2023-05-17T16:21:08Z

awslambdaric/bootstrap.py

@@ -367,9 +368,31 @@ def create_log_sink():
        return StandardLogSink()


+AWS_LAMBDA_LOG_FORMAT = os.environ.get("AWS_LAMBDA_LOG_FORMAT", "TEXT")
+AWS_LAMBDA_LOG_LEVEL = os.environ.get("AWS_LAMBDA_LOG_LEVEL", "INFO")


If this is envvar is not set, we should not default the filtering to info. I the envvar is not set we will not apply the fiter

luben · 2023-05-17T16:46:55Z

awslambdaric/bootstrap.py

+    if log_format == "JSON":
+        logger_handler.setFormatter(JsonFormatter())
+        logging._levelToName[logging.CRITICAL] = "FATAL"
+        logger.setLevel(log_level)


the log level should be set for both Text and JSON is it's defined

thenewguy39 · 2023-05-18T16:51:14Z

Please set flag from Text to JSON in frame header.

luben · 2023-05-23T13:34:12Z

awslambdaric/bootstrap.py

+
+    @staticmethod
+    def set_log_format(frame_type, log_format):
+        if log_format == "JSON":


Should we not create new enum here:

class TextFormat(Enum): JSON=0 TEXT=1 ... def log(self, msg, log_level=logging.NOTSET, log_format: LogFormat: ... frame_type = frame_type | log_format.value

luben · 2023-05-23T13:39:08Z

awslambdaric/bootstrap.py

@@ -347,7 +379,7 @@ def log(self, msg):

    def log_error(self, message_lines):
        error_message = "\n".join(message_lines)
-        self.log(error_message)
+        self.log(error_message, log_level=logging.FATAL)


I think this should be ERROR - at least this is what we use today, e.g. [ERROR] ZeroDivisionError: division by zero

luben · 2023-05-31T20:59:16Z

LGTM

luben · 2023-06-09T10:12:12Z

awslambdaric/bootstrap.py

@@ -333,20 +385,27 @@ def __enter__(self):
    def __exit__(self, exc_type, exc_value, exc_tb):
        self.file.close()

-    def log(self, msg):
+    def set_log_level(self, frame_type, log_level):


Can you inline this function? I think if we expose that name, customer will think that they can change the log level.

awslambdaric/bootstrap.py

tests/test_bootstrap.py

awslambdaric/lambda_runtime_marshaller.py

awslambdaric/bootstrap.py

alex-pewpew · 2023-08-15T12:15:36Z

awslambdaric/bootstrap.py

@@ -333,20 +395,22 @@ def __enter__(self):
    def __exit__(self, exc_type, exc_value, exc_tb):
        self.file.close()

-    def log(self, msg):
+    def log(self, msg, log_level=logging.NOTSET, log_format: int = _TEXT_FORMAT):
+        frame_type = FRAME_TYPES.get((log_format, log_level), DEFAULT_FRAME_TYPE)


For existing customers this is going to create new tuple objects and do hashtable lookups. Not too big of a problem, but can we avoid it for the sake of cleaner implementation?

Yes, moved to formatter.

alex-pewpew · 2023-08-15T12:19:48Z

awslambdaric/bootstrap.py

            + len(encoded_msg).to_bytes(4, "big")
            + timestamp.to_bytes(8, "big")
            + encoded_msg
        )
        self.file.write(log_msg)

-    def log_error(self, message_lines):
+    def log_error(self, message_lines, log_level=logging.ERROR):


With feature enabled, is there need in this method? Are jsons multiline too?

This method is used by log_error(error_result, log_sink) function.

alex-pewpew · 2023-08-15T12:22:30Z

awslambdaric/bootstrap.py

@@ -370,6 +434,28 @@ def create_log_sink():
 _GLOBAL_AWS_REQUEST_ID = None


+def setup_logging(log_format, log_level, log_sink):
+    logging._levelToName[logging.CRITICAL] = "FATAL"


Is it going to affect existing customers who are structuring their logging themselves?

We do not need it anymore.

awslambdaric/bootstrap.py

alex-pewpew · 2023-08-17T11:44:38Z

awslambdaric/lambda_runtime_marshaller.py

@@ -13,8 +13,8 @@
 # simplejson's Decimal encoding allows '-NaN' as an output, which is a parse error for json.loads
 # to get the good parts of Decimal support, we'll special-case NaN decimals and otherwise duplicate the encoding for decimals the same way simplejson does
 class Encoder(json.JSONEncoder):
-    def __init__(self):
-        super().__init__(use_decimal=False)
+    def __init__(self, ensure_ascii=True):


Where is this overload used?

alex-pewpew · 2023-08-17T12:01:11Z

awslambdaric/bootstrap.py

+        )
+
+    if log_level:
+        logger.setLevel(log_level)


Should we put this part under if log_format == LogFormat.JSON: condition?

In case of incorrect value, should we gracefully handle it?

Example:
Code looks like

logging.addLevelName(33, "PEW") def lambda_handler(): logging.addLevelName(42, "PEWPEW")

Natural desire would be to use env variable to limit log level to PEWPEW or PEW, but at the moment of running setup_logging it's not yet registered.
Adding levels in a handler looks quite strange, but natural at INIT phase. If the intention is to support custom log levels, need to setLevel at least after INIT

Yeah let's move it

Let's restrict to standard levels only

alex-pewpew · 2023-08-17T12:14:49Z

awslambdaric/bootstrap.py

-        self.log_sink.log(msg)
+
+        self.log_sink.log(
+            msg, frame_type=getattr(record, "_frame_type", _FRAME_TYPES.get(()))


Should _FRAME_TYPES.get(()) be replaced with just None ?

Nit: Is there any value for attribute lookup for non-JSON logging? If no, would be cleaner to avoid doing it

Yeah, it's a leftover

There is no value in attribute lookup here. But I'm not sure how to avoid it.

alex-pewpew · 2023-08-17T12:26:17Z

awslambdaric/bootstrap.py

@@ -370,6 +416,27 @@ def create_log_sink():
 _GLOBAL_AWS_REQUEST_ID = None


+def setup_logging(log_format, log_level, log_sink):


Let's hide this behind an _

luben

LGTM

alex-pewpew

Please

Squash your feature commits to make history cleaner
Improve PR description

awslambdaric/bootstrap.py

alex-pewpew · 2023-08-20T18:37:12Z

awslambdaric/lambda_runtime_log_utils.py

+        super().__init__(datefmt=_DATETIME_FORMAT)
+
+    @staticmethod
+    def format_stacktrace(exc_info):


This method and below - are they supposed to be private? If yes, let's have them mangled with __

awslambdaric/lambda_runtime_log_utils.py

alex-pewpew · 2023-08-21T17:14:43Z

LGTM

awslambdaric/lambda_runtime_client.py

setup.py

briensea requested review from briensea and alex-pewpew May 16, 2023 07:17

luben suggested changes May 16, 2023

View reviewed changes

luben reviewed May 16, 2023

View reviewed changes

kotyara1005 requested a review from luben May 16, 2023 15:20

luben reviewed May 17, 2023

View reviewed changes

kotyara1005 requested a review from luben May 18, 2023 08:12

luben reviewed May 23, 2023

View reviewed changes

kotyara1005 requested a review from luben May 24, 2023 15:39

luben approved these changes Jun 7, 2023

View reviewed changes

luben suggested changes Jun 9, 2023

View reviewed changes

kotyara1005 requested a review from luben June 12, 2023 16:33

alex-pewpew reviewed Aug 15, 2023

View reviewed changes

kotyara1005 requested a review from alex-pewpew August 15, 2023 18:37

alex-pewpew reviewed Aug 17, 2023

View reviewed changes

luben approved these changes Aug 18, 2023

View reviewed changes

kotyara1005 requested a review from alex-pewpew August 18, 2023 17:10

alex-pewpew reviewed Aug 20, 2023

View reviewed changes

kotyara1005 force-pushed the struct-logging branch from 66ef14d to 4aae5fe Compare August 21, 2023 10:46

kotyara1005 requested a review from alex-pewpew August 21, 2023 10:48

kotyara1005 force-pushed the struct-logging branch 2 times, most recently from 0fa37f2 to f7e8115 Compare August 21, 2023 16:18

alex-pewpew approved these changes Aug 21, 2023

View reviewed changes

briensea requested changes Aug 21, 2023

View reviewed changes

awslambdaric/lambda_runtime_client.py Outdated Show resolved Hide resolved

setup.py Outdated Show resolved Hide resolved

Add structured logging implementation

365c3b8

kotyara1005 force-pushed the struct-logging branch from f7e8115 to 365c3b8 Compare August 22, 2023 09:44

kotyara1005 requested a review from briensea August 22, 2023 09:45

briensea approved these changes Aug 22, 2023

View reviewed changes

briensea merged commit 8b34c48 into aws:main Aug 22, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Emit logs in JSON format #101

Emit logs in JSON format #101

kotyara1005 commented May 15, 2023 •

edited

Loading

kotyara1005 commented May 16, 2023 •

edited

Loading

luben May 16, 2023

luben May 16, 2023

luben May 16, 2023

luben May 17, 2023

luben May 17, 2023

thenewguy39 commented May 18, 2023 •

edited

Loading

luben May 23, 2023 •

edited

Loading

luben May 23, 2023 •

edited

Loading

luben commented May 31, 2023

luben Jun 9, 2023

alex-pewpew Aug 15, 2023

kotyara1005 Aug 15, 2023

alex-pewpew Aug 15, 2023

kotyara1005 Aug 15, 2023

alex-pewpew Aug 15, 2023

kotyara1005 Aug 15, 2023

alex-pewpew Aug 17, 2023

kotyara1005 Aug 17, 2023

alex-pewpew Aug 17, 2023

kotyara1005 Aug 17, 2023

alex-pewpew Aug 17, 2023

kotyara1005 Aug 17, 2023

alex-pewpew Aug 17, 2023

luben left a comment

alex-pewpew left a comment

alex-pewpew Aug 20, 2023

alex-pewpew commented Aug 21, 2023



		def lambda_instance_logs_update(key: str, value: str):
		INSTANCE_LOGGING_CONTEXT[str(key)] = str(value)

		@@ -367,9 +368,29 @@ def create_log_sink():
		return StandardLogSink()


		AWS_LAMBDA_LOG_FORMAT = os.environ.get("AWS_LAMBDA_LOG_FORMAT", "TEXT")

		@@ -370,6 +416,27 @@ def create_log_sink():
		_GLOBAL_AWS_REQUEST_ID = None


		def setup_logging(log_format, log_level, log_sink):

Emit logs in JSON format #101

Emit logs in JSON format #101

Conversation

kotyara1005 commented May 15, 2023 • edited Loading

kotyara1005 commented May 16, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thenewguy39 commented May 18, 2023 • edited Loading

luben May 23, 2023 • edited Loading

Choose a reason for hiding this comment

luben May 23, 2023 • edited Loading

Choose a reason for hiding this comment

luben commented May 31, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

luben left a comment

Choose a reason for hiding this comment

alex-pewpew left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alex-pewpew commented Aug 21, 2023

kotyara1005 commented May 15, 2023 •

edited

Loading

kotyara1005 commented May 16, 2023 •

edited

Loading

thenewguy39 commented May 18, 2023 •

edited

Loading

luben May 23, 2023 •

edited

Loading

luben May 23, 2023 •

edited

Loading