| Summary: | AB-INT PTEST: glib-networking glib-networking/connection-openssl.test failure | ||
|---|---|---|---|
| Product: | [QA/Testing] Package Testing (ptest) | Reporter: | Alexandre Belloni <alexandre.belloni> |
| Component: | ptest | Assignee: | Trevor Gamblin <tgamblin> |
| Status: | RESOLVED WORKSFORME | QA Contact: | |
| Severity: | normal | ||
| Priority: | Medium+ | CC: | alexandre.belloni, joaomarcos.costa, luca.ceresoli, randy.macleod, ross.burton, steve |
| Version: | unspecified | ||
| Target Milestone: | 5.0 M2 | ||
| Hardware: | x86 | ||
| OS: | Multiple | ||
| Whiteboard: | AB-INT | ||
| OS type for building Yocto: | --- | Type of Regression: | --- |
| Verified: | Documentation change: | Don't know | |
|
Description
Alexandre Belloni
2023-03-14 23:09:30 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/4803/steps/12/logs/stdio qemux86-64-ptest ubuntu2204-ty-1 Running test: glib-networking/connection-openssl.test # random seed: R02S888434411953064dd002a703f68cd7c1 # GLib-GIO-DEBUG: _g_io_module_get_default: Found default implementation openssl (GTlsBackendOpenssl) for ?gio-tls-backend? 1..45 # Start of tls tests # Start of openssl tests # Start of connection tests # GLib-GIO-DEBUG: _g_io_module_get_default: Found default implementation dummy (GDummyProxyResolver) for ?gio-proxy-resolver? ok 1 /tls/openssl/connection/basic ok 2 /tls/openssl/connection/verified ok 3 /tls/openssl/connection/verified-chain ok 4 /tls/openssl/connection/verified-chain-with-redundant-root-cert ok 5 /tls/openssl/connection/verified-chain-with-duplicate-server-cert ok 6 /tls/openssl/connection/verified-unordered-chain ok 7 /tls/openssl/connection/verified-chain-with-alternative-ca-cert ok 8 /tls/openssl/connection/invalid-chain-with-alternative-ca-cert ok 9 /tls/openssl/connection/client-auth ok 10 /tls/openssl/connection/client-auth-rehandshake ok 11 /tls/openssl/connection/client-auth-failure # Bug Reference: http://bugzilla.gnome.org/793712 ok 12 /tls/openssl/connection/client-auth-fail-missing-client-private-key ok 13 /tls/openssl/connection/client-auth-request-cert ok 14 /tls/openssl/connection/client-auth-request-fail ok 15 /tls/openssl/connection/client-auth-request-none ok 16 /tls/openssl/connection/client-auth-pkcs11 # SKIP This backend does not support PKCS #11 ok 17 /tls/openssl/connection/no-database ok 18 /tls/openssl/connection/failed # GLib-GIO-DEBUG: GSocketClient: Starting new address enumeration # GLib-GIO-DEBUG: GSocketClient: Address enumeration succeeded # GLib-GIO-DEBUG: GSocketClient: Starting TCP connection attempt # GLib-GIO-DEBUG: GSocketClient: TCP connection successful # GLib-GIO-DEBUG: GSocketClient: Starting application layer connection # GLib-GIO-DEBUG: GSocketClient: Starting TLS handshake # GLib-GIO-DEBUG: GSocketClient: TLS handshake succeeded # GLib-GIO-DEBUG: GSocketClient: Connection successful! ok 19 /tls/openssl/connection/socket-client # GLib-GIO-DEBUG: GSocketClient: Starting new address enumeration # GLib-GIO-DEBUG: GSocketClient: Address enumeration succeeded # GLib-GIO-DEBUG: GSocketClient: Starting TCP connection attempt # GLib-GIO-DEBUG: GSocketClient: TCP connection successful # GLib-GIO-DEBUG: GSocketClient: Starting application layer connection # GLib-GIO-DEBUG: GSocketClient: Starting TLS handshake # GLib-GIO-DEBUG: GSocketClient: TLS handshake failed: Unacceptable TLS certificate # GLib-GIO-DEBUG: GSocketClient: Starting new address enumeration # GLib-GIO-DEBUG: GSocketClient: Address enumeration completed (out of addresses) # GLib-GIO-DEBUG: GSocketClient: Address enumeration failed: (null) # GLib-GIO-DEBUG: GSocketClient: Connection failed: Unacceptable TLS certificate ok 20 /tls/openssl/connection/socket-client-failed # GLib-GIO-DEBUG: GSocketClient: Starting new address enumeration # GLib-GIO-DEBUG: GSocketClient: Address enumeration succeeded # GLib-GIO-DEBUG: GSocketClient: Starting TCP connection attempt # GLib-GIO-DEBUG: GSocketClient: TCP connection successful # GLib-GIO-DEBUG: GSocketClient: Starting application layer connection # GLib-GIO-DEBUG: GSocketClient: Starting TLS handshake # GLib-GIO-DEBUG: GSocketClient: TLS handshake succeeded # GLib-GIO-DEBUG: GSocketClient: Connection successful! ** GLib-Net:ERROR:/usr/src/debug/glib-networking/2.74.0-r0/tls/tests/connection.c:1731:socket_client_timed_out_write: assertion failed (error == (g-io-error-quark, 24)): Resource temporarily unavailable (g-io-error-quark, 27) Bail out! GLib-Net:ERROR:/usr/src/debug/glib-networking/2.74.0-r0/tls/tests/connection.c:1731:socket_client_timed_out_write: assertion failed (error == (g-io-error-quark, 24)): Resource temporarily unavailable (g-io-error-quark, 27) FAIL: glib-networking/connection-openssl.test (Child process killed by signal 6) https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/4611/steps/12/logs/stdio qemuarm64-ptest ubuntu2004-arm-1 https://autobuilder.yoctoproject.org/typhoon/#builders/93/builds/1579/steps/13/logs/stdio qemuarm64-ptest-fast ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#builders/82/builds/4624/steps/12/logs/stdio qemuarm64-ptest ubuntu2004-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/4895/steps/12/logs/stdio qemuarm64-ptest ubuntu2204-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/4883/steps/12/logs/stdio qemuarm64-ptest ubuntu2204-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/4932/steps/12/logs/stdio qemuarm64-ptest ubuntu2204-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5107/steps/12/logs/stdio qemux86-64-ptest ubuntu2210-ty-1 Built core-image-ptest-glib-networking with a virtio-9p-pci mount to export log files. Ran the ptests locally 100 times in a loop on two separate occasions. On the first attempt, I got 33 failures, while on the second I got 22, so in theory this is pretty reproducible. However, on both occasions, after stopping the image and rebuilding it with strace added, followed by running strace on the ptests in a similar 100-attempt loop, I no longer detected any failures. There may be some timing issues here, or alternatively one of strace's dependencies could be masking the problem. Correction on previous comment - strace profiling seems to have a slowing effect on the tests such that they never fail when running that way. If I manually run the tests on an image with strace and its dependencies included, I can still fail the tests. the connection-openssl.test doesn't seem to be influenced by any of the other .test sets in /usr/share/installed-tests, as it can still fail after removing those (i.e. limiting glib-networking's ptest to only connection-openssl). It looks like there are actually two different errors we're hitting, not one: mountdir/ptest-4.log:GLib-Net:ERROR:/usr/src/debug/glib-networking/2.76.0-r0/tls/tests/connection.c:2209:simul_read_thread: assertion failed (error == NULL): Resource temporarily unavailable (g-io-error-quark, 27) mountdir/ptest-4.log:not ok /tls/openssl/connection/simultaneous-sync - GLib-Net:ERROR:/usr/src/debug/glib-networking/2.76.0-r0/tls/tests/connection.c:2209:simul_read_thread: assertion failed (error == NULL): Resource temporarily unavailable (g-io-error-quark, 27) mountdir/ptest-96.log:GLib-Net:ERROR:/usr/src/debug/glib-networking/2.76.0-r0/tls/tests/connection.c:1996:socket_client_timed_out_write: assertion failed (error == (g-io-error-quark, 24)): Resource temporarily unavailable (g-io-error-quark, 27) mountdir/ptest-96.log:not ok /tls/openssl/connection/read-time-out-then-write - GLib-Net:ERROR:/usr/src/debug/glib-networking/2.76.0-r0/tls/tests/connection.c:1996:socket_client_timed_out_write: assertion failed (error == (g-io-error-quark, 24)): Resource temporarily unavailable (g-io-error-quark, 27) https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5243/steps/12/logs/stdio qemux86-64-ptest on fedora38-ty-3 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5062 qemuarm64-ptest on ubuntu2004-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5071/steps/12/logs/stdio qemuarm64-ptest on ubuntu2004-arm-1 mickledore https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5126/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5132/steps/13/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5314/steps/12/logs/stdio qemux86-64-ptest fedora37-ty-2 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5128/steps/13/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5305/steps/12/logs/stdio qemux86-64-ptest fedora37-ty-2 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5303/steps/12/logs/stdio qemux86-64-ptest ubuntu2210-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5058/steps/13/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5151/steps/12/logs/stdio qemux86-64-ptest fedora37-ty-3 Coming back to this again, but I can't make it fail now with a new image build. Will keep trying. I'm on F38 x86_64, built core-image-ptest-glib-networking and ran ptest-runner several times manually, as well as via testimage (100 iterations, no failures). Previously, I was getting a nearly 50% failure rate. I wonder if a fix has solved this, or there's some host contamination going on somehow? https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5422/steps/12/logs/stdio qemux86-64-ptest ubuntu2210-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5413/steps/12/logs/stdio qemux86-64-ptest debian11-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/93/builds/1711/steps/13/logs/stdio qemuarm64-ptest-fast ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5262/steps/13/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 Did another core-image-ptest-glib-networking build, ran it with "runqemu kvm nographic" and looped 100 tests like so:
|for i in {1..100}; do ptest-runner glib-networking 2>&1 | tee -a ptest-$i.log; done
got these results over ten runs:
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
11
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
18
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
23
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
8
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
13
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
23
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
18
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
13
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
14
root@qemux86-64:~# grep -r "FAIL: 1" ptest-* | wc -l
21
so now I can reproduce it, but not at the high rates I was able to previously.
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5463/steps/12/logs/stdio qemux86-64-ptest rocky9-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5278/steps/13/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/5315/steps/13/logs/stdio qemuarm64-ptest on ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5515/steps/13/logs/stdio qemux86-64-ptest on opensuse154-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/93/builds/1733/steps/12/logs/stdio qemuarm64-ptest-fast ubuntu2204-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5509/steps/12/logs/stdio qemux86-64-ptest debian11-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5531/steps/12/logs/stdio qemux86-64-ptest debian11-ty-3 https://autobuilder.yoctoproject.org/typhoon/#/builders/93/builds/1722/steps/13/logs/stdio qemuarm64-ptest-fast ubuntu1804-arm-1 Not seen in ~5 months. Re-open if it rears it's ugly head again! That's because we switched to gnutls. This is the failure that khem tried to send a patch to disable. |