athena.getQueryExecution returns a status of RUNNING for 1 minute+, even though history says the job took 4 seconds


I'm writing a node app using typescript and the aws-sdk to call Athena. Occasionally, the call to Athena will timeout after a minute of waiting for the Athena response. The thing I don't understand is that if I go to the AWS console and look at the Athena History tab, it says my query took 4 seconds to succeed, yet in my code it runs for over a minute waiting for a response. I'm hoping there's something I'm doing wrong in my code.

myFunct... {
    const athena = getAthena();

    const startQueryExecutionResponse: StartQueryExecutionOutput = await athena.startQueryExecution(params).promise();

    let status = "UNKNOWN";
    do { 
        await sleep(1000);
        status = await getQueryStatus(athena, startQueryExecutionResponse);  
    } while (status === "QUEUED" || status === "RUNNING");

    return await athena.getQueryResults(startQueryExecutionResponse as GetQueryResultsInput).promise();
};

const sleep = (ms: number) => {
    return new Promise(resolve => {
        setTimeout(resolve, ms)
    })
};

const getQueryStatus = async (athena: AWS.Athena, startQueryExecutionResponse: Athena.StartQueryExecutionOutput): Promise<QueryExecutionState> => {
    const result: GetQueryExecutionOutput = await athena.getQueryExecution(startQueryExecutionResponse as GetQueryResultsInput).promise();
    console.log(result);
    return result!.QueryExecution!.Status!.State || "Unknown"
};

The code gets stuck in that while loop, and I can see from the console.log below, that the status is Status: { State: 'RUNNING', SubmissionDateTime: 2019-07-23T18:28:00.639Z }, over and over again.

If the AWS console says this query took 4 seconds to complete, why does the getQueryExecution response say it's still RUNNING for minutes?

The history in the Athena console shows execution time. In addition to execution time, there is time in queue, planning, and service processing. I've had queries stuck in queue for much longer than the execution time. I think this is likely in your case. Also, the Athena showed queued queries as "RUNNING" until recently.

More info here: AWS Athena concurrency limits: Number of submitted queries VS number of running queries

Example stats of a query stuck in queue:

"Statistics": {
  "EngineExecutionTimeInMillis": 2689,
  "DataScannedInBytes": 35347476,
  "TotalExecutionTimeInMillis": 106676,
  "QueryQueueTimeInMillis": 103971,
  "QueryPlanningTimeInMillis": 600,
  "ServiceProcessingTimeInMillis": 16
}

It is possible to get the QueryExecutionStatistics for your getQueryExecution function.

         "DataManifestLocation": "string",
         "DataScannedInBytes": number,
         "EngineExecutionTimeInMillis": number,
         "QueryPlanningTimeInMillis": number,
         "QueryQueueTimeInMillis": number,
         "ServiceProcessingTimeInMillis": number,
         "TotalExecutionTimeInMillis": number

That might give you more insight, if you haven't already checked it. It could be the case that the 4 seconds is a subset of the total execution time. Perhaps your query is spending more time in planning as opposed to executing.

EngineExecutionTimeInMillis The number of milliseconds that the query took to execute.

Type: Long

Required: No

QueryPlanningTimeInMillis The number of milliseconds that Athena took to plan the query processing flow. This includes the time spent retrieving table partitions from the data source. Note that because the query engine performs the query planning, query planning time is a subset of engine processing time.

Type: Long

Required: No

source