All right! We have two elements implemented - Traces and Metrics. Let's do the same with the last element of Observability - Logs
Preparations
We did it previously, and we need to repeat the step with updating the SAM template. The variables we need this time are:
LOG_LEVEL: "INFO"
POWERTOOLS_SERVICE_NAME: simpleFunctionService
POWERTOOLS_SERVICE_NAME we already have. LOG_LEVEL set the level of the "logging intensity". We can use INFO, which is default value, or DEBUG.
Decorate the handler
Logs
We have this part:
from aws_lambda_powertools import Tracer, Metrics
from aws_lambda_powertools.metrics import MetricUnit
tracer = Tracer()
metrics = Metrics()
Let's update it with logging functionality.
from aws_lambda_powertools import Tracer, Metrics, Logger
from aws_lambda_powertools.metrics import MetricUnit
tracer = Tracer()
metrics = Metrics()
logger = Logger()
Ok, we have this part, now it is time to add decorator.
@metrics.log_metrics(capture_cold_start_metric=True)
@tracer.capture_lambda_handler
@logger.inject_lambda_context(log_event=True)
def handler(event, context):
Let's deploy it and take a look on CloudWatch Logs.
Wow, now we have the logs!
Do you remember the three entries with very little information from the beginning of this tutorial? now it looks... better.
Let's take a look on a few examples of logs:
{
"level": "INFO",
"location": "decorate:345",
"message": {
"resource": "/",
"path": "/",
"httpMethod": "GET",
"headers": {
"CloudFront-Forwarded-Proto": "https",
"CloudFront-Is-Desktop-Viewer": "true",
"CloudFront-Is-Mobile-Viewer": "false",
"CloudFront-Is-SmartTV-Viewer": "false",
"CloudFront-Is-Tablet-Viewer": "false",
"CloudFront-Viewer-Country": "PL",
"Host": "xxxx.execute-api.eu-central-1.amazonaws.com",
"User-Agent": "Mozilla/5.0 (Windows NT; Windows NT 10.0; pl-PL) WindowsPowerShell/5.1.19041.1320",
"Via": "1.1 xxxxxx.cloudfront.net (CloudFront)",
"X-Amz-Cf-Id": "xxxxxxxxxx==",
"X-Amzn-Trace-Id": "Root=1-61ae4ae5-0e2127a8181ee95663f955f5",
"X-Forwarded-For": "xx.xx.xx.xx",
"X-Forwarded-Port": "443",
"X-Forwarded-Proto": "https"
},
"multiValueHeaders": {
"CloudFront-Forwarded-Proto": [
"https"
],
"CloudFront-Is-Desktop-Viewer": [
"true"
],
"CloudFront-Is-Mobile-Viewer": [
"false"
],
"CloudFront-Is-SmartTV-Viewer": [
"false"
],
"CloudFront-Is-Tablet-Viewer": [
"false"
],
"CloudFront-Viewer-Country": [
"PL"
],
"Host": [
"xxxxxx.execute-api.eu-central-1.amazonaws.com"
],
"User-Agent": [
"Mozilla/5.0 (Windows NT; Windows NT 10.0; pl-PL) WindowsPowerShell/5.1.19041.1320"
],
"Via": [
"1.1 xxxxxf.cloudfront.net (CloudFront)"
],
"X-Amz-Cf-Id": [
"xxxxxxxx=="
],
"X-Amzn-Trace-Id": [
"Root=1-61ae4ae5-0e2127a8181ee95663f955f5"
],
"X-Forwarded-For": [
"xx.xx.xx.xx"
],
"X-Forwarded-Port": [
"443"
],
"X-Forwarded-Proto": [
"https"
]
},
"queryStringParameters": null,
"multiValueQueryStringParameters": null,
"pathParameters": null,
"stageVariables": null,
"requestContext": {
"resourceId": "xxxxxxxx",
"resourcePath": "/",
"httpMethod": "GET",
"extendedRequestId": "J8Cj9GXJFiAFWww=",
"requestTime": "06/Dec/2021:17:39:49 +0000",
"path": "/Prod",
"accountId": "xxxxxxxxx",
"protocol": "HTTP/1.1",
"stage": "Prod",
"domainPrefix": "xxxxxxx",
"requestTimeEpoch": 1638812389988,
"requestId": "9b468736-310c-4b0d-8326-1ac19897435a",
"identity": {
"cognitoIdentityPoolId": null,
"accountId": null,
"cognitoIdentityId": null,
"caller": null,
"sourceIp": "xx.xx.xx.xx",
"principalOrgId": null,
"accessKey": null,
"cognitoAuthenticationType": null,
"cognitoAuthenticationProvider": null,
"userArn": null,
"userAgent": "Mozilla/5.0 (Windows NT; Windows NT 10.0; pl-PL) WindowsPowerShell/5.1.19041.1320",
"user": null
},
"domainName": "xxxxx.execute-api.eu-central-1.amazonaws.com",
"apiId": "xxxxx"
},
"body": null,
"isBase64Encoded": false
},
"timestamp": "2021-12-06 17:39:50,675+0000",
"service": "simpleFunctionService",
"cold_start": true,
"function_name": "lambdaDemo-lambdaFunction-sfSnGT61RScH",
"function_memory_size": "128",
"function_arn": "arn:aws:lambda:eu-central-1:xxxxxx:function:lambdaDemo-lambdaFunction-sfSnGT61RScH:live",
"function_request_id": "de20ea17-289e-4475-88a1-d8b165b24e6f",
"xray_trace_id": "1-61ae4ae5-0e2127a8181ee95663f955f5"
}
This looks better, doesn't it?
Correlation ID
Let's add something what is called correlation ID. What it is? Well, simply speaking it is a GUID (Globally Unique IDentifier) of the request, automatically generated by API Gateway.
Add to our imports:
from aws_lambda_powertools.logging import correlation_paths
And update our decorator:
@logger.inject_lambda_context(log_event=True, correlation_id_path=correlation_paths.API_GATEWAY_REST)
We should confirm it after deployment... And yes, we have it:
{
"function_request_id": "0aa7cecf-1488-4ed1-95a6-0c5bbaf24cba",
"correlation_id": "e91b1f50-f96f-44c8-be62-0d6c1dc95833",
"xray_trace_id": "1-61ae4f32-52f3b3b64de440660f262783"
}
Instrument functions
Now it is time for the last experiment. Let's instrument each function and have a log from each of them. Update the code to this form for each mathematical functions of our example:
@tracer.capture_method
def sumnumbers(a, b):
""" simple function """
logger.info("Executing sumNumbers")
result = a + b
tracer.put_annotation("operationStatus", "success")
tracer.put_annotation("operationResult", result)
metrics.add_metric(name="sumNumbers", unit=MetricUnit.Count, value=1)
message = "sumNumbers result is: {}".format(result)
logger.info(message)
return result
Ok, let's take a look on the log now. We can see mulitple lines of structurized log, where we have not only the message we designed, but more information.
How useful is it?
You may ask "Why we did all of that?" Well, the answer is simple.
- We know exactly what our function is doing
- We know exactly how our function is performing
- We are able to catch easily every single bottleneck in the system
- We can track every single request through the whole system
And more, but let me leave you here :)
How to track requests? I am sure you remember when we added correlation_id to our log. This information is taken from API, using this setting in decorator correlation_id_path=correlation_paths.API_GATEWAY_REST. And we are able to track it through multiple functions. Of course in this example we have only one, but nothing stops us from use it in more wider scope.
For now, let's go to AWS CloudWatch Logs Insights, select all logs you have (yeah, why not :) ) and run this simple query (change the value of correlation_id, of course!)
filter correlation_id="98160ea8-ea2e-4e3f-a322-ea30b945b066"
And... we have all occurences of this specific id through the system!
Now you can go crazy with logging. The topic here is very wide, so... go and play with it!
Top comments (0)