Incorrect Line Numbers in Source-mapped Stack Traces #27600

todbachman-wf · 2016-10-17T19:53:24Z

When Chrome applies source maps generated by dart2js to a stack trace I am finding the line numbers can be off by at least one or two lines. The correct line number can precede or succeed the line number reported by Chrome. This makes interpretation of the stack traces generated in a production application more difficult to interpret.

Here is a simple app that demonstrates the problem. It renders a button that throws an exception when clicked. In this case the line number reported by Chrome precedes the line the exception is actually thrown on by one.

pubspec.yaml:

name: example

dependencies:
  browser: ">=0.10.0 <0.11.0"

transformers:
- $dart2js:
    sourceMaps: true

web\index.html:

<html>
<head><title>Demo</title></head>
<body>
    <script type="application/dart" src="main.dart"></script>
    <script src="/packages/browser/dart.js"></script>
</body>
</html>

web\main.dart:

import 'dart:html';

void main() {
  addElements();
}

void addElements() {
  querySelector('body')
    ..append(new ButtonElement()
      ..text = 'Throw Exception'
      ..onClick.listen(_handleExceptionButton));
}

void _handleExceptionButton(_) {   // <--- Line 14
  throw new IntegerDivisionByZeroException();   // <--- Expected location
}

Steps to generate stack trace in Chrome:

Open Chrome
Open the dev tools
Edit dev tools settings and ensure Enable JavaScript source maps is checked
pub serve
Navigate to localhost:8080 in Chrome
Click the button labeled Throw Exception
Switch to the dev tools Console
You should see an uncaught exception that looks like:

I would expect the stack trace in Chrome to report line 15 rather than 14. In this case the line number is only off by one, but in other circumstances I've observed it to be off by three.

I've tested this with versions 1.14.0 and 1.19.1 of dart and version 53.0.2785.143 of Chrome running on macOS Sierra.

The text was updated successfully, but these errors were encountered:

travissanderson-wf · 2016-10-19T17:12:43Z

+1 this can be very misleading when diagnosing issues in production

thetechnick · 2016-10-21T13:20:33Z

I was doing some testing, because I want to use the stack trace for sentry.io error reporting.
If you throw a Exception in a only using synchronous function calls the stacktrace points points to the dart function declaration in which the exception is thrown,
this also works when calling functions from other packages.

But as soon as there is a async function in the call stack, the source map does very weird things and does not match up with the source code at all.
I have thrown together a small test package to illustrate the behavior.

Using:
Dart VM version: 1.20.1 (Wed Oct 12 15:07:10 2016) on "linux_x64"
Chrome 54.0.2840.59 (64-bit)
Command: pub serve

pubspec.yml

name: 'dart_exception_test'
version: 0.0.1
description: An absolute bare-bones web app.

environment:
  sdk: '>=1.0.0 <2.0.0'

dependencies:
  browser: '>=0.10.0 <0.11.0'
  dart_to_js_script_rewriter: '^1.0.1'

transformers:
- dart_to_js_script_rewriter
- $dart2js:
    sourceMaps: true

web/main.dart

// Copyright (c) 2016, Nico Schieder. All rights reserved. Use of this source code
// is governed by a BSD-style license that can be found in the LICENSE file.

import 'dart:html';
import 'dart:async';
import 'package:dart_exception_test/dart_exception_test.dart';

main() {
  test3();
  test2();
  test1();
}

test1() {
  throw new Exception('main.dart - Sync Exception');
}

test2() async {
  throw new Exception('main.dart - Async Exception');
}

test3() async {
  // exception of package
  testPackage();
}

lib/dart_exception_test.dart

library dart_exception_test;

testPackage() {
  throw new Exception('package - Sync Exception');
}

Output:

1. Sync Exception

Behavior: Stacktrace points to declaration of test1()

main.dart

// ...
main() {
  // test3();
  // test2();
  test1();
}
// ...

Stacktrace:

2. Async Exception

Behavior: Stacktrace points to the closing bracket of main()?

main.dart

// ...
main() {
  // test3();
  test2();
  // test1();
}
// ...

Stacktrace:

3. Other package indirect Async

Behavior: Stacktrace points to the closing bracket of main() and the origin point of the exception cannot be seen at all.

main.dart

// ...
main() {
  test3();
  // test2();
  // test1();
}
// ...

Stacktrace:

Package:
dart-exception-test.tar.gz

I hope this helps finding the issues with source maps.

travissanderson-wf · 2016-10-21T14:15:12Z

@thetechnick that is a really good point, we use the async marker liberally in our code and the lines can be way off. There's also some behind the scenes magic that happens when you use that marker, maybe the source mapping isn't correctly accounting for that.

johnniwinther · 2016-11-17T11:28:21Z

Thanks for the thorough tests! We're working on a new source map engine that, in it's current state, handles the first problem (synchronous code) but not the latter (asynchronous code), yet.

travissanderson-wf · 2016-11-17T15:19:52Z

Is there anything we can watch regarding progress on the new engine or any ETA you could give? This is a daily problem for us right now.

thetechnick · 2016-11-17T16:57:58Z

Thanks for the thorough tests! We're working on a new source map engine that, in it's current state, handles the first problem (synchronous code) but not the latter (asynchronous code), yet.

So the new engine does not generate correct maps if there is something async in the call stack?
Does your "yet" mean that supporting source maps in a async context is a feature on your roadmap?
Can we support you somehow?

johnniwinther · 2016-11-18T08:18:57Z

You can try out the new engine when running dart2js from the command line using the option --use-new-source-info . The option and the fix for synchronous code is in 1.21.0-dev.7.0 . Any feedback on the quality of the new engine will be helpful in making it ready as the default engine.

I've looked into the asynchronous code and found that it contained no source mapping neither in the old nor the new engine. I'm working on a CL providing source mapping for the main parts of async code. This will go in today and should be part of the next dev release.

travissanderson-wf · 2017-01-05T15:50:11Z

@johnniwinther would this be the correct way to use that via pubspec.yaml?

transformers:
  - $dart2js:
      sourceMaps: true
      commandLineOptions: [--use-new-source-info]

travissanderson-wf · 2017-01-05T15:51:11Z

I'm assuming this is available in the stable release of Dart SDK 1.21.0, too.. is there a way to inspect the sourcemap to verify it was generated with the new one instead of the old/current one?

johnniwinther · 2017-01-06T08:54:53Z

It the correct pubspec.yaml parameters but there is no way to verify that the new engine is used (besides seeing you get a different .js.map file in the output).

The option is available in the 1.21 stable release.

travissanderson-wf · 2017-01-06T16:59:03Z

What's the current status regarding accuracy for the new engine? Unfortunately I don't have a reproducing example but we are getting a JS stack trace that maps a null pointer that seems impossible. The code below is a simplified example of the code that is returning a null pointer on the line with return _items[index].

The error we are seeing is Uncaught exception: NullError: method not found: 'd' on null, which doesn't really make sense for the line indicated by the mapping.

class Manager {
  Example example = new Example();

  dispose() {
    example?.dispose();
    example = null;
  }
}

class Example {
  Map<int, String> _items = new Map(); // initialized at instantiation and never nulled out 
  
  String getItemValue(int index) {
    return _items[index];
  }
}

travissanderson-wf · 2017-01-06T19:01:00Z

So I was able to talk to someone that hit this exception and figured out how to reproduce it. The error in Dart is much more helpful and showed that the code was trying to call a method on a null instance of Example, and the method it was trying to call was getItemValue. This is from a private repo so I can't exactly share the code but the whole map seems to be wrong other than the very top of the trace being within 1 line of the method that was called on null.

johnniwinther · 2017-01-09T08:33:01Z

The name 'd' is probably due to the use of minification. If you turn that off the name will probably be something like 'getItemValue$0' which makes a bit more sense. Unfortunately, the message you get for null pointer exceptions is generated by JavaScript directly, which is why minification matters here.

johnniwinther · 2017-01-09T08:38:22Z

Do you use async/await? If so, only top-most synchronous part of the call-stack makes sense (the rest being the call-stack for the event queue handling asynchronous calls).

travissanderson-wf · 2017-01-09T15:49:45Z

Sorry, I meant that error doesn't make sense for the line because it was pointing at the line of the return instead of the method declaration. We do use minification and we use async/await quite a bit. We have a flag to enable Chain.capture but it really kills performance in some browsers.

I added a Manager class above to flesh out what I'm seeing. It was confusing to diagnose a production error because in the Dart error the top of the stack does not refer to the Example file that defines the class for the null object, it only refers to the calling file (Manager) that hit the null pointer. In the mapped Javascript stack it makes it look as if the exception happened in Example instead of in Manager. In fact, even using the new engine the rest of the stack still seems to be completely wrong after mapping, referring to files that are not involved nor do they actually call each other.

johnniwinther · 2017-01-10T08:55:54Z

Sounds bad :( I'd appreciate if you can create an example, maybe mailing me directly.

Regarding the status of the new engine, these are known issues and their state:

Source sourcemapping of every steppable and breakable point in synchronous code (calls, throws, returns, loops, function returns) (Done)
Support sourcemapping of JavaScript embedded in helper methods. (Unimplemented)
Preserve sourcemapping in synchronous parts of async/await code. (Almost done; needs better coverage)
Support sourcemapping of event loop code for the asynchronous part of async/await code. (Unimplemented)
Support inlining (multiple stackframes for a single call) and "outlining" (hiding of stackframes from helper methods). (Unimplemented: This is not supported by the sourcemap format.)

travissanderson-wf · 2017-01-10T15:28:14Z

Sure thing, I will see if I can get a reproducing case and hit you up directly. Thanks.

travissanderson-wf · 2017-01-11T15:18:23Z

Just to update this thread, I reported an off-by-one reproducing case to Johnni that will be resolved.

I also showed him an instance of the map that looked completely wrong. It turns out that is retracer (and browser's) best effort at reading the map for an unmapped region of code; the code is javascript boilerplate for setting up a Dart application environment and there's not many good options for how to handle that in a map that works well with both mapping and debugging.

matanlurey · 2018-06-22T00:17:03Z

Work on Dart SDK 1 has stopped. If this is still an issue in Dart2, please file a new issue.

a-siva added the web-dart2js label Oct 17, 2016

sigmundch assigned johnniwinther Oct 17, 2016

todbachman-wf mentioned this issue Oct 19, 2016

Source-mapped Stack Trace Doesn't Match Chrome dart-lang/source_maps#18

Open

sigmundch added the dart2js-sourcemap label Jan 18, 2017

matanlurey added the closed-obsolete Closed as the reported issue is no longer relevant label Jun 22, 2018

matanlurey closed this as completed Jun 22, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Incorrect Line Numbers in Source-mapped Stack Traces #27600

Incorrect Line Numbers in Source-mapped Stack Traces #27600

todbachman-wf commented Oct 17, 2016 •

edited

Loading

travissanderson-wf commented Oct 19, 2016

thetechnick commented Oct 21, 2016

travissanderson-wf commented Oct 21, 2016

johnniwinther commented Nov 17, 2016

travissanderson-wf commented Nov 17, 2016

thetechnick commented Nov 17, 2016

johnniwinther commented Nov 18, 2016

travissanderson-wf commented Jan 5, 2017

travissanderson-wf commented Jan 5, 2017

johnniwinther commented Jan 6, 2017

travissanderson-wf commented Jan 6, 2017 •

edited

Loading

travissanderson-wf commented Jan 6, 2017

johnniwinther commented Jan 9, 2017

johnniwinther commented Jan 9, 2017

travissanderson-wf commented Jan 9, 2017

johnniwinther commented Jan 10, 2017

travissanderson-wf commented Jan 10, 2017

travissanderson-wf commented Jan 11, 2017

matanlurey commented Jun 22, 2018

Incorrect Line Numbers in Source-mapped Stack Traces #27600

Incorrect Line Numbers in Source-mapped Stack Traces #27600

Comments

todbachman-wf commented Oct 17, 2016 • edited Loading

pubspec.yaml:

web\index.html:

web\main.dart:

Steps to generate stack trace in Chrome:

travissanderson-wf commented Oct 19, 2016

thetechnick commented Oct 21, 2016

Output:

1. Sync Exception

2. Async Exception

3. Other package indirect Async

travissanderson-wf commented Oct 21, 2016

johnniwinther commented Nov 17, 2016

travissanderson-wf commented Nov 17, 2016

thetechnick commented Nov 17, 2016

johnniwinther commented Nov 18, 2016

travissanderson-wf commented Jan 5, 2017

travissanderson-wf commented Jan 5, 2017

johnniwinther commented Jan 6, 2017

travissanderson-wf commented Jan 6, 2017 • edited Loading

travissanderson-wf commented Jan 6, 2017

johnniwinther commented Jan 9, 2017

johnniwinther commented Jan 9, 2017

travissanderson-wf commented Jan 9, 2017

johnniwinther commented Jan 10, 2017

travissanderson-wf commented Jan 10, 2017

travissanderson-wf commented Jan 11, 2017

matanlurey commented Jun 22, 2018

todbachman-wf commented Oct 17, 2016 •

edited

Loading

travissanderson-wf commented Jan 6, 2017 •

edited

Loading