Checking the Breakdown of Athena Query Execution Time with QueryExecution.Statistics / QueryRuntimeStatistics

2026-08-03 aws

Athena queries can sometimes take longer than expected, or slow down depending on the time of day. Serverless overhead and resource exhaustion can’t be helped, but the QueryExecution.Statistics / QueryRuntimeStatistics information can help figure out whether configuration or query tuning could make things faster.

Loaded about 400MB spanning 7 months of data from the partitions tutorial to check.

CREATE EXTERNAL TABLE IF NOT EXISTS elb_logs_raw_native_part (
  request_timestamp string, elb_name string, request_ip string, request_port int,
  backend_ip string, backend_port int, request_processing_time double,
  backend_processing_time double, client_response_time double,
  elb_response_code string, backend_response_code string,
  received_bytes bigint, sent_bytes bigint, request_verb string, url string,
  protocol string, user_agent string, ssl_cipher string, ssl_protocol string
)
PARTITIONED BY (dt string)
ROW FORMAT SERDE 'org.apache.hadoop.hive.serde2.RegexSerDe'
WITH SERDEPROPERTIES (
  'serialization.format' = '1',
  'input.regex' = '([^ ]*) ([^ ]*) ([^ ]*):([0-9]*) ([^ ]*)[:-]([0-9]*) ([-.0-9]*) ([-.0-9]*) ([-.0-9]*) (|[-0-9]*) (-|[-0-9]*) ([-0-9]*) ([-0-9]*) \"([^ ]*) ([^ ]*) (- |[^ ]*)\" ("[^"]*") ([A-Z0-9-]+) ([A-Za-z0-9.-]*)$'
)
LOCATION 's3://athena-examples-ap-northeast-1/elb/plaintext/';

ALTER TABLE elb_logs_raw_native_part ADD PARTITION (dt='2015-01-01')
  LOCATION 's3://athena-examples-ap-northeast-1/elb/plaintext/2015/01/01/';
...

QueryRuntimeStatistics contains detailed information such as Stage, but it does not include the DataScannedInBytes that is present in QueryExecution.Statistics.

$ QID=$(aws athena start-query-execution \
    --query-string "SELECT count(*) FROM elb_logs_raw_native_part" \
    --query-execution-context Database=blog_athena_stats \
    --work-group primary --query 'QueryExecutionId' --output text)

$ aws athena get-query-execution --query-execution-id "$QID" --query 'QueryExecution.Statistics'
{
    "EngineExecutionTimeInMillis": 916,
    "DataScannedInBytes": 406582288,
    "TotalExecutionTimeInMillis": 1097,
    "QueryQueueTimeInMillis": 99,
    "ServicePreProcessingTimeInMillis": 51,
    "QueryPlanningTimeInMillis": 278,
    "ServiceProcessingTimeInMillis": 31,
    "ResultReuseInformation": {
        "ReusedPreviousResult": false
    }
}

$ aws athena get-query-runtime-statistics --query-execution-id "$QID" --query 'QueryRuntimeStatistics'
{
    "Timeline": {
        "QueryQueueTimeInMillis": 99,
        "ServicePreProcessingTimeInMillis": 51,
        "QueryPlanningTimeInMillis": 278,
        "EngineExecutionTimeInMillis": 916,
        "ServiceProcessingTimeInMillis": 31,
        "TotalExecutionTimeInMillis": 1097
    },
    "Rows": {
        "InputRows": 1356206,
        "InputBytes": 0,
        "OutputBytes": 9,
        "OutputRows": 1
    },
    "OutputStage": {
        "StageId": 0,
        "State": "FINISHED",
        "OutputBytes": 9,
        "OutputRows": 1,
        "InputBytes": 378,
        "InputRows": 42,
        "ExecutionTime": 1170,
        "QueryStagePlan": {
            "Name": "Output",
            "Identifier": "{\"columnNames\":\"[_col0]\"}",
            "Children": [
                {
                    "Name": "Aggregate",
                    "Identifier": "{\"type\":\"FINAL\",\"keys\":\"\",\"hash\":\"[]\"}",
                    "Children": [
                        {
                            "Name": "LocalExchange",
                            "Identifier": "{\"partitioning\":\"SINGLE\",\"isReplicateNullsAndAny\":\"\",\"hashColumn\":\"[]\",\"arguments\":\"[]\"}",
                            "Children": [
                                {
                                    "Name": "RemoteSource",
                                    "Identifier": "{\"sourceFragmentIds\":\"[1]\"}",
                                    "Children": [],
                                    "RemoteSources": [
                                        "1"
                                    ]
                                }
                            ]
                        }
                    ]
                }
            ]
        },
        "SubStages": [
            {
                "StageId": 1,
                "State": "FINISHED",
                "OutputBytes": 378,
                "OutputRows": 42,
                "InputBytes": 0,
                "InputRows": 1356206,
                "ExecutionTime": 9510,
                "QueryStagePlan": {
                    "Name": "Aggregate",
                    "Identifier": "{\"type\":\"PARTIAL\",\"keys\":\"\",\"hash\":\"[]\"}",
                    "Children": [
                        {
                            "Name": "TableScan",
                            "Identifier": "{\"table\":\"awsdatacatalog:blog_athena_stats:elb_logs_raw_native_part\"}",
                            "Children": []
                        }
                    ]
                },
                "SubStages": []
            }
        ]
    }
}

Looking at the Timeline values, QueryQueueTimeInMillis and ServicePreProcessingTimeInMillis take about 100ms and 60ms respectively. These are hard to shorten, but when QueryQueueTimeInMillis is large, it can mean that a heavy query running under the same account is pressuring the quota. On the other hand, EngineExecutionTimeInMillis may be improved by tuning the query based on the Stage information, or by changing the file format or granularity. Also, QueryPlanningTimeInMillis is included within it, and there is room to improve efficiency by avoiding too many partitions or files, or by flattening the structure.

When ResultReuse, which reuses the query execution results, is enabled, QueryPlanningTimeInMillis is not returned. Incidentally, tables managed under Lake Formation do not support ResultReuse.

Apply Row and Column Level Access Control on Glue Data Catalog Tables with Lake Formation in CDK - sambaiz-net

$ QID=$(aws athena start-query-execution \
    --query-string "SELECT count(*) FROM elb_logs_raw_native_part" \
    --query-execution-context Database=blog_athena_stats \
    --work-group primary --query 'QueryExecutionId' --output text \
    --result-reuse-configuration 'ResultReuseByAgeConfiguration={Enabled=true,MaxAgeInMinutes=60}')

$ aws athena get-query-execution --query-execution-id "$QID" --query 'QueryExecution.Statistics'
{
    "EngineExecutionTimeInMillis": 114,
    "DataScannedInBytes": 0,
    "TotalExecutionTimeInMillis": 247,
    "QueryQueueTimeInMillis": 84,
    "ServicePreProcessingTimeInMillis": 19,
    "ServiceProcessingTimeInMillis": 30,
    "ResultReuseInformation": {
        "ReusedPreviousResult": true
    }
}

Note that getting the result also takes time beyond this execution time, to poll the State and fetch the data from S3. There is also a way to receive State change notifications via EventBridge, but it is best-effort, and in practice the delivery time varied between 3-8 seconds. Also, when there are many rows, fetching directly from S3 is faster than going through GetQueryResults, which can only retrieve up to 1000 rows at a time. For example, fetching 6000 rows of results took 1668 ms via GetQueryResults, versus 145 ms fetching directly.