diff --git a/src/Runtime/LambdaRuntime.php b/src/Runtime/LambdaRuntime.php index e3b029524..a3d1659d2 100755 --- a/src/Runtime/LambdaRuntime.php +++ b/src/Runtime/LambdaRuntime.php @@ -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. * * Example: * @@ -200,27 +200,23 @@ private function sendResponse(string $invocationId, $responseData): void */ private function signalFailure(string $invocationId, \Throwable $error): void { - if ($error instanceof Exception) { - $errorMessage = 'Uncaught ' . get_class($error) . ': ' . $error->getMessage(); - } else { - $errorMessage = $error->getMessage(); - } + $stackTraceAsArray = explode(PHP_EOL, $error->getTraceAsString()); // Log the exception in CloudWatch - printf( - "Fatal error: %s in %s:%d\nStack trace:\n%s", - $errorMessage, - $error->getFile(), - $error->getLine(), - $error->getTraceAsString() - ); + // We aim to use the same log format as what we can see when throwing an exception in the NodeJS runtime + // See https://github.com/brefphp/bref/pull/579 + echo $invocationId . "\tInvoke Error\t" . json_encode([ + 'errorType' => get_class($error), + 'errorMessage' => $error->getMessage(), + 'stack' => $stackTraceAsArray, + ]) . PHP_EOL; // Send an "error" Lambda response $url = "http://{$this->apiUrl}/2018-06-01/runtime/invocation/$invocationId/error"; $this->postJson($url, [ - 'errorMessage' => $error->getMessage(), 'errorType' => get_class($error), - 'stackTrace' => explode(PHP_EOL, $error->getTraceAsString()), + 'errorMessage' => $error->getMessage(), + 'stackTrace' => $stackTraceAsArray, ]); } diff --git a/tests/Handler/FpmHandlerTest.php b/tests/Handler/FpmHandlerTest.php index e39b605b6..914f3b703 100644 --- a/tests/Handler/FpmHandlerTest.php +++ b/tests/Handler/FpmHandlerTest.php @@ -19,12 +19,14 @@ public function setUp(): void { parent::setUp(); + ob_start(); $this->fakeContext = new Context('abc', time(), 'abc', 'abc'); } public function tearDown() { $this->fpm->stop(); + ob_end_clean(); } public function test simple request() diff --git a/tests/Runtime/LambdaRuntimeTest.php b/tests/Runtime/LambdaRuntimeTest.php index 7e685f641..84a626da8 100644 --- a/tests/Runtime/LambdaRuntimeTest.php +++ b/tests/Runtime/LambdaRuntimeTest.php @@ -31,6 +31,7 @@ class LambdaRuntimeTest extends TestCase protected function setUp() { + ob_start(); Server::start(); $this->runtime = new LambdaRuntime('localhost:8126'); } @@ -38,6 +39,7 @@ protected function setUp() protected function tearDown() { Server::stop(); + ob_end_clean(); } public function test basic behavior() @@ -65,6 +67,18 @@ public function test handler receives context() ]); } + public function test exceptions in the handler result in an invocation error() + { + $this->givenAnEvent(['Hello' => 'world!']); + + $this->runtime->processNextEvent(function () { + throw new \RuntimeException('This is an exception'); + }); + + $this->assertInvocationErrorResult('RuntimeException', 'This is an exception'); + $this->assertErrorInLogs('RuntimeException', 'This is an exception'); + } + public function test an error is thrown if the runtime API returns a wrong response() { $this->expectExceptionMessage('Failed to fetch next Lambda invocation: The requested URL returned error: 404 Not Found'); @@ -141,9 +155,11 @@ public function test a wrong response from the runtime API turns the i $this->assertSame('POST', $eventFailureLog->getMethod()); $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/1/error', $eventFailureLog->getUri()->__toString()); - $error = json_decode((string) $eventFailureLog->getBody()); - $this->expectOutputRegex('/^Fatal error: Uncaught Exception: Error while calling the Lambda runtime API: The requested URL returned error: 400 Bad Request/'); - $this->assertSame('Error while calling the Lambda runtime API: The requested URL returned error: 400 Bad Request', $error->errorMessage); + // Check the lambda result contains the error message + $error = json_decode((string) $eventFailureLog->getBody(), true); + $this->assertSame('Error while calling the Lambda runtime API: The requested URL returned error: 400 Bad Request', $error['errorMessage']); + + $this->assertErrorInLogs('Exception', 'Error while calling the Lambda runtime API: The requested URL returned error: 400 Bad Request'); } public function test function results that cannot be encoded are reported as invocation errors() @@ -154,18 +170,13 @@ public function test function results that cannot be encoded are reporte return "\xB1\x31"; }); - $requests = Server::received(); - $this->assertCount(2, $requests); - - [$eventRequest, $eventFailureLog] = $requests; - $this->assertSame('GET', $eventRequest->getMethod()); - $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/next', $eventRequest->getUri()->__toString()); - $this->assertSame('POST', $eventFailureLog->getMethod()); - $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/1/error', $eventFailureLog->getUri()->__toString()); - - $error = json_decode((string) $eventFailureLog->getBody()); - $this->expectOutputRegex('/^Fatal error: Uncaught Exception: The Lambda response cannot be encoded to JSON/'); - $this->assertSame("The Lambda response cannot be encoded to JSON.\nThis error usually happens when you try to return binary content. If you are writing a HTTP application and you want to return a binary HTTP response (like an image, a PDF, etc.), please read this guide: https://bref.sh/docs/runtimes/http.html#binary-responses\nHere is the original JSON error: 'Malformed UTF-8 characters, possibly incorrectly encoded'", $error->errorMessage); + $message = <<assertInvocationErrorResult('Exception', $message); + $this->assertErrorInLogs('Exception', $message); } public function test generic event handler() @@ -282,11 +293,8 @@ public function test invalid handlers are rejected properly() $this->runtime->processNextEvent(null); - $requests = Server::received(); - $this->assertCount(2, $requests); - $error = json_decode((string) $requests[1]->getBody(), true); - $this->expectOutputRegex('/^Fatal error: Uncaught Exception: The lambda handler must be a callable or implement handler interfaces/'); - $this->assertSame('The lambda handler must be a callable or implement handler interfaces', $error['errorMessage']); + $this->assertInvocationErrorResult('Exception', 'The lambda handler must be a callable or implement handler interfaces'); + $this->assertErrorInLogs('Exception', 'The lambda handler must be a callable or implement handler interfaces'); } /** @@ -298,7 +306,7 @@ private function givenAnEvent($event): void new Response( // lambda event 200, [ - 'lambda-runtime-aws-request-id' => 1, + 'lambda-runtime-aws-request-id' => '1', 'lambda-runtime-invoked-function-arn' => 'test-function-name', ], json_encode($event) @@ -322,4 +330,50 @@ private function assertInvocationResult($result) $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/1/response', $eventResponse->getUri()->__toString()); $this->assertEquals($result, json_decode($eventResponse->getBody()->__toString(), true)); } + + private function assertInvocationErrorResult(string $errorClass, string $errorMessage) + { + $requests = Server::received(); + $this->assertCount(2, $requests); + + [$eventRequest, $eventResponse] = $requests; + $this->assertSame('GET', $eventRequest->getMethod()); + $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/next', $eventRequest->getUri()->__toString()); + $this->assertSame('POST', $eventResponse->getMethod()); + $this->assertSame('http://localhost:8126/2018-06-01/runtime/invocation/1/error', $eventResponse->getUri()->__toString()); + + // Check the content of the result of the lambda + $invocationResult = json_decode($eventResponse->getBody()->__toString(), true); + $this->assertSame([ + 'errorType', + 'errorMessage', + 'stackTrace', + ], array_keys($invocationResult)); + $this->assertEquals($errorClass, $invocationResult['errorType']); + $this->assertEquals($errorMessage, $invocationResult['errorMessage']); + $this->assertInternalType('array', $invocationResult['stackTrace']); + } + + private function assertErrorInLogs(string $errorClass, string $errorMessage): void + { + // Decode the logs from stdout + $stdout = $this->getActualOutput(); + + [$requestId, $message, $json] = explode("\t", $stdout); + + $this->assertSame('Invoke Error', $message); + + // Check the request ID matches a UUID + $this->assertNotEmpty($requestId); + + $invocationResult = json_decode($json, true); + $this->assertSame([ + 'errorType', + 'errorMessage', + 'stack', + ], array_keys($invocationResult)); + $this->assertEquals($errorClass, $invocationResult['errorType']); + $this->assertEquals($errorMessage, $invocationResult['errorMessage']); + $this->assertInternalType('array', $invocationResult['stack']); + } } diff --git a/tests/Sam/PhpRuntimeTest.php b/tests/Sam/PhpRuntimeTest.php index cfbef6bd2..f699fce38 100644 --- a/tests/Sam/PhpRuntimeTest.php +++ b/tests/Sam/PhpRuntimeTest.php @@ -59,23 +59,13 @@ public function test uncaught exception appears in logs and is reported 'exception' => true, ]); - // We don't assert on complete exception traces because they will change over time - $expectedLogs = <<assertInvocationError( + $result, + $logs, + 'Exception', + 'This is an uncaught exception', + '#0 /var/task/src/Runtime/LambdaRuntime.php(' + ); } public function test error appears in logs and is reported as an invocation error() @@ -84,23 +74,13 @@ public function test error appears in logs and is reported as an invoc 'error' => true, ]); - // We don't assert on complete exception traces because they will change over time - $expectedLogs = <<assertInvocationError( + $result, + $logs, + 'ArgumentCountError', + 'strlen() expects exactly 1 parameter, 0 given', + '#0 /var/task/tests/Sam/Php/function.php(39)' + ); } public function test fatal error appears in logs and is reported as an invocation error() @@ -131,8 +111,10 @@ public function test warnings are logged() 'warning' => true, ]); - self::assertNotContains('Warning: This is a test warning', $result); - self::assertContains('Warning: This is a test warning in /var/task/tests/Sam/Php/function.php', $logs); + // The warning does not turn the execution into an error + $this->assertEquals('Hello world', $result); + // But it appears in the logs + $this->assertContains('Warning: This is a test warning in /var/task/tests/Sam/Php/function.php', $logs); } public function test php extensions() @@ -292,4 +274,62 @@ private function invokeLambda($event = null): array return [$result, $logs]; } + + private function assertInvocationError( + array $invocationResult, + string $logs, + string $errorClass, + string $errorMessage, + string $stackTraceStartsWith = '#0 /var/task/' + ): void { + $this->assertSame([ + 'errorType', + 'errorMessage', + 'stackTrace', + ], array_keys($invocationResult)); + $this->assertEquals($errorClass, $invocationResult['errorType']); + $this->assertEquals($errorMessage, $invocationResult['errorMessage']); + $this->assertInternalType('array', $invocationResult['stackTrace']); + $this->assertStringStartsWith($stackTraceStartsWith, $invocationResult['stackTrace'][0]); + + $this->assertErrorInLogs($logs, $errorClass, $errorMessage, $stackTraceStartsWith); + } + + private function assertErrorInLogs( + string $logs, + string $errorClass, + string $errorMessage, + string $stackTraceStartsWith = '#0 /var/task/' + ): void { + // Extract the only interesting log line + $logLines = explode("\n", $logs); + $logLines = array_filter($logLines, function (string $line): bool { + $line = trim($line); + return $line !== '' + && (strpos($line, 'START') !== 0) + && (strpos($line, 'END') !== 0) + && (strpos($line, 'REPORT') !== 0); + }); + $this->assertCount(1, $logLines); + $logLine = reset($logLines); + + // Decode the logs from stdout + [$requestId, $message, $json] = explode("\t", $logLine); + + // Check the request ID matches a UUID + $this->assertRegExp('/[0-9a-fA-F]{8}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{4}\-[0-9a-fA-F]{12}/', $requestId); + + $this->assertSame('Invoke Error', $message); + + $invocationResult = json_decode($json, true); + $this->assertSame([ + 'errorType', + 'errorMessage', + 'stack', + ], array_keys($invocationResult)); + $this->assertEquals($errorClass, $invocationResult['errorType']); + $this->assertEquals($errorMessage, $invocationResult['errorMessage']); + $this->assertInternalType('array', $invocationResult['stack']); + $this->assertStringStartsWith($stackTraceStartsWith, $invocationResult['stack'][0]); + } }