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

INSERT into a secondary index with zero-data-length key is not crash-safe

Details

    Description

      Problem found during RQG testing invoking the RQG reporter "Mariabackup".
      		 
      Scenario:
      		 
      1. More or less heavy DDL/DML load
      		 
           During that some call   mariabackup ... --backup ... is made.
      		 
      2. mariabackup ... --prepare  ...  is called first time.
      		 
       
      		 
      2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
      		 
      2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
      		 
      2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
      		 
      2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
      		 
      [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).
      		 
       
      		 
      origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00
      		 
       
      		 
       
      		 
      Some second variant for the same failure is
      		 
      1. Only on session and that runs
      		 
          REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint  value) ;
      		 
      2. At some point of time the server gets killed (SIGKILL)
      		 
      3. Attempt to restart the server
      		 
       
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
      		 
      2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
      		 
      2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
      		 
      2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
      		 
      2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption
      		 
       
      		 
      origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00
      		 
       
      		 
      The bug affects builds with and without debug.

      Attachments

        1. MDEV-21899.tgz
          869 kB
        2. rqg.log
          381 kB

        Issue Links

          is caused by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-21724 Optimize page_cur_insert_rec_low() redo logging

          • Major - Major loss of function.
          • Closed
          relates to

          Task - A task that needs to be done. MDEV-12353 Efficient InnoDB redo log record format

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            mleich Matthias Leich created issue -
            mleich Matthias Leich made changes -
            Field Original Value New Value
            Description
            {noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

             2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
             [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            {noformat}
            		{noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            {noformat}
            marko Marko Mäkelä made changes -
            Component/s mariabackup [ 14500 ]
            marko Marko Mäkelä made changes -
            mleich Matthias Leich made changes -
            Attachment rqg.log [ 50704 ]
            mleich Matthias Leich made changes -
            Description {noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            {noformat}
            		{noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00

            {noformat}
            mleich Matthias Leich made changes -
            Summary Draft: [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=... page number= ...] [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=... page number= ...]
            mleich Matthias Leich made changes -
            Description {noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00

            {noformat}
            		{noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00


            Some second variant for the same failure is
            1. Only on session and that runs
                REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint value) ;
            2. At some point of time the server gets killed (SIGKILL)
            3. Attempt to restart the server



            2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
            2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
            2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
            2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption

            origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00

            {noformat}
            mleich Matthias Leich made changes -
            Description {noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00


            Some second variant for the same failure is
            1. Only on session and that runs
                REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint value) ;
            2. At some point of time the server gets killed (SIGKILL)
            3. Attempt to restart the server



            2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
            2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
            2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
            2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption

            origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00

            {noformat}
            		{noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00


            Some second variant for the same failure is
            1. Only on session and that runs
                REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint value) ;
            2. At some point of time the server gets killed (SIGKILL)
            3. Attempt to restart the server

            2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
            2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
            2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
            2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption

            origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00

            {noformat}
            mleich Matthias Leich made changes -
            Attachment MDEV-21899.tgz [ 50816 ]
            mleich Matthias Leich made changes -
            Description {noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00


            Some second variant for the same failure is
            1. Only on session and that runs
                REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint value) ;
            2. At some point of time the server gets killed (SIGKILL)
            3. Attempt to restart the server

            2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
            2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
            2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
            2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption

            origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00

            {noformat}
            		{noformat}
            Problem found during RQG testing invoking the RQG reporter "Mariabackup".
            Scenario:
            1. More or less heavy DDL/DML load
                 During that some call mariabackup ... --backup ... is made.
            2. mariabackup ... --prepare ... is called first time.

            2020-03-06 19:20:38 0 [Note] InnoDB: Starting final batch to recover 491 pages from redo log.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=167, page number=36]
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-06 19:20:39 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1580] with error Data structure corruption
            [00] FATAL ERROR: 2020-03-06 19:20:40 mariabackup: innodb_init() returned 39 (Data structure corruption).

            origin/HEAD, origin/10.5 23685378bafa38a74957e8f07e2d56b57e90fa53 2020-03-06T11:06:59+02:00


            Some second variant for the same failure is
            1. Only on session and that runs
                REPLACE INTO <random table which was created earlier> ( _field_no_pk ) VALUES ( <random _mediumint value) ;
            2. At some point of time the server gets killed (SIGKILL)
            3. Attempt to restart the server

            2020-03-23 14:12:49 0 [Note] InnoDB: Completed initialization of buffer pool
            2020-03-23 14:12:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=335923252
            2020-03-23 14:12:49 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
            2020-03-23 14:12:49 0 [Note] InnoDB: Trx id counter is 21150
            2020-03-23 14:12:49 0 [Note] InnoDB: Starting final batch to recover 272 pages from redo log.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=5, page number=22]
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
            2020-03-23 14:12:49 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1574] with error Data structure corruption

            origin/10.5 02fe99750536aad7c9e75513be47c91c8c568419 2020-03-23T10:45:08+01:00

            The bug affects builds with and without debug.

            {noformat}
            marko Marko Mäkelä made changes -
            Status Open [ 1 ] In Progress [ 3 ]
            marko Marko Mäkelä made changes -
            marko Marko Mäkelä made changes -
            Summary [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_DYNAMIC due to corruption on [page id: space=... page number= ...] INSERT into a secondary index with zero-data-length key is not crash-safe
            marko Marko Mäkelä made changes -
            issue.field.resolutiondate 2020-03-27 07:43:58.0 2020-03-27 07:43:58.408
            marko Marko Mäkelä made changes -
            Fix Version/s 10.5.3 [ 24263 ]
            Fix Version/s 10.5 [ 23123 ]
            Resolution Fixed [ 1 ]
            Status In Progress [ 3 ] Closed [ 6 ]
            serg Sergei Golubchik made changes -
            Workflow MariaDB v3 [ 104689 ] MariaDB v4 [ 157407 ]

            People

              marko Marko Mäkelä
              mleich Matthias Leich
              Votes:
              1 Vote for this issue
              Watchers:
              5 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.