[flutter_tools] more debugging for timeouts in break_on_framework_exceptions test #125584

christopherfujino · 2023-04-26T20:40:43Z

Better debugging to investigate: #125241

When the test/integration.shard/break_on_framework_exceptions_test.dart test times out, log out verbose logging to give clues as to why it did not complete.

From one local run it looks like the test runner is failing to load a test file (when I checked the path locally, the file was there, and re-running the flutter test ... invocation succeeded--in that the app threw an exception):

14:12 +26 -1: breaks when StatefulWidget.build throws [E]
  Timed out launching `flutter test`
  package:matcher                                                        fail
  test/integration.shard/break_on_framework_exceptions_test.dart 623:11  _timeoutAfter.<fn>

250s            Spawning flutter [test, --disable-service-auth-codes, --machine, --start-paused, test/test.dart] in /tmp/flutter_break_on_framework_exceptions.GUJDAZ

251s <=stdout=  {"protocolVersion":"0.1.1","runnerVersion":null,"pid":25763,"type":"start","time":0}

<=stdout=  {"suite":{"id":0,"platform":"vm","path":"/tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart"},"type":"suite","time":0}

<=stdout=  {"test":{"id":1,"name":"loading /tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart","suiteID":0,"groupIDs":[],"metadata":{"skip":false,"skipReason":null},"line":null,"column":null,"url":null},"type":"testStart","time":0}

258s <=stdout=  {"testID":1,"error":"Exception: the Dart compiler exited unexpectedly.","stackTrace":"package:flutter_tools/src/base/common.dart 10:3  throwToolExit\npackage:flutter_tools/src/compile.dart 813:13    DefaultResidentCompiler._compile.<fn>\ndart:async/zone.dart 1391:47                     _rootRun\ndart:async/zone.dart 1301:19                     _CustomZone.run\ndart:async/zone.dart 1209:7                      _CustomZone.runGuarded\ndart:async/stream_impl.dart 392:13               _BufferingStreamSubscription._sendDone.sendDone\ndart:async/stream_impl.dart 402:7                _BufferingStreamSubscription._sendDone\ndart:async/stream_impl.dart 291:7                _BufferingStreamSubscription._close\ndart:async/stream_transformers.dart 87:11        _SinkTransformerStreamSubscription._close\ndart:async/stream_transformers.dart 21:11        _EventSinkWrapper.close\ndart:convert/string_conversion.dart 241:11       _StringAdapterSink.close\ndart:convert/line_splitter.dart 141:11           _LineSplitterSink.close\ndart:async/stream_transformers.dart 132:24       _SinkTransformerStreamSubscription._handleDone\ndart:async/zone.dart 1391:47                     _rootRun\ndart:async/zone.dart 1301:19                     _CustomZone.run\ndart:async/zone.dart 1209:7                      _CustomZone.runGuarded\ndart:async/stream_impl.dart 392:13               _BufferingStreamSubscription._sendDone.sendDone\ndart:async/stream_impl.dart 402:7                _BufferingStreamSubscription._sendDone\ndart:async/stream_impl.dart 291:7                _BufferingStreamSubscription._close\ndart:async/stream_transformers.dart 87:11        _SinkTransformerStreamSubscription._close\ndart:async/stream_transformers.dart 21:11        _EventSinkWrapper.close\ndart:convert/string_conversion.dart 241:11       _StringAdapterSink.close\ndart:convert/string_conversion.dart 295:20       _Utf8ConversionSink.close\ndart:convert/chunked_conversion.dart 78:18       _ConverterStreamEventSink.close\ndart:async/stream_transformers.dart 132:24       _SinkTransformerStreamSubscription._handleDone\ndart:async/zone.dart 1391:47                     _rootRun\ndart:async/zone.dart 1301:19                     _CustomZone.run\ndart:async/zone.dart 1209:7                      _CustomZone.runGuarded\ndart:async/stream_impl.dart 392:13               _BufferingStreamSubscription._sendDone.sendDone\ndart:async/stream_impl.dart 402:7                _BufferingStreamSubscription._sendDone\ndart:async/stream_impl.dart...

<=stdout=  {"testID":1,"error":"Failed to load \"/tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart\": Compilation failed for testPath=/tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart","stackTrace":"","isFailure":false,"type":"error","time":7518}

<=stdout=  {"testID":1,"result":"error","skipped":false,"hidden":false,"type":"testDone","time":7521}

<=stdout=  {"count":1,"time":7526,"type":"allSuites"}

<=stdout=  {"success":false,"type":"done","time":7529}

259s            Process exited (1)

371s            Expecting test.startedProcess event
[+    95] <=stdout=  {"suite":{"id":0,"platform":"vm","path":"/tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart"},"type":"suite","time":0}
[+    95] <=stdout=  {"test":{"id":1,"name":"loading /tmp/flutter_break_on_framework_exceptions.GUJDAZ/test/test.dart","suiteID":0,"groupIDs":[],"metadata":{"skip":false,"skipReason":null},"line":null,"column":null,"url":null},"type":"testStart","time":0}
[+  7600] <=stdout=  {"testID":1,"error":"Exception: the Dart compiler exited unexpectedly.","stackTrace":"package:flutter_tools/src/base/common.dart 10:3  throwToolExit\npackage:flutter_tools/src/compile.dart 813:13    DefaultResidentCompiler._compile.<fn>\ndart:async/zone.dart 1391:47                     _rootRun\ndart:async/zone.dart 1301:19                     _CustomZone.run\ndart:async/zone.dart 1209:7                      _CustomZone.runGuarded\ndart:async/stream_impl.dart 392:13               _BufferingStreamSubscription._sendDone.sendDone\ndart:async/stream_impl.dart 402:7                _BufferingStreamSubscription._sendDone\ndart:async/stream_impl.dart 291:7                _BufferingStreamSubscription._close\ndart:async/stream_transformers.dart 87:11        _SinkTransformerStreamSubscription._close\ndart:async/stream_transformers.dart 21:11        _EventSinkWrapper.close\ndart:convert/string_conversion.dart 241:11       _StringAdapterSink.close\ndart:convert/line_splitter.dart 141:11           _LineSplitterSink.close\ndart:async/stream_transformers.dart 132:24       _SinkTransformerStreamSubscription._handleDone\ndart:async/zone.dart 1391:47                     _rootRun\ndart:async/zone.dart 1301:19                     _CustomZone.run\ndart:async/zone.dart 1209:7                      _CustomZone.runGuarded\ndart:async/stream_impl.dart 392:13               _BufferingStreamSubscription._sendDone.sendDone\ndart:async/stream_impl.dart 402:7                _BufferingStreamSubscription._sendDone\ndart:async/stream_impl.dart 291:7                _BufferingStreamSubscription._close\ndart:async/stream_transformers.dart 87:11        _SinkTransformerStreamSubscription._close\ndart:async/stream_transformers.dart 21:11        _EventSinkWrapper.close\ndart:convert/string_conversion.dart 241:11       _StringAdapterSink.close\ndart:convert/string_conversion.dart 295:20       _Utf8ConversionSink.close\ndart:convert/chunked_conversion.dart 78:18       _ConverterStreamEventSink.close\ndart:async/stream_transformers.dart 132:24...

Expecting test.startedProcess event is taking longer than usual...

eliasyishak · 2023-04-27T11:20:46Z

packages/flutter_tools/test/integration.shard/break_on_framework_exceptions_test.dart

+/// package:test can be set and a helpful message used to help debugging.
+///
+/// See https://github.com/flutter/flutter/issues/125241 for more context.
+Future<void> _timeoutAfter({


Do you think we should put this function somewhere global so we can use it to debug other possible flakes?

I'm thinking we shouldn't make it too easy to do this, since it's against the style guide https://github.com/flutter/flutter/wiki/Style-guide-for-Flutter-repo#never-check-if-a-port-is-available-before-using-it-never-add-timeouts-and-other-race-conditions.

Since this is library local, once we fix the bug affecting these test shards, we can delete the function, which we couldn't do if it was used to root cause various flake bugs.

Got it, that makes sense. Also just a general question, i see in the exceptException function we have called the _timeoutAfter function 4 times and each of those calls has a failure if it takes longer than 10 minutes.

What happens if each work call takes 4-5 minutes, which totals for 16-20 minutes which would be greater than the original CI 15 minute timeout... would this function still catch that?

No, this is intending to catch the situation where an isolate hangs and will never complete. If you look at the example I posted in my description, because the compiler failed, our test code will never see the event that it's waiting for.

So, this isn't a general solution to all timeouts, but rather a very specific hack to try to get more information about the flakes in this particular library. Here the actual secret sauce was actually adding a printOnFailure in the _debugPrint() helper function that we were already calling but never actually printed on CI.

Well, I also had to add my own timeouts, because I suspect printOnFailure() would never get run if the runner timed out the isolate.

Got it, that makes sense now, and yep, I saw the additional printOnFailure which made sense to me. Hopefully this can help identify the issue, LGTM

…work_exceptions test (flutter/flutter#125584)

flutter-dashboard bot added the tool Affects the "flutter" command-line tool. See also t: labels. label Apr 26, 2023

add more debugging for timeouts in break_on_framework_exceptions test

66998f8

christopherfujino force-pushed the add-debugging-for-break-on-framework-exceptions-test branch from e4f01c6 to 66998f8 Compare April 26, 2023 20:41

christopherfujino requested a review from eliasyishak April 26, 2023 21:36

eliasyishak reviewed Apr 27, 2023

View reviewed changes

eliasyishak approved these changes Apr 27, 2023

View reviewed changes

christopherfujino added the autosubmit Merge PR when tree becomes green via auto submit App label Apr 27, 2023

auto-submit bot merged commit 4ff505c into flutter:master Apr 27, 2023

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to 5a1ef73dd088 (33 revisions) flutter/packages#3840

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

f501e2a

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to 00bbf5434c0d (34 revisions) flutter/packages#3841

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

eecb307

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to a698da607860 (35 revisions) flutter/packages#3842

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

1a6a526

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to 69af93436767 (36 revisions) flutter/packages#3843

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

a76d3e8

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to 888b208d62eb (37 revisions) flutter/packages#3844

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

da0818a

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 28, 2023

Roll Flutter from 66fa4c5d301c to 50f83fc2777d (38 revisions) flutter/packages#3845

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 28, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

edba2c0

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 29, 2023

Roll Flutter from 66fa4c5d301c to 14981ffc0222 (55 revisions) flutter/packages#3852

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 29, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

e5bf271

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 29, 2023

Roll Flutter from 66fa4c5d301c to 14981ffc0222 (55 revisions) flutter/packages#3853

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 29, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

57233c6

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 29, 2023

Roll Flutter from 66fa4c5d301c to 807c55c6b322 (56 revisions) flutter/packages#3854

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 29, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

90f818b

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 29, 2023

Roll Flutter from 66fa4c5d301c to 29b3e66ecbea (57 revisions) flutter/packages#3855

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 29, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

e1cbb04

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 30, 2023

Roll Flutter from 66fa4c5d301c to 9241329b4669 (62 revisions) flutter/packages#3856

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 30, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

f24c766

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request Apr 30, 2023

Roll Flutter from 66fa4c5d301c to 9241329b4669 (62 revisions) flutter/packages#3857

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request Apr 30, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

2d21f23

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll mentioned this pull request May 1, 2023

Roll Flutter from 66fa4c5d301c to fed8cc4a283a (69 revisions) flutter/packages#3860

Closed

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

7a5a6c5

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

03887f5

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

2108b18

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

237ab77

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

53dc9b8

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

f51d37d

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

1dd8d81

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

7c90c2b

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

6f8815c

…work_exceptions test (flutter/flutter#125584)

engine-flutter-autoroll added a commit to engine-flutter-autoroll/packages that referenced this pull request May 1, 2023

4ff505c [flutter_tools] more debugging for timeouts in break_on_frame…

7a400f2

…work_exceptions test (flutter/flutter#125584)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

[flutter_tools] more debugging for timeouts in break_on_framework_exceptions test #125584

[flutter_tools] more debugging for timeouts in break_on_framework_exceptions test #125584

Uh oh!

christopherfujino commented Apr 26, 2023 •

edited

Loading

Uh oh!

eliasyishak Apr 27, 2023

Uh oh!

christopherfujino Apr 27, 2023

Uh oh!

eliasyishak Apr 27, 2023

Uh oh!

christopherfujino Apr 27, 2023

Uh oh!

christopherfujino Apr 27, 2023

Uh oh!

christopherfujino Apr 27, 2023

Uh oh!

eliasyishak Apr 27, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

[flutter_tools] more debugging for timeouts in break_on_framework_exceptions test #125584

[flutter_tools] more debugging for timeouts in break_on_framework_exceptions test #125584

Uh oh!

Conversation

christopherfujino commented Apr 26, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

eliasyishak Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

christopherfujino Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

eliasyishak Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

christopherfujino Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

christopherfujino Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

christopherfujino Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

eliasyishak Apr 27, 2023

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

christopherfujino commented Apr 26, 2023 •

edited

Loading