Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cloudwatch logs formatted similar to native Runtime, v2 #590

Merged
merged 6 commits into from
Mar 14, 2020

Conversation

mnapoli
Copy link
Member

@mnapoli mnapoli commented Mar 14, 2020

This PR starts from #579 and adds tests + adds a few things.

The problem

To reuse what @deleugpn described in #579: current errors in PHP lambdas appear like this in logs (CloudWatch):

This is hard to read, and this is not consistent with official runtimes like NodeJS. NodeJS logs an exception like this:

This PR

With these changes, here is how logs will look like:

Capture d’écran 2020-03-14 à 12 21 53

In short, the error is formatted in JSON. Looking good!

Other changes:

  • the log message is simpler: it is the error/exception message only
    • it no longer contains Fatal error: (the log line contains Invoke Error, so that's less noise)
    • it no longer contains Uncaught exception:: we don't want users to think "oh I need to catch exceptions" -> exceptions should not be caught, instead Lambda will handle them
    • it no longer contains the file + line number: the first line of the stack trace already contains that
  • the log line now contains the "Request ID" (or invocation ID), because:
    • it is closer to NodeJS's output
    • it allows us to easily find the logs of a single invocation
    • all this stems from Request ID logging logger#3
  • I updated tests and added more of them (as well as made them more readable)

Bonus: how the execution result looks in serverless invoke:

Capture d’écran 2020-03-14 à 12 19 08

How the logs look in serverless logs (yuck…):

Capture d’écran 2020-03-14 à 12 19 56

deleugpn and others added 6 commits March 4, 2020 05:04
When a handler throws an exception, it will no longer show up in the logs as `Fatal error: Uncaught <exception class>: <message> in <file>:<line>`. This gives the feeling that the developer should catch it.

Instead, developers should let exceptions bubble up. The new log message will only contain the message of the exception itself. Hopefully, that's clearer, less noisy.
See brefphp/logger#3: we are trying to copy the log format of other AWS runtimes.

Having the request ID in the log line lets use easily filter logs to find all the logs of a single invocation.
@@ -78,7 +78,7 @@ private function closeReturnHandler(): void
/**
* Process the next event.
*
* @param Handler|callable $handler If it is a callable, it takes two parameters, an $event parameter (mixed) and a $context parameter (Context) and must return anything serializable to JSON.
* @param Handler|RequestHandlerInterface|callable $handler If it is a callable, it takes two parameters, an $event parameter (mixed) and a $context parameter (Context) and must return anything serializable to JSON.
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unrelated fix, sorry about the noise!

'errorType' => get_class($error),
'stackTrace' => explode(PHP_EOL, $error->getTraceAsString()),
'errorMessage' => $error->getMessage(),
'stackTrace' => $stackTraceAsArray,
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just to be certain to have the same order as Node.

@deleugpn
Copy link
Member

deleugpn commented Mar 14, 2020

One last benefit that might be worth mentioning: CloudWatch search will make sense.
Before, I used to struggle (not just with bref but with ECS containers as well) due to PHP stackTrace splitting things into multiple lines.
If you search for an error message, you get a single line in CloudWatch, but dont get the context (previous and next lines), so you lose the stack trace. This is because CloudWatch understands line break as a new entry and php stack is split into lines.
By changing it to an array like this PR does, we can search on CloudWatch for a message and we get a hit that contains the entire json entry, including message + stack.

@mnapoli
Copy link
Member Author

mnapoli commented Mar 14, 2020

Thanks for the feedback! Let's get this going then!

@mnapoli mnapoli merged commit eec582c into master Mar 14, 2020
@mnapoli mnapoli deleted the exception-format branch March 14, 2020 13:55
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants