Elasticsearch request causes task timeout

[dsotirho-ucsc]

CloudWatch Logs Insights
region: us-east-1
log-group-names: /aws/lambda/azul-service-anvildev
start-time: -259200s
end-time: 0s
query-string:

fields @timestamp, @message
# | filter @message like /ERROR|timed out/
| filter @requestId like /b41a2f78-605c-4b92-beac-4b01c059880a|ae5146f9-8097-48a6-a893-0e19821c44de/
| sort @timestamp asc
| limit 200

---

@timestamp	@message
2025-01-26 10:01:03.529	START RequestId: b41a2f78-605c-4b92-beac-4b01c059880a Version: $LATEST
2025-01-26 10:01:03.530	[INFO] 2025-01-26T10:01:03.530Z b41a2f78-605c-4b92-beac-4b01c059880a azul.chalice Received HEAD request for '/index/files', with {"query": {"size": "1"}, "headers": {"accept": "/", "accept-encoding": "gzip, deflate", "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-asn": "14618", "cloudfront-viewer-country": "US", "host": "service.anvil.gi.ucsc.edu", "user-agent": "python-requests/2.32.3", "via": "1.1 193a402ffd948b9e8339796d3c0c8282.cloudfront.net (CloudFront)", "x-amz-cf-id": "6S1ZpyWktqRDlxkwSlGdOYXdSIdmcV0Ser3gusILS1wMorUKy224GA==", "x-amzn-trace-id": "Root=1-679607df-59e89bf46ea091ce3635c24c", "x-forwarded-for": "44.207.234.78, 15.158.60.10", "x-forwarded-port": "443", "x-forwarded-proto": "https"}}.
2025-01-26 10:01:03.530	[INFO] 2025-01-26T10:01:03.530Z b41a2f78-605c-4b92-beac-4b01c059880a azul.chalice Did not authenticate request.
2025-01-26 10:01:03.531	[INFO] 2025-01-26T10:01:03.531Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.GetItem: Making POST request to https://dynamodb.us-east-1.amazonaws.com/
2025-01-26 10:01:03.532	[INFO] 2025-01-26T10:01:03.532Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.GetItem: … with request body b'{"TableName": "azul-sources_cache_by_auth-anvildev", "Key": {"identity": {"S": "anvil:"}}, "ProjectionExpression": "sources,e...'
2025-01-26 10:01:03.536	[INFO] 2025-01-26T10:01:03.536Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.GetItem: Got 200 response
2025-01-26 10:01:03.536	[INFO] 2025-01-26T10:01:03.536Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.GetItem: … with response body b'{"Item":{"expiration":{"N":"1737885603"},"sources":{"S":"[\"c6e19201-4fae-4213-a16c-edfd0cc11335\", \"421f4b48-5e68-4e61-92bb...'
2025-01-26 10:01:03.537	[INFO] 2025-01-26T10:01:03.537Z b41a2f78-605c-4b92-beac-4b01c059880a azul.terra Making GET request to 'https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap'
2025-01-26 10:01:03.537	[DEBUG] 2025-01-26T10:01:03.537Z b41a2f78-605c-4b92-beac-4b01c059880a azul.terra … without request body
2025-01-26 10:01:03.843	[INFO] 2025-01-26T10:01:03.843Z b41a2f78-605c-4b92-beac-4b01c059880a azul.terra Got 200 response after 0.306s from GET to https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap
2025-01-26 10:01:03.843	[DEBUG] 2025-01-26T10:01:03.843Z b41a2f78-605c-4b92-beac-4b01c059880a azul.terra … with response headers HTTPHeaderDict({'Date': 'Sun, 26 Jan 2025 10:01:03 GMT', 'Server': 'Apache', 'X-Frame-Options': 'SAMEORIGIN', 'Access-Control-Allow-Headers': 'DNT,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Range,Authorization,Accept,Referer,X-App-Id,Origin', 'Access-Control-Allow-Methods': 'GET,POST,DELETE,PUT,PATCH,OPTIONS,HEAD', 'X-Content-Type-Options': 'nosniff', 'Strict-Transport-Security': 'max-age=31536000;includeSubDomains', 'Cache-Control': 'no-cache,no-store,must-revalidate', 'X-Request-ID': '6dB9d0P3', 'Content-Type': 'application/json', 'Content-Length': '13303', 'Vary': 'Accept-Encoding,Origin', 'Via': '1.1 google', 'Alt-Svc': 'h3=":443"; ma=2592000,h3-29=":443"; ma=2592000'})
2025-01-26 10:01:03.843	[DEBUG] 2025-01-26T10:01:03.843Z b41a2f78-605c-4b92-beac-4b01c059880a azul.terra … with response body b'{"roleMap":{"a0925f5f-3d38-4f8a-a09f-f6997072dc23":["reader","aggregate_data_reader","discoverer"],"215793b0-b991-4b73-9584-1...'
2025-01-26 10:01:03.844	[INFO] 2025-01-26T10:01:03.844Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.PutItem: Making POST request to https://dynamodb.us-east-1.amazonaws.com/
2025-01-26 10:01:03.845	[INFO] 2025-01-26T10:01:03.845Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.PutItem: … with request body b'{"TableName": "azul-sources_cache_by_auth-anvildev", "Item": {"identity": {"S": "anvil:"}, "sources": {"S": "[\"c6e19201-4fae...'
2025-01-26 10:01:03.850	[INFO] 2025-01-26T10:01:03.850Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.PutItem: Got 200 response
2025-01-26 10:01:03.850	[INFO] 2025-01-26T10:01:03.850Z b41a2f78-605c-4b92-beac-4b01c059880a azul.boto3 dynamodb.PutItem: … with response body b'{}'
2025-01-26 10:01:03.858	[INFO] 2025-01-26T10:01:03.858Z b41a2f78-605c-4b92-beac-4b01c059880a elasticsearch Making POST request to https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com:443/azul_v2_anvildev_anvil_files_aggregate/_search
2025-01-26 10:01:03.858	[INFO] 2025-01-26T10:01:03.858Z b41a2f78-605c-4b92-beac-4b01c059880a elasticsearch … with request body b'{"aggs":{"source_id":{"filter":{"bool":{}},"aggs":{"myTerms":{"terms":{"field":"sources.id.keyword","size":99999},"meta":{"pa...'
2025-01-26 10:01:34.567	2025-01-26T10:01:34.566Z b41a2f78-605c-4b92-beac-4b01c059880a Task timed out after 31.04 seconds
2025-01-26 10:01:34.567	END RequestId: b41a2f78-605c-4b92-beac-4b01c059880a
2025-01-26 10:01:34.567	REPORT RequestId: b41a2f78-605c-4b92-beac-4b01c059880a Duration: 31037.28 ms Billed Duration: 31000 ms Memory Size: 2048 MB Max Memory Used: 156 MB

---

@timestamp	@message
2025-01-27 02:07:03.708	START RequestId: ae5146f9-8097-48a6-a893-0e19821c44de Version: $LATEST
2025-01-27 02:07:03.709	[INFO] 2025-01-27T02:07:03.709Z ae5146f9-8097-48a6-a893-0e19821c44de azul.chalice Received HEAD request for '/index/activities', with {"query": {"size": "1"}, "headers": {"accept": "/", "accept-encoding": "gzip, deflate", "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-asn": "14618", "cloudfront-viewer-country": "US", "host": "service.anvil.gi.ucsc.edu", "user-agent": "python-requests/2.32.3", "via": "1.1 1f133079dc1c94415e666e3b032459fe.cloudfront.net (CloudFront)", "x-amz-cf-id": "pSi2FeTeZ1N30kuO21vizLuQByLIF0lT0ujkTSRkAwHkiZhkMfhpVw==", "x-amzn-trace-id": "Root=1-6796ea47-556dfe780fc3edce7366f68b", "x-forwarded-for": "44.207.234.78, 15.158.60.41", "x-forwarded-port": "443", "x-forwarded-proto": "https"}}.
2025-01-27 02:07:03.709	[INFO] 2025-01-27T02:07:03.709Z ae5146f9-8097-48a6-a893-0e19821c44de azul.chalice Did not authenticate request.
2025-01-27 02:07:03.710	[INFO] 2025-01-27T02:07:03.710Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.GetItem: Making POST request to https://dynamodb.us-east-1.amazonaws.com/
2025-01-27 02:07:03.711	[INFO] 2025-01-27T02:07:03.710Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.GetItem: … with request body b'{"TableName": "azul-sources_cache_by_auth-anvildev", "Key": {"identity": {"S": "anvil:"}}, "ProjectionExpression": "sources,e...'
2025-01-27 02:07:03.716	[INFO] 2025-01-27T02:07:03.716Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.GetItem: Got 200 response
2025-01-27 02:07:03.716	[INFO] 2025-01-27T02:07:03.716Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.GetItem: … with response body b'{"Item":{"expiration":{"N":"1737943564"},"sources":{"S":"[\"170988f8-1dd1-4f39-b72d-645dabf607b7\", \"03b58060-2316-42fc-811f...'
2025-01-27 02:07:03.717	[INFO] 2025-01-27T02:07:03.717Z ae5146f9-8097-48a6-a893-0e19821c44de azul.terra Making GET request to 'https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap'
2025-01-27 02:07:03.717	[DEBUG] 2025-01-27T02:07:03.717Z ae5146f9-8097-48a6-a893-0e19821c44de azul.terra … without request body
2025-01-27 02:07:03.915	[INFO] 2025-01-27T02:07:03.915Z ae5146f9-8097-48a6-a893-0e19821c44de azul.terra Got 200 response after 0.198s from GET to https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap
2025-01-27 02:07:03.915	[DEBUG] 2025-01-27T02:07:03.915Z ae5146f9-8097-48a6-a893-0e19821c44de azul.terra … with response headers HTTPHeaderDict({'Date': 'Mon, 27 Jan 2025 02:07:03 GMT', 'Server': 'Apache', 'X-Frame-Options': 'SAMEORIGIN', 'Access-Control-Allow-Headers': 'DNT,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Range,Authorization,Accept,Referer,X-App-Id,Origin', 'Access-Control-Allow-Methods': 'GET,POST,DELETE,PUT,PATCH,OPTIONS,HEAD', 'X-Content-Type-Options': 'nosniff', 'Strict-Transport-Security': 'max-age=31536000;includeSubDomains', 'Cache-Control': 'no-cache,no-store,must-revalidate', 'X-Request-ID': 'eXEXW9kJ', 'Content-Type': 'application/json', 'Content-Length': '13303', 'Vary': 'Accept-Encoding,Origin', 'Via': '1.1 google', 'Alt-Svc': 'h3=":443"; ma=2592000,h3-29=":443"; ma=2592000'})
2025-01-27 02:07:03.915	[DEBUG] 2025-01-27T02:07:03.915Z ae5146f9-8097-48a6-a893-0e19821c44de azul.terra … with response body b'{"roleMap":{"a0925f5f-3d38-4f8a-a09f-f6997072dc23":["reader","aggregate_data_reader","discoverer"],"215793b0-b991-4b73-9584-1...'
2025-01-27 02:07:03.917	[INFO] 2025-01-27T02:07:03.917Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.PutItem: Making POST request to https://dynamodb.us-east-1.amazonaws.com/
2025-01-27 02:07:03.917	[INFO] 2025-01-27T02:07:03.917Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.PutItem: … with request body b'{"TableName": "azul-sources_cache_by_auth-anvildev", "Item": {"identity": {"S": "anvil:"}, "sources": {"S": "[\"170988f8-1dd1...'
2025-01-27 02:07:03.923	[INFO] 2025-01-27T02:07:03.923Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.PutItem: Got 200 response
2025-01-27 02:07:03.923	[INFO] 2025-01-27T02:07:03.923Z ae5146f9-8097-48a6-a893-0e19821c44de azul.boto3 dynamodb.PutItem: … with response body b'{}'
2025-01-27 02:07:03.932	[INFO] 2025-01-27T02:07:03.932Z ae5146f9-8097-48a6-a893-0e19821c44de elasticsearch Making POST request to https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com:443/azul_v2_anvildev_anvil_activities_aggregate/_search
2025-01-27 02:07:03.932	[INFO] 2025-01-27T02:07:03.932Z ae5146f9-8097-48a6-a893-0e19821c44de elasticsearch … with request body b'{"aggs":{"source_id":{"filter":{"bool":{}},"aggs":{"myTerms":{"terms":{"field":"sources.id.keyword","size":99999},"meta":{"pa...'
2025-01-27 02:07:34.748	2025-01-27T02:07:34.748Z ae5146f9-8097-48a6-a893-0e19821c44de Task timed out after 31.04 seconds
2025-01-27 02:07:34.748	END RequestId: ae5146f9-8097-48a6-a893-0e19821c44de
2025-01-27 02:07:34.748	REPORT RequestId: ae5146f9-8097-48a6-a893-0e19821c44de Duration: 31039.96 ms Billed Duration: 31000 ms Memory Size: 2048 MB Max Memory Used: 211 MB

---