diff --git a/CHANGELOG.md b/CHANGELOG.md index f0ccfc5b..97cff4ce 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,7 @@ Latest ------ ## Fixes +* [#305](https://github.com/cleverage/ui-process-bundle/issues/305) Database logs: the strings of the context of a log record are limited to 65536 characters (followed by ` [...] (over 65536 characters, total, truncated)`), as its arrays (#271): a larger string (e.g. the content of a file) over the maximum packet size of the database made the insertion of the log records written with it fail, and closed the connection shared with the process tasks. Update documentation, add tests. * [#303](https://github.com/cleverage/ui-process-bundle/issues/303) Logs list: the context filter also searches the value as encoded in JSON by Doctrine (internal `LogTextFilter`): PostgreSQL, MariaDB and SQLite keep the JSON as written (`/` written `\/`, `"` written `\"`, non-ASCII characters written `\uXXXX`), a search containing such characters (e.g. a path) found nothing there. Update documentation, add tests. * [#299](https://github.com/cleverage/ui-process-bundle/issues/299) `DoctrineProcessHandler`: below the `Error` level, a log record counted in the report is inserted right away at most every `process_execution.heartbeat_interval` seconds (new `setWriteRightAwayInterval()`), otherwise with the next ones: since 3.5, each warning was inserted with the report of the execution in a transaction of its own (5000 warnings: 60 s instead of 8 s). The records from the `Error` level are still inserted right away. Update documentation, add tests. * [#301](https://github.com/cleverage/ui-process-bundle/issues/301) The `pb_ui_file_filter` and `pb_ui_orm_filter` Monolog handlers accept the level of the handler they wrap (`file_level`, `database_level`, set by the new internal `MonologFilterLevelPass`) instead of every level: the Monolog processors no longer run for the records written by none of them, e.g. the debug record of each task execution. Update documentation, add tests. diff --git a/docs/reference/04-process_executions_and_logs.md b/docs/reference/04-process_executions_and_logs.md index aceb8b29..89c22174 100644 --- a/docs/reference/04-process_executions_and_logs.md +++ b/docs/reference/04-process_executions_and_logs.md @@ -195,7 +195,11 @@ and its values which cannot be encoded (e.g. a resource) replaced by `null`. As `Over 1000 items ( total), aborting normalization`) and to 9 levels deep, the context being the first one (the deeper values are replaced by `Over 9 levels deep, aborting normalization`): an unbounded context (e.g. the output of an aggregator) was stored whole, and over the maximum packet size of the database, it made the insertion of the log records -written with it fail. The objects of the context are stored with their public properties, without limit. +written with it fail. The strings of the context are limited to 65536 characters (Unicode code points), at any depth: +a longer one (e.g. the content of a file) is truncated and followed by ` [...] (over 65536 characters, total, +truncated)` (the log file has it whole); over the maximum packet size of the database (e.g. `max_allowed_packet` of +MySQL), its log record and the ones written with it were lost, and the connection, shared with the process tasks, was +closed. The objects of the context are stored with their public properties, without limit. Records are buffered and inserted every 500 records, and at the end (or failure) of the process. A record counted in the report of the execution (from `report_increment_level`, warnings by default) is inserted right away with the diff --git a/src/Entity/LogRecord.php b/src/Entity/LogRecord.php index ce114722..5524804c 100644 --- a/src/Entity/LogRecord.php +++ b/src/Entity/LogRecord.php @@ -27,6 +27,8 @@ class LogRecord /** Limits of the context, as in the log file (Monolog NormalizerFormatter) */ private const MAX_ITEMS = 1000; private const MAX_DEPTH = 9; + /** Characters (code points) of a string of the context */ + private const MAX_STRING_LENGTH = 65536; #[ORM\Id] #[ORM\GeneratedValue] @@ -70,7 +72,8 @@ public function __construct( /** * The limits of the log file (Monolog NormalizerFormatter): at most 1000 items per array, 9 levels deep. An unbounded * context (e.g. the output of an aggregator) was stored whole, and over the maximum packet size of the database, it - * made the insertion of the log records written with it fail. + * made the insertion of the log records written with it fail. The strings are limited to 65536 characters too (e.g. + * the content of a file): not by the log file. * * @param array $data * @@ -88,13 +91,31 @@ private function limit(array $data, int $depth): array if ($depth + 1 > self::MAX_DEPTH) { $limited[$key] = \sprintf('Over %d levels deep, aborting normalization', self::MAX_DEPTH); } else { - $limited[$key] = \is_array($value) ? $this->limit($value, $depth + 1) : $value; + $limited[$key] = match (true) { + \is_array($value) => $this->limit($value, $depth + 1), + \is_string($value) => $this->limitString($value), + default => $value, + }; } } return $limited; } + /** + * Truncated to MAX_STRING_LENGTH characters, followed by the number of characters of the whole string. Cut on a + * character: a valid UTF-8 string stays valid. + */ + private function limitString(string $value): string + { + // A string of at most MAX_STRING_LENGTH bytes has at most as many characters: not counted + if (\strlen($value) <= self::MAX_STRING_LENGTH || ($length = mb_strlen($value, 'UTF-8')) <= self::MAX_STRING_LENGTH) { + return $value; + } + + return mb_substr($value, 0, self::MAX_STRING_LENGTH, 'UTF-8').\sprintf(' [...] (over %d characters, %d total, truncated)', self::MAX_STRING_LENGTH, $length); + } + /** * Invalid UTF-8 sequences replaced (by "?"), NUL characters removed (rejected by PostgreSQL, or the value truncated * there), truncated to the length of the column: a number of characters (code points) in the database, not of diff --git a/tests/Entity/LogRecordTest.php b/tests/Entity/LogRecordTest.php index 9722231d..41eee87b 100644 --- a/tests/Entity/LogRecordTest.php +++ b/tests/Entity/LogRecordTest.php @@ -126,6 +126,27 @@ public function testEncodableContextIsUnchanged(): void self::assertSame($context, $this->createLogRecord($context)->context); } + /** + * The strings of the context are limited to 65536 characters (not bytes), at any depth: a larger one (e.g. the + * content of a file) could exceed the maximum packet size of the database, the log records were then lost. + */ + public function testContextStringsAreLimitedTo65536Characters(): void + { + $limit = str_repeat('é', 65536); + $context = $this->createLogRecord([ + 'content' => str_repeat('a', 1_000_000), + 'nested' => ['multibyte' => $limit.'éé', 'limit' => $limit, 'bytes' => str_repeat('a', 65536)], + 'number' => 1, + ])->context; + + self::assertSame(str_repeat('a', 65536).' [...] (over 65536 characters, 1000000 total, truncated)', $context['content']); + self::assertSame( + ['multibyte' => $limit.' [...] (over 65536 characters, 65538 total, truncated)', 'limit' => $limit, 'bytes' => str_repeat('a', 65536)], + $context['nested'] + ); + self::assertSame(1, $context['number']); + } + /** * The limits of the log file (Monolog NormalizerFormatter): at most 1000 items per array. */