DART_FORWARDING_PRINT=1 causes test time out

[peter-ahe-google]

This test started timing out:

python tools/test.py -mrelease -cdart2js -rdrt --use-sdk --write-debug-log --write-test-outcome-log --csp -t60 html/mutationobserver_test/childList

However, only when DART_FORWARDING_PRINT is set.

Tentatively assigning to John as this seems to correlate with some big changes he landed in http://src.chromium.org/viewvc/multivm?revision=1624&view=revision

However, it is also possible that it was in revision 1623 or 1625.

[jacob314]

I'll take a look

---

Set owner to @jacob314.

[jacob314]

I've rolled back the CLs to before John and my change and the issue still occurs. There is something very strange going on as I can reproduce it by running the command you suggest but not by running the 3 steps individually.

E.g.
To retest, run: /usr/local/google/home/jacobr/src/dart5/dart/tools/testing/bin/linux/dart /usr/local/google/home/jacobr/src/dart5/dart/tools/testing/dart/http_server.dart -p 35053 -c 54137 --csp --build-directory=/usr/local/google/home/jacobr/src/dart5/dart/out/ReleaseIA32 --runtime=drt

Command[dart2js]: out/ReleaseIA32/dart-sdk/bin/dart2js --package-root=out/ReleaseIA32/packages/ --out=/usr/local/google/home/jacobr/src/dart5/dart/out/ReleaseIA32/generated_compilations/dart2js/tests_html_mutationobserver_test/test.js /usr/local/google/home/jacobr/src/dart5/dart/tests/html/mutationobserver_test.dart
Took 0:00:00.011000

Command[content_shell]: /usr/local/google/home/jacobr/src/dartium10/src/out/Debug/content_shell --no-timeout --dump-render-tree http://127.0.0.1:35053/root_build/generated_tests/dart2js-drt-csp/tests_html_mutationobserver_test/test.html?crossOriginPort=54137&group=childList
Took 0:01:04.611000

Dartium wasn't rolling for a couple days after I rebooted VSM's machine so many other CLs could have also triggered the issue.

I would assign to Pete as he owns the mutation tests but he is OOF.

[mkustermann]

This seems to be a dartium issue -- I don't think Pete can do anything about it.

After the timeout happened on peters commit, he came to me and we looked into this and the issue turned out to be the environment variable (as peter mentioned).

To be a bit concreter:

• If you run the test with tools/test.py the test will timeout.
• If you run the test with the three steps given AND you set "DART_FORWARDING_PRINT=1" when invoking content_shell, it will time out as well (test.py sets the environment variable, but this is not shown in the reproduction commands -- we should fix that).
• If you don't set the environment variable, the test will complete as usual.

The reason why tools/test.py sets the environment variable is that our testing scripts needs to capture print() calls inside the dart VM to determine if a test finished [and it is very useful for debugging test failures if we have print() output].

The real question is why should this environment variable have an impact? We are executing dart2js compiled code after all (and no dart code).

[jacob314]

With the latest Dartium builds I cannot reproduce in release mode on Linux.
If the issue is reproducing for you on OSX please let me know.

In debug mode the test will fail for me but that is only because dart2js takes 90+ seconds to compile which blows past the 60 second timeout. With a longer timeout the test passes for both debug and release builds.

---

Set owner to @peter-ahe-google.
Added CannotReproduce label.

[peter-ahe-google]

FWIW, I was never able to reproduce the problem on Mac.

[whesse]

The problem reproduces on linux for me. I filed a duplicate bug - I'll mark it as duplicate.

---

Added Triaged label.

[whesse]

Issue #15579 has been merged into this issue.

---

cc @blois.
cc @jmesserly.
cc @peter-ahe-google.

[whesse]

It is reproducing on linux running an up-to-date drt:
content_shell is up to date.
Version: gs://dartium-archive/drt-lucid64-inc-be/drt-lucid64-inc-be-31060.0.zip

[DartBot]

This comment was originally written by whesse@chromium.org

---

I have reproduced the problem, by putting quote marks around the URL with an & in it, when running content_shell from the command line. The content security policy is not important, and the DART_FORWARDING_PRINT environment variable doesn't matter.

The only difference between content_shell hanging, and content_shell passing all tests, is whether the HTML file references the script "tests_html_mutationobserver_test/test.precompiled.js" or
"tests_html_mutationobserver_test/test.js"

The hanging only occurs on content_shell with the --dump-render-tree option, not on chrome or dartium. Here is the command and output:

[dart checkout]/client/tests/drt/content_shell --no-timeout --dump-render-tree "http://127.0.0.1:58584/root_build/generated_tests/dart2js-drt-checked-csp/tests_html_mutationobserver_test/test.html?crossOriginPort=58990&group=childList"
CONSOLE MESSAGE: line 78: {
  "type": "debug",
  "value": "test_controller.js started",
  "timestamp": 0
}
CONSOLE MESSAGE: line 78: {
  "type": "print",
  "value": "dart-calling-main",
  "timestamp": 0.154
}
CONSOLE MESSAGE: line 78: {
  "type": "print",
  "value": "dart-main-done",
  "timestamp": 0.19
}
CONSOLE MESSAGE: line 78: {
  "type": "message_received",
  "value": "dart-calling-main",
  "timestamp": 0.196
}
CONSOLE MESSAGE: line 78: {
  "type": "message_received",
  "value": "unittest-suite-wait-for-done",
  "timestamp": 0.197
}
CONSOLE MESSAGE: line 78: {
  "type": "message_received",
  "value": "dart-main-done",
  "timestamp": 0.244
}
CONSOLE MESSAGE: line 78: {
  "type": "message_received",
  "value": "unittest-suite-done",
  "timestamp": 120.318
}
Content-Type: text/plain
FAIL
2 PASS Expectation: childList empty options is syntax error.
3 ERROR Expectation: childList direct-nested options-named. Test timed out after 120 seconds.
4 PASS Expectation: childList direct-parallel options-named.
5 NO STATUS Test did not complete
Total 2 passed, 0 failed 1 errors
PASS
#EOF
#EOF
#EOF

So it looks like a content_shell and dart2js problem to me.

[jacob314]

Added Fixed label.