Skip to content

fix: ensure logs containing at not truncated to at [object Object]#4683

Merged
mrbbot merged 4 commits intomainfrom
bcoll/source-mapped-strings-fix-call-site-detection
Jan 10, 2024
Merged

fix: ensure logs containing at not truncated to at [object Object]#4683
mrbbot merged 4 commits intomainfrom
bcoll/source-mapped-strings-fix-call-site-detection

Conversation

@mrbbot
Copy link
Copy Markdown
Contributor

@mrbbot mrbbot commented Jan 2, 2024

Fixes #4668.

What this PR solves / how to test:

Previously, logs containing at were always treated as stack trace call sites requiring source mapping. This change updates the call site detection to avoid false positives, by requiring an indent of 4 spaces and a valid file name. We aren't able to rely on newlines here, as we support source mapping with console.log({ stack: new Error("oopps").stack }). In this case, the value passed to getSourceMappedString() contains ANSI colour codes and looks something like...

{
  value: '{\n' +
    "  stack: \x1B[32m'Error: oopps\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at Object.fetch (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:53:26)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at __facade_modules_fetch__ (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:111:46)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at __facade_invokeChain__ (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:39:10)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at Object.next (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:36:14)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at jsonError (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:69:32)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at __facade_invokeChain__ (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:39:10)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at __facade_invoke__ (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:42:10)\\n'\x1B[39m +\n" +
    "    \x1B[32m'    at Object.fetch (file:///Users/bcoll/.wrangler/tmp/dev-Bzz87I/index.js:162:14)'\x1B[39m\n" +
    '}'
}

To test this, run wrangler dev in fixtures/worker-app and make a request to http://localhost:8787. You should see all console.log()s correctly logged in the output.

Author has addressed the following:

  • Tests
    • Included
    • Not necessary because:
  • Changeset (Changeset guidelines)
    • Included
    • Not necessary because:
  • Associated docs
    • Issue(s)/PR(s):
    • Not necessary because: fixing a regression

Note for PR author:

We want to celebrate and highlight awesome PR review! If you think this PR received a particularly high-caliber review, please assign it the label highlight pr review so future reviewers can take inspiration and learn from it.

@mrbbot mrbbot requested a review from a team as a code owner January 2, 2024 12:35
@changeset-bot
Copy link
Copy Markdown

changeset-bot Bot commented Jan 2, 2024

🦋 Changeset detected

Latest commit: 06daaaa

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 1 package
Name Type
wrangler Patch

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

@github-actions
Copy link
Copy Markdown
Contributor

github-actions Bot commented Jan 2, 2024

A wrangler prerelease is available for testing. You can install this latest build in your project with:

npm install --save-dev https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/runs/7474518185/npm-package-wrangler-4683

You can reference the automatically updated head of this PR with:

npm install --save-dev https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/prs/7474518185/npm-package-wrangler-4683

Or you can use npx with this latest build directly:

npx https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/runs/7474518185/npm-package-wrangler-4683 dev path/to/script.js
Additional artifacts:
npm install https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/runs/7474518185/npm-package-miniflare-4683
npm install https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/runs/7474518185/npm-package-cloudflare-pages-shared-4683
npx https://prerelease-registry.devprod.cloudflare.dev/workers-sdk/runs/7474518185/npm-package-create-cloudflare-4683 --no-auto-update

Note that these links will no longer work once the GitHub Actions artifact expires.


wrangler@3.22.4 includes the following runtime dependencies:

Package Constraint Resolved
miniflare workspace:* 3.20231218.1
workerd 1.20231218.0 1.20231218.0
workerd --version 1.20231218.0 2023-12-18

|

Please ensure constraints are pinned, and miniflare/workerd minor versions match.

@codecov
Copy link
Copy Markdown

codecov Bot commented Jan 2, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Comparison is base (c37d94b) 75.58% compared to head (06daaaa) 75.66%.
Report is 1 commits behind head on main.

Additional details and impacted files

Impacted file tree graph

@@            Coverage Diff             @@
##             main    #4683      +/-   ##
==========================================
+ Coverage   75.58%   75.66%   +0.08%     
==========================================
  Files         243      243              
  Lines       13101    13106       +5     
  Branches     3380     3381       +1     
==========================================
+ Hits         9902     9917      +15     
+ Misses       3199     3189      -10     
Files Coverage Δ
packages/wrangler/src/sourcemap.ts 67.62% <100.00%> (+1.20%) ⬆️

... and 7 files with indirect coverage changes

Comment thread packages/wrangler/src/sourcemap.ts Outdated
Copy link
Copy Markdown

Choose a reason for hiding this comment

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

IMHO this entire 'feature' wants to be scrapped. No way can it be correct to perform REGEX on the output like this to replace console log messages. This is just ASKING for endless weird bugs and frustration.

Basically this just seems to hide the bug and change it from 'at' to ' {4}at' which is also quite likely to be a normal console log message a user might want to log.

Copy link
Copy Markdown
Contributor Author

@mrbbot mrbbot Jan 8, 2024

Choose a reason for hiding this comment

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

Apologies for the frustration this caused you. This is a fair point and something I considered. I'm also checking that a valid file name was found in the match...
https://github.com/cloudflare/workers-sdk/blob/2362fb4d4a1ebd69e739b81f129fca91346342e9/packages/wrangler/src/sourcemap.ts#L92
...and have added a test to cover the simple {4}at case...
https://github.com/cloudflare/workers-sdk/blob/2362fb4d4a1ebd69e739b81f129fca91346342e9/fixtures/worker-app/tests/index.test.ts#L47
You're right it's still possible to trick this heuristic though. An alternative idea would be to override Error.prepareStackTrace inside the worker to actually perform source mapping. The thing that makes this tricky is that Error.prepareStackTrace functions need to be synchronous, and we can't really access the file system for source maps inside a worker synchronously right now. We could override this function to insert an invisible character that this regexp looked for to verify the log was actually a stack trace though. 🤔

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.

I think a special marker that is very unlikely to normally appar in the stack trace is quite a nice approach.

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.

Alternatively, we already know all the files passed to workerd, so we could also pass those files' source maps as bindings? The source maps could be pretty big though, which may impact startup time.

Copy link
Copy Markdown
Contributor Author

@mrbbot mrbbot Jan 8, 2024

Choose a reason for hiding this comment

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

Or we use a module fallback service to allow source maps to be imported as data modules? That wouldn't work for remote mode though... 🤔

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.

After speaking with @RamIdeas, I've updated the regexp to require at appears at the start of a line, optionally after whitespace and a single quote to handle the console.log({ stack: new Error("oopps").stack }) case.

@mrbbot mrbbot requested a review from RamIdeas January 10, 2024 11:14
@mrbbot mrbbot force-pushed the bcoll/source-mapped-strings-fix-call-site-detection branch from 7b922ac to e1b678c Compare January 10, 2024 11:36
Comment thread fixtures/worker-app/tests/index.test.ts
Match any colour in call site regexp and make log tests more accurate
@mrbbot mrbbot merged commit 2414716 into main Jan 10, 2024
@mrbbot mrbbot deleted the bcoll/source-mapped-strings-fix-call-site-detection branch January 10, 2024 13:24
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.

🐛 BUG: Logs with at get truncated to at [object Object]

4 participants