Read timeouts cause Terra client to exceed restricted timing

[dsotirho-ucsc]

## /aws/lambda/azul-service-anvilprod-servicecachehealth

[
    {
        "@timestamp": "2023-11-22 18:08:37.887",
        "@message": "START RequestId: ede2fb5f-4dfa-4e15-92bc-c54bb4793f2a Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.887",
        "@message": "[INFO]\t2023-11-22T18:08:37.887Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.887",
        "@message": "[INFO]\t2023-11-22T18:08:37.887Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\telasticsearch\tMaking HEAD request to https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com:443/"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.887",
        "@message": "[INFO]\t2023-11-22T18:08:37.887Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.904",
        "@message": "[INFO]\t2023-11-22T18:08:37.903Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\telasticsearch\tGot 200 response after 0.016s from HEAD to https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com:443/"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.904",
        "@message": "[INFO]\t2023-11-22T18:08:37.904Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.904",
        "@message": "[INFO]\t2023-11-22T18:08:37.904Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-11-22 18:08:37.904",
        "@message": "[INFO]\t2023-11-22T18:08:37.904Z\tede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\tazul.health\tMaking HEAD request to https://service.prod.anvil.gi.ucsc.edu/index/activities?size=1"
    },
    {
        "@timestamp": "2023-11-22 18:08:47.977",
        "@message": "2023-11-22T18:08:47.977Z ede2fb5f-4dfa-4e15-92bc-c54bb4793f2a Task timed out after 10.09 seconds\n\n"
    },
    {
        "@timestamp": "2023-11-22 18:08:47.977",
        "@message": "END RequestId: ede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\n"
    },
    {
        "@timestamp": "2023-11-22 18:08:47.977",
        "@message": "REPORT RequestId: ede2fb5f-4dfa-4e15-92bc-c54bb4793f2a\tDuration: 10090.59 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 123 MB\t\n"
    }
]

## /aws/lambda/azul-service-anvilprod

[
    {
        "@timestamp": "2023-11-22 18:08:38.069",
        "@message": "START RequestId: c80fd0db-3eb0-4e8b-a278-7af9d1eb4dab Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:08:38.069",
        "@message": "[INFO]\t2023-11-22T18:08:38.069Z\tc80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\tazul.chalice\tReceived 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.prod.anvil.gi.ucsc.edu\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 a075746ea1824aa1c02a5e26a9e968e4.cloudfront.net (CloudFront)\", \"x-amz-cf-id\": \"TTVBZloR_95_Q5uzcy3oiIypBkV5c1zzq8fFvS5FSKw8UVN_tltWjw==\", \"x-amzn-trace-id\": \"Root=1-655e43a6-551740a975b8f35b0ea39c1b\", \"x-forwarded-for\": \"54.221.248.210, 130.176.98.70\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-11-22 18:08:38.069",
        "@message": "[INFO]\t2023-11-22T18:08:38.069Z\tc80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-11-22 18:08:38.078",
        "@message": "[DEBUG]\t2023-11-22T18:08:38.078Z\tc80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\tazul.terra\t_request('GET', https://data.terra.bio/api/repository/v1/snapshots/roleMap, headers=None, timeout=5.0, body=None)"
    },
    {
        "@timestamp": "2023-11-22 18:08:43.084",
        "@message": "[WARNING]\t2023-11-22T18:08:43.084Z\tc80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\turllib3.connectionpool\tRetrying (Retry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='data.terra.bio', port=443): Read timed out. (read timeout=5.0)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-11-22 18:08:48.142",
        "@message": "[DEBUG]\t2023-11-22T18:08:48.141Z\tc80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\tazul.chalice\tReturning 503 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"Code\": \"ServiceUnavailableError\", \"Message\": \"No response from https://data.terra.bio/api/repository/v1/snapshots/roleMap within 5.0 seconds\"}"
    },
    {
        "@timestamp": "2023-11-22 18:08:48.143",
        "@message": "END RequestId: c80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\n"
    },
    {
        "@timestamp": "2023-11-22 18:08:48.143",
        "@message": "REPORT RequestId: c80fd0db-3eb0-4e8b-a278-7af9d1eb4dab\tDuration: 10074.09 ms\tBilled Duration: 10075 ms\tMemory Size: 2048 MB\tMax Memory Used: 249 MB\t\n"
    }
]

Note the two retries on read, both after waiting five seconds.

• [ ] Security design review completed; the Resolution of this issue does not …
  • [ ] … affect authentication; for example:
  • OAuth 2.0 with the application (API or Swagger UI)
  • Authentication of developers with Google Cloud APIs
  • Authentication of developers with AWS APIs
  • Authentication with a GitLab instance in the system
  • Password and 2FA authentication with GitHub
  • API access token authentication with GitHub
  • Authentication with
  • [ ] … affect the permissions of internal users like access to
  • Cloud resources on AWS and GCP
  • GitLab repositories, projects and groups, administration
  • an EC2 instance via SSH
  • GitHub issues, pull requests, commits, commit statuses, wikis, repositories, organizations
  • [ ] … affect the permissions of external users like access to
  • TDR snapshots
  • [ ] … affect permissions of service or bot accounts
  • Cloud resources on AWS and GCP
  • [ ] … affect audit logging in the system, like
  • adding, removing or changing a log message that represents an auditable event
  • changing the routing of log messages through the system
  • [ ] … affect monitoring of the system
  • [ ] … introduce a new software dependency like
  • Python packages on PYPI
  • Command-line utilities
  • Docker images
  • Terraform providers
  • [ ] … add an interface that exposes sensitive or confidential data at the security boundary
  • [ ] … affect the encryption of data at rest
  • [ ] … require persistence of sensitive or confidential data that might require encryption at rest
  • [ ] … require unencrypted transmission of data within the security boundary
  • [ ] … affect the network security layer; for example by
  • modifying, adding or removing firewall rules
  • modifying, adding or removing security groups
  • changing or adding a port a service, proxy or load balancer listens on
• [ ] Documentation on any unchecked boxes is provided in comments below

[dsotirho-ucsc]

Additional occurrences on prod:

## /aws/lambda/azul-service-prod-servicecachehealth

[
    {
        "@timestamp": "2023-11-22 18:27:29.875",
        "@message": "START RequestId: 2538841d-417b-4651-845a-df7e69a86829 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.875",
        "@message": "[INFO]\t2023-11-22T18:27:29.875Z\t2538841d-417b-4651-845a-df7e69a86829\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.875",
        "@message": "[INFO]\t2023-11-22T18:27:29.875Z\t2538841d-417b-4651-845a-df7e69a86829\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.875",
        "@message": "[INFO]\t2023-11-22T18:27:29.875Z\t2538841d-417b-4651-845a-df7e69a86829\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.909",
        "@message": "[INFO]\t2023-11-22T18:27:29.909Z\t2538841d-417b-4651-845a-df7e69a86829\telasticsearch\tGot 200 response after 0.033s from HEAD to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.909",
        "@message": "[INFO]\t2023-11-22T18:27:29.909Z\t2538841d-417b-4651-845a-df7e69a86829\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.909",
        "@message": "[INFO]\t2023-11-22T18:27:29.909Z\t2538841d-417b-4651-845a-df7e69a86829\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-11-22 18:27:29.909",
        "@message": "[INFO]\t2023-11-22T18:27:29.909Z\t2538841d-417b-4651-845a-df7e69a86829\tazul.health\tMaking HEAD request to https://service.azul.data.humancellatlas.org/index/samples?size=1"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.912",
        "@message": "2023-11-22T18:27:39.912Z 2538841d-417b-4651-845a-df7e69a86829 Task timed out after 10.04 seconds\n\n"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.912",
        "@message": "END RequestId: 2538841d-417b-4651-845a-df7e69a86829\n"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.912",
        "@message": "REPORT RequestId: 2538841d-417b-4651-845a-df7e69a86829\tDuration: 10037.37 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 121 MB\t\n"
    }
]

## /aws/lambda/azul-service-prod-servicecachehealth

[
    {
        "@timestamp": "2023-11-22 18:29:29.919",
        "@message": "START RequestId: 1ed57fbc-0c3a-436a-b56b-f5885d5e7758 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.920",
        "@message": "[INFO]\t2023-11-22T18:29:29.919Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.920",
        "@message": "[INFO]\t2023-11-22T18:29:29.920Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.920",
        "@message": "[INFO]\t2023-11-22T18:29:29.920Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.956",
        "@message": "[INFO]\t2023-11-22T18:29:29.956Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\telasticsearch\tGot 200 response after 0.036s from HEAD to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.957",
        "@message": "[INFO]\t2023-11-22T18:29:29.956Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.957",
        "@message": "[INFO]\t2023-11-22T18:29:29.957Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-11-22 18:29:29.957",
        "@message": "[INFO]\t2023-11-22T18:29:29.957Z\t1ed57fbc-0c3a-436a-b56b-f5885d5e7758\tazul.health\tMaking HEAD request to https://service.azul.data.humancellatlas.org/index/files?size=1"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.952",
        "@message": "2023-11-22T18:29:39.952Z 1ed57fbc-0c3a-436a-b56b-f5885d5e7758 Task timed out after 10.03 seconds\n\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.952",
        "@message": "END RequestId: 1ed57fbc-0c3a-436a-b56b-f5885d5e7758\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.952",
        "@message": "REPORT RequestId: 1ed57fbc-0c3a-436a-b56b-f5885d5e7758\tDuration: 10032.73 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 110 MB\t\n"
    }
]

## /aws/lambda/azul-service-prod

[
    {
        "@timestamp": "2023-11-22 18:27:30.069",
        "@message": "START RequestId: 2ad129f4-96c1-4170-bce0-60553f22e71f Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:27:30.069",
        "@message": "[INFO]\t2023-11-22T18:27:30.069Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\tazul.chalice\tReceived HEAD request for '/index/samples', 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.azul.data.humancellatlas.org](http://service.azul.data.humancellatlas.org/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [c2ab43aa4f5ff7b5cc58894f6a8494bc.cloudfront.net](http://c2ab43aa4f5ff7b5cc58894f6a8494bc.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"NChQqwFjEPCCIxOFGbvIfq9ueYAgd0bvKcKdym5ODd3lom3errfhUw==\", \"x-amzn-trace-id\": \"Root=1-655e4812-48aa39ae5b3b16b2045b02af\", \"x-forwarded-for\": \"52.3.190.111, 18.68.30.171\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-11-22 18:27:30.070",
        "@message": "[INFO]\t2023-11-22T18:27:30.070Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-11-22 18:27:30.077",
        "@message": "[DEBUG]\t2023-11-22T18:27:30.077Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\tazul.terra\t_request('GET', https://data.terra.bio/api/repository/v1/snapshots/roleMap, headers=None, timeout=5.0, body=None)"
    },
    {
        "@timestamp": "2023-11-22 18:27:35.083",
        "@message": "[WARNING]\t2023-11-22T18:27:35.083Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\turllib3.connectionpool\tRetrying (Retry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='data.terra.bio', port=443): Read timed out. (read timeout=5.0)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.790",
        "@message": "[DEBUG]\t2023-11-22T18:27:39.790Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\tazul.terra\t_request(…) -> 9.713s 200 b'{\"roleMap\":{\"f3283538-c86e-4d2b-b6fb-c51d3479b9cc\":[\"reader\"],\"82336861-0e39-497f-bdbe-03923f5f36ab\":[\"reader\"],\"5f006aa6-bae4-4241-a334-4f0e0b731c35\":[\"reader\"],\"c25f206f-c5de-48f2-9dfa-7ab41221d6eb\":[\"reader\"],\"bc7f344d-ff18-4a10-8f59-518324ad4126\":[\"...'"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.837",
        "@message": "[INFO]\t2023-11-22T18:27:39.837Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\telasticsearch\tMaking POST request to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp32_samples_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp32_samples_aggregate/_search)"
    },
    {
        "@timestamp": "2023-11-22 18:27:39.837",
        "@message": "[INFO]\t2023-11-22T18:27:39.837Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\telasticsearch\t… with request body b'{\"post_filter\":{\"bool\":{\"must\":[{\"constant_score\":{\"filter\":{\"terms\":{\"sources.id.keyword\":[\"4e6b4bd3-8534-4ebf-868b-8a3ed739...'"
    },
    {
        "@timestamp": "2023-11-22 18:27:40.243",
        "@message": "[INFO]\t2023-11-22T18:27:40.243Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\telasticsearch\tGot 200 response after 0.406s from POST to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp32_samples_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp32_samples_aggregate/_search)"
    },
    {
        "@timestamp": "2023-11-22 18:27:40.243",
        "@message": "[INFO]\t2023-11-22T18:27:40.243Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\telasticsearch\t… with response body '{\"took\":355,\"timed_out\":false,\"_shards\":{\"total\":1,\"successful\":1,\"skipped\":0,\"failed\":0},\"hits\":{\"total\":{\"value\":19742,\"relat…'"
    },
    {
        "@timestamp": "2023-11-22 18:27:40.270",
        "@message": "[DEBUG]\t2023-11-22T18:27:40.270Z\t2ad129f4-96c1-4170-bce0-60553f22e71f\tazul.chalice\tReturning 200 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"pagination\": {\"count\": 1, \"total\": 19742, \"size\": 1, \"next\": \"[https://service.azul.data.humancellatlas.org/index/samples?catalog=dcp32&filters=%7B%7D&search_after=%5B%22001C_specimen%22%2C+%221e26ce75-1be0-4153-a21e-3d4a08a0d614%22%5D&sort=sampleId&order=asc&size=1\](https://service.azul.data.humancellatlas.org/index/samples?catalog=dcp32&filters=%7B%7D&search_after=%5B%22001C_specimen%22%2C+%221e26ce75-1be0-4153-a21e-3d4a08a0d614%22%5D&sort=sampleId&order=asc&size=1%5C)", \"previous\": null, \"pages\": 19742, \"sort\": \"sampleId\", \"order\": \"asc\"}, \"termFacets\": {\"organ\": {\"terms\": [{\"term\": \"blood\", \"count\": 4969}, {\"term\": \"lung\", \"count\": 1907}, {\"term\": \"pancreas\", \"count\": 1733}, {\"term\": \"adipose tissue\", \"count\": 1441}, {\"term\": \"brain\", \"count\": 1397}, {\"term\": null, \"count\": 1072}, {\"term\": \"skin of body\", \"count\": 803}, {\"term\": \"colon\", \"count\": 635}, {\"term\": \"liver\", \"count\": 600}, {\"term\": \"kidney\", \"count\": 575}, {\"term\": \"heart\", \"count\": 340}, {\"term\": \"embryo\", \"count\": 334}, {\"term\": \"eye\", \"count\": 319}, {\"term\": \"wall of lateral ventricle\", \"count\": 250}, {\"term\": \"small intestine\", \"count\": 195}, {\"term\": \"large intestine\", \"count\": 193}, {\"term\": \"spinal cord\", \"count\": 161}, {\"term\": \"stomach\", "
    },
    {
        "@timestamp": "2023-11-22 18:27:40.282",
        "@message": "END RequestId: 2ad129f4-96c1-4170-bce0-60553f22e71f\n"
    },
    {
        "@timestamp": "2023-11-22 18:27:40.282",
        "@message": "REPORT RequestId: 2ad129f4-96c1-4170-bce0-60553f22e71f\tDuration: 10212.67 ms\tBilled Duration: 10213 ms\tMemory Size: 2048 MB\tMax Memory Used: 211 MB\t\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:30.125",
        "@message": "START RequestId: be4c63b2-8594-44fa-9657-7d56ee386986 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:30.126",
        "@message": "[INFO]\t2023-11-22T18:29:30.126Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\tazul.chalice\tReceived 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.azul.data.humancellatlas.org](http://service.azul.data.humancellatlas.org/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [8917feb7a0623473126b94dc50f359fa.cloudfront.net](http://8917feb7a0623473126b94dc50f359fa.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"IHoTJ0B2s7nJrj5fVccfhJQZFS4tDlDGC3Ku9_A3Yrk3yffNs_Fq2A==\", \"x-amzn-trace-id\": \"Root=1-655e488a-4e53902b30b0d6675818e01a\", \"x-forwarded-for\": \"52.3.190.111, 18.68.30.134\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-11-22 18:29:30.126",
        "@message": "[INFO]\t2023-11-22T18:29:30.126Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-11-22 18:29:30.135",
        "@message": "[DEBUG]\t2023-11-22T18:29:30.135Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\tazul.terra\t_request('GET', https://data.terra.bio/api/repository/v1/snapshots/roleMap, headers=None, timeout=5.0, body=None)"
    },
    {
        "@timestamp": "2023-11-22 18:29:35.141",
        "@message": "[WARNING]\t2023-11-22T18:29:35.141Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\turllib3.connectionpool\tRetrying (Retry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='data.terra.bio', port=443): Read timed out. (read timeout=5.0)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-11-22 18:29:35.462",
        "@message": "[DEBUG]\t2023-11-22T18:29:35.462Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\tazul.terra\t_request(…) -> 5.327s 200 b'{\"roleMap\":{\"f3283538-c86e-4d2b-b6fb-c51d3479b9cc\":[\"reader\"],\"82336861-0e39-497f-bdbe-03923f5f36ab\":[\"reader\"],\"5f006aa6-bae4-4241-a334-4f0e0b731c35\":[\"reader\"],\"c25f206f-c5de-48f2-9dfa-7ab41221d6eb\":[\"reader\"],\"bc7f344d-ff18-4a10-8f59-518324ad4126\":[\"...'"
    },
    {
        "@timestamp": "2023-11-22 18:29:35.508",
        "@message": "[INFO]\t2023-11-22T18:29:35.508Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\telasticsearch\tMaking POST request to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp32_files_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp32_files_aggregate/_search)"
    },
    {
        "@timestamp": "2023-11-22 18:29:35.508",
        "@message": "[INFO]\t2023-11-22T18:29:35.508Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\telasticsearch\t… with request body b'{\"post_filter\":{\"bool\":{\"must\":[{\"constant_score\":{\"filter\":{\"terms\":{\"sources.id.keyword\":[\"4e6b4bd3-8534-4ebf-868b-8a3ed739...'"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.952",
        "@message": "[INFO]\t2023-11-22T18:29:39.952Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\telasticsearch\tGot 200 response after 4.444s from POST to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp32_files_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp32_files_aggregate/_search)"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.953",
        "@message": "[INFO]\t2023-11-22T18:29:39.953Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\telasticsearch\t… with response body '{\"took\":4372,\"timed_out\":false,\"_shards\":{\"total\":1,\"successful\":1,\"skipped\":0,\"failed\":0},\"hits\":{\"total\":{\"value\":508690,\"rel…'"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.978",
        "@message": "[DEBUG]\t2023-11-22T18:29:39.978Z\tbe4c63b2-8594-44fa-9657-7d56ee386986\tazul.chalice\tReturning 200 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"pagination\": {\"count\": 1, \"total\": 508690, \"size\": 1, \"next\": \"[https://service.azul.data.humancellatlas.org/index/files?catalog=dcp32&filters=%7B%7D&search_after=%5B%2200027d78-bcde-444c-b51c-b7446cdf9ea9_qc.bam%22%2C+%221cfe9091-ab53-58d8-9815-2c1216f240b4%22%5D&sort=fileName&order=asc&size=1\](https://service.azul.data.humancellatlas.org/index/files?catalog=dcp32&filters=%7B%7D&search_after=%5B%2200027d78-bcde-444c-b51c-b7446cdf9ea9_qc.bam%22%2C+%221cfe9091-ab53-58d8-9815-2c1216f240b4%22%5D&sort=fileName&order=asc&size=1%5C)", \"previous\": null, \"pages\": 508690, \"sort\": \"fileName\", \"order\": \"asc\"}, \"termFacets\": {\"organ\": {\"terms\": [{\"term\": \"brain\", \"count\": 85138}, {\"term\": \"blood\", \"count\": 46661}, {\"term\": \"pancreas\", \"count\": 36960}, {\"term\": \"adipose tissue\", \"count\": 33236}, {\"term\": \"heart\", \"count\": 30090}, {\"term\": \"decidua\", \"count\": 25162}, {\"term\": \"lung\", \"count\": 23468}, {\"term\": null, \"count\": 21101}, {\"term\": \"bone tissue\", \"count\": 20303}, {\"term\": \"large intestine\", \"count\": 18584}, {\"term\": \"skin of body\", \"count\": 17414}, {\"term\": \"embryo\", \"count\": 15518}, {\"term\": \"liver\", \"count\": 14815}, {\"term\": \"lymph node\", \"count\": 13720}, {\"term\": \"tumor\", \"count\": 12739}, {\"term\": \"hematopoietic system\", \"count\": 12024}, {\"te"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.989",
        "@message": "END RequestId: be4c63b2-8594-44fa-9657-7d56ee386986\n"
    },
    {
        "@timestamp": "2023-11-22 18:29:39.989",
        "@message": "REPORT RequestId: be4c63b2-8594-44fa-9657-7d56ee386986\tDuration: 9863.97 ms\tBilled Duration: 9864 ms\tMemory Size: 2048 MB\tMax Memory Used: 216 MB\t\n"
    }
]

[dsotirho-ucsc]

Assignee to specify solution (extending Retry)

[hannes-ucsc]

Index: src/azul/http.py
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
diff --git a/src/azul/http.py b/src/azul/http.py
--- a/src/azul/http.py  (revision e9ce6c98a4a8cfdf0a464c9e34af98cc28c53f01)
+++ b/src/azul/http.py  (date 1701283433792)
@@ -4,10 +4,3 @@

 def http_client() -> urllib3.PoolManager:
     return urllib3.PoolManager(ca_certs=certifi.where())
-
-
-class RetryAfter301(urllib3.Retry):
-    """
-    A retry policy that honors the Retry-After header on 301 status responses
-    """
-    RETRY_AFTER_STATUS_CODES = urllib3.Retry.RETRY_AFTER_STATUS_CODES | {301}
Index: src/azul/terra.py
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
diff --git a/src/azul/terra.py b/src/azul/terra.py
--- a/src/azul/terra.py (revision e9ce6c98a4a8cfdf0a464c9e34af98cc28c53f01)
+++ b/src/azul/terra.py (date 1701283370544)
@@ -14,6 +14,7 @@
 from typing import (
     ClassVar,
     Optional,
+    Self,
 )

 import attrs
@@ -322,6 +323,51 @@
         super().__init__('Snapshot listing changed while we were paging through it')

+class TerraRetry(urllib3.Retry):
+    start: float
+    timeout: float
+    retries: int
+
+    @classmethod
+    def create(cls, *, start: float, timeout: float, retries: int) -> Self:
+        # No retries on redirect status codes. Limited retries on 500 and 503
+        # status codes, and I/O errors such as refused or dropped connections.
+        # The latter are actually very likely if connections from the pool are
+        # reused after a long period of idleness. That's why we need at least
+        # one retry on read …
+        self = cls(total=None,
+                   connect=retries,
+                   read=retries + 1,
+                   redirect=0,
+                   status=retries,
+                   other=retries,
+                   status_forcelist={500, 503})
+        self.retries = retries
+        self.start = start
+        self.timeout = timeout
+        return self
+
+    def is_exhausted(self):
+        # … but only if the first read attempt failed quickly, in under 10ms.
+        # Otherwise, genuine read errors that don't result from a stale pool
+        # connection could exceed the overall timeout by as much as 100%. The
+        # point of zero retries is to guarantee that the timeout is not
+        # exceeded.
+        return (
+            super().is_exhausted()
+            or self.retries == 0 and time() - self.start - self.timeout < .01
+        )
+
+    def new(self, **kwargs) -> Self:
+        # This is a copy constructor that's used to create a new instance with
+        # decremented retry counters. The `is_exhausted` method is called on
+        # the copy in order to determine if another attempt should be made.
+        return super().new(start=self.start,
+                           timeout=self.timeout,
+                           retries=self.retries,
+                           **kwargs)
+
+
 @attrs.frozen(kw_only=True)
 class TerraClient(OAuth2Client):
     """
@@ -342,16 +388,7 @@
                   method, url, headers, timeout, body)
         start = time()
         try:
-            # Limited retries on I/O errors such as refused or dropped
-            # connections. The latter are actually very likely if connections
-            # from the pool are reused after a long period of idleness. That's
-            # why we need at least one retry on read.
-            retry = urllib3.Retry(total=None,
-                                  connect=retries,
-                                  read=retries + 1,
-                                  redirect=0,
-                                  status=0,
-                                  other=retries)
+            retry = TerraRetry.create(start=start, timeout=timeout, retries=retries)
             response = self._http_client.request(method,
                                                  str(url),
                                                  headers=headers,

The part that changes status=0 to status=retries and status_forcelist=… should be separate commit, since it is somewhat unrelated. Same with the deletion of RetryAfter301.

[hannes-ucsc]

For demo, show that the log line urllib3.connectionpool\tRetrying is not emitted for any Terra requests.

[dsotirho-ucsc]

Issue appears not to be fixed.

## /aws/lambda/azul-service-dev-servicecachehealth

[
    {
        "@timestamp": "2023-12-07 07:13:49.835",
        "@message": "START RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.836",
        "@message": "[INFO]\t2023-12-07T07:13:49.836Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.836",
        "@message": "[INFO]\t2023-12-07T07:13:49.836Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.836",
        "@message": "[INFO]\t2023-12-07T07:13:49.836Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.852",
        "@message": "[INFO]\t2023-12-07T07:13:49.852Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\tGot 200 response after 0.016s from HEAD to [https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.852",
        "@message": "[INFO]\t2023-12-07T07:13:49.852Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.852",
        "@message": "[INFO]\t2023-12-07T07:13:49.852Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-12-07 07:13:49.853",
        "@message": "[INFO]\t2023-12-07T07:13:49.853Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tMaking HEAD request to https://service.dev.singlecell.gi.ucsc.edu/index/files?size=1"
    },
    {
        "@timestamp": "2023-12-07 07:13:59.893",
        "@message": "2023-12-07T07:13:59.893Z 545424e8-5a78-49e4-83a1-417f7d0062e2 Task timed out after 10.06 seconds\n\n"
    },
    {
        "@timestamp": "2023-12-07 07:13:59.893",
        "@message": "END RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2\n"
    },
    {
        "@timestamp": "2023-12-07 07:13:59.893",
        "@message": "REPORT RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2\tDuration: 10057.48 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 124 MB\t\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:02.028",
        "@message": "START RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:02.028",
        "@message": "[INFO]\t2023-12-07T07:15:02.028Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-12-07 07:15:02.028",
        "@message": "[DEBUG]\t2023-12-07T07:15:02.028Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\[tazul.es](http://tazul.es/)\tCreating ES client [[vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443](http://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443/)]"
    },
    {
        "@timestamp": "2023-12-07 07:15:02.194",
        "@message": "[INFO]\t2023-12-07T07:15:02.194Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tbotocore.credentials\tFound credentials in environment variables."
    },
    {
        "@timestamp": "2023-12-07 07:15:03.271",
        "@message": "[INFO]\t2023-12-07T07:15:03.215Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tbotocore.credentials\tFound credentials in environment variables."
    },
    {
        "@timestamp": "2023-12-07 07:15:03.272",
        "@message": "[INFO]\t2023-12-07T07:15:03.272Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.291",
        "@message": "[INFO]\t2023-12-07T07:15:03.272Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.512",
        "@message": "[INFO]\t2023-12-07T07:15:03.512Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\tGot 200 response after 0.221s from HEAD to [https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-dev-atlcgwfjbk6dvrtmiaskbs2swa.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.512",
        "@message": "[INFO]\t2023-12-07T07:15:03.512Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.512",
        "@message": "[INFO]\t2023-12-07T07:15:03.512Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.513",
        "@message": "[INFO]\t2023-12-07T07:15:03.513Z\t545424e8-5a78-49e4-83a1-417f7d0062e2\tazul.health\tMaking HEAD request to https://service.dev.singlecell.gi.ucsc.edu/index/projects?size=1"
    },
    {
        "@timestamp": "2023-12-07 07:15:12.092",
        "@message": "2023-12-07T07:15:12.092Z 545424e8-5a78-49e4-83a1-417f7d0062e2 Task timed out after 10.06 seconds\n\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:12.092",
        "@message": "END RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:12.092",
        "@message": "REPORT RequestId: 545424e8-5a78-49e4-83a1-417f7d0062e2\tDuration: 10064.36 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 108 MB\t\n"
    }
]

##  /aws/lambda/azul-service-dev

[
    {
        "@timestamp": "2023-12-07 07:15:03.733",
        "@message": "START RequestId: 0a813399-8247-4eaa-a8d7-7672510cb531 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.734",
        "@message": "[INFO]\t2023-12-07T07:15:03.734Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.chalice\tReceived HEAD request for '/index/projects', 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.dev.singlecell.gi.ucsc.edu](http://service.dev.singlecell.gi.ucsc.edu/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [3d4bfc42e9575ee1f9559241c9e3f464.cloudfront.net](http://3d4bfc42e9575ee1f9559241c9e3f464.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"fPUkC4Vh551WBtxYtXQ-ndtIffOAj3EH_5ewUr5vZjBe6HqDJ2EpqQ==\", \"x-amzn-trace-id\": \"Root=1-657170f7-6667142c60d9945443d8056d\", \"x-forwarded-for\": \"3.214.122.182, 15.158.50.142\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-12-07 07:15:03.734",
        "@message": "[INFO]\t2023-12-07T07:15:03.734Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-12-07 07:15:03.739",
        "@message": "[INFO]\t2023-12-07T07:15:03.738Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.boto3\tdynamodb.GetItem:\tMaking POST request to https://dynamodb.us-east-1.amazonaws.com/"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.740",
        "@message": "[INFO]\t2023-12-07T07:15:03.740Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.boto3\tdynamodb.GetItem:\t… with request body b'{\"TableName\": \"azul-sources_cache_by_auth-dev\", \"Key\": {\"identity\": {\"S\": \"dcp3:\"}}, \"ProjectionExpression\": \"sources,expirat...'"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.743",
        "@message": "[INFO]\t2023-12-07T07:15:03.743Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.boto3\tdynamodb.GetItem:\tGot 200 response"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.743",
        "@message": "[INFO]\t2023-12-07T07:15:03.743Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.boto3\tdynamodb.GetItem:\t… with response body b'{\"Item\":{\"expiration\":{\"N\":\"1701933110\"},\"sources\":{\"S\":\"[\\\\\"251c52e6-3bda-48df-a4f2-50aa759d7d80\\\\\", \\\\\"dc7a86a7-e75c-4012-934b...'"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.744",
        "@message": "[INFO]\t2023-12-07T07:15:03.744Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.terra\tMaking GET request to 'https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap'"
    },
    {
        "@timestamp": "2023-12-07 07:15:03.744",
        "@message": "[DEBUG]\t2023-12-07T07:15:03.744Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.terra\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 07:15:08.767",
        "@message": "[WARNING]\t2023-12-07T07:15:08.767Z\t0a813399-8247-4eaa-a8d7-7672510cb531\turllib3.connectionpool\tRetrying (LimitedRetry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='[jade.datarepo-dev.broadinstitute.org](http://jade.datarepo-dev.broadinstitute.org/)', port=443): Read timed out. (read timeout=5)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-12-07 07:15:13.792",
        "@message": "[DEBUG]\t2023-12-07T07:15:13.792Z\t0a813399-8247-4eaa-a8d7-7672510cb531\tazul.chalice\tReturning 503 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"Code\": \"ServiceUnavailableError\", \"Message\": \"No response from https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap within 5 seconds\"}"
    },
    {
        "@timestamp": "2023-12-07 07:15:13.793",
        "@message": "END RequestId: 0a813399-8247-4eaa-a8d7-7672510cb531\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:13.793",
        "@message": "REPORT RequestId: 0a813399-8247-4eaa-a8d7-7672510cb531\tDuration: 10059.71 ms\tBilled Duration: 10060 ms\tMemory Size: 2048 MB\tMax Memory Used: 168 MB\t\n"
    }
]

[dsotirho-ucsc]

## /aws/lambda/azul-service-anvildev-servicecachehealth

[
    {
        "@timestamp": "2023-12-07 07:15:04.308",
        "@message": "START RequestId: 0c0a5f07-c291-4169-adaa-d26c7c2764a3 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.309",
        "@message": "[INFO]\t2023-12-07T07:15:04.309Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.309",
        "@message": "[INFO]\t2023-12-07T07:15:04.309Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.309",
        "@message": "[INFO]\t2023-12-07T07:15:04.309Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.339",
        "@message": "[INFO]\t2023-12-07T07:15:04.339Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\telasticsearch\tGot 200 response after 0.030s from HEAD to [https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-anvildev-jubbechxp4wxzfj2kf2hiewjgi.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.340",
        "@message": "[INFO]\t2023-12-07T07:15:04.340Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.340",
        "@message": "[INFO]\t2023-12-07T07:15:04.340Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.349",
        "@message": "[INFO]\t2023-12-07T07:15:04.349Z\t0c0a5f07-c291-4169-adaa-d26c7c2764a3\tazul.health\tMaking HEAD request to https://service.anvil.gi.ucsc.edu/index/bundles?size=1"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.369",
        "@message": "2023-12-07T07:15:14.369Z 0c0a5f07-c291-4169-adaa-d26c7c2764a3 Task timed out after 10.06 seconds\n\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.369",
        "@message": "END RequestId: 0c0a5f07-c291-4169-adaa-d26c7c2764a3\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.369",
        "@message": "REPORT RequestId: 0c0a5f07-c291-4169-adaa-d26c7c2764a3\tDuration: 10060.86 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 121 MB\t\n"
    }
]

## /aws/lambda/azul-service-anvildev

[
    {
        "@timestamp": "2023-12-07 07:15:04.517",
        "@message": "START RequestId: 0d958c0d-0495-4275-8206-9f8688bde2eb Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.517",
        "@message": "[INFO]\t2023-12-07T07:15:04.517Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.chalice\tReceived HEAD request for '/index/bundles', 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](http://service.anvil.gi.ucsc.edu/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [b838afd3b92ba725d13555ccc038c6ce.cloudfront.net](http://b838afd3b92ba725d13555ccc038c6ce.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"afuCfxFz6YmMKSF-ExiC_j04skuFd1OElCaQnFt5DbgnnStGYxskRg==\", \"x-amzn-trace-id\": \"Root=1-657170f8-5dc458dc68761c120d09de69\", \"x-forwarded-for\": \"54.211.146.213, 18.68.30.180\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-12-07 07:15:04.517",
        "@message": "[INFO]\t2023-12-07T07:15:04.517Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-12-07 07:15:04.518",
        "@message": "[INFO]\t2023-12-07T07:15:04.518Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.boto3\tdynamodb.GetItem:\tMaking POST request to https://dynamodb.us-east-1.amazonaws.com/"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.519",
        "@message": "[INFO]\t2023-12-07T07:15:04.519Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.boto3\tdynamodb.GetItem:\t… with request body b'{\"TableName\": \"azul-sources_cache_by_auth-anvildev\", \"Key\": {\"identity\": {\"S\": \"anvil:\"}}, \"ProjectionExpression\": \"sources,e...'"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.525",
        "@message": "[INFO]\t2023-12-07T07:15:04.525Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.boto3\tdynamodb.GetItem:\tGot 200 response"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.525",
        "@message": "[INFO]\t2023-12-07T07:15:04.525Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.boto3\tdynamodb.GetItem:\t… with response body b'{\"Item\":{\"expiration\":{\"N\":\"1701933186\"},\"sources\":{\"S\":\"[\\\\\"2efd70fe-5e5b-453c-a851-e31ed0229e4f\\\\\", \\\\\"006f69b6-7f42-4eba-81df...'"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.526",
        "@message": "[INFO]\t2023-12-07T07:15:04.526Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.terra\tMaking GET request to 'https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap'"
    },
    {
        "@timestamp": "2023-12-07 07:15:04.526",
        "@message": "[DEBUG]\t2023-12-07T07:15:04.526Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.terra\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 07:15:09.648",
        "@message": "[WARNING]\t2023-12-07T07:15:09.648Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\turllib3.connectionpool\tRetrying (LimitedRetry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='[jade.datarepo-dev.broadinstitute.org](http://jade.datarepo-dev.broadinstitute.org/)', port=443): Read timed out. (read timeout=5)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.672",
        "@message": "[DEBUG]\t2023-12-07T07:15:14.671Z\t0d958c0d-0495-4275-8206-9f8688bde2eb\tazul.chalice\tReturning 503 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"Code\": \"ServiceUnavailableError\", \"Message\": \"No response from https://jade.datarepo-dev.broadinstitute.org/api/repository/v1/snapshots/roleMap within 5 seconds\"}"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.673",
        "@message": "END RequestId: 0d958c0d-0495-4275-8206-9f8688bde2eb\n"
    },
    {
        "@timestamp": "2023-12-07 07:15:14.673",
        "@message": "REPORT RequestId: 0d958c0d-0495-4275-8206-9f8688bde2eb\tDuration: 10156.29 ms\tBilled Duration: 10157 ms\tMemory Size: 2048 MB\tMax Memory Used: 164 MB\t\n"
    }
]

[dsotirho-ucsc]

## /aws/lambda/azul-service-anvilprod-servicecachehealth

[
    {
        "@timestamp": "2023-12-07 09:13:37.675",
        "@message": "START RequestId: 75e3a336-017c-4e78-b809-fd4360b50a4e Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.676",
        "@message": "[INFO]\t2023-12-07T09:13:37.675Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\tazul.health\tGetting health property 'elasticsearch'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.676",
        "@message": "[INFO]\t2023-12-07T09:13:37.676Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\telasticsearch\tMaking HEAD request to [https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.676",
        "@message": "[INFO]\t2023-12-07T09:13:37.676Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\telasticsearch\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.689",
        "@message": "[INFO]\t2023-12-07T09:13:37.689Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\telasticsearch\tGot 200 response after 0.013s from HEAD to [https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com:443/](https://vpc-azul-index-anvilprod-ggipah4skn2ftt47u4xgvydzqm.us-east-1.es.amazonaws.com/)"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.689",
        "@message": "[INFO]\t2023-12-07T09:13:37.689Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\telasticsearch\t… with response body ''"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.689",
        "@message": "[INFO]\t2023-12-07T09:13:37.689Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.690",
        "@message": "[INFO]\t2023-12-07T09:13:37.690Z\t75e3a336-017c-4e78-b809-fd4360b50a4e\tazul.health\tMaking HEAD request to https://service.prod.anvil.gi.ucsc.edu/index/biosamples?size=1"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.712",
        "@message": "2023-12-07T09:13:47.712Z 75e3a336-017c-4e78-b809-fd4360b50a4e Task timed out after 10.04 seconds\n\n"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.712",
        "@message": "END RequestId: 75e3a336-017c-4e78-b809-fd4360b50a4e\n"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.712",
        "@message": "REPORT RequestId: 75e3a336-017c-4e78-b809-fd4360b50a4e\tDuration: 10037.15 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 122 MB\t\n"
    }
]

## /aws/lambda/azul-service-anvilprod

[
    {
        "@timestamp": "2023-12-07 09:13:37.852",
        "@message": "START RequestId: 1ff35ae5-5212-4601-8c17-0ce1551f7376 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.853",
        "@message": "[INFO]\t2023-12-07T09:13:37.853Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.chalice\tReceived HEAD request for '/index/biosamples', 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.prod.anvil.gi.ucsc.edu](http://service.prod.anvil.gi.ucsc.edu/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [077b94dab77b8114aebf503be197d7d8.cloudfront.net](http://077b94dab77b8114aebf503be197d7d8.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"GnkSitmbr88n4xIhMbYZnetye0H9UeUQwARxOeDrPBuKndfl1BH7kA==\", \"x-amzn-trace-id\": \"Root=1-65718cc1-43ab32f844703fac4fa46c82\", \"x-forwarded-for\": \"54.221.248.210, 130.176.98.68\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-12-07 09:13:37.853",
        "@message": "[INFO]\t2023-12-07T09:13:37.853Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-12-07 09:13:37.854",
        "@message": "[INFO]\t2023-12-07T09:13:37.854Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.boto3\tdynamodb.GetItem:\tMaking POST request to https://dynamodb.us-east-1.amazonaws.com/"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.855",
        "@message": "[INFO]\t2023-12-07T09:13:37.855Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.boto3\tdynamodb.GetItem:\t… with request body b'{\"TableName\": \"azul-sources_cache_by_auth-anvilprod\", \"Key\": {\"identity\": {\"S\": \"anvil3:\"}}, \"ProjectionExpression\": \"sources...'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.862",
        "@message": "[INFO]\t2023-12-07T09:13:37.862Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.boto3\tdynamodb.GetItem:\tGot 200 response"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.862",
        "@message": "[INFO]\t2023-12-07T09:13:37.862Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.boto3\tdynamodb.GetItem:\t… with response body b'{\"Item\":{\"expiration\":{\"N\":\"1701940358\"},\"sources\":{\"S\":\"[\\\\\"4d333d73-7728-4c8c-b615-d2ddefa37eb0\\\\\", \\\\\"95be012f-91ad-4082-879e...'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.864",
        "@message": "[INFO]\t2023-12-07T09:13:37.864Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\tMaking POST request to 'https://oauth2.googleapis.com/token'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.864",
        "@message": "[DEBUG]\t2023-12-07T09:13:37.864Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\t… with request body b'assertion=eyJ0eXAiOiAiSldUIiwgImFsZyI6ICJSUzI1NiIsICJraWQiOiAiNjlkMTRlZmQ2OGE2ZmRhMzNlNjE0NjdjOTc3YTA4ZWViN2Y0MGVmZiJ9.eyJpYX...'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.900",
        "@message": "[INFO]\t2023-12-07T09:13:37.900Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\tGot 200 response after 0.036s from POST to https://oauth2.googleapis.com/token"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.900",
        "@message": "[DEBUG]\t2023-12-07T09:13:37.900Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\t… with response headers HTTPHeaderDict({'Content-Type': 'application/json; charset=UTF-8', 'Vary': 'X-Origin, Referer, Origin,Accept-Encoding', 'Date': 'Thu, 07 Dec 2023 09:13:37 GMT', 'Server': 'scaffolding on HTTPServer2', 'Cache-Control': 'private', 'X-XSS-Protection': '0', 'X-Frame-Options': 'SAMEORIGIN', 'X-Content-Type-Options': 'nosniff', 'Alt-Svc': 'h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000', 'Accept-Ranges': 'none', 'Transfer-Encoding': 'chunked'})"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.900",
        "@message": "[DEBUG]\t2023-12-07T09:13:37.900Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\t… with response body b'{\"access_token\":\"ya29.c.c0AY_VpZhCgSavHoVBoKxNPcRUywvK1Wggcjyls8KAIjThB7yDkJZNdPgE7tc1s2OkpPcSmLNS8cPC8Jm6NtwrUSfH9jrtIMJ8LTA...'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.900",
        "@message": "[INFO]\t2023-12-07T09:13:37.900Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\tMaking GET request to 'https://data.terra.bio/api/repository/v1/snapshots/roleMap'"
    },
    {
        "@timestamp": "2023-12-07 09:13:37.901",
        "@message": "[DEBUG]\t2023-12-07T09:13:37.901Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.terra\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 09:13:42.907",
        "@message": "[WARNING]\t2023-12-07T09:13:42.907Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\turllib3.connectionpool\tRetrying (LimitedRetry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='data.terra.bio', port=443): Read timed out. (read timeout=5)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.978",
        "@message": "[DEBUG]\t2023-12-07T09:13:47.978Z\t1ff35ae5-5212-4601-8c17-0ce1551f7376\tazul.chalice\tReturning 503 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"Code\": \"ServiceUnavailableError\", \"Message\": \"No response from https://data.terra.bio/api/repository/v1/snapshots/roleMap within 5 seconds\"}"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.979",
        "@message": "END RequestId: 1ff35ae5-5212-4601-8c17-0ce1551f7376\n"
    },
    {
        "@timestamp": "2023-12-07 09:13:47.979",
        "@message": "REPORT RequestId: 1ff35ae5-5212-4601-8c17-0ce1551f7376\tDuration: 10126.46 ms\tBilled Duration: 10127 ms\tMemory Size: 2048 MB\tMax Memory Used: 162 MB\t\n"
    }
]

[dsotirho-ucsc]

## /aws/lambda/azul-service-prod-servicecachehealth

[
    {
        "@timestamp": "2023-12-07 14:12:29.821",
        "@message": "START RequestId: 3bbc9be2-f115-4c9c-a078-ecc14b8507e8 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.821",
        "@message": "[INFO]\t2023-12-07T14:12:29.821Z\t3bbc9be2-f115-4c9c-a078-ecc14b8507e8\tazul.health\tGetting health property 'api_endpoints'"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.822",
        "@message": "[INFO]\t2023-12-07T14:12:29.822Z\t3bbc9be2-f115-4c9c-a078-ecc14b8507e8\tazul.health\tMaking HEAD request to https://service.azul.data.humancellatlas.org/index/files?size=1"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.871",
        "@message": "2023-12-07T14:12:39.871Z 3bbc9be2-f115-4c9c-a078-ecc14b8507e8 Task timed out after 10.05 seconds\n\n"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.871",
        "@message": "END RequestId: 3bbc9be2-f115-4c9c-a078-ecc14b8507e8\n"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.871",
        "@message": "REPORT RequestId: 3bbc9be2-f115-4c9c-a078-ecc14b8507e8\tDuration: 10050.15 ms\tBilled Duration: 10000 ms\tMemory Size: 128 MB\tMax Memory Used: 121 MB\t\n"
    }
]

## /aws/lambda/azul-service-prod

[
    {
        "@timestamp": "2023-12-07 14:12:29.978",
        "@message": "START RequestId: 6f0cec52-7923-4676-9256-071a6481c1e9 Version: $LATEST\n"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.978",
        "@message": "[INFO]\t2023-12-07T14:12:29.978Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.chalice\tReceived 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.azul.data.humancellatlas.org](http://service.azul.data.humancellatlas.org/)\", \"user-agent\": \"python-requests/2.31.0\", \"via\": \"1.1 [1e54a46a2c47322a41a5f070c060e878.cloudfront.net](http://1e54a46a2c47322a41a5f070c060e878.cloudfront.net/) (CloudFront)\", \"x-amz-cf-id\": \"QacerKSqa1vkLIC1wt-X1R0z_yZnHTLkmdr5uNy_MjFUoArDq2bX5w==\", \"x-amzn-trace-id\": \"Root=1-6571d2cd-3b112c762a4035c358825b53\", \"x-forwarded-for\": \"35.175.100.160, 18.68.30.151\", \"x-forwarded-port\": \"443\", \"x-forwarded-proto\": \"https\"}}."
    },
    {
        "@timestamp": "2023-12-07 14:12:29.979",
        "@message": "[INFO]\t2023-12-07T14:12:29.979Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.chalice\tDid not authenticate request."
    },
    {
        "@timestamp": "2023-12-07 14:12:29.980",
        "@message": "[INFO]\t2023-12-07T14:12:29.980Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.GetItem:\tMaking POST request to https://dynamodb.us-east-1.amazonaws.com/"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.980",
        "@message": "[INFO]\t2023-12-07T14:12:29.980Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.GetItem:\t… with request body b'{\"TableName\": \"azul-sources_cache_by_auth-prod\", \"Key\": {\"identity\": {\"S\": \"dcp33:\"}}, \"ProjectionExpression\": \"sources,expir...'"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.997",
        "@message": "[INFO]\t2023-12-07T14:12:29.997Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.GetItem:\tGot 200 response"
    },
    {
        "@timestamp": "2023-12-07 14:12:29.997",
        "@message": "[INFO]\t2023-12-07T14:12:29.997Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.GetItem:\t… with response body b'{\"Item\":{\"expiration\":{\"N\":\"1701958346\"},\"sources\":{\"S\":\"[\\\\\"e8512de7-750c-4ea2-89b5-59005475018b\\\\\", \\\\\"f7b42ded-e60f-45cf-bf1b...'"
    },
    {
        "@timestamp": "2023-12-07 14:12:30.180",
        "@message": "[INFO]\t2023-12-07T14:12:30.180Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.terra\tMaking GET request to 'https://data.terra.bio/api/repository/v1/snapshots/roleMap'"
    },
    {
        "@timestamp": "2023-12-07 14:12:30.181",
        "@message": "[DEBUG]\t2023-12-07T14:12:30.180Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.terra\t… without request body"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.254",
        "@message": "[WARNING]\t2023-12-07T14:12:35.254Z\t6f0cec52-7923-4676-9256-071a6481c1e9\turllib3.connectionpool\tRetrying (LimitedRetry(total=None, connect=0, read=0, redirect=0, status=0)) after connection broken by 'ReadTimeoutError(\"HTTPSConnectionPool(host='data.terra.bio', port=443): Read timed out. (read timeout=5)\")': /api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.672",
        "@message": "[INFO]\t2023-12-07T14:12:35.672Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.terra\tGot 200 response after 5.492s from GET to https://data.terra.bio/api/repository/v1/snapshots/roleMap"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.673",
        "@message": "[DEBUG]\t2023-12-07T14:12:35.673Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.terra\t… with response headers HTTPHeaderDict({'Date': 'Thu, 07 Dec 2023 14:12:35 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': 'em2roWEG', 'Content-Type': 'application/json', 'Content-Length': '43625', 'Vary': 'Accept-Encoding,Origin', 'Via': '1.1 google', 'Alt-Svc': 'h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000'})"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.673",
        "@message": "[DEBUG]\t2023-12-07T14:12:35.673Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.terra\t… with response body b'{\"roleMap\":{\"f3283538-c86e-4d2b-b6fb-c51d3479b9cc\":[\"reader\"],\"82336861-0e39-497f-bdbe-03923f5f36ab\":[\"reader\"],\"5f006aa6-bae...'"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.676",
        "@message": "[INFO]\t2023-12-07T14:12:35.676Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.PutItem:\tMaking POST request to https://dynamodb.us-east-1.amazonaws.com/"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.676",
        "@message": "[INFO]\t2023-12-07T14:12:35.676Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.PutItem:\t… with request body b'{\"TableName\": \"azul-sources_cache_by_auth-prod\", \"Item\": {\"identity\": {\"S\": \"dcp33:\"}, \"sources\": {\"S\": \"[\\\\\"0370ee0b-9111-449...'"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.684",
        "@message": "[INFO]\t2023-12-07T14:12:35.684Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.PutItem:\tGot 200 response"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.684",
        "@message": "[INFO]\t2023-12-07T14:12:35.684Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.boto3\tdynamodb.PutItem:\t… with response body b'{}'"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.722",
        "@message": "[INFO]\t2023-12-07T14:12:35.722Z\t6f0cec52-7923-4676-9256-071a6481c1e9\telasticsearch\tMaking POST request to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp33_files_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp33_files_aggregate/_search)"
    },
    {
        "@timestamp": "2023-12-07 14:12:35.722",
        "@message": "[INFO]\t2023-12-07T14:12:35.722Z\t6f0cec52-7923-4676-9256-071a6481c1e9\telasticsearch\t… with request body b'{\"post_filter\":{\"bool\":{\"must\":[{\"constant_score\":{\"filter\":{\"terms\":{\"sources.id.keyword\":[\"0370ee0b-9111-449c-882b-b1b7e707...'"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.926",
        "@message": "[INFO]\t2023-12-07T14:12:39.926Z\t6f0cec52-7923-4676-9256-071a6481c1e9\telasticsearch\tGot 200 response after 4.202s from POST to [https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com:443/azul_v2_prod_dcp33_files_aggregate/_search](https://vpc-azul-index-prod-mjluewlvxikvhillefxotw2tbm.us-east-1.es.amazonaws.com/azul_v2_prod_dcp33_files_aggregate/_search)"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.926",
        "@message": "[INFO]\t2023-12-07T14:12:39.926Z\t6f0cec52-7923-4676-9256-071a6481c1e9\telasticsearch\t… with response body '{\"took\":4155,\"timed_out\":false,\"_shards\":{\"total\":1,\"successful\":1,\"skipped\":0,\"failed\":0},\"hits\":{\"total\":{\"value\":510724,\"rel…'"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.954",
        "@message": "[DEBUG]\t2023-12-07T14:12:39.954Z\t6f0cec52-7923-4676-9256-071a6481c1e9\tazul.chalice\tReturning 200 response with headers {\"Access-Control-Allow-Origin\": \"*\", \"Access-Control-Allow-Headers\": \"Authorization,Content-Type,X-Amz-Date,X-Amz-Security-Token,X-Api-Key\", \"Strict-Transport-Security\": \"max-age=31536000; includeSubDomains\"}. See next line for the first 1024 characters of the body.\n{\"pagination\": {\"count\": 1, \"total\": 510724, \"size\": 1, \"next\": \"[https://service.azul.data.humancellatlas.org/index/files?catalog=dcp33&filters=%7B%7D&search_after=%5B%2200027d78-bcde-444c-b51c-b7446cdf9ea9_qc.bam%22%2C+%221cfe9091-ab53-58d8-9815-2c1216f240b4%22%5D&sort=fileName&order=asc&size=1\](https://service.azul.data.humancellatlas.org/index/files?catalog=dcp33&filters=%7B%7D&search_after=%5B%2200027d78-bcde-444c-b51c-b7446cdf9ea9_qc.bam%22%2C+%221cfe9091-ab53-58d8-9815-2c1216f240b4%22%5D&sort=fileName&order=asc&size=1%5C)", \"previous\": null, \"pages\": 510724, \"sort\": \"fileName\", \"order\": \"asc\"}, \"termFacets\": {\"organ\": {\"terms\": [{\"term\": \"brain\", \"count\": 85138}, {\"term\": \"blood\", \"count\": 46666}, {\"term\": \"pancreas\", \"count\": 36960}, {\"term\": \"adipose tissue\", \"count\": 33236}, {\"term\": \"heart\", \"count\": 30090}, {\"term\": \"decidua\", \"count\": 25162}, {\"term\": \"lung\", \"count\": 23468}, {\"term\": null, \"count\": 21107}, {\"term\": \"bone tissue\", \"count\": 20303}, {\"term\": \"large intestine\", \"count\": 18584}, {\"term\": \"skin of body\", \"count\": 17443}, {\"term\": \"embryo\", \"count\": 15518}, {\"term\": \"liver\", \"count\": 14815}, {\"term\": \"lymph node\", \"count\": 13720}, {\"term\": \"tumor\", \"count\": 12739}, {\"term\": \"hematopoietic system\", \"count\": 12024}, {\"te"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.966",
        "@message": "END RequestId: 6f0cec52-7923-4676-9256-071a6481c1e9\n"
    },
    {
        "@timestamp": "2023-12-07 14:12:39.966",
        "@message": "REPORT RequestId: 6f0cec52-7923-4676-9256-071a6481c1e9\tDuration: 9988.34 ms\tBilled Duration: 9989 ms\tMemory Size: 2048 MB\tMax Memory Used: 192 MB\t\n"
    }
]