FreeBSD port: testunit fail

[nunotexbsd]

Problem:

testunit fail

FreeBSD amd64:

-- The C compiler identification is Clang 14.0.5
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Check for working C compiler: /usr/bin/cc - skipped
-- Detecting C compile features
-- Detecting C compile features - done
-- Detected CMAKE_SYSTEM_PROCESSOR as amd64
-- Detected 64-Bit system
-- Looking for pthread.h
-- Looking for pthread.h - found
-- Found Threads: TRUE
-- S2N_NO_PQ_ASM flag was detected - disabling PQ crypto assembly code
-- madvise() support detected
-- minherit() support detected
-- Found crypto: /usr/lib/libcrypto.so
-- LibCrypto Include Dir: /usr/include
-- LibCrypto Shared Lib:  /usr/lib/libcrypto.so
-- LibCrypto Static Lib:  /usr/lib/libcrypto.a
-- Using libcrypto from the cmake path
-- Configuring done
-- Generating done

testunit:

cmake -DCMAKE_BUILD_TYPE=Release -DCMAKE_INSTALL_PREFIX=/usr -DBUILD_SHARED_LIBS=ON \ -DUNSAFE_TREAT_WARNINGS_AS_ERRORS=OFF -S . -B build
cmake --build build
cmake --build build --target test
Running tests...

99% tests passed, 1 tests failed out of 217

Total Test time (real) = 189.66 sec

The following tests FAILED:
         20 - s2n_cipher_suites_test (SEGFAULT)
Errors while running CTest
Output from these tests are in: /usr/home/nunotex/Work/freebsd/ports/security/s2n-tls/work/.build/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
FAILED: CMakeFiles/test.util

LastTest.log:

20/217 Testing: s2n_cipher_suites_test
20/217 Test: s2n_cipher_suites_test
Command: "/usr/home/nunotex/Work/freebsd/ports/security/s2n-tls/work/.build/bin/s2n_cipher_suites_test"
Directory: /usr/home/nunotex/Work/freebsd/ports/security/s2n-tls/work/s2n-tls-1.3.20/tests/unit
"s2n_cipher_suites_test" start time: Sep 13 22:36 WEST
Output:
----------------------------------------------------------
<end of output>
Test time =   0.02 sec
----------------------------------------------------------
Test Failed.
"s2n_cipher_suites_test" end time: Sep 13 22:36 WEST
"s2n_cipher_suites_test" time elapsed: 00:00:00
----------------------------------------------------------

Any clue on how to find the cause of this fail?

Thanks

[maddeleine]

Hello, thanks for reporting this issue. We do run our tests on FreeBSD, but the Clang version that we test with is 13.0.0. Can you use that version?

[nunotexbsd]

Hi, yes I can and for better results I can use poudriere to run clean environments builds on FreeBSD s2n-tls port:

FreeBSD-14 amd64 current: clang 14.0.5
FreeBSD-13.1 amd64: clang 13.0.0
FreeBSD-12.3 amd64|i386: clang 10.0.1

I did make same tests on this versions and result is the same as above mentioned.
I can publish logs if you like.

[nunotexbsd]

poudriere interactive jail for:

package name: s2n-tls-1.3.20_1,1
building for: FreeBSD 131amd64-devel 13.1-RELEASE FreeBSD 13.1-RELEASE amd64

-- The C compiler identification is Clang 13.0.0

make test:

(...)
99% tests passed, 1 tests failed out of 217

Total Test time (real) = 187.78 sec

The following tests FAILED:
         20 - s2n_cipher_suites_test (SEGFAULT)
Errors while running CTest
Output from these tests are in: /wrkdirs/usr/ports/security/s2n-tls/work/.build/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
FAILED: CMakeFiles/test.util
cd /wrkdirs/usr/ports/security/s2n-tls/work/.build && /usr/local/bin/ctest --force-new-ctest-process
ninja: build stopped: subcommand failed.
*** Error code 1

ctest --force-new-ctest-process --rerun-failed --output-on-failure:

Test project /wrkdirs/usr/ports/security/s2n-tls/work/.build
    Start 20: s2n_cipher_suites_test
1/1 Test #20: s2n_cipher_suites_test ...........***Exception: SegFault  0.02 sec


0% tests passed, 1 tests failed out of 1

Total Test time (real) =   0.03 sec

The following tests FAILED:
         20 - s2n_cipher_suites_test (SEGFAULT)
Errors while running CTest

cat LastTest.log:

Start testing: Sep 14 11:24 UTC
----------------------------------------------------------
20/217 Testing: s2n_cipher_suites_test
20/217 Test: s2n_cipher_suites_test
Command: "/wrkdirs/usr/ports/security/s2n-tls/work/.build/bin/s2n_cipher_suites_test"
Directory: /wrkdirs/usr/ports/security/s2n-tls/work/s2n-tls-1.3.20/tests/unit
"s2n_cipher_suites_test" start time: Sep 14 11:24 UTC
Output:
----------------------------------------------------------
<end of output>
Test time =   0.02 sec
----------------------------------------------------------
Test Failed.
"s2n_cipher_suites_test" end time: Sep 14 11:24 UTC
"s2n_cipher_suites_test" time elapsed: 00:00:00
----------------------------------------------------------

End testing: Sep 14 11:24 UTC

[diizzyy]

Still occurs on 1.3.25, FreeBSD 13.1-STABLE (amd64)

[lrstewart]

This is odd because we test with the latest FreeBSD in our CI. We use https://github.com/vmactions/freebsd-vm, and run this script.

How are you running your tests? If you have direct access to the environment, can you build them with S2N_DEBUG=1 and then use gdb to figure out where the seg fault is occuring?

[diizzyy]

Hi,

We're using the ports collection for testing but it shouldn't be much different from yours in that regard.

I can confirm that building with CMake's debug profile enabled make s2n-tls pass all unit tests.

Comparing the two...

Release
[  0% 6/188] /usr/bin/cc -D_FORTIFY_SOURCE=2 -D_POSIX_C_SOURCE=200809L -Ds2n_EXPORTS -I/usr/ports/security/s2n-tls/work/s2n-tls-1.3.26 -I/usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/api -O2 -pipe -march=tigerlake  -fstack-protector-strong -fno-strict-aliasing -O2 -pipe -march=tigerlake  -fstack-protector-strong -fno-strict-aliasing  -DNDEBUG -fPIC -pedantic -std=gnu99 -Wall -Wimplicit -Wunused -Wcomment -Wchar-subscripts -Wuninitialized -Wshadow -Wcast-align -Wwrite-strings -Wno-deprecated-declarations -Wno-unknown-pragmas -Wformat-security -Wno-missing-braces -Wa,--noexecstack -Werror -fvisibility=hidden -DS2N_EXPORTS -DS2N_KYBER512R3_AVX2_BMI2 -DS2N_STACKTRACE -DS2N_CPUID_AVAILABLE -fPIC -DS2N_FALL_THROUGH_SUPPORTED -DS2N___RESTRICT__SUPPORTED -DS2N_MADVISE_SUPPORTED -DS2N_MINHERIT_SUPPORTED -DS2N_LIBCRYPTO_SUPPORTS_EVP_MD5_SHA1_HASH -DS2N_LIBCRYPTO_SUPPORTS_EVP_RC4 -DS2N_LIBCRYPTO_SUPPORTS_EVP_MD_CTX_SET_PKEY_CTX -MD -MT CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o -MF CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o.d -o CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o -c /usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/crypto/s2n_cipher.c

Debug
[  0% 6/188] /usr/bin/cc -D_POSIX_C_SOURCE=200809L -Ds2n_EXPORTS -I/usr/ports/security/s2n-tls/work/s2n-tls-1.3.26 -I/usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/api -pipe -march=tigerlake  -g -fstack-protector-strong -fno-strict-aliasing -pipe -march=tigerlake  -g -fstack-protector-strong -fno-strict-aliasing -fPIC -pedantic -std=gnu99 -Wall -Wimplicit -Wunused -Wcomment -Wchar-subscripts -Wuninitialized -Wshadow -Wcast-align -Wwrite-strings -Wno-deprecated-declarations -Wno-unknown-pragmas -Wformat-security -Wno-missing-braces -Wa,--noexecstack -Werror -fvisibility=hidden -DS2N_EXPORTS -DS2N_KYBER512R3_AVX2_BMI2 -DS2N_STACKTRACE -DS2N_CPUID_AVAILABLE -fPIC -DS2N_FALL_THROUGH_SUPPORTED -DS2N___RESTRICT__SUPPORTED -DS2N_MADVISE_SUPPORTED -DS2N_MINHERIT_SUPPORTED -DS2N_LIBCRYPTO_SUPPORTS_EVP_MD5_SHA1_HASH -DS2N_LIBCRYPTO_SUPPORTS_EVP_RC4 -DS2N_LIBCRYPTO_SUPPORTS_EVP_MD_CTX_SET_PKEY_CTX -MD -MT CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o -MF CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o.d -o CMakeFiles/s2n.dir/crypto/s2n_cipher.c.o -c /usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/crypto/s2n_cipher.c

Differences:

Release
-D_FORTIFY_SOURCE=2 -O2 -DNDEBUG
Note: -DNDEBUG was only added recently in Ports framework for CMake release target

Debug:
-g

Playing around with this a bit I found that defining any kind of optimzation (-O/-O1/-O2/-O3) causes a segfault using the set release flags

Tested on FreeBSD 13.1-STABLE (stable/13-n252834-a7766860e0f)
clang --version
FreeBSD clang version 14.0.5 (https://github.com/llvm/llvm-project.git llvmorg-14.0.5-0-gc12386ae247c)
Target: x86_64-unknown-freebsd13.1

[lrstewart]

Gotta love a bug that only happens when not in debug mode :)

You should be able to use gdb to pinpoint the bug even with the -O option. You just need to make sure you're building with "-g" to include debug symbols. Then run "gdb s2n_cipher_suites_test".

[diizzyy]

Logs:

lldb s2n_cipher_suites_test
(lldb) target create "s2n_cipher_suites_test"
Current executable set to '/usr/ports/security/s2n-tls/work/.build/bin/s2n_cipher_suites_test' (x86_64).
(lldb) run
Process 81434 launched: '/usr/ports/security/s2n-tls/work/.build/bin/s2n_cipher_suites_test' (x86_64)
Process 81434 stopped
* thread #1, name = 's2n_cipher_suite', stop reason = signal SIGSEGV: invalid address (fault address: 0x0)
    frame #0: 0x000000082350a0b8 libs2n.so.1`s2n_cipher_suite_from_iana(iana=0x0000000000000000, cipher_suite=0x0000000820f15850) at s2n_cipher_suites.c:1072:17
   1069     while (low <= top) {
   1070         /* Check in the middle */
   1071         size_t mid = low + ((top - low) / 2);
-> 1072         int m = memcmp(s2n_all_cipher_suites[mid]->iana_value, iana, S2N_TLS_CIPHER_SUITE_LEN);
   1073
   1074         if (m == 0) {
   1075             *cipher_suite = s2n_all_cipher_suites[mid];
(lldb) bt
* thread #1, name = 's2n_cipher_suite', stop reason = signal SIGSEGV: invalid address (fault address: 0x0)
  * frame #0: 0x000000082350a0b8 libs2n.so.1`s2n_cipher_suite_from_iana(iana=0x0000000000000000, cipher_suite=0x0000000820f15850) at s2n_cipher_suites.c:1072:17
    frame #1: 0x0000000000204250 s2n_cipher_suites_test`main at s2n_cipher_suites_test.c:80:13
    frame #2: 0x00000000002027f0 s2n_cipher_suites_test`_start + 256
(lldb) quit

gdb s2n_cipher_suites_test
GNU gdb (GDB) 12.1 [GDB v12.1 for FreeBSD]
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-portbld-freebsd13.1".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from s2n_cipher_suites_test...
(gdb) run
Starting program: /usr/ports/security/s2n-tls/work/.build/bin/s2n_cipher_suites_test
warning: Could not load shared library symbols for [vdso].
Do you need "set solib-search-path" or "set sysroot"?

Program received signal SIGSEGV, Segmentation fault.
Address not mapped to object.
0x00000008003250b8 in s2n_cipher_suite_from_iana (iana=0x0, cipher_suite=0x7fffffffe920) at /usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/tls/s2n_cipher_suites.c:1072
1072            int m = memcmp(s2n_all_cipher_suites[mid]->iana_value, iana, S2N_TLS_CIPHER_SUITE_LEN);
(gdb) list 1072
1067
1068        /* Perform a textbook binary search */
1069        while (low <= top) {
1070            /* Check in the middle */
1071            size_t mid = low + ((top - low) / 2);
1072            int m = memcmp(s2n_all_cipher_suites[mid]->iana_value, iana, S2N_TLS_CIPHER_SUITE_LEN);
1073
1074            if (m == 0) {
1075                *cipher_suite = s2n_all_cipher_suites[mid];
1076                return S2N_RESULT_OK;
(gdb) bt full
#0  0x00000008003250b8 in s2n_cipher_suite_from_iana (iana=0x0, cipher_suite=0x7fffffffe920) at /usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/tls/s2n_cipher_suites.c:1072
        m = <optimized out>
        mid = <optimized out>
        low = 0
        top = 36
#1  0x0000000000204250 in main () at /usr/ports/security/s2n-tls/work/s2n-tls-1.3.26/tests/unit/s2n_cipher_suites_test.c:80
        iana = "\000"
        cipher_suite = 0x0
(gdb) quit
A debugging session is active.

        Inferior 1 [process 82164] will be killed.

Quit anyway? (y or n) y

[lrstewart]

Interesting. s2n_cipher_suite_from_iana apparently got all the way to s2n_cipher_suites.c:1072, but shouldn't have gotten past this null check on iana: https://github.com/aws/s2n-tls/blob/main/tls/s2n_cipher_suites.c#L1063 The compiler must somehow be optimizing out that check...?

I think it has something to do with iana being defined as const uint8_t iana[static S2N_TLS_CIPHER_SUITE_LEN]. It looks like it changed ~6mo from const uint8_t iana[]

I repro'd the original error in our CI FreeBSD job by changing it to do Release instead of Debug, then tested that fix, and it seems to have actually solved the problem: #3586

[diizzyy]

That change fixes it on my testbox as well, thanks!

[nunotexbsd]

Thanks all for testing and fixing it.

https://cgit.freebsd.org/ports/commit/?id=e3fbcdd9aaabe9f8abd377f7acbabf6891d79a6c