[2.19.4] Sporadic test failure with `_GLIBCXX_ASSERTIONS` #3916

thesamesam · 2024-02-21T08:32:33Z

Hi all!

When running tests for Botan 2.19.4 when packaging for Gentoo, I got:

bcrypt:
bcrypt ran 380 tests in 2.33 sec all ok
bcrypt_pbkdf:
/usr/lib/gcc/x86_64-pc-linux-gnu/14/include/g++-v14/bits/stl_vector.h:1127: std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = long unsigned int]: Assertion '__n < this->size()' failed.
Aborted (core dumped)

It only happens on some runs, unfortunately.

Backtraces (hit this with gcc 13 too):

Core was generated by `./botan-test2 --test-threads=32'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f403f2bec7c in ?? () from /usr/lib64/libc.so.6
[Current thread is 1 (Thread 0x7f4032a136c0 (LWP 2878430))]
(gdb) bt
#0  0x00007f403f2bec7c in ?? () from /usr/lib64/libc.so.6
#1  0x00007f403f268fc2 in raise () from /usr/lib64/libc.so.6
#2  0x00007f403f2514f2 in abort () from /usr/lib64/libc.so.6
#3  0x00007f403f4e4dfb in std::__glibcxx_assert_fail (file=file@entry=0x7f403fdac4f0 "/usr/lib/gcc/x86_64-pc-linux-gnu/14/include/g++-v14/bits/stl_vector.h", line=line@entry=1127,
    function=function@entry=0x7f403fdacee0 "std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = "..., condition=condition@entry=0x7f403fda401a "__n < this->size()")
    at /usr/src/debug/sys-devel/gcc-14.0.9999/gcc-14.0.9999/libstdc++-v3/src/c++11/assert_fail.cc:41
#4  0x00007f403fca9eff in std::vector<unsigned char, Botan::secure_allocator<unsigned char> >::operator[] (this=<optimized out>, __n=<optimized out>)
    at /usr/lib/gcc/x86_64-pc-linux-gnu/14/include/g++-v14/bits/stl_vector.h:1127
#5  Botan::TLS::TLS_CBC_HMAC_AEAD_Encryption::finish (this=0x7f3fc804b580, buffer=std::vector of length 0, capacity 0, offset=5) at src/lib/tls/tls_cbc/tls_cbc.cpp:207
#6  0x000055b54d1981c0 in ?? ()
#7  0x00007f4032a136c0 in ?? ()
#8  0x0000000000000001 in ?? ()
#9  0x0000000000000000 in ?? ()

#0  0x00007f2c660bec7c in ?? () from /usr/lib64/libc.so.6
#1  0x00007f2c66068fc2 in raise () from /usr/lib64/libc.so.6
#2  0x00007f2c660514f2 in abort () from /usr/lib64/libc.so.6
#3  0x00007f2c662e4dfb in std::__glibcxx_assert_fail (file=file@entry=0x7f2c66ba7578 "/usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h", line=line@entry=1125,
    function=function@entry=0x7f2c66ba7f68 "std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = "..., condition=condition@entry=0x7f2c66b9f000 "__n < this->size()")
    at /usr/src/debug/sys-devel/gcc-14.0.9999/gcc-14.0.9999/libstdc++-v3/src/c++11/assert_fail.cc:41
#4  0x00007f2c66a9f0df in std::vector<unsigned char, Botan::secure_allocator<unsigned char> >::operator[] (__n=<optimized out>, this=<optimized out>)
    at /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h:1125
#5  Botan::TLS::TLS_CBC_HMAC_AEAD_Encryption::finish (this=0x7f2c661f7b50, buffer=std::vector of length 5, capacity 10240 = {...}, offset=5) at src/lib/tls/tls_cbc/tls_cbc.cpp:207
#6  0x000055e4428366f0 in ?? ()
#7  0x00007f2c5f01e6c0 in ?? ()
#8  0x0000000000000001 in ?? ()
#9  0x0000000000000000 in ?? ()

See also #3623, #3736, and #3737.

The text was updated successfully, but these errors were encountered:

thesamesam · 2024-02-21T08:34:15Z

My memory of those bugs from last year is completely gone, but wonder if a fix needed to be backported to 2.19.x from 3.x?

Has a test failure. Bug: randombit/botan#3916 Bug: https://bugs.gentoo.org/925147 Signed-off-by: Sam James <sam@gentoo.org>

randombit · 2024-02-21T13:47:23Z

Replicated here

#0  0x00007ffff72ab32c in ?? () from /usr/lib/libc.so.6
#1  0x00007ffff725a6c8 in raise () from /usr/lib/libc.so.6
#2  0x00007ffff72424b8 in abort () from /usr/lib/libc.so.6
#3  0x00007ffff74dd3b2 in std::__glibcxx_assert_fail (file=file@entry=0x7ffff7d574f0 "/usr/include/c++/13.2.1/bits/stl_vector.h",
    line=line@entry=1125,
    function=function@entry=0x7ffff7d57de0 "std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = "...,
    condition=condition@entry=0x7ffff7d4f000 "__n < this->size()") at /usr/src/debug/gcc/gcc/libstdc++-v3/src/c++11/debug.cc:61
#4  0x00007ffff7c5d28f in std::vector<unsigned char, Botan::secure_allocator<unsigned char> >::operator[] (__n=<optimized out>,
    this=<optimized out>) at /usr/include/c++/13.2.1/bits/stl_vector.h:1125
#5  Botan::TLS::TLS_CBC_HMAC_AEAD_Encryption::finish (this=0x7fffec04ee00, buffer=std::vector of length 5, capacity 10240 = {...}, offset=5)
    at src/lib/tls/tls_cbc/tls_cbc.cpp:207
#6  0x00007ffff7c8a51e in Botan::TLS::write_record (output=std::vector of length 5, capacity 10240 = {...}, record_type=<optimized out>,
    version=..., record_sequence=<optimized out>, message=0x7fffec05c46e "\211\301\264o\267ɡ3\370<\221\002", message_len=0, cs=..., rng=...)
    at src/lib/tls/tls_record.cpp:260
#7  0x00007ffff7c5fcd4 in Botan::TLS::Channel::write_record (this=this@entry=0x7fffec0406c0, cipher_state=0x7fffec0412b0, epoch=epoch@entry=1,
    record_type=record_type@entry=23 '\027', input=input@entry=0x7fffec05c46e "\211\301\264o\267ɡ3\370<\221\002", length=length@entry=0)
    at src/lib/tls/tls_channel.cpp:570
#8  0x00007ffff7c63b3e in Botan::TLS::Channel::send_record_array (this=0x7fffec0406c0, epoch=<optimized out>, type=type@entry=23 '\027',
    input=0x7fffec05c46e "\211\301\264o\267ɡ3\370<\221\002", length=<optimized out>) at /usr/include/c++/13.2.1/bits/shared_ptr_base.h:1665
#9  0x00007ffff7c63f2d in Botan::TLS::Channel::send (this=<optimized out>, buf=<optimized out>, buf_size=<optimized out>)
    at src/lib/tls/tls_channel.cpp:642

randombit · 2024-02-21T13:49:29Z

Can you try this

diff --git a/src/lib/tls/tls_cbc/tls_cbc.cpp b/src/lib/tls/tls_cbc/tls_cbc.cpp
index 3e3e4c2df..bdf8f2e00 100644
--- a/src/lib/tls/tls_cbc/tls_cbc.cpp
+++ b/src/lib/tls/tls_cbc/tls_cbc.cpp
@@ -204,7 +204,9 @@ void TLS_CBC_HMAC_AEAD_Encryption::finish(secure_vector<uint8_t>& buffer, size_t

    buffer.reserve(offset + msg_size + padding_length + tag_size());
    buffer.resize(offset + msg_size);
-   copy_mem(&buffer[offset], msg().data(), msg_size);
+   if(msg_size > 0) {
+      copy_mem(&buffer[offset], msg().data(), msg_size);
+   }

    mac().update(assoc_data());

GH #3916

randombit · 2024-02-21T14:01:40Z

The same expression appears on master

   copy_mem(&buffer[offset], msg().data(), msg_size);

So I don't know why you wouldn't be able to repro it in 3.3 as well. (Unless GCC's iterator debugging behavior depends on C++ version in use, which seems possible but not something I have knowledge of.)

thesamesam · 2024-02-22T07:44:27Z

Trying it now. It's possible I was just very unlucky. I can't hit it very often, and when I ran in a loop, for 3.3, all I hit was the other bug.

thesamesam · 2024-02-22T07:53:27Z

No luck! I double checked the patch was applied.

Test run 7/100000 complete ran 6959 tests in 1.76 sec all tests ok
tls:
/usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h:1125: std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = long unsigned int]: Assertion '__n < this->size()' failed.
Aborted (core dumped)

(gdb) bt
#0  0x00007f1025cbec7c in ?? () from /usr/lib64/libc.so.6
#1  0x00007f1025c68fc2 in raise () from /usr/lib64/libc.so.6
#2  0x00007f1025c514f2 in abort () from /usr/lib64/libc.so.6
#3  0x00007f1025ee4dfb in std::__glibcxx_assert_fail (file=file@entry=0x7f10266ac128 "/usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h", line=line@entry=1125,
    function=function@entry=0x7f10266ac9e8 "std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](size_type) [with _Tp = unsigned char; _Alloc = Botan::secure_allocator<unsigned char>; reference = unsigned char&; size_type = "..., condition=condition@entry=0x7f10266c7c2f "__n < this->size()")
    at /usr/src/debug/sys-devel/gcc-14.0.9999/gcc-14.0.9999/libstdc++-v3/src/c++11/assert_fail.cc:41
#4  0x00007f10265d416f in std::vector<unsigned char, Botan::secure_allocator<unsigned char> >::operator[] (this=0x7f1025df7b50, __n=5)
    at /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h:1123
#5  std::vector<unsigned char, Botan::secure_allocator<unsigned char> >::operator[] (__n=<optimized out>, this=<optimized out>)
    at /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/stl_vector.h:1123
#6  Botan::TLS::TLS_CBC_HMAC_AEAD_Encryption::finish (this=0x7f1026808580, buffer=std::vector of length 0, capacity 0, offset=5) at src/lib/tls/tls_cbc/tls_cbc.cpp:209
#7  0x00007f10265f81f4 in Botan::TLS::write_record (output=std::vector of length 5, capacity 10240 = {...}, record_type=<optimized out>, version=..., record_sequence=<optimized out>,
    message=0x56014694d551 "\315\034\252M\026/T\371i\206;(\364ɶZN5*!f\002KH\364\322?e!d\302)\226\313W\243\031\315\315\310\3362]5c\242\346\233_\344\tU_\334\327\020~bx\364\aO\n\017^\3728\206\247\220/\r,\317\002\300\262_\333W\222a\255\242\377+B\213\tlJ_\255\225\263\272\204\253`&@\315\270\016\037\314χ\204\303\364\377}}mo\3006cwLqw\234&\323?\326\t\213\202\234Io\177\374\303\350\264\366\263%U\021\200\357\343'Y\267\306\037e<.\370\217\227?7ۮ\232\265\311f\373~3\343\026¿\246+\003\240\026z{G9\220\a\373\342/F˪7\353W\314\334\0360L\304Z"..., message_len=0,
    cs=..., rng=...) at src/lib/tls/tls_record.cpp:260
#8  0x00007f10265d6694 in Botan::TLS::Channel::write_record (this=this@entry=0x5601469bf5e0, cipher_state=0x5601469b02d0, epoch=epoch@entry=1, record_type=record_type@entry=23 '\027',
    input=input@entry=0x56014694d551 "\315\034\252M\026/T\371i\206;(\364ɶZN5*!f\002KH\364\322?e!d\302)\226\313W\243\031\315\315\310\3362]5c\242\346\233_\344\tU_\334\327\020~bx\364\aO\n\017^\3728\206\247\220/\r,\317\002\300\262_\333W\222a\255\242\377+B\213\tlJ_\255\225\263\272\204\253`&@\315\270\016\037\314χ\204\303\364\377}}mo\3006cwLqw\234&\323?\326\t\213\202\234Io\177\374\303\350\264\366\263%U\021\200\357\343'Y\267\306\037e<.\370\217\227?7ۮ\232\265\311f\373~3\343\026¿\246+\003\240\026z{G9\220\a\373\342/F˪7\353W\314\334\0360L\304Z"...,
    length=length@entry=0) at src/lib/tls/tls_channel.cpp:570
#9  0x00007f10265d9ecc in Botan::TLS::Channel::send_record_array (this=0x5601469bf5e0, epoch=<optimized out>, type=type@entry=23 '\027',
    input=0x56014694d551 "\315\034\252M\026/T\371i\206;(\364ɶZN5*!f\002KH\364\322?e!d\302)\226\313W\243\031\315\315\310\3362]5c\242\346\233_\344\tU_\334\327\020~bx\364\aO\n\017^\3728\206\247\220/\r,\317\002\300\262_\333W\222a\255\242\377+B\213\tlJ_\255\225\263\272\204\253`&@\315\270\016\037\314χ\204\303\364\377}}mo\3006cwLqw\234&\323?\326\t\213\202\234Io\177\374\303\350\264\366\263%U\021\200\357\343'Y\267\306\037e<.\370\217\227?7ۮ\232\265\311f\373~3\343\026¿\246+\003\240\026z{G9\220\a\373\342/F˪7\353W\314\334\0360L\304Z"...,
    length=<optimized out>) at /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/shared_ptr_base.h:1665
#10 0x00007f10265da2cd in Botan::TLS::Channel::send (this=<optimized out>, buf=<optimized out>, buf_size=<optimized out>) at src/lib/tls/tls_channel.cpp:642
#11 0x0000560146350453 in Botan_Tests::(anonymous namespace)::TLS_Handshake_Test::go (this=this@entry=0x7ffe130c1840) at src/tests/unit_tls.cpp:727
#12 0x0000560146351bd1 in Botan_Tests::(anonymous namespace)::TLS_Unit_Tests::test_with_policy (test_descr=..., results=std::vector of length 51, capacity 64 = {...}, client_ses=...,
    server_ses=..., creds=..., versions=..., policy=..., client_auth=<optimized out>, this=<optimized out>) at src/tests/unit_tls.cpp:895
#13 0x00005601463529f4 in Botan_Tests::(anonymous namespace)::TLS_Unit_Tests::test_all_versions (test_descr="3DES ECDH", results=std::vector of length 51, capacity 64 = {...},
    client_ses=..., server_ses=..., creds=..., kex_policy="ECDH", cipher_policy="3DES", mac_policy="SHA-1", etm_policy="false", client_auth=false, this=<optimized out>)
    at src/tests/unit_tls.cpp:944
#14 0x000056014635361f in Botan_Tests::(anonymous namespace)::TLS_Unit_Tests::run (this=<optimized out>) at src/tests/unit_tls.cpp:1114
#15 0x00005601462d1113 in Botan_Tests::(anonymous namespace)::run_a_test (test_name="tls") at src/tests/test_runner.cpp:256
#16 0x00005601462d1f0b in Botan_Tests::Test_Runner::run_tests (this=this@entry=0x7ffe130c2790, tests_to_run=std::vector of length 1, capacity 1 = {...}, test_threads=<optimized out>,
    test_run=test_run@entry=7, tot_test_runs=100000) at src/tests/test_runner.cpp:389
#17 0x00005601462d3c26 in Botan_Tests::Test_Runner::run (this=this@entry=0x7ffe130c2790, opts=...) at src/tests/tests.h:100
#18 0x00005601461af1d6 in main (argc=<optimized out>, argv=<optimized out>) at src/tests/main.cpp:101

thesamesam · 2024-02-22T07:55:40Z

Maybe I've made a mistake (or missing something obvious):

(gdb) frame 6
#6  Botan::TLS::TLS_CBC_HMAC_AEAD_Encryption::finish (this=0x7f1026808580, buffer=std::vector of length 0, capacity 0, offset=5) at src/lib/tls/tls_cbc/tls_cbc.cpp:209
209           copy_mem(&buffer[offset], msg().data(), msg_size);
(gdb) p msg_size
$1 = 0
(gdb) p buffer
$2 = std::vector of length 0, capacity 0
(gdb) list
204
205        buffer.reserve(offset + msg_size + padding_length + tag_size());
206        buffer.resize(offset + msg_size);
207        if(msg_size > 0)
208           {
209           copy_mem(&buffer[offset], msg().data(), msg_size);
210           }
211
212        mac().update(assoc_data());
213
(gdb)

reneme · 2024-02-22T09:10:53Z

Given that copy_mem is in line 209, I do confirm that the patch must have been applied. It would be in line 207 otherwise.

But why does it enter the if-body if msg_size is actually 0?

FWIW: We do the same &buffer[offset] thingy a few lines below.

thesamesam mentioned this issue Feb 21, 2024

[3.3.0] Sporadic dilithium_kat_4x4_AES_Deterministic failure #3917

Open

gentoo-bot pushed a commit to gentoo/gentoo that referenced this issue Feb 21, 2024

dev-libs/botan: drop kw for 2.19.4

efbc796

Has a test failure. Bug: randombit/botan#3916 Bug: https://bugs.gentoo.org/925147 Signed-off-by: Sam James <sam@gentoo.org>

randombit added a commit that referenced this issue Feb 21, 2024

Fix an iterator debugging error in TLS CBC decryption

6c15872

GH #3916

randombit mentioned this issue Feb 21, 2024

Fix an iterator debugging error in TLS CBC decryption #3918

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[2.19.4] Sporadic test failure with `_GLIBCXX_ASSERTIONS` #3916

[2.19.4] Sporadic test failure with `_GLIBCXX_ASSERTIONS` #3916

thesamesam commented Feb 21, 2024 •

edited

thesamesam commented Feb 21, 2024

randombit commented Feb 21, 2024

randombit commented Feb 21, 2024

randombit commented Feb 21, 2024

thesamesam commented Feb 22, 2024

thesamesam commented Feb 22, 2024 •

edited

thesamesam commented Feb 22, 2024 •

edited

reneme commented Feb 22, 2024

[2.19.4] Sporadic test failure with _GLIBCXX_ASSERTIONS #3916

[2.19.4] Sporadic test failure with _GLIBCXX_ASSERTIONS #3916

Comments

thesamesam commented Feb 21, 2024 • edited

thesamesam commented Feb 21, 2024

randombit commented Feb 21, 2024

randombit commented Feb 21, 2024

randombit commented Feb 21, 2024

thesamesam commented Feb 22, 2024

thesamesam commented Feb 22, 2024 • edited

thesamesam commented Feb 22, 2024 • edited

reneme commented Feb 22, 2024

[2.19.4] Sporadic test failure with `_GLIBCXX_ASSERTIONS` #3916

[2.19.4] Sporadic test failure with `_GLIBCXX_ASSERTIONS` #3916

thesamesam commented Feb 21, 2024 •

edited

thesamesam commented Feb 22, 2024 •

edited

thesamesam commented Feb 22, 2024 •

edited