vibe-d/vibe-d+tests fails on buildkite

Question

vibe-d/vibe-d+tests fails on buildkite

dkorpel opened this issue 3 years ago · 8 comments

The vibe-d/vibe-d+tests target fails on dmd's buildkite with a time out after an hour. This happens on multiple PRs and looks unrelated to the changes to DMD, so I think this is caused by #2646.

Example build log:

https://buildkite.com/dlang/dmd/builds/25804#cd6393e1-73e4-4ce3-a35e-146af935a3d7

~> case "$REPO_FULL_NAME" in
~> remove_spurious_vibed_tests
~> rm -rf tests/std.concurrency
~> rm -rf tests/vibe.http.client.1389
~> rm -rf tests/redis
~> VIBED_DRIVER=vibe-core
~> PARTS=tests
~> ./run-ci.sh
+ DUB_ARGS='--build-mode=separate '
+ : tests
+ [[ tests =~ (^|,)lint(,|$) ]]
+ [[ tests =~ (^|,)builds(,|$) ]]
+ [[ tests =~ (^|,)unittests(,|$) ]]
+ [[ tests =~ (^|,)examples(,|$) ]]
+ [[ tests =~ (^|,)tests(,|$) ]]
++ ls -1 tests/
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/args/run.sh ']'
+ '[' -r tests/args/dub.json ']'
+ '[' args == vibe.http.client.2080 ']'
+ echo '[INFO] Running test args'
[INFO] Running test args
+ cd tests/args
+ dub --compiler=dmd --build-mode=separate
Fetching vibe-core 1.22.3 (getting selected version)...
Fetching memutils 1.0.4 (getting selected version)...
Fetching taggedalgebraic 0.11.22 (getting selected version)...
Fetching botan-math 1.0.3 (getting selected version)...
Fetching stdx-allocator 2.77.5 (getting selected version)...
Fetching botan 1.12.19 (getting selected version)...
Fetching diet-ng 1.8.0 (getting selected version)...
Fetching openssl 1.1.6+1.0.1g (getting selected version)...
Fetching eventcore 0.9.20 (getting selected version)...
Fetching mir-linux-kernel 1.0.1 (getting selected version)...
Fetching libasync 0.8.6 (getting selected version)...
Running pre-generate commands for vibe-d:tls...
Performing "debug" build using dmd for x86_64.
mir-linux-kernel 1.0.1: building configuration "library"...
taggedalgebraic 0.11.22: building configuration "library"...
eventcore 0.9.20: building configuration "epoll"...
stdx-allocator 2.77.5: building configuration "library"...
vibe-core 1.22.3: building configuration "epoll"...
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(378,68): Deprecation: returning `&this.addr` escapes a reference to parameter `this`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(378,29):        perhaps annotate the function with `return`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(396,15): Deprecation: returning `&this.addr_ip4` escapes a reference to parameter `this`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(394,32):        perhaps annotate the function with `return`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(400,15): Deprecation: returning `&this.addr_ip6` escapes a reference to parameter `this`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(398,33):        perhaps annotate the function with `return`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(405,16): Deprecation: returning `&this.addr_unix` escapes a reference to parameter `this`
../../../.dub/packages/vibe-core-1.22.3/vibe-core/source/vibe/core/net.d(403,33):        perhaps annotate the function with `return`
vibe-d:crypto ~master: building configuration "library"...
vibe-d:utils ~master: building configuration "library"...
vibe-d:data ~master: building configuration "library"...
../../data/vibe/data/bson.d(994,41): Deprecation: returning `cast(inout(ubyte)[])this.m_bytes` escapes a reference to parameter `this`
../../data/vibe/data/bson.d(994,17):        perhaps annotate the function with `return`
diet-ng 1.8.0: building configuration "library"...
vibe-d:stream ~master: building configuration "library"...
vibe-d:textfilter ~master: building configuration "library"...
vibe-d:inet ~master: building configuration "library"...
vibe-d:tls ~master: building configuration "openssl"...
vibe-d:http ~master: building configuration "library"...
vibe-d:mail ~master: building configuration "library"...
vibe-d:mongodb ~master: building configuration "library"...
../../mongodb/vibe/db/mongo/collection.d(979,10): Deprecation: returning `this.cursor.batchSize` escapes a reference to parameter `this`
../../mongodb/vibe/db/mongo/collection.d(977,26):        perhaps annotate the function with `return`
vibe-d:redis ~master: building configuration "library"...
vibe-d:web ~master: building configuration "library"...
vibe-d ~master: building configuration "vibe-core"...
tests ~master: building configuration "application"...
Linking...
Running tests
argtest=
+ dub clean
Cleaning package at /var/lib/buildkite-agent/builds/ci-agent-2f967577-5d57-40b1-8d8b-bb1d0ee6cf90-2/dlang/dmd/build/vibe-d-vibe.d+tests/tests/args...
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/mongodb/run.sh ']'
+ '[' -r tests/mongodb/dub.json ']'
+ '[' -r tests/mongodb/dub.sdl ']'
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/not-runnable/run.sh ']'
+ '[' -r tests/not-runnable/dub.json ']'
+ '[' -r tests/not-runnable/dub.sdl ']'
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/rest/run.sh ']'
+ '[' -r tests/rest/dub.json ']'
+ '[' rest == vibe.http.client.2080 ']'
+ echo '[INFO] Running test rest'
[INFO] Running test rest
+ cd tests/rest
+ dub --compiler=dmd --build-mode=separate
Running pre-generate commands for vibe-d:tls...
Performing "debug" build using dmd for x86_64.
mir-linux-kernel 1.0.1: target for configuration "library" is up to date.
taggedalgebraic 0.11.22: target for configuration "library" is up to date.
eventcore 0.9.20: target for configuration "epoll" is up to date.
stdx-allocator 2.77.5: target for configuration "library" is up to date.
vibe-core 1.22.3: target for configuration "epoll" is up to date.
vibe-d:crypto ~master: target for configuration "library" is up to date.
vibe-d:utils ~master: target for configuration "library" is up to date.
vibe-d:data ~master: target for configuration "library" is up to date.
diet-ng 1.8.0: target for configuration "library" is up to date.
vibe-d:stream ~master: target for configuration "library" is up to date.
vibe-d:textfilter ~master: target for configuration "library" is up to date.
vibe-d:inet ~master: target for configuration "library" is up to date.
vibe-d:tls ~master: target for configuration "openssl" is up to date.
vibe-d:http ~master: target for configuration "library" is up to date.
vibe-d:mail ~master: target for configuration "library" is up to date.
vibe-d:mongodb ~master: target for configuration "library" is up to date.
vibe-d:redis ~master: target for configuration "library" is up to date.
vibe-d:web ~master: building configuration "library"...
vibe-d ~master: building configuration "vibe-core"...
tests ~master: building configuration "application"...
Linking...
To force a rebuild of up-to-date targets, run again with --force.
Running tests
[main(----) INF] Listening for requests on http://127.0.0.1:41428/
[main(Qj+F) INF] Success.
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
+ dub clean
Cleaning package at /var/lib/buildkite-agent/builds/ci-agent-2f967577-5d57-40b1-8d8b-bb1d0ee6cf90-2/dlang/dmd/build/vibe-d-vibe.d+tests/tests/rest...
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/restclient/run.sh ']'
+ '[' -r tests/restclient/dub.json ']'
+ '[' restclient == vibe.http.client.2080 ']'
+ echo '[INFO] Running test restclient'
[INFO] Running test restclient
+ cd tests/restclient
+ dub --compiler=dmd --build-mode=separate
Running pre-generate commands for vibe-d:tls...
Performing "debug" build using dmd for x86_64.
mir-linux-kernel 1.0.1: target for configuration "library" is up to date.
taggedalgebraic 0.11.22: target for configuration "library" is up to date.
eventcore 0.9.20: target for configuration "epoll" is up to date.
stdx-allocator 2.77.5: target for configuration "library" is up to date.
vibe-core 1.22.3: target for configuration "epoll" is up to date.
vibe-d:crypto ~master: target for configuration "library" is up to date.
vibe-d:utils ~master: target for configuration "library" is up to date.
vibe-d:data ~master: target for configuration "library" is up to date.
diet-ng 1.8.0: target for configuration "library" is up to date.
vibe-d:stream ~master: target for configuration "library" is up to date.
vibe-d:textfilter ~master: target for configuration "library" is up to date.
vibe-d:inet ~master: target for configuration "library" is up to date.
vibe-d:tls ~master: target for configuration "openssl" is up to date.
vibe-d:http ~master: target for configuration "library" is up to date.
vibe-d:mail ~master: target for configuration "library" is up to date.
vibe-d:mongodb ~master: target for configuration "library" is up to date.
vibe-d:redis ~master: target for configuration "library" is up to date.
vibe-d:web ~master: target for configuration "library" is up to date.
vibe-d ~master: target for configuration "vibe-core" is up to date.
tests ~master: building configuration "application"...
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.getFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.setFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.setFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.addFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.addFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.addBar as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.removeBar as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.updateBar as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPICors.removeFoo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ISub.get as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.info as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.getInfo as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.customParameters as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.customParameters2 as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.testID1 as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.testID2 as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.get as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ITestAPI.testKeyword as @safe.
source/app.d(218,9): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
Linking...
To force a rebuild of up-to-date targets, run again with --force.
Running tests
[main(7Upc) INF] Listening for requests on http://127.0.0.1:41867/
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
+ dub clean
Cleaning package at /var/lib/buildkite-agent/builds/ci-agent-2f967577-5d57-40b1-8d8b-bb1d0ee6cf90-2/dlang/dmd/build/vibe-d-vibe.d+tests/tests/restclient...
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/restcollections/run.sh ']'
+ '[' -r tests/restcollections/dub.json ']'
+ '[' restcollections == vibe.http.client.2080 ']'
+ echo '[INFO] Running test restcollections'
[INFO] Running test restcollections
+ cd tests/restcollections
+ dub --compiler=dmd --build-mode=separate
Running pre-generate commands for vibe-d:tls...
Performing "debug" build using dmd for x86_64.
mir-linux-kernel 1.0.1: target for configuration "library" is up to date.
taggedalgebraic 0.11.22: target for configuration "library" is up to date.
eventcore 0.9.20: target for configuration "epoll" is up to date.
stdx-allocator 2.77.5: target for configuration "library" is up to date.
vibe-core 1.22.3: target for configuration "epoll" is up to date.
vibe-d:crypto ~master: target for configuration "library" is up to date.
vibe-d:utils ~master: target for configuration "library" is up to date.
vibe-d:data ~master: target for configuration "library" is up to date.
diet-ng 1.8.0: target for configuration "library" is up to date.
vibe-d:stream ~master: target for configuration "library" is up to date.
vibe-d:textfilter ~master: target for configuration "library" is up to date.
vibe-d:inet ~master: target for configuration "library" is up to date.
vibe-d:tls ~master: target for configuration "openssl" is up to date.
vibe-d:http ~master: target for configuration "library" is up to date.
vibe-d:mail ~master: target for configuration "library" is up to date.
vibe-d:mongodb ~master: target for configuration "library" is up to date.
vibe-d:redis ~master: target for configuration "library" is up to date.
vibe-d:web ~master: target for configuration "library" is up to date.
vibe-d ~master: target for configuration "vibe-core" is up to date.
tests ~master: building configuration "application"...
Non-@safe methods are deprecated in REST interfaces - Mark SubItemAPI.length as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark SubItemAPI.name as @safe.
Non-@safe methods are deprecated in REST interfaces - Mark ItemManagerAPI.databaseURL as @safe.
source/app.d(109,9): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
Linking...
To force a rebuild of up-to-date targets, run again with --force.
Running tests
Starting event loop.
REST route: GET /items/:item/sub_items/length []
add route GET /items/:item/sub_items/length
REST route: GET /items/:item/sub_items/:index/name []
add route GET /items/:item/sub_items/:index/name
REST route: OPTIONS /items/:item/sub_items/:index/name []
add route OPTIONS /items/:item/sub_items/:index/name
REST route: OPTIONS /items/:item/sub_items/length []
add route OPTIONS /items/:item/sub_items/length
REST route: GET /items/manager/database_url []
add route GET /items/manager/database_url
REST route: OPTIONS /items/manager/database_url []
add route OPTIONS /items/manager/database_url
[main(OYea) INF] Listening for requests on http://127.0.0.1:37384/
Create HTTP client pool 127.0.0.1():37384 false proxy :0
creating new HTTPClient connection, all 0 are in use
 ... 7FC96F2D1F20
Now got 1 connections
Disambiguate done: 216 nodes, 1192 max stack size
Match tree has 55 (of 216 in the builder) nodes, 6 terminals
REST call: GET http://127.0.0.1:37384/items/foo/sub_items/length -> 200, OK
REST call: GET http://127.0.0.1:37384/items/foo/sub_items/0/name -> 200, OK
REST call: GET http://127.0.0.1:37384/items/foo/sub_items/1/name -> 200, OK
REST call: GET http://127.0.0.1:37384/items/manager/database_url -> 200, OK
exitEventLoop called (true)
Event loop exit reason (exit flag=true): exited
Event loop done (scheduled tasks=0, waiters=3, thread exit=true).
Thread exit main (index 0) (main=true)
Main thread exiting
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
Warning (thread: main): leaking eventcore driver because there are still active handles
  FD 6 (streamListen)
  FD 9 (streamSocket)
Use '-debug=EventCoreLeakTrace' to show where the instantiation happened
+ dub clean
Cleaning package at /var/lib/buildkite-agent/builds/ci-agent-2f967577-5d57-40b1-8d8b-bb1d0ee6cf90-2/dlang/dmd/build/vibe-d-vibe.d+tests/tests/restcollections...
+ for ex in '`\ls -1 tests/`'
+ '[' -r tests/tls/run.sh ']'
+ '[' -r tests/tls/dub.json ']'
+ '[' tls == vibe.http.client.2080 ']'
+ echo '[INFO] Running test tls'
[INFO] Running test tls
+ cd tests/tls
+ dub --compiler=dmd --build-mode=separate
Running pre-generate commands for vibe-d:tls...
Performing "debug" build using dmd for x86_64.
taggedalgebraic 0.11.22: target for configuration "library" is up to date.
eventcore 0.9.20: target for configuration "epoll" is up to date.
stdx-allocator 2.77.5: target for configuration "library" is up to date.
vibe-core 1.22.3: target for configuration "epoll" is up to date.
vibe-d:utils ~master: target for configuration "library" is up to date.
vibe-d:stream ~master: target for configuration "library" is up to date.
vibe-d:tls ~master: target for configuration "openssl" is up to date.
tests ~master: building configuration "application"...
source/app.d(46,19): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
source/app.d(67,19): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
source/app.d(178,19): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
source/app.d(208,19): Deprecation: template `vibe.core.core.runTask(ARGS...)(void delegate(ARGS) @system task, auto ref ARGS args)` is deprecated - The `task` argument should be nothrow
Linking...
To force a rebuild of up-to-date targets, run again with --force.
Running tests
[main(----) INF] Test client fail (, , , localhost), server fail (server.crt, server.key, , )
[main(----) INF] Test client success (, , , ), server success (server.crt, server.key, , )
[main(----) INF] Test client success (, , , localhost), server success (server.crt, server.key, , )
[main(----) INF] Test client fail (, , ca.crt, wronghost), server success (server.crt, server.key, , )
[main(----) INF] Test client success (, , ca.crt, wronghost), server success (server.crt, server.key, , )
[main(----) INF] Test client success (, , ca.crt, localhost), server success (server.crt, server.key, , )
[main(----) INF] Test client dontCare (client.crt, client.key, , ), server fail (server.crt, server.key, , )
[main(----) INF] Test client success (client.crt, client.key, , ), server success (server.crt, server.key, , )
[main(----) INF] Test client success (client.crt, client.key, , ), server success (server.crt, server.key, , )
[main(----) INF] Test client success (client.crt, client.key, , ), server success (server.crt, server.key, ca.crt, )
[main(----) INF] Test for failure client ssl3, server any
[main(----) INF] Test for failure client ssl3, server ssl3
[main(----) INF] Test for failure client ssl3, server tls1
[main(----) INF] Test for failure client ssl3, server tls1_1
[main(----) INF] Test for failure client ssl3, server tls1_2
[main(----) INF] Test for failure client tls1, server ssl3
[main(----) INF] Test for failure client tls1, server tls1_1
🚨 Error: The command exited with status -1

dkorpel commented 2 years ago

Yes

Answer 1 · 2022-04-05T10:55:00.000Z

~~Which platform is that test running on? I'm wondering why it is executing the TLS1->TLS1.1 test at all, because that should be disabled on Linux through support_old_tls.~~

Scratch that, I was looking at the wrong line. So it appears that it hangs somewhere in the TLS logic. Since everything works fine on the other CI platforms, as well as locally, I'd suggest to add the tls test to remove_spurious_vibed_tests in the buildkite script for now, it's unlikely that it catches DMD related breakage anyway.

Answer 2 · 2022-04-29T01:07:47.000Z

Is it possible SSLv23 references got yanked off from OpenSSL? Because I recently upgraded my system to something that's based on Ubuntu 22.04 LTS, and I'm getting no references to SSLv23_client_method (and similar) when linking.

My machine is on OpenSSL 3.0.2 (both program and dev library).

Looking at https://www.openssl.org/docs/manmaster/man3/SSLv23_server_method.html :

SSLv23_method(), SSLv23_server_method(), SSLv23_client_method()

These functions do not exist anymore, they have been renamed to TLS_method(),

Answer 3 · 2022-05-09T08:04:23.000Z

That's an interesting point - there is an OpenSSL version detection script in tls/dub.sdl that forwards the version to a D file that gets imported by tls/vibe/stream/openssl.d. Inside there, there is a string prefix comparison against "1.1" to determine whether a "new" version of OpenSSL is being used. If the version ends up as "3.0.0", then it would get treated as "old" instead.

The easiest fix would be to compare against "1.0"/"0.9" instead and reverse the condition.

Answer 4 · 2022-06-07T17:42:03.000Z

Updated error: https://buildkite.com/dlang/dmd/builds/26985#01813f37-292b-4d81-8836-a2e9389e2cc9

core.exception.AssertError@source/app.d(43): Web sockets failed: Connecting TLS tunnel: error:140C5042:SSL routines:ssl_undefined_function:called a function you should not call (336351298)
----------------
??:? _d_assert_msg [0xa0e848]
source/app.d:43 nothrow void app.test(bool).__lambda7() [0x791ce4]
../../../.dub/packages/vibe-core-1.22.4/vibe-core/source/vibe/core/task.d:734 nothrow void vibe.core.task.TaskFuncInfo.set!(void delegate() nothrow).set(ref void delegate() nothrow).callDelegate(ref vibe.core.task.TaskFuncInfo) [0x792cb3]
../../../.dub/packages/vibe-core-1.22.4/vibe-core/source/vibe/core/task.d:755 void vibe.core.task.TaskFuncInfo.call() [0x98ecbd]
../../../.dub/packages/vibe-core-1.22.4/vibe-core/source/vibe/core/task.d:454 nothrow void [vibe.core.task.TaskFiber.run](http://vibe.core.task.taskfiber.run/)() [0x98deab]
??:? void core.thread.context.Callable.opCall() [0xa1a35c]
??:? fiber_entryPoint [0xa78bb3]
Program exited with code -6

Answer 5 · 2022-06-07T18:43:40.000Z

@dd86k : Yes, that was an issue with OpenSSL v3 not being supported, fixed now.
However the Buildkite machines are on an ancient version of OpenSSL (v1.0.2 something AFAIK).

Answer 6 · 2022-06-08T19:33:03.000Z

Should be fixed now, I reverted the functional changes and re-run one of the failing job to confirm.

Answer 7 · 2022-10-19T15:25:28.000Z

can this be closed?