From f54ca8450be12685516ee17083e24af044c93cb8 Mon Sep 17 00:00:00 2001 From: David Dreschner Date: Mon, 19 Oct 2026 13:54:39 +0200 Subject: [PATCH] perf(LogIterator): Read long lines in linear time MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit LogIterator reads the log backwards in chunks of 8 KB. When a line spans several chunks, every chunk is prepended to the whole buffer before the whole buffer is searched for a newline again. Reading a line of length L therefore takes O(L²) time. Such long lines can be written, for example by occ upgrade, which forces the debug log level. A log with a few of them stalls the "Errors in the log" setup check and the log viewer. Remember where the line ends, only search the newly read chunk for its start, and then read the whole line at once. This reduces the time to O(L). Assisted-by: ClaudeCode:claude-opus-5-5 Signed-off-by: David Dreschner --- lib/Log/LogIterator.php | 21 ++++++++++++++++--- tests/Unit/Log/LogIteratorTest.php | 33 ++++++++++++++++++++++++++++++ 2 files changed, 51 insertions(+), 3 deletions(-) diff --git a/lib/Log/LogIterator.php b/lib/Log/LogIterator.php index 046f23f6a..6a6569ad4 100644 --- a/lib/Log/LogIterator.php +++ b/lib/Log/LogIterator.php @@ -81,30 +81,45 @@ private function fillBuffer(): void { #[\Override] public function next(): void { + // End offset of a line spanning multiple chunks. Its chunks are dropped once searched + // and the whole line is read again at once when its start is found. + $lineEnd = null; // Loop through each character of the file looking for new lines while ($this->position >= 0) { $newlinePos = strrpos($this->buffer, "\n"); if ($newlinePos !== false) { - if ($newlinePos + 1 === strlen($this->buffer)) { + if ($lineEnd === null && $newlinePos + 1 === strlen($this->buffer)) { // try again with truncated buffer if it ends with newline, i.e. on first call $this->buffer = substr($this->buffer, 0, $newlinePos); continue; } - $this->lastLine = substr($this->buffer, $newlinePos + 1); + $this->lastLine = $lineEnd === null + ? substr($this->buffer, $newlinePos + 1) + : $this->readRange($this->position + $newlinePos + 1, $lineEnd); $this->buffer = substr($this->buffer, 0, $newlinePos); $this->currentKey++; return; } elseif ($this->position === 0) { - $this->lastLine = $this->buffer; + $this->lastLine = $lineEnd === null ? $this->buffer : $this->readRange(0, $lineEnd); $this->buffer = ''; $this->currentKey++; return; } else { + // $lineEnd must stay null until the line has content, the trailing newline check relies on it + if ($this->buffer !== '') { + $lineEnd ??= $this->position + strlen($this->buffer); + $this->buffer = ''; + } $this->fillBuffer(); } } } + private function readRange(int $start, int $end): string { + fseek($this->handle, $start); + return (string)stream_get_contents($this->handle, $end - $start); + } + #[\Override] public function valid(): bool { if (!is_resource($this->handle)) { diff --git a/tests/Unit/Log/LogIteratorTest.php b/tests/Unit/Log/LogIteratorTest.php index 1c643d4a5..f39ae894d 100644 --- a/tests/Unit/Log/LogIteratorTest.php +++ b/tests/Unit/Log/LogIteratorTest.php @@ -8,6 +8,7 @@ namespace OCA\LogReader\Tests\Unit\Log; use OCA\LogReader\Log\LogIterator; +use PHPUnit\Framework\Attributes\DataProvider; use Test\TestCase; class LogIteratorTest extends TestCase { @@ -23,6 +24,38 @@ private function getLogIterator(string $log) { return new LogIterator($handle, \DateTime::ATOM, 'UTC'); } + private function getLogLine(string $reqId, int $length): string { + $emptyLine = json_encode(['reqId' => $reqId, 'level' => 3, 'message' => '']); + $line = json_encode(['reqId' => $reqId, 'level' => 3, 'message' => str_repeat('a', $length - strlen($emptyLine))]); + $this->assertSame($length, strlen($line)); + return $line; + } + + public static function trailingNewlineProvider(): array { + return [ + 'without trailing newline' => [''], + 'with trailing newline' => ["\n"], + ]; + } + + #[DataProvider(methodName: 'trailingNewlineProvider')] + public function testGetLinesSpanningMultipleChunks(string $trailingNewline): void { + // The first line starts at the beginning of the file. The last line and the trailing newline fill + // exactly two chunks, so the newline in front of the last line is the last byte of the next chunk. + $first = $this->getLogLine('1', 3 * LogIterator::CHUNK_SIZE + 17); + $middle = $this->getLogLine('2', 100); + $last = $this->getLogLine('3', 2 * LogIterator::CHUNK_SIZE - strlen($trailingNewline)); + $log = $this->getLogIterator($first . "\n" . $middle . "\n" . $last . $trailingNewline); + + $entries = iterator_to_array($log); + + $this->assertSame([ + json_decode($last, true), + json_decode($middle, true), + json_decode($first, true), + ], $entries); + } + public function testGetLines() { $log = $this->getLogIterator( '{"reqId":"1","level":3,"time":"2019-11-04T18:50:57+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"comments","method":"GET","url":"/settings/admin/logging","message":{"Exception":"RuntimeException","Message":"App class OCA\\\\Comments\\\\AppInfo\\\\Application is not setup via query() but directly","Code":0,"Trace":[{"file":"/srv/http/cloud/apps/comments/lib/AppInfo/Application.php","line":42,"function":"__construct","class":"OCP\\\\AppFramework\\\\App","type":"->","args":["comments",[]]},{"file":"/srv/http/cloud/apps/comments/appinfo/app.php","line":24,"function":"__construct","class":"OCA\\\\Comments\\\\AppInfo\\\\Application","type":"->","args":[]},{"file":"/srv/http/cloud/lib/private/legacy/app.php","line":260,"args":["/srv/http/cloud/apps/comments/appinfo/app.php"],"function":"require_once"},{"file":"/srv/http/cloud/lib/private/legacy/app.php","line":154,"function":"requireAppFile","class":"OC_App","type":"::","args":["comments"]},{"file":"/srv/http/cloud/lib/private/legacy/app.php","line":127,"function":"loadApp","class":"OC_App","type":"::","args":["comments"]},{"file":"/srv/http/cloud/lib/base.php","line":991,"function":"loadApps","class":"OC_App","type":"::","args":[]},{"file":"/srv/http/cloud/index.php","line":42,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/srv/http/cloud/lib/public/AppFramework/App.php","Line":77,"CustomMessage":"--"},"userAgent":"Mozilla","version":"18.0.0.1"}