aws-powertools / powertools-lambda-typescript

Powertools is a developer toolkit to implement Serverless best practices and increase developer velocity.
https://docs.powertools.aws.dev/lambda/typescript/latest/
MIT No Attribution
1.56k stars 138 forks source link

Bug: CloudWatch envelope assumes data is always a JSON #3225

Open dreamorosi opened 9 hours ago

dreamorosi commented 9 hours ago

Expected Behavior

When processing Amazon CloudWatch Logs using an AWS Lambda function subscription, the logs are forwarded to the function. By using an envelope, customers can quickly access the contents of the message.

The envelope should decode the awslogs.data key and return the content of logEvents[*].

Current Behavior

Currently with an event that looks like the one below (see "details" for decoded version), the function throws an error because not all messages can be parsed as JSON strings:

{
  "awslogs": {
    "data": "H4sIAAAAAAAA/81VTW/bRhD9K8SiR9Ga2Z2Z3eFNjuUkRR0HltpDQsNYkSuHqD5ckrbjGv7vhRSnNdrIkJEceiNm3y7eezPzeG+WqeviZZreXSVTmKPRdHRxMp5MRq/HZmDWt6vUmsKwE8tkgdCKGZjF+vJ1u76+MoUZxttuuIjLWR2H3XqZ8nX/KbX5Ki7TF+Ckb1NcmsJYsDREGFocnm4wx6uPP/0ymo4n03OUCj1Hnge1JDHGmqvgQ0yzmFKsvBmY7nrWVW1z1Tfr1XGz6FPbmeKjeXXbt83lZWonfax+z0/uJk9wr1TGeHzIeYWjN5+mlm7Cz5/M+ZbW+Cat+s0T96apTWFcYFEB8hqIHbLzQohsJYAnJ44kECqSMnoEx+QCWtCNG32zTF0fl1emQG+VLQRl5DD46u2j+BwhtzhFKmwokA+Qw4eyT7GuFKuQB+tdTtHW+Qw95DOIPgQ3E9RU9m/fHZ+W/Zu0WKyzebteZlubD/quXJmHwfdp8HtqmExHZ9PsLP1xnbr+bV1k+1DPfktt16xXRfbY7F2EPRMTgzp0XoOoZ2AAQufJWhQmYSD1ahlpN2F9Svi+NIt0kxalKUqzddAMyq/n2+K3DN1guri8WjSry4s29hskbGqpvWmqL/cevy+uV3WaN6tUb2/9zWmL2dnyDfRzG+8u+jZW6aKpt3DMxaMIzee56AxS5cUSWZeAmKgC6+aledjhHlsAZlX1CIFVyfkQwDN7p+JJLIYAgp6do93tFnzq3vjd0Uub/QPYhT3ZnY3fn758Gsv+6LqN/XYe7QH4bNmV/WGzWKQ6++fEbcsnablu77JJ82cqMrQhOzks+5P4OXs8+LVLdZGJ39a/pTw46606VXRkWYLjQFbBBfEEZBGAgnfBOvaIpG6HchHlZ9dQ2JGdhZTXhJITQ53rHCAP6GNVOYS6cnut4YYwo6gGr8TsREhkM37g0FoKVtSDqicURUXYTViezz45EJUPZb8P8xdm30aDJwAQS8IuqIegGERdCLSZOUdMgpa8eOvsrmUQUf9/jpJHB5+NEgbIKUUOlmrmea0QKvEV2SS4I0qCs4FAwQYBS0ohKAdBZGLVzb5aBSb2woKO/a6/n3iAZ6Jkr7Z/P7udvf0Xu/9GyX5z+TRKnPuhUXL+8BdONu+NmQkAAA=="
  }
}
```json { "awslogs": { "data": { "messageType": "DATA_MESSAGE", "owner": "536254204126", "logGroup": "/aws/lambda/some-other-name", "logStream": "2024/10/21/OtherFn[$LATEST]16c175a5f89246aaad5c878aebaeeac7", "subscriptionFilters": [ "CwtriggerStack-MySubscriptionC96E1FB5-c1AHhT24v8Jh" ], "logEvents": [ { "id": "38569604798453153764115268074363468419149517103543812096", "timestamp": 1729520895158, "message": "2024-10-21T14:28:15.158Z\teadc91c8-8273-4a2d-b170-b0a7883b619e\tINFO\tHello from other.ts\n" }, { "id": "38569604798453153764115268074363468419149517103543812097", "timestamp": 1729520895158, "message": "START RequestId: eadc91c8-8273-4a2d-b170-b0a7883b619e Version: $LATEST\n" }, { "id": "38569604798475454509313798697505004137422165465049792514", "timestamp": 1729520895159, "message": "{\"level\":\"INFO\",\"message\":\"Hello from other.ts\",\"sampling_rate\":0,\"service\":\"service_undefined\",\"timestamp\":\"2024-10-21T14:28:15.158Z\",\"xray_trace_id\":\"1-671664ff-69b0ec7624423e04544c023f\"}\n" }, { "id": "38569604798520055999710859943788075573967462188061753347", "timestamp": 1729520895161, "message": "END RequestId: eadc91c8-8273-4a2d-b170-b0a7883b619e\n" }, { "id": "38569604798520055999710859943788075573967462188061753348", "timestamp": 1729520895161, "message": "REPORT RequestId: eadc91c8-8273-4a2d-b170-b0a7883b619e\tDuration: 2.07 ms\tBilled Duration: 3 ms\tMemory Size: 128 MB\tMax Memory Used: 67 MB\t\n" }, { "id": "38569604832729399134256835842903867404210048738235711493", "timestamp": 1729520896695, "message": "START RequestId: 65342b8e-d416-450d-9f00-817acc310dc3 Version: $LATEST\n" }, { "id": "38569604832751699879455366466045403122482697099741691910", "timestamp": 1729520896696, "message": "2024-10-21T14:28:16.696Z\t65342b8e-d416-450d-9f00-817acc310dc3\tINFO\tHello from other.ts\n" }, { "id": "38569604832774000624653897089186938840755345461247672327", "timestamp": 1729520896697, "message": "{\"level\":\"INFO\",\"message\":\"Hello from other.ts\",\"sampling_rate\":0,\"service\":\"service_undefined\",\"timestamp\":\"2024-10-21T14:28:16.696Z\",\"xray_trace_id\":\"1-67166500-4ea5824d55fd908c67c42e61\"}\n" }, { "id": "38569604832840902860249488958611545995573290545765613576", "timestamp": 1729520896700, "message": "END RequestId: 65342b8e-d416-450d-9f00-817acc310dc3\n" }, { "id": "38569604832840902860249488958611545995573290545765613577", "timestamp": 1729520896700, "message": "REPORT RequestId: 65342b8e-d416-450d-9f00-817acc310dc3\tDuration: 2.33 ms\tBilled Duration: 3 ms\tMemory Size: 128 MB\tMax Memory Used: 67 MB\t\n" } ] } } } ```

Error:

2024-10-21T14:31:16.011Z    1b55f3ae-54f6-4e5c-820f-fe4091cb7f14    ERROR   Invoke Error    {
    "errorType": "ParseError",
    "errorMessage": "Failed to parse envelope. This error was caused by: Unexpected non-whitespace character after JSON at position 4.",
    "name": "ParseError",
    "stack": [
        "ParseError: Failed to parse envelope. This error was caused by: Unexpected non-whitespace character after JSON at position 4.",
        "    at Object.parse (file:///var/task/index.mjs:2:69766)",
        "    at file:///var/task/index.mjs:2:82281",
        "    at Array.map (<anonymous>)",
        "    at Object.parse (file:///var/task/index.mjs:2:82272)",
        "    at Runtime.Vl [as handler] (file:///var/task/index.mjs:2:82763)",
        "    at Runtime.handleOnceNonStreaming (file:///var/runtime/index.mjs:1173:29)"
    ]
}

Code snippet

N/A

Steps to Reproduce

N/A

Possible Solution

No response

Powertools for AWS Lambda (TypeScript) version

latest

AWS Lambda function runtime

20.x

Packaging format used

npm

Execution logs

No response

dreamorosi commented 9 hours ago

While working on this, we should also modify the envelope to return the entirety of logEvents rather than logEvents[*].message only.

After discussing this internally with the Python team, we agreed that the reference implementation in Python could be improved. The reasoning is that when processing log messages, the message alone without the timestamp is kind of useless.

The Python version won't be able to fix this soon due to it being a breaking change, for us we'll fix this in a minor release since the current implementation is completely broken and as such, it's unlikely any customer is relying on the current behavior.