Introduction to AWS Log Insights as CloudWatch Metrics

Recently I started using and I find the tool really useful to extract data about the systems I'm running without having to set up dedicated monitoring tools, which come with their own set of permissions, rules, configuration language, and so forth. AWS CloudWatch Log Insights Log Insights allow you to query log outputs with a language based on regular expressions with hints of SQL and to produce tables or graphs of quantities that you need to monitor. For example, the system I am monitoring runs Celry in ECS containers that log received tasks with a line like the following 16:39:11,156 [32mINFO [0m [34m[celery.worker.strategy][0m [01mReceived task: lib.tasks.lists.trigger_list_log_notification[9b33b464-d4f9-4909-8d4e-1a3134fead97] [0m In this case the specific function in the system that was triggered is , and I'm interested in knowing which functions are called the most, so I can easily count them with lib.tasks.log_notification parse @message /\[celery\.(? [a-z.]+)\].*Received task: (? [a-z._]+)\[/ | filter not isblank(source) | stats count(*) as number by task | sort number desc | limit 9 This gives me a nice table of the top 9 functions and the number of submitted for each, and the time frame can be adjusted with the usual CloudWatch controls source task 1 lib.tasks.lists.trigger_list_log_notification 4559 2 lib.tasks.notify.notify_recipient 397 3 lib.message._send_mobile_push_notification 353 4 lib.tasks.jobs.check_job_cutoffs 178 5 lib.tasks.notify.check_message_cutoffs 177 6 lib.tasks.notify.check_notification_retry 177 7 lib.tasks.notify.async_list_response 81 8 lib.tasks.hmrc_poll.govtalk_periodic_poll 59 9 lib.tasks.lists.recalculate_list_entry 56 Using time bins, quantities can also be easily plotted. For example, I can process and visualise the number of received tasks with parse @message /\[celery\.(? [a-z.]+)\].*Received task: (? [a-z._]+)\[/ | filter not isblank(source) | stats count(*) by bin(30s) Unfortunately, I quickly discovered an important limitation of Log Insights, that is . Which also immediately implies that I can't set up alarms on those queries. As fun as it is to look at nice plots, I need something automatic that sends me messages or scales up systems in reaction to specific events such as "too many submitted tasks". queries are not metrics The standard solution to this problem suggested by AWS is to write a Lambda that runs the query and stores the value into a custom CloudWatch metric, which I can then use to satisfy my automation needs. I did it, and in this post I will show you exactly how, using Terraform, Python and Zappa, CloudWatch, and DynamoDB. At the end of the post I will also briefly discuss the cost of the solution. The big picture Before I get into the details of the specific tools or solutions that I decided to implement, let me have a look at the bigger picture. The initial idea is very simple: a Lambda function can run a specific Log Insights query and store the results in a custom metric, which can in turn be used to trigger alarms and other actions. For a single system I already have 4 or 5 of these queries that I'd like to run, and I have multiple systems, so I'd prefer to have a solution that doesn't require me to deploy and maintain a different Lambda for each query. The maintenance can be clearly automated as well, but such a solution smells of duplicated code miles away, and if there is no specific reason to go down that road I prefer to avoid it. Since Log Insights queries are just strings of code, however, we can store them somewhere and then simply loop on all of them within the same Lambda function. To implement this, I created a DynamoDB table and every element contains all the data I need to run each query, such as the log group that I want to investigate and the name of the target metric. Terraform In the following sections, I will discuss the main components of the solution from the infrastructural point of view, showing how I created them with Terraform. The four main AWS services that I will use are: , , , . DynamoDB Lambda IAM CloudWatch I put the bulk of the code in a module so that I can easily create the same structure for multiple AWS accounts. While my current setup is a bit more complicated that that, the structure of the code can be simplified as + common + lambda-loginsights2metrics + cloudwatch.tf + dynamodb.tf + iam.tf + lambda.tf + variables.tf + account1 + lambda-loginsights2metrics + main.tf + variables.tf Variables Since I will refer to them in the following sections, let me show you the four variables I defined for this module. First I need to receive the items that I need to store in the DynamoDB table common/lambda-loginsights2metrics/variables.tf variable { = = [] } "items" type "list" default I prefer to have a prefix in front of my components that allows me to duplicate them without clashes common/lambda-loginsights2metrics/variables.tf variable { = = } "prefix" type "string" default "loginsights2metrics" The Lambda function will require a list of security groups that grant access to specific network components common/lambda-loginsights2metrics/variables.tf variable { = = [] } "security_groups" type "list" default Finally, Lambda functions need to be told which VPC subnets they can use to run common/lambda-loginsights2metrics/variables.tf variable { = = [] } "vpc_subnets" type "list" default Resources . Terraform variables DynamoDB Let's start with the corner stone, which is the DynamoDB table that contains data for the queries. As DynamoDB is not a SQL database we don't need to define columns in advance. This clearly might get us into trouble later, so we need to be careful and be consistent when we write items, adding everything is needed by the Lambda code. common/lambda-loginsights2metrics/dynamodb.tf resource { name = billing_mode = hash_key = attribute { name = = } } "aws_dynamodb_table" "loginsights2metrics" " -items" ${var.prefix} "PAY_PER_REQUEST" "SlotName" "SlotName" type "S" Speaking of items, I assume I will pass them when I call the module, so here I just need to loop on the input variable items common/lambda-loginsights2metrics/dynamodb.tf resource { count = length( .items) table_name = aws_dynamodb_table hash_key = aws_dynamodb_table item = jsonencode(element( , count.index)) } "aws_dynamodb_table_item" "item" var .loginsights2metrics .name .loginsights2metrics .hash_key var .items Since the query is written as a Terraform string and will be read from Python there are two small caveats here. To be consistent with Terraform's syntax we need to escape double quotes in the query, and to avoid fights with Python we need to escape backslashes. So for example a valid query like parse @message /\[celery\.(? [a-z.]+)\].*Received task: (? [a-z._]+)\[/ | filter not isblank(source) | stats count(*) as Value by bin(1m) will be stored as "parse @message /\\[celery\\.(? [a-z.]+)\\].*Received task: (? [a-z._]+)\\[/ | filter not isblank(source) | stats count(*) as Value by bin(1m)" Another remark is that the Lambda I will write in Python will read data plotted with the name on bins of 1 minute, so the query should end with where is a specific stat, for example . Value stats X as Value by bin(1m) X stats count(*) as Value by bin(1m) The reason behind 1 minute is that the maximum standard resolution of CloudWatch metrics is 1 minute. Should you want more you need to have a look at . CloudWatch High-Resolution Metrics Resources Amazon DynamoDB aws_dynamodb_table documentation aws_dynamodb_table_item documentation IAM part 1 IAM roles are central in AWS. In this specific case we have the so-called , which is the IAM role that the Lambda assumes when you run it. In AWS users or services (that is humans or AWS components) a role, receiving the permissions connected with it. To assume roles, however, they need to have a specific permission, a so-called . Lambda execution role assume trust policy Let's define a trust policy that allows the Lambda service to assume the role that we will define common/lambda-loginsights2metrics/iam.tf data { statement { actions = [ ] principals { = identifiers = [ ] } } } "aws_iam_policy_document" "trust" "sts:AssumeRole" type "Service" "lambda.amazonaws.com" and after that the role in question common/lambda-loginsights2metrics/iam.tf resource { name = assume_role_policy = data } "aws_iam_role" "loginsights2metrics" var .prefix .aws_iam_policy_document .trust .json To run, Lambdas need an initial set of permissions which can be found in the canned policy . You can see the content of the policy in the IAM console or dumping it with and AWSLambdaVPCAccessExecutionRole aws iam get-policy aws iam get-policy-version $ aws iam get-policy --policy-arn arn:aws:iam::aws:policy/service-role/AWSLambdaVPCAccessExecutionRole { "Policy": { "PolicyName": "AWSLambdaVPCAccessExecutionRole", "PolicyId": "ANPAJVTME3YLVNL72YR2K", "Arn": "arn:aws:iam::aws:policy/service-role/AWSLambdaVPCAccessExecutionRole", "Path": "/service-role/", "DefaultVersionId": "v2", "AttachmentCount": 0, "PermissionsBoundaryUsageCount": 0, "IsAttachable": true, "Description": "Provides minimum permissions for a Lambda function to execute while accessing a resource within a VPC - create, describe, delete network interfaces and write permissions to CloudWatch Logs. ", "CreateDate": "2016-02-11T23:15:26Z", "UpdateDate": "2020-10-15T22:53:03Z" } } $ aws iam get-policy-version --policy-arn arn:aws:iam::aws:policy/service-role/AWSLambdaVPCAccessExecutionRole --version-id v2 { "PolicyVersion": { "Document": { "Version": "2012-10-17", "Statement": [ { "Effect": "Allow", "Action": [ "logs:CreateLogGroup", "logs:CreateLogStream", "logs:PutLogEvents", "ec2:CreateNetworkInterface", "ec2:DescribeNetworkInterfaces", "ec2:DeleteNetworkInterface", "ec2:AssignPrivateIpAddresses", "ec2:UnassignPrivateIpAddresses" ], "Resource": "*" } ] }, "VersionId": "v2", "IsDefaultVersion": true, "CreateDate": "2020-10-15T22:53:03Z" } } Attaching a canned policy is just a matter of creating a specific resource aws_iam_role_policy_attachment common/lambda-loginsights2metrics/iam.tf resource { .loginsights2metrics.name policy_arn = } "aws_iam_role_policy_attachment" "loginsights2metrics-" role = aws_iam_role "arn:aws:iam::aws:policy/service-role/AWSLambdaVPCAccessExecutionRole" Now that we have the IAM role and the basic policy we can assign custom permissions to it. We need to grant the Lambda permissions on other AWS components, namely CloudWatch to run Log Insights queries and to store metrics and DynamoDB to retrieve all the items from the queries table. common/lambda-loginsights2metrics/iam.tf { { = [ , , , , , ] resources = [ ] } statement { = [ ] resources = [aws_dynamodb_table.loginsights2metrics.arn] } } data "aws_iam_policy_document" "loginsights2metrics" statement actions "cloudwatch:PutMetricData" "cloudwatch:PutMetricAlarm" "logs:StartQuery" "logs:GetQueryResults" "logs:GetLogEvents" "*" actions "dynamodb:Scan" Through we can create and assign the policy out of a data structure aws_iam_role_policy common/lambda-loginsights2metrics/iam.tf resource { name = role = aws_iam_role policy = data } "aws_iam_role_policy" "loginsights2metrics" var .prefix .loginsights2metrics .name .aws_iam_policy_document .loginsights2metrics .json Resources aws_iam_policy_document documentation aws_iam_role documentation aws_iam_role_policy_attachment documentation aws_iam_role_policy documentation AWS CLI iam get-policy documentation AWS CLI iam get-policy-version documentation Lambda We can now create the Lambda function container. I do not use Terraform as a deployer, as I think it should be used to define static infrastructure only, so I will use a dummy function here and later deploy the real code using the AWS CLI. The dummy function can be easily created with common/lambda-loginsights2metrics/lambda.tf data { = output_path = source { content = filename = } } "archive_file" "dummy" type "zip" " /lambda.zip" ${path.module} "dummy" "dummy.txt" The Lambda function is a bit more complicated. As I mentioned, I'll use Zappa to package the function, so the has to be . The IAM role given to the function is the one we defined previously, while and clearly depend on the specific function. Lambdas should run in private networks, and I won't cover here the steps to create them. The AWS docs contains a lot of details on this topic, e.g. . handler "zappa.handler.lambda_handler" memory_size timeout https://aws.amazon.com/premiumsupport/knowledge-center/internet-access-lambda-function/ The environment variables allow me to inject the name of the DynamoDB table so that I don't need to hardcode it. I also pass another variable, the that I use in my configuration. This is not essential for the problem at hand, but I left it there to show how to pass such values. Sentry DSN common/lambda-loginsights2metrics/lambda.tf resource { function_name = handler = runtime = filename = data role = aws_iam_role memory_size = timeout = vpc_config { subnet_ids = security_group_ids = } environment { variables = { = , = aws_dynamodb_table } } lifecycle { ignore_changes = [last_modified, filename] } } "aws_lambda_function" "loginsights2metrics" "loginsights2metrics" "zappa.handler.lambda_handler" "python3.8" .archive_file .dummy .output_path .loginsights2metrics .arn 128 300 var .vpc_subnets var .security_groups "SENTRY_DSN" "https://XXXXXX:@sentry.io/YYYYYY" "DYNAMODB_TABLE" .loginsights2metrics .name Please note that I instructed Terraform to ignore changes to the two attributes and , and that I haven't used any . This way I can safely apply Terraform to change parameters like or without affecting what I deployed with the CI. last_modified filename source_code_hash memory_size timeout Since I want to trigger the function from AWS CloudWatch Events I need to grant the service the permission. events.amazonaws.com lambda:InvokeFunction common/lambda-loginsights2metrics/lambda.tf resource { statement_id = action = function_name = aws_lambda_function principal = source_arn = aws_cloudwatch_event_rule } "aws_lambda_permission" "loginsights2metrics" "AllowExecutionFromCloudWatch" "lambda:InvokeFunction" .loginsights2metrics .function_name "events.amazonaws.com" .rate .arn Resources archive_file documentation aws_lambda_function documentation aws_lambda_permission documentation IAM part 2 Since 2018 Lambdas have a maximum execution time of 15 minutes (900 seconds), which is more than enough for many services, but to be conservative I preferred to leverage Zappa's asynchronous calls and to make the main Lambda call itself for each query. The Lambda doesn't clearly call the same Python function (it's not recursive), but from AWS's point of view we have a Lambda that calls itself, so we need to give it a specific permission to do this. common/lambda-loginsights2metrics/iam.tf { { = [ , ] resources = [aws_lambda_function.loginsights2metrics.arn] } } data "aws_iam_policy_document" "loginsights2metrics_exec" statement actions "lambda:InvokeAsync" "lambda:InvokeFunction" I could not define this when I defined the rest of the IAM components because this needs the Lambda to be defined, but the resource is in the same file. Terraform doesn't care about which resource we defined first and where we define it as long as there are no loops in the definitions. We can now assign the newly created policy document to the IAM role we created previously common/lambda-loginsights2metrics/iam.tf resource { name = role = aws_iam_role.loginsights2metrics.name = data.aws_iam_policy_document.loginsights2metrics_exec.json } "aws_iam_role_policy" "loginsights2metrics_exec" " -exec" ${var.prefix} policy Resources aws_iam_policy_document documentation aws_iam_role_policy documentation CloudWatch Whenever you need to run Lambdas (or other things) periodically, the standard AWS solution is to use CloudWatch Events, which work as the AWS cron system. CloudWatch Events are made of rules and targets, so first of all I defined a rule that gets triggered every 2 minutes common/lambda-loginsights2metrics/cloudwatch.tf resource { = = = } "aws_cloudwatch_event_rule" "rate" # Zappa requires the name to match the processing function name "main.loginsights2metrics" description "Trigger Lambda " ${var.prefix} schedule_expression "rate(2 minutes)" Please note that Zappa has a specific requirement for CloudWatch Events, so I left a comment to clarify this to my future self. The second part of the event is the target, which is the Lambda function that we defined in the previous section. common/lambda-loginsights2metrics/cloudwatch.tf resource { rule = aws_cloudwatch_event_rule target_id = arn = aws_lambda_function } "aws_cloudwatch_event_target" "lambda" .rate .name "${var.prefix}-target" .loginsights2metrics .arn Resources aws_cloudwatch_event_rule documentation aws_cloudwatch_event_target documentation Using the module Now the module is finished, so I just need to create some items for the DynamoDB table and to call the module itself account1/lambda-loginsights2metrics/main.tf locals { items = [ { : { : }, : { : , }, : { : }, : { : , }, : { : }, : { : } }, { : { : }, : { : , }, : { : }, : { : app.trace\ succeeded\ , }, : { : }, : { : } }, { : { : }, : { : , }, : { : }, : { : app.trace\ retry\ , }, : { : }, : { : } } ] } "SlotName" "S" "Celery Logs submitted tasks" "LogGroup" "S" "mycluster/celery" "ClusterName" "S" "mycluster" "Query" "S" "parse @message /\\[celery\\.(? [a-z.]+)\\].*Received task: (? [a-z._]+)\\[/ | filter not isblank(source) | stats count(*) as Value by bin(1m)" "Namespace" "S" "Custom" "MetricName" "S" "Submitted tasks" "SlotName" "S" "Celery Logs succeeded tasks" "LogGroup" "S" "mycluster/celery" "ClusterName" "S" "mycluster" "Query" "S" "parse @message /\\[celery.(? [a-z\\._]+)].*Task (? [a-z\\._]+)\\[.*\\] (? [a-z]+)/ | filter source = \" " | filter event = \" " | stats count(*) as Value by bin(1m)" "Namespace" "S" "Custom" "MetricName" "S" "Succeeded tasks" "SlotName" "S" "Celery Logs retried tasks" "LogGroup" "S" "mycluster/celery" "ClusterName" "S" "mycluster" "Query" "S" "parse @message /\\[celery.(? [a-z\\._]+)].*Task (? [a-z\\._]+)\\[.*\\] (? [a-z]+)/ | filter source = \" " | filter event = \" " | stats count(*) as Value by bin(1m)" "Namespace" "S" "Custom" "MetricName" "S" "Retried tasks" I need to provide a security group for the Lambda, and in this case I can safely use the default one provided by the VPC account1/lambda-loginsights2metrics/main.tf data { name = vpc_id = } "aws_security_group" "default" "default" var .vpc_id And I can finally call the module account1/lambda-loginsights2metrics/main.tf module { source = items = local security_groups = [data ] vpc_subnets = } "loginsights2metrics" "../../common/lambda-loginsights2metrics" .items .aws_security_group .default .id var .vpc_private_subnets Please note that the variable is a list of subnet names that I created in another module. vpc_private_subnets Resources aws_security_group documentation Creating Terraform modules Python As I mentioned before, the Python code of the Lambda function is contained in a different repository and deployed with the CI using . Given we are interacting with AWS I am clearly using Boto3, the . The code was developed locally without Zappa's support, to test out the Boto3 functions I wanted to use, then quickly adjusted to be executed in a Lambda. Zappa AWS SDK for Python I think the code is pretty straightforward, but I left my original comments to be sure everything is clear. os time json datetime datetime, timedelta boto3 zappa.asynchronous task logs = boto3.client( , region_name= ) cw = boto3.client( , region_name= ) dynamodb = boto3.resource( , region_name= ) slot_name = item[ ] log_group = item[ ] cluster_name = item[ ] query = item[ ] namespace = item[ ] metric_name = item[ ] start_query_response = logs.start_query( logGroupName=log_group, startTime=int((datetime.now() - timedelta(minutes= )).timestamp()), endTime=int(datetime.now().timestamp()), queryString=query, ) query_id = start_query_response[ ] response = response response[ ] == : print( ) time.sleep( ) response = logs.get_query_results(queryId=query_id) data = [] d response[ ]: sample = {} i d: field = i[ ] value = i[ ] sample[field] = value data.append(sample) d data: timestamp = datetime.strptime(d[ ], ) value = int(d[ ]) print( ) cw.put_metric_data( Namespace=namespace, MetricData=[ { : metric_name, : [{ : , : cluster_name}], : timestamp, : value, : , } ], ) open( , ) f: package_info = json.load(f) build_timestamp = int(package_info[ ]) build_datetime = datetime.fromtimestamp(build_timestamp) print( ) print( ) print( ) print( ) table = dynamodb.Table(os.environ[ ]) response = table.scan(Select= ) i response[ ]: print( ) put_metric_data(i) import import import from import import from import # CONFIG "logs" "eu-west-1" "cloudwatch" "eu-west-1" "dynamodb" "eu-west-1" @task : def put_metric_data (item) "SlotName" "LogGroup" "ClusterName" "Query" "Namespace" "MetricName" # This runs the Log Insights query fetching data # for the last 15 minutes. # As we deal with logs processing it's entirely possible # for the metric to be updated, for example because # a log was received a bit later. # When we put multiple values for the same timestamp # in the metric CW can show max, min, avg, and percentiles. # Since this is an update of a count we should then always # use "max". 15 "queryId" # Just polling the API. 5 seconds seems to be a good # compromise between not pestering the API and not paying # too much for the Lambda. None while is None or "status" "Running" f" : waiting for query to complete ..." {slot_name} 5 # Data comes in a strange format, a dictionary of # {"field":name,"value":actual_value}, so this converts # it into something that can be accessed through keys for in "results" for in "field" "value" # Now that we have the data, let's put them into a metric. for in "bin(1m)" "%Y-%m-%d %H:%M:%S.000" "Value" f" : putting on " {slot_name} {value} {timestamp} "MetricName" "Dimensions" "Name" "Cluster" "Value" "Timestamp" "Value" "Unit" "None" : def loginsights2metrics (event, context) with "package_info.json" "r" as "build_time" "###################################" "LogInsights2Metrics - Build date: " f' ' {build_datetime.strftime( )} "%Y/%m/%d %H:%M:%S" "###################################" f'Reading task from DynamoDB table ' {os.environ[ ]} "DYNAMODB_TABLE" "DYNAMODB_TABLE" # This is the simplest way to get all entries in the table # The next loop will asynchronously call `put_metric_data` # on each entry. "ALL_ATTRIBUTES" for in "Items" f"* Processing item " {i[ ]} 'SlotName' So, when the Lambda is executed, the entry point is the function which queries the DynamoDB table and loops over all the items contained in it. The loop executes the function which being a Zappa task runs it in a new Lambda invocation. This function runs the Log Insights query, adjusts Boto3's output, and finally puts the values in the custom metric. loginsights2metrics put_metric_data The problem I mention in the comment just before I run is interesting. Log Insights are queries, and since they extract data from logs the result can change between two calls of the same query. This means that, since there is an overlap between calls (we run a query on the last 15 minutes every 2 minutes), the function will put multiple values in the same bin of the metric. This is perfectly normal, and it's the reason why CloudWatch allows you to show the maximum, minimum, average, or various percentiles of the same metric. When it comes to counting events, the number can only increase or stay constant in time, but never decrease, so it's sensible to look at the maximum. This is not true if you are looking at execution times, for example, so pay attention to the nature of the underlying query when you graph the metric. logs.start_query The Zappa settings I use for the function are zappa_settings.json { : { : , : , : , : , : , : } } "main" "app_module" "main" "app_function" "main.loginsights2metrics" "runtime" "python3.8" "log_level" "WARNING" "xray_tracing" true "exception_handler" "zappa_sentry.unhandled_exceptions" And the requirements are requirements.txt zappa zappa-sentry Please note that as I mentioned before is not a strict requirement for this solution. zappa-sentry The code can be packaged and deployed with a simple bash script like VENV_DIRECTORY=venv LAMBDA_PACKAGE=lambda.zip REGION=eu-west-1 FUNCTION_NAME=loginsights2metrics [[ -d ]]; rm -fR ; [[ -f ]]; rm -fR ; python -m venv /bin/activate pip install -r requirements.txt zappa package main -o rm -fR aws --region= lambda update-function-code -- -name --zip-file #!/bin/bash if ${VENV_DIRECTORY} then ${VENV_DIRECTORY} fi if ${LAMBDA_PACKAGE} then ${LAMBDA_PACKAGE} fi ${VENV_DIRECTORY} source ${VENV_DIRECTORY} ${LAMBDA_PACKAGE} ${VENV_DIRECTORY} ${REGION} function ${FUNCTION_NAME} "fileb:// " ${LAMBDA_PACKAGE} Costs I will follow here the and the calculations published in 2018 by my colleague João Neves on . AWS guide on Lambda pricing his blog I assume the following: The Lambda runs 4 queries, so we have 5 invocations (1 for the main Lambda and 4 asynchronous tasks) Each invocation runs for 5 seconds. The current average time of each invocation in my AWS accounts is 4.6 seconds I run the Lambda every 2 minutes Requests: 5 invocations/event * 30 events/hour * 24 hours/day * 31 days/month = 111600 requests Duration: 0.128 GB/request * 111600 requests * 5 seconds = 71424 GB-second Total: $0.20 * 111600 / 10^6 + $0.0000166667 * 71424 ~= $1.22/month As you can see, for applications like this it's extremely convenient to use a serverless solution like Lambda functions. Previously published at https://www.thedigitalcatonline.com/blog/2021/03/22/aws-log-insights-as-cloudwatch-metrics-with-python-and-terraform/