Sporadic test failure with 3.1.0 (related to BOTAN_CLEAR_CPUID -- 0cd6692)

[thesamesam]

Hi folks,

Thanks for Botan. I package it in Gentoo and hit the following test failure when first bumping our package to 3.1.0:

SP800-108-Feedback(HMAC(SHA-1)) ran 120 tests in 2.72 msec all ok
SP800-108-Feedback(HMAC(SHA-256)) ran 120 tests in 2.73 msec all ok
SP800-108-Feedback(HMAC(SHA-384)) ran 120 tests in 3.02 msec all ok
SP800-108-Feedback(HMAC(SHA-512)) ran 120 tests in 2.61 msec all ok
SP800-108-Pipeline(CMAC(AES-128)) ran 120 tests in 3.87 msec 1 FAILED
Failure 1: SP800-108-Pipeline(CMAC(AES-128)) unexpected result for derived key
Produced: 7020B91FCED6BBC5A9A2F196
Expected: A2762C4FF7BC4D21E5C25245
XOR Diff: D2569550396AF6E44C60A3D3 (at src/tests/test_kdf.cpp:54)
Note 1: SP800-108-Pipeline(CMAC(AES-128)) Test # 18 SP800-108-Pipeline(CMAC(AES-128)) failed Output=A2762C4FF7BC4D21E5C25245 Secret=F9089D56D9A6C6F6BCB9992D1896510C
SP800-108-Pipeline(CMAC(AES-192)) ran 120 tests in 4.28 msec all ok
SP800-108-Pipeline(CMAC(AES-256)) ran 120 tests in 3.91 msec all ok
SP800-108-Pipeline(CMAC(TripleDES)) ran 120 tests in 1.86 msec all ok
SP800-108-Pipeline(HMAC(SHA-1)) ran 120 tests in 3.97 msec all ok
SP800-108-Pipeline(HMAC(SHA-256)) ran 120 tests in 3.90 msec all ok
SP800-108-Pipeline(HMAC(SHA-384)) ran 120 tests in 3.89 msec all ok
SP800-108-Pipeline(HMAC(SHA-512)) ran 120 tests in 3.88 msec all ok
SP800-56A(HMAC(SHA-1)) ran 200 tests in 2.92 msec all ok
SP800-56A(HMAC(SHA-224)) ran 196 tests in 3.55 msec all ok
SP800-56A(HMAC(SHA-256)) ran 196 tests in 3.55 msec all ok
SP800-56A(HMAC(SHA-384)) ran 196 tests in 3.54 msec all ok
SP800-56A(HMAC(SHA-512)) ran 192 tests in 3.96 msec all ok
[...]
zfec:
ZFEC encoding/decoding ran 10449 tests in 8.10 msec all ok
Tests complete ran 2927570 tests in 22.14 sec 1 tests failed (in kdf_kat)
 * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
 *   Validation tests failed

I can't reproduce this on subsequent runs yet..

This is with GCC 13.1.1 20230708 on amd64. The machine has ECC ram and I don't see any EDAC events though..

[thesamesam]

After running in a loop, I got it to fail again:

$ grep -rsin failed /var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log -C 5
1881-Kyber_768_90s ran 800 tests in 148.90 msec all ok
1882-kyber_keygen:
1883-Kyber Kyber-1024-90s-r3 keygen ran 28 tests in 1.01 sec all ok
1884-Kyber Kyber-1024-r3 keygen ran 28 tests in 1.38 sec all ok
1885-Kyber Kyber-512-90s-r3 keygen ran 28 tests in 1.15 sec all ok
1886:Kyber Kyber-512-r3 keygen ran 26 tests in 1.19 sec 1 FAILED
1887:Failure 1: Kyber Kyber-512-r3 keygen roundtrip encrypted PEM private key with error PKCS #8 private key decoding failed with Invalid CBC padding (at src/tests/test_kyber.cpp:280)
1888-Kyber Kyber-768-90s-r3 keygen ran 28 tests in 998.07 msec all ok
1889-Kyber Kyber-768-r3 keygen ran 28 tests in 2.10 sec all ok
1890-kyber_pairwise:
1891-Kyber1024 API ran 6 tests all ok
1892-Kyber1024_90s API ran 6 tests all ok
--
2630-XMSS/SHAKE_16_512 verify invalid signature ran 28 tests in 465.36 msec all ok
2631-XMSS/SHAKE_20_256 verify invalid signature ran 28 tests in 289.62 msec all ok
2632-XMSS/SHAKE_20_512 verify invalid signature ran 28 tests in 414.43 msec all ok
2633-zfec:
2634-ZFEC encoding/decoding ran 10449 tests in 8.80 msec all ok
2635:Tests complete ran 2927568 tests in 22.71 sec 1 tests failed (in kyber_keygen)
2636: * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
2637: *   Validation tests failed
2638- *
2639- * Call stack:
2640- *     ebuild.sh, line 136:  Called src_test
2641- *   environment, line 2757:  Called die
2642- * The specific snippet of code:
2643: *       LD_LIBRARY_PATH="${S}" ./botan-test$(ver_cut 1) || die "Validation tests failed"
2644- *
2645- * If you need support, post the output of `emerge --info '=dev-libs/botan-3.1.0::gentoo'`,
2646- * the complete build log and the output of `emerge -pqv '=dev-libs/botan-3.1.0::gentoo'`.
2647- * The complete build log is located at '/var/log/portage/build/dev-libs/botan-3.1.0:20230712-062143.log'.
2648- * For convenience, a symlink to the build log is located at '/var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log'.
``

[reneme]

Thanks for reporting and investigating. You've seen two different tests fail:

SP800-108-Pipeline(CMAC(AES-128))

SP800-108-Pipeline(CMAC(AES-128)) ran 120 tests in 3.87 msec 1 FAILED
Failure 1: SP800-108-Pipeline(CMAC(AES-128)) unexpected result for derived key
Produced: 7020B91FCED6BBC5A9A2F196
Expected: A2762C4FF7BC4D21E5C25245
XOR Diff: D2569550396AF6E44C60A3D3 (at src/tests/test_kdf.cpp:54)
Note 1: SP800-108-Pipeline(CMAC(AES-128)) Test # 18 SP800-108-Pipeline(CMAC(AES-128)) failed Output=A2762C4FF7BC4D21E5C25245 Secret=F9089D56D9A6C6F6BCB9992D1896510C

kyber_keygen

1886:Kyber Kyber-512-r3 keygen ran 26 tests in 1.19 sec 1 FAILED
1887:Failure 1: Kyber Kyber-512-r3 keygen roundtrip encrypted PEM private key with error PKCS #8 private key decoding failed with Invalid CBC padding (at src/tests/test_kyber.cpp:280)

It seems the Kyber test fails due to an issue during the generic private key decoding/decryption: encountering an invalid CBC padding.

We'll look into it.

[thesamesam]

Thanks! Please let me know if I can grab some more information. Happy to try building with asan/ubsan/whatever. Running in a loop with Valgrind would be doable but a bit trickier given how much slower it makes it.

[reneme]

You've been looping the entire test corpus, right?

Just looping the failing kyber_keygen test didn't give me any errors in about 4000 iterations, unfortunately.

i=1; while ./botan-test kyber_keygen; do echo $i; i=$(( i+1 )); done

Edit: same with kdf_kat in 20k iterations. :(

i=1; while ./botan-test kdf_kat; do echo $i; i=$(( i+1 )); done

Edit 2: the full corpus failed rather quickly. 😮

I seem to be able to reproduce it.

Edit 3: 50 iterations of the test corpus on Botan 3.0.0 came back clean.

[thesamesam]

Yeah, running the whole corpus.

Any chance of it being a parallelism thing (either there being some missing locking between the threads, or re-using the same test files)? I've not yet tried using a failing seed again either..

Edit: heh, so I realised we weren't passing --test-threads=N in our packaging (we want it to respect the user's chosen level of parallelism) and then on that run:

$ grep -rsin failed /var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log -C 5
1332-Diffie-Hellman/KDF2(SHA-1) Valid key agreement ran 8 tests in 25.18 msec all ok
1333-Diffie-Hellman/Raw Valid key agreement ran 108 tests in 189.21 msec all ok
1334-dh_keygen:
1335-DH modp/ietf/1024 keygen ran 28 tests in 267.72 msec all ok
1336-dilithium_kat_4x4_AES_Deterministic:
1337:Dilithium_4x4_AES ran 601 tests in 165.10 msec 4 FAILED
1338-Failure 1: Dilithium_4x4_AES unexpected result for generated expected signature hash
1339-Produced: 8D481FAB10E705BE20AD8631ECE62D11E167C11C66C7D74DD66D8BC465BB475D
1340-Expected: 02BE7AAD469649B0F6833B3B975A8897829A4F987394DAB82D8D0BF55BBEEE11
1341-XOR Diff: 8FF6650656714C0ED62EBD0A7BBCA58663FD8E8415530DF5FBE080313E05A94C (at src/tests/test_dilithium.cpp:101)
1342-Failure 2: Dilithium_4x4_AES unexpected result for generated expected signature
1343-Produced: DED8EE05F87E6F3F8EE1A002CCE94E7751BE596974CB8FF7A5DBD9B9327D1B2DECFE8C69B6D33151CFB220112363A5C779CE35ACAF2AD2583F761C331359DCD124CC0DF0698F7D664E487B0902E00DED33AFCDAEB0162C6C273A82635467F14E76091CC75CB50B39102D4DC3B1597F45411EB9E99A96263E5E436BD7851095797AD0FF24CFDB959FA89F1273C3DAD8F1592FFC5C19F909999106AADD2B64E95192503F8883DE0BCC2069767A76242C64D28F0DAF0341BEBA20713D165677CF9DC5303D80F15EFFBA744656967A223447C38DF65B7E8C819A3F645583A5DCB1067132ABB57CE864877252992D41EB38D8762DCD7544B824194DEC3DACBC739500BEB036EF9F782D8FF4B3F03051C60EB6BB17C6709A2E5784DE5A13C7901E39E0E0879F7824AEFC6E8CBF51065EFFFE3BF4FE3DC55CEAF75BF095B482DFB1D0E069D96C71930F0AAABFB57FB2975BBB0712F8614814B9885CBD9F745C33C7499C5BCFD066B7A110E8143A6C993D8525BDBD47C3A5970EBD71C0F142B1A7E246806637B812CB431EC1B04DD2969EFD3E7ED3E77308C39FD6CA973A020602E64622E7812935E6F9FC5D1DC81B63E8A43C587835606914BEA6A883BB0A4DA80F7F42342F4EB8A53C0EDB7C5DABDD0CD7E52C0242A35DEC667CF39F9A45D529EB0C9FD3F8DC959CD6A7AD6F1B87C529D1D0039507CE8C27E31F9B7F085C092D23DE210E529F6DE7EFDD3880687472DFE5773EBAC074D9F17A450BF4E3644442A34CB7396B9CDF50605197C805CFC8118DFBD011EEA3157C6744ABC7ABAC8D19D7B62C899ED2AA0A56ACB0FBC3A39E49907EEF8F5EDEC1437599583329A17B684FB034DA519CB3189E8CEC6DA2AA7D4CF032544FE0B04BC631FFCC0D921C7F79B8ECC7776B9C88365950C706D47A280469795CE87C9B2E864B47A3D9C57DBD46C818E4E2665C9EB103D7A9BDF8E27F1F93487F6F19BF1427C748F9CCAEC38AB3AAA220A32D88E50FDC4AD62CC86A44F8187BB3AD78B48BCBA4EF9FEEB790B8B8C97020B84C69C7F141737D11EB52D71D54509F616EE55BA3751BF5D4075458BDC8FDF2DE48AA8638F761A7DDF2B4E39775D947A1A3C420D8CDC062B9E8E3F764135AC1A76C71E5801B047AA01F36E878EB1185C79EDE3601922169265CA27B45930BA180737CD6CA3B7E80ED177102209232318364D37BC8449396D8D36E8200F36CDE8D5A09FC788BB3625B2D000C6A499C1AAF2665CBE27F6A07CAC985F68503ACD309758B818F5937E2DCC0E7CCA9FF7FE506B75FADE1D462E5DBC07990B69E711891AFF53B2064FC59C2A55F6DE3B513E53E8A5444170D20E1064FF71B1C169AAADD855E99BD01FE36E80FACC256457DEF1CE11D064F96E68FD7F09605B6CAAFF3FBE119FCE9B8ACFC426B75382FCB76AA503CA626BDB5F8D7B8CA07BCD4EE23C16973C6BE728DEBBF447F509ACA98822A2EA413A5C64EDA2E020DF3F800CDBF6FE33C0F2CB01348B44FF9D940BE605B45193A9CED74597FC8EEA5FD51E3DC1751083C7FEB016B120FF193B8CDD94921DE5A2E0ADAFFD5CEEE7BB46BBDC5DECB5D8DBECFEF890E0B2D281C87C7805D2087F4B56DE490278FF7A1D7E21A0B7F6B9701807BF369E16EE8A4612633AA4737762239FFD9740732F5DD0AB61A3B7A818F80D1FA0DDBC6966B5C5B82082C11D9EFBDA081CA8A6F2517F8346800D1DA7A8C41B4F4168EC0B001C66BC12FC524E1FAE65828BE316D2DCC15150A22A11F9DAC6534A3607155A6F21A2D76422B5C059E8DE67E46E8BDB8C0467F156A64A093B56AD9190DA03DD4B224E7E3802D2B6A5A8660CFF6748FE5FD86DF88AEF1350284B49237CFA8309863BCD832E582AE33D9FD5775B89DD16B43EE7F97017EA4EF07E96B7493651502DF686A162EFB0BA9B261DE3A893149C067CE7303D9DB3A8E2276593F53AF034A581D41712C6FA435D3EBD731134751A237D80EB95B8925C6659E70516FC78C9F3412F3A44CF2438D82F53954C7177851FD03FC3A90AE45114E51BA9F9F41ED9F3680AFBDDEC5F63A7783A27D84F1621E947F81C638EBC9AE86DAE3EF252B47CEEC4E52C3FC2195C3FA29E1378ACFFA706588F7838F69247A0FDD6757A46E46154B1652E00EEA3384E5214C44FFD91006DDEC64083597956DC6DB9F9573400AD8ABB9C6ED8F95867A239099D9D04603B7C0B645DE1AADF15B828B6FA8FB6E3680B3707FE6E6245BC6AAEAD0D618E190D1E7BAA87BFA27F31FD1F0800895C8EE2A7A43AB7C6E3CCBAD00EF36BBAE51152DFD61B32664507005FC1D20CB37C5DDC377AA4EC07971924D7F87643A18B8605DBC63DF3A39404440B05BC27035FB2AAE9191A9593D91FAE4271A23BB59040E5CD429595E9CD42B588C908FDDBA8F41E21FB293FA4578A4371E0A6A86CD780C2E6F705905E8033704444CE528E17D74D061EA36F4EDAE336E05F4EF2B9D7A1F50051AA2B14262F151ABC7F141A55FBA8A9664C6AD0135A0635854EA65497DB06AC04A79F7BBA1A095D019CFD5092E6EB0681E7FCF6E7B559CDEBFB978822DF6F43111BC69010F8B4FE2CA687204F1CB5D133698121D40EC456563E69CDB2DAA3F338A186BA532DC96FF9C51A08084A2B5856F5DAE5B5707197CA53018C5AE9CCC62BCE3C4BF101E7F903A242384EDFDE32C2D20E09393678664E9916846748C9E4FCE7D39AD493D48CAC4454806D7186F24C01C7CBC052F532CABCB1A8B0B80C8488D34B37A8C735DB31579EEBC45FBA4F4F790E4A0B5320A0F58D9A9C38C89422465710124D03780954D1873AF079B4EBFE40942791F8FAD2B2522989DF53B9CDBA7A4D2208D197A818783B78F9608C59307DE62CE96A82C7BC4D300F7310648C30ADEA92FEAE6FC5B3E4B65CC30693F8316AC15521420AF6DB072EE887A3F5FCEFA61A57046FE9B84BCEBB5EB629E4A8ECCF051AF0FA5FE2AEFE22BCC99D317FBB2E9EEEE6074BB60CA1E0C81B870957B2246EC99FB3A0EAE58AACD1879ED28FE71EDEA565EC13972FD3F7085D7535530C97BBA316A47E348B7A6D0536882A0B633D319C0F48DDF4CD3247BCC29A8ADB38FB32AE74F25E8E512F5854EA70D22B965742D5D03168F2E93177DB5A23FF68447D6782737ED1E9C880E084729B633085EC8D80FDE63A6CE9D70553D37006D1F4D1C2BE270DC09208012042EC08ECB63458190A75AC6DA9514641A7F76A025422AB34FCA0C57204A5A6C437FF257DED21B55EDD2E3184394F82D4A9679A4C2F94B9491E7982BC6D824DE3184200E4E9221AB98CCC6B89E0D29547B91A4B0B7C9D2E7E81325394157609FB0BAC0D5DBE2E7ECEDF70105242629355461768387969EABBABED8F00E264E5F676D6F778C99BFCAE9EAEBEDF0FA000000000000000000000000000000000B1C2E40
1344-Expected: EB5742B00BD29D1365DE0E434DA8A154B0D939088507EABF21C68FF30BAEA9F0E6FEB469B6D4F14FCFA520ED2233A54778CE4FACF32A82593F741C3F1351DC21248C06F0688F3566AE473B0602E20DFD336FCDEEB016206C1F3AE2639466F14376391C675CF50839FE2C29C3D159BF45413CB9119B7626FE5D4365D7A910D579FACCFF17CFF7959FA9DF0E73C3DAECF1892E7C5A19F009A19186A99D2864E9516E50FF8703E10BC320C976AA76E43064C88FA5AE0342FEBD206B3D365667CEDDC8301C80FD5E0FBB344256907A4634F7C28DF75B6B8C959A9F659584A5E0B1EE70C2AA757EE84D878E52992D01EF38D77625CD9544B8281958EC99AC5C735506BEA736BB9FD82CCFF5B3FA30BDC61EB6FB16C6729A0657E4DEDA0CC7841E11E05087DF7724A6FCAA8C9F538662FF043C54FFBDC4DCE9F76CF07DB4A2DFF1D1E063D94C71730F0AAABFC67F8E97DBBA4714F84948F4B8E85BFD9B745833B3490C5B4FD166B2A128E8843A2C9D3D852599BDC7C365990EC971C4F1D2B1E7E3468666FBB7D2CCC31FC1B64D0E97BEFDBE7FD3F47318C3DFD70A9B3A0506CAE57623E77E2953E62DFDBD1EC81C63EAA41C58E835206914C5A60884EB0A4DA40F9542582FCEB8E5400EDE7C75ABDD0C97DE2C1842AF5D5C667CF49F8C459529EB0CDFD2F8F29570D637AE6F1B87B929D9D0C394C7D18C32E3179B4F089C0B2D31DE590E32A06DE6EFE438246864729FE67739BAB47429F23A460BE5E3584432A3CCB739619CF750405157C405C3C8F18C7BD351F3A31F7CB3442BC8ABAF8D1BD7EE2C299F12A80A5BAC18FCB3A35E4D908AEFD35E4EC283749960333DA17B670FB434D4519CB3A89FCCEE6D9DAA514C4033D44DE0B44BC2313FCC0D971C84798CEC07786B9788305950C776D3FA28045E795CE83C9BEE884B4DA3C9C52DBEC6C918DBE2925CEEB303D8A9BCF82280EF93487E6F11BF5427274A39D0AEC18A97AA8220E32A88DD0FF84A762D08674408197BB33D79F489CBA1EF67EE978E78B7C96720E44CE9C63146739311E752671D14529F616EF55B9375DBF5D4065428BD38FEF2E348AD8660F7D1A89DF1B4E997D1D9F7A1A3C920D3CDB86279E823F9640D5A0DA87C72257F1B147A881FD6E878EB1196C7A2DE7602D21D69055C927BC593CBA380687CE2CA0B7E40EB175C02409282318363D36AC8009306D913758204F394DE0D5B49FE7882B3665BEDFF8B6B49AA1A7B26E5CAE27E6A0FCA4986468703B2D32675B3812F59B7E6DCCCE73CAAAF7FE503B766AD05D5B2E5DBC77999B692715890AFF83BFD63205A42A59F6EE3BC13C13E3A53C4130D0FE1024F871C1C149AB6DD715EF9BD810237EB0FDCC21645BDF31CE91D324F76E7CFD7F09B0506CBAFF37BE519FBE9C8AC7C44AB78382BCBB2AA303C662BBDAAF8C3B8EA07BCD5EE1EC1A57356BE728FEBBD4463502AC998832A3CA40BA5B64F1A2D020BF350017DBEEFE43C292CCC13E8B44FF8D929BE6C5B9517FA9EED7259C7C87EA63D54E3F6178908CC80EB036B0D0FCD9398CC194B21E45A0E0A9AFF15D2EE81B497BD55DE0B608DC5CF278AEE096D241C73C7385D2087F4B86DD890538F37A297E41A0E7F2F97917FBBF369E36EB0A4C12733A8473C7636393FDAF40932E3DD02B67A3A3A838F93D1EA0DBBC6D6685C5E82DC2B91D86FBDA077CA826FF515383768F4D03A7BDC41F4F91695C01C02666B4134C51EE1F6E6F8283E336D2CCC41154A23211F9DB06530A3707095A4F21F2D3E423B5D059A8DF17E62E84DB880477F0E6A7CA063B52AD819FE9F11D4822467EA80272BBA5A56608FF5748EE521876F89EEF035EB83B092E7CDA8329850BCBC323583AE31D9FE5725B8ADCFEB41EE8297ED7D84EF47E76B7193891572DE286F1630FB03A93262DE3E893949B0671E7343DADB408E2E76793F53AF0346581D41D12CEFA435B9EBAB31134811A237DC0E815B5925C6649E6D51AFC7DC9F3416F3A84C1A440D82753D54BF17AC51DD047C3F90B3455D4E31B9DF9E41E99F26800FBDDEC1F62777CBA1ED83F15D1E807F4DC638EAC9AD86CAE3BF25AB460EEF4E55C37C2225C3BA2FE12D8ADFFAF06488FB839369407ABFDDA75DA47446414B76522011EA4084C521DC423FDA10EEDCB864383517936DBADBA395433E4AD4ABBAC6E58F3586BA22908AD9984673B540BA45F01AE9F1CB834B6EA8E56E4280036F7FE9E61C5BA2AABAD0161BE181D1CFBAC87BFA2AF311D114812894C8E92A7243C37C1E3DCBAD00F536DBAEA1156D0062C1265450B005BC1C20C637CDDD7378EA4CC08771AE4D5F86A43518B660FDBB93DEBA344026405C5BE26FF5F62AA491C5A9593C11FAE4191AF7BAD9044E60D426598A9CF42BD88F90A2DDFA8F51E45FB593054680A4871D8A6886D978D82D0F715905E80837D8430CE568DD7D70D055EAF6F36DA9335905D4EFBB9CFA2250F61992B162623150ABC0F151A55FBB0A9564CAADB134D0619854EA664985B02ABF8A76F7B9A15C95D0190FD709226EC0684E804F6E7B5A9CCABF99790232F60132FDBB29024F8B4FE4CA7C7234F10B58133098DA1CB0EB456363DE9C9F2D0A3EB3851855A50ADC06FE5C4FA08084B2B5056F9DAB5B5107397CF52F98C1AEB5CC62BC53C47F0F1E6F907224C384EDFCE3382D00E04394678564E6914C46848BDE4ECE80394D494D484AC4454D06F3188F24001B7CB605BF525CAC0B1B8B1D80B4481D3373828C6C5DAF1599EF7C47FB9AF4F790749FB5330AF057C1A9A38B493C2451719D239037009E4D09738F07BB4DBFE2093279338F5D2C2524988EF5FB9B3BA864D520A519668157847791960EC557076E628E92A81E7BE0D3D0F5310348BA0ADEA97FE9E6FD5B264B31CC1068FF8516A6157E1440AE2DAD72DB883E3FBFCEBA66A595461A9CD4BCABB8EB629E0A8ECCF011B30F90FE2EEF622A8C9BD30AFBBAE92EEFE075BB47CA020CB1B7309B7B1E46D8999B3A8EAB58A5CD7C79FD287E78EDDB5602C17972BD417073D78355E0C83BC0315847D348C7A61054688AA0E633331900F08DC24CB324ABCC29A8ADB18F6B2AA74EA5E6E506F5AD4E870DE2B965682D7503368F2E971781B5E63FB68507D6781837E91E0C880E094732B65F08DEC61813DE64A6269EC0557D3A00611F5D1C9BE130DE092C80E603EEBFCECA6343819CA7FAC59A9514691A7376F026C226B345CAF856F04B9A704388F223DE421D95EDD2EC184B94582D8A97798FC2E14B6493679A2BBAD860DE418460114E8F218F989CC638A10D22284A546C7A7B858C91A4ACBDC0C5D2FD132C3E4B85AEB2BFC0C8D5DBE9ED0313181E283944516C7A8596A2A8AAB2DEE1E2E3E5F41F2021263F545D65676F7499A2A7B4BFCAD2EDFD00000000000000111F3549
1345-XOR Diff: 358FACB5F3ACF22CEB3FAE418141EF23E1676061F1CC6548841D564A39D3B2DD0A0038000007C01E001700FC0150008001007A005C0050010002000C000800F000400B0001004800E00F400F0002001000C0004000000C0038006000C001000D003000A000400300EE0164006000C000002200F801E000C003000E002C004000801C0033002C000001401C0000003400D0018006000900380080034003000000FC00C00F803F000F00A000D000C01C001A00A80100034007001A0020001001400D0021000C00F00140040006006400B00100010015001400A001C007003C00E801F001C002002900FC0000004004000F000800E000000C001500A400E000C0060017005400A0014001000A00EC001000400100020028006000801F0014002800B000400F000800C4002002803C00FA07A00180018003003700E80020004001000A002000E00000000073003C0080014006002800E0016007400400040074009000800100050038009000400400000024008000C00E007400040090004001000600CC0FC0078001000600DC012000800100130010004001C00C000700C803300100FF006600D401E0030007000200200090004000007B00A0075000000C00EA006C008000407C00050028000000403B001A000C00B0000007001600400000004001002E00EC0090030000007C000800C001C01F00150008003000C0020012007800603F0001003900A400100040030007007400F00340030011003C0070008000000A0028002000C00C000C00E0018003401D000A00D400800F00030002005800A001C002000D00A8077000C00400F4005C009003C0010038001400000F4004000E000000B0014002003F002C00B00180020004000400C000000500FB003400C00F000B00060000007007800000370000004000C00E000A00100050038001003F00F4007002000F000100C0FFF00000010008004000E002C01C0002002400200040070038002400A001C00D00F001000090014002000500F800201EC00F0017005C008001C00700EE000C00B000400200000010003000C0000001007000F003003D0007005800B00F4003000A00A400B000000D000B007800C000C00E001E00CC0F1003C0FF0010002800E00000000013003C004003403C00230030008000C002001B0034003000C006002D006000B000000700110044009001C01B000400F800800140020009000400C0FF8701003600D400800100010008008003B002001E002F003800A0008004000C00F00350000005003900E401D00000070009000C004001000D00DD07DC038000C0030009002400B0078004002F00040070070002001C00F400600080FC01030070004000C01C0008003400E0014000000D00B0010000800400070070008006C00D000400C4006000C00D001F00140020000001003D00CC00900000020002001C00B003000100120018007001C003000600A801B00180070026007C00A00000010069000C00D00EC002000600B8009003C005002A00D800F0FF0002001F003C002001C002003A0020004000C01C00FA00FC009000C03D007B00C803E002400C00F400B8000000000D003C007400C0034006000500440090FFC0000002005800A0010002000B001400C003800E001600080060014002001300100060004003000500D4078001800000F6000800D002C00300F401E0015000400D001B00AC03A000801B003A000C00A0008002000100540040018000001C0004001001C0020005004800100100040017002400F0004001001B001800F000400100F33F2C0030008009000A00D000D0004003000100DC01B001400100E9070400D00200020033006400D00100020003005000301E800200FD00EC032000400E000500EC0070014005001E000800800300040008007000D0004003007A000C0020000000000C000000A0008000006A007C00000F40000004003800D0000001001D00C00050000004000C00E80780008004007800D40020078005001D004C00600340010004001000A0000004001D0048039007003F001400CC000001000300100050008001C0030007008003B0004006001A0010008001000C001C006400B000C00A001A0054006000C01F00730020009006C00300E801540030008006007C003C00307E400C0003000800A000C00100130048007002800C002E0044009001C001001E007400B01F000F00380064005000C00300110028006000000D000E00E40120010007000800680070010000001A006000F00040FD0372003000C0004001000D000800B00F400200FE003C002001C00F000E00A007F001800D006200EC00201FC00D000A00540000018000003E00D4018000403C000F00D40020008003002D0040001006400700FF03F800B0038002001400D40360010000000B00DC074000403C0004003400C007800700370020009001803D00F30330002000C001000700100000018003000C00B0017002C000000300F800407FC00F000200FC000000C002000C00700050FF8000000F0014002001801F00F503EC074003400000060014003000C005000600C801F00700060038004400A001800F003E0038009001C01E00000010008000C0050006002000501F80040029000000B000C01F0010004800E00000010014002000D0070003000F002400F007400100FD00E000700080000005002400E000C007000A0090017007C0010016007C009007C0F8001F001C00E001C002003E000000903F000100FF0F18006007C07E0034009C074000800B0011002000200300060070002C00F0070006001300C007E00FC0070028001C00D007C01E000600C400B00040040032002400D002000500790000005003000100180054002001C006000A002C006001401D0035004400E000400700E500E4075000400D00000040000000401C003500040080014002001D000800C00180010027001C00300F400E003C00340060008005000F006400100080090031005C004000407E00F600D000D001407A00320030007000C0070008005000E000C004001D006000D0000000000200D8004001800E00140028002000C000001C0028002000000400FC00440040014000003F00040090000001001B006C00800EC01C000700E803B000400D000C001000B0034002000C00F407C07F40010006000C00A0034000000D000C005003800C000A00F401D001C01C00F70074009006C000000F000800A000C001002B001800F0028002007C0044007000401F001D0024005000803F000B7C31C5C8CACC4C5E764CBF98F984859D8C9C848B507550582C2522DAECC9253A2D4A494FC7D6FAE42E2C1C705ABCF8AFBD84889B68ACB899F5BDB78E8A9F8E99A2A7B4BFCAD2EDFD000000000000001A031B09 (at src/tests/test_dilithium.cpp:101)
1346-Failure 3: Dilithium_4x4_AES signature verifies produced unexpected result '0' expected '1' (at src/tests/test_dilithium.cpp:101)
1347-Failure 4: Dilithium_4x4_AES signature verifies produced unexpected result '0' expected '1' (at src/tests/test_dilithium.cpp:101)
1348:Note 1: Dilithium_4x4_AES Test # 1 Dilithium_4x4_AES failed HashPk=1ecbf9c21c96e7c287901d8853995fc2edbe0a86680e42a0747e2deb4bd11056 HashSig=02be7aad469649b0f6833b3b975a8897829a4f987394dab82d8d0bf55bbeee11 HashSk=bd0c8516566a958d12a458e7a1b5ac2763208aa9988bec64e3a695dd12d93dd8 Msg=D81C4D8D734FCBFBEADE3D3F8A039FAA2A2C9957E835AD55B22E75BF57BB556AC8 Seed=061550234D158C5EC95595FE04EF7A25767F2E24CC2BC479D09D86DC9ABCFDE7056A8C266F9EF97ED08541DBD2E1FFA1
1349-dilithium_kat_4x4_AES_Randomized:
1350-Dilithium_4x4_AES ran 601 tests in 544.86 msec all ok
1351-dilithium_kat_4x4_Deterministic:
1352-Dilithium_4x4 ran 601 tests in 412.12 msec all ok
1353-dilithium_kat_4x4_Randomized:
--
2360-Handshake involving Hello Retry Request (Client side) ran 68 tests in 111.67 msec all ok
2361-Middlebox Compatibility Mode (Client side) ran 49 tests in 148.10 msec all ok
2362-Resumption with 0-RTT data (Client side) ran 12 tests in 150.97 msec all ok
2363-Simple 1-RTT (Client side) ran 78 tests in 159.82 msec all ok
2364-tls_rfc8448_server:
2365:Client Authentication (Server side) ran 68 tests in 547.24 msec 2 FAILED
2366:Failure 1: Receive Client close_notify failed unexpectedly with error Invalid authentication tag: GCM tag check failed (at src/tests/test_tls_rfc8448.cpp:2068)
2367-Failure 2: Expect Server close_notify unexpected result for Server's close notify
2368-Produced: 17030300131EF8C5693F8E5D66CF95731ACC058E093D399E
2369-Expected: 17030300131DECC5D6E64BBA8A6F21B4FD077497DA2A90CB
2370-XOR Diff: 0000000000031400BFD9C5E7ECA0B4C7E7CB7119D317A955 (at src/tests/test_tls_rfc8448.cpp:2068)
2371:Note 1: Client Authentication (Server side) Test # 1 Client_Authentication_Handshake failed Client_RNG_Pool=6a472236328b83af40386d3a3e1f1ce624fa4ed89ab865a4ff0f4144ce3ae233c040b2bb8f3addd20fd4058c547003a3c6f9c1cd915d5e535c87d8d191aaf071 CurrentTimestamp=1651826546000 Record_ClientFinished=1703030280b46a63934e673841abaf267403bc677f6b6d2a1e2f12bb5f62683bfe36a82673f06d6287ddd609bcf2f5fd3225923d24af3c76682c180ee571a17ca4bfbe2f510dc9a0e1fca5cff2cee87d11cb531a6ef90bf5309a6b63bbbc0b88ea45103a4304091543859fa11ec032ed873444cd5185ead5f6a76420f0f0286acef802c8e4788c23275f1b06da600f4a7decd0bc59d7bef10e649ae32690397fc3d4ed6f30f801d8cd569b71ad4fa05ea7cf2ac2dfa150d220505d4011b34d09d53853eba61a101e4f8dca47d8171a884b19259a3dd48c5ac141983edc77814d25e7f66bbbdb9096839266e06561828ecfb27eafd4e9e81a0b96e3bfa42dae5ad80359b9a6661402c3a2104177030106dbd8f65bb6a0159d512eb13af22a259f313bd58c2e21fe053d57f2a962b0a4ea682c96f70b79b560136192823b27be6a2fb7b1c751ccc0e3303615541485b7b307b423332c11efa80b72f9b80a53e53f7bb38a3af4c59f8008bad0544e5614e688ff57bccd6935f81f447f420c1c1bf4058818e90bf5dc716ccae42524856df8250bcdbd7af65f82dd53061d024f6d2ff5c11e3792a9a70e0ee2a3c20a1b968ac391f8f92831135d25242ada2fe241c2653ec996339dfa12dfae7a3373df88b07ca27aef6dc266a25f13f75c76039c1f46fd7a53ae6399c999f4b2aee18e480d6d12bfae226bbdc92a6ad50b4d3bac7abc3b3651eb5be56f33bf41127b3ca886dc714a50d1490357bd40d9fd6be42209a4ddb9ebb2987e29f120f05814614d2c79320015b461fe7324447670a1af5f65caed15b474ab7faa495016adf808e53b94ef54afbb0e0a3a2732ab597f7d5923c77386aa5124731f8cc73e703b341c175a454939a77ab64313c15cf3fe03c4f33842564976 Record_ClientHello_1=16030100c0010000bc03036a472236328b83af40386d3a3e1f1ce624fa4ed89ab865a4ff0f4144ce3ae2330000061301130313020100008d0000000b0009000006736572766572ff01000100000a00140012001d00170018001901000101010201030104003300260024001d0020089cc2671f738d9a671e5b2e464981d05b76e361aa22aea91f1d49ca10a7a362002b0003020304000d0020001e040305030603020308040805080604010501060102010402050206020202002d00020101001c00024001 Record_Client_CloseNotify=1703030013e4ad7d44c29245339d355962c779b89ef44c58 Record_ServerHandshakeMessages=17030302166d0a7ac079b32a94aa68c4e2893e8bd0d3c185f549c236fbbce3d647f08f3c94a2bf424d8708883605ad8955f97718b0213dead13dfb23ebb8381da582756612bcb5a5d40847719fbe9f179bfae656f3ecfd59a4c0d35132ce418a7e46f6b6a60622f8a6c06b28d83360163563be9c37f97eb902326924a72b3ed8c8381277d1581cab9c3715ac2401398467ad7ebfab3d0c3419e750104f7d62c5027901f2e4cd4ca5b8071eb03d3c732d83215066dfc4d291d4c1ff3b8d7e4298f677d4d51dea1168d8f16cb27ba40266313a1fedf9e23cc77f765450f9e96f05d08f3da245b14d4946f07ec81eed6d56f26bd574f0b7f7c7047037c16fce3b23754e662fad73e2b7213f6af296769c99a1d38e6232e0ec8dc4f84d6aa6f7de3887be0057862f9018e0ab396705aa4090ab5f2dff6325a557e7320d4effd46bb4f997d163207cce6665294aa4465541e3fe37ee7350659ea550d6dcb6af3c518852c7a14c3cc15bc32b3273bdf1751da184203135b117d300204fb12d58ca9ac34b68eca27030832f7a4b46d2a55757f63fe8f6e85ac47469e6198da88a64586bf23c69590de822263be75fd836847240c48f8c145cd6bd698962e7edc234ebe59231351eef8d7652cf3b08ab3af6e5ec74c58a8da34b39f9b0d6c4279a9a1f82071729e7059dd7f7b95b9433c4684ce1891a6d33432d52eddb0b8cee9181d403eccc12991f1ad4aa62c36049713a7bb135fdda6661a05a93f8c16f Record_ServerHello=160303005a0200005603033b50fdf1c3d572e40e68953e7fff4e2758459c59afa0582c0ea032874255fe6e00130100002e00330024001d00206c2e50e865919a6b5a12dfaf918f92b442567b0f89bc54478c6921366658f062002b00020304 Record_Server_CloseNotify=17030300131decc5d6e64bba8a6f21b4fd077497da2a90cb Server_RNG_Pool=3b50fdf1c3d572e40e68953e7fff4e2758459c59afa0582c0ea032874255fe6e7382a5ad1cdd2056ae18cc708bd007d98130dbe2cd4d9ead9b96952becbb0888
2372-Handshake involving Hello Retry Request (Server side) ran 72 tests in 341.47 msec all ok
2373-Middlebox Compatibility Mode (Server side) ran 58 tests in 121.29 msec all ok
2374-Resumption with 0-RTT data (Server side) ran 28 tests in 157.00 msec all ok
2375-Simple 1-RTT (Server side) ran 79 tests in 361.64 msec all ok
2376-tls_session:
--
2646-XMSS/SHAKE_16_512 verify invalid signature ran 28 tests in 534.38 msec all ok
2647-XMSS/SHAKE_20_256 verify invalid signature ran 28 tests in 266.00 msec all ok
2648-XMSS/SHAKE_20_512 verify invalid signature ran 28 tests in 526.00 msec all ok
2649-zfec:
2650-ZFEC encoding/decoding ran 10449 tests in 8.06 msec all ok
2651:Tests complete ran 2927565 tests in 23.98 sec 6 tests failed (in dilithium_kat_4x4_AES_Deterministic tls_rfc8448_server)
2652: * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
2653: *   Validation tests failed

Coincidence, I'm sure, just interesting how there's various different failures that pop up.

Edit 2: meh, using that seed again as ./botan-test3 --drbg-seed=177112CDBBB03DFB --test-threads=32 didn't reproduce it.

Edit 3: Had a report downstream as well at https://bugs.gentoo.org/910240 with a bunch of failures.

[reneme]

I'm currently bisecting this. Obviously that's a bit tricky with a sporadic failure. Along the way I found one more failure mode:

  FFI DSA ran 134 tests in 3.40 sec 1 FAILED
  Failure 1: FFI DSA botan_privkey_load unexpectedly failed with error code -1 (at src/tests/test_ffi.cpp:2906)

Still supporting my hypothesis that something in the low-level private key decryption fails. That is the common denominator of all the observed failure modes.

[reneme]

Bisect points at the merge commit of #3206. "Good" was defined as: at least ten iterations of ./botan-test succeeded.

❗ ❗ Edit: continuing to manually poke around showed the bug before, in 2f7d5296e. So the below bisect did take a wrong turn... Currently trying again requiring more successful operations.

Here is the path (outdated):

bad: a9c4a8e56
bad: ce428cb6e
probably good: 79f50afb7
bad: 1881cd8ed
  FFI DSA ran 134 tests in 3.40 sec 1 FAILED
  Failure 1: FFI DSA botan_privkey_load unexpectedly failed with error code -1 (at src/tests/test_ffi.cpp:2906)
probably good: 003efcdaa
probably good: 8a8dec9bb
probably good: 2f7d5296e
probably good: 805326917

❗ Surprisingly, the actual commit (805326917) in the suspected pull request seems to be "good", but the merge commit isn't.

[reneme]

Another failure mode pointing at sporadic decryption failures:

RSA 1280 keygen ran 26 tests in 894.02 msec 1 FAILED
Failure 1: RSA 1280 keygen roundtrip encrypted BER private key with error PKCS #8 private key decoding failed with Invalid CBC padding (at src/tests/test_rsa.cpp:365)

[reneme]

Here's a second attempt (using 20 iterations as the cutoff). This points at #3535 being the culprit. This finding is consistent with the odd situation in the first bisect round, where the PR's commit seemed okay but the merge commit was found to be the culprit. The CPUID modification was done around the same time, so the PR's commit didn't have that patch, in contrast to the merge commit that brought both together:

a9377f1f5 Add CT::all_zeros
Probably good.

8e2b8c104 Merge GH #3528 Small base64 encoding optimization
Probably good.

003efcdaa Merge GH #3531 Modify headers so ffi.h no longer depends on compiler.h
Probably good.

8a8dec9bb Merge GH #3534 Small cleanups for mul128.h
Probably good.

0cd6692bd Add env var to clear CPUID bits
Definitely bad

16f427848 Fix references to botan2.py [ci skip]
Probably good.

0cd6692bdd150e978c5c18b9c29ab8d466e99ebb is the first bad commit
commit 0cd6692bdd150e978c5c18b9c29ab8d466e99ebb
Author: Jack Lloyd <jack@randombit.net>
Date:   Sat Apr 29 15:57:32 2023 -0400

    Add env var to clear CPUID bits

 doc/api_ref/env_vars.rst      |  5 +++++
 src/lib/utils/cpuid/cpuid.cpp | 13 +++++++++++++
 src/lib/utils/cpuid/cpuid.h   | 30 +++++++++++++++---------------
 src/scripts/test_cli.py       | 29 +++++++++++++++++++++++++++--
 4 files changed, 60 insertions(+), 17 deletions(-)

[reneme]

Indeed, reverting 0cd6692bdd150e978c5c18b9c29ab8d466e99ebb seems to resolve this on master.

[randombit]

I think the problem is not exactly in 0cd6692bdd150e978c5c18b9c29ab8d466e99ebb but rather that this change exposed a pre-existing bug that we had happened to miss prior. Specifically, that commit added checks on the basic SIMD operations like so

-         { return has_cpuid_bit(CPUID_SSSE3_BIT); }
+         { return has_sse2() && has_cpuid_bit(CPUID_SSSE3_BIT); }

And when the (unserialized) ZFEC tests manipulate the CPUID bits, this confuses the AES implementation, which assumes that the CPUID bits are stable over time.

[randombit]

3625

I am unable to repro this locally, probably because my desktop doesn't have enough cores :sob: so I'll need @reneme or @thesamesam to confirm this fixes it

iff --git a/src/tests/test_zfec.cpp b/src/tests/test_zfec.cpp
index 8e873742d..199cf66c9 100644
--- a/src/tests/test_zfec.cpp
+++ b/src/tests/test_zfec.cpp
@@ -102,7 +102,7 @@ class ZFEC_KAT final : public Text_Based_Test {
       }
 };

-BOTAN_REGISTER_TEST("zfec", "zfec", ZFEC_KAT);
+BOTAN_REGISTER_SERIALIZED_TEST("zfec", "zfec", ZFEC_KAT);

 }  // namespace Botan_Tests

[randombit]

We probably missed this entirely in CI simply because we only have 2 or 3 cores there and zfec happens to run at the very end of the test suite due to sorting.

[thesamesam]

It was looking good at first, but after 4 iterations:

$ grep -rsin failed /var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log -C 5
1823-GF2m ran 131064 tests all ok
1824-gost_3410_keygen:
1825-GOST-34.10 gost_256A keygen ran 28 tests in 3.88 sec all ok
1826-GOST-34.10 secp256r1 keygen ran 28 tests in 2.55 sec all ok
1827-gost_3410_sign:
1828:pubkey/gost_3410_sign.vec ran 1 tests 1 FAILED
1829:Failure 1: Test # 1 A=0x7 B=0x5FBFF498AA938CE739B8E022FBAFEF40563F6E6A3472FC2A514C0CE9DAE23B7E Cofactor=1 Gx=2 Gy=0x8E2A8A0E65147D4BD6316030E16D19C85C97F0A9CA267122B96ABBCEA7E8FC8 Hash=Raw Msg=E53E042B67E6EC678E2E02B12A0352CE1FC6EEE0529CC088119AD872B3C1FB2D Nonce=77105C9B20BCD3122823C8CF6FCC7B956DE33814E95B7FE64FED924594DCEAB3 Oid=1.3.6.1.4.1.25258.2 Order=0x8000000000000000000000000000000150FE8A1892976154C59CFC193ACCF5B3 P=0x8000000000000000000000000000000000000000000000000000000000000431 Signature=01456C64BA4642A1653C235A98A60249BCD6D3F746B631DF928014F6C5BF9C4041AA28D2F1AB148280CD9ED56FEDA41974053554A42767B83AD043FD39DC0493 X=0x7A929ADE789BB9BE10ED359DD39A72C11B60961F49397EEE1D19CE9891EC3B28 failed with exception 'Unknown EC_Group 1.3.6.1.4.1.25258.2' (at src/tests/test_gost_3410.cpp:89)
1830-gost_3410_verify:
1831-GOST 34.10-2001/Raw signature verification ran 8 tests in 211.39 msec all ok
1832-hash_nist_mc:
1833-NIST Monte Carlo SHA-1 ran 1 tests in 9.75 msec all ok
1834-NIST Monte Carlo SHA-224 ran 1 tests in 10.31 msec all ok
--
2637-XMSS/SHAKE_16_512 verify invalid signature ran 28 tests in 519.32 msec all ok
2638-XMSS/SHAKE_20_256 verify invalid signature ran 28 tests in 284.70 msec all ok
2639-XMSS/SHAKE_20_512 verify invalid signature ran 28 tests in 542.47 msec all ok
2640-zfec:
2641-ZFEC encoding/decoding ran 10449 tests in 6.79 msec all ok
2642:Tests complete ran 2927554 tests in 24.00 sec 1 tests failed (in gost_3410_sign)
2643: * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
2644: *   Failed to run command: ./botan-test3 --test-threads=32
2645- *
2646- * Call stack:
2647- *     ebuild.sh, line  136:  Called src_test
2648- *   environment, line 2772:  Called edo './botan-test3' '--test-threads=32'
2649- *   environment, line 1130:  Called die
2650- * The specific snippet of code:
2651: *       "$@" || die -n "Failed to run command: $@"
2652- *
2653- * If you need support, post the output of `emerge --info '=dev-libs/botan-3.1.0::gentoo'`,
2654- * the complete build log and the output of `emerge -pqv '=dev-libs/botan-3.1.0::gentoo'`.
2655- * The complete build log is located at '/var/log/portage/build/dev-libs/botan-3.1.0:20230712-121644.log'.
2656- * For convenience, a symlink to the build log is located at '/var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log'.

[reneme]

@randombit We actually drilled to the same conclusion by now: zfec is interferring with the global CPUID bits in the tests while not being marked as "serialized". What we don't understand is the dependency on #3535. Why does this seem to bring it to light? (never mind, overlooked: https://github.com/randombit/botan/issues/3623#issuecomment-1632407591)

Anyway: On my machine the patch seems to be effective (now running the 25th iteration).

[randombit]

That's a really weird test to fail in this context - all of the other failing tests (KDF, Kyber, TLS, etc) would certainly fail if the AES impl did something wrong. But GOST signature scheme, and all of its dependencies, do nothing CPU specific. I wonder if there is some other issue here?

[randombit]

@reneme I think it is not because of BOTAN_CLEAR_CPUID at all but because of the checks like

      static bool has_clmul()
-         { return has_cpuid_bit(CPUID_CLMUL_BIT); }
+         { return has_ssse3() && has_cpuid_bit(CPUID_CLMUL_BIT); }

so when ZFEC cleared SSSE3 in order to run its test, it implicitly also "cleared" CLMUL. So it increased the blast radius of what was affected. Before that point, when ZFEC cleared SSSE3 it would not have affected CLMUL or AESNI, etc.

The intent of that change was that using say BOTAN_CLEAR_CPUID=ssse3 actually disables use of all code using SSSE3; it would be awkward if you used that flag, and then we immediately use SSSE3 in CLMUL code or etc. But this may be too confusing in other parts of the code; I think we should revert that part of the change, at least for now.

[thesamesam]

UBSAN splats for me:

bcrypt ran 380 tests in 7.75 sec all ok
build/include/botan/internal/ffi_util.h:126:23: runtime error: member call on address 0x7f0bd4015980 which does not point to an object of type 'botan_struct'
0x7f0bd4015980: note: object is of type 'botan_mp_struct'
 00 00 00 00  c0 bc 3b f0 0b 7f 00 00  d2 b9 28 c8 00 00 00 00  30 95 00 d4 0b 7f 00 00  25 00 00 00
              ^~~~~~~~~~~~~~~~~~~~~~~
              vptr for 'botan_mp_struct'
    #0 0x7f0beecc8e76 in Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}::operator()() const build/include/botan/internal/ffi_util.h:126
    #1 0x7f0beecc8e76 in int std::__invoke_impl<int, Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}&>(std::__invoke_other, Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}&) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:61
    #2 0x7f0beecc8e76 in std::enable_if<is_invocable_r_v<int, Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}&>, int>::type std::__invoke_r<int, Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}&>(Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}&) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:114
    #3 0x7f0beecc8e76 in std::_Function_handler<int (), Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*)::{lambda()#1}>::_M_invoke(std::_Any_data const&) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/std_function.h:290
    #4 0x7f0beec67125 in std::function<int ()>::operator()() const /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/std_function.h:591
    #5 0x7f0beec67125 in Botan_FFI::ffi_guard_thunk(char const*, std::function<int ()> const&) src/lib/ffi/ffi.cpp:119
    #6 0x7f0beeccb5f8 in int Botan_FFI::ffi_delete_object<Botan::HashFunction, 520769412u>(Botan_FFI::botan_struct<Botan::HashFunction, 520769412u>*, char const*) build/include/botan/internal/ffi_util.h:121
    #7 0x55786f90f628 in ffi_test src/tests/test_ffi.cpp:1428
    #8 0x55786f90ef02 in run src/tests/test_ffi.cpp:56
    #9 0x55786f63f4b4 in run_a_test src/tests/runner/test_runner.cpp:160
    #10 0x55786f6448a6 in operator() src/tests/runner/test_runner.cpp:208
    #11 0x55786f6448a6 in __invoke_impl<std::vector<Botan_Tests::Test::Result>, Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:61
    #12 0x55786f6448a6 in __invoke<Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:97
    #13 0x55786f6448a6 in __call<std::vector<Botan_Tests::Test::Result>, 0> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/functional:508
    #14 0x55786f6448a6 in operator()<> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/functional:593
    #15 0x55786f6448a6 in __invoke_impl<std::vector<Botan_Tests::Test::Result>, std::_Bind<Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>(std::__cxx11::basic_string<char>)>&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:61
    #16 0x55786f6448a6 in __invoke_r<std::vector<Botan_Tests::Test::Result>, std::_Bind<Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>(std::__cxx11::basic_string<char>)>&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:116
    #17 0x55786f6448a6 in operator() /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/future:1492
    #18 0x55786f6448a6 in operator() /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/future:1409
    #19 0x55786f6448a6 in __invoke_impl<std::unique_ptr<std::__future_base::_Result<std::vector<Botan_Tests::Test::Result> >, std::__future_base::_Result_base::_Deleter>, std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<std::vector<Botan_Tests::Test::Result> >, std::__future_base::_Result_base::_Deleter>, std::__future_base::_Task_state<std::_Bind<Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>(std::__cxx11::basic_string<char>)>, std::allocator<int>, std::vector<Botan_Tests::Test::Result>()>::_M_run()::<lambda()>, std::vector<Botan_Tests::Test::Result> >&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:61
    #20 0x55786f6448a6 in __invoke_r<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter>, std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<std::vector<Botan_Tests::Test::Result> >, std::__future_base::_Result_base::_Deleter>, std::__future_base::_Task_state<std::_Bind<Botan_Tests::Test_Runner::run_tests_multithreaded(const std::vector<std::__cxx11::basic_string<char> >&, size_t)::<lambda(const std::string&)>(std::__cxx11::basic_string<char>)>, std::allocator<int>, std::vector<Botan_Tests::Test::Result>()>::_M_run()::<lambda()>, std::vector<Botan_Tests::Test::Result> >&> /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/invoke.h:116
    #21 0x55786f6448a6 in _M_invoke /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/std_function.h:291
    #22 0x55786f65135d in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/std_function.h:591
    #23 0x55786f65135d in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/future:589
    #24 0x7f0bee0ae506  (/usr/lib64/libc.so.6+0x8d506)
    #25 0x55786f65401f in __gthread_once /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/x86_64-pc-linux-gnu/bits/gthr-default.h:700
    #26 0x55786f65401f in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/mutex:907
    #27 0x55786f634356 in std::__future_base::_State_baseV2::_M_set_result(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>, bool) /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/future:428
    #28 0x55786f634356 in _M_run /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/future:1494
    #29 0x7f0beffdadda in std::function<void ()>::operator()() const /usr/lib/gcc/x86_64-pc-linux-gnu/13/include/g++-v13/bits/std_function.h:591
    #30 0x7f0beffdadda in Botan::Thread_Pool::worker_thread() src/lib/utils/thread_utils/thread_pool.cpp:127
    #31 0x7f0bee2ec2e2 in execute_native_thread_routine /usr/src/debug/sys-devel/gcc-14.0.0_pre20230709/gcc-14-20230709/libstdc++-v3/src/c++11/thread.cc:104
    #32 0x7f0bee0a94f0  (/usr/lib64/libc.so.6+0x884f0)
    #33 0x7f0bee12e34f  (/usr/lib64/libc.so.6+0x10d34f)

 * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
 *   Failed to run command: ./botan-test3 --test-threads=32

Full log: http://sprunge.us/sqkQz0

[randombit]

@thesamesam That's an test that is intentionally UB because that's the only way we can check an error case. I imagine this happened because you passed the UbSan flags directly via CXXFLAGS - we expect UbSan to be set with --enable-sanitizers=undefined in which case we set a macro and skip tests of this sort.

[thesamesam]

Thanks, lemme adjust the ebuild to handle that.

[thesamesam]

Failed again after 5 iterations or so (with ubsan but no output from it):

$ grep -rsin failed /var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log -C 5
1584-GF2m ran 131064 tests all ok
1585-gost_3410_keygen:
1586-GOST-34.10 gost_256A keygen ran 28 tests in 5.02 sec all ok
1587-GOST-34.10 secp256r1 keygen ran 28 tests in 3.13 sec all ok
1588-gost_3410_sign:
1589:pubkey/gost_3410_sign.vec ran 1 tests 1 FAILED
1590:Failure 1: Test # 1 A=0x7 B=0x5FBFF498AA938CE739B8E022FBAFEF40563F6E6A3472FC2A514C0CE9DAE23B7E Cofactor=1 Gx=2 Gy=0x8E2A8A0E65147D4BD6316030E16D19C85C97F0A9CA267122B96ABBCEA7E8FC8 Hash=Raw Msg=E53E042B67E6EC678E2E02B12A0352CE1FC6EEE0529CC088119AD872B3C1FB2D Nonce=77105C9B20BCD3122823C8CF6FCC7B956DE33814E95B7FE64FED924594DCEAB3 Oid=1.3.6.1.4.1.25258.2 Order=0x8000000000000000000000000000000150FE8A1892976154C59CFC193ACCF5B3 P=0x8000000000000000000000000000000000000000000000000000000000000431 Signature=01456C64BA4642A1653C235A98A60249BCD6D3F746B631DF928014F6C5BF9C4041AA28D2F1AB148280CD9ED56FEDA41974053554A42767B83AD043FD39DC0493 X=0x7A929ADE789BB9BE10ED359DD39A72C11B60961F49397EEE1D19CE9891EC3B28 failed with exception 'Unknown EC_Group 1.3.6.1.4.1.25258.2' (at src/tests/test_gost_3410.cpp:89)
1591-gost_3410_verify:
1592-GOST 34.10-2001/Raw signature verification ran 8 tests in 848.16 msec all ok
1593-hash_nist_mc:
1594-NIST Monte Carlo SHA-1 ran 1 tests in 17.64 msec all ok
1595-NIST Monte Carlo SHA-224 ran 1 tests in 19.24 msec all ok
--
2398-XMSS/SHAKE_16_512 verify invalid signature ran 28 tests in 614.72 msec all ok
2399-XMSS/SHAKE_20_256 verify invalid signature ran 28 tests in 340.02 msec all ok
2400-XMSS/SHAKE_20_512 verify invalid signature ran 28 tests in 582.92 msec all ok
2401-zfec:
2402-ZFEC encoding/decoding ran 10449 tests in 21.14 msec all ok
2403:Tests complete ran 2927553 tests in 35.46 sec 1 tests failed (in gost_3410_sign)
2404: * ERROR: dev-libs/botan-3.1.0::gentoo failed (test phase):
2405: *   Failed to run command: ./botan-test3 --test-threads=32
2406- *
2407- * Call stack:
2408- *     ebuild.sh, line  136:  Called src_test
2409- *   environment, line 3217:  Called edo './botan-test3' '--test-threads=32'
2410- *   environment, line 1392:  Called die
2411- * The specific snippet of code:
2412: *       "$@" || die -n "Failed to run command: $@"
2413- *
2414- * If you need support, post the output of `emerge --info '=dev-libs/botan-3.1.0::gentoo'`,
2415- * the complete build log and the output of `emerge -pqv '=dev-libs/botan-3.1.0::gentoo'`.
2416- * The complete build log is located at '/var/log/portage/build/dev-libs/botan-3.1.0:20230712-232747.log'.
2417- * For convenience, a symlink to the build log is located at '/var/tmp/portage/dev-libs/botan-3.1.0/temp/build.log'.

[randombit]

Aha, the GOST problem is another dependency between tests. Namely the GOST tests need to register a new curve, but some of the ECC tests clear all of the curve info, and if they race the GOST tests break.

There is probably a better fix to be had here but in the short term serializing the ECC tests should do the trick.

Interestingly I'm also unable to reproduce this one, even on a 192 core POWER machine, but I'm betting this is the fix

diff --git a/src/tests/test_ec_group.cpp b/src/tests/test_ec_group.cpp
index ae902f13c..59223dacd 100644
--- a/src/tests/test_ec_group.cpp
+++ b/src/tests/test_ec_group.cpp
@@ -743,7 +743,7 @@ class ECC_Unit_Tests final : public Test {
       }
 };

-BOTAN_REGISTER_TEST("pubkey", "ecc_unit", ECC_Unit_Tests);
+BOTAN_REGISTER_SERIALIZED_TEST("pubkey", "ecc_unit", ECC_Unit_Tests);

    #if defined(BOTAN_HAS_ECDSA)

[thesamesam]

Nice! Trying the diff from the PR now.

(We have a 96-cored arm64 box (and a 266-cored sparc one, but I assume your interest in that is less, although it's great for alignment checking) if either of you two ever want access to it. It's purely for development and testing stuff like this, so it's no bother.)

Edit: I'm going to declare victory for now after 35 good iterations. Thank you!

[randombit]

@thesamesam Fixes are included in the newly released 3.1.1. Thanks so much for reporting this and all your help in repro and testing.