Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-22471

binlog_encryption.rpl_parallel_ignored_errors failed in buildbot due to slave crash

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Won't Fix
    • 10.2
    • N/A
    • Replication, Tests
    • None

    Description

      http://buildbot.askmonty.org/buildbot/builders/kvm-asan/builds/3392/steps/mtr_nm/logs/stdio

      bb-10-release 5008fc709bca54bd29a4d3f35aebf6e2

      binlog_encryption.rpl_parallel_ignored_errors 'innodb,stmt' w1 [ fail ]
              Test ended at 2020-05-04 04:35:17
       
      CURRENT_TEST: binlog_encryption.rpl_parallel_ignored_errors
      mysqltest: In included file "./suite/rpl/include/rpl_parallel_ignored_errors.inc": 
      included from /home/buildbot/buildbot/build/mariadb-10.2.32/mysql-test/suite/binlog_encryption/rpl_parallel_ignored_errors.test at line 2:
      At line 105: query 'SET GLOBAL debug_dbug=@old_debug' failed: 2013: Lost connection to MySQL server during query
       
      The result from queries just before the failure was:
      < snip >
      SET debug_sync="debug_sync_action SIGNAL reached_pause WAIT_FOR continue_worker";
      connection server_1;
      SET gtid_seq_no=100;
      INSERT INTO t1 VALUES (33);
      connection server_2;
      SET debug_sync='now WAIT_FOR reached_pause';
      connection server_1;
      INSERT INTO t1 VALUES (34);
      connection server_2;
      connection con_temp2;
      COMMIT;
      connection server_2;
      include/stop_slave.inc
      include/assert.inc [table t1 should have zero rows where a>32]
      SELECT * FROM t1 WHERE a>32;
      a
      DELETE FROM t1 WHERE a=32;
      SET GLOBAL slave_parallel_threads=@old_parallel_threads;
      SET GLOBAL slave_parallel_mode=@old_parallel_mode;
      SET GLOBAL debug_dbug=@old_debug;
       
      More results from queries before failure can be found in /dev/shm/var/1/log/rpl_parallel_ignored_errors.log
       
       
      Server [mysqld.2 - pid: 7165, winpid: 7165, exit: 256] failed during test run
      Server log from this test:
      ----------SERVER LOG START-----------
      2020-05-04  4:35:14 140388002363328 [Note] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld (mysqld 10.2.32-MariaDB-debug-log) starting as process 7166 ...
      2020-05-04  4:35:14 140388002363328 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
      2020-05-04  4:35:14 140388002363328 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'SEQUENCE' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'partition' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Uses event mutexes
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Using Linux native AIO
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Number of pools: 1
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Using generic crc32 instructions
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Completed initialization of buffer pool
      2020-05-04  4:35:14 140387797407488 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Highest supported file format is Barracuda.
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Creating shared tablespace for temporary tables
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2020-05-04  4:35:14 140388002363328 [Note] InnoDB: 5.7.30 started; log sequence number 1628840
      2020-05-04  4:35:14 140387701475072 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var/1/mysqld.2/data/ib_buffer_pool
      2020-05-04  4:35:14 140387701475072 [Note] InnoDB: Buffer pool(s) load completed at 200504  4:35:14
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_MUTEXES' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_CMP' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'FEEDBACK' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'user_variables' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
      2020-05-04  4:35:14 140388002363328 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
      2020-05-04  4:35:14 140388002363328 [Warning] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld: unknown option '--loose-pam-debug'
      2020-05-04  4:35:14 140388002363328 [Note] Server socket created on IP: '127.0.0.1'.
      2020-05-04  4:35:14 140388002363328 [Note] Reading of all Master_info entries succeeded
      2020-05-04  4:35:14 140388002363328 [Note] Added new Master_info '' to hash table
      2020-05-04  4:35:14 140388002363328 [Note] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld: ready for connections.
      Version: '10.2.32-MariaDB-debug-log'  socket: '/dev/shm/var/tmp/1/mysqld.2.sock'  port: 16001  Source distribution
      2020-05-04  4:35:15 140387622995712 [Note] Deleted Master_info file '/dev/shm/var/1/mysqld.2/data/master.info'.
      2020-05-04  4:35:15 140387622995712 [Note] Deleted Master_info file '/dev/shm/var/1/mysqld.2/data/relay-log.info'.
      2020-05-04  4:35:15 140387622995712 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
      2020-05-04  4:35:15 140387622995712 [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='16000', master_log_file='master-bin.000001', master_log_pos='4'.
      2020-05-04  4:35:15 140387619055360 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication started in log 'master-bin.000001' at position 4
      2020-05-04  4:35:15 140387618584320 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
      2020-05-04  4:35:15 140387618584320 [Note] Error reading relay log event: slave SQL thread was killed
      2020-05-04  4:35:15 140387618584320 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 369
      2020-05-04  4:35:15 140387619055360 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 369
      2020-05-04  4:35:15 140387622995712 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
      2020-05-04  4:35:15 140387622995712 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='369'. New state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='369'.
      2020-05-04  4:35:15 140387622995712 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
      2020-05-04  4:35:15 140387618584320 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position ''
      2020-05-04  4:35:15 140387619055360 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 369, relay log './slave-relay-bin.000001' position: 4; GTID position ''
      2020-05-04  4:35:15 140387616610048 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t1 VALUES (32)', Gtid 0-1-3, Internal MariaDB error code: 1062
      2020-05-04  4:35:15 140387616610048 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
      2020-05-04  4:35:15 140387616610048 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 682; GTID position '0-1-2'
      2020-05-04  4:35:15 140387619055360 [Note] Error reading relay log event: slave SQL thread was killed
      2020-05-04  4:35:15 140387617081088 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2020-05-04  4:35:15 140387617081088 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2020-05-04  4:35:15 140387617081088 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 682; GTID position '0-1-2'
      2020-05-04  4:35:15 140387619055360 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 682; GTID position '0-1-2'
      2020-05-04  4:35:15 140387618584320 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 1180; GTID position 0-1-101
      200504  4:35:16 [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.2.32-MariaDB-debug-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=5
      max_threads=153
      thread_count=12
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63103 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x62a00003c208
      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 = 0x7fae90980b70 thread_stack 0x5b000
      /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld(__interceptor_backtrace+0x5b)[0x5cb62b]
      /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld(my_print_stacktrace+0x10e)[0x22639ae]
      /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld(handle_fatal_signal+0x67a)[0xe95eca]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0)[0x7faea164c3c0]
      /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld(_db_doprnt_+0x2a7)[0x22b88f7]
      maria/ma_check.c:535(maria_chk_key)[0x16dc414]
      sql/sql_string.h:351(String::free())[0x1897d3c]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x9609)[0x7faea1640609]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7faea1156153]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x0): 
      Connection ID (thread ID): 2
      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=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=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.
      Writing a core file...
      Working directory at /dev/shm/var/1/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             23440                23440                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       23440                23440                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: |/usr/share/apport/apport %p %s %c %d %P ...
      ----------SERVER LOG END-------------
      

      Attachments

        Activity

          People

            Elkin Andrei Elkin
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.