[FEATURE] Can't see cause or aggregate details for uncaught errors

[towerofnix]

Is there an existing issue for this?

• I have searched the existing issues

Have you read the CONTRIBUTING guide on posting issues, and CODE_OF_CONDUCT?

• yes I read the things

Description

To aid in debugging without necessitating futzing around with Chrome-style debugger statements, several infrastructural parts of my code wrap uncaught errors with supplemental details by creating errors with cause.

In practice we use a custom (and not-so-appropriately named) showAggregate function to display causes and aggregate errors in a nice, compact tree, for example below:

Node.js already tries to accommodate errors with cause and aggregate errors, too, as below:

Tap doesn't, though! All I get is details about the top-level error.

 FAIL  example.js 1 failed of 1 440ms
 ✖ Example > Oh dear in relation(fakeRelation)
    example.js                                                            
     3 t.test('Example', t => {                                           
     4   t.plan(1);                                                       
     5                                                                    
     6   throw new Error("Oh dear in relation(fakeRelation)", {           
     ━━━━━━━━━━┛                                                           
     7     cause: new Error("Oh my in relation(otherRelation)", {         
     8       cause: new Error("Oh chihuahua in relation(thirdRelation)", {
     9         cause: doSomething(),                                      
    10       }),                                                          
    tapCaught: testFunctionThrow
    Test.<anonymous> (example.js:6:9)

This is problematic for a few reasons, but the biggest is that — provided a simple cause chain, with no aggregate errors — I don't get any information about the bottom error. That's where the code actually failed (since it's an uncaught error). Of course, I hardly get any of the surrounding context I've added through errors with cause; I get the very top layer (since it's the top-level error object that tap considers), but that's it.

Of course, if any layers are aggregate errors, the overall structure really is important — it's not just supplemental context anymore, but describing possibly multiple errors that went wrong. For proper debugging, I need access to not just one of them (or the top layer) but the whole structure.

In practice I've worked around this by temporarily editing the test file, wrapping the line of code that eventually throws the error in debugging boilerplate:

try {
  t.equal(await doSomething(), someResult) // or any other assert
} catch (error) {
  (await import('#sugar')).showAggregate(error);
  throw error;
}

It works, but it's super inconvenient.

I can think of three ways to make this better on tap's part:

• Adapt tap's custom error reporting to handle errors with cause and aggregate errors. This is probably an involved process — I don't know how much tap is built on Node's own error reporting, but if its implementation is highly customized/hand-made, it could require a lot of work to approximate or take inspiration from Node's error handling.
• Have a setting/option which skips out of tap's custom error reporting and instead uses Node's default, unaltered. Since Node is based on V8, this means debugging support should improve at about the same pace that the language itself supports new kinds of errors. It's less nice than customized tap reporting, but would be pretty much bullet-proof.
• Allow and integrate custom uncaught error tracing. This would basically mean you can run a function which indicates, for all tests in the current file/suite/whatever, to use a function you provide to transform an error object into a string to print out. If the test raises an uncaught error, your function will get used, and the result will be displayed in place of tap's usual error tracing.

There's also a big question of what to do with the code context that tap provides, which is genuinely super helpful, but completely fails for errors-with-cause or aggregate errors — providing only code context for the top-level (and generally supplemental) error. But obviously displaying code context for every error in a chain would get very unwieldy. (You could argue that this is why tap only shows the code context for the top line in an error trace!)

On my part there are probably nicer ways to get around this, for example by handling uncaught errors in general (unhandledRejection) or by putting specific error-handling code into a helper function that wraps my tests. (I already have one for snapshot tests, but most of my unit tests just use the top-level t.test() function directly, so those would take some not-so-nice refactoring).

But I'm pretty sure workarounds I'd code on my end wouldn't be able to integrate nicely into tap's own error reporting; I basically only have the option to spit text into stdout/stderr and manually correlate it to the actual test that failed, in tap's summary, once all my tests have evaluated.

Although this gets in the way, it's not like tap is doing anything wrong here — it just doesn't specially report uncaught errors with cause and aggregate errors. So I've filed making any sorts of related improvements as a feature request! And I'd love to find out that actually there are ways to handle this better right now, too, but figured I'd summarize the situation anyway.

Example

Simple reproduction code with only a plain cause chain, no aggregate errors:

const t = require('tap');

t.test('Example', t => {
  t.plan(1);

  throw new Error("Oh dear in relation(fakeRelation)", {
    cause: new Error("Oh my in relation(otherRelation)", {
      cause: new Error("Oh chihuahua in relation(thirdRelation)", {
        cause: doSomething(),
      }),
    }),
  });
});

function doSomething() {
  return new TypeError("Division by zero, ma'am?");
}

Note that the code context for the bottom error is around return new TypeError("Division by zero, ma'am?");, but the context tap provides is around throw new Error("Oh dear in relation(fakeRelation)", {. tap also doesn't give me any way to figure out the trace or even message for that bottom-level error, nor any of the errors in-between.

Edit: Yay, issue #1000! 🥳

[towerofnix]

I'm noting that this is probably related to tapjs/stack-utils#61, which has a whole ton of discussion about cause formatting in general. It's probably the place to go to discuss specifics on that mark! (See also jestjs/jest#11935.) But I'm keeping this issue around as tracking for other ways to integrate custom or Node.js-built-in error tracing for tap itself.

[towerofnix]

I've done some digging in the source to try to get more familiar with basically how tap works and where changes would be needed, and the give-away (after digging in the reporter code) is that the reporter is most certainly parsing the tap results, with no extra "magic" after the fact to generate new information, so the core test runner is responsible (which generates tap output) is responsible for stack tracing.

Specifically, the function we've gotta look at is TestBase.threw. Stack tracing is handled here, essentially joining (one for each line) the results of parseStack. Internal details are super interesting (@tapjs/stack is cool!) but not relevant for this issue, since they're lower level than processing a thrown error object itself.

I'm not sure what the ideal solution would be for embedding information that isn't a plain stack trace into the results here. I guess the good thing is that YAML Diagnostic blocks aren't standardized? So we can choose to add completely new information here, without altering the existing expected contents of stack.

Personally, seeing as it's a structured YAML object anyway, I think we should basically allow recursive details here, exactly the same as the current flat shape is reported, just without tapCaught (since I'm assuming that's only relevant to the top-level error). That means including stack, at, and source for every nested error, as well as cause (single item recursive) and errors (array recursive) when applicable. (Oh, and message for nested errors, too!) It'd be up to the reporter to decide what to do with that data — including not displaying it at all, for example.

Of course, all this means that as-is, cause and errors information is just completely discarded — it's not part of the TAP output (i.e. YAML diagnostic block) and so unavailable for processing by reporters.

tap's error reporting for result details is handled by ResultDetails, and expressly parses the diagnostic object to provide source and stack information (respectively Source and Stack). If we add a new key on the diagnostic results - rather than messing with the existing stack - then we'd need to add a new element for handling recursion, displaying message and at information for sure, and maybe a compressed/context-sensitive version of stack (ala Node.js) and maaaaaaybe source if an option is set, too.

Actually, if stack is context-sensitive, we need the top-level stack to be similarly context-sensitive. We could accomplish that in two ways:

1. By providing the entire diagnostic structure to Stack and a pointer to the current entry in that structure, allowing Stack to infer which lines are duplicates and should be hidden for conciseness
2. By doing that processing ourselves and just providing a concise stack string to Stack from the get-go, and making the recursive component responsible not just for nested stacks, but the top-level one too (since it'll contain the conciseness logic)

I'm definitely inclined more towards the second approach, because it keeps Stack logic simple, isolates recursive or recursion-sensitive logic into a dedicated component, and avoids "special" behavior for trace reporting on the top-level error, since that's just a case where the root node is also the (only) leaf node.

I might give implementing all of this a shot, since implementation-wise it doesn't sound dreadfully complicated (recursion in TypeScript isn't that hard, right!?), and would be a fun project to get familiar with tap's internals — even if any of this is out of scope for tap or some totally different approach is selected. But no guarantees I'll get anywhere with my code! 👾

[towerofnix]

We did it!

We still need to do test cases, and probably some extra-detail adjustments (it doesn't display the error type, nor any otherDiags-style details; stack beneath heading should possibly also be indented to match Node.js...) — but the essential implementation is all here. See our detailed commit messages if so desired. (We'll try to make a PR happen sometime soon.)

Also some checking against Node.js to make sure everything is, in fact, working precisely as intended (that's where we're pulling the essential appearance, "42 lines matching cause trace" messaging, and a chunk of implementation code from).

[isaacs]

I'm starting to use Error.cause pretty extensively now, and moving everything away from throw Object.assign(new Error(msg), { some: 'stuff' }) to the more idiomatic throw new Error(msg, { cause: { some: 'stuff' }}) so not having this is annoying for me, too. I'm going to tackle this shortly, as part of tap v19.

I'd like to get this fully integrated throughout the stack of things that handle Error objects, and use cause internally in a bunch of places to track things that I'm currently handling with custom properties. For the output, I'm thinking it might be nice to have every cause/aggregate attached to an Error displayed indented, so you'd have the pretty source of the callsite, then indented, next error with callsite, etc. That could get super noisy for long chains, so an alternative would be to just give the full treatment to the top and bottom of the chain (ie, the Error that was raised, and the ultimate cause), with each Error along the way just displayed with its message and throw location as a string or something. So it'd be something like:

X Example > Oh dear (in relation fakeRelation)
  example.ts
  123 some
  124 source code
     ------^
  125 context
  tapCaught: testFunctionThrow
  some-file.ts:124:15
  other-file.ts:342:1234
  Cause: some elided intermediate cause (path/to/file.ts:43:32)
  Cause: another intermediate cause (path/to/file.ts:43:32)
  Cause:
    if: the
      - cause
      - is not
    an:
      - Error object
      - just show yaml
  Cause: Oh my (in relation otherRelation)
    something-else.ts
    12 "hello"
    13 world.asdfasdfasdf()
          ---^
    14 blah

With the top and bottom of the chain visually brighter/bolder, since that's what you want your attention drawn to.

Sometimes (when it's not an Error) the cause might have some very "big" objects on it, so it might be good to trim that down somehow. It might have a Response object from an http request, a child_process that failed, anything else imaginable.

[towerofnix]

Thanks for your attention on this and keeping up with error causes in general! They're an awesome feature I love to see getting adopted more.

Just a nit about your example, to make sure it's getting communicated properly:

Cause:
  if: the
  cause: is not
  an:
    - Error object
    - just show yaml

I'm noting that the non-Error object you're displaying here itself has a cause, but the line beneath is a different cause. Would this actually display something more like this?

Cause:
  if: the
  an:
    - Error object
    - just show yaml
Cause: is not

# or even:
Cause:
  if: the
  cause: <see below>
  an:
    - Error object
    - just show yaml
Cause: is not

If we don't do this, then a non-Error cause would always (if present) mark the bottom of the chain.

If we do support it, I think that makes for better expressiveness, but I'm noting it's sort of a new/benign interpretation of the spec (InstallErrorCause etc), which doesn't mention that an error's cause has to have literally any particular value/shape. (So, doesn't provide meaning to that value, etc, though clearly browsers choose to interpret it by showing a chain of errors, for example.)

IMO cause chaining is a fairly popular use of error causes, so since causes support any value (not just errors), we might want to say "any error.cause that itself has a cause property represents an intermediate cause in a chain".

That could get super noisy for long chains, so an alternative would be to just give the full treatment to the top and bottom of the chain (ie, the Error that was raised, and the ultimate cause), with each Error along the way just displayed with its message and throw location as a string or something.

Generally I'm a huge fan of this! Just, you might want to bring some aggregate errors into your examples, too (you've only got a non-aggregate cause chain above). Aggregate errors always represent multiple errors (and nothing more than multiple errors), so the only semantic way to show them is to display those errors. E.g, if the cause of an error is an aggregate error, then the cause is multiple errors, so we have to display the multiple errors.

But I agree that displaying full stack traces can get extremely noisy, and that's exactly why we wrote a custom showAggregate function for our library (so-named before error.cause was a thing, but it supports that too). See the top screenshot in our first post.

A couple of thoughts related to verbosity here:

• Generally, reducing potentially meaningful verbosity without giving the user any way at all to gain access to that verbosity is probably a bad idea.
• Environment variables aren't nice — for example TAP_TRACE_VERBOSE=1 npm run test — but they are easy to use.
• We could have the filtering of causes be performed by node-tap reporter, rather than being something hard-written into the tap runner results file. So, the output file would always be full-verbosity.
  • This is nice for always storing all the results in the output of any test run...
  • But not so nice for just browsing those results files yourself, in a text editor. Well, it could be nice in some cases, but you're stuck without any option to reduce the verbosity — because the reduction is handled by the reporter.
  • Being stuck with greater verbosity rather than less verbosity is a lesser Evil™, but in practice it's just as (if not more) annoying, most times!

My suggestion would be to use an environment variable to increase the default filtered verbosity, which also affects the generated tap results file (because re-running a test isn't that inconvenient), but maybe you have a better idea!

Sometimes (when it's not an Error) the cause might have some very "big" objects on it, so it might be good to trim that down somehow. It might have a Response object from an http request, a child_process that failed, anything else imaginable.

Yeah, good point. Does node-tap handle the string/yaml-ification of arbitrary objects anywhere else (outside of diffs) yet?

TAP_TRACE_VERBOSE=normal, loud, louder, ha, ha. (Maybe better names would be TAP_NESTED_TRACE=verbose - for traces in both cause and aggregate - and TAP_CAUSE_DETAILS=everything - for showing all properties on non-Error causes.)

What would a less verbose arbitrary object look like, though? If we'd like to represent a "useful" subset of the properties, that depends on knowledge based on the constructor, which is totally out of scope for node-tap's internals and project work IMO. But probably a problem that's already being tackled by other people, e.g. whoever makes objects in chrome's devtools useful? Maybe there's a library for this?

If we don't make any guesses about which of the object's properties are useful, we could display:

• Just its constructor, no properties at all
• Just the result of Node.js util.inspect, maybe with a low depth value (This is debatably reliable for getting anything "useful" and may accidentally be a lot more verbose than we want; however, classes can implement custom [util.inspect] functions, which is exactly the interface util.inspect() exists to use. So it gets ecosystem brownie points!)
• Just its constructor and keys, no values
• Just its constructor and own keys with values (This should handle most cases while not being loud about stuff inherited directly from objects' prototypes, though that's still more information than necessarily useful? Also this might just be exactly what util.inspect does anyway, in which case why not just use that for ecosystem points?)

Looking forward to see where your experience with causes goes in general! I think tooling which not just supports but is itself built around causes is still pretty rare, so we're super interested to see how it develops.

[isaacs]

I'm noting that the non-Error object you're displaying here itself has a cause, but the line beneath is a different cause. Would this actually display something more like this?

Haha, yes, my dummy text should not have included a cause key lol. Updated.

[isaacs]

Looking forward to see where your experience with causes goes in general! I think tooling which not just supports but is itself built around causes is still pretty rare, so we're super interested to see how it develops.

It's been around a while now, but it's still a somewhat new feature, as far as the language goes. It just arrived in Node 16.9, so it's only pretty recently that all non-Error.cause-supporting node versions have fallen out of the common support set. It'll probably for some time still be more common to see throw Object.assign(new Error(..), { code: 'EWHATEVER' }).

With any large program that does a lot of fs and network stuff, handles user input that must be validated, calculates things that might not be resolveable, etc, you end up needing to have some code in a single place that reports errors usefully to the user, but also there's a need to keep the separation of concerns. This tension in npm was resolved with a hodgepodge of duck-typing and some convention around known Error.code strings, but it was pretty inconsistent and the code that did it was some of npm's most tangled internal spaghetti.

With vlt, we're trying to make this a bit more orderly. We're using an error('some message', { some: 'cause' }) method which defines a ErrorCause type so that we always use the fields consistently, and so far at least, it's been super helpful. We don't have the error logging parts done, so it'll likely change a bit prior to being released due to applying that pressure, but I think you might find it useful. The pattern is that we always decorate an error using the cause if we have some decoration to add. So either that could be error(msg, originalError) or error(msg, { some: 'details' }) or combining them into error(msgs, { some: 'details', cause: originalError }). When reporting, the cause can be either another error, or an object with some known fields, and the let c=er; while (c.cause) c = c.cause; c will always give you the details about the initial thing that failed.

[towerofnix]

That's awesome. I love the comparison between how things have historically been handled in Node.js (A for effort, but...) and the new capabilities that such a simple idea, "a cause that can be anything" (and alongside that, cause chaining) can help bring.

We've been seeing really similar semantic benefits in hsmusic too. We've exclusively set error causes to be Error objects, but they're liberally chained as we add higher-level context in details. They're helpful for runtime validation reporting in general, thanks to aggregate errors and some useful internal composition. We set symbols on cause errors to indicate certain semantic cues for the reporter (showAggregate), such as to indicate that this layer is "translucent" and should only be displayed if you're actually debugging. And we use subclasses of Error to readily construct useful messages and to expose useful values as data, mostly for detection in test cases, although it'd also be effective for more specialized custom reporting (showAggregate is pretty generic).

It's been a couple years so I honestly don't remember how we did validation before, but it was certainly a lot less flexible and informative than today. Since hsmusic is fundamentally a "convert a static data repository into a static wiki website (showing loads of relationships, presentational details, general info, etc)" project, data validation is one of its most important duties. Error causes and aggregate errors have gone a long, long way to make the results of that validation explorable, traceable, and useful!

[isaacs]

import t from 'tap'
const e = new Error('hello', {
  cause: new Error('xyz', {
    cause: {
      some: 'stuff',
      cause: new Error('deeper', {
        cause: true,
      }),
    },
  }),
})
t.test('parent', t => {
  t.test('child', t => {
    t.error(e)
    t.end()
  })
  t.end()
})

Here's what I got so far, still pretty rough and a bit noisier than I'd like: http://167.99.100.141/tap-cause-output.html

Indentation makes it kind of crazy when you have a lot of things, and I feel like just adding the separator makes it clear that it's a chain of events. I'm not doing anything now to elide out the intermediate causes, but I think you're right, that they should ideally be preserved as verbose as you'd likely ever want in the raw TAP output, and then elided down in the reporter, possibly based on a config. Then you could always tap replay --show-cause=verbose or something to see all the intermediate error sites.

[towerofnix]

This is very stylish! I see that the bold line has the text "Cause:" and then the message, for error-based causes. I love the separator and think it's a great fit if cause entries will frequently be more than one line long—indentation works for us because of how hierarchically structured it is (lots of aggregate errors) and how few extra details we include (not even the top line of traceback in most instances). Just using a separator line is sleek and simple at conveying a chain.

When aggregates are output, I think indentation is necessary as a baseline, since that's a tree structure - otherwise you'd be looking at something like XML without indentation, which is impossible to navigate impossible to have a good time navigating. But cause chains are basically a linked list structure, and lists are more naturally represented flat. Trees are usually represented with indentation, so not using indentation for lists/chains makes for a better visual cue, and should make for easier navigation of complex error structures.

Do you think the message: xyz line is necessary? You are already special-casing cause to be excluded from the summary, because you're representing it in a more "first-class" way (i.e. as the stuff after the following separator line). You're similarly treating message in a "first-class" way (putting it in brightface as part of the "Cause:" header).

This isn't to say that other properties should be filtered out, necessarily (e.g. a subclass of Error that provides other useful keys/values), but if you're specially showing "cause" and skipping that in the property list, you can probably do the same for "message" and get a more concise output.

Also, the bottom entry - visually the last in the chain - has a cause. It's a cause which isn't an Error, sure, but we've already seen that those are displayed within the chain just like Errors are (some: stuff above). It feels confusing to me that the visual last item isn't really the last thing in the chain, it's the second to last. I would probably show something like this instead:

    ...
    ---------------
    Cause: deeper
    ec.js                                
     3   cause: new Error('xyz', {       
     4     cause: {                      
     5       some: 'stuff',              
     6       cause: new Error('deeper', {
     ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ━ ┛                     
     7         cause: true,              
     8       }),                         
     9     },                            
    10   }),                             
    ec.js:6:14
    ---------------
    Cause: true
    ---------------

Asserts:  0 pass  1 fail  1 of 1 complete
Suites:   0 pass  1 fail  1 of 1 complete

I get why the final cause: true is shown as, well, just cause: true — it's not an object so it couldn't possibly have its own cause, not even its own message, so why treat it as the same level of meaning as other links in the chain? But IMO even if it's destined to be the final link, it's still semantically representing the same kind of meaning as any other cause, so it should be represented with the same sort of appearance as the other links.

I'm also noting some confusion over the ordering of lines. As far as I can tell, based on these examples:

    ...
    ---------------
    Cause: xyz
    ec.js                                
    <visual code context>
    message: xyz
    ec.js:3:10
    ---------------
    Cause
    some: stuff
    ---------------
    Cause: deeper
    ec.js                                
    <visual code context>
    message: deeper
    ec.js:6:14
    cause: true
    ---------------

The order appears to be:

1. Header line, "Cause: ${message}" or just "Cause" if no message
2. Visual code context lines, which have the filename at the top
3. Properties which are not specially skipped, e.g. some: stuff or message: xyz
4. Top traceback line
5. The cause property line, if that cause is the last in the chain (and is not an Error?)

To me the practical use for showing both ec.js and ec.js:3:10 in the same entry is only that it correlates more closely with the top-level reported error. This is admittedly a nice-to-have (consistency is good) and it's convenient when space isn't a concern (because you're only displaying one error), but if you're going for a more compact form, you could choose to display only the ec.js:3:10line, either at top (replacingec.js`) or mostly bottom (where it is now).

Like I mentioned above, I think you can drop the message: xyz line and make the final cause: true into a special case. Combining everything gets these results:

    ...
    ---------------
    Cause: xyz
    ec.js:3:10
    <visual code context>
    ---------------
    Cause
    some: stuff
    ---------------
    Cause: deeper
    ec.js:6:14
    <visual code context>
    ---------------
    Cause: true
    ---------------

Order being:

1. Header line, either "Cause: ${message}" or "Cause: ${value}" or just "Cause"
2. Visual code context lines, which have the top traceback line (including filename) at the top
3. Properties which are not specially skipped, e.g. some: stuff

With the code context, too, for a more direct comparison (I am a <details>, click me!)

    ...
    ---------------
    Cause: xyz
    ec.js:3:10
     1 import t from 'tap'               
     2 const e = new Error('hello', {    
     3   cause: new Error('xyz', {       
     ━━━━━━━━━━━┛                         
     4     cause: {                      
     5       some: 'stuff',              
     6       cause: new Error('deeper', {
     7         cause: true,              
    ---------------
    Cause
    some: stuff
    ---------------
    Cause: deeper
    ec.js:6:14
     3   cause: new Error('xyz', {       
     4     cause: {                      
     5       some: 'stuff',              
     6       cause: new Error('deeper', {
     ━━━━━━━━━━━━━━━┛                     
     7         cause: true,              
     8       }),                         
     9     },                            
    10   }),                             
    ---------------
    Cause: true
    ---------------

Simpler to reason about and more compact too — hopefully, easier to parse and mentally process!

Also note that I didn't suggest dropping the code context. I don't want to rule that out or anything, but I do want to give it as much of a chance as possible, because I like it, and because the other ways of compactness are more "free". We aren't reducing information, we're just simplifying it to a more uniform appearance (proper chain entry instead of cause: true) and dropping redundant information (filename only once, no message: xyz). None of that comes close to how many lines you'd actually save by just dropping all the code context, but I think that code context is valuable! And that other kinds of simplification probably make a greater aid. (If we wanted this in as few lines as possible, we could just JSON.stringify it lol.)

[isaacs]

The reason why it's showing ec.js:<line>:<number> as just a single line is because the stack only has a single entry.

It's exceedingly rare, outside of contrived tests, to create an Error.cause right inline. Usually, it comes from some other part of the program, and having the full stack can be essential. It's already stripping out node internal frames and any frames from within tap itself (unless you're in the tap project, which I am in this case), so I'm not too worried about it.

I cleaned it up a bit in main having put it through some tests, but I'm going to roll with this overly verbose option as a default for now, and then probably make the verbosity configurable once it starts to annoy me 😅

[towerofnix]

That makes sense! Sounds good. I still think dropping message: xyz (because it's in the header) is OK if you're also dropping cause (because it's the next item in the chain), but a little extra verbosity there isn't going to be a deal breaker for us LOL.

[isaacs]

Landed and published in v19

[towerofnix]

Thank you @isaacs! 🙏 🎉