Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Map error positions against the original source (sourcemapping) #848

Merged
merged 34 commits into from
Jan 13, 2025

Conversation

josephjclark
Copy link
Collaborator

@josephjclark josephjclark commented Dec 19, 2024

Short Description

This PR uses sourcemapping to report accurate positions on error messages

It also adds some general improvements to error messages, for clarity, brevity and accuracy.

Fixes #230

Implementation Details

This is not a particularly focused bit of work, as it impacts lots of corners of code - including some gnarly bits.

The basic strategy is this:

  • The compiler now returns compiled code AND a source map (produced by recast). The sourcemap is then grafted onto the ExecutionPlan for each step, and used to map positions when errors are thrown.
  • Error handling more or less works like it used to, except that we catch adaptor errors directly in expression.ts now, rather than working them out later. This is so that we can map positions on top-level operations.
  • The actual mapping logic is in runtime/src/util/sourcemap-errors.ts. The sourcemap library does most of this for us - so mostly this module just updates metadata on the error object and parses the callstack to map positions there.
  • We now append stack traces to errors, but we only include frames from VM code or adaptor code, and we modify the reported paths to be relative to the adaptor, rather than the full system path. I need more data to make a judgement on how well this is working.
  • The final error output has been cleaned up a bit form production - see Runtime: attempt to clean up error output #852 for details and isolated changes for that.

API changes from the compiler have a big knock-on affect, resulting in a large diff.

Note that for top-level operations, this got a bit difficult because the stack trace is entirely in runtime code, not vm code. See #851 for details. Basically there's no meaningful position we can report for these cases - so what we do is work out which operation is responsible for the error, and say something like "error throw by the fn() operation on line 8".

Changes:

  • map error positions and stack traces against the original job source
  • Generate a text string representing the source line and mark where the error occurred
  • Work out how and where to log this. Probably in the runtime's error reporter, which I don't really like. Maybe this is a good time to refactor this?
  • Make sure positions are logged appropriately for all the right error types.
  • Get stacktrace showing the callstack within the VM, but not the runtime. I've had a go at this but it doesn't seem to work as I expect. I might branch this out as a new issue Runtime: attempt to clean up error output #852
  • Figure out errors coming from top-level operations, which don't have a vm stack Sourcemapping adaptor errors #851
  • Graft sourcemaps to the Workflow
  • Fix the CLI to use new compiler ouputs
  • Fix the worker to use new compiler outputs
  • Look closely at worker outputs and make sure they're OK
  • Test from the CLI and worker and show outputs here
  • Refine serialized error objects (less noise, maybe don't log json) Runtime: attempt to clean up error output #852
  • Fix an issue in the logger where logger.print() wasn't reporting to the Worker because it didn't have a timestamp

QA Notes

I will be asking for help testing the CLI and the worker. There are a lot of changes here

AI Usage

Please disclose how you've used AI in this work (it's cool, we just want to know!):

  • Code generation (copilot but not intellisense)
  • Learning or fact checking
  • Strategy / design
  • Optimisation / refactoring
  • Translation / spellchecking / doc gen
  • Other
  • I have not used AI

You can read more details in our Responsible AI Policy

@doc-han doc-han self-requested a review December 21, 2024 13:49
@josephjclark

This comment was marked as outdated.

@josephjclark
Copy link
Collaborator Author

It might be a distraction but I want to go back and look at the example in #582

It still doesn't serialize well (in prod or this branch), and just shows the error as [object Object]

But when I look at the stack trace, there's no stack in the job code, so we can't extract any error information.

I think it's something to do with the axios callback - the error occurs in an async callstack, hence there's nothing useful in the stack to report. Is there anything we can everdo about this?

Btw to repro the error (and get a real error message out), do this:

import { CookieJar } from 'tough-cookie';

const cookiejar = new CookieJar();
cookiejar.getCookies({});

This goes away in later http versions, but I'm still worried about / interested in this async error case.

@josephjclark

This comment was marked as resolved.

@josephjclark

This comment was marked as resolved.

* runtime: refine error output

* tests: added error logging tests

* compiler: append positional information to top level operations

* compiler: write the operations map to the souce map

* lexicon: add typings for extended source map

* lexicon: tweak sourcemap types

* package lock

* runtime: updat error handling to handle adaptor errors with source mapping

* runtime: better handling of nested adaptor errors

probably

* runtime: update tests

* cli: types

* tidy

* runtime: better handling of nested errors
* compiler: append positional information to top level operations

* compiler: write the operations map to the souce map

* lexicon: add typings for extended source map

* lexicon: tweak sourcemap types

* package lock

* runtime: updat error handling to handle adaptor errors with source mapping

* runtime: better handling of nested adaptor errors

probably

* runtime: update tests

* cli: types

* tidy

* runtime: better handling of nested errors

* runtime: improvements to reporting of errors

* changeset

* runtime: improve error details

* runtime: better frame detection for adaptor errors

* runtime: fix tests

* tests: update output logs
@josephjclark josephjclark marked this pull request as ready for review January 4, 2025 16:06
@josephjclark
Copy link
Collaborator Author

Hey @doc-han - are you up for a bit of a review over the runtime changes next week?

I'll be putting this out to the team for QA in the CLI and Worker, I want to test this really thoroughly. But I'd welcome your feedback on the solution (if you can figure it out - it's quite a messy PR tbh!)

@josephjclark
Copy link
Collaborator Author

R/T TypeError: state.data is not a function
    at vm:module(0):3:9
    @openfn/language-common_2.1.1/dist/index.cjs:333:12
R/T Error occurred at: New job
R/T 3:   state.data()
R/T            ^     

Maybe on "error occurred at" we should say error occurred at ${step.name} (line N column N). That also makes the following source line a bit clearer

Make sure dist is properly cleaned each time
@josephjclark
Copy link
Collaborator Author

TODO - probably as a new issue. Pass a custom Error class into job code which generates a mapped stack trace. When job code writes throw new Error('blah') we can then report a position. Because right now, no positional information is attached to errors directly thrown by job code

@josephjclark
Copy link
Collaborator Author

Hey @doc-han I'm targeting a release of this on Monday next week. A review from you isn't essential but it is appreciated - if you'd like to review it, it needs to be in the next couple of days please :)

@doc-han
Copy link
Collaborator

doc-han commented Jan 10, 2025

Hey @doc-han I'm targeting a release of this on Monday next week. A review from you isn't essential but it is appreciated - if you'd like to review it, it needs to be in the next couple of days please :)

Alright. I'll commence with review today then.

@josephjclark
Copy link
Collaborator Author

@doc-han I think a consistently failing integration test has crept in, bit weird. I'll investigate it.

Copy link
Collaborator

@doc-han doc-han left a comment

Choose a reason for hiding this comment

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

Awesome!

I was thinking we could get a path to source code for a job running via a file.
eg.
Instead of at vm:module(0): 5:8 we get at /jobs/get-data.js: 5:8 so that user can just click to file but then I started thinking of lightning.

@doc-han
Copy link
Collaborator

doc-han commented Jan 11, 2025

The currently failing tests are right. We can't assume that a compiled code will always error at line 333:12.
Also, the adaptor version.

@josephjclark
Copy link
Collaborator Author

I was thinking we could get a path to source code for a job running via a file.

yeah, I'm pretty sure when we create the node vm that we can control the name of the vm, so instead of vm:module we can print fetch-patients. I would use the step NAME instead of the path (the CLI will default a name from the path) - I think we always have one.

I haven't found time to look into it properly. We can spin out a new issue to implement later - I'm sure it's not a big deal. We just to think about, in regard to THIS PR, making these custom vm frames easy to detect in stack traces (so maybe we prefix each name with vm:, ie, vm:fetch-patients

@josephjclark josephjclark changed the title Sourcemapping Map errors positions against the original source (sourcemappig) Jan 13, 2025
@josephjclark josephjclark changed the title Map errors positions against the original source (sourcemappig) Map errors positions against the original source (sourcemapping) Jan 13, 2025
@josephjclark josephjclark merged commit c9afba0 into main Jan 13, 2025
9 checks passed
@josephjclark josephjclark deleted the sourcemapping branch January 13, 2025 11:17
@josephjclark josephjclark changed the title Map errors positions against the original source (sourcemapping) Map error positions against the original source (sourcemapping) Jan 13, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: Done
Development

Successfully merging this pull request may close these issues.

Runtime: Report error positions against a sourcemap
2 participants