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

Parallel replication deadlock around creating temporary table and updating a MyISAM table

    XMLWordPrintable

    Details

      Description

      I have one occasion so far, so not sure which factors are important here and which are not.

      Server: 10.1 commit bb15b9e29b3304
      Built as cmake . -DCMAKE_BUILD_TYPE=Debug && make

      Full processlist

      MariaDB [test]> show full processlist;
      +-----+-------------+-----------------+-------+---------+-------+--------------------------------------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+
      | Id  | User        | Host            | db    | Command | Time  | State                                                                          | Info                                                                                                                                                                                                                                   | Progress |
      +-----+-------------+-----------------+-------+---------+-------+--------------------------------------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+
      |   2 | root        | localhost:51845 | mysql | Query   | 81378 | Waiting for the slave SQL thread to advance position                           | SELECT MASTER_POS_WAIT('mysql-bin.000001',494481)                                                                                                                                                                                      |    0.000 |
      | 347 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 348 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 349 | system user |                 | NULL  | Connect | 81399 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 350 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 351 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 352 | system user |                 | NULL  | Connect | 81398 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 353 | system user |                 | NULL  | Connect | 81399 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 354 | system user |                 | NULL  | Connect | 81398 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 355 | system user |                 | NULL  | Connect | 81399 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 356 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 357 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 358 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 359 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 360 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 361 | system user |                 | NULL  | Connect | 81399 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 362 | system user |                 | test  | Connect | 81405 | Waiting for prior transaction to commit                                        | CREATE TEMPORARY TABLE view_table11_myisam ( `col_int_key` INTEGER, KEY (`col_int_key`) ) SELECT /* QUERY_ID: 9416192 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ 0 AS `col_int_key` FROM `view_table11_myisam` WHERE 5 <> `col_int_key` |    0.000 |
      | 363 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 364 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 365 | system user |                 | test  | Connect | 81397 | Waiting for table level lock                                                   | UPDATE table11_myisam SET `col_int_key` = 4                                                                                                                                                                                            |    0.000 |
      | 366 | system user |                 | NULL  | Connect | 81397 | Waiting for prior transaction to start commit before starting next transaction | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 367 | system user |                 | NULL  | Connect | 81377 | Slave has read all relay log; waiting for the slave I/O thread to update it    | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 370 | system user |                 | NULL  | Connect | 81378 | Waiting for master to send event                                               | NULL                                                                                                                                                                                                                                   |    0.000 |
      | 376 | root        | localhost:52728 | test  | Query   |     0 | init                                                                           | show full processlist                                                                                                                                                                                                                  |    0.000 |
      +-----+-------------+-----------------+-------+---------+-------+--------------------------------------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+

      Metadata lock info

      MariaDB [test]> select * from information_schema.metadata_lock_info;
      +-----------+-------------------------+-----------------+---------------------+--------------+---------------------+
      | THREAD_ID | LOCK_MODE               | LOCK_DURATION   | LOCK_TYPE           | TABLE_SCHEMA | TABLE_NAME          |
      +-----------+-------------------------+-----------------+---------------------+--------------+---------------------+
      |       365 | MDL_INTENTION_EXCLUSIVE | MDL_STATEMENT   | Global read lock    |              |                     |
      |       362 | MDL_SHARED_READ         | MDL_TRANSACTION | Table metadata lock | test         | table11_myisam      |
      |       365 | MDL_SHARED_WRITE        | MDL_TRANSACTION | Table metadata lock | test         | table11_myisam      |
      |       362 | MDL_SHARED_READ         | MDL_TRANSACTION | Table metadata lock | test         | view_table11_myisam |
      +-----------+-------------------------+-----------------+---------------------+--------------+---------------------+
      4 rows in set (0.01 sec)

      Slave startup command line

       /home/elenst/git/10.1/sql/mysqld --no-defaults --basedir=/home/elenst/git/10.1 --datadir=/home/elenst/test_results/10.1-parallel-replication-10/current1_1_slave/data --lc-messages-dir=/home/elenst/git/10.1/sql/share --character-sets-dir=/home/elenst/git/10.1/sql/share/charsets --tmpdir=/home/elenst/test_results/10.1-parallel-replication-10/current1_1_slave/tmp --core-file --max-allowed-packet=128Mb --port=10732 --socket=/home/elenst/test_results/10.1-parallel-replication-10/current1_1_slave/mysql.sock --pid-file=/home/elenst/test_results/10.1-parallel-replication-10/current1_1_slave/mysql.pid --general-log --general-log-file=/home/elenst/test_results/10.1-parallel-replication-10/current1_1_slave/mysql.log --server_id=2 --report-host=127.0.0.1 --report_port=10732 --log_output=FILE --slow_query_log --log_bin_trust_function_creators=1 --query_cache_size=64M --slave-skip-errors=1054,1317,1049,1305,1539,1505 --slave-parallel-mode=conservative --binlog_commit_wait_count=20 --binlog_commit_wait_usec=1000000 --slave-parallel-threads=20 --sql-mode=no_engine_substitution

      Master startup command line

      /home/elenst/git/10.1/sql/mysqld --no-defaults --basedir=/home/elenst/git/10.1 --datadir=/home/elenst/test_results/10.1-parallel-replication-10/current1_1/data --lc-messages-dir=/home/elenst/git/10.1/sql/share --character-sets-dir=/home/elenst/git/10.1/sql/share/charsets --tmpdir=/home/elenst/test_results/10.1-parallel-replication-10/current1_1/tmp --core-file --max-allowed-packet=128Mb --port=10730 --socket=/home/elenst/test_results/10.1-parallel-replication-10/current1_1/mysql.sock --pid-file=/home/elenst/test_results/10.1-parallel-replication-10/current1_1/mysql.pid --general-log --general-log-file=/home/elenst/test_results/10.1-parallel-replication-10/current1_1/mysql.log --server_id=1 --log-bin=mysql-bin --report-host=127.0.0.1 --report_port=10730 --log_output=FILE --slow_query_log --log_bin_trust_function_creators=1 --query_cache_size=64M --slave-skip-errors=1054,1317,1049,1305,1539,1505 --slave-parallel-mode=conservative --binlog_commit_wait_count=20 --binlog_commit_wait_usec=1000000 --slave-parallel-threads=20 --sql-mode=no_engine_substitution

      Slave status

      MariaDB [test]> show all slaves status \G
      *************************** 1. row ***************************
                    Connection_name: 
                    Slave_SQL_State: Slave has read all relay log; waiting for the slave I/O thread to update it
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 127.0.0.1
                        Master_User: root
                        Master_Port: 10730
                      Connect_Retry: 1
                    Master_Log_File: mysql-bin.000001
                Read_Master_Log_Pos: 494481
                     Relay_Log_File: mysql-relay-bin.000016
                      Relay_Log_Pos: 4611
              Relay_Master_Log_File: mysql-bin.000001
                   Slave_IO_Running: Yes
                  Slave_SQL_Running: Yes
                    Replicate_Do_DB: 
                Replicate_Ignore_DB: 
                 Replicate_Do_Table: 
             Replicate_Ignore_Table: 
            Replicate_Wild_Do_Table: 
        Replicate_Wild_Ignore_Table: 
                         Last_Errno: 0
                         Last_Error: 
                       Skip_Counter: 0
                Exec_Master_Log_Pos: 466551
                    Relay_Log_Space: 93945
                    Until_Condition: None
                     Until_Log_File: 
                      Until_Log_Pos: 0
                 Master_SSL_Allowed: No
                 Master_SSL_CA_File: 
                 Master_SSL_CA_Path: 
                    Master_SSL_Cert: 
                  Master_SSL_Cipher: 
                     Master_SSL_Key: 
              Seconds_Behind_Master: 82059
      Master_SSL_Verify_Server_Cert: No
                      Last_IO_Errno: 0
                      Last_IO_Error: 
                     Last_SQL_Errno: 0
                     Last_SQL_Error: 
        Replicate_Ignore_Server_Ids: 
                   Master_Server_Id: 1
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: No
                        Gtid_IO_Pos: 
            Replicate_Do_Domain_Ids: 
        Replicate_Ignore_Domain_Ids: 
                      Parallel_Mode: conservative
               Retried_transactions: 0
                 Max_relay_log_size: 1073741824
               Executed_log_entries: 5958
          Slave_received_heartbeats: 45
             Slave_heartbeat_period: 1800.000
                     Gtid_Slave_Pos: 0-1-2246
      1 row in set (0.01 sec)

      mysql.gtid_slave_pos

      MariaDB [test]> select * from mysql.gtid_slave_pos;
      +-----------+--------+-----------+--------+
      | domain_id | sub_id | server_id | seq_no |
      +-----------+--------+-----------+--------+
      |         0 |   2658 |         1 |   2121 |
      |         0 |   2659 |         1 |   2122 |
      |         0 |   2660 |         1 |   2123 |
      |         0 |   2661 |         1 |   2124 |
      |         0 |   2662 |         1 |   2125 |
      |         0 |   2663 |         1 |   2126 |
      |         0 |   2664 |         1 |   2127 |
      |         0 |   2665 |         1 |   2128 |
      |         0 |   2784 |         1 |   2246 |
      +-----------+--------+-----------+--------+
      9 rows in set (0.00 sec)

      gtid pos

      MariaDB [test]> show variables like 'gtid%pos';
      +------------------+----------+
      | Variable_name    | Value    |
      +------------------+----------+
      | gtid_binlog_pos  |          |
      | gtid_current_pos | 0-1-2246 |
      | gtid_slave_pos   | 0-1-2246 |
      +------------------+----------+
      3 rows in set (0.00 sec)

      table11_myisam

      MariaDB [test]> show create table table11_myisam;
      +----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | Table          | Create Table                                                                                                                                                                                                        |
      +----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      | table11_myisam | CREATE TABLE `table11_myisam` (
        `col_int_key` int(11) DEFAULT NULL,
        `col_int` int(11) DEFAULT NULL,
        `default` int(11) DEFAULT '1',
        KEY `col_int_key` (`col_int_key`)
      ) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
      +----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
      1 row in set (0.00 sec)

      view_table11_myisam

      MariaDB [test]> show create table view_table11_myisam \G
      *************************** 1. row ***************************
                      View: view_table11_myisam
               Create View: CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `view_table11_myisam` AS select `table11_myisam`.`col_int_key` AS `col_int_key`,`table11_myisam`.`col_int` AS `col_int` from `table11_myisam`
      character_set_client: latin1
      collation_connection: latin1_swedish_ci
      1 row in set (0.00 sec)

      default storage engine

      MariaDB [test]> select @@default_storage_engine;
      +--------------------------+
      | @@default_storage_engine |
      +--------------------------+
      | InnoDB                   |
      +--------------------------+
      1 row in set (0.00 sec)

      Attached:
      master.err - master's error log
      master.log - master's general log
      slave.err - slave's error log
      slave.log - slave's general log
      mysql-bin.* - master's binary log (slave is running without binlog)
      threads - all threads' bt
      threads_full - all threads' bt full
      session_vars - show variables
      global_vars - show global variables
      global_status - show global status

      RQG command line (for a record, it does not reproduce the problem while running again)

      perl /home/elenst/bzr/randgen-mariadb-patches/runall-new.pl --no-mask --seed=1432477513 --threads=16 --duration=400 --queries=100M --reporters=QueryTimeout,Backtrace,ErrorLog,Deadlock,ReplicationThreadRestarter --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/10.0-features-redefine.yy --mysqld=--log_output=FILE --mysqld=--slow_query_log --mysqld=--log_bin_trust_function_creators=1 --mysqld=--query_cache_size=64M --views --grammar=conf/runtime/metadata_stability.yy --gendata=conf/runtime/metadata_stability.zz --engine=MyISAM --rpl_mode=statement --mysqld=--slave-skip-errors=1054,1317,1049,1305,1539,1505 --mysqld=--slave-parallel-mode=conservative --mysqld=--binlog_commit_wait_count=20 --mysqld=--binlog_commit_wait_usec=1000000 --mysqld=--slave-parallel-threads=20 --use-gtid=no --mtr-build-thread=73 --basedir1=/home/elenst/git/10.1 --vardir1=/home/elenst/test_results/10.1-parallel-replication-10/current1_1

      RQG: lp:~elenst/randgen/mariadb-patches revno 1019

        Attachments

        1. global_status
          12 kB
        2. global_vars
          18 kB
        3. master.err
          17 kB
        4. master.log
          914 kB
        5. mysql-bin.000001
          483 kB
        6. mysql-bin.index
          0.0 kB
        7. session_vars
          18 kB
        8. slave.err
          16 kB
        9. slave.log
          576 kB
        10. threads
          52 kB
        11. threads_full
          154 kB

          Activity

            People

            Assignee:
            knielsen Kristian Nielsen
            Reporter:
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated:

                Git Integration