Skip to content

Commit 090c07a

Browse files
mralephCommit Queue
mraleph
authored and
Commit Queue
committed
[vm] Improve unwinding for Future.timeout
Make unwinding follow the awaiter link attached to the timeout handler, which allows it to continue past the asynchronous gap into the corresponding listeners. This significantly improves the stack trace: for example a timing out `await Socket.connect()` now produces: SocketException: Connection timed out, ... _NativeSocket.connect.<anonymous closure>.<anonymous closure> _RootZone.run (dart:async/zone.dart:1655:54) Future.timeout.<anonymous closure> <asynchronous suspension> _RawSocket.connect.<anonymous closure> <asynchronous suspension> Socket._connect.<anonymous closure> <asynchronous suspension> main <asynchronous suspension> Where without this change it produced: SocketException: Connection timed out, ... _NativeSocket.connect.<anonymous closure>.<anonymous closure> _RootZone.run Future.timeout.<anonymous closure> Timer._createTimer.<anonymous closure> _Timer._runTimers _Timer._handleMessage _RawReceivePort._handleMessage Which is much less informative. TEST=vm/dart/awaiter_stacks Fixes #56431 Change-Id: If4798e9e216ed88480a2b2b91ad6fa13dcb14ca4 Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/380982 Reviewed-by: Sigmund Cherem <[email protected]> Reviewed-by: Martin Kustermann <[email protected]> Commit-Queue: Slava Egorov <[email protected]> Reviewed-by: Lasse Nielsen <[email protected]>
1 parent 4ef9223 commit 090c07a

File tree

4 files changed

+134
-6
lines changed

4 files changed

+134
-6
lines changed

‎runtime/tests/vm/dart/awaiter_stacks/async_stacks_test.dart

Lines changed: 92 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,10 @@ import 'harness.dart' as harness;
1616

1717
// Test functions:
1818

19+
Future<void> neverCompletes() {
20+
return Completer<void>().future;
21+
}
22+
1923
Future<void> throwSync() {
2024
throw 'throw from throwSync';
2125
}
@@ -167,6 +171,16 @@ Future awaitTimeout() async {
167171
await (throwAsync().timeout(Duration(seconds: 1)));
168172
}
169173

174+
Future awaitTimeoutHappens() async {
175+
await neverCompletes().timeout(Duration(milliseconds: 1));
176+
}
177+
178+
Future awaitTimeoutHappensThrowFromOnTimeout() async {
179+
await neverCompletes().timeout(Duration(milliseconds: 1), onTimeout: () {
180+
throw 'timeout';
181+
});
182+
}
183+
170184
// ----
171185
// Scenario: Future.wait:
172186
// ----
@@ -242,6 +256,8 @@ Future<void> main(List<String> args) async {
242256
listenAsyncStarThrowAsync,
243257
customErrorZone,
244258
awaitTimeout,
259+
awaitTimeoutHappens,
260+
awaitTimeoutHappensThrowFromOnTimeout,
245261
awaitWait,
246262
futureSyncWhenComplete,
247263
futureThen,
@@ -625,6 +641,82 @@ final currentExpectations = [
625641
#4 runTest (harness.dart)
626642
<asynchronous suspension>
627643
#5 main (%test%)
644+
<asynchronous suspension>""",
645+
"""
646+
#0 Future.timeout.<anonymous closure> (future_impl.dart)
647+
<asynchronous suspension>
648+
#1 awaitTimeoutHappens (%test%)
649+
<asynchronous suspension>
650+
#2 doTestAwait (%test%)
651+
<asynchronous suspension>
652+
#3 runTest (harness.dart)
653+
<asynchronous suspension>
654+
#4 main (%test%)
655+
<asynchronous suspension>""",
656+
"""
657+
#0 Future.timeout.<anonymous closure> (future_impl.dart)
658+
<asynchronous suspension>
659+
#1 awaitTimeoutHappens (%test%)
660+
<asynchronous suspension>
661+
#2 doTestAwaitThen.<anonymous closure> (%test%)
662+
<asynchronous suspension>
663+
#3 doTestAwaitThen (%test%)
664+
<asynchronous suspension>
665+
#4 runTest (harness.dart)
666+
<asynchronous suspension>
667+
#5 main (%test%)
668+
<asynchronous suspension>""",
669+
"""
670+
#0 Future.timeout.<anonymous closure> (future_impl.dart)
671+
<asynchronous suspension>
672+
#1 awaitTimeoutHappens (%test%)
673+
<asynchronous suspension>
674+
#2 doTestAwaitCatchError (%test%)
675+
<asynchronous suspension>
676+
#3 runTest (harness.dart)
677+
<asynchronous suspension>
678+
#4 main (%test%)
679+
<asynchronous suspension>""",
680+
"""
681+
#0 awaitTimeoutHappensThrowFromOnTimeout.<anonymous closure> (%test%)
682+
#1 _RootZone.run (zone.dart)
683+
#2 Future.timeout.<anonymous closure> (future_impl.dart)
684+
<asynchronous suspension>
685+
#3 awaitTimeoutHappensThrowFromOnTimeout (%test%)
686+
<asynchronous suspension>
687+
#4 doTestAwait (%test%)
688+
<asynchronous suspension>
689+
#5 runTest (harness.dart)
690+
<asynchronous suspension>
691+
#6 main (%test%)
692+
<asynchronous suspension>""",
693+
"""
694+
#0 awaitTimeoutHappensThrowFromOnTimeout.<anonymous closure> (%test%)
695+
#1 _RootZone.run (zone.dart)
696+
#2 Future.timeout.<anonymous closure> (future_impl.dart)
697+
<asynchronous suspension>
698+
#3 awaitTimeoutHappensThrowFromOnTimeout (%test%)
699+
<asynchronous suspension>
700+
#4 doTestAwaitThen.<anonymous closure> (%test%)
701+
<asynchronous suspension>
702+
#5 doTestAwaitThen (%test%)
703+
<asynchronous suspension>
704+
#6 runTest (harness.dart)
705+
<asynchronous suspension>
706+
#7 main (%test%)
707+
<asynchronous suspension>""",
708+
"""
709+
#0 awaitTimeoutHappensThrowFromOnTimeout.<anonymous closure> (%test%)
710+
#1 _RootZone.run (zone.dart)
711+
#2 Future.timeout.<anonymous closure> (future_impl.dart)
712+
<asynchronous suspension>
713+
#3 awaitTimeoutHappensThrowFromOnTimeout (%test%)
714+
<asynchronous suspension>
715+
#4 doTestAwaitCatchError (%test%)
716+
<asynchronous suspension>
717+
#5 runTest (harness.dart)
718+
<asynchronous suspension>
719+
#6 main (%test%)
628720
<asynchronous suspension>""",
629721
"""
630722
#0 throwAsync (%test%)

‎runtime/tests/vm/dart/awaiter_stacks/zone_callback_stack_traces_test.dart

Lines changed: 33 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,9 @@ Future<void> foo() async {
3333
Future<void> bar() async {
3434
await foo();
3535
stacktraces.add(StackTrace.current);
36+
await Completer().future.timeout(Duration(milliseconds: 1), onTimeout: () {
37+
stacktraces.add(StackTrace.current);
38+
});
3639
}
3740

3841
Future<void> runTest() {
@@ -75,7 +78,7 @@ Future<void> main() async {
7578
for (var st in stacktraces) {
7679
await harness.checkExpectedStack(st);
7780
}
78-
Expect.equals(6, stacktraces.length);
81+
Expect.equals(9, stacktraces.length);
7982

8083
harness.updateExpectations();
8184
}
@@ -135,6 +138,35 @@ final currentExpectations = [
135138
#0 bar (%test%)
136139
<asynchronous suspension>
137140
#1 main (%test%)
141+
<asynchronous suspension>""",
142+
"""
143+
#0 _registerUnaryCallback (%test%)
144+
#1 _CustomZone.registerUnaryCallback (zone.dart)
145+
#2 Future.then (future_impl.dart)
146+
#3 Future.timeout (future_impl.dart)
147+
#4 bar (%test%)
148+
<asynchronous suspension>
149+
#5 main (%test%)
150+
<asynchronous suspension>""",
151+
"""
152+
#0 _registerBinaryCallback (%test%)
153+
#1 _CustomZone.registerBinaryCallback (zone.dart)
154+
#2 _registerErrorHandler (future_impl.dart)
155+
#3 Future.then (future_impl.dart)
156+
#4 Future.timeout (future_impl.dart)
157+
#5 bar (%test%)
158+
<asynchronous suspension>
159+
#6 main (%test%)
160+
<asynchronous suspension>""",
161+
"""
162+
#0 bar.<anonymous closure> (%test%)
163+
#1 _rootRun (zone.dart)
164+
#2 _CustomZone.run (zone.dart)
165+
#3 Future.timeout.<anonymous closure> (future_impl.dart)
166+
<asynchronous suspension>
167+
#4 bar (%test%)
168+
<asynchronous suspension>
169+
#5 main (%test%)
138170
<asynchronous suspension>"""
139171
];
140172
// CURRENT EXPECTATIONS END

‎runtime/vm/stack_trace.cc

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -384,10 +384,14 @@ bool AsyncAwareStackUnwinder::HandleSynchronousFrame() {
384384
if (function_.HasAwaiterLink()) {
385385
object_ = GetReceiver();
386386
if (object_.IsClosure() &&
387-
StackTraceUtils::GetSuspendState(Closure::Cast(object_),
388-
&awaiter_frame_.next)) {
389-
awaiter_frame_.closure ^= object_.ptr();
390-
return true; // Hide this frame from the stack trace.
387+
TryGetAwaiterLink(Closure::Cast(object_), &awaiter_frame_.next)) {
388+
if (awaiter_frame_.next.IsSuspendState()) {
389+
awaiter_frame_.closure ^= object_.ptr();
390+
return true; // Hide this frame from the stack trace.
391+
} else if (awaiter_frame_.next.GetClassId() == _Future().id()) {
392+
UnwindFrameToFutureListener();
393+
return false; // Do not hide this from the stack trace.
394+
}
391395
}
392396
}
393397

‎sdk/lib/async/future_impl.dart

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -945,7 +945,7 @@ class _Future<T> implements Future<T> {
945945
timer = new Timer(timeLimit, () {
946946
_future._completeError(
947947
new TimeoutException("Future not completed", timeLimit),
948-
StackTrace.empty);
948+
StackTrace.current);
949949
});
950950
} else {
951951
Zone zone = Zone.current;

0 commit comments

Comments
 (0)