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

Assertion failure in file log0crypt.cc line 220 on server restart

Details

    • 10.1.6-1

    Description

      If the server was previously started with InnoDB log encryption, restarting the server without the encryption plugin causes the assertion failure as below. On a release build, there is no assertion failure, but a crash with SIGABRT.

      I realize it cannot really work without the plugin on encrypted logs, and expect it to abort, but it would be good to have clear diagnostics for this rather than the scary crash.

      Also, I thought it might work with innodb_fast_shutdown turned off, but it doesn't make a difference.

      150513  3:32:01 [ERROR] InnoDB: Redo log crypto: getting mysqld crypto key from key version failed.
      2015-05-13 03:32:01 7f4331ff6760  InnoDB: Assertion failure in thread 139926578358112 in file log0crypt.cc line 220
      InnoDB: We intentionally generate a memory trap.

      Stack trace from 10.1 commit c8ad5b2f

      #5  0x00007f432fbd33e0 in *__GI_abort () at abort.c:92
      #6  0x00007f4332962742 in init_crypt_key (info=0x7ffce3e6e010) at 10.1/storage/xtradb/log/log0crypt.cc:220
      #7  0x00007f4332962884 in add_crypt_info (info=0x7ffce3e6e010) at 10.1/storage/xtradb/log/log0crypt.cc:254
      #8  0x00007f4332962fa3 in log_crypt_read_checkpoint_buf (buf=0x7f432f015b36 "") at 10.1/storage/xtradb/log/log0crypt.cc:474
      #9  0x00007f433295bcfb in recv_find_max_checkpoint (max_group=0x7ffce3e6eb58, max_field=0x7ffce3e6eb60) at 10.1/storage/xtradb/log/log0recv.cc:813
      #10 0x00007f433295fbac in recv_recovery_from_checkpoint_start_func (type=78656949, limit_lsn=18446744073709551615, min_flushed_lsn=1616911, max_flushed_lsn=1616911) at 10.1/storage/xtradb/log/log0recv.cc:3162
      #11 0x00007f4332a411dc in innobase_start_or_create_for_mysql () at 10.1/storage/xtradb/srv/srv0start.cc:2528
      #12 0x00007f43328d87fa in innobase_init (p=0x7f432f02e270) at 10.1/storage/xtradb/handler/ha_innodb.cc:4083
      #13 0x00007f433272c2f0 in ha_initialize_handlerton (plugin=0x7f432f1446e8) at 10.1/sql/handler.cc:512
      #14 0x00007f4332513fa8 in plugin_initialize (tmp_root=0x7ffce3e728e0, plugin=0x7f432f1446e8, argc=0x7f43337f59d0, argv=0x7f432f01e6c0, options_only=false) at 10.1/sql/sql_plugin.cc:1403
      #15 0x00007f4332514b7a in plugin_init (argc=0x7f43337f59d0, argv=0x7f432f01e6c0, flags=2) at 10.1/sql/sql_plugin.cc:1676
      #16 0x00007f43324363e7 in init_server_components () at 10.1/sql/mysqld.cc:5041
      #17 0x00007f4332437528 in mysqld_main (argc=12, argv=0x7f432f01e6c0) at 10.1/sql/mysqld.cc:5631
      #18 0x00007f433242d100 in main (argc=11, argv=0x7ffce3e73628) at 10.1/sql/main.cc:25

      To reproduce:

      • start server with

        [mysqld]
        plugin-load-add=file_key_management.so
        loose-file_key_management_filename=/home/elenst/git/10.1/mysql-test/std_data/keys.txt
        innodb-encrypt-log=on

      • shut down the server
      • start the server without the options above.

      Attachments

        Activity

          commit f5ddffd83e627cc0f6a24dfe4d8fc2e0c983bf78
          Author: Jan Lindström <jan.lindstrom@mariadb.com>
          Date: Thu Jun 18 19:58:57 2015 +0300

          MDEV-8156: Assertion failure in file log0crypt.cc line 220 on server restart

          Instead of asserting print informative error message to error log
          and return failure from innodb_init causing the server to shutdown.

          jplindst Jan Lindström (Inactive) added a comment - commit f5ddffd83e627cc0f6a24dfe4d8fc2e0c983bf78 Author: Jan Lindström <jan.lindstrom@mariadb.com> Date: Thu Jun 18 19:58:57 2015 +0300 MDEV-8156 : Assertion failure in file log0crypt.cc line 220 on server restart Instead of asserting print informative error message to error log and return failure from innodb_init causing the server to shutdown.
          Aurelien_LEQUOY Aurélien LEQUOY added a comment - - edited

          I just tried with lastest 10.1.6 (donwload and compiled 1 hour ago) and i got same problem !

          [mariadb-10.1]
          plugin-load-add=file_key_management.so
          file-key-management
          file-key-management
          file-key-management-filename='key.enc'
          file_key_management_filekey='secretPassword2'
          innodb-encrypt-tables
          innodb-encrypt-log
          innodb-encryption-threads=2
          encrypt-tmp-disk-tables=1

          create a table with encrypt
          insert one line

          remove these options and restart server and i got :

          150806 16:26:41 mysqld_safe Starting mysqld daemon with databases from /data/mysql/data
          2015-08-06 16:26:42 139969101432640 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.6-MariaDB-log) starting as process 30296 ...
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Using mutexes to ref count buffer pool pages
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: The InnoDB memory heap is disabled
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Memory barrier is not used
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Compressed tables use zlib 1.2.3.4
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Not using CPU crc32 instructions
          2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Initializing buffer pool, size = 4.0G
          2015-08-06 16:26:43 139969101432640 [Note] InnoDB: Completed initialization of buffer pool
          2015-08-06 16:26:45 139969101432640 [Note] InnoDB: Highest supported file format is Barracuda.
          2015-08-06 16:26:45 139969101432640 [ERROR] InnoDB: Redo log crypto: getting mysqld crypto key from key version failed. Reason could b
          e that requested key_version 1 is not found or required encryption  key management is not found.
          2015-08-06 16:26:45 139969101432640 [ERROR] Plugin 'InnoDB' init function returned error.
          2015-08-06 16:26:45 139969101432640 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
          2015-08-06 16:26:45 139969101432640 [Note] Plugin 'FEEDBACK' is disabled.
          2015-08-06 16:26:45 139969101432640 [ERROR] Unknown/unsupported storage engine: InnoDB
          2015-08-06 16:26:45 139969101432640 [ERROR] Aborting
           
          2015-08-06 16:26:45 139969101432640 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

          Aurelien_LEQUOY Aurélien LEQUOY added a comment - - edited I just tried with lastest 10.1.6 (donwload and compiled 1 hour ago) and i got same problem ! [mariadb- 10.1 ] plugin-load-add=file_key_management.so file-key-management file-key-management file-key-management-filename= 'key.enc' file_key_management_filekey= 'secretPassword2' innodb-encrypt-tables innodb-encrypt-log innodb-encryption-threads= 2 encrypt-tmp-disk-tables= 1 create a table with encrypt insert one line remove these options and restart server and i got : 150806 16 : 26 : 41 mysqld_safe Starting mysqld daemon with databases from /data/mysql/data 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1 . 6 -MariaDB-log) starting as process 30296 ... 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Using mutexes to ref count buffer pool pages 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: The InnoDB memory heap is disabled 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Memory barrier is not used 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Compressed tables use zlib 1.2 . 3.4 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Not using CPU crc32 instructions 2015 - 08 - 06 16 : 26 : 42 139969101432640 [Note] InnoDB: Initializing buffer pool, size = 4 .0G 2015 - 08 - 06 16 : 26 : 43 139969101432640 [Note] InnoDB: Completed initialization of buffer pool 2015 - 08 - 06 16 : 26 : 45 139969101432640 [Note] InnoDB: Highest supported file format is Barracuda. 2015 - 08 - 06 16 : 26 : 45 139969101432640 [ERROR] InnoDB: Redo log crypto: getting mysqld crypto key from key version failed. Reason could b e that requested key_version 1 is not found or required encryption key management is not found. 2015 - 08 - 06 16 : 26 : 45 139969101432640 [ERROR] Plugin 'InnoDB' init function returned error. 2015 - 08 - 06 16 : 26 : 45 139969101432640 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 2015 - 08 - 06 16 : 26 : 45 139969101432640 [Note] Plugin 'FEEDBACK' is disabled. 2015 - 08 - 06 16 : 26 : 45 139969101432640 [ERROR] Unknown/unsupported storage engine: InnoDB 2015 - 08 - 06 16 : 26 : 45 139969101432640 [ERROR] Aborting   2015 - 08 - 06 16 : 26 : 45 139969101432640 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

          Hi,

          To me this does not look the same. In original bug report there was a error message and crash. Now server refuses the start and prints error message (if full error log is provided). If requested key_version is not found there is no way to continue.

          jplindst Jan Lindström (Inactive) added a comment - Hi, To me this does not look the same. In original bug report there was a error message and crash. Now server refuses the start and prints error message (if full error log is provided). If requested key_version is not found there is no way to continue.

          yes, but my point of view it's you miss key, so you lost encripted data => normal.

          But in this case you lost all data even data not encripted. (i just cripted one table one this table).

          More how to get back without encryption ?

          Aurelien_LEQUOY Aurélien LEQUOY added a comment - yes, but my point of view it's you miss key, so you lost encripted data => normal. But in this case you lost all data even data not encripted. (i just cripted one table one this table). More how to get back without encryption ?

          Yes, can you explain step by step what you did, but original problem was that you had innodb-encrypt-log=on
          , after this log file is encrypted and if you lost the key you can't restart the database from latest checkpoint (because it is encrypted).

          jplindst Jan Lindström (Inactive) added a comment - Yes, can you explain step by step what you did, but original problem was that you had innodb-encrypt-log=on , after this log file is encrypted and if you lost the key you can't restart the database from latest checkpoint (because it is encrypted).

          People

            jplindst Jan Lindström (Inactive)
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            3 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.