openshift / os

89 stars 105 forks source link

fips.enable failing in c9s #1540

Open jlebon opened 5 days ago

jlebon commented 5 days ago
--- FAIL: fips.enable (47.25s)
        harness.go:1823: mach.Start() failed: machine 8330598d-4529-45ff-9568-efe2b9636806 entered emergency.target in initramfs
        harness.go:1740: Found Go panic (opensslcrypto: can't enable FIPS mode for OpenSSL 3.2.2 4 Jun 2024: OSSL_PROVIDER_try_load
         Starting Ignition (fetch-offline)...
[    9.238794] ignition[763]: panic: opensslcrypto: can't enable FIPS mode for OpenSSL 3.2.2 4 Jun 2024: OSSL_PROVIDER_try_load
[    9.246143] ignition[763]: openssl error(s):
[    9.249212] ignition[763]: error:12800067:DSO support routines::could not load the shared library
[    9.255057] ignition[763]:   crypto/dso/dso_dlfcn.c:118
[    9.258551] ignition[763]: error:12800067:DSO support routines::could not load the shared library
[    9.264293] ignition[763]:   crypto/dso/dso_lib.c:147
[    9.267750] ignition[763]: error:07880025:common libcrypto routines::reason(37)
[    9.272762] ignition[763]:   crypto/provider_core.c:949
[    9.276444] ignition[763]: goroutine 1 gp=0xc0000081c0 m=0 mp=0x560b55045420 [running]:
[    9.281902] ignition[763]: panic({0x560b545e7ca0?, 0xc0001be110?})
[    9.286327] ignition[763]:   /usr/lib/golang/src/runtime/panic.go:779 +0x158 fp=0xc00053fce8 sp=0xc00053fc38 pc=0x560b53572318
[    9.293619] ignition[763]: crypto/internal/backend.init.0()
[    9.298779] ignition[763]:   /usr/lib/golang/src/crypto/internal/backend/openssl.go:72 +0x21f fp=0xc00053fe20 sp=0xc00053fce8 pc=0x560b536d5c7f
[    9.307026] ignition[763]: runtime.doInit1(0x560b54fdf500)
[    9.310822] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:7176 +0xea fp=0xc00053ff50 sp=0xc00053fe20 pc=0x560b535842ea
[    9.317976] ignition[763]: runtime.doInit(...)
[    9.321079] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:7143
[    9.325327] ignition[763]: runtime.main()
[    9.328158] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:253 +0x357 fp=0xc00053ffe0 sp=0xc00053ff50 pc=0x560b53575a97
[    9.335571] ignition[763]: runtime.goexit({})
[    9.338738] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00053ffe8 sp=0xc00053ffe0 pc=0x560b535a87c1
[    9.346157] ignition[763]: goroutine 2 gp=0xc000008c40 m=nil [force gc (idle)]:
[    9.351589] ignition[763]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
[    9.356056] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:402 +0xce fp=0xc00005efa8 sp=0xc00005ef88 pc=0x560b53575e0e
[    9.363168] ignition[763]: runtime.goparkunlock(...)
[    9.366638] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:408
[    9.370848] ignition[763]: runtime.forcegchelper()
[    9.374201] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:326 +0xb8 fp=0xc00005efe0 sp=0xc00005efa8 pc=0x560b53575c98
[    9.381555] ignition[763]: runtime.goexit({})
[    9.384791] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005efe8 sp=0xc00005efe0 pc=0x560b535a87c1
[    9.392287] ignition[763]: created by runtime.init.7 in goroutine 1
[    9.396743] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:314 +0x1a
[    9.401275] ignition[763]: goroutine 3 gp=0xc000008e00 m=nil [runnable]:
[    9.405793] ignition[763]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
[    9.410254] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:402 +0xce fp=0xc00005f780 sp=0xc00005f760 pc=0x560b53575e0e
[    9.417383] ignition[763]: runtime.goparkunlock(...)
[    9.420805] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:408
[    9.425010] ignition[763]: runtime.bgsweep(0xc00007e000)
[    9.428679] ignition[763]:   /usr/lib/golang/src/runtime/mgcsweep.go:278 +0x94 fp=0xc00005f7c8 sp=0xc00005f780 pc=0x560b535614f4
[    9.435997] ignition[763]: runtime.gcenable.gowrap1()
[    9.439534] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:203 +0x25 fp=0xc00005f7e0 sp=0xc00005f7c8 pc=0x560b53555e25
[    9.446967] ignition[763]: runtime.goexit({})
[    9.450132] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005f7e8 sp=0xc00005f7e0 pc=0x560b535a87c1
[    9.458763] ignition[763]: created by runtime.gcenable in goroutine 1
[    9.463067] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:203 +0x66
[    9.467762] ignition[763]: goroutine 4 gp=0xc000008fc0 m=nil [runnable]:
[    9.472186] ignition[763]: runtime.gopark(0xc00007e000?, 0x560b54522090?, 0x1?, 0x0?, 0xc000008fc0?)
[    9.478636] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:402 +0xce fp=0xc00005ff78 sp=0xc00005ff58 pc=0x560b53575e0e
[    9.485779] ignition[763]: runtime.goparkunlock(...)
[    9.489211] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:408
[    9.493427] ignition[763]: runtime.(*scavengerState).park(0x560b55043ea0)
[    9.498774] ignition[763]:   /usr/lib/golang/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc00005ffa8 sp=0xc00005ff78 pc=0x560b5355eee9
[    9.506436] ignition[763]: runtime.bgscavenge(0xc00007e000)
[    9.510359] ignition[763]:   /usr/lib/golang/src/runtime/mgcscavenge.go:653 +0x3c fp=0xc00005ffc8 sp=0xc00005ffa8 pc=0x560b5355f47c
[    9.517861] ignition[763]: runtime.gcenable.gowrap2()
[    9.521364] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:204 +0x25 fp=0xc00005ffe0 sp=0xc00005ffc8 pc=0x560b53555dc5
[    9.528762] ignition[763]: runtime.goexit({})
[    9.532106] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005ffe8 sp=0xc00005ffe0 pc=0x560b535a87c1
[    9.540577] ignition[763]: created by runtime.gcenable in goroutine 1
[    9.545760] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:204 +0xa5
[    9.550246] ignition[763]: goroutine 5 gp=0xc000009c00 m=nil [finalizer wait]:
[    9.555057] ignition[763]: runtime.gopark(0xc00005e648?, 0x560b53549445?, 0xa8?, 0x1?, 0xc0000081c0?)
[    9.561006] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:402 +0xce fp=0xc00005e620 sp=0xc00005e600 pc=0x560b53575e0e
[    9.568771] ignition[763]: runtime.runfinq()
[    9.571795] ignition[763]:   /usr/lib/golang/src/runtime/mfinal.go:194 +0x107 fp=0xc00005e7e0 sp=0xc00005e620 pc=0x560b53554de7
[    9.579104] ignition[763]: runtime.goexit({})
[    9.582124] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005e7e8 sp=0xc00005e7e0 pc=0x560b535a87c1
[    9.589531] ignition[763]: created by runtime.createfing in goroutine 1
[    9.594764] ignition[763]:   /usr/lib/golang/src/runtime/mfinal.go:164 +0x3d
[    9.599847] ignition[763]: goroutine 6 gp=0xc00014e1c0 m=nil [GC worker (idle)]:
[    9.605281] ignition[763]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
[    9.610134] ignition[763]:   /usr/lib/golang/src/runtime/proc.go:402 +0xce fp=0xc000060750 sp=0xc000060730 pc=0x560b53575e0e
[    9.617914] ignition[763]: runtime.gcBgMarkWorker()
[    9.621662] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:1310 +0xe5 fp=0xc0000607e0 sp=0xc000060750 pc=0x560b53557f25
[    9.629771] ignition[763]: runtime.goexit({})
[    9.632835] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000607e8 sp=0xc0000607e0 pc=0x560b535a87c1
[    9.640102] ignition[763]: created by runtime.gcBgMarkStartWorkers in goroutine 1
[    9.645775] ignition[763]:   /usr/lib/golang/src/runtime/mgc.go:1234 +0x1c
[    9.650387] ignition[763]: goroutine 7 gp=0xc00014e380 m=nil [runnable]:
[    9.654938] ignition[763]: go.opencensus.io/stats/view.init.0.gowrap1()
[    9.659519] ignition[763]:   /builddir/build/BUILD/ignition-2.19.0/vendor/go.opencensus.io/stats/view/worker.go:34 fp=0xc000060fe0 sp=0xc000060fd8 pc=0x560b53bbd340
[    9.669783] ignition[763]: runtime.goexit({})
[    9.673413] ignition[763]:   /usr/lib/golang/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000060fe8 sp=0xc000060fe0 pc=0x560b535a87c1
[    9.681502] ignition[763]: created by go.opencensus.io/stats/view.init.0 in goroutine 1
[    9.689769] ignition[763]:   /builddir/build/BUILD/ignition-2.19.0/vendor/go.opencensus.io/stats/view/worker.go:34 +0x8d

https://gcsweb-ci.apps.ci.l2s4.p1.openshiftapps.com/gcs/test-platform-results/pr-logs/pull/openshift_os/1532/pull-ci-openshift-os-master-scos-9-build-test-qemu/1805559141113008128/artifacts/test/artifacts/kola/fips.enable/8330598d-4529-45ff-9568-efe2b9636806/console.txt

:/# LD_LIBRARY_PATH=$libs $strace -e trace=openat ignition |& grep crypto
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.3", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/proc/sys/crypto/fips_enabled", O_RDONLY) = 3
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/glibc-hwcaps/x86-64-v4/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/glibc-hwcaps/x86-64-v3/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/glibc-hwcaps/x86-64-v2/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/haswell/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/haswell/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/haswell/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/haswell/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/tls/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/haswell/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/haswell/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/haswell/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/haswell/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/glibc-hwcaps/x86-64-v4/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/glibc-hwcaps/x86-64-v3/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/glibc-hwcaps/x86-64-v2/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/haswell/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/haswell/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/haswell/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/haswell/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/tls/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/haswell/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/haswell/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/haswell/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/haswell/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/avx512_1/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/avx512_1/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/x86_64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.1.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.11", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.11", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.11", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.111", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.111", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.111", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.1.0.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.1.0.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.1.0.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.1.0.0", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.1.0.0", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.1.0.0", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/sysroot/ostree/deploy/scos/deploy/d0b3d5aaa6d689af7d70740fe38e2dc0884172260e0bbfd9503f43d1c5420f67.0/usr/lib64/libcrypto.so.10", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib64/libcrypto.so.10", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib64/libcrypto.so.10", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/crypto/fips_enabled", O_RDONLY|O_CLOEXEC) = 3

so it tries really hard to find various versions and locations for libcrypto, except the one that we actually have:

:/# ls -l /usr/lib64/libcrypto*
lrwxrwxrwx 1 root root      30 Jan  1  1970 /usr/lib64/libcrypto.so.3 -> ../../lib64/libcrypto.so.3.2.2
-rwxr-xr-x 1 root root 5435176 Jan  1  1970 /usr/lib64/libcrypto.so.3.2.2

so some build misconfiguration or something?