[MDEV-22835] galera.wsrep_strict_ddl MTR failed: crashed while running 'analyze-timeout' Created: 2020-06-08  Updated: 2020-06-16  Resolved: 2020-06-12

Status: Closed
Project: MariaDB Server
Component/s: Galera, Tests
Affects Version/s: 10.5.4
Fix Version/s: 10.5.4

Type: Bug Priority: Major
Reporter: Stepan Patryshev (Inactive) Assignee: Seppo Jaakola
Resolution: Duplicate Votes: 0
Labels: None
Environment:

kvm-rpm-centos74-amd64, Galera 26.4.4(r4599)


Attachments: Zip Archive 200608_wsrep_strict_ddl_10.5.zip     HTML File 200608_wsrep_strict_ddl_stdio_10.5.html    
Issue Links:
Relates
relates to MDEV-20051 Add new mode to wsrep_OSU_method in w... Closed
relates to MDEV-22878 galera.wsrep_strict_ddl hangs in 10.5... Closed

 Description   

galera.wsrep_strict_ddl MTR failed on BB, 10.5 CS: "crashed while running 'analyze-timeout'".

stdio.log:

10.5.4 d3681335b18b82cf1cfb090ce1938de2ee6b21fc

galera.wsrep_strict_ddl 'innodb'         w2 [ fail ]  timeout after 900 seconds
        Test ended at 2020-06-08 12:28:10
 
Test case timeout after 900 seconds
 
== /dev/shm/var/2/log/wsrep_strict_ddl.log == 
Table	Create Table
t2	CREATE TABLE `t2` (
  `a` int(11) NOT NULL,
  PRIMARY KEY (`a`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
connection node_1;
TRUNCATE TABLE before_t1;
ERROR HY000: DDL-statement is forbidden as table storage engine does not support Galera replication
SELECT * FROM before_t1;
a	count	b
1	1	1
connection node_2;
SET SESSION wsrep_sync_wait=15;
SELECT @@wsrep_sync_wait;
@@wsrep_sync_wait
15
SELECT * FROM before_t1;
a	count	b
connection node_1;
CREATE VIEW x1 AS SELECT * FROM before_t1;
 
The server [mysqld.2 - pid: 4943, winpid: 4943, exit: 256] crashed while running 'analyze-timeout'
Server log from this test:
----------SERVER LOG START-----------
2020-06-08 12:12:23 37 [ERROR] Slave SQL: Error 'DDL-statement is forbidden as table storage engine does not support Galera replication' on query. Default database: 'test'. Query: 'TRUNCATE TABLE before_t1', Internal MariaDB error code: 4165
2020-06-08 12:12:23 37 [Warning] WSREP: Ignoring error 'DDL-statement is forbidden as table storage engine does not support Galera replication' on query. Default database: 'test'. Query: 'TRUNCATE TABLE before_t1', Error_code: 4165
2020-06-08 12:27:22 72 [Warning] Aborted connection 72 to db: 'test' user: 'root' host: 'localhost' (Got an error reading communication packets)
200608 12:27:30 [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.4-MariaDB-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=3
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63596 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
/usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x55e58ef7f31e]
/usr/sbin/mariadbd(handle_fatal_signal+0x307)[0x55e58e98cc27]
2020-06-08 12:27:30 0 [Note] WSREP: (494b5961-be31, 'tcp://0.0.0.0:16025') turning message relay requesting on, nonlive peers: tcp://127.0.0.1:16022 
2020-06-08 12:27:31 0 [Note] WSREP: (494b5961-be31, 'tcp://0.0.0.0:16025') reconnecting to ff2ed5c7-8449 (tcp://127.0.0.1:16022), attempt 0
2020-06-08 12:27:43 0 [Note] WSREP: evs::proto(494b5961-be31, OPERATIONAL, view_id(REG,494b5961-be31,14)) suspecting node: ff2ed5c7-8449
2020-06-08 12:27:43 0 [Note] WSREP: evs::proto(494b5961-be31, OPERATIONAL, view_id(REG,494b5961-be31,14)) suspected node without join message, declaring inactive
2020-06-08 12:27:44 0 [Warning] WSREP: last inactive check more than PT1.5S ago (PT4.52699S), skipping check
2020-06-08 12:27:44 0 [Note] WSREP: view(view_id(NON_PRIM,494b5961-be31,14) memb {
	494b5961-be31,0
} joined {
} left {
} partitioned {
	ff2ed5c7-8449,0
})
2020-06-08 12:27:44 0 [Note] WSREP: view(view_id(NON_PRIM,494b5961-be31,15) memb {
	494b5961-be31,0
} joined {
} left {
} partitioned {
	ff2ed5c7-8449,0
})
2020-06-08 12:27:44 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2020-06-08 12:27:44 0 [Note] WSREP: Flow-control interval: [16, 16]
2020-06-08 12:27:44 0 [Note] WSREP: Received NON-PRIMARY.
2020-06-08 12:27:44 0 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 397)
2020-06-08 12:27:44 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2020-06-08 12:27:44 0 [Note] WSREP: Flow-control interval: [16, 16]
2020-06-08 12:27:44 0 [Note] WSREP: Received NON-PRIMARY.
2020-06-08 12:27:52 0 [Warning] WSREP: last inactive check more than PT1.5S ago (PT1.74041S), skipping check
sigaction.c:0(__restore_rt)[0x7f2b745145e0]
:0(__poll_nocancel)[0x7f2b72861a3d]
/usr/sbin/mariadbd(_Z26handle_connections_socketsv+0x1f7)[0x55e58e6c9ce7]
/usr/sbin/mariadbd(_Z11mysqld_mainiPPc+0xec0)[0x55e58e6caef0]
??:0(__libc_start_main)[0x7f2b72795c05]
/usr/sbin/mariadbd(+0x68cf43)[0x55e58e6bef43]
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 /dev/shm/var/2/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             4096                 23142                processes 
Max open files            1024                 1024                 files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       23142                23142                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-------------
 
 - found 'core.4945' (0/0)
 
Trying 'dbx' to get a backtrace
gdb not found, cannot get the stack trace
 
Trying 'lldb' to get a backtrace from coredump /dev/shm/var/2/log/galera.wsrep_strict_ddl-innodb/mysqld.2/data/core.4945
Compressed file /dev/shm/var/2/log/galera.wsrep_strict_ddl-innodb/mysqld.2/data/core.4945
 - found 'core.2988' (1/0)
 
Trying 'dbx' to get a backtrace
gdb not found, cannot get the stack trace
 
Trying 'lldb' to get a backtrace from coredump /dev/shm/var/2/log/galera.wsrep_strict_ddl-innodb/mysqld.1/data/core.2988
Compressed file /dev/shm/var/2/log/galera.wsrep_strict_ddl-innodb/mysqld.1/data/core.2988
 - saving '/dev/shm/var/2/log/galera.wsrep_strict_ddl-innodb/' to '/dev/shm/var/log/galera.wsrep_strict_ddl-innodb/'
 
Retrying test galera.wsrep_strict_ddl, attempt(2/3)...
 
worker[2] > Restart  - not started
worker[2] > Restart  - not started
***Warnings generated in error logs during shutdown after running tests: galera.galera_var_certify_nonPK_off galera.lp959512 galera.lp1276424 galera.lp1376747-3 galera.galera_var_fkchecks galera.galera_var_replicate_myisam_on galera.lp1438990 galera.mdev_9290 galera.mysql-wsrep#31 galera.wsrep_strict_ddl galera.galera_var_OSU_method2 galera.mysql-wsrep#332 galera.view galera.galera_var_OSU_method galera.galera_var_cluster_address galera.galera_unicode_pk galera.mdev_21025 galera.lp1376747-2 galera.mysql-wsrep#90 galera.lp1376747 galera.galera_wsrep_provider_options_syntax galera.galera_var_mysql_replication_bundle galera.galera_var_wsrep_on_off galera.unique_key galera.rename galera.galera_update_limit galera.grant galera.lp1347768 galera.galera_var_auto_inc_control_off galera.galera_var_ignore_apply_errors galera.galera_var_cluster_conf_id galera.galera_var_replicate_myisam_off galera.galera_var_max_ws_size galera.galera_var_sync_wait galera.mysql-wsrep#237 galera.galera_var_desync_on galera.mysql-wsrep#110 galera.galera_var_max_ws_rows galera.galera_wsrep_provider_unset_set galera.pxc-421 galera.galera_var_dirty_reads galera.mysql-wsrep#247 galera.galera_zero_length_column galera.galera_view
 
Attempting backtrace. You can use the following information to find out
Attempting backtrace. You can use the following information to find out

Server logs.



 Comments   
Comment by Marko Mäkelä [ 2020-06-12 ]

The parameter wsrep_strict_ddl was introduced in MDEV-20051 (10.5.1).

Generated at Thu Feb 08 09:17:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.