Dart-Code / Dart-Code

Dart and Flutter support for VS Code
https://dartcode.org/
MIT License
1.5k stars 306 forks source link

Debugged Flutter 2 application dies when inspecting locals (hovering or 'Run and debug -> Variables' view) #3185

Closed wujek-srujek closed 3 years ago

wujek-srujek commented 3 years ago

Describe the bug Whenever a Flutter 2 (2.0.1 to be exact) application is being debugged and a breakpoint is hit, hovering over a variable or expanding it in the 'Run and debug -> Variables' view causes the application to die. As a result, there is no way to efficiently debug a Flutter 2 app.

I noticed this with a custom app during the first session trying to debug an issue after Flutter upgrade. After downgrading to Flutter 1.22.6 and going to the latest commit where the app was still on that version, debugging worked as it always used to.

The issue can be reproduced with the simplest Flutter sample app created using this command:

flutter create flutter_counter_sample

The error I see in the console is:

Launching lib/main.dart on iPhone Xs in debug mode...
lib/main.dart:1
Xcode build done.                                            8.5s
Connecting to VM Service at ws://127.0.0.1:55869/saA4Pe9POFQ=/ws
Error handling 'checkPlatformOverride' custom request: method not available: ext.flutter.platformOverride
Error handling 'checkBrightnessOverride' custom request: method not available: ext.flutter.brightnessOverride
Error handling 'serviceExtension' custom request: method not available: ext.flutter.inspector.setPubRootDirectories
Error handling 'checkIsWidgetCreationTracked' custom request: method not available: ext.flutter.inspector.isWidgetCreationTracked
Lost connection to device.
Exited (sigterm)

No amount of flutter clean etc. helps.

To Reproduce Steps to reproduce the behavior:

  1. Create a sample app: flutter create flutter_counter_sample
  2. Open the app in VSCode and start with debugging on.
  3. Set a breakpoint in _MyHomePageState.build.
  4. When the app starts, click the + button. The debugger will stop at the breakpoint.
  5. Hover over the context local or expand it in the 'Variables' view.
  6. The application will crash.

Versions (please complete the following information):

wujek-srujek commented 3 years ago

Debugging works with Android Studio so this seems not to be a Flutter issue, but a VSCode one.

DanTup commented 3 years ago

I've not been able to reproduce this:

Screenshot 2021-03-08 at 10 12 25

Although I suspect it's a Flutter or Dart VM issue given that it works on the previous Flutter version (there's also not a lot VS Code could do to cause the VM to crash).

Could you confirm what type of device you're running on (Simulator or physical iPhone?), and also capture a verbose log (using the sample counter app):

Thanks!

DanTup commented 3 years ago

Also - could you confirm if typing context into the Debug Console to evaluate it causes the same termination as hovering?

wujek-srujek commented 3 years ago

Strange, it is 100% reproducible for me in VSCode and there is no crash in Android Studio. I attach two videos, and the requested log.

Evaluating in Debug Console by itself doesn't cause the bug, its expanding the variable to see its 'insides' what crashes the app. This is consistent with the 'Variables' view behavior - I can stop and see the variable names, but as soon as I expand any of them, it fails.

I'm using an iOS simulator (iPhone XS with iOS 14.4), but it also happens on a real Android device (up-to-date Pixel 3XL).

Dart-Code-Log-2021-02-01 13-00-05.txt

https://user-images.githubusercontent.com/2421362/110319148-c2247a00-800e-11eb-8b11-65c4a4c3be52.mov

https://user-images.githubusercontent.com/2421362/110319170-ca7cb500-800e-11eb-9456-baef9c38a0ba.mov

DanTup commented 3 years ago

If you set the dart.evaluateGettersInDebugViews setting to false in VS Code, does this change anything?

@bkonyi @aam it seems like something is crashing here (perhaps the Flutter services that's evaluating the expressions?) while VS Code is trying to enumerate the fields on the class and fetch them via the VM service for the tooltip (or expanded view in the Debug Console). The relevant part of the log is below but there's no obvious error/crash - we send a bunch of evaluate requests and some work, and others return errors saying "The client closed with pending requests".

[1:00:29 PM] [VmService] ==> {"id":"580","jsonrpc":"2.0","method":"getObject","params":{"isolateId":"isolates/199456990271431","objectId":"classes/1693"}}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"Class","class":{"type":"@Class","fixedId":true,"id":"classes/4","name":"Class"},"size":208,"fixedId":true,"id":"classes/1693","name":"DiagnosticableTree","abstract":true,"const":true,"_finalized":true,"_implemented":true,"_patch":false,"_traceAllocations":false,"super":{"type":"@Class","fixedId":true,"id":"classes/1695","name":"_DiagnosticableTree&Object&Diagnosticable","_vmName":"_DiagnosticableTree&Object&Diagnosticable@108198569"},"superType":{"type":"@Instance","_vmType":"Type","class":{"type":"@Class","fixedId":true,"id":"classes/42","name":"_Type","_vmName":"_Type@0150898"},"kind":"Type","fixedId":true,"id":"classes/1695/types/0","typeClass":{"type":"@Class","fixedId":true,"id":"classes/1695","name":"_DiagnosticableTree&Object&Diagnosticable","_vmName":"_DiagnosticableTree&Object&Diagnosticable@108198569"},"name":"_DiagnosticableTree&Object&Diagnosticable","_vmName":"_DiagnosticableTree&Object&Diagnosticable@108198569"},"library":{"type":"@Library","fixedId":true,"id":"libraries/@108198569","name":"","uri":"package:flutter/src/foundation/diagnostics.dart"},"location":{"type":"SourceLocation","script":{"type":"@Script","fixedId":true,"id":"libraries/@61482824/scripts/package%3Aflutter%2Fsrc%2Ffoundation%2Fdiagnostics.dart/17811b5b86d","uri":"package:flutter/src/foundation/diagnostics.dart","_kind":"kernel"},"tokenPos":116598,"endTokenPos":120428},"interfaces":[],"fields":[],"functions":[{"type":"@Function","fixedId":true,"id":"classes/1693/functions/DiagnosticableTree.","name":"DiagnosticableTree","_vmName":"DiagnosticableTree.","owner":{"type":"@Class","fixedId":true,"id":"classes/1693","name":"DiagnosticableTree"},"_kind":"Constructor","static":false,"const":true,"_intrinsic":false,"_native":false},{"type":"@Function","fixedId":true,"id":"classes/1693/functions/toStringShallow","name":"toStringShallow","owner":{"type":"@Class","fixedId":true,"id":"classes/1693","name":"DiagnosticableTree"},"_kind":"…
[1:00:29 PM] [VmService] ==> {"id":"581","jsonrpc":"2.0","method":"getObject","params":{"isolateId":"isolates/199456990271431","objectId":"classes/1695"}}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"Class","class":{"type":"@Class","fixedId":true,"id":"classes/4","name":"Class"},"size":208,"fixedId":true,"id":"classes/1695","name":"_DiagnosticableTree&Object&Diagnosticable","_vmName":"_DiagnosticableTree&Object&Diagnosticable@108198569","abstract":true,"const":true,"_finalized":true,"_implemented":true,"_patch":false,"_traceAllocations":false,"super":{"type":"@Class","fixedId":true,"id":"classes/38","name":"Object"},"superType":{"type":"@Instance","_vmType":"Type","class":{"type":"@Class","fixedId":true,"id":"classes/42","name":"_Type","_vmName":"_Type@0150898"},"kind":"Type","fixedId":true,"id":"classes/38/types/0","typeClass":{"type":"@Class","fixedId":true,"id":"classes/38","name":"Object"},"name":"Object"},"mixin":{"type":"@Instance","_vmType":"Type","class":{"type":"@Class","fixedId":true,"id":"classes/42","name":"_Type","_vmName":"_Type@0150898"},"kind":"Type","fixedId":true,"id":"classes/1413/types/0","typeClass":{"type":"@Class","fixedId":true,"id":"classes/1413","name":"Diagnosticable"},"name":"Diagnosticable"},"library":{"type":"@Library","fixedId":true,"id":"libraries/@108198569","name":"","uri":"package:flutter/src/foundation/diagnostics.dart"},"location":{"type":"SourceLocation","script":{"type":"@Script","fixedId":true,"id":"libraries/@61482824/scripts/package%3Aflutter%2Fsrc%2Ffoundation%2Fdiagnostics.dart/17811b5b86d","uri":"package:flutter/src/foundation/diagnostics.dart","_kind":"kernel"},"tokenPos":116598,"endTokenPos":120428},"interfaces":[{"type":"@Instance","_vmType":"Type","class":{"type":"@Class","fixedId":true,"id":"classes/42","name":"_Type","_vmName":"_Type@0150898"},"kind":"Type","fixedId":true,"id":"classes/1413/types/0","typeClass":{"type":"@Class","fixedId":true,"id":"classes/1413","name":"Diagnosticable"},"name":"Diagnosticable"}],"fields":[],"functions":[{"type":"@Function","fixedId":true,"id":"classes/1695/functions/_DiagnosticableTree%26Object%26Diagnosticable%4010819…
[1:00:29 PM] [VmService] ==> {"id":"582","jsonrpc":"2.0","method":"getObject","params":{"isolateId":"isolates/199456990271431","objectId":"classes/38"}}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"Class","class":{"type":"@Class","fixedId":true,"id":"classes/4","name":"Class"},"size":208,"fixedId":true,"id":"classes/38","name":"Object","abstract":false,"const":true,"_finalized":true,"_implemented":false,"_patch":false,"_traceAllocations":false,"library":{"type":"@Library","fixedId":true,"id":"libraries/@0150898","name":"dart.core","uri":"dart:core"},"location":{"type":"SourceLocation","script":{"type":"@Script","fixedId":true,"id":"libraries/@0150898/scripts/dart%3Acore%2Fobject.dart/0","uri":"dart:core/object.dart","_kind":"kernel"},"tokenPos":838,"endTokenPos":6287},"interfaces":[],"fields":[{"type":"@Field","fixedId":true,"id":"classes/38/fields/_hashCodeRnd%400150898","name":"_hashCodeRnd","_vmName":"_hashCodeRnd@0150898","owner":{"type":"@Class","fixedId":true,"id":"classes/38","name":"Object"},"declaredType":{"type":"@Instance","_vmType":"Type","class":{"type":"@Class","fixedId":true,"id":"classes/42","name":"_Type","_vmName":"_Type@0150898"},"kind":"Type","fixedId":true,"id":"classes/649/types/0","typeClass":{"type":"@Class","fixedId":true,"id":"classes/649","name":"Random"},"name":"Random"},"static":true,"final":true,"const":false}],"functions":[{"type":"@Function","fixedId":true,"id":"classes/38/functions/get%3A_hashCodeRnd%400150898","name":"_hashCodeRnd","_vmName":"get:_hashCodeRnd@0150898","owner":{"type":"@Class","fixedId":true,"id":"classes/38","name":"Object"},"_kind":"ImplicitStaticGetter","static":true,"const":false,"_intrinsic":false,"_native":false},{"type":"@Function","fixedId":true,"id":"classes/38/functions/Object.","name":"Object","_vmName":"Object.","owner":{"type":"@Class","fixedId":true,"id":"classes/38","name":"Object"},"_kind":"Constructor","static":false,"const":true,"_intrinsic":false,"_native":false},{"type":"@Function","fixedId":true,"id":"classes/38/functions/_objectHashCode%400150898","name":"_objectHashCode","_vmName":"_objectHashCode@0150898","owner":{"type":"@Clas…
[1:00:29 PM] [VmService] ==> {"id":"583","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"debugDoingBuild","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"584","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"depth","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"585","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"dirty","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"586","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"hashCode","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"587","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"owner","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"588","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"renderObject","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"589","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"runtimeType","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"590","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"size","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"591","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"slot","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] ==> {"id":"592","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"widget","isolateId":"isolates/199456990271431","targetId":"objects/39"}}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"@Instance","_vmType":"String","class":{"type":"@Class","fixedId":true,"id":"classes/78","name":"_OneByteString","_vmName":"_OneByteString@0150898"},"kind":"String","id":"objects/71","length":1565,"valueAsString":"{_FocusMarker: _FocusMarker, Directionality: Directionality(textDirection: ltr), _ShortcutsMarker: _ShortcutsMarker, UnmanagedRe","count":128,"valueAsStringIsTruncated":true},"id":"570"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"@Instance","_vmType":"String","class":{"type":"@Class","fixedId":true,"id":"classes/78","name":"_OneByteString","_vmName":"_OneByteString@0150898"},"kind":"String","id":"objects/72","length":56,"valueAsString":"{_LocalizationsScope-[GlobalKey#5cf03], _InheritedTheme}"},"id":"569"}
[1:00:29 PM] [VmService] ==> {"id":"593","jsonrpc":"2.0","method":"getObject","params":{"isolateId":"isolates/199456990271431","objectId":"objects/71"}}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","result":{"type":"Instance","_vmType":"String","class":{"type":"@Class","fixedId":true,"id":"classes/78","name":"_OneByteString","_vmName":"_OneByteString@0150898"},"size":1584,"fields":[],"kind":"String","id":"objects/73","length":1565,"valueAsString":"{_FocusMarker: _FocusMarker, Directionality: Directionality(textDirection: ltr), _ShortcutsMarker: _ShortcutsMarker, UnmanagedRestorationScope: UnmanagedRestorationScope, _ActionsMarker: _ActionsMarker, _ModalScopeStatus: _ModalScopeStatus(active), HeroControllerScope: HeroControllerScope, _ScaffoldMessengerScope: _ScaffoldMessengerScope, _InheritedCupertinoTheme: _InheritedCupertinoTheme, ScrollConfiguration: ScrollConfiguration(behavior: _MaterialScrollBehavior), PrimaryScrollController: PrimaryScrollController(ScrollController#c35f2(no clients)), IconTheme: IconTheme(color: Color(0xdd000000)), MediaQuery: MediaQuery(MediaQueryData(size: Size(375.0, 812.0), devicePixelRatio: 3.0, textScaleFactor: 1.0, platformBrightness: Brightness.dark, padding: EdgeInsets(0.0, 44.0, 0.0, 34.0), viewPadding: EdgeInsets(0.0, 44.0, 0.0, 34.0), viewInsets: EdgeInsets.zero, alwaysUse24HourFormat: false, accessibleNavigation: false, highContrast: false, disableAnimations: false, invertColors: false, boldText: false, navigationMode: traditional)), _FocusTraversalGroupMarker: _FocusTraversalGroupMarker, _LocalizationsScope: _LocalizationsScope-[GlobalKey#5cf03], _InheritedTheme: _InheritedTheme, DefaultTextStyle: DefaultTextStyle(debugLabel: fallback style; consider putting your text in a Material, inherit: true, color: Color(0xd0ff0000), family: monospace, size: 48.0, weight: 900, decoration: double Color(0xffffff00) TextDecoration.underline, softWrap: wrapping at box width, overflow: clip), _EffectiveTickerMode: _EffectiveTickerMode(effective mode: enabled)}"},"id":"593"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","data":{"full":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","stack":"package:json_rpc_2/src/client.dart 70:24      new Client.withoutJson.<fn>\ndart:async/zone.dart 1346:47                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/future_impl.dart 176:18            _FutureListener.handleWhenComplete\ndart:async/future_impl.dart 674:39            Future._propagateToListeners.handleWhenCompleteCallback\ndart:async/future_impl.dart 730:37            Future._propagateToListeners\ndart:async/future_impl.dart 629:9             Future._propagateToListeners\ndart:async/future_impl.dart 539:5             Future._completeWithValue\ndart:async/future_impl.dart 577:7             Future._asyncCompleteWithValue.<fn>\ndart:async/zone.dart 1354:13                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/zone.dart 1162:7                   _CustomZone.runGuarded\ndart:async/zone.dart 1202:23                  _CustomZone.bindCallbackGuarded.<fn>\ndart:async/schedule_microtask.dart 40:21      _microtaskLoop\ndart:async/schedule_microtask.dart 49:5       _startMicrotaskLoop\ndart:isolate-patch/isolate_patch.dart 120:13  _runPendingImmediateCallback\ndart:isolate-patch/isolate_patch.dart 185:5   _RawReceivePortImpl._handleMessage\n","request":{"id":"583","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"debugDoingBuild","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"583"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","data":{"full":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","stack":"package:json_rpc_2/src/client.dart 70:24      new Client.withoutJson.<fn>\ndart:async/zone.dart 1346:47                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/future_impl.dart 176:18            _FutureListener.handleWhenComplete\ndart:async/future_impl.dart 674:39            Future._propagateToListeners.handleWhenCompleteCallback\ndart:async/future_impl.dart 730:37            Future._propagateToListeners\ndart:async/future_impl.dart 629:9             Future._propagateToListeners\ndart:async/future_impl.dart 539:5             Future._completeWithValue\ndart:async/future_impl.dart 577:7             Future._asyncCompleteWithValue.<fn>\ndart:async/zone.dart 1354:13                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/zone.dart 1162:7                   _CustomZone.runGuarded\ndart:async/zone.dart 1202:23                  _CustomZone.bindCallbackGuarded.<fn>\ndart:async/schedule_microtask.dart 40:21      _microtaskLoop\ndart:async/schedule_microtask.dart 49:5       _startMicrotaskLoop\ndart:isolate-patch/isolate_patch.dart 120:13  _runPendingImmediateCallback\ndart:isolate-patch/isolate_patch.dart 185:5   _RawReceivePortImpl._handleMessage\n","request":{"id":"584","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"depth","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"584"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","data":{"full":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","stack":"package:json_rpc_2/src/client.dart 70:24      new Client.withoutJson.<fn>\ndart:async/zone.dart 1346:47                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/future_impl.dart 176:18            _FutureListener.handleWhenComplete\ndart:async/future_impl.dart 674:39            Future._propagateToListeners.handleWhenCompleteCallback\ndart:async/future_impl.dart 730:37            Future._propagateToListeners\ndart:async/future_impl.dart 629:9             Future._propagateToListeners\ndart:async/future_impl.dart 539:5             Future._completeWithValue\ndart:async/future_impl.dart 577:7             Future._asyncCompleteWithValue.<fn>\ndart:async/zone.dart 1354:13                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/zone.dart 1162:7                   _CustomZone.runGuarded\ndart:async/zone.dart 1202:23                  _CustomZone.bindCallbackGuarded.<fn>\ndart:async/schedule_microtask.dart 40:21      _microtaskLoop\ndart:async/schedule_microtask.dart 49:5       _startMicrotaskLoop\ndart:isolate-patch/isolate_patch.dart 120:13  _runPendingImmediateCallback\ndart:isolate-patch/isolate_patch.dart 185:5   _RawReceivePortImpl._handleMessage\n","request":{"id":"585","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"dirty","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"585"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","data":{"full":"Bad state: The client closed with pending request \"_evaluateCompiledExpression\".","stack":"package:json_rpc_2/src/client.dart 70:24      new Client.withoutJson.<fn>\ndart:async/zone.dart 1346:47                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/future_impl.dart 176:18            _FutureListener.handleWhenComplete\ndart:async/future_impl.dart 674:39            Future._propagateToListeners.handleWhenCompleteCallback\ndart:async/future_impl.dart 730:37            Future._propagateToListeners\ndart:async/future_impl.dart 629:9             Future._propagateToListeners\ndart:async/future_impl.dart 539:5             Future._completeWithValue\ndart:async/future_impl.dart 577:7             Future._asyncCompleteWithValue.<fn>\ndart:async/zone.dart 1354:13                  _rootRun\ndart:async/zone.dart 1258:19                  _CustomZone.run\ndart:async/zone.dart 1162:7                   _CustomZone.runGuarded\ndart:async/zone.dart 1202:23                  _CustomZone.bindCallbackGuarded.<fn>\ndart:async/schedule_microtask.dart 40:21      _microtaskLoop\ndart:async/schedule_microtask.dart 49:5       _startMicrotaskLoop\ndart:isolate-patch/isolate_patch.dart 120:13  _runPendingImmediateCallback\ndart:isolate-patch/isolate_patch.dart 185:5   _RawReceivePortImpl._handleMessage\n","request":{"id":"586","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"hashCode","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"586"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client is closed.","data":{"full":"Bad state: The client is closed.","stack":"package:json_rpc_2/src/client.dart 152:19         Client._send\npackage:json_rpc_2/src/client.dart 120:5          Client.sendRequest\npackage:json_rpc_2/src/peer.dart 98:15            Peer.sendRequest\npackage:dds/src/expression_evaluator.dart 120:38  ExpressionEvaluator._evaluateCompiledExpression\npackage:dds/src/expression_evaluator.dart 52:18   ExpressionEvaluator.execute\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 212:18         Server._handleSingleRequest\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 188:18         Server._handleRequest\n","request":{"id":"587","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"owner","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"587"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client is closed.","data":{"full":"Bad state: The client is closed.","stack":"package:json_rpc_2/src/client.dart 152:19         Client._send\npackage:json_rpc_2/src/client.dart 120:5          Client.sendRequest\npackage:json_rpc_2/src/peer.dart 98:15            Peer.sendRequest\npackage:dds/src/expression_evaluator.dart 120:38  ExpressionEvaluator._evaluateCompiledExpression\npackage:dds/src/expression_evaluator.dart 52:18   ExpressionEvaluator.execute\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 212:18         Server._handleSingleRequest\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 188:18         Server._handleRequest\n","request":{"id":"588","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"renderObject","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"588"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client is closed.","data":{"full":"Bad state: The client is closed.","stack":"package:json_rpc_2/src/client.dart 152:19         Client._send\npackage:json_rpc_2/src/client.dart 120:5          Client.sendRequest\npackage:json_rpc_2/src/peer.dart 98:15            Peer.sendRequest\npackage:dds/src/expression_evaluator.dart 120:38  ExpressionEvaluator._evaluateCompiledExpression\npackage:dds/src/expression_evaluator.dart 52:18   ExpressionEvaluator.execute\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 212:18         Server._handleSingleRequest\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 188:18         Server._handleRequest\n","request":{"id":"589","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"runtimeType","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"589"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client is closed.","data":{"full":"Bad state: The client is closed.","stack":"package:json_rpc_2/src/client.dart 152:19         Client._send\npackage:json_rpc_2/src/client.dart 120:5          Client.sendRequest\npackage:json_rpc_2/src/peer.dart 98:15            Peer.sendRequest\npackage:dds/src/expression_evaluator.dart 120:38  ExpressionEvaluator._evaluateCompiledExpression\npackage:dds/src/expression_evaluator.dart 52:18   ExpressionEvaluator.execute\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 212:18         Server._handleSingleRequest\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 188:18         Server._handleRequest\n","request":{"id":"590","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"size","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"590"}
[1:00:29 PM] [VmService] <== {"jsonrpc":"2.0","error":{"code":-32000,"message":"Bad state: The client is closed.","data":{"full":"Bad state: The client is closed.","stack":"package:json_rpc_2/src/client.dart 152:19         Client._send\npackage:json_rpc_2/src/client.dart 120:5          Client.sendRequest\npackage:json_rpc_2/src/peer.dart 98:15            Peer.sendRequest\npackage:dds/src/expression_evaluator.dart 120:38  ExpressionEvaluator._evaluateCompiledExpression\npackage:dds/src/expression_evaluator.dart 52:18   ExpressionEvaluator.execute\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 212:18         Server._handleSingleRequest\n===== asynchronous gap ===========================\npackage:json_rpc_2/src/server.dart 188:18         Server._handleRequest\n","request":{"id":"591","jsonrpc":"2.0","method":"evaluate","params":{"disableBreakpoints":true,"expression":"slot","isolateId":"isolates/199456990271431","targetId":"objects/39"}}}},"id":"591"}

Any suggestions for debugging to understand what's going on? I can't reproduce it myself. This log was a verbose log, so it should've included any stdout/stderr from the Flutter tool.

wujek-srujek commented 3 years ago

Setting dart.evaluateGettersInDebugViews to false does indeed prevent the crash, but now I don't see the values...

I don't really have any suggestions, I'm not doing anything out of the ordinary (as far as I know). I updated everything that could be updated (Flutter, XCode, VSCode, ...); I even removed VSCode and ~/.vscode and installed only the necessary plugins from scratch to see what could be the issue. I am using https://github.com/leoafarias/fvm, not sure if this could be an issue (then again, debugging does work elsewhere). My OS version is macOS Catalina 10.15.7 on a Mac Book Pro (15 inch, 2018 (I can't upgrade to Big Sur yet with this computer).

I know of at least one colleague who has the same issue with their application: their project and mine, where I first stumbled upon this issue, are completely unrelated; theirs can also be debugged in Android Studio. The thing they both have in common are that they are upgraded to Flutter 2.0.1 from 1.22.6. But as you can see, I can 100% reproduce it with the simplest Flutter sample.

Let me know if you come up with an idea and I can help provider more information.

DanTup commented 3 years ago

Setting dart.evaluateGettersInDebugViews to false does indeed prevent the crash, but now I don't see the values...

Yep, I just wanted to check whether it was specifically the getters triggering this. Calling getters in the hover tooltips can have side-effects which is why there's an option - though ofcourse it's not expected that calling the getters would terminating anything.

Out of interest - does Android Studio show all of the getters in the debug view? I was under the impression it did not (which would prevent the crash), though if it is it might be interested to compare whether it's doing anything differently to VS Code.

I don't really have any other ideas, but perhaps @bkonyi or @aam may have some ideas to debug further.

bkonyi commented 3 years ago

It looks like the Flutter tooling is losing connection to the application when trying to evaluate a compiled expression:

"Bad state: The client closed with pending request \"_evaluateCompiledExpression\"

@wujek-srujek you application is dying, not just losing connection correct? If so, can you check your device logs around the time of the crash and see if there's a stack trace from the application? I'm guessing there's an issue in the VMs expression evaluation code that's causing it to crash.

wujek-srujek commented 3 years ago

Yes @bkonyi the application dies immediately. I hope this is the log that you need, it does indeed have errors inside:


Mar  9 18:54:07 laptop0637 log[66286]: log run noninteractively, parent: 7353 (launchd_sim), args: 'log' 'stream' '--style' 'json' '--predicate' 'eventType = logEvent AND processImagePath ENDSWITH "Runner" AND (senderImagePath ENDSWITH "/Flutter" OR senderImagePath ENDSWITH "/libswiftCore.dyli
Mar  9 18:54:07 laptop0637 syslogd[7355]: ASL Sender Statistics
Mar  9 18:54:07 laptop0637 diagnosticd[7403]: Posting stream filter: "{
        global = 38655164416;
        processImagePath =     {
            Runner = 34360197121;
        };
    }"
Mar  9 18:54:07 laptop0637 diagnosticd[7403]: System mode client started - log (66286) - mode: 0x8, filter: "{
        processImagePath =     {
            Runner = 1;
        };
    }"
Mar  9 18:54:25 laptop0637 Runner[66500]: assertion failed: 19H524 18D46: libxpc.dylib + 50260 [26B6416F-496E-32F6-AC9D-FFCD86331B43]: 0x7d
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.DocumentManagerCore.Downloads): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.DocumentManagerCore.Downloads): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FileProvider.ArchiveService): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FileProvider.ArchiveService): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.FontProviderLoader): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.FontProviderLoader): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.GSFontServices): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.GSFontServices): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.UserFontManager): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.FontServices.UserFontManager): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.MTLCompilerService): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.MTLCompilerService): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.StreamingUnzipService): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.StreamingUnzipService): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.backboard.display.archive): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.backboard.display.archive): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.textkit.nsattributedstringagent): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.textkit.nsattributedstringagent): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.uifoundation-bundle-helper): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.uifoundation-bundle-helper): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.xpc.launchd.domain.pid.Runner.66500): Failed to bootstrap path: path = /Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/System/Library/Frameworks/IOKit.framework/Versions/A/IOKit, error = 2: No such file or directory
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.xpc.launchd.domain.pid.Runner.66500): Failed to bootstrap path: path = /Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/usr/lib/dyld_sim, error = 2: No such file or directory
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.xpc.launchd.domain.pid.MTLCompilerService.66508): Failed to bootstrap path: path = /Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/System/Library/Frameworks/IOKit.framework/Versions/A/IOKit, error = 2: No such file or directory
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.xpc.launchd.domain.pid.MTLCompilerService.66508): Failed to bootstrap path: path = /Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/usr/lib/dyld_sim, error = 2: No such file or directory
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.MTLCompilerService): Unknown key for Boolean: EnableTransactions
Mar  9 18:54:27 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.MTLCompilerService): Unknown key for Boolean: EnablePressuredExit
Mar  9 18:54:30 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (UIKitApplication:com.example.flutterCounterSample[ce0c][rb-legacy][66500]): Service exited due to SIGSEGV | sent by exc handler[66500]
Mar  9 18:54:30 laptop0637 diagnosticd[7403]: System mode client stopped - log (66286) - clearing mode: 0x0, still active: 0x9
Mar  9 18:54:30 laptop0637 diagnosticd[7403]: Posting stream filter: "{
        global = 38655164416;
    }"
Mar  9 18:54:30 laptop0637 com.apple.CoreSimulator.SimDevice.DCA407AC-0D22-4CB5-A2EC-624AE7228EC4[7353] (com.apple.xpc.launchd.oneshot.0x1000002d.log[66286]): Service exited due to SIGTERM | sent by simctl[66283]

It is strange because the paths it complains and isn't able to find are on my system:

Screenshot 2021-03-09 at 19 02 35
bkonyi commented 3 years ago

@wujek-srujek thanks for sending logs, but I have a feeling something is being filtered out here. Can you check unfiltered logs to see if there's more details, particularly a stack trace? If you don't find more details and you can still reproduce this on Android, we might have better luck looking at logcat output.

wujek-srujek commented 3 years ago

I don't see any option to disable 'filtering'. I reproduced on my Pixel 3XL, here is the log:

03-09 19:23:53.741  1059  2017 I chatty  : uid=1010 wifi_ext@1.0-se identical 9 lines
03-09 19:23:55.749  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:23:57.616  1047  1133 I CHRE    : @ 955657.290: [AR] inconsistent: 41.176471
03-09 19:23:57.668  2691 29974 E WakeLock: GCM_HB_ALARM release without a matched acquire!
03-09 19:23:57.745  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:23:57.115  1597  1960 I chatty  : uid=1000(system) ConnectivitySer identical 2 lines
03-09 19:24:00.141  1597  1960 D ConnectivityService: NetReassign [no changes]
03-09 19:24:02.017  1597  9975 I ActivityManager: Force stopping com.example.flutter_counter_sample appid=10340 user=0: from pid 1696
03-09 19:23:59.760  1059  2017 I chatty  : uid=1010 wifi_ext@1.0-se identical 1 line
03-09 19:24:01.771  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:24:02.031  2425  2425 D CarrierSvcBindHelper: No carrier app for: 0
03-09 19:24:02.035  6219  6219 D RegisteredNfcFServicesCache: Service unchanged, not updating
03-09 19:24:02.046 31403 31403 I EuiccGoogle: [2] EuiccServiceImpl.onCreate: mSimCardState in onCreate: 11
03-09 19:24:02.047 31403 31403 I EuiccGoogle: [2] GservicesChangedReceiver.setSupportedCountries: Set eUICC supported countries to
03-09 19:24:02.047 31403 31403 I EuiccGoogle: [2] GservicesChangedReceiver.setSupportedCountries: Set eUICC unsupported countries to sg
03-09 19:24:02.058 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: slotId = 0
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.onGetEuiccProfileInfoList: slotId = 0, isRemovable = false
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: isRemovable = false.
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.getProfileInfoList: getProfileInfoList: slotId = 0.
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.getProfileInfoList: getProfileInfoList: supports HAL/P APIs
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.getEidFromSlotId: getEidFromSlotId: slotId = 0.
03-09 19:24:02.062 31403  1705 I EuiccGoogle: [17163] UiccSlotUtil.getEidForSlot: getEidForSlot: 0
03-09 19:24:02.064 31403  1705 I EuiccGoogle: [17163] BlockingEuiccCardManager.requestAllProfiles: requestAllProfiles: cardId = 89049032000001000000020780623287
03-09 19:24:02.287 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: Profile nickname = Telekom.de.
03-09 19:24:02.287 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.toUiccAccessRules: toUiccAccessRules: empty Carrier privilege rule
03-09 19:24:02.287 31403  1705 I EuiccGoogle: [17163] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: Profile info = EuiccProfileInfo (nickname=Telekom.de, serviceProviderName=null, profileName=null, profileClass=2, state=0, CarrierIdentifier=CarrierIdentifier{mcc=262,mnc=01,spn=null,imsi=null,gid1=01,gid2=FF,carrierid=-1,specificCarrierId=-1}, policyRules=0, accessRules=null).
03-09 19:24:02.291  2425  2425 D TelephonyProvider: Using old permission behavior for telephony provider compat
03-09 19:24:02.292  1597  7035 I ActivityTaskManager: START u0 {act=android.intent.action.RUN flg=0x30000000 cmp=com.example.flutter_counter_sample/.MainActivity (has extras)} from uid 2000
03-09 19:24:02.293  1597  1615 D EventSequenceValidator: inc AccIntentStartedEvents to 2
03-09 19:24:02.295  2425  2425 W SQLiteLog: (28) double-quoted string literal: "89490200001433350157"
03-09 19:24:02.297  2425  2425 I chatty  : uid=1001(radio) com.android.phone identical 1 line
03-09 19:24:02.301  2425  2425 W SQLiteLog: (28) double-quoted string literal: "89490200001433350157"
03-09 19:24:02.303  1721  1724 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
03-09 19:24:02.306  2425  2425 W SQLiteLog: (28) double-quoted string literal: "89490200001433350157"
03-09 19:24:02.307  1597  1615 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10340; state: DISABLED
03-09 19:24:02.308  1597  1632 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10340; state: ENABLED
03-09 19:24:02.308  2425  2425 D TelephonyProvider: Using old permission behavior for telephony provider compat
03-09 19:24:02.310  2425  2601 D TelephonyProvider: Using old permission behavior for telephony provider compat
03-09 19:24:02.312  2425  2425 D TelephonyProvider: Using old permission behavior for telephony provider compat
03-09 19:24:02.313  1597  7035 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  1597  7035 I chatty  : uid=1000(system) Binder:1597_1A identical 3 lines
03-09 19:24:02.314  1597  7035 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2053  6354 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2053  6038 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2334  2456 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2601 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2053  2053 V KeyguardUpdateMonitor: onSubscriptionInfoChanged()
03-09 19:24:02.314  2425  2978 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2601 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2473 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2723 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  3138  3154 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2585 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  3068 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2032 28223 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  2425  2600 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.314  6242  8557 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.315  2425 11767 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.315  2425  2562 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.315  6242 12706 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.315  2425  2425 D MultiSimSettingController: notifySubscriptionInfoChanged
03-09 19:24:02.315  2425 10277 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.315  2032 29875 I HeadsetPhoneState: stopListenForPhoneState(), no listener indicates nothing is listening
03-09 19:24:02.315  2032 29875 W HeadsetPhoneState: startListenForPhoneState, no event to listen
03-09 19:24:02.317  2425  2425 D CallNotifier: updatePhoneStateListeners: update CF notifications.
03-09 19:24:02.317  2425  2425 I NotificationMgr: updateCfi: subId= 2, visible=N
03-09 19:24:02.317  2053  2053 V KeyguardUpdateMonitor: SubInfo:{id=2 iccId=894902000[****] simSlotIndex=0 carrierId=3 displayName=Telekom.de carrierName=Telekom.de nameSource=2 iconTint=-16746133 number=[****] dataRoaming=1 iconBitmap=android.graphics.Bitmap@255563f mcc=262 mnc=01 countryIso=de isEmbedded=true nativeAccessRules=null cardString=890490320[****] cardId=0 isOpportunistic=false groupUUID=null isGroupDisabled=false profileClass=2 ehplmns=[] hplmns=[26201, 26201] subscriptionType=0 groupOwner=null carrierConfigAccessRules=null areUiccApplicationsEnabled=true}
03-09 19:24:02.318  2425  2425 I NotificationMgr: updateMwi(): subId 2 update to false
03-09 19:24:02.323  3138  4173 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.323 31095 31737 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.323 30167 30386 D TelephonyRegistryManager: onSubscriptionsChangedListener callback received.
03-09 19:24:02.324  2334  2438 I QCNEJ   : |CORE| phoneCount: 1
03-09 19:24:02.324  2425  2425 I Telephony: TelecomAccountRegistry: onSubscriptionsChanged - update accounts
03-09 19:24:02.324  2425  2425 I Telephony: PstnIncomingCallNotifier: Unregistering: Handler (com.android.internal.telephony.GsmCdmaPhone) {a2fa277}
03-09 19:24:02.324  2425  2425 D Telephony: Unregistering: Handler (com.android.internal.telephony.GsmCdmaPhone) {a2fa277}
03-09 19:24:02.324 31095 31321 I CarrierServices: [9273] cpn.c: SIM delay is not enabled
03-09 19:24:02.324 30167 30167 I Finsky  : [2] lax.onSubscriptionsChanged(1): onSubscriptionsChanged
03-09 19:24:02.327  2425  2425 I ImsCallbackAM [0]: Local callback removed: android.telephony.ims.ImsMmTelManager$CapabilityCallback$CapabilityBinder@a6fdf36
03-09 19:24:02.327  1016  1016 D Zygote  : Forked child process 1726
03-09 19:24:02.328  2425  2425 I ImsCallbackAM [0]: Local callback removed: android.telephony.ims.RegistrationManager$RegistrationCallback$RegistrationBinder@168ae37
03-09 19:24:02.328  2425  2425 I Telephony: TelecomAccountRegistry: setupAccounts: Found 1 phones.  Attempting to register.
03-09 19:24:02.328  2425  2425 I Telephony: TelecomAccountRegistry: setupAccounts: Phone with subscription id 2
03-09 19:24:02.328 32137 32137 I DialerLegacyVoicemailNotificationReceiver: com.android.dialer.app.calllog.LegacyVoicemailNotificationReceiver.onReceive:106 received legacy voicemail notification
03-09 19:24:02.328 32137 32165 I DialerLegacyVoicemailNotificationReceiver: com.android.dialer.app.calllog.LegacyVoicemailNotificationReceiver.handleNotification:140 isRefresh: true
03-09 19:24:02.328 32137 32165 I DialerLegacyVoicemailNotificationReceiver: com.android.dialer.app.calllog.LegacyVoicemailNotificationReceiver.handleNotification:159 clearing notification
03-09 19:24:02.328 32137 32165 I DialerLegacyVoicemailNotifier: com.android.dialer.app.calllog.LegacyVoicemailNotifier.cancelNotification:174 enter
03-09 19:24:02.330  1597  1632 I ActivityManager: Start proc 1726:com.example.flutter_counter_sample/u0a340 for pre-top-activity {com.example.flutter_counter_sample/com.example.flutter_counter_sample.MainActivity}
03-09 19:24:02.332 31095 31321 I CarrierServices: [9273] cpj.V: (Sim): Processing an intent
03-09 19:24:02.332  2425  2425 D Telephony: isEmergencyPreferredAccount: subId=2, activeData=2
03-09 19:24:02.332  2425  2425 D Telephony: isEmergencyPreferredAccount: one or less active subscriptions.
03-09 19:24:02.335 31095 31321 I CarrierServices: [9273] cpj.s: (Sim): Ignoring duplicate SIM state: LOADED
03-09 19:24:02.336  2425  2425 I Telephony: isRttCurrentlySupported -- regular acct, hasVoiceAvailability: false
03-09 19:24:02.336  2425  2425 I Telephony:  isRttSupported: false
03-09 19:24:02.336  2425  2425 I Telephony:  isRoaming: false
03-09 19:24:02.336  2425  2425 I Telephony:  isOnWfc: false
03-09 19:24:02.338  1726  1726 I _counter_sampl: Late-enabling -Xcheck:jni
03-09 19:24:02.348  1597  2969 I Telecom : PhoneAccountRegistrar: Modify account: [ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}]: TSI.rPA@Rss
03-09 19:24:02.350  1597  2969 I Telecom : CallsManager: handlePhoneAccountChanged: phoneAccount=[[X] PhoneAccount: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0} Capabilities: CallProvider MultiUser PlaceEmerg SimSub  Audio Routes: BESW Schemes: tel voicemail  Extras: Bundle[{android.telecom.extra.SUPPORTS_VIDEO_CALLING_FALLBACK=true, android.telecom.extra.SUPPORTS_HANDOVER_FROM=true}] GroupId: ***]: TSI.rPA@Rss
03-09 19:24:02.351  2425  2425 I Telephony: AccountEntry: Registered phoneAccount: [[ ] PhoneAccount: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0} Capabilities: CallProvider MultiUser PlaceEmerg SimSub  Audio Routes: BESW Schemes: tel voicemail  Extras: Bundle[{android.telecom.extra.SUPPORTS_VIDEO_CALLING_FALLBACK=true, android.telecom.extra.SUPPORTS_HANDOVER_FROM=true}] GroupId: ***] with handle: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}
03-09 19:24:02.351  2425  2425 I Telephony: PstnIncomingCallNotifier: Registering: Handler (com.android.internal.telephony.GsmCdmaPhone) {a2fa277}
03-09 19:24:02.351  2425  2425 D Telephony: Registering: Handler (com.android.internal.telephony.GsmCdmaPhone) {a2fa277}
03-09 19:24:02.352  2425  2425 I ImsCallbackAM [0]: Local callback added: android.telephony.ims.ImsMmTelManager$CapabilityCallback$CapabilityBinder@e96bf3c
03-09 19:24:02.352  2425  2425 I ImsCallbackAM [0]: Local callback added: android.telephony.ims.RegistrationManager$RegistrationCallback$RegistrationBinder@8dbe4c5
03-09 19:24:02.354  2425  2425 D QtiCarrierConfigHelper: Reload carrier configs on sub Id due sub changed: 2
03-09 19:24:02.355  2425  2425 D QtiCarrierConfigHelper: Load carrier configs on sub Id: 2 slot Id: 0
03-09 19:24:02.356  2425  2425 D MultiSimSettingController: onSubscriptionsChanged
03-09 19:24:02.356  2425  2425 D MultiSimSettingController: updateDefaults
03-09 19:24:02.356  2425  2425 D MultiSimSettingController: [updateDefaultValues] change: 0
03-09 19:24:02.357  2425  2425 I ImsExternalCallTracker: handleVideoCapabilitiesChanged : isVideoCapable = false
03-09 19:24:02.357  2425  2425 D ImsExternalCallTracker: refreshCallPullState
03-09 19:24:02.357  2425  2425 I Telephony: handleVideoCapabilitesChanged. Video capability - false
03-09 19:24:02.359  1726  1726 I _counter_sampl: Unquickening 12 vdex files!
03-09 19:24:02.359  2425  2425 D Telephony: isEmergencyPreferredAccount: subId=2, activeData=2
03-09 19:24:02.359  2425  2425 D Telephony: isEmergencyPreferredAccount: one or less active subscriptions.
03-09 19:24:02.359  2425  2425 I ImsCallbackAM [0]: Local callback added: android.telephony.ims.ImsMmTelManager$CapabilityCallback$CapabilityBinder@e96bf3c
03-09 19:24:02.362  2425  2425 I Telephony: isRttCurrentlySupported -- regular acct, hasVoiceAvailability: false
03-09 19:24:02.362  2425  2425 I Telephony:  isRttSupported: false
03-09 19:24:02.362  2425  2425 I Telephony:  isRoaming: false
03-09 19:24:02.362  2425  2425 I Telephony:  isOnWfc: false
03-09 19:24:02.365  1321  1434 I adbd    : jdwp connection from 1726
03-09 19:24:02.374  1597  2969 I Telecom : PhoneAccountRegistrar: Modify account: [ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}]: TSI.rPA@Rs0
03-09 19:24:02.376  1597  2969 I Telecom : CallsManager: handlePhoneAccountChanged: phoneAccount=[[X] PhoneAccount: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0} Capabilities: CallProvider MultiUser PlaceEmerg SimSub  Audio Routes: BESW Schemes: tel voicemail  Extras: Bundle[{android.telecom.extra.SUPPORTS_VIDEO_CALLING_FALLBACK=true, android.telecom.extra.SUPPORTS_HANDOVER_FROM=true}] GroupId: ***]: TSI.rPA@Rs0
03-09 19:24:02.378  2425  2425 I Telephony: isRttCurrentlySupported -- regular acct, hasVoiceAvailability: true
03-09 19:24:02.378  2425  2425 I Telephony:  isRttSupported: false
03-09 19:24:02.378  2425  2425 I Telephony:  isRoaming: false
03-09 19:24:02.378  2425  2425 I Telephony:  isOnWfc: false
03-09 19:24:02.380  2425  2425 I Telephony: isRttCurrentlySupported -- regular acct, hasVoiceAvailability: true
03-09 19:24:02.380  2425  2425 I Telephony:  isRttSupported: false
03-09 19:24:02.380  2425  2425 I Telephony:  isRoaming: false
03-09 19:24:02.380  2425  2425 I Telephony:  isOnWfc: false
03-09 19:24:02.406 15004 15042 I MicroDetectionState: Should stop hotword detection immediately - false
03-09 19:24:02.415  1597  1617 W Choreographer: Frame time is 0.208156 ms in the future!  Check that graphics HAL is generating vsync timestamps using the correct timebase.
03-09 19:24:02.415  2053  2053 W Choreographer: Frame time is 0.208364 ms in the future!  Check that graphics HAL is generating vsync timestamps using the correct timebase.
03-09 19:24:02.441  1726  1726 D NetworkSecurityConfig: No Network Security Config specified, using platform default
03-09 19:24:02.441  1726  1726 D NetworkSecurityConfig: No Network Security Config specified, using platform default
03-09 19:24:02.476  1726  1768 I ResourceExtractor: Found extracted resources res_timestamp-1-1615314019831
03-09 19:24:02.481  1726  1726 W _counter_sample: type=1400 audit(0.0:54319): avc: denied { read } for name="max_map_count" dev="proc" ino=22276588 scontext=u:r:untrusted_app:s0:c84,c257,c512,c768 tcontext=u:object_r:proc_max_map_count:s0 tclass=file permissive=0 app=com.example.flutter_counter_sample
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: QUALCOMM build                   : ef9bae8, Ia11ce2d146
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Build Date                       : 09/02/20
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: OpenGL ES Shader Compiler Version: EV031.31.04.00
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Local Branch                     : gfx-adreno.lnx.2.0
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Remote Branch                    :
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Remote Branch                    :
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Reconstruct Branch               :
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Build Config                     : C P 11.0.1 AArch64
03-09 19:24:02.497  1726  1726 I AdrenoGLES-0: Driver Path                      : /vendor/lib64/egl/libGLESv2_adreno.so
03-09 19:24:02.502  1726  1726 I AdrenoGLES-0: PFP: 0x016ee189, ME: 0x00000000
03-09 19:24:02.505  1726  1726 W AdrenoUtils: <ReadGpuID_from_sysfs:197>: Failed to open /sys/class/kgsl/kgsl-3d0/gpu_model
03-09 19:24:02.505  1726  1726 W AdrenoUtils: <ReadGpuID:221>: Failed to read chip ID from gpu_model. Fallback to use the GSL path
03-09 19:24:02.535  1726  1726 W _counter_sampl: Accessing hidden method Landroid/view/accessibility/AccessibilityNodeInfo;->getSourceNodeId()J (greylist,test-api, reflection, allowed)
03-09 19:24:02.535  1726  1726 W _counter_sampl: Accessing hidden method Landroid/view/accessibility/AccessibilityRecord;->getSourceNodeId()J (greylist, reflection, allowed)
03-09 19:24:02.535  1726  1726 W _counter_sampl: Accessing hidden field Landroid/view/accessibility/AccessibilityNodeInfo;->mChildNodeIds:Landroid/util/LongArray; (greylist, reflection, allowed)
03-09 19:24:02.535  1726  1726 W _counter_sampl: Accessing hidden method Landroid/util/LongArray;->get(I)J (greylist, reflection, allowed)
03-09 19:24:02.645  1726  1792 I flutter : Observatory listening on http://127.0.0.1:40257/KicgcDqeqvg=/
03-09 19:24:02.788   665   665 I hwservicemanager: getTransport: Cannot find entry android.hardware.graphics.mapper@4.0::IMapper/default in either framework or device manifest.
03-09 19:24:02.788  1726  1764 I Gralloc4: mapper 4.x is not supported
03-09 19:24:02.788   665   665 I hwservicemanager: getTransport: Cannot find entry android.hardware.graphics.mapper@3.0::IMapper/default in either framework or device manifest.
03-09 19:24:02.789  1726  1764 W Gralloc3: mapper 3.x is not supported
03-09 19:24:02.790  1726  1764 E libc    : Access denied finding property "vendor.gralloc.disable_ahardware_buffer"
03-09 19:24:02.797  1597  1630 D ArtManagerInternalImpl: /data/misc/iorapd/com.example.flutter_counter_sample/1/com.example.flutter_counter_sample.MainActivity/compiled_traces/compiled_trace.pb doesn't exist
03-09 19:24:02.798  1597  1630 I ActivityTaskManager: Displayed com.example.flutter_counter_sample/.MainActivity: +504ms
03-09 19:24:02.799  1597  1615 D EventSequenceValidator: dec AccIntentStartedEvents to 1
03-09 19:24:02.814 26190 26190 I GoogleInputMethodService: GoogleInputMethodService.onFinishInput():3311
03-09 19:24:02.815 26190 26190 I GoogleInputMethodService: GoogleInputMethodService.onStartInput():1914
03-09 19:24:02.816 15004 28623 I PBSessionCacheImpl: Deleted sessionId[65989905151942408] from persistence.
03-09 19:24:02.822 15004 15042 W SearchServiceCore: Abort, client detached.
03-09 19:24:02.823 15004 15042 I A       : cleanUpControllerScope(nowcards-15-38d54629-d2c5)
03-09 19:24:03.157  1597  1960 D ConnectivityService: NetReassign [no changes]
03-09 19:24:03.770  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:24:03.772  1321  1321 W adbd    : timeout expired while flushing socket, closing
03-09 19:24:05.777  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:24:06.449  1726  1770 F libc    : Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 1770 (1.ui), pid 1726 (_counter_sample)
03-09 19:24:06.570  1806  1806 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
03-09 19:24:06.570   996   996 I tombstoned: received crash request for pid 1770
03-09 19:24:06.571  1806  1806 I crash_dump64: performing dump of process 1726 (target tid = 1770)
03-09 19:24:06.577  1806  1806 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
03-09 19:24:06.577  1806  1806 F DEBUG   : Build fingerprint: 'google/crosshatch/crosshatch:11/RQ1A.210205.004/7038034:user/release-keys'
03-09 19:24:06.577  1806  1806 F DEBUG   : Revision: 'MP1.0'
03-09 19:24:06.577  1806  1806 F DEBUG   : ABI: 'arm64'
03-09 19:24:06.578  1806  1806 F DEBUG   : Timestamp: 2021-03-09 19:24:06+0100
03-09 19:24:06.578  1806  1806 F DEBUG   : pid: 1726, tid: 1770, name: 1.ui  >>> com.example.flutter_counter_sample <<<
03-09 19:24:06.578  1806  1806 F DEBUG   : uid: 10340
03-09 19:24:06.578  1806  1806 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
03-09 19:24:06.578  1806  1806 F DEBUG   : Cause: null pointer dereference
03-09 19:24:06.578  1806  1806 F DEBUG   :     x0  0000000000000000  x1  0000000000000000  x2  000000768a9a9b80  x3  000000768a9a9b90
03-09 19:24:06.578  1806  1806 F DEBUG   :     x4  000000768a9a9b50  x5  000000768a9a9ae0  x6  5b4dec3676f1f5e1  x7  fefeff7558ff3734
03-09 19:24:06.578  1806  1806 F DEBUG   :     x8  0000000000000000  x9  00000074ee4cf618  x10 00000074ee5ee668  x11 000000000000001a
03-09 19:24:06.578  1806  1806 F DEBUG   :     x12 8000000000000000  x13 ffffffffffffffff  x14 ffffffff00000000  x15 ffffffffffffffff
03-09 19:24:06.578  1806  1806 F DEBUG   :     x16 00000074ee520000  x17 00000077ed08a520  x18 00000074eb258000  x19 00000074eb95bd68
03-09 19:24:06.578  1806  1806 F DEBUG   :     x20 00000074eb95b9b8  x21 0000000000000000  x22 0000000000000000  x23 00000074eb95b9d8
03-09 19:24:06.578  1806  1806 F DEBUG   :     x24 00000074eb95b9c0  x25 000000768a9a9ab0  x26 000000768a9a9b00  x27 00000075ea991ad0
03-09 19:24:06.578  1806  1806 F DEBUG   :     x28 0000000000000000  x29 000000000000003d
03-09 19:24:06.578  1806  1806 F DEBUG   :     lr  00000074ee1b9a38  sp  00000074eb95b950  pc  00000074ee1b9a3c  pst 0000000020000000
03-09 19:24:06.667  1806  1806 F DEBUG   : backtrace:
03-09 19:24:06.667  1806  1806 F DEBUG   :       #00 pc 000000000174da3c  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.667  1806  1806 F DEBUG   :       #01 pc 000000000174e3c0  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #02 pc 00000000017786ac  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #03 pc 0000000001820d50  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #04 pc 0000000001818bd4  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #05 pc 000000000181918c  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #06 pc 0000000001736258  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #07 pc 000000000175a414  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #08 pc 000000000175a7a8  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #09 pc 0000000001a04d50  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #10 pc 000000000173aa68  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #11 pc 000000000171bdfc  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #12 pc 0000000001723b14  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #13 pc 0000000001724348  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #14 pc 000000000180f738  /data/app/~~HTU9hTZuU5KmhR8bm5WzRg==/com.example.flutter_counter_sample-RVPVQ7r2cbd9mR7qesKx4A==/lib/arm64/libflutter.so (BuildId: 4f453a1bb64d1244a9dd8bd68e926b4779043b43)
03-09 19:24:06.668  1806  1806 F DEBUG   :       #15 pc 0000000000002968  <anonymous:74dcd80000>
03-09 19:24:06.186  1597  1960 D ConnectivityService: NetReassign [no changes]
03-09 19:24:06.911  1597  1810 I DropBoxManagerService: add tag=data_app_native_crash isTagEnabled=true flags=0x2
03-09 19:24:06.911  1597  1809 W ActivityTaskManager:   Force finishing activity com.example.flutter_counter_sample/.MainActivity
03-09 19:24:06.927   996   996 E tombstoned: Tombstone written to: /data/tombstones/tombstone_11
03-09 19:24:06.930  1597  1643 I BootReceiver: Copying /data/tombstones/tombstone_11 to DropBox (SYSTEM_TOMBSTONE)
03-09 19:24:06.931  1597  1643 I DropBoxManagerService: add tag=SYSTEM_TOMBSTONE isTagEnabled=true flags=0x2
03-09 19:24:06.934  1597  1631 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
03-09 19:24:06.934  1597  1631 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
03-09 19:24:06.948  1597  1631 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
03-09 19:24:06.948  1597  1631 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
03-09 19:24:06.959  1016  1016 I Zygote  : Process 1726 exited due to signal 11 (Segmentation fault)
03-09 19:24:06.960  1597  6331 I WindowManager: WIN DEATH: Window{8ee095e u0 com.example.flutter_counter_sample/com.example.flutter_counter_sample.MainActivity}
03-09 19:24:06.960  1597  6331 W InputDispatcher: Attempted to unregister already unregistered input channel '8ee095e com.example.flutter_counter_sample/com.example.flutter_counter_sample.MainActivity (server)'
03-09 19:24:06.960  1597  6784 I ActivityManager: Process com.example.flutter_counter_sample (pid 1726) has died: prcp CRE
03-09 19:24:06.976  1597  1615 W ActivityManager: setHasOverlayUi called on unknown pid: 1726
03-09 19:24:07.006  1597  1633 I libprocessgroup: Successfully killed process cgroup uid 10340 pid 1726 in 45ms
03-09 19:24:07.025 15004 15044 W ThreadPoolDumper: Queue length for executor EventBus is now 11. Perhaps some tasks are too long, or the pool is too small.
03-09 19:24:07.037 15004 15042 I A       : registerScope: nowcards-15-38d54629-d2c5
03-09 19:24:07.040 26190 26190 I GoogleInputMethodService: GoogleInputMethodService.onFinishInput():3311
03-09 19:24:07.041 26190 26190 I GoogleInputMethodService: GoogleInputMethodService.onStartInput():1914
03-09 19:24:07.056 15004 15042 I MicroDetectionState: Should stop hotword detection immediately - false
03-09 19:24:07.056 15004 15004 I BgTaskExecutorImpl: Starting EXCLUSIVE background task TNG_MINUS_ONE_SYNC.
03-09 19:24:07.056 15004 15004 I BgTaskExecutorImpl: Starting EXCLUSIVE background task TNG_VOICE_SEARCH_SYNC.
03-09 19:24:07.057 15004 15042 I MicroDetectionState: Keep running DSP hotword
03-09 19:24:07.058 15004 15042 I TngMinusOneSync: Syncing TNG:-1
03-09 19:24:07.060 15004 15042 I TngVoiceSearchSync: Syncing TNG:VoiceSearch
03-09 19:24:07.787  1059  2017 I WifiHAL : event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xd
03-09 19:24:08.795  1321  1321 W adbd    : timeout expired while flushing socket, closing
03-09 19:24:09.216  1597  1960 D ConnectivityService: NetReassign [no changes]

The line 03-09 19:24:06.449 1726 1770 F libc : Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 1770 (1.ui), pid 1726 (_counter_sample) is the one that is the first line once I start hovering over a variable.

bkonyi commented 3 years ago

Awesome, thanks for grabbing those! It does indeed look like we're crashing in the VM, but it's unfortunate that the stack isn't symbolized so I'll try and reproduce myself. You're running on OSX, correct?

wujek-srujek commented 3 years ago

This is my computer and system information:

Screenshot 2021-03-09 at 19 39 05

Let me know if I can provide any more info that would be of any help.

aam commented 3 years ago

@flutter-symbolizer-bot engine#40441def692f444660a11e20fac37af9050245ab https://github.com/Dart-Code/Dart-Code/issues/3185#issuecomment-794274068 android debug arm64

aam commented 3 years ago

Thank you @wujek-srujek . Symbolicated stack trace from https://github.com/Dart-Code/Dart-Code/issues/3185#issuecomment-794274068 looks like this

third_party/dart/runtime/vm/kernel_binary.h:?
third_party/dart/runtime/vm/kernel_binary.cc:235
third_party/dart/runtime/vm/object.cc:13116
third_party/dart/runtime/vm/service.cc:3049
third_party/dart/runtime/vm/service.cc:927
third_party/dart/runtime/vm/service.cc:975
third_party/dart/runtime/vm/isolate.cc:1344
third_party/dart/runtime/vm/message_handler.cc:233
third_party/dart/runtime/vm/message_handler.cc:342
third_party/dart/runtime/vm/dart_api_impl.cc:2092
third_party/dart/runtime/vm/isolate.cc:3369
third_party/dart/runtime/vm/debugger.cc:3080
third_party/dart/runtime/vm/debugger.cc:3509
third_party/dart/runtime/vm/debugger.cc:3735
third_party/dart/runtime/vm/runtime_entry.cc:1070
aam commented 3 years ago

@wujek-srujek We are trying to reproduce the failure locally, however meanwhile could you add print statement to the vmservice.dart per below diff, remove flutter_tools.dart.snapshot from flutter/bin/cache folder, run flutter doctor to rebuild that snapshot and retry reproducing the crash from the vscode capturing Dart: Capture Debugging Logs again hopefully with that additional printed data?

diff --git a/packages/flutter_tools/lib/src/vmservice.dart b/packages/flutter_tools/lib/src/vmservice.dart
index 5178606557..1452209ac4 100644
--- a/packages/flutter_tools/lib/src/vmservice.dart
+++ b/packages/flutter_tools/lib/src/vmservice.dart
@@ -239,6 +239,9 @@ vm_service.VmService setUpVmService(
       final String kernelBytesBase64 = await compileExpression(isolateId,
           expression, definitions, typeDefinitions, libraryUri, klass,
           isStatic);
+
+      print('compileExpression expression: $expression, $isolateId, $definitions, $typeDefinitions, $libraryUri, $klass, $isStatic -> $kernelBytesBase64');
+
       return <String, dynamic>{
         'type': 'Success',
         'result': <String, dynamic>{'kernelBytes': kernelBytesBase64},
wujek-srujek commented 3 years ago

Here is the output file: Dart-Code-Log-2021-02-03 08-49-55.txt

aam commented 3 years ago

Thank you @wujek-srujek ! Looks like some compile expression request do indeed come back empty:

[8:50:28 AM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== compileExpression expression: debugDoingBuild, isolates/1644654122391867, [], [], package:flutter/src/widgets/framework.dart, StatefulElement, false ->

I couldn't reproduce the problem locally (setting breakpoint, inspecting context works fine), so can I ask you to add some more tracing to the code and share the output? Thanks!

diff --git a/packages/flutter_tools/lib/src/compile.dart b/packages/flutter_tools/lib/src/compile.dart
index 49e224c802..fd1b4a6b0a 100644
--- a/packages/flutter_tools/lib/src/compile.dart
+++ b/packages/flutter_tools/lib/src/compile.dart
@@ -89,6 +89,7 @@ class StdoutHandler {
   bool _expectSources;

   void handler(String message) {
+    _logger.printTrace('handler: $message');
     const String kResultPrefix = 'result ';
     if (boundaryKey == null && message.startsWith(kResultPrefix)) {
       boundaryKey = message.substring(kResultPrefix.length);
@@ -645,6 +646,7 @@ class DefaultResidentCompiler implements ResidentCompiler {
       _artifacts.getArtifactPath(Artifact.engineDartBinary),
       '--disable-dart-dev',
       frontendServer,
+      '--verbose',
       '--sdk-root',
       sdkRoot,
       '--incremental',
@@ -762,6 +764,7 @@ class DefaultResidentCompiler implements ResidentCompiler {
     _server.stdin
       ..writeln('compile-expression $inputKey')
       ..writeln(request.expression);
+    _logger.printTrace('<- compileExpression ${request.expression}');
     request.definitions?.forEach(_server.stdin.writeln);
     _server.stdin.writeln(inputKey);
     request.typeDefinitions?.forEach(_server.stdin.writeln);
diff --git a/packages/flutter_tools/lib/src/run_hot.dart b/packages/flutter_tools/lib/src/run_hot.dart
index 5bc1af09b6..042efd9091 100644
--- a/packages/flutter_tools/lib/src/run_hot.dart
+++ b/packages/flutter_tools/lib/src/run_hot.dart
@@ -158,8 +158,12 @@ class HotRunner extends ResidentRunner {
         final CompilerOutput compilerOutput =
             await device.generator.compileExpression(expression, definitions,
                 typeDefinitions, libraryUri, klass, isStatic);
+        print('_compileExpressionService compilerOutput: $compilerOutput');
         if (compilerOutput != null && compilerOutput.outputFilename != null) {
-          return base64.encode(globals.fs.file(compilerOutput.outputFilename).readAsBytesSync());
+          print('_compileExpressionService compilerOutput filename: ${compilerOutput.outputFilename} filesize:${globals.fs.file(compilerOutput.outputFilename).lengthSync()}');
+          final encoded = base64.encode(globals.fs.file(compilerOutput.outputFilename).readAsBytesSync());
+          print('_compileExpressionService compilerOutput encoded: $encoded');
+          return encoded;
         }
       }
     }
wujek-srujek commented 3 years ago

Sure, here it is: Dart-Code-Log-2021-02-03 17-03-44.txt

aam commented 3 years ago

Thank you, very helpful @wujek-srujek Looking at the section below I think we have a race where several compilation requests running simultaneously, later one overriding the binary file app.dill.incremental.dill with results of previous compilation(evaluation of debugDoingBuild overridden by evaluation of depth):

5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [  +60 ms] <- compileExpression debugDoingBuild
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [        ] handler: result d4292fa3-a1a8-4139-82a2-49149b07dba9
...
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [        ] handler: d4292fa3-a1a8-4139-82a2-49149b07dba9 /var/folders/h6/bzbblf890cnbtp6fv4_b_75h0000gp/T/flutter_tools.UhuQRJ/flutter_tool.myaAgL/app.dill.incremental.dill 0
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [        ] <- compileExpression depth
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput: Instance of 'CompilerOutput'
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput filename: /var/folders/h6/bzbblf890cnbtp6fv4_b_75h0000gp/T/flutter_tools.UhuQRJ/flutter_tool.myaAgL/app.dill.incremental.dill filesize:400
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput encoded:
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== compileExpression expression: debugDoingBuild, isolates/3609183885116199, [], [], package:flutter/src/widgets/framework.dart, StatefulElement, false ->
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [   +3 ms] handler: result 3e8d53c8-34bb-49e1-ab8d-d3f5e00b0801
...
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [        ] handler: 3e8d53c8-34bb-49e1-ab8d-d3f5e00b0801 /var/folders/h6/bzbblf890cnbtp6fv4_b_75h0000gp/T/flutter_tools.UhuQRJ/flutter_tool.myaAgL/app.dill.incremental.dill 0
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== [        ] <- compileExpression dirty
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput: Instance of 'CompilerOutput'
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput filename: /var/folders/h6/bzbblf890cnbtp6fv4_b_75h0000gp/T/flutter_tools.UhuQRJ/flutter_tool.myaAgL/app.dill.incremental.dill filesize:400
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== _compileExpressionService compilerOutput encoded: kKvN7wAAADY3MmMxOTk1MDAxAAICDAEAAAAAAAAAAAECAgAAAAAAAQAAAWACBgAAAAABBgQBAAAAAABAAgAAAQMAAAAAAAAAAABbAUoAARYBLgMJAAAAAAAzAAAAVQAAAAEAAAABAQAAAGUAAAAgAAAAYgAAAAEAAABlAAAAAAAAAAIAAAAAAC1vcmctZGFydGxhbmctZGVidWc6c3ludGhldGljX2RlYnVnX2V4cHJlc3Npb24AAAAAAAAAgwAAAIgJAAQBAQIFAwIABgUHBQgHCQgDAAAAAAAAAAoACxAVJCxWZm11I0RlYnVnQ2xhc3M6RXZhbGRlcHRoZXZhbHVhdGU6c291cmNlQG1ldGhvZHNwYWNrYWdlOmZsdXR0ZXIvc3JjL3dpZGdldHMvZnJhbWV3b3JrLmRhcnRDb21wb25lbnRFbGVtZW50RWxlbWVudEBnZXR0ZXJzAAAAAAAAAH8AAADCAAAA2AAAANgAAADcAAABXAAAAAAAAAAAAAAAEwAAAH8AAAABAAABkA==
[5:04:21 PM] [FlutterRun] [Info] [Flutter (iPhone Xs)] <== compileExpression expression: depth, isolates/3609183885116199, [], [], package:flutter/src/widgets/framework.dart, StatefulElement, false -> kKvN7wAAADY3MmMxOTk1MDAxAAICDAEAAAAAAAAAAAECAgAAAAAAAQAAAWACBgAAAAABBgQBAAAAAABAAgAAAQMAAAAAAAAAAABbAUoAARYBLgMJAAAAAAAzAAAAVQAAAAEAAAABAQAAAGUAAAAgAAAAYgAAAAEAAABlAAAAAAAAAAIAAAAAAC1vcmctZGFydGxhbmctZGVidWc6c3ludGhldGljX2RlYnVnX2V4cHJlc3Npb24AAAAAAAAAgwAAAIgJAAQBAQIFAwIABgUHBQgHCQgDAAAAAAAAAAoACxAVJCxWZm11I0RlYnVnQ2xhc3M6RXZhbGRlcHRoZXZhbHVhdGU6c291cmNlQG1ldGhvZHNwYWNrYWdlOmZsdXR0ZXIvc3JjL3dpZGdldHMvZnJhbWV3b3JrLmRhcnRDb21wb25lbnRFbGVtZW50RWxlbWVudEBnZXR0ZXJzAAAAAAAAAH8AAADCAAAA2AAAANgAAADcAAABXAAAAAAAAAAAAAAAEwAAAH8AAAABAAABkA==
aam commented 3 years ago

@DanTup do you do anything special to ensure that you get a response from first expression evaluation request before sending next one?

aam commented 3 years ago

cc @jonahwilliams

DanTup commented 3 years ago

@DanTup do you do anything special to ensure that you get a response from first expression evaluation request before sending next one?

Nope, nothing 😬

We deliberately send them all at the same time (because there can be a few when evaluating getters and otherwise it'd be quite slow). My understanding was that this was ok (I think @bkonyi Ben did some perf testing this way, because we'd previously asked for a "batch evaluation" mode but it seemed like this way was easier).

aam commented 3 years ago

I think compile(compile-expression) facility should handle concurrent requests without problems. It serializes those requests as they come in. But the code that reads result of the every compilation request(dill file) is outside of that serialization section, so previous dill file might get overridden by the time next compilation request is processed before the file was actually read https://github.com/flutter/flutter/blob/master/packages/flutter_tools/lib/src/run_hot.dart#L169.

aam commented 3 years ago

To reproduce the problem one can introduce await Future<dynamic>.delayed(Duration(seconds: 1)); before https://github.com/flutter/flutter/blob/master/packages/flutter_tools/lib/src/run_hot.dart#L169 and observe how lots of variables in VSCode Variables view are evaluated to the same value(using same repro as above - breakpoint in build method in sample flutter counter app). Not sure why in @wujek-srujek's case observed dill file is empty, but the root cause is the same: dill file is being written over before it was read.

jonahwilliams commented 3 years ago

I think we could fix this by reading the dill into memory before we return from the compile expression. Will take a look

jonahwilliams commented 3 years ago

Here is my attempt at fixing it: https://github.com/flutter/flutter/pull/77867

aam commented 3 years ago

The fix landed few days ago, @wujek-srujek will you be able to confirm that the issue is fixed for you on latest flutter master channel?

wujek-srujek commented 3 years ago

Sorry, I wasn't aware of it.

~Sadly, I still have the same crash, the versions I'm testing it against:~

Flutter 2.1.0-13.0.pre.104 • channel master • https://github.com/flutter/flutter.git
Framework • revision 5be3f215ed (42 minutes ago) • 2021-03-16 08:35:00 +0100
Engine • revision 20375cebcf
Tools • Dart 2.13.0 (build 2.13.0-137.0.dev)

Edit: after restarting VSCode it works fine! I also tested it using my bigger, more complex app. Thank you.

Two questions:

  1. For my understanding (I find it highly unusual that only I can reproduce this issue): have there been any changes to the tool after 1.22.6 that broke it in 2.0.0?
  2. Could this fix be backported to the 2.0.x line, or will we have to wait for 2.1.0? (I upgrade often and early, but can't use pre-releases).
aam commented 3 years ago

Glad it is working for you. I think this has been broken for a while, it's just failed in more subtle way where evaluated expressions in IDE were wrong(several fields might show up as having same value(as the temporary file on disk with evaluated expression was reused).I would love to know why it behaved differently for you(where the file was actually empty). Yes, I think this is a good candidate for a cherry-pick.

wujek-srujek commented 3 years ago

Hi guys, Flutter 2.0.3 is out and this commit apparently hasn't made the cut. Is there anything I can do to help? I'm afraid I will otherwise need to wait a few months for a Flutter version to come out which does incorporate the fix. Should I create a a cherry-pick PR? (which branch?)

aam commented 3 years ago

@wujek-srujek sorry, see comments on cherry-pick request https://github.com/flutter/flutter/issues/77728#issuecomment-801447720

wujek-srujek commented 3 years ago

@aam Do I understand correctly: the stable channel only has releases every fifth minor release, e.g. 1.12, 1.17, 1.22. This means I can expect this fix to land on stable in 2.5, which will be in about 6 months (this is the timeframe between 1.12 and 1.17, and 1.17 and 1.22)?

DanTup commented 3 years ago

@wujek-srujek it's probably best to follow up about that in the Flutter issue. I don't think they pre-announce dates, although there's a little info in the wiki here which suggests beta releases are approximately monthly (although I don't know whether using a beta branch is viable for you).

I'll close this as fixed upstream as there's nothing to do in the VS Code extension - once upgraded to an SDK with the fix, it will automatically apply without requiring any changes here.