Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.4.12, 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5
-
Ubuntu 18.0.4
Master 6 cores/6Gb and 2 Slaves 4 cores/4Gbs
Yandex Cloud VPS
Description
Hello.
We have a Master-to-multi-Slave config and are regularly facing slaves crashes (they crash together at the same time, approx. once every 24 hours). Maybe this has something to do with load, but crashed did not happen under heavy load and still happened today with relatively (50%) of highest load we've had so far.
Master 10.4.12 setup is Ubuntu 18.0.4 cloud VPS (yandex cloud) with 6 cores 100% quota, 6 Gbs RAM, 30 Gbs space.
Slaves 10.4.12 and 10.4.13 setup is Ubuntu 18.0.4 cloud VPS (yandex cloud) with 4 cores 100% quota, 4 Gbs RAM, 30 Gbs space.
Replication is setup using this guide - https://mariadb.com/kb/en/setting-up-a-replication-slave-with-mariabackup/
Everything works well, until slaves crash.
Currently Web API sends DML statements to Master directly and SELECT statements are sent to HAProxy with wieght distribution 20/40/40 (Master/Slave1/Slave2).
Before that we had Master 10.4.12 and only 1 Slave 10.4.12 with direct requests from API to Slave without HAProxy - Slave still crashed, I hoped with 2 slaves we would at least have 1 standing... but alas...
We removed all triggers from the DB.
We use GTIDs.
We now use mixed binlog (but id did crash with 'row' mode).
We don't have any DDL statements running (except a few CREATE TEMPORARY TABLE).
We use InnoDB only to store data.
We don't have any FullText Indexes.
We don't use compression.
We don't use SSL between Mater and Slaves.
Timezone on all machines is UTC.
Data size now approximately 800Mb, InnoDb buffer pool size is 1024Mb, InnoDb log file size is128Mb.
Here's syslog:
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: 200627 12:44:00 [ERROR] mysqld got signal 11 ;
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: This could be because you hit a bug. It is also possible that this binary
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: or one of the libraries it was linked against is corrupt, improperly built,
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: or misconfigured. This error can also be caused by malfunctioning hardware.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: We will try our best to scrape up some info that will hopefully help
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: diagnose the problem, but since we have already crashed,
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: something is definitely wrong and this may fail.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Server version: 10.4.12-MariaDB-1:10.4.12+maria~bionic-log
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: key_buffer_size=134217728
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: read_buffer_size=2097152
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: max_used_connections=15
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: max_threads=77
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: thread_count=24
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: It is possible that mysqld could use up to
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 606038 K bytes of memory
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Hope that's ok; if not, decrease some variables in the equation.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Thread pointer: 0x7f40500014f8
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Attempting backtrace. You can use the following information to find out
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: where mysqld died. If you see no messages after this, something went
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: terribly wrong...
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: stack_bottom = 0x7f40fc901e98 thread_stack 0x49000
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55b8a063ac3e]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(handle_fatal_signal+0x515)[0x55b8a00aecf5]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f411d583890]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /lib/x86_64-linux-gnu/libc.so.6(+0x18f039)[0x7f411c008039]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xae4170)[0x55b8a031e170]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xa205dd)[0x55b8a025a5dd]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb10a85)[0x55b8a034aa85]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb116be)[0x55b8a034b6be]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb1224c)[0x55b8a034c24c]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xae7959)[0x55b8a0321959]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xad0db6)[0x55b8a030adb6]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb0b658)[0x55b8a0345658]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb1173f)[0x55b8a034b73f]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xb1224c)[0x55b8a034c24c]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xae73a4)[0x55b8a03213a4]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xa21f8f)[0x55b8a025bf8f]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x9f)[0x55b8a00ba7af]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(_ZN21Delete_rows_log_event11do_exec_rowEP14rpl_group_info+0x12d)[0x55b8a01b12ad]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(_ZN14Rows_log_event14do_apply_eventEP14rpl_group_info+0x25d)[0x55b8a01a440d]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0x5b6e90)[0x55b89fdf0e90]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(handle_slave_sql+0x17b4)[0x55b89fdfa344]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /usr/sbin/mysqld(+0xdab79a)[0x55b8a05e579a]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f411d5786db]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f411bf9a88f]
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Trying to get some variables.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Some pointers may be invalid and cause the dump to abort.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Query (0x0):
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Connection ID (thread ID): 49
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Status: NOT_KILLED
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: information that should help you find out what is causing the crash.
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Writing a core file...
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Working directory at /var/lib/mysql
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Resource Limits:
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Limit Soft Limit Hard Limit Units
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max cpu time unlimited unlimited seconds
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max file size unlimited unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max data size unlimited unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max stack size 8388608 unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max core file size 0 unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max resident set unlimited unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max processes 15602 15602 processes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max open files 16364 16364 files
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max locked memory 16777216 16777216 bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max address space unlimited unlimited bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max file locks unlimited unlimited locks
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max pending signals 15602 15602 signals
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max msgqueue size 819200 819200 bytes
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max nice priority 0 0
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max realtime priority 0 0
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Max realtime timeout unlimited unlimited us
|
Jun 27 12:44:00 vox-db1-read1 mysqld[7728]: Core pattern: core
|
Jun 27 12:44:00 vox-db1-read1 kernel: [264684.731198] mysqld[7861]: segfault at 115 ip 00007f411c008039 sp 00007f40fc8fcfc8 error 6 in libc-2.27.so[7f411be79000+1e7000]
|
Jun 27 12:44:00 vox-db1-read1 systemd[1]: mariadb.service: Main process exited, code=killed, status=11/SEGV
|
Jun 27 12:44:00 vox-db1-read1 systemd[1]: mariadb.service: Failed with result 'signal'.
|
Jun 27 12:44:05 vox-db1-read1 systemd[1]: mariadb.service: Service hold-off time over, scheduling restart.
|
Jun 27 12:44:05 vox-db1-read1 systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.
|
Jun 27 12:44:05 vox-db1-read1 systemd[1]: Stopped MariaDB 10.4.12 database server.
|
Jun 27 12:44:05 vox-db1-read1 systemd[1]: Starting MariaDB 10.4.12 database server...
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] /usr/sbin/mysqld (mysqld 10.4.12-MariaDB-1:10.4.12+maria~bionic-log) starting as process 12132 ...
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Using Linux native AIO
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Uses event mutexes
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Number of pools: 1
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Using SSE2 crc32 instructions
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 8, chunk size = 128M
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: Completed initialization of buffer pool
|
Jun 27 12:44:06 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:06 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
Jun 27 12:44:07 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:07 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=142473402785
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 2 row operations to undo
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Trx id counter is 11134299
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Starting final batch to recover 63 pages from redo log.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mariadb-bin.000634', position 59120658
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: 10.4.12 started; log sequence number 142473413250; transaction id 11134301
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Plugin 'FEEDBACK' is disabled.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Recovering after a crash using /var/log/mysql/mariadb-bin
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Starting crash recovery...
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Crash recovery finished.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Rolled back recovered transaction 11134298
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] InnoDB: Rollback of non-prepared transactions completed
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Server socket created on IP: '0.0.0.0'.
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Reading of all Master_info entries succeeded
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [Note] Added new Master_info '' to hash table
|
Jun 27 12:44:10 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:10 0 [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=mysqld-relay-bin' to avoid this problem.
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:11 10 [Note] Slave I/O thread: Start asynchronous replication to master 'replication_user@10.130.0.25:3306' in log 'mariadb-bin.000712' at position 4
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:11 11 [Note] Slave SQL thread initialized, starting replication in log 'mariadb-bin.000712' at position 4, relay log './mysqld-relay-bin.000001' position: 4; GTID position '0-1-5332814'
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:11 0 [Note] /usr/sbin/mysqld: ready for connections.
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: Version: '10.4.12-MariaDB-1:10.4.12+maria~bionic-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: 2020-06-27 12:44:11 10 [Note] Slave I/O thread: connected to master 'replication_user@10.130.0.25:3306',replication starts at GTID position '0-1-5332814'
|
Jun 27 12:44:11 vox-db1-read1 systemd[1]: Started MariaDB 10.4.12 database server.
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12175]: Upgrading MySQL tables if necessary.
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12178]: Looking for 'mysql' as: /usr/bin/mysql
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12178]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12178]: This installation of MariaDB is already upgraded to 10.4.12-MariaDB, use --force if you still need to run mysql_upgrade
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12186]: Checking for insecure root accounts.
|
Jun 27 12:44:11 vox-db1-read1 /etc/mysql/debian-start[12190]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: 200627 12:44:11 [ERROR] mysqld got signal 11 ;
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: This could be because you hit a bug. It is also possible that this binary
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: or one of the libraries it was linked against is corrupt, improperly built,
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: or misconfigured. This error can also be caused by malfunctioning hardware.
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: We will try our best to scrape up some info that will hopefully help
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: diagnose the problem, but since we have already crashed,
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: something is definitely wrong and this may fail.
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: Server version: 10.4.12-MariaDB-1:10.4.12+maria~bionic-log
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: key_buffer_size=134217728
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: read_buffer_size=2097152
|
Jun 27 12:44:11 vox-db1-read1 mysqld[12132]: max_used_connections=1
|
...and so on, it loops indefinitely.
My theory is that something comes from Master that breaks Slaves.
When first crash occured (same day I've setup replication, ~4-5 days ago) I tried to restore Slave from same backup I used to initilize it. And Slave could not be started. I suppose while catching up to Master it still encountered this breaking transaction and crashed. Then I just took a fresh backup from Master, and Slave started without problems.
Since then every time Slaves crash I just take make backup (with mariabackup) and restore slaves. This is stupid I know, but what choice do we currently have? 
What additional information can I provide you with to find the root of this issue?
Thanks!
Attachments
Issue Links
- is duplicated by
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
Activity
Hello,
We've faced 3 crashes since then (2 on Sunday and 1 Monday).
We had to rotate logs and I did not save that particular log you ask for.
Last crash's log reads log # 879 in the same place where #712 was:
Jun 29 11:19:27 vox-db1-read2 mysqld[9112]: 2020-06-29 11:19:27 10 [Note] Slave I/O thread: Start asynchronous replication to master 'replication_user@10.130.0.25:3306' in log 'mariadb-bin.000879' at position 4
Jun 29 11:19:27 vox-db1-read2 mysqld[9112]: 2020-06-29 11:19:27 11 [Note] Slave SQL thread initialized, starting replication in log 'mariadb-bin.000879' at position 4, relay log './mysqld-relay-bin.000001' position: 4; GTID position '0-1-6364314'
So I am attaching fresh show bonlog events in 'mariadb-bin.000879' export. I hope that helps.
I've passworded the attached ZIP file and emailed you the password to alice.sherepa@mariadb.com.
Thanks a lot! The issue repeatable on 10.2-10.5 with InnoDB engine.
The test case:
--source include/have_binlog_format_row.inc
|
--source include/have_innodb.inc
|
--source include/master-slave.inc
|
|
|
CREATE TABLE t1 (id int NOT NULL PRIMARY KEY) ENGINE=InnoDB; |
INSERT INTO t1 VALUES (1),(2),(3); |
|
|
CREATE TABLE t2 ( id int NOT NULL PRIMARY KEY, t1_id int NOT NULL, c1 text, |
v_c1 varchar(256) AS (json_value(c1,'$.login')) virtual, |
KEY (v_c1), |
KEY (t1_id), |
CONSTRAINT a FOREIGN KEY (t1_id) REFERENCES t1 (id) ON DELETE CASCADE |
) ENGINE=InnoDB;
|
INSERT INTO t2 VALUES (90,1,NULL,NULL); |
|
|
delete from t1 WHERE id=1; |
--sync_slave_with_master
|
|
|
--connection master
|
drop table t2,t1; |
|
10.2 a1e52e7f32cee7c204078db4 |
mysqld: /10.2/storage/innobase/handler/ha_innodb.cc:21982: dfield_t* innobase_get_computed_value(dtuple_t*, const dict_v_col_t*, const dict_index_t*, mem_heap_t**, mem_heap_t*, const dict_field_t*, THD*, TABLE*, byte*, const dict_table_t*, upd_t*, dict_foreign_t*): Assertion `mysql_table' failed.
|
200720 9:45:29 [ERROR] mysqld got signal 6 ;
|
|
|
Server version: 10.2.33-MariaDB-debug-log
|
|
|
linux/raise.c:51(__GI_raise)[0x7fe2a66507bb]
|
stdlib/abort.c:81(__GI_abort)[0x7fe2a663b535]
|
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7fe2a663b40f]
|
/lib/x86_64-linux-gnu/libc.so.6(+0x30102)[0x7fe2a6649102]
|
handler/ha_innodb.cc:21984(innobase_get_computed_value(dtuple_t*, dict_v_col_t const*, dict_index_t const*, mem_block_info_t**, mem_block_info_t*, dict_field_t const*, THD*, TABLE*, unsigned char*, dict_table_t const*, upd_t*, dict_foreign_t*))[0x55bc0eea1c61]
|
row/row0upd.cc:2189(row_upd_store_v_row(upd_node_t*, upd_t const*, THD*, TABLE*))[0x55bc0f0184e5]
|
row/row0upd.cc:2261(row_upd_store_row(upd_node_t*, THD*, TABLE*))[0x55bc0f018743]
|
row/row0upd.cc:2995(row_upd_del_mark_clust_rec(upd_node_t*, dict_index_t*, unsigned short*, que_thr_t*, unsigned long, bool, mtr_t*))[0x55bc0f01aa70]
|
row/row0upd.cc:3166(row_upd_clust_step(upd_node_t*, que_thr_t*))[0x55bc0f01b362]
|
row/row0upd.cc:3292(row_upd(upd_node_t*, que_thr_t*))[0x55bc0f01b84c]
|
row/row0upd.cc:3438(row_upd_step(que_thr_t*))[0x55bc0f01bd23]
|
row/row0mysql.cc:2110(row_update_cascade_for_mysql(que_thr_t*, upd_node_t*, dict_table_t*))[0x55bc0efc6ea3]
|
row/row0ins.cc:1419(row_ins_foreign_check_on_constraint(que_thr_t*, dict_foreign_t*, btr_pcur_t*, dtuple_t*, mtr_t*))[0x55bc0efa2783]
|
row/row0ins.cc:1808(row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*))[0x55bc0efa3560]
|
row/row0upd.cc:325(row_upd_check_references_constraints(upd_node_t*, btr_pcur_t*, dict_table_t*, dict_index_t*, unsigned short*, que_thr_t*, mtr_t*))[0x55bc0f014ace]
|
row/row0upd.cc:3005(row_upd_del_mark_clust_rec(upd_node_t*, dict_index_t*, unsigned short*, que_thr_t*, unsigned long, bool, mtr_t*))[0x55bc0f01ab40]
|
row/row0upd.cc:3166(row_upd_clust_step(upd_node_t*, que_thr_t*))[0x55bc0f01b362]
|
row/row0upd.cc:3292(row_upd(upd_node_t*, que_thr_t*))[0x55bc0f01b84c]
|
row/row0upd.cc:3438(row_upd_step(que_thr_t*))[0x55bc0f01bd23]
|
row/row0mysql.cc:1827(row_update_for_mysql(row_prebuilt_t*))[0x55bc0efc64ba]
|
handler/ha_innodb.cc:9105(ha_innobase::delete_row(unsigned char const*))[0x55bc0ee8ba1f]
|
sql/handler.cc:6168(handler::ha_delete_row(unsigned char const*))[0x55bc0ec9a1d0]
|
sql/log_event.cc:13746(Delete_rows_log_event::do_exec_row(rpl_group_info*))[0x55bc0edc0104]
|
sql/log_event.cc:11101(Rows_log_event::do_apply_event(rpl_group_info*))[0x55bc0edb9f4b]
|
sql/log_event.h:1452(Log_event::apply_event(rpl_group_info*))[0x55bc0e9607d3]
|
sql/slave.cc:3567(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x55bc0e9556d5]
|
sql/slave.cc:3735(apply_event_and_update_pos(Log_event*, THD*, rpl_group_info*))[0x55bc0e955c22]
|
sql/slave.cc:4034(exec_relay_log_event(THD*, Relay_log_info*, rpl_group_info*))[0x55bc0e956349]
|
sql/slave.cc:5181(handle_slave_sql)[0x55bc0e95982f]
|
perfschema/pfs.cc:1871(pfs_spawn_thread)[0x55bc0f364d74]
|
nptl/pthread_create.c:487(start_thread)[0x7fe2a6d8efa3]
|
x86_64/clone.S:97(clone)[0x7fe2a67124cf]
|
|
|
Query (0x7fe23c014dd3): delete from t1 WHERE id=1
|
not-debug build:
|
10.5 054f10365c49b70a3868edc0c955ff |
200720 11:27:37 [ERROR] mysqld got signal 11 ;
|
|
|
??:0(__restore_rt)[0x7fe18c3c5730]
|
handler/ha_innodb.cc:20930(innobase_get_computed_value(dtuple_t*, dict_v_col_t const*, dict_index_t const*, mem_block_info_t**, mem_block_info_t*, dict_field_t const*, THD*, TABLE*, unsigned char*, dict_table_t const*, upd_t*, dict_foreign_t*))[0x56093ba52555]
|
row/row0upd.cc:1865(row_upd_store_v_row)[0x56093ba53a0e]
|
row/row0upd.cc:2689(row_upd_del_mark_clust_rec)[0x56093ba5506a]
|
row/row0upd.cc:2997(row_upd)[0x56093ba2ebe9]
|
row/row0mysql.cc:2252(row_update_cascade_for_mysql(que_thr_t*, upd_node_t*, dict_table_t*))[0x56093ba1e787]
|
row/row0ins.cc:1395(row_ins_foreign_check_on_constraint)[0x56093ba4ff51]
|
bits/atomic_base.h:524(row_upd_check_references_constraints(upd_node_t*, btr_pcur_t*, dict_table_t*, dict_index_t*, unsigned short*, que_thr_t*, mtr_t*) [clone .part.49])[0x56093ba53f28]
|
row/row0upd.cc:231(row_upd_check_references_constraints)[0x56093ba5506a]
|
row/row0upd.cc:2997(row_upd)[0x56093ba30894]
|
row/row0mysql.cc:1887(row_update_for_mysql(row_prebuilt_t*))[0x56093b975bdf]
|
handler/ha_innodb.cc:8645(ha_innobase::delete_row(unsigned char const*))[0x56093b6bf71e]
|
sql/handler.cc:7249(handler::ha_delete_row(unsigned char const*))[0x56093b7af9e4]
|
sql/log_event_server.cc:8148(Delete_rows_log_event::do_exec_row(rpl_group_info*))[0x56093b7a443f]
|
sql/log_event_server.cc:5675(Rows_log_event::do_apply_event(rpl_group_info*))[0x56093b42a082]
|
sql/log_event.h:1497(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x56093b433a3f]
|
sql/slave.cc:4482(exec_relay_log_event)[0x56093b8e1d7b]
|
nptl/pthread_create.c:487(start_thread)[0x7fe18c3bafa3]
|
x86_64/clone.S:97(clone)[0x7fe18b9c34cf]
|
|
|
Query (0x7fe12c01ac9b): delete from t1 WHERE id=1
|
Hello Andrei,
Thank you for the review comments.
I have addressed all your review comments. Please find the following patch
https://github.com/MariaDB/server/commit/3f48bc08b92b2734c2af7408c246b96338675205
Please point in the description that only slave needs upgrading, master is not buggy.
Approved.
Fix is implemented in 10.2.37.
10.2 fix is cherry-picked on higher versions and tested on build bot.
10.3 patch: https://github.com/MariaDB/server/commit/a1d9614d8c026949dc2c53d719943af6bebd8a0c
10.4 patch: https://github.com/MariaDB/server/commit/c42021422e4ee9dfe2239853cf378f15ba10b4f8
10.5 patch: https://github.com/MariaDB/server/commit/3eb27d04ed5a112f2f47782083f0b7e878216b84
Could you please provide the output of "Show binlog events" for 'mariadb-bin.000712'?