TR-7543 - Add stdout JSON-Lines formatter for VictoriaLogs dual-write

[sanchowsk]

Task

TR-7543: Add dual-write stdout logging (VictoriaLogs) to paysera/lib-logging-extra-bundle
https://jira.paysera.net/browse/TR-7543

Part of the New-DC migration dual-write logging initiative: every log record is written to both Graylog and stdout, where stdout is collected by VictoriaLogs. Apps on this bundle (raw Monolog + paysera/lib-logging-extra-bundle) had no shared stdout formatter and were hand-writing per-app ones — this puts it in the shared bundle instead.

Changes

• src/Service/Formatter/StdoutJsonFormatter.php — new formatter, service paysera_logging_extra.formatter.stdout_json. Produces one compact JSON object per line: timestamp (ISO-8601, microseconds + offset), application_name, channel, syslog level (DEBUG=7 … EMERGENCY=0), level_name, message, optional full_message/context/extra, and a top-level correlation_id (hoisted from extra, populated by the bundle's CorrelationIdProcessor). The concrete class is declared per Monolog major (class_exists('Monolog\LogRecord') → LogRecord on v3, array on v1/v2), matching the existing GelfMessageFormatter/CorrelationIdProcessor idiom.
• src/Service/Formatter/StdoutRecordEncoder.php — the shared encoding logic, a plain class composed by the formatter (injected as a service) rather than an abstract base. Each line is capped at 32766 bytes, enforced against the encoded length; oversize records stay single-line, get truncated: true, and are shrunk by dropping full_message, then context/extra, then truncating message UTF-8-safely, then dropping correlation_id so the cap always holds.
• src/Service/ExceptionMessageParser.php — splits an exception-shaped message into a short message + the raw full_message.
• formatters.xml — registers the services.
• Tests — tests/Unit/Service/Formatter/StdoutJsonFormatterTest.php (compactness, syslog mapping, correlation-id hoisting, falsey-context preservation, empty-field omission, canonical field order, message/full_message rendering, 32 KB truncation incl. escape-heavy payloads and an oversize correlation_id, batch) and tests/Unit/Service/ExceptionMessageParserTest.php (match, no-match, newline normalization).
• CHANGELOG 3.4.0, README opt-in section.

Output contract

Matches the canonical StdoutJsonFormatter from evp/lib-application-logging-bundle for plain records: same field set and order, same syslog severity mapping, same 32766-byte cap and shrink order.

One deliberate deviation: ExceptionMessageParser here matches case-insensitively, so standard PHP class names (RuntimeException, PDOException, …) are split into a short message + raw full_message. The canonical parser only matches a lowercase exception and leaves those unsplit. Plain records remain byte-identical.

Opt-in

No per-call-site changes. Add a php://stdout handler using the formatter and make it a member of the existing graylog_failsafe whatfailuregroup (see README). WhatFailureGroupHandler isolates failures, so Graylog being unreachable cannot break stdout and vice-versa. The existing GELF/Graylog path is unchanged — upgrading the bundle changes nothing until an app opts in.

Tests

Full suite green across the CI matrix (38 jobs, PHP 7.4–8.4 × Symfony 4–7):

PHP 7.4 / Monolog 2   OK (81 tests, 1277 assertions)
PHP 8.3 / Monolog 3   OK (70 tests, 1262 assertions, 2 skipped by design)

[gemini-code-assist]

Code Review

This pull request introduces StdoutJsonFormatter, a compact, one-object-per-line JSON formatter for stdout collected by VictoriaLogs. It includes an abstract base class AbstractStdoutJsonFormatter to handle syslog severity mapping and a 32766-byte limit truncation strategy, and a concrete StdoutJsonFormatter class designed to support both Monolog v1/v2 (arrays) and Monolog v3 (LogRecord objects). The changes also include service registration, comprehensive unit tests, and documentation on how to configure dual-writing to stdout. There are no review comments, and I have no additional feedback to provide.

Important

The consumer version of Gemini Code Assist on GitHub is being sunset. Starting June 18, 2026, new organization installations will be blocked, and all code review activity will officially cease on July 17, 2026.
For more details on the timeline and next steps, please review the Help Documentation.

[mSprunskas]

  1. Dead/vestigial full_message field and unreachable shrink step (Low)

  Location: src/Service/Formatter/AbstractStdoutJsonFormatter.php:100, :119-126

  full_message is hardcoded to null in formatRecord() (line 100). filterEmptyFields() strips any null/[] field before every encode, so full_message never appears in the output (confirmed at runtime — output keys are
  timestamp,application_name,channel,level,level_name,message,context,extra,correlation_id).

  Consequently the shrink branch:
  if (isset($fields['full_message'])) {   // isset(null) === false → always skipped
      unset($fields['full_message']);
      ...
  }
  is dead code — isset() returns false for a null value, so lines 120-126 can never execute.
  
  Impact: No functional bug (the test testOmitsEmptyContextExtraAndFullMessage confirms omission is intended), but the field and shrink step are vestigial copies from the canonical evp formatter. The class docblock (line 17) and CHANGELOG claim "same field
  set" including full_message and "same shrink order" — this bundle emits neither. If true byte-compatibility with the canonical formatter is required, the permanent absence of full_message is a deviation worth confirming with the source formatter.
  Fix: Either drop full_message and its dead branch entirely, or populate it if parity with the canonical formatter genuinely requires the field.

  2. datetime read without a fallback on the array path (Low)

  Location: src/Service/Formatter/StdoutJsonFormatter.php:47

  In the Monolog v1/v2 branch, every field is defensively defaulted except datetime:
  $record['datetime'],                              // no ?? fallback
  (string) ($record['channel'] ?? ''),
  (int) ($record['level'] ?? Logger::DEBUG),
  ...
  A record missing datetime yields an undefined-index warning and then a TypeError (null passed to the DateTimeInterface $datetime parameter of formatRecord()). In practice Monolog always populates datetime, and the sibling GelfMessageFormatter explicitly
  validates its presence — so this is a robustness/consistency nit, not a live bug.
  Fix: Guard datetime consistently with the other fields, or (like GelfMessageFormatter) throw a clear InvalidArgumentException when it is absent.

  3. Escape-heavy messages are over-truncated to empty (Low / informational)

  Location: src/Service/Formatter/AbstractStdoutJsonFormatter.php:134-140

  The single-pass budget subtracts the encoded overflow from the raw message length. For content that inflates heavily under JSON escaping (e.g. control chars → \u0001), the encoded overflow can exceed the raw length, so truncateToByteLength() receives a
  non-positive length and drops the entire message. Verified at runtime: a 60000-byte escape-heavy message is truncated to an empty message, even though a few thousand characters would still have fit.

  This is a deliberate, documented tradeoff (the inline comment guarantees "a single pass never overshoots the cap") and the output stays valid, within the cap, and flagged truncated — so it is not a correctness bug. Flagging only because it discards more
  log content than necessary; an iterative shrink (or budgeting against escaped length) would retain more of the message.

[sanchowsk]

Thanks for the review @mSprunskas — pushed the changes in 711c189.

Inline threads (replied on each):

• Composition over inheritance — abstract base removed; logic moved to a regular StdoutRecordEncoder composed by the formatter.
• Verbose docblock — trimmed.
• Test boilerplate — duplicate truncation tests folded into a data provider.

Review-body findings:

1. Dead full_message + unreachable shrink step — removed the field and the isset($fields['full_message']) branch entirely, and corrected the CHANGELOG wording so it no longer claims full_message/"same shrink order". We intentionally don't split exceptions into full_message (the consumer app doesn't need it), so this is now stated explicitly rather than carried as vestigial code.
2. datetime without a fallback — now throws InvalidArgumentException when an array record lacks a datetime, consistent with GelfMessageFormatter (added a test for it). The Monolog v3 path reads the typed LogRecord::$datetime property, so no guard is needed there.
3. Escape-heavy over-truncation — left as-is per your note that it's a documented, non-buggy tradeoff (output stays valid, within the cap, and flagged truncated). Happy to switch to an iterative shrink if you'd prefer retaining more of the message.

Full suite green (42 tests across the Monolog 1/2/3 matrix); output remains byte-identical to the canonical evp formatter for the emitted fields.

Note: the same changes are mirrored on the 2.x backport branch (for app-target2-integration, which stays on sentry-symfony ^4); that PR will follow once a 2.x maintenance branch exists to target.

[sanchowsk]

@mSprunskas one more request — could you create a 2.x maintenance branch from the 2.2.0 tag? I'd like to open a separate PR to backport this same StdoutJsonFormatter as 2.3.0, and there's currently no 2.x branch on origin to target (only master, which is the 3.x line).

Why a 2.x release is needed rather than just consuming 3.x:

• The consumer here is app-target2-integration (TR-7176), which is on this bundle ^2.2 and on sentry/sentry-symfony ^4.
• Bundle 3.x's only BC change (3.0.0) is bumping sentry/sentry-symfony to ^5.3. So a ^2.2 → ^3.4 bump would drag that app through a sentry-symfony 4 → 5 major upgrade (its sentry.yaml still uses options.send_attempts, removed in sentry/sentry 4) — unrelated to logging and out of scope for that ticket.
• Shipping the formatter on the 2.x line as 2.3.0 (purely additive, no sentry change) lets the app adopt dual-write with a simple ^2.2 → ^2.3 bump.

The backport is already prepared and green — it mirrors this PR, adapted to the 2.x line (single self-contained class using FormatterTrait instead of the v3 LogRecord split; PHP 7.2 / Monolog 1|2 compatible; full suite passing). I'll point the PR at 2.x as soon as it exists.

To keep both lines consistent and avoid a feature regression on a future 2.x → 3.x upgrade, the plan is to release it on both 3.4.0 (this PR) and 2.3.0 (the backport).

[sanchowsk]

Follow-up on the full_message point (review finding #1) — reversing my earlier decision.

I'd initially dropped full_message as vestigial, but the task's actual requirement is byte-compatibility with the canonical StdoutJsonFormatter, and that formatter does emit full_message for exception-shaped messages. So rather than drop it, I've now implemented it properly (580d90f):

• Ported ExceptionMessageParser (same regex as the canonical) as a small Service\ExceptionMessageParser, composed into StdoutRecordEncoder.
• Exception-shaped messages are split into a short message + the raw full_message, and the shrink order drops full_message first — so the branch you flagged as dead is now actually exercised, not vestigial.
• CHANGELOG updated to state the full canonical field set + shrink order.

Verified: a plain record stays byte-identical to the canonical output, and an exception message now produces {... "message":"<short>", "full_message":"<raw>" ...} in the canonical field order. Full suite green (43 tests on the Monolog 1/2/3 matrix). The same change is mirrored on the 2.x backport branch.

[mSprunskas]

┌─────┬─────────────┬─────────────────────────────────────────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ # │ Severity │ Location │ Note │
├─────┼─────────────┼─────────────────────────────────────────────────────────────────┼────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┤
│ │ │ │ For an oversize record whose message is escape-heavy (e.g. many ", \n, control chars), the single-pass overflow math computes a negative target length, so message │
│ 1 │ Low │ StdoutRecordEncoder::encodeWithinByteLimit() │ is truncated to "" — the entire message is discarded rather than trimmed to fit ~32 KB. I reproduced this: a 60 KB escape-heavy message yields a 151-byte line │
│ │ (by-design) │ src/Service/Formatter/StdoutRecordEncoder.php:117-123 │ with an empty message. This is identical to the canonical evp formatter and is a deliberate consequence of the "byte-compatible / single-pass" design, so it is │
│ │ │ │ not a defect against spec — but it is worth being aware of as real data loss. A future iterative pass could preserve more of the message if desired. │
├─────┼─────────────┼─────────────────────────────────────────────────────────────────┼────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┤
│ 2 │ Trivial │ README.md:118-121 │ The field list and shrink description omit full_message (which the formatter does emit for exception-shaped messages, and which is dropped first during shrink, │
│ │ (docs) │ │ before context/extra). The CHANGELOG entry documents both correctly; only the README is slightly incomplete. │
└─────┴─────────────┴─────────────────────────────────────────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘

[sanchowsk]

Thanks @mSprunskas — pushed 0295ac9 addressing the latest round.

Inline threads (replied on each):

• Typed properties instead of @var phpdoc on the formatter (both Monolog branches) and the encoder.
• Encoder now injected as a service dependency (registered stdout_record_encoder + exception_message_parser in formatters.xml) rather than constructed in the ctor.
• UTF-8 lead-byte length resolution extracted into a private utf8SequenceLength() method.

Review-body table:

1. Escape-heavy over-truncation — left as-is, per your "by-design / not a defect against spec" note; output stays valid, within the 32766-byte cap, and flagged truncated, matching the canonical evp formatter. Still happy to switch to an iterative shrink if you'd prefer retaining more of the message.
2. README omitted full_message — fixed. The field list now includes full_message (raw original for exception-shaped messages) and the shrink description states the correct order: full_message → context/extra → truncate message.

Full suite green (43 tests, 1232 assertions).

[mSprunskas]

 Issue 1 — ExceptionMessageParser regex is case-sensitive, misses standard PHP exception class names

  File: src/Service/ExceptionMessageParser.php:15
  Severity: Medium
  Type: Correctness — Logic Gap

  The regex /^(.*?:?.*?exception.*?) in / uses lowercase exception without the i (case-insensitive) flag. Standard PHP exception class names all use uppercase E in Exception (e.g. RuntimeException, LogicException, PDOException, InvalidArgumentException).

  Verified with PHP execution — the regex fails to match all common formats:

  ┌─────────────────────────────────────────────────────────────┬──────────┐
  │                           Message                           │  Result  │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ Uncaught RuntimeException: error in /app/file.php:42        │ NO MATCH │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ App\Exception\SomeException: error in /app/file.php:42      │ NO MATCH │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ LogicException in /app/file.php:42                          │ NO MATCH │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ PDOException: SQLSTATE[23000] in /app/file.php:42           │ NO MATCH │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ Uncaught PHP Exception RuntimeException in /app/file.php:42 │ NO MATCH │
  ├─────────────────────────────────────────────────────────────┼──────────┤
  │ An exception occurred while executing a query in SomeClass  │ MATCH    │
  └─────────────────────────────────────────────────────────────┴──────────┘
  
  The only messages it matches are those with the word "exception" in lowercase natural language (e.g. Doctrine's "An exception occurred...").

  Impact: For the majority of real exception log messages, parse() returns null, so full_message is never set and the message is never split into a short headline. The message/full_message split feature is effectively inert for standard PHP exceptions.

  Mitigating note: The docblock says "matching the canonical ExceptionMessageParser from evp/lib-application-logging-bundle", so this may be intentional to maintain behavioral parity. If the canonical parser has the same case-sensitivity, this code
  faithfully reproduces it.

  Fix (if not intentionally matching canonical): Add the i flag: '/^(.*?:?.*?exception.*?) in /i'

  ---
  Issue 2 — Test for exception splitting uses unrealistic message format
  
  File: tests/Unit/Service/Formatter/StdoutJsonFormatterTest.php:102
  Severity: Low
  Type: Test coverage gap

  The test testSplitsExceptionMessageIntoShortMessageAndFullMessage uses the message 'Some exception in /app/src/Foo.php:42' with lowercase exception. This validates the mechanism works, but does not test against realistic PHP exception message formats (e.g.
  'RuntimeException: Something went wrong in /app/src/Foo.php:42'). Since the regex is case-sensitive (Issue 1), adding a test with a realistic Exception (capital E) class name would immediately reveal the gap.

  ---
  Issue 3  - Tests worth consolidating

  Message / full_message rendering. Two methods verify the same act (decode(['message' => …])) with the same two assertions (message, full_message), differing only by input shape:
  - testSplitsExceptionMessageIntoShortMessageAndFullMessage (exception → split)
  - the message half of testFormatsRecordAsSingleCompactJsonLine (plain → no split)

  These collapse into one provider-driven method, and the provider is the natural home for the currently-untested paths: the "has full_message key vs. doesn't" branch and the parser's newline normalization (strtr($message, ["\r" => '', "\n" => ' ']) in
  ExceptionMessageParser — no test exercises a multiline message today).

  /** @dataProvider messageProvider */
  public function testRendersMessageAndFullMessage(string $raw, string $expectedMessage, ?string $expectedFull): void
  {
      $decoded = $this->decode(['message' => $raw]);
      $this->assertSame($expectedMessage, $decoded['message']);
      $expectedFull === null
          ? $this->assertArrayNotHasKey('full_message', $decoded)
          : $this->assertSame($expectedFull, $decoded['full_message']);
  }

  public static function messageProvider(): array
  {
      return [
          'plain'            => ['Example message', 'Example message', null],
          'exception'        => ['Some exception in /app/src/Foo.php:42', 'Some exception', 'Some exception in /app/src/Foo.php:42'],
          'multiline'        => ["Some exception\n stack in /app/x.php:1", 'Some exception  stack', "Some exception\n stack in /app/x.php:1"],
      ];
  }

  Since ExceptionMessageParser is its own class with zero coverage of its own, the higher-value version is a dedicated ExceptionMessageParserTest driving parse() directly with this provider (match / no-match / newline cases), keeping just one integration
  assertion in the formatter test. That removes the whole-formatter round-trip from each parser case.

--

 4 (Low) Byte-cap guarantee has a hole for non-truncatable fields — StdoutRecordEncoder::encodeWithinByteLimit() (src/Service/Formatter/StdoutRecordEncoder.php:88-119)

  The shrink ladder drops full_message, then context/extra, then truncates message. But correlation_id, application_name, channel, and level_name are never dropped or shortened, and there is no final byte-limit re-check after the message truncation (return 
  $this->toJson($fields);). If any of those fixed fields were themselves large (most plausibly correlation_id, which comes from extra and is hoisted verbatim), truncating message to empty still wouldn't bring the line under MAX_JSON_BYTE_COUNT, and an
  over-cap line would be emitted.

  - Impact: Theoretical in this bundle — correlation_id is generated internally (~40–50 chars), so it's not reachable in normal operation. It's a robustness gap in the "always ≤ cap" contract rather than a live bug.
  - Fix (optional): After the final truncation, re-check strlen($json) and, if still over, also drop/shorten correlation_id; or assert the fixed-field floor is well under the cap.

[sanchowsk]

Thanks @mSprunskas — pushed d9bed95 addressing all four findings.

1. ExceptionMessageParser regex is case-sensitive — fixed, with a caveat worth your attention.

I confirmed your reproduction, and I also checked the mitigating note you raised: the canonical parser in evp/lib-application-logging-bundle is identically case-sensitive — the file is md5-identical (66ab2e12) across every vendored copy I could find, up to v8.5.1, and no copy anywhere carries the /i flag. So the port was faithful.

We've decided to add the /i flag here anyway, because a full_message split that never fires for RuntimeException/PDOException is dead weight. The consequence is explicit: this bundle no longer produces byte-identical output to the canonical formatter for exception-shaped messages. For those records we emit a short message + full_message where the canonical formatter emits the raw message and no full_message. Plain (non-exception) records remain byte-identical — same field set, order, syslog mapping, and cap.

I've updated the CHANGELOG and README to state this deviation rather than continue claiming byte-compatibility. The PR description still carries the old "byte-compatible" wording; I'll correct it.

Worth flagging: if VictoriaLogs consumers rely on both bundles emitting the same shape, the real fix is /i in both parsers. Happy to raise a follow-up to change the canonical one in lockstep — your call.

I also verified /i doesn't over-match: User logged in /app/x.php and Some error in /app/Exception/Foo.php:42 still return null.

2. Test used an unrealistic message format — fixed. The formatter test now carries realistic cases (RuntimeException: boom in /app/src/Foo.php:42) alongside the lowercase one.

3. Tests consolidated + dedicated parser test — done. Took your stronger suggestion: added tests/Unit/Service/ExceptionMessageParserTest.php driving parse() directly with a provider covering match, no-match, and the previously-untested newline/carriage-return normalization. The formatter's message/full_message assertions collapsed into one provider-driven testRendersMessageAndFullMessage, with the round-trip kept as a single integration case.

4. Byte-cap hole for non-truncatable fields — fixed. Reproduced first: a 40000-byte correlation_id emitted a 40169-byte line, over the cap. encodeWithinByteLimit() now re-checks the encoded length after truncating message and drops correlation_id if still over, so the "always ≤ 32766" contract holds unconditionally. Added testDropsCorrelationIdWhenItAloneExceedsTheByteCap.

Note this fix cannot break output parity: it only changes records where the canonical formatter would emit an already-over-cap line. Your "theoretical in this bundle" read was right — correlation_id comes from CorrelationIdProvider (uniqid(), bounded, no external setter), and the externally-influenced parent_corr_id is validated to ≤128 bytes and lives in the droppable extra. Hardened anyway.

Tests — green on both matrix legs:

• PHP 7.4 / Monolog 2 — OK (81 tests, 1277 assertions)
• PHP 8.3 / Monolog 3 (LogRecord) — OK (70 tests, 1262 assertions, 2 skipped by design)

Resolving the eight inline threads from the earlier rounds — all were addressed in 711c189 / 0295ac9. The same changes will be mirrored on the 2.x backport branch.