[MDEV-8444] mysql-test - main.openssl_6975 is failing with fips=1 Created: 2015-07-10  Updated: 2017-05-17  Due: 2016-08-28  Resolved: 2017-05-17

Status: Closed
Project: MariaDB Server
Component/s: SSL
Affects Version/s: 10.0.16, 10.0.20
Fix Version/s: N/A

Type: Bug Priority: Minor
Reporter: Nirbhay Choubey (Inactive) Assignee: Sergei Golubchik
Resolution: Won't Fix Votes: 0
Labels: SUSE, fips, upstream

Sprint: 10.0.22, 10.0.25

 Description    

dhcp72:/usr/share/mysql-test # ./mysql-test-run.pl main.openssl_6975 --force
 
Logging: ./mysql-test-run.pl  main.openssl_6975 --force
 
vardir: /usr/share/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/usr/share/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.0.20-MariaDB
 
 - SSL connections supported
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
worker[1] mysql-test-run: WARNING: running this script as _root_ will cause some tests to be skipped
 
main.openssl_6975 'tlsv10'               [ fail ]
 
        Test ended at 2015-07-08 08:59:23
 
 
 
CURRENT_TEST: main.openssl_6975
 
--- /usr/share/mysql-test/r/openssl_6975,tlsv10.result	2015-06-17 10:54:11.000000000 -0400
 
+++ /usr/share/mysql-test/r/openssl_6975,tlsv10.reject	2015-07-08 08:59:23.372542505 -0400
 
@@ -10,16 +10,14 @@
 
 ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
 ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
 SSLv3 ciphers: user is ok with any cipher
 
-Variable_name	Value
 
-Ssl_cipher	RC4-SHA
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 Variable_name	Value
 
 Ssl_cipher	DHE-RSA-AES256-SHA
 
 SSLv3 ciphers: user requires SSLv3 cipher RC4-SHA
 
-Variable_name	Value
 
-Ssl_cipher	RC4-SHA
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 ERROR 1045 (28000): Access denied for user 'ssl_sslv3'@'localhost' (using password: NO)
 
 SSLv3 ciphers: user requires TLSv1.2 cipher AES128-SHA256
 
-ERROR 1045 (28000): Access denied for user 'ssl_tls12'@'localhost' (using password: NO)
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 ERROR 1045 (28000): Access denied for user 'ssl_tls12'@'localhost' (using password: NO)
 
 drop user ssl_sslv3@localhost;
 
 drop user ssl_tls12@localhost;
 
 
 
mysqltest: Result length mismatch
 
 
 
 - saving '/usr/share/mysql-test/var/log/main.openssl_6975-tlsv10/' to '/usr/share/mysql-test/var/log/main.openssl_6975-tlsv10/'
 
main.openssl_6975 'tlsv12'               [ fail ]
 
        Test ended at 2015-07-08 08:59:25
 
 
 
CURRENT_TEST: main.openssl_6975
 
--- /usr/share/mysql-test/r/openssl_6975,tlsv12.result	2015-06-17 10:54:11.000000000 -0400
 
+++ /usr/share/mysql-test/r/openssl_6975,tlsv12.reject	2015-07-08 08:59:24.944542505 -0400
 
@@ -13,13 +13,13 @@
 
 Ssl_cipher	AES128-SHA256
 
 ERROR 1045 (28000): Access denied for user 'ssl_tls12'@'localhost' (using password: NO)
 
 SSLv3 ciphers: user is ok with any cipher
 
-ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
 SSLv3 ciphers: user requires SSLv3 cipher RC4-SHA
 
-ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
 SSLv3 ciphers: user requires TLSv1.2 cipher AES128-SHA256
 
-ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
+ERROR 2026 (HY000): SSL connection error: Failed to set ciphers to use
 
 ERROR 2026 (HY000): SSL connection error: error:14077410:SSL routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
 
 drop user ssl_sslv3@localhost;
 
 drop user ssl_tls12@localhost;
 
 
 
mysqltest: Result length mismatch
 
 
 
 - saving '/usr/share/mysql-test/var/log/main.openssl_6975-tlsv12/' to '/usr/share/mysql-test/var/log/main.openssl_6975-tlsv12/'
 
--------------------------------------------------------------------------
 
The servers were restarted 1 times
 
Spent 0.000 of 14 seconds executing testcases
 
 
 
Completed: Failed 2/2 tests, 0.00% were successful.
 
 
 
Failing test(s): main.openssl_6975
 
 
 
The log files in var/log may give you some hint of what went wrong.
 
 
 
If you want to report this error, please read first the documentation
 
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
 
 
 
mysql-test-run: *** ERROR: there were failing test cases
 
dhcp72:/usr/share/mysql-test #

mariadb-10.0.20-18.1.x86_64
openssl-1.0.1i-25.1.x86_64

found also on mariadb-10.0.16-15.1.x86_64

https://bugzilla.suse.com/show_bug.cgi?id=937388

 Comments   
Comment by Nirbhay Choubey (Inactive) [ 2015-07-10 ]

Test passed on my system.

 
 
$ cat /etc/issue
 
Ubuntu 14.04.2 LTS \n \l
 
 
 
$ perl mtr main.openssl_6975
 
Logging: mtr  main.openssl_6975
 
vardir: /home/nirbhay/project/git-repo/maria/10.0/install/mysql-test/var
 
Checking leftover processes...
 
 - found old pid 9789 in 'mysqld.1.pid', killing it...
 
   process did not exist!
 
Removing old var directory...
 
Creating var directory '/home/nirbhay/project/git-repo/maria/10.0/install/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.0.20-MariaDB-debug
 
 - SSL connections supported
 
 - binaries are debug compiled
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
main.openssl_6975 'tlsv10'               [ pass ]    260
 
main.openssl_6975 'tlsv12'               [ pass ]    290
 
--------------------------------------------------------------------------
 
The servers were restarted 1 times
 
Spent 0.550 of 7 seconds executing testcases
 
 
 
Completed: All 2 tests were successful.

Comment by Elena Stepanova [ 2015-07-12 ]

nirbhay_c,

Can you reproduce it on their binaries? Do you know how to obtain official SUSE binaries for 10.0?

Comment by Nirbhay Choubey (Inactive) [ 2015-07-16 ]

elenst I have requested for the binaries. An update is that it happens with fips=1.

Comment by Nirbhay Choubey (Inactive) [ 2015-07-17 ]

Couldn't reproduce with fips enabled.

[nirbhay@localhost mysql-test]$ cat /etc/issue
 
CentOS release 6.6 (Final)
 
Kernel \r on an \m
 
 
 
[nirbhay@localhost mysql-test]$ cat /proc/sys/crypto/fips_enabled 
1
 
[nirbhay@localhost mysql-test]$ perl mtr main.openssl_6975
 
Logging: mtr  main.openssl_6975
 
vardir: /home/nirbhay/project/git-repo/maria/bld/10.0.20/install/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/home/nirbhay/project/git-repo/maria/bld/10.0.20/install/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.0.20-MariaDB-debug
 
 - SSL connections supported
 
 - binaries are debug compiled
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
main.openssl_6975 'tlsv10'               [ pass ]    333
 
main.openssl_6975 'tlsv12'               [ pass ]    318
 
--------------------------------------------------------------------------
 
The servers were restarted 1 times
 
Spent 0.651 of 6 seconds executing testcases
 
 
 
Completed: All 2 tests were successful.

Comment by Nirbhay Choubey (Inactive) [ 2015-07-23 ]

Packages have now been shared by SUSE : https://bugzilla.suse.com/show_bug.cgi?id=937388

Comment by Sergei Golubchik [ 2015-10-22 ]

Is something wrong with out sles12 images?

buildbot@sles12-x86-64:~> cat /etc/os-release 
NAME="SLES"
 
VERSION="12"
 
VERSION_ID="12"
 
PRETTY_NAME="SUSE Linux Enterprise Server 12"
 
ID="sles"
 
ANSI_COLOR="0;32"
 
CPE_NAME="cpe:/o:suse:sles:12"
 
buildbot@sles12-x86-64:~> cat /proc/sys/crypto/fips_enabled
 
1
 
buildbot@sles12-x86-64:~> openssl
 
fips.c(137): OpenSSL internal error, assertion failed: FATAL FIPS SELFTEST FAILURE
 
Aborted

And mysqld doesn't start, sudo doesn't work, ssh doesn't connect.

Comment by Elena Stepanova [ 2015-10-24 ]

Sorry, I promised to check on my openSUSE, but I couldn't even get this far.
On openSUSE 12.3, the whole tree of dependencies for patterns-sles-fips is outside the default repos, and it's huge. I stopped at the point when it requested a newer version of systemd than the one available in official repos.
On openSUSE 13.2, it got installed more or less easily, but apparently something is still missing, as the file /proc/sys/crypto/fips_enabled did not exist (in fact, /proc/sys/crypto did not exist). Enabling fips in kernel parameters made the system fail booting, complaining about misconfigured fips.

Apparently it should be somewhat better with sles; but still, if it was installed on our sles12 manually, I'm not surprised that it does not work.

Comment by Nirbhay Choubey (Inactive) [ 2016-02-16 ]

With fips enabled, I get the following trace for main.openssl_6975:

Thread 1 (Thread 0x7f154bc81700 (LWP 32143)):
 
#0  0x00007f1552a790d1 in pthread_kill () from /lib64/libpthread.so.0
 
#1  0x0000000000e3571b in my_write_core (sig=6) at /home/buildbot/repo/10.0/mysys/stacktrace.c:457
 
#2  0x000000000084718d in handle_fatal_signal (sig=6) at /home/buildbot/repo/10.0/sql/signal_handler.cc:262
 
#3  <signal handler called>
 
#4  0x00007f1551032187 in raise () from /lib64/libc.so.6
 
#5  0x00007f1551033538 in abort () from /lib64/libc.so.6
 
#6  0x000000000059c10e in openssl_lock (mode=5, lock=0x25358b0, file=0x7f1551f47a4c "fips_drbg_rand.c", line=127) at /h
 
ome/buildbot/repo/10.0/sql/mysqld.cc:4561
 
#7  0x000000000059c02c in openssl_lock_function (mode=5, n=18, file=0x7f1551f47a4c "fips_drbg_rand.c", line=127) at /ho
 
me/buildbot/repo/10.0/sql/mysqld.cc:4529
 
#8  0x00007f1551f1e0be in ?? () from /lib64/libcrypto.so.1.0.0
 
#9  0x00007f1551eaf28e in ?? () from /lib64/libcrypto.so.1.0.0
 
#10 0x00007f1551eafad9 in RAND_poll () from /lib64/libcrypto.so.1.0.0
 
#11 0x00007f1551eae963 in ssleay_rand_bytes () from /lib64/libcrypto.so.1.0.0
 
#12 0x00007f1551eaf3b3 in ?? () from /lib64/libcrypto.so.1.0.0
 
#13 0x00007f1551f1d325 in ?? () from /lib64/libcrypto.so.1.0.0
 
#14 0x00007f1551f1d49c in ?? () from /lib64/libcrypto.so.1.0.0
 
#15 0x00007f1551eaf2b9 in ?? () from /lib64/libcrypto.so.1.0.0
 
#16 0x00007f15521dd700 in ?? () from /lib64/libssl.so.1.0.0 
#17 0x0000000000e830e1 in ssl_handshake_loop (vio=0x2674d50, ssl=0x7f1534004c80, func=0x7f15521f25f0 <SSL_accept>) at /
 
home/buildbot/repo/10.0/vio/viossl.c:294
 
#18 0x0000000000e832e1 in ssl_do (ptr=0x26693e0, vio=0x2674d50, timeout=60, func=0x7f15521f25f0 <SSL_accept>, errptr=0x
 
7f154bc7ff00) at /home/buildbot/repo/10.0/vio/viossl.c:358  
#19 0x0000000000e8361d in sslaccept (ptr=0x26693e0, vio=0x2674d50, timeout=60, errptr=0x7f154bc7ff00) at /home/buildbot
 
/repo/10.0/vio/viossl.c:415
 
#20 0x00000000005eb0d6 in parse_client_handshake_packet (mpvio=0x7f154bc80420, buff=0x7f154bc80030, pkt_len=32) at /hom
 
e/buildbot/repo/10.0/sql/sql_acl.cc:11461
 
#21 0x00000000005ebe7a in server_mpvio_read_packet (param=0x7f154bc80420, buf=0x7f154bc80030) at /home/buildbot/repo/10
 
.0/sql/sql_acl.cc:11812
 
#22 0x00000000005ed3d7 in native_password_authenticate (vio=0x7f154bc80420, info=0x7f154bc80438) at /home/buildbot/repo
 
/10.0/sql/sql_acl.cc:12377
 
#23 0x00000000005ec49a in do_auth_once (thd=0x28c9900, auth_plugin_name=0x167fa60 <native_password_plugin_name>, mpvio=
 
0x7f154bc80420) at /home/buildbot/repo/10.0/sql/sql_acl.cc:11972
 
#24 0x00000000005ec7c2 in acl_authenticate (thd=0x28c9900, com_change_user_pkt_len=0) at /home/buildbot/repo/10.0/sql/s
 
ql_acl.cc:12070
 
#25 0x0000000000771850 in check_connection (thd=0x28c9900) at /home/buildbot/repo/10.0/sql/sql_connect.cc:1065
 
#26 0x00000000007719ca in login_connection (thd=0x28c9900) at /home/buildbot/repo/10.0/sql/sql_connect.cc:1133
 
#27 0x0000000000771f38 in thd_prepare_connection (thd=0x28c9900) at /home/buildbot/repo/10.0/sql/sql_connect.cc:1300
 
#28 0x000000000077218c in do_handle_one_connection (thd_arg=0x28c9900) at /home/buildbot/repo/10.0/sql/sql_connect.cc:1
 
368
 
#29 0x0000000000771f0d in handle_one_connection (arg=0x28c9900) at /home/buildbot/repo/10.0/sql/sql_connect.cc:1292
 
#30 0x0000000000b4ca47 in pfs_spawn_thread (arg=0x26c67d0) at /home/buildbot/repo/10.0/storage/perfschema/pfs.cc:1860
 
#31 0x00007f1552a740a4 in start_thread () from /lib64/libpthread.so.0
 
#32 0x00007f15510e27fd in clone () from /lib64/libc.so.6

Comment by Sergei Golubchik [ 2016-04-21 ]

Here's what happens:

  • main.openssl_6975 test is about making connections that fail inside OpenSSL and return an error
  • to be used in a multi-threaded program, OpenSSL needs to lock its internal data structures. This is done via the openssl_lock_function() callback in mysqld.cc
  • the crash happens because OpenSSL tries to lock the rwlock number 18 for write. And then—from the same thread—to lock it for read. Without unlocking.
  • the first lock happens with the following stack trace: handle_one_connection → ... → parse_client_handshake_packet → sslaccept → ssl_do → ssl_handshake_loop → (inside OpenSSL) → rand_lib.c:245 → openssl_lock_function
  • the second lock happens with the following stack trace: handle_one_connection → ... → parse_client_handshake_packet → sslaccept → ssl_do → ssl_handshake_loop → (inside OpenSSL) → fips_drbg_rand.c:127 → openssl_lock_function

This looks like an OpenSSL bug to me. It's not unreasonable to suspect that FIPS-related code is less tested and it can have a code path where some function takes a lock, detects an error, and returns without unlocking.

Generated at Thu Feb 08 07:27:12 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.