Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-15587

AES test fails, segfaults in EVP_CipherInit_ex

Details

    Description

      The aes test always fails:

      gdb /home/mariadb/mariadb-10.2.13/unittest/mysys/aes-t
      GNU gdb (Debian 7.11.1-2~bpo8+1) 7.11.1
      Copyright (C) 2016 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-linux-gnu".
      Type "show configuration" for configuration details.
      For bug reporting instructions, please see:
      <http://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 /home/mariadb/mariadb-10.2.13/unittest/mysys/aes-t...done.
      (gdb) r
      Starting program: /home/mariadb/mariadb-10.2.13/unittest/mysys/aes-t 
      [Thread debugging using libthread_db enabled]
      Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
      1..87
      ok 1 - encrypt MY_AES_ECB 200 pad
      ok 2 - my_aes_get_size
      ok 3 - md5
      ok 4 - decrypt MY_AES_ECB 208
      ok 5 - memcmp
      ok 6 - encrypt MY_AES_ECB 128 pad
      ok 7 - my_aes_get_size
      ok 8 - md5
      ok 9 - decrypt MY_AES_ECB 144
      ok 10 - memcmp
      ok 11 - encrypt MY_AES_CBC 159 pad
      ok 12 - my_aes_get_size
      ok 13 - md5
      ok 14 - decrypt MY_AES_CBC 160
      ok 15 - memcmp
      ok 16 - encrypt MY_AES_CBC 192 pad
      ok 17 - my_aes_get_size
      ok 18 - md5
      ok 19 - decrypt MY_AES_CBC 208
      ok 20 - memcmp
       
      Program received signal SIGSEGV, Segmentation fault.
      EVP_CipherInit_ex (enc=1, iv=0x0, key=<optimized out>, cipher=0x555555600d04 <EVP_aes_128_ecb()::c>, ctx=0x7fffffffd208) at /home/mariadb/mariadb-10.2.13/mysys_ssl/yassl.cc:100
      100         TAO(ctx)->SetIV(iv);
      (gdb) quit
      

      Attachments

        Issue Links

          Activity

            The above crash was with amd64. I also see it with i686. Here is a different stack trace from binlog_encryption.rpl_relayrotate:

            #3  0x56b2185f in handle_fatal_signal (sig=11) at /mariadb/10.2/sql/signal_handler.cc:305
            #4  <signal handler called>
            #5  0x5706bf59 in memcpy (__len=16, __src=0x0, __dest=<optimized out>) at /usr/include/i386-linux-gnu/bits/string_fortified.h:34
            #6  TaoCrypt::AES::SetIV (iv=0x0, this=<optimized out>) at /mariadb/10.2/extra/yassl/taocrypt/include/aes.hpp:54
            #7  EVP_CipherInit_ex (cipher=0x57202574 <EVP_aes_128_ecb()::c>, cipher=0x57202574 <EVP_aes_128_ecb()::c>, enc=1, iv=0x0, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", ctx=<optimized out>) at /mariadb/10.2/mysys_ssl/yassl.cc:100
            #8  MyCTX::init (ivlen=<optimized out>, iv=0x0, klen=<optimized out>, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", encrypt=1, cipher=0x57202574 <EVP_aes_128_ecb()::c>, this=0xffab49d0) at /mariadb/10.2/mysys_ssl/my_crypt.cc:57
            #9  MyCTX_nopad::init (this=<optimized out>, cipher=<optimized out>, encrypt=<optimized out>, key=<optimized out>, klen=<optimized out>, iv=<optimized out>, ivlen=<optimized out>) at /mariadb/10.2/mysys_ssl/my_crypt.cc:99
            #10 0x5706b8e2 in my_aes_crypt (mode=mode@entry=MY_AES_ECB, flags=flags@entry=3, src=src@entry=0xffab4f74 "\232\021l\355\264\350/\334\rpP\336(\001", slen=slen@entry=16, dst=dst@entry=0xffab4c6c "\030\330\300V\001", dlen=dlen@entry=0xffab4c68, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", klen=16, iv=iv@entry=0x0, ivlen=ivlen@entry=0) at /mariadb/10.2/mysys_ssl/my_crypt.cc:289
            #11 0x5706c468 in MyCTX_nopad::finish (this=0xffab4e00, dst=0xffab4cec "\021\300J\357\034P\253\377\\M\253\377\006", dlen=0xffab4ce8) at /mariadb/10.2/mysys_ssl/my_crypt.cc:129
            #12 0x5706b850 in my_aes_crypt_finish (ctx=0xffab4e00, dst=0xffab4cec "\021\300J\357\034P\253\377\\M\253\377\006", dlen=0xffab4ce8) at /mariadb/10.2/mysys_ssl/my_crypt.cc:277
            #13 0x56c0e2b8 in Log_event_writer::write_footer (this=0xffab501c) at /mariadb/10.2/sql/log_event.cc:1688
            #14 0x56c15f6b in Log_event::write_footer (this=0xffab50ec) at /mariadb/10.2/sql/log_event.h:1345
            #15 Gtid_list_log_event::write() () at /mariadb/10.2/sql/log_event.cc:7951
            #16 0x56bf003f in Log_event_writer::write (ev=<optimized out>, this=0xffab501c) at /mariadb/10.2/sql/log_event.h:5164
            #17 MYSQL_BIN_LOG::write_event (this=<optimized out>, this@entry=0x5770d980 <mysql_bin_log>, ev=<optimized out>, ev@entry=0xffab50ec, file=<optimized out>, file@entry=0x5770dc7c <mysql_bin_log+764>) at /mariadb/10.2/sql/log.cc:5250
            #18 0x56bfc407 in MYSQL_BIN_LOG::write_event (ev=0xffab50ec, this=0x5770d980 <mysql_bin_log>) at /mariadb/10.2/sql/log.h:754
            #19 MYSQL_BIN_LOG::open(char const*, enum_log_type, char const*, unsigned long, cache_type, unsigned long, bool, bool) () at /mariadb/10.2/sql/log.cc:3559
            #20 0x568e200f in init_server_components () at /mariadb/10.2/sql/mysqld.cc:5458
            #21 mysqld_main (argc=<optimized out>, argv=<optimized out>) at /mariadb/10.2/sql/mysqld.cc:5891
            #22 0x568bc627 in main (argc=28, argv=0xffab57e4) at /mariadb/10.2/sql/main.cc:25
            

            In both stack traces, the problem could be iv=0x0.
            If I remember correctly from a debugging session a couple of months ago, the parameter should have been passed as an address of a stack-local variable. Maybe some function attribute could be provoking wrong behaviour from GCC? This would not be the first time: I encountered something similar in GCC 4.6.3, 4.7.2, 4.9.1 years ago.

            marko Marko Mäkelä added a comment - The above crash was with amd64. I also see it with i686. Here is a different stack trace from binlog_encryption.rpl_relayrotate : #3 0x56b2185f in handle_fatal_signal (sig=11) at /mariadb/10.2/sql/signal_handler.cc:305 #4 <signal handler called> #5 0x5706bf59 in memcpy (__len=16, __src=0x0, __dest=<optimized out>) at /usr/include/i386-linux-gnu/bits/string_fortified.h:34 #6 TaoCrypt::AES::SetIV (iv=0x0, this=<optimized out>) at /mariadb/10.2/extra/yassl/taocrypt/include/aes.hpp:54 #7 EVP_CipherInit_ex (cipher=0x57202574 <EVP_aes_128_ecb()::c>, cipher=0x57202574 <EVP_aes_128_ecb()::c>, enc=1, iv=0x0, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", ctx=<optimized out>) at /mariadb/10.2/mysys_ssl/yassl.cc:100 #8 MyCTX::init (ivlen=<optimized out>, iv=0x0, klen=<optimized out>, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", encrypt=1, cipher=0x57202574 <EVP_aes_128_ecb()::c>, this=0xffab49d0) at /mariadb/10.2/mysys_ssl/my_crypt.cc:57 #9 MyCTX_nopad::init (this=<optimized out>, cipher=<optimized out>, encrypt=<optimized out>, key=<optimized out>, klen=<optimized out>, iv=<optimized out>, ivlen=<optimized out>) at /mariadb/10.2/mysys_ssl/my_crypt.cc:99 #10 0x5706b8e2 in my_aes_crypt (mode=mode@entry=MY_AES_ECB, flags=flags@entry=3, src=src@entry=0xffab4f74 "\232\021l\355\264\350/\334\rpP\336(\001", slen=slen@entry=16, dst=dst@entry=0xffab4c6c "\030\330\300V\001", dlen=dlen@entry=0xffab4c68, key=0x5770e394 <mysql_bin_log+2580> "w\n\212e\332\025m$\356*\t2wS\001B", klen=16, iv=iv@entry=0x0, ivlen=ivlen@entry=0) at /mariadb/10.2/mysys_ssl/my_crypt.cc:289 #11 0x5706c468 in MyCTX_nopad::finish (this=0xffab4e00, dst=0xffab4cec "\021\300J\357\034P\253\377\\M\253\377\006", dlen=0xffab4ce8) at /mariadb/10.2/mysys_ssl/my_crypt.cc:129 #12 0x5706b850 in my_aes_crypt_finish (ctx=0xffab4e00, dst=0xffab4cec "\021\300J\357\034P\253\377\\M\253\377\006", dlen=0xffab4ce8) at /mariadb/10.2/mysys_ssl/my_crypt.cc:277 #13 0x56c0e2b8 in Log_event_writer::write_footer (this=0xffab501c) at /mariadb/10.2/sql/log_event.cc:1688 #14 0x56c15f6b in Log_event::write_footer (this=0xffab50ec) at /mariadb/10.2/sql/log_event.h:1345 #15 Gtid_list_log_event::write() () at /mariadb/10.2/sql/log_event.cc:7951 #16 0x56bf003f in Log_event_writer::write (ev=<optimized out>, this=0xffab501c) at /mariadb/10.2/sql/log_event.h:5164 #17 MYSQL_BIN_LOG::write_event (this=<optimized out>, this@entry=0x5770d980 <mysql_bin_log>, ev=<optimized out>, ev@entry=0xffab50ec, file=<optimized out>, file@entry=0x5770dc7c <mysql_bin_log+764>) at /mariadb/10.2/sql/log.cc:5250 #18 0x56bfc407 in MYSQL_BIN_LOG::write_event (ev=0xffab50ec, this=0x5770d980 <mysql_bin_log>) at /mariadb/10.2/sql/log.h:754 #19 MYSQL_BIN_LOG::open(char const*, enum_log_type, char const*, unsigned long, cache_type, unsigned long, bool, bool) () at /mariadb/10.2/sql/log.cc:3559 #20 0x568e200f in init_server_components () at /mariadb/10.2/sql/mysqld.cc:5458 #21 mysqld_main (argc=<optimized out>, argv=<optimized out>) at /mariadb/10.2/sql/mysqld.cc:5891 #22 0x568bc627 in main (argc=28, argv=0xffab57e4) at /mariadb/10.2/sql/main.cc:25 In both stack traces, the problem could be iv=0x0 . If I remember correctly from a debugging session a couple of months ago, the parameter should have been passed as an address of a stack-local variable. Maybe some function attribute could be provoking wrong behaviour from GCC? This would not be the first time: I encountered something similar in GCC 4.6.3, 4.7.2, 4.9.1 years ago.

            For me, the problem goes away if I ensure that CMAKE_CXX_FLAGS contain -O0 instead of -O1 or -O2. The CMAKE_C_FLAGS can be anything. I also tested 10.2 with CMAKE_CXX_FLAGS=-O2 -fno-lifetime-dse, but disabling that optimization did not fix the issue.

            Strangely, 10.1 is not affected, even though I build it with the same options, and InnoDB uses encryption in both.

            marko Marko Mäkelä added a comment - For me, the problem goes away if I ensure that CMAKE_CXX_FLAGS contain -O0 instead of -O1 or -O2 . The CMAKE_C_FLAGS can be anything. I also tested 10.2 with CMAKE_CXX_FLAGS=-O2 -fno-lifetime-dse , but disabling that optimization did not fix the issue. Strangely, 10.1 is not affected, even though I build it with the same options, and InnoDB uses encryption in both.

            #5  0x5706bf59 in memcpy (__len=16, __src=0x0, __dest=<optimized out>) at /usr/include/i386-linux-gnu/bits/string_fortified.h:34
            

            Argument order here looks unusual.

            kevg Eugene Kosov (Inactive) added a comment - #5 0x5706bf59 in memcpy (__len=16, __src=0x0, __dest=<optimized out>) at /usr/include/i386-linux-gnu/bits/string_fortified.h:34 Argument order here looks unusual.

            I believe that the problem is that in EVP_CipherInit_ex(), a condition on iv is wrongly being optimized away.
            I see that there are several callers that invoke my_aes_crypt(…, iv=NULL, ivlen=0).
            The problematic code is here:

            static int EVP_CipherInit_ex(EVP_CIPHER_CTX *ctx, const EVP_CIPHER *cipher,
                                         void *, const uchar *key, const uchar *iv, int enc)
            {
              new (ctx->tao_buf) TaoCrypt::AES(enc ? TaoCrypt::ENCRYPTION
                                                   : TaoCrypt::DECRYPTION, cipher->mode);
              TAO(ctx)->SetKey(key, cipher->key_len);
              if (iv)
                TAO(ctx)->SetIV(iv);
            

            The following patch works around the issue for me:

            diff --git a/mysys_ssl/yassl.cc b/mysys_ssl/yassl.cc
            --- a/mysys_ssl/yassl.cc
            +++ b/mysys_ssl/yassl.cc
            @@ -90,6 +90,7 @@ static int EVP_CIPHER_CTX_set_padding(EVP_CIPHER_CTX *ctx, int pad)
              return 1;@@ -90,6 +90,7 @@ static int EVP_CIPHER_CTX_set_padding(EVP_CIPHER_CTX *ctx, int pad)
               return 1;
             }
             
            +__attribute__((noinline))
             static int EVP_CipherInit_ex(EVP_CIPHER_CTX *ctx, const EVP_CIPHER *cipher,
                                          void *, const uchar *key, const uchar *iv, int enc)
             {
            

            marko Marko Mäkelä added a comment - I believe that the problem is that in EVP_CipherInit_ex() , a condition on iv is wrongly being optimized away. I see that there are several callers that invoke my_aes_crypt(…, iv=NULL, ivlen=0) . The problematic code is here: static int EVP_CipherInit_ex(EVP_CIPHER_CTX *ctx, const EVP_CIPHER *cipher, void *, const uchar *key, const uchar *iv, int enc) { new (ctx->tao_buf) TaoCrypt::AES(enc ? TaoCrypt::ENCRYPTION : TaoCrypt::DECRYPTION, cipher->mode); TAO(ctx)->SetKey(key, cipher->key_len); if (iv) TAO(ctx)->SetIV(iv); The following patch works around the issue for me: diff --git a/mysys_ssl/yassl.cc b/mysys_ssl/yassl.cc --- a/mysys_ssl/yassl.cc +++ b/mysys_ssl/yassl.cc @@ -90,6 +90,7 @@ static int EVP_CIPHER_CTX_set_padding(EVP_CIPHER_CTX *ctx, int pad) return 1;@@ -90,6 +90,7 @@ static int EVP_CIPHER_CTX_set_padding(EVP_CIPHER_CTX *ctx, int pad) return 1; } +__attribute__((noinline)) static int EVP_CipherInit_ex(EVP_CIPHER_CTX *ctx, const EVP_CIPHER *cipher, void *, const uchar *key, const uchar *iv, int enc) {

            It looks like the call memcpy(oiv, iv, ivlen=0) allowed GCC to infer that both pointers must be __attribute__((nonnull)).

            marko Marko Mäkelä added a comment - It looks like the call memcpy(oiv, iv, ivlen=0) allowed GCC to infer that both pointers must be __attribute__((nonnull)) .

            People

              serg Sergei Golubchik
              NG Nicolas G.
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.