From 219935a48f4d09c1dc2a2b798d81d260cfbcd31a Mon Sep 17 00:00:00 2001 From: Clement Skau Date: Wed, 8 Jul 2020 06:50:40 +0000 Subject: [PATCH] [VM] Adds Future.timeout stack unwinding support for --lazy-async-stacks. Bug: https://github.com/dart-lang/sdk/issues/40815 Change-Id: I1603e1effe67b727d5dc47c0830b4758c764cf4a Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/152328 Commit-Queue: Clement Skau Reviewed-by: Martin Kustermann --- .../tests/vm/dart/causal_stacks/utils.dart | 101 ++++++++++++++++++ .../tests/vm/dart_2/causal_stacks/utils.dart | 101 ++++++++++++++++++ runtime/vm/compiler/frontend/scope_builder.cc | 16 ++- runtime/vm/compiler/recognized_methods_list.h | 1 + runtime/vm/object.h | 1 + runtime/vm/scopes.cc | 10 +- runtime/vm/scopes.h | 5 + runtime/vm/stack_trace.cc | 19 +++- runtime/vm/symbols.h | 1 + sdk/lib/async/future_impl.dart | 17 +-- 10 files changed, 259 insertions(+), 13 deletions(-) diff --git a/runtime/tests/vm/dart/causal_stacks/utils.dart b/runtime/tests/vm/dart/causal_stacks/utils.dart index c1bd59f95259..50b0bf3e816b 100644 --- a/runtime/tests/vm/dart/causal_stacks/utils.dart +++ b/runtime/tests/vm/dart/causal_stacks/utils.dart @@ -149,6 +149,14 @@ Future customErrorZone() async { return completer.future; } +// ---- +// Scenario: Future.timeout: +// ---- + +Future awaitTimeout() async { + await (throwAsync().timeout(Duration(seconds: 1))); +} + // Helpers: // We want lines that either start with a frame index or an async gap marker. @@ -587,6 +595,7 @@ Future doTestsCausal([String? debugInfoFilename]) async { r'^#7 _RawReceivePortImpl._handleMessage \(.+\)$', ], debugInfoFilename); + final customErrorZoneExpected = const [ r'#0 throwSync \(.*/utils.dart:16(:3)?\)$', r'#1 allYield3 \(.*/utils.dart:39(:3)?\)$', @@ -638,6 +647,48 @@ Future doTestsCausal([String? debugInfoFilename]) async { r'#14 _RawReceivePortImpl._handleMessage ', ], debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'^#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^^$', + r'^#1 awaitTimeout ', + ]; + await doTestAwait( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwait ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwaitThen ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwaitCatchError ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); } // For: --no-causal-async-stacks --no-lazy-async-stacks @@ -957,6 +1008,25 @@ Future doTestsNoCausalNoLazy([String? debugInfoFilename]) async { customErrorZone, customErrorZoneExpected, debugInfoFilename); await doTestAwaitCatchError( customErrorZone, customErrorZoneExpected, debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^#1 _RootZone.runUnary ', + r'^#2 _FutureListener.handleValue ', + r'^#3 Future._propagateToListeners.handleValueCallback ', + r'^#4 Future._propagateToListeners ', + r'^#5 Future.(_addListener|_prependListeners). ', + r'^#6 _microtaskLoop ', + r'^#7 _startMicrotaskLoop ', + r'^#8 _runPendingImmediateCallback ', + r'^#9 _RawReceivePortImpl._handleMessage ', + ]; + await doTestAwait( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); } // For: --lazy-async-stacks @@ -1218,4 +1288,35 @@ Future doTestsLazy([String? debugInfoFilename]) async { customErrorZone, customErrorZoneExpected, debugInfoFilename); await doTestAwaitCatchError( customErrorZone, customErrorZoneExpected, debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'^#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^$', + r'^#1 Future.timeout. \(dart:async/future_impl.dart\)$', + r'^$', + r'^#2 awaitTimeout ', + r'^$', + ]; + await doTestAwait( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#3 doTestAwait ', + r'^$', + r'^#4 doTestsLazy ', + r'^$', + r'^#5 main ', + r'^$', + ], + debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#3 doTestAwaitThen. ', + r'^$', + ], + debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); } diff --git a/runtime/tests/vm/dart_2/causal_stacks/utils.dart b/runtime/tests/vm/dart_2/causal_stacks/utils.dart index a7df6560b9c4..ec787cf0d211 100644 --- a/runtime/tests/vm/dart_2/causal_stacks/utils.dart +++ b/runtime/tests/vm/dart_2/causal_stacks/utils.dart @@ -149,6 +149,14 @@ Future customErrorZone() async { return completer.future; } +// ---- +// Scenario: Future.timeout: +// ---- + +Future awaitTimeout() async { + await (throwAsync().timeout(Duration(seconds: 1))); +} + // Helpers: // We want lines that either start with a frame index or an async gap marker. @@ -587,6 +595,7 @@ Future doTestsCausal([String debugInfoFilename]) async { r'^#7 _RawReceivePortImpl._handleMessage \(.+\)$', ], debugInfoFilename); + final customErrorZoneExpected = const [ r'#0 throwSync \(.*/utils.dart:16(:3)?\)$', r'#1 allYield3 \(.*/utils.dart:39(:3)?\)$', @@ -638,6 +647,48 @@ Future doTestsCausal([String debugInfoFilename]) async { r'#14 _RawReceivePortImpl._handleMessage ', ], debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'^#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^^$', + r'^#1 awaitTimeout ', + ]; + await doTestAwait( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwait ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwaitThen ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#2 doTestAwaitCatchError ', + r'^#3 doTestsCausal ', + r'^$', + r'^#4 main \(.+\)$', + r'^#5 _startIsolate. ', + r'^#6 _RawReceivePortImpl._handleMessage ', + ], + debugInfoFilename); } // For: --no-causal-async-stacks --no-lazy-async-stacks @@ -957,6 +1008,25 @@ Future doTestsNoCausalNoLazy([String debugInfoFilename]) async { customErrorZone, customErrorZoneExpected, debugInfoFilename); await doTestAwaitCatchError( customErrorZone, customErrorZoneExpected, debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^#1 _RootZone.runUnary ', + r'^#2 _FutureListener.handleValue ', + r'^#3 Future._propagateToListeners.handleValueCallback ', + r'^#4 Future._propagateToListeners ', + r'^#5 Future.(_addListener|_prependListeners). ', + r'^#6 _microtaskLoop ', + r'^#7 _startMicrotaskLoop ', + r'^#8 _runPendingImmediateCallback ', + r'^#9 _RawReceivePortImpl._handleMessage ', + ]; + await doTestAwait( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); } // For: --lazy-async-stacks @@ -1218,4 +1288,35 @@ Future doTestsLazy([String debugInfoFilename]) async { customErrorZone, customErrorZoneExpected, debugInfoFilename); await doTestAwaitCatchError( customErrorZone, customErrorZoneExpected, debugInfoFilename); + + final awaitTimeoutExpected = const [ + r'^#0 throwAsync \(.*/utils.dart:21(:3)?\)$', + r'^$', + r'^#1 Future.timeout. \(dart:async/future_impl.dart\)$', + r'^$', + r'^#2 awaitTimeout ', + r'^$', + ]; + await doTestAwait( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#3 doTestAwait ', + r'^$', + r'^#4 doTestsLazy ', + r'^$', + r'^#5 main ', + r'^$', + ], + debugInfoFilename); + await doTestAwaitThen( + awaitTimeout, + awaitTimeoutExpected + + const [ + r'^#3 doTestAwaitThen. ', + r'^$', + ], + debugInfoFilename); + await doTestAwaitCatchError( + awaitTimeout, awaitTimeoutExpected + const [], debugInfoFilename); } diff --git a/runtime/vm/compiler/frontend/scope_builder.cc b/runtime/vm/compiler/frontend/scope_builder.cc index e8b8a2c3ccbc..5bca20f8de41 100644 --- a/runtime/vm/compiler/frontend/scope_builder.cc +++ b/runtime/vm/compiler/frontend/scope_builder.cc @@ -540,6 +540,8 @@ void ScopeBuilder::VisitFunctionNode() { FunctionNodeHelper function_node_helper(&helper_); function_node_helper.ReadUntilExcluding(FunctionNodeHelper::kTypeParameters); + const auto& function = parsed_function_->function(); + intptr_t list_length = helper_.ReadListLength(); // read type_parameters list length. for (intptr_t i = 0; i < list_length; ++i) { @@ -565,10 +567,8 @@ void ScopeBuilder::VisitFunctionNode() { } if (function_node_helper.async_marker_ == FunctionNodeHelper::kSyncYielding) { - intptr_t offset = parsed_function_->function().num_fixed_parameters(); - for (intptr_t i = 0; - i < parsed_function_->function().NumOptionalPositionalParameters(); - i++) { + intptr_t offset = function.num_fixed_parameters(); + for (intptr_t i = 0; i < function.NumOptionalPositionalParameters(); i++) { parsed_function_->ParameterVariable(offset + i)->set_is_forced_stack(); } } @@ -627,6 +627,14 @@ void ScopeBuilder::VisitFunctionNode() { } } } + + // Mark known chained futures such as _Future::timeout()'s _future. + if (function.recognized_kind() == MethodRecognizer::kFutureTimeout && + depth_.function_ == 1) { + LocalVariable* future = scope_->LookupVariable(Symbols::_future(), true); + ASSERT(future != nullptr); + future->set_is_chained_future(); + } } void ScopeBuilder::VisitInitializer() { diff --git a/runtime/vm/compiler/recognized_methods_list.h b/runtime/vm/compiler/recognized_methods_list.h index 849cff7270f8..60841011ce06 100644 --- a/runtime/vm/compiler/recognized_methods_list.h +++ b/runtime/vm/compiler/recognized_methods_list.h @@ -177,6 +177,7 @@ namespace dart { V(Pointer, get:address, FfiGetAddress, 0x29a505a1) \ V(::, reachabilityFence, ReachabilityFence, 0x0) \ V(_Utf8Decoder, _scan, Utf8DecoderScan, 0x78f44c3c) \ + V(_Future, timeout, FutureTimeout, 0) \ // List of intrinsics: // (class-name, function-name, intrinsification method, fingerprint). diff --git a/runtime/vm/object.h b/runtime/vm/object.h index ff4e74646290..053f6148afdb 100644 --- a/runtime/vm/object.h +++ b/runtime/vm/object.h @@ -6708,6 +6708,7 @@ class Context : public Object { static const intptr_t kAwaitJumpVarIndex = 0; static const intptr_t kAsyncCompleterIndex = 1; static const intptr_t kControllerIndex = 1; + static const intptr_t kChainedFutureIndex = 2; static intptr_t variable_offset(intptr_t context_index) { return OFFSET_OF_RETURNED_VALUE(ContextLayout, data) + diff --git a/runtime/vm/scopes.cc b/runtime/vm/scopes.cc index ca297b78cffd..cff9a826d665 100644 --- a/runtime/vm/scopes.cc +++ b/runtime/vm/scopes.cc @@ -212,6 +212,7 @@ VariableIndex LocalScope::AllocateVariables(VariableIndex first_parameter_index, LocalVariable* await_jump_var = nullptr; LocalVariable* async_completer = nullptr; LocalVariable* controller = nullptr; + LocalVariable* chained_future = nullptr; for (intptr_t i = 0; i < num_variables(); i++) { LocalVariable* variable = VariableAt(i); if (variable->owner() == this) { @@ -222,6 +223,8 @@ VariableIndex LocalScope::AllocateVariables(VariableIndex first_parameter_index, async_completer = variable; } else if (variable->name().Equals(Symbols::Controller())) { controller = variable; + } else if (variable->is_chained_future()) { + chained_future = variable; } } } @@ -243,6 +246,11 @@ VariableIndex LocalScope::AllocateVariables(VariableIndex first_parameter_index, *found_captured_variables = true; ASSERT(controller->index().value() == Context::kControllerIndex); } + if (chained_future != nullptr) { + AllocateContextVariable(chained_future, &context_owner); + *found_captured_variables = true; + ASSERT(chained_future->index().value() == Context::kChainedFutureIndex); + } while (pos < num_parameters) { LocalVariable* parameter = VariableAt(pos); @@ -273,7 +281,7 @@ VariableIndex LocalScope::AllocateVariables(VariableIndex first_parameter_index, if (variable->is_captured()) { // Skip the two variables already pre-allocated above. if (variable != await_jump_var && variable != async_completer && - variable != controller) { + variable != controller && variable != chained_future) { AllocateContextVariable(variable, &context_owner); *found_captured_variables = true; } diff --git a/runtime/vm/scopes.h b/runtime/vm/scopes.h index fd012c6ccc00..f31a3a07a271 100644 --- a/runtime/vm/scopes.h +++ b/runtime/vm/scopes.h @@ -93,6 +93,7 @@ class LocalVariable : public ZoneAllocated { is_forced_stack_(false), is_explicit_covariant_parameter_(false), is_late_(false), + is_chained_future_(false), late_init_offset_(0), type_check_mode_(kDoTypeCheck), index_() { @@ -131,6 +132,9 @@ class LocalVariable : public ZoneAllocated { bool is_late() const { return is_late_; } void set_is_late() { is_late_ = true; } + bool is_chained_future() const { return is_chained_future_; } + void set_is_chained_future() { is_chained_future_ = true; } + intptr_t late_init_offset() const { return late_init_offset_; } void set_late_init_offset(intptr_t late_init_offset) { late_init_offset_ = late_init_offset; @@ -220,6 +224,7 @@ class LocalVariable : public ZoneAllocated { bool is_forced_stack_; bool is_explicit_covariant_parameter_; bool is_late_; + bool is_chained_future_; intptr_t late_init_offset_; TypeCheckMode type_check_mode_; VariableIndex index_; diff --git a/runtime/vm/stack_trace.cc b/runtime/vm/stack_trace.cc index a9df9e1e6cf9..c2b7828a1ef5 100644 --- a/runtime/vm/stack_trace.cc +++ b/runtime/vm/stack_trace.cc @@ -104,6 +104,7 @@ class CallerClosureFinder { explicit CallerClosureFinder(Zone* zone) : receiver_context_(Context::Handle(zone)), receiver_function_(Function::Handle(zone)), + parent_function_(Function::Handle(zone)), context_entry_(Object::Handle(zone)), is_sync(Object::Handle(zone)), future_(Object::Handle(zone)), @@ -130,7 +131,8 @@ class CallerClosureFinder { var_data_field(Field::Handle(zone)), state_field(Field::Handle(zone)), on_data_field(Field::Handle(zone)), - state_data_field(Field::Handle(zone)) { + state_data_field(Field::Handle(zone)), + future_timeout_method_(Function::Handle(zone)) { const auto& async_lib = Library::Handle(zone, Library::AsyncLibrary()); // Look up classes: // - async: @@ -195,6 +197,11 @@ class CallerClosureFinder { state_data_field = stream_iterator_class.LookupFieldAllowPrivate(Symbols::_stateData()); ASSERT(!state_data_field.IsNull()); + + // Functions: + future_timeout_method_ = + future_impl_class.LookupFunction(Symbols::timeout()); + ASSERT(!future_timeout_method_.IsNull()); } ClosurePtr GetCallerInFutureImpl(const Object& future_) { @@ -285,6 +292,13 @@ class CallerClosureFinder { return FindCallerInAsyncClosure(receiver_context_); } else if (receiver_function_.IsAsyncGenClosure()) { return FindCallerInAsyncGenClosure(receiver_context_); + } else if (receiver_function_.IsLocalFunction()) { + parent_function_ = receiver_function_.parent_function(); + if (parent_function_.recognized_kind() == + MethodRecognizer::kFutureTimeout) { + context_entry_ = receiver_context_.At(Context::kChainedFutureIndex); + return GetCallerInFutureImpl(context_entry_); + } } return Closure::null(); @@ -318,6 +332,7 @@ class CallerClosureFinder { private: Context& receiver_context_; Function& receiver_function_; + Function& parent_function_; Object& context_entry_; Object& is_sync; @@ -348,6 +363,8 @@ class CallerClosureFinder { Field& state_field; Field& on_data_field; Field& state_data_field; + + Function& future_timeout_method_; }; void StackTraceUtils::CollectFramesLazy( diff --git a/runtime/vm/symbols.h b/runtime/vm/symbols.h index 7e38f9e16ce5..8d124600fe90 100644 --- a/runtime/vm/symbols.h +++ b/runtime/vm/symbols.h @@ -490,6 +490,7 @@ class ObjectPointerVisitor; V(start_index_param, ":start_index_param") \ V(string_param, ":string_param") \ V(string_param_length, ":string_param_length") \ + V(timeout, "timeout") \ V(toString, "toString") \ V(vm_prefer_inline, "vm:prefer-inline") \ V(vm_entry_point, "vm:entry-point") \ diff --git a/sdk/lib/async/future_impl.dart b/sdk/lib/async/future_impl.dart index 3f337371d3db..4e24a48db624 100644 --- a/sdk/lib/async/future_impl.dart +++ b/sdk/lib/async/future_impl.dart @@ -768,13 +768,16 @@ class _Future implements Future { } } + @pragma("vm:entry-point") Future timeout(Duration timeLimit, {FutureOr onTimeout()?}) { if (_isComplete) return new _Future.immediate(this); - _Future result = new _Future(); + // This is a VM recognised method, and the _future variable is deliberately + // allocated in a specific slot in the closure context for stack unwinding. + _Future _future = new _Future(); Timer timer; if (onTimeout == null) { timer = new Timer(timeLimit, () { - result._completeError( + _future._completeError( new TimeoutException("Future not completed", timeLimit), StackTrace.empty); }); @@ -785,24 +788,24 @@ class _Future implements Future { timer = new Timer(timeLimit, () { try { - result._complete(zone.run(onTimeoutHandler)); + _future._complete(zone.run(onTimeoutHandler)); } catch (e, s) { - result._completeError(e, s); + _future._completeError(e, s); } }); } this.then((T v) { if (timer.isActive) { timer.cancel(); - result._completeWithValue(v); + _future._completeWithValue(v); } }, onError: (Object e, StackTrace s) { if (timer.isActive) { timer.cancel(); - result._completeError(e, s); + _future._completeError(e, s); } }); - return result; + return _future; } }