brefphp / bref

Serverless PHP on AWS Lambda
https://bref.sh
MIT License
3.1k stars 367 forks source link

Fix #1520 "Unknown application error occurred Runtime.Unknown" #1616

Closed mnapoli closed 1 year ago

mnapoli commented 1 year ago

I finally found the source of the issue 🎉

When failing to get the handler (in the function runtime), the Lambda would fail but would only consider the exception message. It would completely ignore the rest of the exception (stack trace & class name).

In the case of Laravel (which is the most common report for this bug), we would get the following log:

App\TestHandler
START
Unknown application error occurred
Runtime.Unknown
END Duration: 108.02 ms Memory Used: 36 MB

As you can see, the name of the handler class is logged, but that's it. What happens is that Laravel throws an EntryNotFoundException: the exception message is only the class name…

So the exception message gets logged, but it's not useful, and it looks like the exception wasn't logged at all.

With this PR, the exception message + class name + stack trace will correctly be logged.

On top of that, I refactored how "initialization failures" are reported to have even better logs from Lambda.

Additionally, specifically for this Laravel exception, I will probably catch + rethrow this exception with a clearer message (but this change will go in the Laravel bridge).

Before

Lambda logs:

App\TestHandler
App\TestHandler
START
Unknown application error occurred
Runtime.Unknown
END Duration: 108.02 ms Memory Used: 36 MB

Lambda invocation result:

{
    "errorMessage": "App\\TestHandler ",
    "errorType": "Internal",
    "stackTrace": []
}

After

Lambda logs:

Fatal error: Illuminate\Container\EntryNotFoundException: App\TestHandler in /var/task/vendor/laravel/framework/src/Illuminate/Container/Container.php:723
{"message":"App\\TestHandler","type":"Illuminate\\Container\\EntryNotFoundException","stackTrace":["#0 \/var\/task\/vendor\/bref\/laravel-bridge\/src\/HandlerResolver.php(46): Illuminate\\Container\\Container->get('App\\\\TestHandler...')","#1 \/var\/task\/vendor\/bref\/bref\/src\/FunctionRuntime\/Main.php(26): Bref\\LaravelBridge\\HandlerResolver->get('App\\\\TestHandler...')","#2 \/opt\/bref\/bootstrap.php(17): Bref\\FunctionRuntime\\Main::run()","#3 {main}"]}
The function failed to start. AWS Lambda will restart the process, do not be surprised if you see the error message twice.
Fatal error: Illuminate\Container\EntryNotFoundException: App\TestHandler in /var/task/vendor/laravel/framework/src/Illuminate/Container/Container.php:723
{"message":"App\\TestHandler","type":"Illuminate\\Container\\EntryNotFoundException","stackTrace":["#0 \/var\/task\/vendor\/bref\/laravel-bridge\/src\/HandlerResolver.php(46): Illuminate\\Container\\Container->get('App\\\\TestHandler...')","#1 \/var\/task\/vendor\/bref\/bref\/src\/FunctionRuntime\/Main.php(26): Bref\\LaravelBridge\\HandlerResolver->get('App\\\\TestHandler...')","#2 \/opt\/bref\/bootstrap.php(17): Bref\\FunctionRuntime\\Main::run()","#3 {main}"]}
The function failed to start. AWS Lambda will restart the process, do not be surprised if you see the error message twice.
START
Unknown application error occurred
Runtime.NoSuchHandler
END Duration: 114.13 ms Memory Used: 36 MB

The exception is logged twice because AWS Lambda performs a retry (in the same function, it simply restarts the Bref process).

Lambda invocation result:

{
    "errorMessage": "App\\TestHandler App\\TestHandler",
    "errorType": "Illuminate\\Container\\EntryNotFoundException",
    "stackTrace": [
        "#0 /var/task/vendor/bref/laravel-bridge/src/HandlerResolver.php(46): Illuminate\\Container\\Container->get('App\\\\TestHandler...')",
        "#1 /var/task/vendor/bref/bref/src/FunctionRuntime/Main.php(26): Bref\\LaravelBridge\\HandlerResolver->get('App\\\\TestHandler...')",
        "#2 /opt/bref/bootstrap.php(17): Bref\\FunctionRuntime\\Main::run()",
        "#3 {main}"
    ]
}

Here's a preview with the JSON logs in the Bref Dashboard:

image