From e3eb27e70dcf381190ec31277665e720b9d22bcd Mon Sep 17 00:00:00 2001 From: Hector Mendoza Jacobo Date: Wed, 4 Sep 2024 21:42:11 +0000 Subject: [PATCH] Add the StdOutLogger and Logging Trait --- composer.json | 3 +- src/Logging/LogEvent.php | 121 +++++++++++++++++++++++++ src/Logging/LoggingTrait.php | 94 ++++++++++++++++++++ src/Logging/StdOutLogger.php | 107 +++++++++++++++++++++++ tests/Logging/LogEventTest.php | 42 +++++++++ tests/Logging/LoggingTraitTest.php | 136 +++++++++++++++++++++++++++++ tests/Logging/StdOutLoggerTest.php | 74 ++++++++++++++++ 7 files changed, 576 insertions(+), 1 deletion(-) create mode 100644 src/Logging/LogEvent.php create mode 100644 src/Logging/LoggingTrait.php create mode 100644 src/Logging/StdOutLogger.php create mode 100644 tests/Logging/LogEventTest.php create mode 100644 tests/Logging/LoggingTraitTest.php create mode 100644 tests/Logging/StdOutLoggerTest.php diff --git a/composer.json b/composer.json index 41a1d0532..33428c5fa 100644 --- a/composer.json +++ b/composer.json @@ -14,7 +14,8 @@ "guzzlehttp/guzzle": "^7.4.5", "guzzlehttp/psr7": "^2.4.5", "psr/http-message": "^1.1||^2.0", - "psr/cache": "^2.0||^3.0" + "psr/cache": "^2.0||^3.0", + "psr/log": "^3.0" }, "require-dev": { "guzzlehttp/promises": "^2.0", diff --git a/src/Logging/LogEvent.php b/src/Logging/LogEvent.php new file mode 100644 index 000000000..38697f2c6 --- /dev/null +++ b/src/Logging/LogEvent.php @@ -0,0 +1,121 @@ + + */ + public null|array $headers = null; + + /** + * An array representation of JSON for the response or request + * + * @var null|string|array + */ + public null|string|array $payload = null; + + /** + * Status code for REST or gRPC methods + * + * @var null|int|string + */ + public null|int|string $status = null; + + /** + * The latency in miliseconds + * + * @var null|int + */ + public null|int $latency = null; + + /** + * The retry attempt number + * + * @var null|int + */ + public null|int $retryAttempt = null; + + /** + * The name of the gRPC method being called + * + * @var null|string + */ + public null|string $rpcName = null; + + /** + * The Service Name of the gRPC + * + * @var null|string $serviceName + */ + public null|string $serviceName; + + /** + * The Client Id for easy trace + * + * @var int $clientId + */ + public int $clientId; + + /** + * The Request id for easy trace + * + * @var in $requestId; + */ + public int $requestId; + + /** + * Creates an object with all the fields required for logging + * Passing a string representation of a timestamp calculates the difference between + * these two times and sets the latency field with the result. + * + * @param null|string $startTime (Optional) Parameter to calculate the latency + */ + public function __construct(null|string $startTime = null) + { + $this->timestamp = date(DATE_RFC3339); + + if ($startTime) { + $this->latency = (int) strtotime($this->timestamp) - strtotime($startTime); + } + } +} diff --git a/src/Logging/LoggingTrait.php b/src/Logging/LoggingTrait.php new file mode 100644 index 000000000..664726bc8 --- /dev/null +++ b/src/Logging/LoggingTrait.php @@ -0,0 +1,94 @@ + $event->timestamp, + 'severity' => strtoupper(LogLevel::DEBUG), + 'clientId' => $event->clientId, + 'requestId' => $event->requestId, + ]; + + $jsonPayload = [ + 'request.method' => $event->method, + 'request.url' => $event->url, + 'request.headers' => $event->headers, + 'request.payload' => $event->payload, + 'request.jwt' => $this->getJwtToken($event->headers), + 'retryAttempt' => $event->retryAttempt + ]; + + // Filter out the falsey values + $jsonPayload = array_filter($jsonPayload); + $debugEvent['jsonPayload'] = $jsonPayload; + + $this->logger->debug((string) json_encode($debugEvent)); + } + + private function logResponse(LogEvent $event): void + { + $debugEvent = [ + 'timestamp' => $event->timestamp, + 'severity' => strtoupper(LogLevel::DEBUG), + 'clientId' => $event->clientId, + 'requestId' => $event->requestId, + 'jsonPayload' => [ + 'response.headers' => $event->headers, + 'response.payload' => $event->payload, + 'latency' => $event->latency, + ] + ]; + + $this->logger->debug((string) json_encode($debugEvent)); + + $infoEvent = [ + 'timestamp' => $event->timestamp, + 'severity' => LogLevel::INFO, + 'clientId' => $event->clientId, + 'requestId' => $event->requestId, + 'jsonPayload' => [ + 'response.status' => $event->status + ] + ]; + + $this->logger->info((string) json_encode($infoEvent)); + } + + private function getJwtToken(array $headers): null|array + { + $tokenHeader = $headers['Authorization'] ?? ''; + $token = str_replace('Bearer ', '', $tokenHeader); + + if (substr_count($token, '.') !== 2) { + return null; + } + + [$header, $token, $_] = explode('.', $token); + + return [ + 'header' => base64_decode($header), + 'token' => base64_decode($token) + ]; + } +} diff --git a/src/Logging/StdOutLogger.php b/src/Logging/StdOutLogger.php new file mode 100644 index 000000000..eeae3fec3 --- /dev/null +++ b/src/Logging/StdOutLogger.php @@ -0,0 +1,107 @@ + + */ + private array $levelMapping = [ + LogLevel::EMERGENCY => 7, + LogLevel::ALERT => 6, + LogLevel::CRITICAL => 5, + LogLevel::ERROR => 4, + LogLevel::WARNING => 3, + LogLevel::NOTICE => 2, + LogLevel::INFO => 1, + LogLevel::DEBUG => 0, + ]; + private int $level; + + public function __construct(string $level = LogLevel::DEBUG) + { + $this->level = $this->getLevelMap($level); + } + + public function emergency(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::EMERGENCY, $message); + } + + public function alert(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::ALERT, $message); + } + + public function critical(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::CRITICAL, $message); + } + + public function error(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::ERROR, $message); + } + + public function warning(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::WARNING, $message); + } + + public function notice(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::NOTICE, $message); + } + + public function info(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::INFO, $message); + } + + public function debug(string|Stringable $message, array $context = []): void + { + $this->log(LogLevel::DEBUG, $message); + } + + public function log($level, string|Stringable $message, array $context = []): void + { + if ($this->getLevelMap($level) < $this->level) { + return; + } + + print($message . "\n"); + } + + private function getLevelMap(string $levelName): int + { + if (!array_key_exists($levelName, $this->levelMapping)) { + throw new Exception('The level supplied to the Logger is not valid'); + } + + return $this->levelMapping[$levelName]; + } +} diff --git a/tests/Logging/LogEventTest.php b/tests/Logging/LogEventTest.php new file mode 100644 index 000000000..5b29b7eb0 --- /dev/null +++ b/tests/Logging/LogEventTest.php @@ -0,0 +1,42 @@ +assertNotNull($item->timestamp); + } + + public function testConstructorWithoutParameterHasNoLatency() + { + $item = new LogEvent(); + $this->assertNull($item->latency); + } + + public function testConstructorWithParameterHasLatencySet() + { + $item = new LogEvent(date(DATE_RFC3339)); + $this->assertNotNull($item->latency); + } +} diff --git a/tests/Logging/LoggingTraitTest.php b/tests/Logging/LoggingTraitTest.php new file mode 100644 index 000000000..f162b4760 --- /dev/null +++ b/tests/Logging/LoggingTraitTest.php @@ -0,0 +1,136 @@ +loggerContainer = new MockClassWithLogger(); + } + + public function testLogRequest() + { + ob_start(); + + $event = $this->getNewLogEvent(); + $this->loggerContainer->logRequestEvent($event); + + $buffer = ob_get_contents(); + ob_end_clean(); + $jsonParsed = json_decode($buffer, true); + + $this->assertEquals($event->timestamp, $jsonParsed['timestamp']); + $this->assertEquals($event->clientId, $jsonParsed['clientId']); + $this->assertEquals($event->method, $jsonParsed['jsonPayload']['request.method']); + $this->assertEquals($event->url, $jsonParsed['jsonPayload']['request.url']); + $this->assertEquals($event->headers, $jsonParsed['jsonPayload']['request.headers']); + $this->assertArrayHasKey('request.jwt', $jsonParsed['jsonPayload']); + } + + public function testRequestWithoutJwtShouldNotPrintAJwt() + { + ob_start(); + + $event = $this->getNewLogEvent(); + $event->headers = ['no jwt' => true]; + $this->loggerContainer->logRequestEvent($event); + + $buffer = ob_get_contents(); + ob_end_clean(); + $jsonParsed = json_decode($buffer, true); + + $this->assertArrayNotHasKey('request.jwt', $jsonParsed['jsonPayload']); + } + + public function testLogResponse() + { + ob_start(); + + $event = $this->getNewLogEvent(); + $this->loggerContainer->logResponseEvent($event); + + $buffer = ob_get_contents(); + ob_end_clean(); + + $buffer = str_replace("\n", '', $buffer); + + // The LogResponse method logs two evnets, one for info and one for debug. + [$debugEvent, $infoEvent] = explode('}{', $buffer); + $debugEvent .= '}'; + $infoEvent = '{' . $infoEvent; + + $parsedDebugEvent = json_decode($debugEvent, true); + $this->assertEquals($event->clientId, $parsedDebugEvent['clientId']); + $this->assertEquals($event->requestId, $parsedDebugEvent['requestId']); + $this->assertEquals($event->headers, $parsedDebugEvent['jsonPayload']['response.headers']); + + $parsedInfoEvent = json_decode($infoEvent, true); + $this->assertEquals($event->status, $parsedInfoEvent['jsonPayload']['response.status']); + } + + private function getNewLogEvent(): LogEvent + { + $event = new LogEvent(); + $event->clientId = 123; + $event->method = 'get'; + $event->url = 'test.com'; + $event->headers = [ + 'header1' => 'test', + 'Authorization' => 'Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG9lIiwiaWF0IjoxNTE2MjM5MDIyfQ.cThIIoDvwdueQB468K5xDc5633seEFoqwxjF_xSJyQQ' + ]; + $event->payload = ['param' => 'test']; + $event->status = 200; + $event->retryAttempt = 0; + $event->rpcName = 'Rpc NameTest'; + $event->serviceName = 'Service Name'; + $event->requestId = 321; + $event->latency = 555; + + return $event; + } +} + +class MockClassWithLogger +{ + use LoggingTrait; + private LoggerInterface $logger; + + public function __construct() + { + $this->logger = new StdOutLogger(); + } + + public function logRequestEvent(LogEvent $event): void + { + $this->logRequest($event); + } + + public function logResponseEvent(LogEvent $event): void + { + $this->logResponse($event); + } +} diff --git a/tests/Logging/StdOutLoggerTest.php b/tests/Logging/StdOutLoggerTest.php new file mode 100644 index 000000000..a58cecad2 --- /dev/null +++ b/tests/Logging/StdOutLoggerTest.php @@ -0,0 +1,74 @@ +expectException(Exception::class); + new StdOutLogger('invalid level'); + } + + public function testLoggingOnSameLevelWritesToStdOut() + { + ob_start(); + + $logger = new StdOutLogger(LogLevel::DEBUG); + $expectedString = 'test'; + $logger->debug($expectedString); + $buffer = ob_get_contents(); + + $this->assertEquals($expectedString . "\n", $buffer); + + ob_end_clean(); + } + + public function testLoggingOnHigherLeverWritesToStdOut() + { + ob_start(); + + $logger = new StdOutLogger(LogLevel::WARNING); + $expectedString = 'test'; + $logger->error($expectedString); + $buffer = ob_get_contents(); + + $this->assertEquals($expectedString . "\n", $buffer); + + ob_end_clean(); + } + + public function testLoggingOnLowerLeverDoesNotWriteToStdOut() + { + ob_start(); + + $logger = new StdOutLogger(LogLevel::WARNING); + $expectedString = 'test'; + $logger->debug($expectedString); + $buffer = ob_get_contents(); + + $this->assertEmpty($buffer); + + ob_end_clean(); + } +}