From e6be89f7cc4502119d4544456864bd5c56f174a9 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Thu, 27 Jun 2024 11:58:00 +0200 Subject: [PATCH] L-2183 Ensure flushed logs in long running scripts (#22) - add options flushIntervalMs (default 5s) and throwExceptions (default false) to LogtailHandler - change default of bufferLimit from 0 to 1000 and flushOnOverflow from false to true - add LogtailHandlerBuilder --- .github/workflows/main.yml | 1 + example-project/README.md | 6 +- example-project/index.php | 9 +- src/Monolog/LogtailHandler.php | 71 ++++++++- src/Monolog/LogtailHandlerBuilder.php | 180 ++++++++++++++++++++++ src/Monolog/SynchronousLogtailHandler.php | 37 ++++- 6 files changed, 287 insertions(+), 17 deletions(-) create mode 100644 src/Monolog/LogtailHandlerBuilder.php diff --git a/.github/workflows/main.yml b/.github/workflows/main.yml index 9be5564..1db0f7e 100644 --- a/.github/workflows/main.yml +++ b/.github/workflows/main.yml @@ -6,6 +6,7 @@ on: push: branches: - master + - 2.x jobs: build: diff --git a/example-project/README.md b/example-project/README.md index 7d29e30..0bf3714 100644 --- a/example-project/README.md +++ b/example-project/README.md @@ -51,7 +51,7 @@ Now it’s time to create a `Logger` instance and push a `LogtailHandler` handle ```php $logger = new Logger("logtail-source"); -$logger->pushHandler(new LogtailHandler("")); +$logger->pushHandler(LogtailHandlerBuilder::withSourceToken("")->build()); ``` Don’t forget to change `` to your actual token which you can find in the *Basic information* section when clicking on *Edit* on your select source. @@ -69,11 +69,11 @@ Creating multiple loggers for different channels is fairly easy: ```php # Logger for shopping cart component $cart_logger = new Logger("shoping-cart"); -$cart_logger->pushHandler(new LogtailHandler("")); +$cart_logger->pushHandler(LogtailHandlerBuilder::withSourceToken("")->build()); # Logger for payment component $payment_logger = new Logger("payment"); -$payment_logger->pushHandler(new LogtailHandler("")); +$payment_logger->pushHandler(LogtailHandlerBuilder::withSourceToken("")->build()); ``` Then you can filter your logs using the following search formula: diff --git a/example-project/index.php b/example-project/index.php index 38f8564..6c235d8 100644 --- a/example-project/index.php +++ b/example-project/index.php @@ -7,7 +7,7 @@ # Setting logger use Monolog\Logger; -use Logtail\Monolog\LogtailHandler; +use Logtail\Monolog\LogtailHandlerBuilder; # Check for arguments if($argc != 2){ @@ -17,7 +17,12 @@ } $logger = new Logger("logtail-source"); -$logger->pushHandler(new LogtailHandler($argv[1])); +$handler = LogtailHandlerBuilder::withSourceToken($argv[1]) + ->withBufferLimit(100) + ->withFlushIntervalMilliseconds(500) + ->withExceptionThrowing(true) + ->build(); +$logger->pushHandler($handler); # Below you can see available methods that can be used to send logs to logtail. # Each method corresponds to Monologs log level. diff --git a/src/Monolog/LogtailHandler.php b/src/Monolog/LogtailHandler.php index 3e8f186..ee10866 100644 --- a/src/Monolog/LogtailHandler.php +++ b/src/Monolog/LogtailHandler.php @@ -19,27 +19,84 @@ */ class LogtailHandler extends BufferHandler { + const DEFAULT_BUBBLE = true; + const DEFAULT_BUFFER_LIMIT = 1000; + const DEFAULT_FLUSH_ON_OVERFLOW = true; + const DEFAULT_FLUSH_INTERVAL_MILLISECONDS = 5000; + + /** + * @var int|null $flushIntervalMs + */ + private $flushIntervalMs; + + /** + * @var int|float|null highResolutionTimeOfNextFlush + */ + private $highResolutionTimeOfNextFlush; + /** * @param string $sourceToken Logtail source token * @param int|string $level The minimum logging level at which this handler will be triggered * @param bool $bubble Whether the messages that are handled can bubble up the stack or not - * @param $endpoint Logtail ingesting endpoint - * @param int $bufferLimit How many entries should be buffered at most, beyond that the oldest items are removed from the buffer. + * @param string $endpoint Logtail ingesting endpoint + * @param int $bufferLimit How many entries should be buffered at most, beyond that the oldest items are removed from the buffer * @param bool $flushOnOverflow If true, the buffer is flushed when the max size has been reached, by default oldest entries are discarded * @param int $connectionTimeoutMs The maximum time in milliseconds that you allow the connection phase to the server to take * @param int $timeoutMs The maximum time in milliseconds that you allow a transfer operation to take + * @param int|null $flushIntervalMs The time in milliseconds after which next log record will trigger flushing all logs. Null to disable + * @param bool $throwExceptions Whether to throw exceptions when sending logs fails */ public function __construct( $sourceToken, $level = Logger::DEBUG, - $bubble = true, + $bubble = self::DEFAULT_BUBBLE, $endpoint = LogtailClient::URL, - $bufferLimit = 0, - $flushOnOverflow = false, + $bufferLimit = self::DEFAULT_BUFFER_LIMIT, + $flushOnOverflow = self::DEFAULT_FLUSH_ON_OVERFLOW, $connectionTimeoutMs = LogtailClient::DEFAULT_CONNECTION_TIMEOUT_MILLISECONDS, - $timeoutMs = LogtailClient::DEFAULT_TIMEOUT_MILLISECONDS + $timeoutMs = LogtailClient::DEFAULT_TIMEOUT_MILLISECONDS, + $flushIntervalMs = self::DEFAULT_FLUSH_INTERVAL_MILLISECONDS, + $throwExceptions = SynchronousLogtailHandler::DEFAULT_THROW_EXCEPTION ) { - parent::__construct(new SynchronousLogtailHandler($sourceToken, $level, $bubble, $endpoint, $connectionTimeoutMs, $timeoutMs), $bufferLimit, $level, $bubble, $flushOnOverflow); + parent::__construct(new SynchronousLogtailHandler($sourceToken, $level, $bubble, $endpoint, $connectionTimeoutMs, $timeoutMs, $throwExceptions), $bufferLimit, $level, $bubble, $flushOnOverflow); + $this->flushIntervalMs = $flushIntervalMs; + $this->setHighResolutionTimeOfLastFlush(); + } + + /** + * @inheritDoc + */ + public function handle(array $record): bool + { + $return = parent::handle($record); + + if ($this->highResolutionTimeOfNextFlush !== null && $this->highResolutionTimeOfNextFlush <= hrtime(true)) { + $this->flush(); + $this->setHighResolutionTimeOfLastFlush(); + } + + return $return; + } + + /** + * @inheritDoc + */ + public function flush(): void + { + parent::flush(); + $this->setHighResolutionTimeOfLastFlush(); } + private function setHighResolutionTimeOfLastFlush(): void + { + $currentHighResolutionTime = hrtime(true); + if ($this->flushIntervalMs === null || $currentHighResolutionTime === false) { + $this->highResolutionTimeOfNextFlush = null; + + return; + } + + // hrtime(true) returns nanoseconds, converting flushIntervalMs from milliseconds to nanoseconds + $this->highResolutionTimeOfNextFlush = $currentHighResolutionTime + $this->flushIntervalMs * 1e+6; + } } diff --git a/src/Monolog/LogtailHandlerBuilder.php b/src/Monolog/LogtailHandlerBuilder.php new file mode 100644 index 0000000..d3501db --- /dev/null +++ b/src/Monolog/LogtailHandlerBuilder.php @@ -0,0 +1,180 @@ +sourceToken = $sourceToken; + } + + /** + * Builder for comfortable creation of {@see LogtailHandler}. + * + * @var string $sourceToken Your Better Stack source token. + * @see https://logs.betterstack.com/team/0/sources + * @return self Always returns new immutable instance + */ + public static function withSourceToken($sourceToken): self + { + return new self($sourceToken); + } + + /** + * Sets the minimum logging level at which this handler will be triggered. + * + * @param int|string $level + * @return self Always returns new immutable instance + */ + public function withLevel($level): self + { + $clone = clone $this; + $clone->level = $level; + + return $clone; + } + + /** + * Sets whether the messages that are handled can bubble up the stack or not. + * + * @param bool $bubble + * @return self Always returns new immutable instance + */ + public function withLogBubbling($bubble): self + { + $clone = clone $this; + $clone->bubble = $bubble; + + return $clone; + } + + /** + * Sets how many entries should be buffered at most, beyond that the oldest items are flushed or removed from the buffer. + * + * @param int $bufferLimit + * @return self Always returns new immutable instance + */ + public function withBufferLimit($bufferLimit): self + { + $clone = clone $this; + $clone->bufferLimit = $bufferLimit; + + return $clone; + } + + /** + * Sets whether the buffer is flushed (true) or discarded (false) when the max size has been reached. + * + * @param bool $flushOnOverflow + * @return self Always returns new immutable instance + */ + public function withFlushOnOverflow($flushOnOverflow): self + { + $clone = clone $this; + $clone->flushOnOverflow = $flushOnOverflow; + + return $clone; + } + + /** + * Sets the maximum time in milliseconds that you allow the connection phase to the server to take. + * + * @param int $connectionTimeoutMs + * @return self Always returns new immutable instance + */ + public function withConnectionTimeoutMilliseconds($connectionTimeoutMs): self + { + $clone = clone $this; + $clone->connectionTimeoutMs = $connectionTimeoutMs; + + return $clone; + } + + /** + * Sets the maximum time in milliseconds that you allow a transfer operation to take. + * + * @param int $timeoutMs + * @return self Always returns new immutable instance + */ + public function withTimeoutMilliseconds($timeoutMs): self + { + $clone = clone $this; + $clone->timeoutMs = $timeoutMs; + + return $clone; + } + + /** + * Set the time in milliseconds after which next log record will trigger flushing all logs. Null to disable. + * + * @param int|null $flushIntervalMs + * @return self Always returns new immutable instance + */ + public function withAlwaysFlushingEveryMilliseconds($flushIntervalMs): self + { + $clone = clone $this; + $clone->flushIntervalMs = $flushIntervalMs; + + return $clone; + } + + /** + * Sets whether to throw exceptions when sending logs fails. + * + * @param bool $throwExceptions + * @return self Always returns new immutable instance + */ + public function withExceptionThrowing($throwExceptions): self + { + $clone = clone $this; + $clone->throwExceptions = $throwExceptions; + + return $clone; + } + + /** + * Builds the {@see LogtailHandler} instance based on the setting. + * + * @return LogtailHandler + */ + public function build(): LogtailHandler + { + return new LogtailHandler( + $this->sourceToken, + $this->level, + $this->bubble, + $this->endpoint, + $this->bufferLimit, + $this->flushOnOverflow, + $this->connectionTimeoutMs, + $this->timeoutMs, + $this->flushIntervalMs + ); + } +} diff --git a/src/Monolog/SynchronousLogtailHandler.php b/src/Monolog/SynchronousLogtailHandler.php index 49ab41e..8a1a13b 100644 --- a/src/Monolog/SynchronousLogtailHandler.php +++ b/src/Monolog/SynchronousLogtailHandler.php @@ -16,12 +16,20 @@ /** * Sends log to Logtail. */ -class SynchronousLogtailHandler extends \Monolog\Handler\AbstractProcessingHandler { +class SynchronousLogtailHandler extends \Monolog\Handler\AbstractProcessingHandler +{ + const DEFAULT_THROW_EXCEPTION = false; + /** * @var LogtailClient $client */ private $client; + /** + * @var bool $throwExceptions + */ + private $throwExceptions; + /** * @param string $sourceToken * @param int $level @@ -29,18 +37,21 @@ class SynchronousLogtailHandler extends \Monolog\Handler\AbstractProcessingHandl * @param string $endpoint * @param int $connectionTimeoutMs * @param int $timeoutMs + * @param bool throwExceptions */ public function __construct( $sourceToken, $level = \Monolog\Logger::DEBUG, - $bubble = true, + $bubble = LogtailHandler::DEFAULT_BUBBLE, $endpoint = LogtailClient::URL, $connectionTimeoutMs = LogtailClient::DEFAULT_CONNECTION_TIMEOUT_MILLISECONDS, - $timeoutMs = LogtailClient::DEFAULT_TIMEOUT_MILLISECONDS + $timeoutMs = LogtailClient::DEFAULT_TIMEOUT_MILLISECONDS, + $throwExceptions = self::DEFAULT_THROW_EXCEPTION ) { parent::__construct($level, $bubble); $this->client = new LogtailClient($sourceToken, $endpoint, $connectionTimeoutMs, $timeoutMs); + $this->throwExceptions = $throwExceptions; $this->pushProcessor(new \Monolog\Processor\IntrospectionProcessor($level, ['Logtail\\'])); $this->pushProcessor(new \Monolog\Processor\WebProcessor); @@ -52,7 +63,15 @@ public function __construct( * @param array $record */ protected function write(array $record): void { - $this->client->send($record["formatted"]); + try { + $this->client->send($record["formatted"]); + } catch (Throwable $throwable) { + if ($this->throwExceptions) { + throw $throwable; + } else { + trigger_error("Failed to send a single log record to Better Stack because of " . $throwable, E_USER_WARNING); + } + } } /** @@ -62,7 +81,15 @@ protected function write(array $record): void { public function handleBatch(array $records): void { $formattedRecords = $this->getFormatter()->formatBatch($records); - $this->client->send($formattedRecords); + try { + $this->client->send($formattedRecords); + } catch (\Throwable $throwable) { + if ($this->throwExceptions) { + throw $throwable; + } else { + trigger_error("Failed to send " . count($records) . " log records to Better Stack because of " . $throwable, E_USER_WARNING); + } + } } /**