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

Stack traces missing frame information when using --lazy-async-stacks with --dwarf-stack-traces #41578

Closed
sstrickl opened this issue Apr 20, 2020 · 4 comments
Assignees
Labels
area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends.

Comments

@sstrickl
Copy link
Contributor

See this CL for an example way to adjust our existing test of lazy async stack traces to also work with --dwarf-stack-traces/--save-debugging-info for reproduction. An example run when this modification is made:

--- Command "vm" (took 787ms):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/dart_precompiled_runtime --dwarf-stack-traces --save-debugging-info=async_dwarf.so --lazy-async-stacks --no-causal-async-stacks --ignore-unrecognized-flags --packages=/usr/local/google/home/sstrickl/dart/sdk/.packages /usr/local/google/home/sstrickl/dart/sdk/out/ReleaseX64/generated_compilations/dartkp/runtime_tests_vm_dart_causal_stacks_async_throws_stack_lazy_test.dart_1/out.aotsnapshot

exit code:
255

stdout:
Non-symbolic stack:
Warning: This VM has been configured to produce stack traces that violate the Dart standard.
*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
pid: 142209, tid: 140036591318784, name DartWorker
isolate_instructions: 7f5cd06ef000 vm_instructions: 7f5cd06eb000
    #00 abs 00007f5cd08080d1 virt 000000000011e0d1 /usr/local/google/home/sstrickl/dart/sdk/out/ReleaseX64/generated_compilations/dartkp/runtime_tests_vm_dart_causal_stacks_async_throws_stack_lazy_test.dart_1/out.aotsnapshot
<asynchronous suspension>
<asynchronous suspension>
<asynchronous suspension>
<asynchronous suspension>

Actual stack:
#0      throwSync (file:///usr/local/google/home/sstrickl/dart/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:16)
#1      allYield3 (file:///usr/local/google/home/sstrickl/dart/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:39)

stderr:
Unhandled exception:
Expect.fail('Expected 10 frames, found 2!')
Warning: This VM has been configured to produce stack traces that violate the Dart standard.
*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
pid: 142209, tid: 140036612765632, name Dart_Initialize
isolate_instructions: 7f5cd06ef000 vm_instructions: 7f5cd06eb000
    #00 abs 00007f5cd0797dea virt 00000000000addea /usr/local/google/home/sstrickl/dart/sdk/out/ReleaseX64/generated_compilations/dartkp/runtime_tests_vm_dart_causal_stacks_async_throws_stack_lazy_test.dart_1/out.aotsnapshot
    #01 abs 00007f5cd0797e36 virt 00000000000ade36 /usr/local/google/home/sstrickl/dart/sdk/out/ReleaseX64/generated_compilations/dartkp/runtime_tests_vm_dart_causal_stacks_async_throws_stack_lazy_test.dart_1/out.aotsnapshot
    #02 abs 00007f5cd08044b6 virt 000000000011a4b6 /usr/local/google/home/sstrickl/dart/sdk/out/ReleaseX64/generated_compilations/dartkp/runtime_tests_vm_dart_causal_stacks_async_throws_stack_lazy_test.dart_1/out.aotsnapshot
<asynchronous suspension>

--- Re-run this test:
python tools/test.py -m release -c dartkp vm/dart/causal_stacks/async_throws_stack_lazy_test/1

Note that we're missing the expected stack information from the test once we start hitting asynchronous suspensions.

/cc @mkustermann @mraleph

@sstrickl sstrickl added the area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends. label Apr 20, 2020
@sstrickl sstrickl assigned ghost and sstrickl and unassigned ghost Apr 20, 2020
@sstrickl
Copy link
Contributor Author

Taking over because I've mostly finished the fix (and checked with Clement that he hadn't already done any work on it before I switched the assignee)

@sstrickl
Copy link
Contributor Author

The new tests are broken on the optcounter and android bots. For the android bots, these tests should just be skipped or no-ops because the gen_snapshot doesn't occur on the device, so the debugging info would need to be copied there for them to work. That's done in CL 144562.

Not sure why they're failing on the optcounter bots. There's an extra async gap, apparently. Otherwise, they match, so at least the change still gives back the expected information, but will investigate this divergence.

@sstrickl sstrickl reopened this Apr 23, 2020
@sstrickl
Copy link
Contributor Author

An example of the latter failure:

--- Command "vm" (took 06.000823s):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/dart --dwarf-stack-traces --save-debugging-info=async_causal_debug.so --causal-async-stacks --no-lazy-async-stacks --optimization-counter-threshold=5 --random-seed=2120349408 --ignore-unrecognized-flags --packages=/b/s/w/ir/cache/builder/sdk/.packages /b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/async_throws_stack_non_symbolic_test.dart

exit code:
255

stdout:
RegExps for expected stack:
"^#0      throwAsync \(.*/utils.dart:21(:3)?\)$"
"^<asynchronous suspension>$"
"^#1      mixedYields3 \(.*/utils.dart:70(:10)?\)$"
"^#2      mixedYields2 \(.*/utils.dart:66(:9)?\)$"
"^<asynchronous suspension>$"
"^#3      mixedYields \(.*/utils.dart:61(:9)?\)$"
"^#4      doTestAwaitCatchError "
"^#5      doTestsCausal "
"^<asynchronous suspension>$"
"^#6      main "
"^#7      _startIsolate.<anonymous closure> "
"^#8      _RawReceivePortImpl._handleMessage "

Actual stack:
#0      throwAsync (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:21:3)
<asynchronous suspension>
#1      mixedYields3 (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:70:10)
#2      mixedYields2 (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:66:9)
<asynchronous suspension>
#3      mixedYields (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:61:9)
#4      doTestAwaitCatchError (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:248:10)
<asynchronous suspension>
#5      doTestsCausal (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:380:9)
<asynchronous suspension>
#6      main (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/async_throws_stack_non_symbolic_test.dart:12:11)
#7      _startIsolate.<anonymous closure> (dart:isolate-patch/isolate_patch.dart:299:32)
#8      _RawReceivePortImpl._handleMessage (dart:isolate-patch/isolate_patch.dart:168:12)

Expected line 8 to be `^#5      doTestsCausal ` but was `<asynchronous suspension>`

stderr:
Unhandled exception:
Expect.isTrue(false) fails.
#0      Expect._fail (package:expect/expect.dart:677:5)
#1      Expect.isTrue (package:expect/expect.dart:135:5)
#2      assertStack (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:201:14)
<asynchronous suspension>
#3      doTestAwaitCatchError (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:251:3)
<asynchronous suspension>
#4      doTestsCausal (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/utils.dart:380:9)
<asynchronous suspension>
#5      main (file:///b/s/w/ir/cache/builder/sdk/runtime/tests/vm/dart/causal_stacks/async_throws_stack_non_symbolic_test.dart:12:11)
#6      _startIsolate.<anonymous closure> (dart:isolate-patch/isolate_patch.dart:299:32)
#7      _RawReceivePortImpl._handleMessage (dart:isolate-patch/isolate_patch.dart:168:12)

--- Re-run this test:
python tools/test.py -n dartk-optcounter-linux-release-x64 vm/dart/causal_stacks/async_throws_stack_non_symbolic_test

dart-bot pushed a commit that referenced this issue Apr 23, 2020
We don't copy the saved debugging info over to the Android device,
so these tests can't succeed.

Bug: #41578
Change-Id: Ife11e31862457e7c7dba1c38f15c8c7d22eda414
Cq-Include-Trybots: luci.dart.try:vm-kernel-precomp-android-release-arm64-try
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/144562
Reviewed-by: Martin Kustermann <kustermann@google.com>
Commit-Queue: Tess Strickland <sstrickl@google.com>
@sstrickl
Copy link
Contributor Author

Given that the only differences is an additional async gap between two async functions, I'm guessing this is just due to a difference in optimization due to the changed optcounter setting and isn't concerning in itself. It'd be nice to extend the test to be more lenient towards such, but since this is the only mode in which it happens and this isn't a production mode, I think it's okay to just leave it as an approved failure for now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends.
Projects
None yet
Development

No branches or pull requests

1 participant