[MDEV-13582] Mariadb Slave - mysqld got signal 6 - InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.2.7/storage/innobase/dict/dict0stats.cc line 1572 Created: 2017-08-18  Updated: 2017-08-24  Resolved: 2017-08-24

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.7, 10.2.8
Fix Version/s: 10.2.9

Type: Bug Priority: Major
Reporter: Tech Nik Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 0
Labels: innodb, need_feedback, replication
Environment:

Debian 8, X64, latest updates,
physical and virtual machine affected
mysqld_multi with 2 / more instances.

Issue Links:
Duplicate
duplicates MDEV-13534 InnoDB STATS_PERSISTENT fails to igno... Closed

 Description   

Hi guys,
we use mariadb replication in a Master-Slave-Slave-Slave-Slave environment.
Our Master is running on Mariadb 10.0, also two Slaves.
While we want to upgrade all servers to Mariadb 10.2 we started with our testing machine, the latest two slaves.
About three weeks ago we upgraded the last to slaves to Mariadb 10.2.7. As described one machineis a virtual linux server, the other is on hardware.
Yesterday suddenly both slaves with 10.2.7 died - we didn't know why and thought maybe the reconfiguration of the firewall cause this.
The other 2 Slaves are running fine.

We restarted the slaves, everything was ok. This happened one more time yesterday.
This day again, both slaves broke down - and there were no reconfigurations on the firewall.
so we checked the logs and here is what we got:

2017-08-18 15:37:32 0x7fef31f88700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.2.7/storage/innobase/dict/dict0stats.cc line 1572
 
InnoDB: Failing assertion: offsets_rec != NULL
 
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.7/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
170818 15:37:32 [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 https://mariadb.com/kb/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.2.7-MariaDB-10.2.7+maria~jessie-log
 
key_buffer_size=16777216
 
read_buffer_size=131072
 
max_used_connections=2
 
max_threads=3002
 
thread_count=10
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6612061 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0
 
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 0x40000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x561051d410fe]
 
/usr/sbin/mysqld(handle_fatal_signal+0x305)[0x56105177e895]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7feff4ce8890]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7feff2e05067]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7feff2e06448]
 
/usr/sbin/mysqld(+0x41b206)[0x561051522206]
 
/usr/sbin/mysqld(+0xa3f5e6)[0x561051b465e6]
 
/usr/sbin/mysqld(+0xa40fb7)[0x561051b47fb7]
 
/usr/sbin/mysqld(+0xa42ecd)[0x561051b49ecd]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7feff4ce1064]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7feff2eb862d]
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.
 
170818 15:37:33 mysqld_safe Number of processes running now: 0
 
170818 15:37:33 mysqld_safe mysqld restarted
 
2017-08-18 15:37:34 140448271968128 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
2017-08-18 15:37:34 140448271968128 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
2017-08-18 15:37:34 140448271968128 [Note] /usr/sbin/mysqld (mysqld 10.2.7-MariaDB-10.2.7+maria~jessie-log) starting as process 22633 ...
 
2017-08-18 15:37:34 140448271968128 [Warning] You need to use --log-bin to make --binlog-format work.
 
2017-08-18 15:37:34 140448271968128 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Uses event mutexes
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Using Linux native AIO
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Number of pools: 1
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Using SSE2 crc32 instructions
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Initializing buffer pool, total size = 512M, instances = 1, chunk size = 128M
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Completed initialization of buffer pool
 
2017-08-18 15:37:34 140445034010368 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Highest supported file format is Barracuda.
 
2017-08-18 15:37:34 140448271968128 [Note] InnoDB: Starting crash recovery from checkpoint LSN=217540936716
 
2017-08-18 15:37:35 140448271968128 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 179121 row operations to undo
 
2017-08-18 15:37:35 140448271968128 [Note] InnoDB: Trx id counter is 33515776
 
2017-08-18 15:37:35 140448271968128 [Note] InnoDB: Starting final batch to recover 1428 pages from redo log.
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2017-08-18 15:37:38 140445133588224 [Note] InnoDB: Starting in background the rollback of recovered transactions
 
2017-08-18 15:37:38 140445133588224 [Note] InnoDB: Rolling back trx with id 33515478, 179121 rows to undo
 
 
 
InnoDB: Progress in percents: 12017-08-18 15:37:38 140448271968128 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: Waiting for purge to start
 
2017-08-18 15:37:38 140448271968128 [Note] InnoDB: 5.7.18 started; log sequence number 217540936859
 
2017-08-18 15:37:38 140444465874688 [Note] InnoDB: Loading buffer pool(s) from /data/mysql_3319/ib_buffer_pool
 
2017-08-18 15:37:38 140444465874688 [Note] InnoDB: Cannot open '/data/mysql_3319/ib_buffer_pool' for reading: No such file or directory
 
 2 3 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 482017-08-18 15:37:41 140448271968128 [Note] Plugin 'FEEDBACK' is disabled.
 
2017-08-18 15:37:41 140448271968128 [Note] Recovering after a crash using tc.log
 
2017-08-18 15:37:41 140448271968128 [Note] Starting crash recovery...
 
2017-08-18 15:37:41 140448271968128 [Note] Crash recovery finished.
 
2017-08-18 15:37:41 140448271968128 [Note] Server socket created on IP: '0.0.0.0'.
 
 49 50 51 522017-08-18 15:37:41 140448271968128 [Note] Reading of all Master_info entries succeded
 
2017-08-18 15:37:41 140448271968128 [Note] Added new Master_info '' to hash table
 
2017-08-18 15:37:41 140448271968128 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.2.7-MariaDB-10.2.7+maria~jessie-log'  socket: '/var/run/mysqld/mysqld_3319.sock'  port: 3319  mariadb.org binary distribution
 
 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 1002017-08-18 15:37:43 140445133588224 [Note] InnoDB: Rollback of trx with id 33515478 completed
 
2017-08-18 15:37:43 140445133588224 [Note] InnoDB: Rollback of non-prepared transactions completed

So my question - are the version 10.0 and 10.2 not compatible with replication or did I find a bug?
Can anyone reproduce this?

best regards
Andreas

 Comments   
Comment by Elena Stepanova [ 2017-08-23 ]

Replication from 10.0 to 10.2 should certainly work fine, so you have hit a bug.
Could you please also paste a portion of the error log before the assertion failure, and your cnf file(s) from the crashing server?
Is configuration identical on both servers?
Do both servers resume replication from the exact same event after recovery? (It should be visible in the error log soon after the quoted fragment).

Comment by Marko Mäkelä [ 2017-08-23 ]

I believe that this is a duplicate of MDEV-13534.
I already posted some analysis there. The bug should be possible in MariaDB 10.0 already.

In any case, a core dump could be useful to check if my analysis is correct. I would want to extract the index page contents from the core dump.

Generated at Thu Feb 08 08:06:43 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.