Skip to content

[SLES-3037] fix: reassemble log records Lambda splits into pieces - #1415

Merged
shreyamalpani merged 9 commits into
mainfrom
shreya.malpani/fix-logs-payload-restitch
Oct 23, 2026
Merged

shreyamalpani merged 9 commits into
mainfrom
shreya.malpani/fix-logs-payload-restitch

Conversation

@shreyamalpani

@shreyamalpani shreyamalpani commented Oct 8, 2026 •

Copy link
Copy Markdown
Contributor

Overview

Follow-up to #1357 (SLES-2997). That fix added stitch.rs to recover telemetry payloads broken by an oversized log record, and raised maxBytes to 1 MiB. Customers on v100 still hit the same timeouts. The stitcher was in place, but their payloads never reached it.

#1357 assumed the Telemetry API cuts a record at maxBytes and resumes it in the next POST under the same envelope. That isn't what happens. Lambda itself cuts any log line longer than about 256 KiB into pieces, whatever maxBytes is, and sends each piece as its own event with its own timestamp. For JSON log lines, each piece's raw bytes become that event's record value, so no payload containing a piece parses. The stitcher's assumptions failed in three ways:

  • Pieces in the same POST. At 1 MiB maxBytes, several pieces land in one POST. The stitcher only handled a split across two POSTs, so a single body like this was dropped.
  • Envelope pairing. The halves were paired by a byte-identical envelope, but each piece has its own timestamp, so pairing failed whenever two pieces fell in different milliseconds.
  • Error category. Only Eof parse failures were held. A cut right after a \ or a complete value fails as Syntax, so it was rejected outright.

So these payloads were still discarded, platform.runtimeDone went with them, and the on-demand loop waited until the sandbox timed out. The original repro passed because, at 256 KiB maxBytes, each piece ended its own POST and both pieces shared a timestamp, which happens to fit the old model.

Changes (extension/telemetry/stitch.rs)

  • Find seams by testing the record before each boundary. The payload is split into events, and a boundary is a seam when the record value before it is cut short (valid JSON until its input runs out: serde reports EOF, or an invalid number at its last byte for a cut after -, . or e) and the next event is a log piece of the same type. The pieces are joined and the payload rebuilt. A whole record before a boundary means a normal boundary, so a platform.* event like runtimeDone is never absorbed.
  • Keep events that land between pieces. A whole event of another type between two pieces, such as an extension log line, is moved ahead of the joined record.
  • Hold a payload whose last record is cut short (the same test), so the next POST can complete it.
  • Join across POSTs without envelope matching. The next payload must open with a log piece, and the joined payload goes through the same walk, so a record can span more than two POSTs.
  • Fall back if a join fails. The held fragment is dropped, and the incoming payload is stitched on its own rather than discarded along with it.

Performance: unchanged for payloads that parse, since the stitcher only runs after a failed parse. Recovering a payload parses each record value on its own, and the cut record again for each piece added, bounded by the 4 MiB fragment cap and 64 seams. That's a few ms for a ~1 MiB record, and only on payloads that previously hung the invocation.

Known gaps

  • A split that happens to be valid JSON (a cut inside a number in an array of objects) arrives as one garbled log line, since payloads that parse never reach the stitcher. Telling it apart from a whole line would depend on Lambda's cut size, which isn't documented.
  • If runtimeDone lands between two pieces, it's moved ahead of the joined line, so the line is sent without its request ID. We haven't seen this happen; follow-up ticket.
  • In a payload that already fails to parse, a log line that itself contains telemetry-envelope-shaped JSON can be misread as pieces. Before this PR, that whole payload was dropped.

Testing

  • Unit tests:
    • Every-byte cuts: two synthetic JSON records, one with escapes, \u sequences and multi-byte text inside a string, and one with arrays of objects in its structure, cut at every char boundary: as pieces in one payload (with and without an extension log line between them) and as a piece split across two POSTs. Each case must reassemble the exact record plus runtimeDone. Cuts that leave the payload valid JSON are skipped as the known gap above.
    • Multi-piece: a record in several pieces where the POST boundary falls between two of them.
    • runtimeDone after a cut piece is kept whole and delivered with the joined record.
    • Regressions: a broken record isn't taken for pieces, a payload that doesn't continue the held fragment is still recovered, and a continuation opening with a whole event isn't joined.
  • Full bottlecap test suite passes, and clippy and fmt are clean.
  • Tested with a repro function manually: log lines over 256 KiB that previously hung every invocation now complete with the record reassembled.

@shreyamalpani
shreyamalpani marked this pull request as ready for review October 8, 2026 15:58
@shreyamalpani
shreyamalpani requested a review from a team as a code owner October 8, 2026 15:58
@shreyamalpani
shreyamalpani requested review from lym953 and a balanced review from Copilot October 8, 2026 15:58

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The stitching logic is bounded, thoroughly tested, and correctly integrated with telemetry handling.

0 open findings

What changed in this PR

Reworks telemetry stitching to recover oversized Lambda log records split within or across POST payloads.

Changes:

  • Detects and removes split-record seams.
  • Supports multi-piece and cross-POST recovery with fallback handling.
  • Adds comprehensive boundary and regression tests.
File Description
bottlecap/​src/​extension/​telemetry/​stitch.rs Implements generalized record reassembly and tests.
bottlecap/​src/​extension/​telemetry/​listener.rs Uses the revised stitching API.

🧠 Review effort: Balanced


Give feedback about Copilot approvals in this survey to enter a drawing for a $150 gift card.

@datadog-official

datadog-official Bot commented Oct 8, 2026 •

Copy link
Copy Markdown
Contributor

Pipelines

This comment will be updated automatically if new data arrives.
🔗 Commit SHA: ab87a3e | Docs | Give us feedback!

@lym953

lym953 commented Oct 9, 2026

Copy link
Copy Markdown
Contributor

Also adds GHSA-2mjx-qc3c-rqvc to .trivyignore.yaml.

I'm also doing this in #1414. Feel free to approve and rebase on my changes to make your PR smaller.

Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
@shreyamalpani
shreyamalpani force-pushed the shreya.malpani/fix-logs-payload-restitch branch from 1b5eca7 to d6f0a71 Compare October 13, 2026 14:25
@shreyamalpani
shreyamalpani force-pushed the shreya.malpani/fix-logs-payload-restitch branch from 269ced9 to b92a519 Compare October 13, 2026 17:42

@lym953 lym953 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Written by Claude, reviewed by @lym953 before posting.

One payload shape still loses runtimeDone: a JSON log line with an array of objects, cut inside one of the objects. Details and a failing test are on SEAM_REACH.

Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/listener.rs Outdated
@shreyamalpani
shreyamalpani requested a review from lym953 October 20, 2026 17:35

@lym953 lym953 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Written by Claude, reviewed by @lym953 before posting.

Thanks, the new design recovers every cut I tried, in one POST and in two. The only exception is a short first piece, which you excluded on purpose. Two smaller problems and one question are inline.

}
_ => return false,
},
Some((record, _)) if event.kind != record.kind => {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Written by Claude, reviewed by @lym953 before posting.

When runtimeDone comes before the joined record, the logs processor sends that log line with an empty request ID.

This branch moves an event of another type ahead of the cut record, and keeps_runtime_done_whole_after_a_cut_piece expects this for runtimeDone. The logs processor handles events in order:

  1. A function log line without its own requestId takes the request ID of the current invocation (processor.rs#L486-L497).
  2. runtimeDone clears that ID (processor.rs#L346-L347).
  3. A line with no request ID goes to the orphan queue (processor.rs#L555-L556).
  4. When the next log line with a request ID arrives, the lines in the orphan queue get the current request ID (processor.rs#L860-L865). After runtimeDone, that next line is REPORT, and the current request ID is empty.

I sent this sequence through the processor's process in a test: START of req-1, the joined record {"items":[{"id":1},{"id":23}]} and runtimeDone in the order below, then platform.report, then START of req-2.

Order of the two events Request ID on the joined log line in the output
Joined log line, then runtimeDone req-1
runtimeDone, then joined log line "" (empty)

Did the repro show runtimeDone between two pieces? If it did, one option is to put events of another type after the joined record, in their original order. A JSON line that holds its own requestId does not have this problem.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good find, you're right about the ordering. Though a full fix would make the cross-POST join more complex, since instead of appending the next POST it'd have to remember where the cut record ends and splice the next piece in ahead of the held events. We haven't seen runtimeDone land between two pieces so far, and if it does happen runtimeDone and its metrics still get handled and the line still gets sent, just without the request ID. So, I’m thinking of leaving this as-is for now and handling that in a follow-up, so that we can get the hang fix out as soon as possible.

Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
Comment thread bottlecap/src/extension/telemetry/stitch.rs Outdated
@lym953

lym953 commented Oct 22, 2026

Copy link
Copy Markdown
Contributor

🤖 Written by Claude, reviewed by @lym953 before posting.

Thanks for the changes. I ran these on d1a1465:

Check Result
Every cut of the array-of-objects record, pieces in one POST 44 of 45 recovered. The one miss is the known gap, a cut inside 23 that leaves valid JSON.
Same cuts, pieces in two POSTs 45 of 45 recovered
The 261,215-byte whole line from the earlier comment Not changed

Two requests, neither blocking:

  1. Please update the PR description before merge. It still says "Serde always fails at, or up to 4 bytes after, a seam". The stitcher now tests the record value before each boundary.
  2. Please file a ticket for the runtimeDone order follow-up. A short comment on keeps_runtime_done_whole_after_a_cut_piece that calls the current order a known gap also helps a later reader.

@shreyamalpani
shreyamalpani merged commit 8a2cc02 into main Oct 23, 2026
62 checks passed
@shreyamalpani
shreyamalpani deleted the shreya.malpani/fix-logs-payload-restitch branch October 23, 2026 14:51
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants