rpl.rpl_gtid_crash 'innodb,row' w62 [ fail ]
|
Test ended at 2020-01-24 11:27:07
|
|
CURRENT_TEST: rpl.rpl_gtid_crash
|
|
|
Server [mysqld.2 - pid: 51375, winpid: 51375, exit: 256] failed during test run
|
Server log from this test:
|
----------SERVER LOG START-----------
|
2020-01-24 11:25:51 0 [Note] /10.5/sql/mysqld (mysqld 10.5.1-MariaDB-debug-log) starting as process 28144 ...
|
2020-01-24 11:25:51 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4246)
|
2020-01-24 11:25:51 0 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000)
|
2020-01-24 11:25:51 0 [Note] Plugin 'partition' is disabled.
|
2020-01-24 11:25:51 0 [Note] Plugin 'SEQUENCE' is disabled.
|
2020-01-24 11:25:51 0 [Note] InnoDB: Using Linux native AIO
|
2020-01-24 11:25:51 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2020-01-24 11:25:51 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2020-01-24 11:25:51 0 [Note] InnoDB: Uses event mutexes
|
2020-01-24 11:25:51 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
2020-01-24 11:25:51 0 [Note] InnoDB: Number of pools: 1
|
2020-01-24 11:25:51 0 [Note] InnoDB: Using SSE2 crc32 instructions
|
2020-01-24 11:25:51 0 [Note] mysqld: O_TMPFILE is not supported on /10.5/mysql-test/var/tmp/62/mysqld.2 (disabling future attempts)
|
io_setup(1280) returned -11
|
2020-01-24 11:25:51 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
|
2020-01-24 11:25:51 0 [Note] InnoDB: Completed initialization of buffer pool
|
2020-01-24 11:25:51 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2020-01-24 11:25:56 0 [Note] InnoDB: 128 rollback segments are active.
|
2020-01-24 11:25:56 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2020-01-24 11:25:56 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2020-01-24 11:25:56 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2020-01-24 11:25:56 0 [Note] InnoDB: 10.5.1 started; log sequence number 64036; transaction id 28
|
2020-01-24 11:25:56 0 [Note] InnoDB: Loading buffer pool(s) from /10.5/mysql-test/var/62/mysqld.2/data/ib_buffer_pool
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_CMP' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'FEEDBACK' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'user_variables' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
|
2020-01-24 11:25:56 0 [Note] Plugin 'unix_socket' is disabled.
|
2020-01-24 11:25:56 0 [Warning] /10.5/sql/mysqld: unknown option '--loose-pam-debug'
|
2020-01-24 11:25:56 0 [Warning] /10.5/sql/mysqld: unknown option '--loose-aria'
|
2020-01-24 11:25:56 0 [Note] Server socket created on IP: '127.0.0.1'.
|
2020-01-24 11:25:56 0 [Note] InnoDB: Buffer pool(s) load completed at 200124 11:25:56
|
2020-01-24 11:25:56 0 [Note] Reading of all Master_info entries succeeded
|
2020-01-24 11:25:56 0 [Note] Added new Master_info '' to hash table
|
2020-01-24 11:25:56 0 [Note] /10.5/sql/mysqld: ready for connections.
|
Version: '10.5.1-MariaDB-debug-log' socket: '/10.5/mysql-test/var/tmp/62/mysqld.2.sock' port: 17261 Source distribution
|
2020-01-24 11:25:57 5 [Note] Deleted Master_info file '/10.5/mysql-test/var/62/mysqld.2/data/master.info'.
|
2020-01-24 11:25:57 5 [Note] Deleted Master_info file '/10.5/mysql-test/var/62/mysqld.2/data/relay-log.info'.
|
2020-01-24 11:25:57 5 [Note] Master connection name: '' Master_info_file: 'master.info' Relay_info_file: 'relay-log.info'
|
2020-01-24 11:25:57 5 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='17260', master_log_file='master-bin.000001', master_log_pos='4'.
|
2020-01-24 11:25:57 7 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log 'master-bin.000001' at position 4
|
2020-01-24 11:25:57 8 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
|
2020-01-24 11:25:57 7 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication started in log 'master-bin.000001' at position 4
|
2020-01-24 11:26:09 8 [Note] Error reading relay log event: slave SQL thread was killed
|
2020-01-24 11:26:09 8 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 2245
|
2020-01-24 11:26:09 7 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2245
|
2020-01-24 11:26:10 5 [Note] Master connection name: '' Master_info_file: 'master.info' Relay_info_file: 'relay-log.info'
|
2020-01-24 11:26:10 5 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='17260', master_log_file='master-bin.000001', master_log_pos='2245'. New state master_host='127.0.0.1', master_port='17260', master_log_file='', master_log_pos='4'.
|
2020-01-24 11:26:10 5 [Note] Previous Using_Gtid=No. New Using_Gtid=Current_Pos
|
2020-01-24 11:26:10 9 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log '' at position 4
|
2020-01-24 11:26:10 10 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 4, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-7'
|
2020-01-24 11:26:10 9 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication starts at GTID position '0-1-7'
|
2020-01-24 11:26:37 9 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
|
2020-01-24 11:26:37 9 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'master-bin.000001' at position 46359; GTID position '0-1-209'
|
2020-01-24 11:26:37 9 [ERROR] Slave I/O: error reconnecting to master 'root@127.0.0.1:17260' - retry-time: 1 maximum-retries: 100 message: Can't connect to MySQL server on '127.0.0.1' (111 "Connection refused"), Internal MariaDB error code: 2003
|
2020-01-24 11:26:40 9 [Note] Slave: connected to master 'root@127.0.0.1:17260',replication resumed in log 'master-bin.000001' at position 46359
|
2020-01-24 11:26:49 10 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 708; GTID position '0-1-211'
|
2020-01-24 11:26:49 9 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 708; GTID position 0-1-211
|
2020-01-24 11:26:54 11 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log 'master-bin.000002' at position 708
|
2020-01-24 11:26:54 12 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 708, relay log './slave-relay-bin.000001' position: 4; GTID position ''
|
2020-01-24 11:26:54 11 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication starts at GTID position ''
|
2020-01-24 11:26:58 11 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
|
2020-01-24 11:26:58 11 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'master-bin.000003' at position 419; GTID position '1-1-2,2-1-1,0-1-1'
|
2020-01-24 11:26:58 11 [ERROR] Slave I/O: error reconnecting to master 'root@127.0.0.1:17260' - retry-time: 1 maximum-retries: 100 message: Can't connect to MySQL server on '127.0.0.1' (111 "Connection refused"), Internal MariaDB error code: 2003
|
2020-01-24 11:27:00 11 [Note] Slave: connected to master 'root@127.0.0.1:17260',replication resumed in log 'master-bin.000003' at position 419
|
2020-01-24 11:27:00 12 [Note] Error reading relay log event: slave SQL thread was killed
|
2020-01-24 11:27:00 12 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 375; GTID position '0-1-1,1-1-2,2-1-1'
|
2020-01-24 11:27:00 11 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 375; GTID position 1-1-2,2-1-1,0-1-1
|
2020-01-24 11:27:00 13 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log 'master-bin.000004' at position 375
|
2020-01-24 11:27:00 14 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 375, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1,1-1-2,2-1-1'
|
2020-01-24 11:27:00 13 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication starts at GTID position '1-1-2,0-1-1,2-1-1'
|
SIGKILL myself
|
2020-01-24 11:27:01 0 [Note] /10.5/sql/mysqld (mysqld 10.5.1-MariaDB-debug-log) starting as process 50773 ...
|
2020-01-24 11:27:01 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4246)
|
2020-01-24 11:27:01 0 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000)
|
2020-01-24 11:27:01 0 [Note] Plugin 'partition' is disabled.
|
2020-01-24 11:27:01 0 [Note] Plugin 'SEQUENCE' is disabled.
|
2020-01-24 11:27:01 0 [Note] InnoDB: Using Linux native AIO
|
2020-01-24 11:27:01 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2020-01-24 11:27:01 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2020-01-24 11:27:01 0 [Note] InnoDB: Uses event mutexes
|
2020-01-24 11:27:01 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
2020-01-24 11:27:01 0 [Note] InnoDB: Number of pools: 1
|
2020-01-24 11:27:01 0 [Note] InnoDB: Using SSE2 crc32 instructions
|
2020-01-24 11:27:01 0 [Note] mysqld: O_TMPFILE is not supported on /10.5/mysql-test/var/tmp/62/mysqld.2 (disabling future attempts)
|
2020-01-24 11:27:01 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
|
2020-01-24 11:27:01 0 [Note] InnoDB: Completed initialization of buffer pool
|
2020-01-24 11:27:01 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2020-01-24 11:27:01 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=217637
|
2020-01-24 11:27:01 0 [Note] InnoDB: Starting final batch to recover 7 pages from redo log.
|
2020-01-24 11:27:02 0 [Note] InnoDB: Last binlog file './slave-bin.000001', position 46573
|
2020-01-24 11:27:02 0 [Note] InnoDB: 128 rollback segments are active.
|
2020-01-24 11:27:02 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
|
2020-01-24 11:27:02 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2020-01-24 11:27:02 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2020-01-24 11:27:02 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2020-01-24 11:27:02 0 [Note] InnoDB: 10.5.1 started; log sequence number 217759; transaction id 481
|
2020-01-24 11:27:02 0 [Note] InnoDB: Loading buffer pool(s) from /10.5/mysql-test/var/62/mysqld.2/data/ib_buffer_pool
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_CMP' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'FEEDBACK' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'user_variables' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
|
2020-01-24 11:27:02 0 [Note] Plugin 'unix_socket' is disabled.
|
2020-01-24 11:27:02 0 [Warning] /10.5/sql/mysqld: unknown option '--loose-pam-debug'
|
2020-01-24 11:27:02 0 [Warning] /10.5/sql/mysqld: unknown option '--loose-aria'
|
2020-01-24 11:27:02 0 [Note] Recovering after a crash using slave-bin
|
2020-01-24 11:27:02 0 [Note] Starting crash recovery...
|
2020-01-24 11:27:02 0 [Note] Crash recovery finished.
|
2020-01-24 11:27:02 0 [Note] InnoDB: Buffer pool(s) load completed at 200124 11:27:02
|
2020-01-24 11:27:02 0 [Note] Server socket created on IP: '127.0.0.1'.
|
2020-01-24 11:27:02 0 [Note] Reading of all Master_info entries succeeded
|
2020-01-24 11:27:02 0 [Note] Added new Master_info '' to hash table
|
2020-01-24 11:27:02 5 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log 'master-bin.000004' at position 4
|
2020-01-24 11:27:02 6 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 4, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1,1-1-2,2-1-1'
|
2020-01-24 11:27:02 0 [Note] /10.5/sql/mysqld: ready for connections.
|
Version: '10.5.1-MariaDB-debug-log' socket: '/10.5/mysql-test/var/tmp/62/mysqld.2.sock' port: 17261 Source distribution
|
2020-01-24 11:27:02 5 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication starts at GTID position '1-1-2,0-1-1,2-1-1'
|
2020-01-24 11:27:02 6 [Note] Error reading relay log event: slave SQL thread was killed
|
2020-01-24 11:27:02 6 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 579; GTID position '0-1-2,1-1-2,2-1-1'
|
2020-01-24 11:27:02 5 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 579; GTID position 1-1-2,0-1-2,2-1-1
|
2020-01-24 11:27:02 8 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:17260' in log 'master-bin.000004' at position 579
|
2020-01-24 11:27:02 9 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 579, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-2,1-1-2,2-1-1'
|
2020-01-24 11:27:02 8 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:17260',replication starts at GTID position '1-1-2,0-1-2,2-1-1'
|
SIGKILL myself
|
2020-01-24 11:27:03 0 [Note] /10.5/sql/mysqld (mysqld 10.5.1-MariaDB-debug-log) starting as process 51376 ...
|
2020-01-24 11:27:03 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4246)
|
2020-01-24 11:27:03 0 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000)
|
2020-01-24 11:27:03 0 [Note] Plugin 'partition' is disabled.
|
2020-01-24 11:27:03 0 [Note] Plugin 'SEQUENCE' is disabled.
|
2020-01-24 11:27:03 0 [Note] InnoDB: Using Linux native AIO
|
2020-01-24 11:27:03 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2020-01-24 11:27:03 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2020-01-24 11:27:03 0 [Note] InnoDB: Uses event mutexes
|
2020-01-24 11:27:03 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
2020-01-24 11:27:03 0 [Note] InnoDB: Number of pools: 1
|
2020-01-24 11:27:03 0 [Note] InnoDB: Using SSE2 crc32 instructions
|
2020-01-24 11:27:03 0 [Note] mysqld: O_TMPFILE is not supported on /10.5/mysql-test/var/tmp/62/mysqld.2 (disabling future attempts)
|
2020-01-24 11:27:03 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
|
2020-01-24 11:27:03 0 [Note] InnoDB: Completed initialization of buffer pool
|
2020-01-24 11:27:03 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2020-01-24 11:27:03 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=218037
|
mysqld: /10.5/storage/innobase/log/log0recv.cc:2638: bool recv_parse_log_recs(lsn_t, store_t*, ulint, bool): Assertion `recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn' failed.
|
200124 11:27:03 [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.5.1-MariaDB-debug-log
|
key_buffer_size=1048576
|
read_buffer_size=131072
|
max_used_connections=0
|
max_threads=153
|
thread_count=0
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63718 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 0x49000
|
/10.5/sql/mysqld(my_print_stacktrace+0x40)[0x55e7d8179ab4]
|
/10.5/sql/mysqld(handle_fatal_signal+0x3ae)[0x55e7d78243e5]
|
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7ff7b8195730]
|
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7ff7b79177bb]
|
/lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7ff7b7902535]
|
/lib/x86_64-linux-gnu/libc.so.6(+0x2240f)[0x7ff7b790240f]
|
/lib/x86_64-linux-gnu/libc.so.6(+0x30102)[0x7ff7b7910102]
|
/10.5/sql/mysqld(+0x10ea27b)[0x55e7d7d4027b]
|
/10.5/sql/mysqld(+0x10eb474)[0x55e7d7d41474]
|
/10.5/sql/mysqld(+0x10eba12)[0x55e7d7d41a12]
|
/10.5/sql/mysqld(+0x10ed228)[0x55e7d7d43228]
|
/10.5/sql/mysqld(+0x123b5b4)[0x55e7d7e915b4]
|
/10.5/sql/mysqld(+0x1001a1e)[0x55e7d7c57a1e]
|
/10.5/sql/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0xfc)[0x55e7d7827dfd]
|
/10.5/sql/mysqld(+0x89d0ab)[0x55e7d74f30ab]
|
/10.5/sql/mysqld(_Z11plugin_initPiPPci+0xa6b)[0x55e7d74f3e2c]
|
/10.5/sql/mysqld(+0x73eb5d)[0x55e7d7394b5d]
|
/10.5/sql/mysqld(_Z11mysqld_mainiPPc+0x6db)[0x55e7d7395db0]
|
/10.5/sql/mysqld(main+0x20)[0x55e7d738a365]
|
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb)[0x7ff7b790409b]
|
/10.5/sql/mysqld(_start+0x2a)[0x55e7d738a28a]
|
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.
|
Writing a core file...
|
Working directory at /10.5/mysql-test/var/62/mysqld.2/data
|
Resource Limits:
|
Limit Soft Limit Hard Limit Units
|
Max cpu time unlimited unlimited seconds
|
Max file size unlimited unlimited bytes
|
Max data size unlimited unlimited bytes
|
Max stack size 8388608 unlimited bytes
|
Max core file size unlimited unlimited bytes
|
Max resident set unlimited unlimited bytes
|
Max processes 515503 515503 processes
|
Max open files 1024 1024 files
|
Max locked memory 67108864 67108864 bytes
|
Max address space unlimited unlimited bytes
|
Max file locks unlimited unlimited locks
|
Max pending signals 515503 515503 signals
|
Max msgqueue size 819200 819200 bytes
|
Max nice priority 0 0
|
Max realtime priority 0 0
|
Max realtime timeout unlimited unlimited us
|
Core pattern: core
|
|
----------SERVER LOG END-------------
|
mysqltest failed but provided no output
|
The result from queries just before the failure was:
|
< snip >
|
a
|
1
|
2
|
3
|
*** Test crashing slave at various points and check that it recovers crash-safe. ***
|
include/stop_slave.inc
|
SET GLOBAL debug_dbug="+d,inject_crash_before_write_rpl_slave_state";
|
START SLAVE;
|
connection server_1;
|
INSERT INTO t1 VALUES (4);
|
include/save_master_gtid.inc
|
connection server_2;
|
include/sync_with_master_gtid.inc
|
include/stop_slave.inc
|
START SLAVE;
|
SET GLOBAL debug_dbug="+d,crash_commit_before";
|
connection server_1;
|
INSERT INTO t1 VALUES (5);
|
include/save_master_gtid.inc
|
connection server_2;
|
|
|
|
- found 'core' (0/5)
|
|
Trying 'dbx' to get a backtrace
|
|
Trying 'gdb' to get a backtrace from coredump /10.5/mysql-test/var/62/log/rpl.rpl_gtid_crash-innodb,row/mysqld.2/data/core
|
Core generated by '/10.5/sql/mysqld'
|
Output from gdb follows. The first stack trace is from the failing thread.
|
The following stack traces are from all threads (so the failing one is
|
duplicated).
|
--------------------------
|
[New LWP 51376]
|
[New LWP 51454]
|
[New LWP 51461]
|
[New LWP 51550]
|
[New LWP 51537]
|
[Thread debugging using libthread_db enabled]
|
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
|
Core was generated by `/10.5/sql/mysqld --defaults-group-suffix=.2 --defaults-file=/10.5'.
|
Program terminated with signal SIGABRT, Aborted.
|
#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
|
56 ../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
|
[Current thread is 1 (Thread 0x7ff7b78db740 (LWP 51376))]
|
#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
|
#1 0x000055e7d8179ba6 in my_write_core (sig=6) at /10.5/mysys/stacktrace.c:518
|
#2 0x000055e7d782476e in handle_fatal_signal (sig=6) at /10.5/sql/signal_handler.cc:343
|
#3 <signal handler called>
|
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#5 0x00007ff7b7902535 in __GI_abort () at abort.c:79
|
#6 0x00007ff7b790240f in __assert_fail_base (fmt=0x7ff7b7a64ee0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e7d854d988 "recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn", file=0x55e7d854bdd0 "/10.5/storage/innobase/log/log0recv.cc", line=2638, function=<optimized out>) at assert.c:92
|
#7 0x00007ff7b7910102 in __GI___assert_fail (assertion=0x55e7d854d988 "recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn", file=0x55e7d854bdd0 "/10.5/storage/innobase/log/log0recv.cc", line=2638, function=0x55e7d8550860 <recv_parse_log_recs(unsigned long, store_t*, unsigned long, bool)::__PRETTY_FUNCTION__> "bool recv_parse_log_recs(lsn_t, store_t*, ulint, bool)") at assert.c:101
|
#8 0x000055e7d7d4027b in recv_parse_log_recs (checkpoint_lsn=216102, store=0x7ffeb4da9bc4, available_mem=5390336, apply=true) at /10.5/storage/innobase/log/log0recv.cc:2638
|
#9 0x000055e7d7d41474 in recv_scan_log_recs (available_mem=5390336, store_to_hash=0x7ffeb4da9bc4, log_block=0x7ff7b0b81800 "", checkpoint_lsn=216102, start_lsn=216064, end_lsn=218624, contiguous_lsn=0x7ffeb4da9c48, group_scanned_lsn=0x55e7d9601498 <log_sys+664>) at /10.5/storage/innobase/log/log0recv.cc:3099
|
#10 0x000055e7d7d41a12 in recv_group_scan_log_recs (checkpoint_lsn=216102, contiguous_lsn=0x7ffeb4da9c48, last_phase=false) at /10.5/storage/innobase/log/log0recv.cc:3187
|
#11 0x000055e7d7d43228 in recv_recovery_from_checkpoint_start (flush_lsn=64036) at /10.5/storage/innobase/log/log0recv.cc:3496
|
#12 0x000055e7d7e915b4 in srv_start (create_new_db=false) at /10.5/storage/innobase/srv/srv0start.cc:1698
|
#13 0x000055e7d7c57a1e in innodb_init (p=0x55e7daa82eb8) at /10.5/storage/innobase/handler/ha_innodb.cc:4029
|
#14 0x000055e7d7827dfd in ha_initialize_handlerton (plugin=0x55e7da9c6230) at /10.5/sql/handler.cc:550
|
#15 0x000055e7d74f30ab in plugin_initialize (tmp_root=0x7ffeb4dadf30, plugin=0x55e7da9c6230, argc=0x55e7d8d97ed8 <remaining_argc>, argv=0x55e7da890048, options_only=false) at /10.5/sql/sql_plugin.cc:1452
|
#16 0x000055e7d74f3e2c in plugin_init (argc=0x55e7d8d97ed8 <remaining_argc>, argv=0x55e7da890048, flags=0) at /10.5/sql/sql_plugin.cc:1734
|
#17 0x000055e7d7394b5d in init_server_components () at /10.5/sql/mysqld.cc:5008
|
#18 0x000055e7d7395db0 in mysqld_main (argc=167, argv=0x55e7da890048) at /10.5/sql/mysqld.cc:5536
|
#19 0x000055e7d738a365 in main (argc=27, argv=0x7ffeb4dae778) at /10.5/sql/main.cc:25
|
|
Thread 5 (Thread 0x7ff7b1d81700 (LWP 51537)):
|
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
|
#1 0x00007ff7b814527a in ?? () from /usr/lib/x86_64-linux-gnu/libaio.so.1
|
#2 0x000055e7d80ccd0e in tpool::aio_linux::getevent_thread_routine (aio=0x55e7daa7c010) at /10.5/tpool/aio_linux.cc:53
|
#3 0x000055e7d80cd377 in std::__invoke_impl<void, void (*)(tpool::aio_linux*), tpool::aio_linux*> (__f=@0x55e7daafeb50: 0x55e7d80cccca <tpool::aio_linux::getevent_thread_routine(tpool::aio_linux*)>, __args#0=@0x55e7daafeb48: 0x55e7daa7c010) at /usr/include/c++/8/bits/invoke.h:60
|
#4 0x000055e7d80cd09e in std::__invoke<void (*)(tpool::aio_linux*), tpool::aio_linux*> (__fn=@0x55e7daafeb50: 0x55e7d80cccca <tpool::aio_linux::getevent_thread_routine(tpool::aio_linux*)>, __args#0=@0x55e7daafeb48: 0x55e7daa7c010) at /usr/include/c++/8/bits/invoke.h:95
|
#5 0x000055e7d80cd625 in std::thread::_Invoker<std::tuple<void (*)(tpool::aio_linux*), tpool::aio_linux*> >::_M_invoke<0ul, 1ul> (this=0x55e7daafeb48) at /usr/include/c++/8/thread:244
|
#6 0x000055e7d80cd5e0 in std::thread::_Invoker<std::tuple<void (*)(tpool::aio_linux*), tpool::aio_linux*> >::operator() (this=0x55e7daafeb48) at /usr/include/c++/8/thread:253
|
#7 0x000055e7d80cd5c4 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)(tpool::aio_linux*), tpool::aio_linux*> > >::_M_run (this=0x55e7daafeb40) at /usr/include/c++/8/thread:196
|
#8 0x00007ff7b7cf9b2f in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
|
#9 0x00007ff7b818afa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
|
#10 0x00007ff7b79d94cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
Thread 4 (Thread 0x7ff7b0980700 (LWP 51550)):
|
#0 futex_wait_cancelable (private=0, expected=0, futex_word=0x55e7dac54ec8) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
|
#1 __pthread_cond_wait_common (abstime=0x0, mutex=0x55e7dac54e78, cond=0x55e7dac54ea0) at pthread_cond_wait.c:502
|
#2 __pthread_cond_wait (cond=0x55e7dac54ea0, mutex=0x55e7dac54e78) at pthread_cond_wait.c:655
|
#3 0x000055e7d7d6642c in os_event::wait (this=0x55e7dac54e60) at /10.5/storage/innobase/os/os0event.cc:158
|
#4 0x000055e7d7d65f38 in os_event::wait_low (this=0x55e7dac54e60, reset_sig_count=1) at /10.5/storage/innobase/os/os0event.cc:325
|
#5 0x000055e7d7d6621b in os_event_wait_low (event=0x55e7dac54e60, reset_sig_count=0) at /10.5/storage/innobase/os/os0event.cc:502
|
#6 0x000055e7d7fa3324 in buf_flush_page_cleaner_coordinator () at /10.5/storage/innobase/buf/buf0flu.cc:3174
|
#7 0x00007ff7b818afa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
|
#8 0x00007ff7b79d94cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
Thread 3 (Thread 0x7ff7b2998700 (LWP 51461)):
|
#0 futex_abstimed_wait_cancelable (private=0, abstime=0x7ff7b2997de0, expected=0, futex_word=0x55e7d95d55c8 <COND_checkpoint+40>) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
|
#1 __pthread_cond_wait_common (abstime=0x7ff7b2997de0, mutex=0x55e7d95d5508 <LOCK_checkpoint+40>, cond=0x55e7d95d55a0 <COND_checkpoint>) at pthread_cond_wait.c:539
|
#2 __pthread_cond_timedwait (cond=0x55e7d95d55a0 <COND_checkpoint>, mutex=0x55e7d95d5508 <LOCK_checkpoint+40>, abstime=0x7ff7b2997de0) at pthread_cond_wait.c:667
|
#3 0x000055e7d817ff50 in safe_cond_timedwait (cond=0x55e7d95d55a0 <COND_checkpoint>, mp=0x55e7d95d54e0 <LOCK_checkpoint>, abstime=0x7ff7b2997de0, file=0x55e7d84d0df0 "/10.5/include/mysql/psi/mysql_thread.h", line=1204) at /10.5/mysys/thr_mutex.c:546
|
#4 0x000055e7d7af94b5 in inline_mysql_cond_timedwait (that=0x55e7d95d55a0 <COND_checkpoint>, mutex=0x55e7d95d54e0 <LOCK_checkpoint>, abstime=0x7ff7b2997de0, src_file=0x55e7d84d0e20 "/10.5/storage/maria/ma_servicethread.c", src_line=116) at /10.5/include/mysql/psi/mysql_thread.h:1204
|
#5 0x000055e7d7af99fa in my_service_thread_sleep (control=0x55e7d8bc5c80 <checkpoint_control>, sleep_time=29000000000) at /10.5/storage/maria/ma_servicethread.c:115
|
#6 0x000055e7d7aecce6 in ma_checkpoint_background (arg=0x1e) at /10.5/storage/maria/ma_checkpoint.c:707
|
#7 0x000055e7d7beeb08 in pfs_spawn_thread (arg=0x55e7daa71ac8) at /10.5/storage/perfschema/pfs.cc:1862
|
#8 0x00007ff7b818afa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
|
#9 0x00007ff7b79d94cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
Thread 2 (Thread 0x7ff7b3511700 (LWP 51454)):
|
#0 futex_abstimed_wait_cancelable (private=0, abstime=0x7ff7b3510e90, expected=0, futex_word=0x55e7d964058c <COND_timer+44>) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
|
#1 __pthread_cond_wait_common (abstime=0x7ff7b3510e90, mutex=0x55e7d96404c8 <LOCK_timer+40>, cond=0x55e7d9640560 <COND_timer>) at pthread_cond_wait.c:539
|
#2 __pthread_cond_timedwait (cond=0x55e7d9640560 <COND_timer>, mutex=0x55e7d96404c8 <LOCK_timer+40>, abstime=0x7ff7b3510e90) at pthread_cond_wait.c:667
|
#3 0x000055e7d817ff50 in safe_cond_timedwait (cond=0x55e7d9640560 <COND_timer>, mp=0x55e7d96404a0 <LOCK_timer>, abstime=0x7ff7b3510e90, file=0x55e7d868bac0 "/10.5/include/mysql/psi/mysql_thread.h", line=1204) at /10.5/mysys/thr_mutex.c:546
|
#4 0x000055e7d81813e0 in inline_mysql_cond_timedwait (that=0x55e7d9640560 <COND_timer>, mutex=0x55e7d96404a0 <LOCK_timer>, abstime=0x7ff7b3510e90, src_file=0x55e7d868baf0 "/10.5/mysys/thr_timer.c", src_line=321) at /10.5/include/mysql/psi/mysql_thread.h:1204
|
#5 0x000055e7d81820b9 in timer_handler (arg=0x0) at /10.5/mysys/thr_timer.c:321
|
#6 0x000055e7d7beeb08 in pfs_spawn_thread (arg=0x55e7da9bdf58) at /10.5/storage/perfschema/pfs.cc:1862
|
#7 0x00007ff7b818afa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
|
#8 0x00007ff7b79d94cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
Thread 1 (Thread 0x7ff7b78db740 (LWP 51376)):
|
#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
|
#1 0x000055e7d8179ba6 in my_write_core (sig=6) at /10.5/mysys/stacktrace.c:518
|
#2 0x000055e7d782476e in handle_fatal_signal (sig=6) at /10.5/sql/signal_handler.cc:343
|
#3 <signal handler called>
|
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#5 0x00007ff7b7902535 in __GI_abort () at abort.c:79
|
#6 0x00007ff7b790240f in __assert_fail_base (fmt=0x7ff7b7a64ee0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e7d854d988 "recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn", file=0x55e7d854bdd0 "/10.5/storage/innobase/log/log0recv.cc", line=2638, function=<optimized out>) at assert.c:92
|
#7 0x00007ff7b7910102 in __GI___assert_fail (assertion=0x55e7d854d988 "recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn", file=0x55e7d854bdd0 "/10.5/storage/innobase/log/log0recv.cc", line=2638, function=0x55e7d8550860 <recv_parse_log_recs(unsigned long, store_t*, unsigned long, bool)::__PRETTY_FUNCTION__> "bool recv_parse_log_recs(lsn_t, store_t*, ulint, bool)") at assert.c:101
|
#8 0x000055e7d7d4027b in recv_parse_log_recs (checkpoint_lsn=216102, store=0x7ffeb4da9bc4, available_mem=5390336, apply=true) at /10.5/storage/innobase/log/log0recv.cc:2638
|
#9 0x000055e7d7d41474 in recv_scan_log_recs (available_mem=5390336, store_to_hash=0x7ffeb4da9bc4, log_block=0x7ff7b0b81800 "", checkpoint_lsn=216102, start_lsn=216064, end_lsn=218624, contiguous_lsn=0x7ffeb4da9c48, group_scanned_lsn=0x55e7d9601498 <log_sys+664>) at /10.5/storage/innobase/log/log0recv.cc:3099
|
#10 0x000055e7d7d41a12 in recv_group_scan_log_recs (checkpoint_lsn=216102, contiguous_lsn=0x7ffeb4da9c48, last_phase=false) at /10.5/storage/innobase/log/log0recv.cc:3187
|
#11 0x000055e7d7d43228 in recv_recovery_from_checkpoint_start (flush_lsn=64036) at /10.5/storage/innobase/log/log0recv.cc:3496
|
#12 0x000055e7d7e915b4 in srv_start (create_new_db=false) at /10.5/storage/innobase/srv/srv0start.cc:1698
|
#13 0x000055e7d7c57a1e in innodb_init (p=0x55e7daa82eb8) at /10.5/storage/innobase/handler/ha_innodb.cc:4029
|
#14 0x000055e7d7827dfd in ha_initialize_handlerton (plugin=0x55e7da9c6230) at /10.5/sql/handler.cc:550
|
#15 0x000055e7d74f30ab in plugin_initialize (tmp_root=0x7ffeb4dadf30, plugin=0x55e7da9c6230, argc=0x55e7d8d97ed8 <remaining_argc>, argv=0x55e7da890048, options_only=false) at /10.5/sql/sql_plugin.cc:1452
|
#16 0x000055e7d74f3e2c in plugin_init (argc=0x55e7d8d97ed8 <remaining_argc>, argv=0x55e7da890048, flags=0) at /10.5/sql/sql_plugin.cc:1734
|
#17 0x000055e7d7394b5d in init_server_components () at /10.5/sql/mysqld.cc:5008
|
#18 0x000055e7d7395db0 in mysqld_main (argc=167, argv=0x55e7da890048) at /10.5/sql/mysqld.cc:5536
|
#19 0x000055e7d738a365 in main (argc=27, argv=0x7ffeb4dae778) at /10.5/sql/main.cc:25
|