Exception from stream can print with no name/other information on web

[alanknight-wk]

• Dart SDK Version (dart --version) Dart SDK version: 2.13.4 (stable) (Wed Jun 23 13:08:41 2021 +0200) on "macos_x64" DDC

• Whether you are using Windows, MacOSX, or Linux (if applicable) Mac

• Whether you are using Chrome, Safari, Firefox, Edge (if applicable) Chrome

In our application we have code listening on a stream with code like _eventStream.where(stuff).timeout(timeout) We were previously using Dart 2.7.2, and there the exception on a timeout printed useful information. Upgrading to 2.13.4, it would simply print "Uncaught" with no string. The exception had a message, but it was not used.

I have trouble creating a simple repro for this, but the essence of the issue seems to be that

• on a timeout, the stream calls addError with a null stack trace.
• This comes through to AsyncException.defaultStackTrace, which creates a StringStackTrace('') to populate it.
• Then in rootUncaughtErrorHandler we get the following in JS

  P._rootHandleUncaughtError_closure.prototype = {
    call$0: function() {
      var error = H.wrapException(this.error);
      error.stack = J.toString$0$(this.stackTrace);
      throw error;
    },

so it overwrites the stack of the JS error with a stringified version of the stack trace, which is an empty string. Then, although the toString()of the JS Error has the original exception's message field in it, what actually prints in the devtools console is just Uncaught.

The AsyncError defaultStackTrace seems to be new in 2.13, but it seems like there's an interaction between this and the way the exception gets logged.

This can be reasonably worked around by either calling it as

   .timeout(timeout, onTimeout: (sink) {
      var exception = MessageTimeout(message);
      sink.addError(timeout, StackTrace.fromString(exception.toString()));
  })

or else by awaiting the answer inside a try/catch and throwing (not re-throwing) the exception. That makes it pick up the message, presumably because it has a valid stack trace. And as a bonus, the stack trace is more useful, since it's one from the call tree that was doing the awaiting, not (as much of) an async trace coming out of nowhere.

[alanknight-wk]

Not area-vm, this is with DDC (presumably also dart2js) on the web.

[sigmundch]

This appears to me more likely to be an odd side-effect of how the async library was migrated to null safety. Before we allowed null stack traces and at the time we'd call _rethrow we'd create a new exception with a stack if the stack was missing. With null safety that logic is now gone, so there is no safety net if a stack is missing (which now appears as empty as opposed to null)

At the same time, further up in the async library we still use null for stack traces in some parts of the stream implementation, so maybe we need to attach a stack earlier? @lrhn @natebosch what are your thoughts?

[lrhn]

We don't use null for stack traces anywhere internally in the implementation, only at the API boundary where they've always been optional. The Completer.addError call itself will immediately replace null with StackTrace.empty and store that. (It'll check the error object for a .stackTrace first, but since the error object was just created and never thrown, it won't have one).

We considered using StackTrace.current to replace absent stack traces, but that's a significant overhead for code which doesn't actually need the stack trace for anything - which it presumably didn't since the stack trace was omitted to begin with.

Maybe we should just check for the empty stack trace and not overwrite anything with it?

  if (StackTrace.emtpy != this.stackTrace) {
     error.stack = J.toString$0$(this.stackTrace);
  }

[sigmundch]

@lrhn - that's an interesting suggestion, but I worry this may also be an issue in other runtimes and not just on the web.

Could it be handled by rootHandleUncaughtError?

That is, before null safety we used to do so there:

void _rootHandleUncaughtError(
    Zone self, ZoneDelegate parent, Zone zone, error, StackTrace stackTrace) {
  if (error == null) {
    error = ArgumentError.notNull("error");
    stackTrace = StackTrace.current;
  }
  _schedulePriorityAsyncCallback(() {
    if (stackTrace == null) throw error;
    _rethrow(error, stackTrace);
  });
}

Today it looks like:

void _rootHandleUncaughtError(Zone? self, ZoneDelegate? parent, Zone zone,
    Object error, StackTrace stackTrace) {
  _rootHandleError(error, stackTrace);
}

void _rootHandleError(Object error, StackTrace stackTrace) {
  _schedulePriorityAsyncCallback(() {
    _rethrow(error, stackTrace);
  });
}

What if we we change it to:

void _rootHandleError(Object error, StackTrace stackTrace) {
  _schedulePriorityAsyncCallback(() {
    if (StackTrace.empty == stackTrace) throw error; 
    _rethrow(error, stackTrace);
  });
}

Thoughts?

[lrhn]

We can add if (identical(StackTrace.empty, stackTrace)) throw error; to the root handler. It will introduce a new, unrelated, stack trace, which most likely isn't very useful.

If the root uncaught async error handler gets an empty stack trace, then it can be deeply nested inside something, but most likely that's all platform code. (You have to be using a sync completer/controller to introduce an uncaught error with anything useful on the stack, and that should be rare in user code. Most likely the stack is just going to be "eventLoop > microtaskLoop > propagateToListeners > rootUncaughtErrorHandler" every time).

[natebosch]

Was the old behavior of if (StackTrace.empty == stackTrace) throw error; useful, or is it mostly an aesthetic change? It seems like if (identical(StackTrace.empty, stackTrace)) throw error; is no less useful right? Are the downsides to that change if we preferred having the non-meaningful but non-empty stack before?

[lrhn]

The old code of

    if (stackTrace == null) throw error;
    _rethrow(error, stackTrace);

was written like that only because _rethrow required a stack trace, and there was no stack trace available, so we couldn't call it. Doing throw error; was the only thing left to do, not necessarily because it was desirable by itself. Doubly so because it might set the Error.stackTrace on an error that wasn't actually thrown anywhere in the user program.

The throw successfully introduced a stack trace, so it "worked". Even if the stack trace was entirely unrelated to the thrown object - it happens in the callback of schedulePriorityAsyncCallback, so the stack is definitely going to be boiler-plate event handling only, then that one private system callback closure. Not even remote useful or related to anything.

I think _rethrow(error, stackTrace ?? StackTrace.current) would have been be better, but zone code (Dart 1.0) predates StackTrace.current (introduced in Dart 1.14), so that's probably why it wasn't used originally, and no-one came back and looked afterwards, because it "worked".

Using StackTrace.empty is also fine, there really is no useful stack-trace information. None, whatsoever. Anything we print is spurious noise.

[natebosch]

I do think it could be useful to guard writing error.stack and never write the empty stack trace - in some cases that stack field would have a useful trace.

I don't think we do want to go back to having a throw error to get a trace - a misleading trace seems strictly less useful to me than no trace at all.

The most troubling piece IMO is the missing exception message more than the missing stack. @sigmundch - do we know why that is happening?

[lrhn]

Good idea. If we have an empty stack trace (or evan a null stack trace in unsound null-safe mode, which probably won't happen, but users can call zone.handleUncaughtError directly from non-null-safe code), we may want to check whether error is an Error and use its Error.stackTrace instead, if that is set. If that also has no stack trace, printing no stack trace still seems like the most correct behavior.

I'm not seeing the "no message printed" in DartPad. For:

void main(){
  var s = Stream.multi((c) {c.add(1);});
  print("waiting");
  s.timeout(Duration(seconds: 1)).forEach(print);
}

it prints

Uncaught Error: TimeoutException after 0:00:01.000000: No stream event

There might be more going on. Are there any custom error handling zones involved?

[alanknight-wk]

There is a little bit of zone error handling, but from what I can see the only side effect is to log the exceptions. I did find it difficult to reproduce the problem in a small example. And unfortunately it's not possible to test against a current SDK, as it requires major upgrades to be able to run there.

As Nate said above, the absence of any error message is more of an issue than a missing (possibly unhelpful) stack trace.

[sigmundch]

Thanks for the additional context and details. Nothing immediate comes to mind to justify the message being dropped, so I'm not sure there is much for us to dig into yet.

@alanknight-wk - would it be any easier to try to reduce the problem of the dropped message if we ignore all the aspects related to the stack trace at the moment? Some questions that come to mind:

• is the same behavior reproducing in dart2js, not just DDC?
• it is possible to disable/remove the current zone handling? If so, what behavior do you see?

[alanknight-wk]

Actually, it may be only in dartj2s. But it's not trivial to run exactly the same code in DDC because reasons (this occurs as part of running separately compiled Dart programs communicating via DOM events, and only one can be run in DDC at once). I didn't see it when trying to run the same thing in DDC, but I may have done something wrong.

And while there's some Zone code in that package, it doesn't look like it's being called at all in the path to the failure. And I can trap on the uncaught exception in devtools, and it's thrown and immediately goes into rootHandleUncaughtError.