[#MDEV-20536] rpl.rpl_circular_for_4_hosts failed in buildbot with crash in lf_hash_search_using_hash

Version: '10.4.8-MariaDB-log'  socket: '/Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/var/tmp/mysqld.4.sock'  port: 16003  MariaDB Server

190903  9:59:45 [ERROR] mysqld got signal 11 ;

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.4.8-MariaDB-log

key_buffer_size=1048576

read_buffer_size=131072

max_used_connections=1

max_threads=153

thread_count=8

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63511 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fcb2e882408

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 = 0x70000b94ae60 thread_stack 0x49000

0   mysqld                              0x0000000105f45f2c my_print_stacktrace + 60

0   mysqld                              0x00000001056282c4 handle_fatal_signal + 740

addr2line: /usr/lib/system/libsystem_platform.dylib: file format not recognized

0   libsystem_platform.dylib            0x00007fff7089ff5a _sigtramp + 26

0   ???                                 0x00007fcb2f951008 0x0 + 140510653386760

0   mysqld                              0x0000000105f4e261 lf_hash_search_using_hash_value + 257

0   mysqld                              0x000000010599df01 _ZN7MDL_map14find_or_insertEP7LF_PINSPK7MDL_key + 129

0   mysqld                              0x000000010599fdc0 _ZN11MDL_context21try_acquire_lock_implEP11MDL_requestPP10MDL_ticket + 240

0   mysqld                              0x00000001059a0035 _ZN11MDL_context12acquire_lockEP11MDL_requestd + 37

0   mysqld                              0x00000001058fdcfc _Z14get_all_tablesP3THDP10TABLE_LISTP4Item + 2828

0   mysqld                              0x0000000105905b85 _Z24get_schema_tables_resultP4JOIN23enum_schema_table_state + 613

0   mysqld                              0x00000001058cc828 _ZN4JOIN10exec_innerEv + 1736

0   mysqld                              0x00000001058b024d _Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex + 1037

0   mysqld                              0x00000001058afd3f _Z13handle_selectP3THDP3LEXP13select_resultm + 239

0   mysqld                              0x000000010588100b _ZL21execute_sqlcom_selectP3THDP10TABLE_LIST + 1227

0   mysqld                              0x0000000105878818 _Z21mysql_execute_commandP3THD + 5112

0   mysqld                              0x00000001057c0180 _ZN13sp_instr_stmt9exec_coreEP3THDPj + 112

0   mysqld                              0x00000001057bf2ef _ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr + 623

0   mysqld                              0x00000001057bfabb _ZN13sp_instr_stmt7executeEP3THDPj + 1083

0   mysqld                              0x00000001057b9c04 _ZN7sp_head7executeEP3THDb + 1668

0   mysqld                              0x00000001057bb43c _ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE + 2316

0   mysqld                              0x000000010587739e _ZL13do_execute_spP3THDP7sp_head + 270

0   mysqld                              0x0000000105876f05 _ZN12Sql_cmd_call7executeEP3THD + 261

0   mysqld                              0x0000000105878757 _Z21mysql_execute_commandP3THD + 4919

0   mysqld                              0x0000000105873ce7 _Z11mysql_parseP3THDPcjP12Parser_statebb + 791

0   mysqld                              0x0000000105870dbf _Z16dispatch_command19enum_server_commandP3THDPcjbb + 2383

0   mysqld                              0x0000000105874187 _Z10do_commandP3THD + 711

0   mysqld                              0x0000000105996599 _Z24do_handle_one_connectionP7CONNECT + 681

0   mysqld                              0x00000001059962d8 handle_one_connection + 56

0   mysqld                              0x0000000105e1d7db pfs_spawn_thread + 299

addr2line: /usr/lib/system/libsystem_pthread.dylib: file format not recognized

0   libsystem_pthread.dylib             0x00007fff708a9661 _pthread_body + 340

0   libsystem_pthread.dylib             0x00007fff708a950d _pthread_body + 0

0   libsystem_pthread.dylib             0x00007fff708a8bf9 thread_start + 13

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x7fcb2e87fa20): is an invalid pointer

Connection ID (thread ID): 9

Status: NOT_KILLED

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

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.

We think the query pointer is invalid, but we will try to print it anyway.

Query: SELECT CONCAT(table_schema, '.', table_name) AS columns_in_mysql,   	 column_name, ordinal_position, column_default, is_nullable,          data_type, character_maximum_length, character_octet_length,          numeric_precision, numeric_scale, character_set_name,          collation_name, column_type, column_key, extra, column_comment     FROM INFORMATION_SCHEMA.COLUMNS       WHERE table_schema='mysql'         ORDER BY columns_in_mysql

rpl.rpl_circular_for_4_hosts 'innodb,mix' w6 [ fail ]

        Test ended at 2020-10-02 13:46:26

CURRENT_TEST: rpl.rpl_circular_for_4_hosts

Server [mysqld.1 - pid: 20717, winpid: 20717, exit: 256] failed during test run

Server log from this test:

----------SERVER LOG START-----------

2020-10-02 13:44:42 0 [Note] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd (mysqld 10.5.6-MariaDB-log) starting as process 20718 ...

2020-10-02 13:44:42 0 [Warning] Could not increase number of max_open_files to more than 1012 (request: 32190)

2020-10-02 13:44:42 0 [Warning] Changed limits: max_open_files: 1012  max_connections: 151 (was 151)  table_cache: 415 (was 2000)

2020-10-02 13:44:43 0 [Note] Plugin 'partition' is disabled.

2020-10-02 13:44:43 0 [Note] Plugin 'SEQUENCE' is disabled.

2020-10-02 13:44:43 0 [Note] InnoDB: Using Linux native AIO

2020-10-02 13:44:43 0 [Note] InnoDB: Uses event mutexes

2020-10-02 13:44:43 0 [Note] InnoDB: Compressed tables use zlib 1.2.7

2020-10-02 13:44:44 0 [Note] InnoDB: Number of pools: 1

2020-10-02 13:44:44 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

2020-10-02 13:44:44 0 [Note] mariadbd: O_TMPFILE is not supported on /var/tmp/mtr/tmp/6/mysqld.1 (disabling future attempts)

2020-10-02 13:44:44 0 [Note] InnoDB: Initializing buffer pool, total size = 8388608, chunk size = 8388608

2020-10-02 13:44:44 0 [Note] InnoDB: Completed initialization of buffer pool

2020-10-02 13:44:44 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2020-10-02 13:44:45 0 [Note] InnoDB: 128 rollback segments are active.

2020-10-02 13:44:46 0 [Note] InnoDB: Creating shared tablespace for temporary tables

2020-10-02 13:44:46 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2020-10-02 13:44:46 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2020-10-02 13:44:46 0 [Note] InnoDB: 10.5.6 started; log sequence number 47235; transaction id 27

2020-10-02 13:44:46 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.

2020-10-02 13:44:46 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_CMP' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'FEEDBACK' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'user_variables' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.

2020-10-02 13:44:47 0 [Note] Plugin 'unix_socket' is disabled.

2020-10-02 13:44:47 0 [Note] InnoDB: Loading buffer pool(s) from /var/tmp/mtr/6/mysqld.1/data/ib_buffer_pool

2020-10-02 13:44:47 0 [Note] InnoDB: Buffer pool(s) load completed at 201002 13:44:47

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown variable 'loose-feedback-debug-startup-interval=20'

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown variable 'loose-feedback-debug-first-interval=60'

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown variable 'loose-feedback-debug-interval=60'

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown option '--loose-pam-debug'

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown option '--loose-aria'

2020-10-02 13:44:48 0 [Warning] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: unknown variable 'loose-debug-sync-timeout=300'

2020-10-02 13:44:50 0 [Note] Server socket created on IP: '127.0.0.1'.

2020-10-02 13:44:51 0 [Note] Reading of all Master_info entries succeeded

2020-10-02 13:44:51 0 [Note] Added new Master_info '' to hash table

2020-10-02 13:44:51 0 [Note] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mariadbd: ready for connections.

Version: '10.5.6-MariaDB-log'  socket: '/var/tmp/mtr/tmp/6/mysqld.1.sock'  port: 16120  Source distribution

2020-10-02 13:45:00 6 [Note] Deleted Master_info file '/var/tmp/mtr/6/mysqld.1/data/master.info'.

2020-10-02 13:45:00 6 [Note] Deleted Master_info file '/var/tmp/mtr/6/mysqld.1/data/relay-log.info'.

2020-10-02 13:45:01 6 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'

2020-10-02 13:45:01 6 [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='16123', master_log_file='master-bin.000001', master_log_pos='4'.

2020-10-02 13:45:03 8 [Note] Start binlog_dump to slave_server(2), pos(master-bin.000001, 4), using_gtid(0), gtid('')

2020-10-02 13:45:03 9 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16123' in log 'master-bin.000001' at position 4

2020-10-02 13:45:03 10 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './master-relay-bin.000001' position: 4

2020-10-02 13:45:03 9 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16123',replication started in log 'master-bin.000001' at position 4

----------SERVER LOG END-------------

mysqltest failed but provided no output

The result from queries just before the failure was:

< snip >

SELECT 'Master B',b,COUNT(*) FROM t2 WHERE c = 2 GROUP BY b ORDER BY b;

Master B	b	COUNT(*)

Master B	B	100

Master B	D	100

connection server_3;

SELECT 'Master C',b,COUNT(*) FROM t2 WHERE c = 2 GROUP BY b ORDER BY b;

Master C	b	COUNT(*)

Master C	B	100

Master C	D	100

connection server_4;

SELECT 'Master D',b,COUNT(*) FROM t2 WHERE c = 2 GROUP BY b ORDER BY b;

Master D	b	COUNT(*)

Master D	B	100

Master D	D	100

connection server_1;

*** Clean up ***

connection server_1;

DROP TABLE t1,t2;

include/rpl_end.inc

 - skipping '/var/tmp/mtr/6/log/rpl.rpl_circular_for_4_hosts-innodb,mix/'

***Warnings generated in error logs during shutdown after running tests: rpl.rpl_circular_for_4_hosts

2020-10-02 13:45:12 9 [Warning] Slave: Duplicate entry '6' for key 'PRIMARY' Error_code: 1062

[MDEV-20536] rpl.rpl_circular_for_4_hosts failed in buildbot with crash in lf_hash_search_using_hash_value Created: 2019-09-08 Updated: 2020-10-07
Status:	Open
Project:	MariaDB Server
Component/s:	Server, Tests
Affects Version/s:	10.4, 10.5
Fix Version/s:	10.4

[MDEV-20536] rpl.rpl_circular_for_4_hosts failed in buildbot with crash in lf_hash_search_using_hash_value Created: 2019-09-08 Updated: 2020-10-07