Skip to content

fix(debugger): attribute console logs to the app source that emitted them - #647

Open
filip131311 wants to merge 4 commits into
mainfrom
filip/log-registry-source-attribution
Open

fix(debugger): attribute console logs to the app source that emitted them#647
filip131311 wants to merge 4 commits into
mainfrom
filip/log-registry-source-attribution

Conversation

@filip131311

Copy link
Copy Markdown
Collaborator

Fixes #646.

The problem

Every cluster from debugger-log-registry reported the same sourceLine, and every line in the flat
log file had source -. Reproduced on an Expo SDK54 / RN 0.81.5 app with two probes planted at known
positions (app/(tabs)/index.tsx:11, components/hello-wave.tsx:4):

{ message: 'Running "main" with {...}', sourceLine: 1160 }   // no sourceFile
{ message: 'ARGENT_PROBE_HOME',         sourceLine: 1160 }   // no sourceFile
{ message: 'ARGENT_PROBE_WAVE ...',     sourceLine: 1160 }   // no sourceFile

Three separate causes, found by capturing the raw Runtime.consoleAPICalled frames:

  1. The top frame is never the call site. Every console.* call on React Native enters through the
    same polyfill, so callFrames[0] is a fixed position in the runtime for every log ever emitted.
    The real call site was at frame 2 and frame 5 respectively.
  2. The bundle URL never survived. All frames share
    http://localhost:8081/…/entry.bundle//&platform=ios&…, whose pathname failed the source-extension
    check, so sourceFile was always dropped.
  3. Bundle lines were never mapped. Even the correct frame would have reported a generated line.

The result is worse than no attribution: a constant line number with no file reads as authoritative.

The fix

Walk the stack, map each frame back to its original source, and take the first frame that is not
runtime or third-party code.

No hand-maintained denylist of framework internals is involved. Metro already publishes the standard
x_google_ignoreList in its source map (1421 of 1441 sources on the test app), which marks exactly
the console polyfill, LogBox, react-devtools and the renderer. Where a map publishes no ignore list,
node_modules is the fallback convention. Where a log has no app frame at all, it is reported as
unattributed rather than pinned to the runtime internal it passed through.

SourceMapConsumer drops unknown keys, so the ignore list is read off the raw JSON at registration.
Frames are only resolved against a map that owns their script — borrowing another script's map would
produce a real-looking file and line that is simply wrong, which is the failure this issue is about.

Also corrected

  • Lines are now 1-based, matching what an editor shows. Call frames are 0-based, so the reported
    line was previously one short — including on Chromium, where the issue described 76/81 as
    correct when the calls are really on lines 77 and 82.
  • sourceFile and sourceLine are now always present together. They previously came from two
    independent expressions, which is how a bare line number with no file was produced at all.
  • file:// paths stay absolute and HTML documents are accepted as sources, since an inline
    script's frame reports its line within the document. Without this, Electron logs would have lost
    the attribution they used to have.

Deliberately not done

  • Registering source maps on the Chromium debugger so Electron gets mapped attribution too. Desirable,
    but it changes Chromium behaviour and needs its own review of the source-map fetch allowlist for
    non-loopback dev-server origins.
  • Consolidating utils/react-profiler/metro/source-map.ts, which is a second source-map
    implementation that could now sit on this registry.
  • Surfacing the source on the console websocket payload. The flat file discards the source column on
    read, so this needs its own delimiter design.

Verification

Live, against the reproduction above, running this branch's tool-server on a booted iPhone 17 Pro:

ARGENT_PROBE_HOME   -> app/(tabs)/index.tsx:11      (ground truth: line 11)
ARGENT_PROBE_WAVE   -> components/hello-wave.tsx:4  (ground truth: line 4)
Running "main" ...  -> unattributed                 (no app frame in the stack)

No cluster reports 1160; no cluster has a line without a file. The flat file carries the same
attribution and is greppable as app/(tabs)/index.tsx:11. Re-verified after debugger-reload-metro,
which re-registers the bundle's map.

Chromium control, on the Electron test app (console.log at index.html:77, console.warn at :82):

log      /Users/…/electron-test-app/index.html:77
warning  /Users/…/electron-test-app/index.html:82

Both exact, and strictly better than before, where these carried a bare 76/81 and no file.

Full tool-server suite green (3127 passed). New coverage: generated→original resolution and ignore-list
handling against a Metro-shaped fixture map, the frame-selection policy per branch, and an end-to-end
test that drives a real registry through a real writer with the stack shape captured from the device.

🤖 Generated with Claude Code

…ources

The source-map registry could only map original -> generated. Log attribution
needs the other direction: a call frame reports a position in the bundle, and
what a user can act on is the file and line it came from.

Adds `toOriginalPosition`, along with the map's ignore list — the standard
`x_google_ignoreList`, which bundlers use to mark their own runtime, polyfills
and dependencies. `SourceMapConsumer` drops unknown keys, so it is read off the
raw JSON at registration. Indices that collide on a normalised source name are
left attributable rather than hidden, so an ambiguous entry cannot swallow real
app code.

A frame is only resolved against a map that owns its script; with no match the
call returns null rather than borrowing another script's map, which would yield
a real-looking file and line that is simply wrong. Lookups retry upwards when a
frame's column precedes the first mapping on its line, which is routine for
indented bundle output.

Registrations are capped so that Fast Refresh reloads and lazy chunks cannot
accumulate parsed maps for the life of a session.
Taking the top call frame does not identify a call site. On React Native every
console.* call enters through the same polyfill, so the top frame is a fixed
position inside the runtime — identical for every log the app ever emits.

Walks the stack instead, mapping each frame back to its original source and
taking the first that is not runtime or third-party code. The map's ignore list
decides that where one is published, so no hand-maintained list of framework
internals is needed; without one, `node_modules` is the fallback convention.

A log with no app frame at all is reported as unattributed rather than pinned to
the runtime internal it passed through — naming that would restate the same
constant position in mapped form.

The file and line are produced together, so a line number can no longer be
emitted without the file it belongs to.
The log writer read the top call frame directly, so every entry from a bundled
app carried the same line number and no file at all — a constant that reads as
authoritative. `debugger-log-registry` reported `sourceLine: 1160` for React
Native's own startup log and for app logs alike.

The writer now attributes through the source-map registry, which the Metro
debugger passes in by reference so lazily parsed scripts are picked up on the
next write. Runtimes that serve unbundled scripts pass none and keep reading the
frame's own URL.

Line numbers are now the 1-based line an editor shows; call frames are 0-based,
so the reported line was previously one short. Paths are also left absolute when
they are not under the project root, and an HTML document is accepted as a
source, since an inline script's frame reports its line within the document.

A cluster whose first occurrence arrived before its source map was registered
now takes the attribution from a later one instead of discarding it.

Fixes #646
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.

debugger-log-registry: console-log source attribution is empty or constant (every cluster reports the same sourceLine)

1 participant