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

Server is restarting in the loop after crash

    XMLWordPrintable

    Details

    • Sprint:
      10.1.10

      Description

      Mariadb 10.1.8 server crashed and now it is restarting in the loop

      Server is used just as backup server with no read traffic and it crashed during replication of commands from master running Mariadb 10.0.22

      Part of the error log:

      2015-11-13 05:39:37 7f4e03ffe700  InnoDB: Assertion failure in thread 139973051279104 in file row0merge.cc line 892
      InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      151113  5:39:37 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see http://kb.askmonty.org/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.1.8-MariaDB-log
      key_buffer_size=134217728
      read_buffer_size=131072
      max_used_connections=0
      max_threads=5002
      thread_count=0
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11117553 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x0
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x0 thread_stack 0x48000
      2015-11-13 05:39:37 7f4e047ff700  InnoDB: Assertion failure in thread 139973059671808 in file row0merge.cc line 892
      InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      151113 05:39:38 mysqld_safe Number of processes running now: 0
      151113 05:39:38 mysqld_safe mysqld restarted
      2015-11-13  5:39:38 139789607671840 [Note] /usr/sbin/mysqld (mysqld 10.1.8-MariaDB-log) starting as process 11180 ...
      2015-11-13 05:39:38 7f234de89820 InnoDB: Warning: Setting innodb_use_sys_malloc to FALSE is DEPRECATED. This option may be removed in future releases, together with the InnoDB's internal memory allocator.
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Using mutexes to ref count buffer pool pages
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Memory barrier is not used
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Compressed tables use zlib 1.2.3
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Using Linux native AIO
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Using CPU crc32 instructions
      2015-11-13  5:39:38 139789607671840 [Note] InnoDB: Initializing buffer pool, size = 25.0G
      2015-11-13  5:39:40 139789607671840 [Note] InnoDB: Completed initialization of buffer pool
      2015-11-13  5:39:41 139789607671840 [Note] InnoDB: Highest supported file format is Barracuda.
      2015-11-13  5:39:41 139789607671840 [Note] InnoDB: Log scan progressed past the checkpoint lsn 4932606017459
      2015-11-13  5:39:41 139789607671840 [Note] InnoDB: Database was not shutdown normally!
      2015-11-13  5:39:41 139789607671840 [Note] InnoDB: Starting crash recovery.
      2015-11-13  5:39:41 139789607671840 [Note] InnoDB: Reading tablespace information from the .ibd files...
      2015-11-13  5:39:57 139789607671840 [Note] InnoDB: Processed 100683 .ibd/.isl files
      2015-11-13  5:40:13 139789607671840 [Note] InnoDB: Processed 198737 .ibd/.isl files
      2015-11-13  5:40:29 139789607671840 [Note] InnoDB: Processed 297902 .ibd/.isl files
      2015-11-13  5:40:45 139789607671840 [Note] InnoDB: Processed 391842 .ibd/.isl files
      2015-11-13  5:41:01 139789607671840 [Note] InnoDB: Processed 487883 .ibd/.isl files
      2015-11-13  5:41:17 139789607671840 [Note] InnoDB: Processed 579656 .ibd/.isl files
      2015-11-13  5:41:33 139789607671840 [Note] InnoDB: Processed 670725 .ibd/.isl files
      2015-11-13  5:41:42 139789607671840 [Note] InnoDB: Restoring possible half-written data pages 
      2015-11-13  5:41:42 139789607671840 [Note] InnoDB: from the doublewrite buffer...
      InnoDB: Doing recovery: scanned up to log sequence number 4932606076098
      2015-11-13  5:41:43 139789607671840 [Note] InnoDB: Starting an apply batch of log records to the database...
      InnoDB: Progress in percent: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
      InnoDB: Apply batch completed
      InnoDB: Last MySQL binlog file position 0 242205496, file name ./mysql-bin.001779
      2015-11-13  5:42:07 139789607671840 [Note] InnoDB: 128 rollback segment(s) are active.
      2015-11-13  5:42:07 139789607671840 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 4932606076098
      2015-11-13  5:42:07 139756801316608 [Note] InnoDB: Dumping buffer pool(s) not yet started
      2015-11-13  5:42:07 139789607671840 [Note] Plugin 'FEEDBACK' is disabled.
      2015-11-13  5:42:07 139789607671840 [Note] Recovering after a crash using mysql-bin
      2015-11-13  5:42:07 139789607671840 [Note] Starting crash recovery...
      2015-11-13  5:42:07 139789607671840 [Note] Crash recovery finished.
      2015-11-13  5:42:07 139789607671840 [Note] Server socket created on IP: '::'.
      2015-11-13  5:42:07 139789607671840 [Note] Event Scheduler: Loaded 0 events
      2015-11-13  5:42:07 139789607671840 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=3_dbbackup_la_linode-uk-relay-bin' to avoid this problem.
      2015-11-13  5:42:07 139789607671840 [Note] /usr/sbin/mysqld: ready for connections.
      Version: '10.1.8-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
      2015-11-13  5:42:07 139789218531072 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.001790' at position 257187369, relay log './3_dbbackup_la_linode-uk-relay-bin.000928' position: 257187657
      2015-11-13  5:42:07 139789606020864 [Note] Slave I/O thread: connected to master 'replicator@192.168.169.192:3306',replication started in log 'mysql-bin.001790' at position 862639170
      2015-11-13  5:42:07 139789218830080 [Note] InnoDB: Online DDL : Start
      2015-11-13  5:42:07 139789218830080 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
      2015-11-13 05:42:09 7f1b9f3fe700  InnoDB: Assertion failure in thread 139756612609792 in file row0merge.cc line 892
      InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      151113  5:42:09 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see http://kb.askmonty.org/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.1.8-MariaDB-log
      key_buffer_size=134217728
      read_buffer_size=131072
      max_used_connections=0
      max_threads=5002
      thread_count=0
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11117553 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x0
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x0 thread_stack 0x48000
      2015-11-13 05:42:09 7f1b9fbff700  InnoDB: Assertion failure in thread 139756621002496 in file row0merge.cc line 892
      InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      151113 05:42:10 mysqld_safe Number of processes running now: 0
      151113 05:42:10 mysqld_safe mysqld restarted
      2015-11-13  5:42:10 140555941337120 [Note] /usr/sbin/mysqld (mysqld 10.1.8-MariaDB-log) starting as process 11482 ...
      2015-11-13 05:42:10 7fd5baf45820 InnoDB: Warning: Setting innodb_use_sys_malloc to FALSE is DEPRECATED. This option may be removed in future releases, together with the InnoDB's internal memory allocator.
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Using mutexes to ref count buffer pool pages
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Memory barrier is not used
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Compressed tables use zlib 1.2.3
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Using Linux native AIO
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Using CPU crc32 instructions
      2015-11-13  5:42:10 140555941337120 [Note] InnoDB: Initializing buffer pool, size = 25.0G
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Completed initialization of buffer pool
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Highest supported file format is Barracuda.
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Log scan progressed past the checkpoint lsn 4932606076108
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Database was not shutdown normally!
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Starting crash recovery.
      2015-11-13  5:42:13 140555941337120 [Note] InnoDB: Reading tablespace information from the .ibd files...
      2015-11-13  5:42:29 140555941337120 [Note] InnoDB: Processed 97537 .ibd/.isl files
      2015-11-13  5:42:45 140555941337120 [Note] InnoDB: Processed 195624 .ibd/.isl files
      2015-11-13  5:43:01 140555941337120 [Note] InnoDB: Processed 293425 .ibd/.isl files
      2015-11-13  5:43:17 140555941337120 [Note] InnoDB: Processed 386672 .ibd/.isl files
      2015-11-13  5:43:33 140555941337120 [Note] InnoDB: Processed 480040 .ibd/.isl files
      2015-11-13  5:43:49 140555941337120 [Note] InnoDB: Processed 574244 .ibd/.isl files
      2015-11-13  5:44:05 140555941337120 [Note] InnoDB: Processed 661463 .ibd/.isl files
      2015-11-13  5:44:16 140555941337120 [Note] InnoDB: Restoring possible half-written data pages 
      2015-11-13  5:44:16 140555941337120 [Note] InnoDB: from the doublewrite buffer...
      InnoDB: Doing recovery: scanned up to log sequence number 4932606134463
      2015-11-13  5:44:17 140555941337120 [Note] InnoDB: Starting an apply batch of log records to the database...
      InnoDB: Progress in percent: 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
      InnoDB: Apply batch completed
      InnoDB: Last MySQL binlog file position 0 242205496, file name ./mysql-bin.001779
      2015-11-13  5:44:40 140555941337120 [Note] InnoDB: 128 rollback segment(s) are active.
      2015-11-13  5:44:40 140555941337120 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 4932606134463
      2015-11-13  5:44:40 140523113240320 [Note] InnoDB: Dumping buffer pool(s) not yet started
      2015-11-13  5:44:40 140555941337120 [Note] Plugin 'FEEDBACK' is disabled.
      2015-11-13  5:44:40 140555941337120 [Note] Recovering after a crash using mysql-bin
      2015-11-13  5:44:40 140555941337120 [Note] Starting crash recovery...
      2015-11-13  5:44:40 140555941337120 [Note] Crash recovery finished.
      2015-11-13  5:44:40 140555941337120 [Note] Server socket created on IP: '::'.
      2015-11-13  5:44:40 140555941337120 [Note] Event Scheduler: Loaded 0 events
      2015-11-13  5:44:40 140555941337120 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=3_dbbackup_la_linode-uk-relay-bin' to avoid this problem.
      2015-11-13  5:44:40 140555941337120 [Note] /usr/sbin/mysqld: ready for connections.
      Version: '10.1.8-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
      2015-11-13  5:44:40 140555552024320 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.001790' at position 257187369, relay log './3_dbbackup_la_linode-uk-relay-bin.000928' position: 257187657
      2015-11-13  5:44:40 140555939686144 [Note] Slave I/O thread: connected to master 'replicator@192.168.169.192:3306',replication started in log 'mysql-bin.001790' at position 873411395
      2015-11-13  5:44:40 140555846170368 [Note] InnoDB: Online DDL : Start
      2015-11-13  5:44:40 140555846170368 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
      2015-11-13 05:44:42 7fce0a7fe700  InnoDB: Assertion failure in thread 140522916144896 in file row0merge.cc line 892
      InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.

      .... and the same logs again and again

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              jplindst Jan Lindström
              Reporter:
              unitminer Viktor Zeman
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration