Often getting Test timed out after 12 minutes

[marandaneto]

TimeoutException after 0:12:00.000000: Test timed out after 12 minutes.
package:test_api/src/backend/invoker.dart 333:28 Invoker._handleError.
dart:async/zone.dart 1420:47 _rootRun
dart:async/zone.dart 1328:19 _CustomZone.run
package:test_api/src/backend/invoker.dart 331:10 Invoker._handleError
package:test_api/src/backend/invoker.dart 287:9 Invoker.heartbeat..
dart:async/zone.dart 1428:13 _rootRun
dart:async/zone.dart 1328:19 _CustomZone.run
package:test_api/src/backend/invoker.dart 286:38 Invoker.heartbeat.
dart:async-patch/timer_patch.dart 18:15 Timer._createTimer.
dart:isolate-patch/timer_impl.dart 395:19 _Timer._runTimers
dart:isolate-patch/timer_impl.dart 426:5 _Timer._handleMessage
dart:isolate-patch/isolate_patch.dart 192:12 _RawReceivePortImpl._handleMessage

eg https://github.com/getsentry/sentry-dart/runs/3994055172?check_suite_focus=true

[jakemac53]

Likely a duplicate of #1620?

[jakemac53]

Please try with test version 1.19.2 and if that solves things then you can close the issue, if not we can investigate further.

[marandaneto]

it's not related to #1620, see this issue getsentry/sentry-dart#500
every time fails in different tests, those tests don't do any async work that requires waiting for something that might not be finished in time, happens only on macOS so far apparently.

[marandaneto]

just happened again https://github.com/getsentry/sentry-dart/runs/4021713079?check_suite_focus=true

[jakemac53]

It looks to me like this is timing out when compiling the load_android_image_list_test.dart test. Do you have any expectation for how long that app typically takes to compile? You might be able to just do dart compile js locally to try it out, although if its a flutter test that may not work without some extra arguments.

If the cause is indeed just a very large test app which takes a very long time to compile, then you could try increasing the timeout, probably for the whole package (see docs here)

[marandaneto]

@jakemac53 its a very light SDK actually, which takes seconds to compile, its probably something else, time already has been increased for testing, even 30minutes were not enough sometimes, its a flaky thingie.

[jakemac53]

Interesting that this only appears to be failing for flutter tests as well, and not the dart tests? Is that still accurate?

I don't know if flutter is using a custom platform for web tests or our default one (they have a custom platform for non-web tests).

[jakemac53]

One thing worth mentioning is that this compiling stage actually also includes loading the test in the browser. So if it could be failing to load for some reason as well, and we can't differentiate today.

Am I right in assuming you can't reproduce this locally?

[marandaneto]

Interesting that this only appears to be failing for flutter tests as well, and not the dart tests? Is that still accurate?

I don't know if flutter is using a custom platform for web tests or our default one (they have a custom platform for non-web tests).

not really, also for pure Dart tests as well, see https://github.com/getsentry/sentry-dart/runs/3990987164?check_suite_focus=true

[marandaneto]

One thing worth mentioning is that this compiling stage actually also includes loading the test in the browser. So if it could be failing to load for some reason as well, and we can't differentiate today.

Am I right in assuming you can't reproduce this locally?

I can't reproduce locally, and I run from the very same macOS version.
it's very intermittent. unfortunately, but it happens quite often.

[marandaneto]

The very same issue happens on windows-latest as well now: https://github.com/getsentry/sentry-dart/runs/5646627135?check_suite_focus=true

[bruno-garcia]

Is there something we can do like run it in diagnostics mode and collect some logs? This is a huge problems for our productivity with CI and releases flaky failures

[natebosch]

The last change we had in this area was to add retry, but that was on a version of the package release 2022-03-16, and the latest comments on this issue suggest the problem was still happening.
#1676

It looks like the output was also a little different.

I don't think we've been seeing chrome issues in our github action runs lately.

[natebosch]

Looking at the error message and stack trace, I wonder if the problem isn't within the test bodies.

Is it possible there is a flaky bug with an expectAsync callback that never gets called, or an expect(someFuture, completes) where the Future never completes or something along those lines?

I don't think I've seen other reports of a timeout within the running tests, as opposed to a timeout of the infrastructure talking to the browser.

[marandaneto]

We've debugged and tried to reproduce it plenty of times, but we could not find a bug in the tests or reproduce it.
Also, happening only on specific OSs was another indication that could be a bug in the test infrastructure.

We don't use expectAsync at all but expect with futures, yes.

Right now we are running tests on chrome only using Linux, never experienced this issue again.

[natebosch]

I'm not sure how to get more output from chrome to get a better idea of what is happening.

We are running with flags that I would expect to give us verbose output on stdout

test/pkgs/test/lib/src/runner/browser/chrome.dart

Lines 52 to 53 in 0e5c028

	'--enable-logging=stdout',
	'--v=1',

But the only message I've been able to see is the "DevTools listenening" message.

We might need to look in to always attaching to devtools and forwarding messages or errors from there?

[marandaneto]

Yeah not sure, currently using dart test -p chrome --test-randomize-ordering-seed=random --chain-stack-traces

Info: Compiling with sound null safety.
Compiled 11,865,262 characters Dart to 1,271,437 characters JavaScript in 8.70 seconds using 373.520 MB of memory
Dart file /C:/Users/runneradmin/AppData/Local/Temp/dart_test_2be0ef33/runInBrowser.dart compiled to JavaScript: /C:/Users/runneradmin/AppData/Local/Temp/dart_test_6b2d06a5/test_4ef4e285/client_report_recorder_test.dart.browser_test.dart.js

Failed to load "test\client_reports\client_report_recorder_test.dart":
Timed out waiting for Chrome to connect.
Browser output:
DevTools listening on ws://127.0.0.1:56758/devtools/browser/3bc493ec-e9f3-4602-b6c1-499d5c165109

package:test/src/runner/browser/browser_manager.dart 143:9 BrowserManager._start.
dart:async/zone.dart 1390:47 _rootRun
dart:async/zone.dart 1300:19 _CustomZone.run
dart:async/future_impl.dart 882:34 Future.timeout.
dart:async/zone.dart 1390:47 _rootRun
dart:async/zone.dart 1300:19 _CustomZone.run
dart:async/zone.dart 1208:7 _CustomZone.runGuarded
dart:async/zone.dart 1248:23 _CustomZone.bindCallbackGuarded.
dart:async/zone.dart 1398:13 _rootRun
dart:async/zone.dart 1300:19 _CustomZone.run
dart:async/zone.dart 1232:23 _CustomZone.bindCallback.
dart:async-patch/timer_patch.dart 18:15 Timer._createTimer.
dart:isolate-patch/timer_impl.dart 398:19 _Timer._runTimers
dart:isolate-patch/timer_impl.dart 429:5 _Timer._handleMessage
dart:isolate-patch/isolate_patch.dart 189:12 _RawReceivePort._handleMessage

[natebosch]

We've made some changes to the browser startup process which didn't seem to make a difference with the flakes. See discussion at #1104

In the end a chrome update seems to have fixed it. It still this reproing for you?

[marandaneto]

After running Chrome tests only on Linux, we never experienced this issue again, I'm not sure if it still happens.
I'm not working on that codebase anymore so I will close it and reopen it in case I have see it again, thanks.