Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Dart VM shutdown hangs #35192

Open
mraleph opened this issue Nov 16, 2018 · 12 comments

Comments

Projects
None yet
6 participants
@mraleph
Copy link
Contributor

commented Nov 16, 2018

From the stack traces it seems that we are waiting for service isolate to shutdown - but in fact there are no service isolate running.

FAILED: dartkp-dart_precompiled release_x64 standalone_2/io/stdout_stderr_non_blocking_test
Expected: Pass
Actual: Timeout

--- Command "vm_compile_to_kernel" (took 01.000867s):
DART_CONFIGURATION=ReleaseX64 /b/s/w/ir/pkg/vm/tool/gen_kernel --aot --platform=out/ReleaseX64/vm_platform_strong.dill -o /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill /b/s/w/ir/tests/standalone_2/io/stdout_stderr_non_blocking_test.dart --packages=/b/s/w/ir/.packages -Ddart.developer.causal_async_stacks=true

exit code:
0

--- Command "precompiler" (took 03.000341s):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/gen_snapshot --snapshot-kind=app-aot-assembly --assembly=/b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.S --obfuscate --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill

exit code:
0

stderr:
Warning: This VM has been configured to obfuscate symbol information which violates the Dart standard.
         See dartbug.com/30524 for more information.

--- Command "remove_kernel_file" (took 12ms):
DART_CONFIGURATION=ReleaseX64 rm /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill

exit code:
0

--- Command "assemble" (took 01.000622s):
DART_CONFIGURATION=ReleaseX64 gcc -m64 -shared -nostdlib -o /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.aotsnapshot /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.S

exit code:
0

--- Command "remove_assembly" (took 15ms):
DART_CONFIGURATION=ReleaseX64 rm /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.S

exit code:
0

--- Command "vm" (took 02:00.000052s):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/dart_precompiled_runtime --obfuscate --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/out/ReleaseX64/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.aotsnapshot

exit code:
-15

diagnostics:
Process list including children: [10640]
Trying to capture stack trace for pid 10640
PID 10640 - process
TID 10640:
#0  0x00007f95ff566404 pthread_cond_wait@@GLIBC_2.3.2
#1  0x000055f0f82b3cc8 dart::Monitor::WaitMicros(long)
#2  0x000055f0f830d23a dart::ServiceIsolate::Shutdown()
#3  0x000055f0f81de6af dart::Dart::Cleanup()
#4  0x000055f0f7fe9557 dart::bin::main(int, char**)
#5  0x000055f0f7fe9bb9 main
#6  0x00007f95fe78af45 __libc_start_main
#7  0x000055f0f7fe8029 _start
TID 10641:
#0  0x00007f95fe8676d3 epoll_wait
#1  0x000055f0f7fef725 dart::bin::EventHandlerImplementation::Poll(unsigned long)
#2  0x000055f0f800eece dart::bin::ThreadStart(void*)
#3  0x00007f95ff562184 start_thread
#4  0x00007f95fe86703d __clone



stdout:
Hello
Hello
Hello
Hello
Hello
Hello

stderr:
Hello
Hello
Hello
Hello
Hello
Hello

--- Re-run this test:
python tools/test.py -m release -n dartkp-obfuscate-linux-release-x64 --write-logs standalone_2/io/stdout_stderr_non_blocking_test
@mraleph

This comment has been minimized.

Copy link
Contributor Author

commented Nov 16, 2018

I am going to try implementing core dump generation and archiving for tests that time out.

@mraleph

This comment has been minimized.

Copy link
Contributor Author

commented Nov 26, 2018

Based on stack traces I think this is the same bug that @mkustermann has fixed in 83ba397 - we are not propagating UnwindError correctly.

@mraleph mraleph closed this Nov 26, 2018

@aam

This comment has been minimized.

Copy link
Contributor

commented Nov 30, 2018

This stdout_stderr_non_blocking_test test timed out on shutdown again( https://logs.chromium.org/logs/dart/buildbucket/cr-buildbucket.appspot.com/8928428248600968144/+/steps/vm_tests_shard_1/0/stdout ), so reopening.

@mkustermann

This comment has been minimized.

Copy link
Member

commented Nov 30, 2018

@rmacnak-google seems to have found another place where we might've swallowed UnwindErrors

@mkustermann

This comment has been minimized.

Copy link
Member

commented Dec 6, 2018

Even after @rmacnak-google 's change in 07f4351 we have seen another case just now. From log:

FAILED: dartkp-dart_precompiled release_simarm standalone_2/io/stdout_stderr_non_blocking_test
Expected: Pass
Actual: Timeout

--- Command "vm_compile_to_kernel" (took 01.000775s):
DART_CONFIGURATION=ReleaseSIMARM /b/s/w/ir/pkg/vm/tool/gen_kernel --aot --platform=out/ReleaseSIMARM/vm_platform_strong.dill -o /b/s/w/ir/out/ReleaseSIMARM/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill /b/s/w/ir/tests/standalone_2/io/stdout_stderr_non_blocking_test.dart --packages=/b/s/w/ir/.packages -Ddart.developer.causal_async_stacks=true

exit code:
0

--- Command "precompiler" (took 02.000776s):
DART_CONFIGURATION=ReleaseSIMARM out/ReleaseSIMARM/gen_snapshot --snapshot-kind=app-aot-blobs --blobs_container_filename=/b/s/w/ir/out/ReleaseSIMARM/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.aotsnapshot --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/out/ReleaseSIMARM/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill

exit code:
0

--- Command "remove_kernel_file" (took 13ms):
DART_CONFIGURATION=ReleaseSIMARM rm /b/s/w/ir/out/ReleaseSIMARM/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.dill

exit code:
0

--- Command "vm" (took 08:00.000096s):
DART_CONFIGURATION=ReleaseSIMARM out/ReleaseSIMARM/dart_precompiled_runtime --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/out/ReleaseSIMARM/generated_compilations/dartkp/tests_standalone_2_io_stdout_stderr_non_blocking_test/out.aotsnapshot

exit code:
-15

diagnostics:
Process list including children: [12883]
Trying to capture stack trace for pid 12883
PID 12883 - process
TID 12883:
#0  0xf775bcd9 __kernel_vsyscall
#1  0xf772cd0b pthread_cond_wait@@GLIBC_2.3.2
#2  0x0089dc65 dart::Monitor::WaitMicros(long long)
#3  0x0089dbb7 dart::Monitor::Wait(long long)
#4  0x008f0018 dart::ServiceIsolate::Shutdown()
#5  0x007e6553 dart::Dart::Cleanup()
#6  0x0094ddbe Dart_Cleanup
#7  0x006425cd dart::bin::main(int, char**)
#8  0x00642c84 main
#9  0xf753aaf3 __libc_start_main
#10 0x00641021 _start
TID 12884:
#0  0xf775bcd9 __kernel_vsyscall
#1  0xf760fee6 epoll_wait
#2  0x00648791 dart::bin::EventHandlerImplementation::Poll(unsigned int)
#3  0x00668e44 dart::bin::ThreadStart(void*)
#4  0xf7728f72 start_thread
#5  0xf760f43e __clone

eu-stack: dwfl_thread_getframes tid 12883 at 0x641020 in /b/s/w/ir/out/ReleaseSIMARM/dart_precompiled_runtime: no matching address range


stdout:
Hello
Hello
Hello
Hello
Hello
Hello

stderr:
Hello
Hello
Hello
Hello
Hello
Hello

--- Re-run this test:
python tools/test.py -n dartkp-linux-release-simarm standalone_2/io/stdout_stderr_non_blocking_test
@dcharkes

This comment has been minimized.

Copy link
Contributor

commented Jan 4, 2019

Still happening: log, log, and log.

@dcharkes dcharkes changed the title Dart VM shutdown hang on dartkp-obfuscate-linux-release-x64 Dart VM shutdown hangs Jan 4, 2019

@dcharkes

This comment has been minimized.

Copy link
Contributor

commented Jan 11, 2019

Again: log

Marking in status file.

dart-bot pushed a commit that referenced this issue Jan 11, 2019

[gardening] mark standalone_2/io/stdout_stderr_non_blocking_test as f…
…laky

Issue: #35192
Change-Id: Ieb2e3b6d1dbb5577963cf3ef528c356d0dd7dd44
Reviewed-on: https://dart-review.googlesource.com/c/89144
Reviewed-by: Samir Jindel <sjindel@google.com>
Commit-Queue: Samir Jindel <sjindel@google.com>
Auto-Submit: Daco Harkes <dacoharkes@google.com>
@sstrickl

This comment has been minimized.

Copy link
Contributor

commented Jan 14, 2019

Another timeout (log) that looks similar:

FAILED: app_jitk-vm release_x64 standalone_2/io/http_bind_test
Expected: Pass
Actual: Timeout

--- Command "app_jit" (took 01.000077s):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/dart --snapshot=/b/s/w/ir/cache/builder/sdk/out/ReleaseX64/generated_compilations/app_jitk/tests_standalone_2_io_http_bind_test/out.jitsnapshot --snapshot-kind=app-jit --ignore-unrecognized-flags --packages=/b/s/w/ir/cache/builder/sdk/.packages /b/s/w/ir/cache/builder/sdk/tests/standalone_2/io/http_bind_test.dart

exit code:
0

stdout:
unittest-suite-wait-for-done
unittest-suite-success

--- Command "vm" (took 01:00.000380s):
DART_CONFIGURATION=ReleaseX64 out/ReleaseX64/dart --ignore-unrecognized-flags --packages=/b/s/w/ir/cache/builder/sdk/.packages /b/s/w/ir/cache/builder/sdk/out/ReleaseX64/generated_compilations/app_jitk/tests_standalone_2_io_http_bind_test/out.jitsnapshot

exit code:
-15

diagnostics:
Process list including children: [5328]
Trying to capture stack trace for pid 5328
PID 5328 - process
TID 5328:
#0  0x00007fe549543404 pthread_cond_wait@@GLIBC_2.3.2
#1  0x000056294a0cc158 dart::Monitor::WaitMicros(long)
#2  0x000056294a2d0f3a Dart_RunLoop
#3  0x0000562949db3afd dart::bin::RunMainIsolate(char const*, dart::bin::CommandLineOptions*)
#4  0x0000562949db4807 dart::bin::main(int, char**)
#5  0x0000562949db5119 main
#6  0x00007fe548c81f45 __libc_start_main
#7  0x0000562949db3029 _start
TID 5329:
#0  0x00007fe548d5e6d3 epoll_wait
#1  0x0000562949dbc095 dart::bin::EventHandlerImplementation::Poll(unsigned long)
#2  0x0000562949ddb6de dart::bin::ThreadStart(void*)
#3  0x00007fe54953f184 start_thread
#4  0x00007fe548d5e03d __clone
TID 5344:
#0  0x00007fe549543404 pthread_cond_wait@@GLIBC_2.3.2
#1  0x000056294a0cc158 dart::Monitor::WaitMicros(long)
#2  0x000056294a29ccaa dart::BackgroundCompiler::Run()
#3  0x000056294a1654f7 dart::ThreadPool::Worker::Loop()
#4  0x000056294a165383 dart::ThreadPool::Worker::Main(unsigned long)
#5  0x000056294a0cba49 dart::ThreadStart(void*)
#6  0x00007fe54953f184 start_thread
#7  0x00007fe548d5e03d __clone



stdout:
unittest-suite-wait-for-done

--- Re-run this test:
python tools/test.py -n app_jitk-linux-release-x64 standalone_2/io/http_bind_test
@sstrickl

This comment has been minimized.

Copy link
Contributor

commented Jan 14, 2019

And another log from today for io/http_bind_test, marking it as flaky now.

@aam

This comment has been minimized.

Copy link
Contributor

commented Jan 15, 2019

@dcharkes

This comment has been minimized.

Copy link
Contributor

commented Jan 18, 2019

Another failure log

From the flakiness dashboard:

name configuration outcomes expected current run timeout pass          
standalone_2/io/http_bind_test dartk-optcounter-linux-release-ia32 Pass,Timeout Pass 64 1 64          
standalone_2/io/http_bind_test dartkb-compile-linux-release-x64 Pass,Timeout Pass 31 1 31          
standalone_2/io/http_bind_test dartkp-linux-debug-x64 Pass,Timeout Pass 54 1 54          
standalone_2/io/stdout_stderr_non_blocking_test dartkp-linux-release-simarm Pass,Timeout Pass 22 8 273          
standalone_2/io/stdout_stderr_non_blocking_test dartkp-linux-release-x64 Pass,Timeout Pass 86 1 86          

dart-bot pushed a commit that referenced this issue Jan 18, 2019

[gardening] Mark io/stdout_stderr_non_blocking_test flaky on x64
Issue: #35192
Change-Id: I6af9b935ba2fffbb32c854c36c3888df0258490d
Reviewed-on: https://dart-review.googlesource.com/c/90228
Auto-Submit: Daco Harkes <dacoharkes@google.com>
Reviewed-by: Samir Jindel <sjindel@google.com>
Commit-Queue: Samir Jindel <sjindel@google.com>
@dcharkes

This comment has been minimized.

Copy link
Contributor

commented Feb 8, 2019

standalone_2/io/http_bind_test also failed in configuration dartk-linux-release-simarm log

Flakyness dashboard filtered on name=standalone_2/io and outcomes=Pass,Timeout:

Last New Result Seen Name Configuration Outcomes Current Status Current Run Pass CTE RTE fail crash TO
2019-02-08 01:23:35 standalone_2/io/http_bind_test dartk-linux-release-simarm Pass,Timeout Pass 9 9         1
2019-01-31 18:16:52 standalone_2/io/http_read_test dartkp-android-release-arm Pass,Timeout Pass 99 99         1
2019-02-04 16:00:26 standalone_2/io/process_detached_test dartk-asan-linux-release-x64 Pass,Timeout Pass 62 62         1
2019-02-08 01:48:47 standalone_2/io/socket_connect_stream_data_close_cancel_test dartk-mac-debug-x64 Pass,Timeout Pass 24 27         1
2019-02-07 11:27:56 standalone_2/io/socket_connect_stream_data_close_cancel_test dartkp-mac-release-simarm64 Pass,Timeout Pass 64 67         1
2019-02-04 10:49:49 standalone_2/io/stdout_stderr_non_blocking_test dartkp-no-bare-linux-release-simarm Pass,Timeout Pass 4 83         2
2019-01-30 18:15:13 standalone_2/io/stdout_stderr_non_blocking_test dartkp-linux-release-simarm Pass,Timeout Pass 73 138         5
2019-01-29 06:02:36 standalone_2/io/stdout_stderr_non_blocking_test dartkp-linux-release-simarm64 Pass,Timeout Pass 99 99         1
  standalone_2/io/stdout_stderr_non_blocking_test dartkp-bare-linux-release-simarm Pass,Timeout Pass 22 199         5
  standalone_2/io/stdout_stderr_non_blocking_test dartkp-bare-linux-release-simarm64 Pass,Timeout Pass 89 89        
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.