Bug #1331586 “Replication stall with multi-threaded replication” : Bugs : Percona Server moved to https://jira.percona.com/projects/PS

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-18:

#1

gdb_std.txt Edit (82.8 KiB, text/plain)

thread apply all bt

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-18:

#2

gdb_full.txt Edit (124.2 KiB, text/plain)

thread apply all bt full

tags:

added: i43091

Ovais Tariq (ovais-tariq) on 2014-06-18

description:

updated

Revision history for this message

Valerii Kravchuk (valerii-kravchuk) wrote on 2014-06-19:

#3

Looks similar to upstream http://bugs.mysql.com/bug.php?id=72537 (check processlist attached there).

tags:

added: upstream

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-19:

#4

@Valeri,

The bug http://bugs.mysql.com/bug.php?id=72537 links the issue to the table being MyISAM but in my case the table is InnoDB. So this might be a more generic storage-engine independent bug.

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-19:

#5

coordinator_stuck_worker_open_trx.tar Edit (450.0 KiB, application/x-tar)

Download full text (3.2 KiB)

So I have another instance of a slave stuck because one of the worker has a transaction open for 22367 seconds and the coordinator is waiting on the worker to finish.

+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined |
+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+
| 91 | system user | | NULL | Connect | 35042 | Waiting for master to send event | NULL | 0 | 0 |
| 92 | system user | | NULL | Connect | 22356 | Waiting for Slave Worker to release partition | NULL | 0 | 0 |
| 93 | system user | | NULL | Connect | 35042 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 94 | system user | | NULL | Connect | 35042 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 95 | system user | | NULL | Connect | 35042 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 96 | system user | | NULL | Connect | 35042 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 97 | system user | | NULL | Connect | 35042 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 98 | system user | | NULL | Connect | 71771 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 99 | system user | | NULL | Connect | 71771 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 100 | system user | | NULL | Connect | 71771 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 101 | system user | | NULL | Connect | 71771 | Waiting for an event from Coordinator | NULL | 0 | 1 |
| 102 | system user | | NULL | Connect | 71771 | Waiting for an event from Coordinator | NULL | 0 | 0 |
| 176 | root | localhost | NULL | Query | 0 | init | show processlist | 0 | 0 |
+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+

---TRANSACTION 53789616362, ACTIVE 22367 sec
2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 101, OS thread handle 0x39, query id 95380210 Waiting for an event from Coordinator
TABLE LOCK table `db2`.`some_tbl` /* Partition `p5` */ trx id 53789616362 lock mode IX
RECORD LOCKS space id 3485 page no 16641 n bits 424 index `PRIMARY` of table `db2`.`some_tbl` /* Partition `p5` *...

So I have another instance of a slave stuck because one of the worker has a transaction open for 22367 seconds and the coordinator is waiting on the worker to finish.

+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+
| Id  | User        | Host      | db   | Command | Time  | State                                         | Info             | Rows_sent | Rows_examined |
+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+
|  91 | system user |           | NULL | Connect | 35042 | Waiting for master to send event              | NULL             |         0 |             0 |
|  92 | system user |           | NULL | Connect | 22356 | Waiting for Slave Worker to release partition | NULL             |         0 |             0 |
|  93 | system user |           | NULL | Connect | 35042 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  94 | system user |           | NULL | Connect | 35042 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  95 | system user |           | NULL | Connect | 35042 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  96 | system user |           | NULL | Connect | 35042 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  97 | system user |           | NULL | Connect | 35042 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  98 | system user |           | NULL | Connect | 71771 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
|  99 | system user |           | NULL | Connect | 71771 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
| 100 | system user |           | NULL | Connect | 71771 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
| 101 | system user |           | NULL | Connect | 71771 | Waiting for an event from Coordinator         | NULL             |         0 |             1 |
| 102 | system user |           | NULL | Connect | 71771 | Waiting for an event from Coordinator         | NULL             |         0 |             0 |
| 176 | root        | localhost | NULL | Query   |     0 | init                                          | show processlist |         0 |             0 |
+-----+-------------+-----------+------+---------+-------+-----------------------------------------------+------------------+-----------+---------------+

---TRANSACTION 53789616362, ACTIVE 22367 sec
2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 101, OS thread handle 0x39, query id 95380210 Waiting for an event from Coordinator
TABLE LOCK table `db2`.`some_tbl` /* Partition `p5` */ trx id 53789616362 lock mode IX
RECORD LOCKS space id 3485 page no 16641 n bits 424 index `PRIMARY` of table `db2`.`some_tbl` /* Partition `p5` */ trx id 53789616362 lock_mode X locks rec but not gap

Attached are the full and standard backtraces generated from gdb

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-19:

#6

Download full text (39.7 KiB)

More details on the state of the coordinator thread:

set print pretty on
p *w_entry

$9 = {
  <Relay_log_info> = {
    <Rpl_info> = {
      <Slave_reporting_capability> = {
        _vptr.Slave_reporting_capability = 0x1146d30 <vtable for Slave_worker+16>,
        err_lock = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 4,
              __pthread_mutex_flag2 = 0 '\000',
              __pthread_mutex_ceiling = 0 '\000',
              __pthread_mutex_type = 0,
              __pthread_mutex_magic = 19800
            },
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              },
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0,
                __pthread_lockword = 0
              },
              __pthread_mutex_owner64 = 0
            },
            __pthread_mutex_data = 0
          },
          m_psi = 0x0
        },
        m_last_error = {
          number = 0,
          message = '\000' <repeats 1023 times>,
          timestamp = '\000' <repeats 15 times>
        },
        m_thread_name = 0x10b0199 "SQL"
      },
      members of Rpl_info:
      data_lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4,
            __pthread_mutex_flag2 = 0 '\000',
            __pthread_mutex_ceiling = 0 '\000',
            __pthread_mutex_type = 0,
            __pthread_mutex_magic = 19800
          },
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            },
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0,
              __pthread_lockword = 0
            },
            __pthread_mutex_owner64 = 0
          },
          __pthread_mutex_data = 0
        },
        m_psi = 0x0
      },
      run_lock = {
                m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4,
            __pthread_mutex_flag2 = 0 '\000',
            __pthread_mutex_ceiling = 0 '\000',
            __pthread_mutex_type = 0,
            __pthread_mutex_magic = 19800
          },
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            },
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0,
              __pthread_lockword = 0
            },
            __pthread_mutex_owner64 = 0
          },
          __pthread_mutex_data = 0
        },
        m_psi = 0x0
      },
      sleep_lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4,
            __pthread_mutex_flag2 = 0 '\000',
            __pthread_mutex_ceiling = 0 '\000',
            __pthread_mutex_type = 0,
            __pthread_mutex_magic = 19800
          },
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            },
           ...

More details on the state of the coordinator thread:

set print pretty on
p *w_entry

$9 = {
  <Relay_log_info> = {
    <Rpl_info> = {
      <Slave_reporting_capability> = {
        _vptr.Slave_reporting_capability = 0x1146d30 <vtable for Slave_worker+16>, 
        err_lock = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 4, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 19800
            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }, 
        m_last_error = {
          number = 0, 
          message = '\000' <repeats 1023 times>, 
          timestamp = '\000' <repeats 15 times>
        }, 
        m_thread_name = 0x10b0199 "SQL"
      }, 
      members of Rpl_info: 
      data_lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      run_lock = {
                m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      sleep_lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      data_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
            __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      start_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
                          __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      stop_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
            __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      sleep_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
            __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      key_info_run_lock = 0x1264bfc <key_relay_log_info_run_lock>, 
      key_info_data_lock = 0x1264c08 <key_relay_log_info_data_lock>, 
      key_info_sleep_lock = 0x1264c04 <key_relay_log_info_sleep_lock>, 
      key_info_data_cond = 0x1264b3c <key_relay_log_info_data_cond>, 
      key_info_start_cond = 0x1264b34 <key_relay_log_info_start_cond>, 
      key_info_stop_cond = 0x1264b30 <key_relay_log_info_stop_cond>, 
      key_info_sleep_cond = 0x1264b2c <key_relay_log_info_sleep_cond>, 
      info_thd = 0x9b7f9930, 
      inited = true, 
      abort_slave = false, 
      slave_running = 0, 
      slave_run_id = 0, 
      handler = 0x9b27e180, 
      internal_id = 9
    }, 
    members of Relay_log_info: 
    replicate_same_server_id = false, 
    cur_log_fd = -1, 
    relay_log = {
      <TC_LOG> = {
        _vptr.TC_LOG = 0x1146750 <vtable for MYSQL_BIN_LOG+16>
      }, 
      <MYSQL_LOG> = {
        LOCK_log = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 4, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 19800
                            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }, 
        name = 0x0, 
        log_file_name = '\000' <repeats 511 times>, 
        time_buff = '\000' <repeats 19 times>, 
        db = '\000' <repeats 192 times>, 
        write_error = false, 
        inited = true, 
        log_file = {
          pos_in_file = 0, 
          end_of_file = 0, 
          read_pos = 0x0, 
          read_end = 0x0, 
          buffer = 0x0, 
          request_pos = 0x0, 
          write_buffer = 0x0, 
          append_read_pos = 0x0, 
          write_pos = 0x0, 
          write_end = 0x0, 
          current_pos = 0x0, 
          current_end = 0x0, 
          append_buffer_lock = {
            m_mutex = {
              __pthread_mutex_flags = {
                __pthread_mutex_flag1 = 0, 
                __pthread_mutex_flag2 = 0 '\000', 
                __pthread_mutex_ceiling = 0 '\000', 
                __pthread_mutex_type = 0, 
                __pthread_mutex_magic = 0
              }, 
              __pthread_mutex_lock = {
                __pthread_mutex_lock64 = {
                  __pthread_mutex_pad = "\000\000\000\000\000\000\000"
                }, 
                __pthread_mutex_lock32 = {
                  __pthread_ownerpid = 0, 
                  __pthread_lockword = 0
                }, 
                __pthread_mutex_owner64 = 0
              }, 
              __pthread_mutex_data = 0
            }, 
            m_psi = 0x0
          }, 
          share = 0x0, 
          read_function = 0x0, 
          write_function = 0x0,
                      type = TYPE_NOT_SET, 
          pre_read = 0x0, 
          post_read = 0x0, 
          pre_close = 0x0, 
          disk_writes = 0, 
          arg = 0x0, 
          file_name = 0x0, 
          dir = 0x0, 
          prefix = 0x0, 
          file = 0, 
          seek_not_done = 0, 
          error = 0, 
          buffer_length = 0, 
          read_length = 0, 
          myflags = 0, 
          alloced_buffer = 0 '\000'
        }, 
        log_type = LOG_UNKNOWN, 
        log_state = LOG_CLOSED, 
        io_cache_type = TYPE_NOT_SET, 
        cur_log_ext = 18446744073709551615, 
        m_log_file_key = 0, 
        m_key_LOCK_log = 20
      }, 
      members of MYSQL_BIN_LOG: 
      m_key_LOCK_index = 19, 
      m_key_COND_done = 7, 
      m_key_LOCK_commit_queue = 16, 
      m_key_LOCK_done = 17, 
      m_key_LOCK_flush_queue = 18, 
      m_key_LOCK_sync_queue = 22, 
      m_key_LOCK_commit = 15, 
      m_key_LOCK_sync = 21, 
      m_key_LOCK_xids = 23, 
      m_key_update_cond = 8, 
      m_key_prep_xids_cond = 9, 
      m_key_file_log = 4, 
      m_key_file_log_index = 5, 
      LOCK_index = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
                }, 
      LOCK_commit = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      LOCK_sync = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      LOCK_xids = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
                          __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      update_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
            __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      bytes_written = 0, 
      index_file = {
        pos_in_file = 0, 
        end_of_file = 0, 
        read_pos = 0x0, 
        read_end = 0x0, 
        buffer = 0x0, 
        request_pos = 0x0, 
        write_buffer = 0x0, 
        append_read_pos = 0x0, 
        write_pos = 0x0, 
        write_end = 0x0, 
        current_pos = 0x0, 
        current_end = 0x0, 
        append_buffer_lock = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 0, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 0
            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }, 
        share = 0x0, 
        read_function = 0x0, 
                  write_function = 0x0, 
        type = TYPE_NOT_SET, 
        pre_read = 0x0, 
        post_read = 0x0, 
        pre_close = 0x0, 
        disk_writes = 0, 
        arg = 0x0, 
        file_name = 0x0, 
        dir = 0x0, 
        prefix = 0x0, 
        file = 0, 
        seek_not_done = 0, 
        error = 0, 
        buffer_length = 0, 
        read_length = 0, 
        myflags = 0, 
        alloced_buffer = 0 '\000'
      }, 
      index_file_name = '\000' <repeats 511 times>, 
      crash_safe_index_file = {
        pos_in_file = 0, 
        end_of_file = 0, 
        read_pos = 0x0, 
        read_end = 0x0, 
        buffer = 0x0, 
        request_pos = 0x0, 
        write_buffer = 0x0, 
        append_read_pos = 0x0, 
        write_pos = 0x0, 
        write_end = 0x0, 
        current_pos = 0x0, 
        current_end = 0x0, 
        append_buffer_lock = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 0, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 0
            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }, 
        share = 0x0, 
        read_function = 0x0, 
        write_function = 0x0, 
        type = TYPE_NOT_SET, 
        pre_read = 0x0, 
                  post_read = 0x0, 
        pre_close = 0x0, 
        disk_writes = 0, 
        arg = 0x0, 
        file_name = 0x0, 
        dir = 0x0, 
        prefix = 0x0, 
        file = 0, 
        seek_not_done = 0, 
        error = 0, 
        buffer_length = 0, 
        read_length = 0, 
        myflags = 0, 
        alloced_buffer = 0 '\000'
      }, 
      crash_safe_index_file_name = '\000' <repeats 511 times>, 
      purge_index_file = {
        pos_in_file = 0, 
        end_of_file = 0, 
        read_pos = 0x0, 
        read_end = 0x0, 
        buffer = 0x0, 
        request_pos = 0x0, 
        write_buffer = 0x0, 
        append_read_pos = 0x0, 
        write_pos = 0x0, 
        write_end = 0x0, 
        current_pos = 0x0, 
        current_end = 0x0, 
        append_buffer_lock = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 0, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 0
            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }, 
        share = 0x0, 
        read_function = 0x0, 
        write_function = 0x0, 
        type = TYPE_NOT_SET, 
        pre_read = 0x0, 
        post_read = 0x0, 
        pre_close = 0x0, 
        disk_writes = 0, 
                  arg = 0x0, 
        file_name = 0x0, 
        dir = 0x0, 
        prefix = 0x0, 
        file = 0, 
        seek_not_done = 0, 
        error = 0, 
        buffer_length = 0, 
        read_length = 0, 
        myflags = 0, 
        alloced_buffer = 0 '\000'
      }, 
      purge_index_file_name = '\000' <repeats 511 times>, 
      max_size = 0, 
      file_id = 1, 
      open_count = 1, 
      readers_count = 0, 
      sync_period_ptr = 0x1269918 <sync_relaylog_period>, 
      sync_counter = 0, 
      m_prep_xids_lock = 0 '\000', 
      m_prep_xids_cond = {
        m_cond = {
          __pthread_cond_flags = {
            __pthread_cond_flag = "\000\003\000", 
            __pthread_cond_type = 0, 
            __pthread_cond_magic = 17238
          }, 
          __pthread_cond_data = 0
        }, 
        m_psi = 0x0
      }, 
      m_prep_xids = 0, 
      stage_manager = {
        m_queue = {{
            m_first = 0x0, 
            m_last = 0x9b632d48, 
            m_lock = {
              m_mutex = {
                __pthread_mutex_flags = {
                  __pthread_mutex_flag1 = 4, 
                  __pthread_mutex_flag2 = 0 '\000', 
                  __pthread_mutex_ceiling = 0 '\000', 
                  __pthread_mutex_type = 0, 
                  __pthread_mutex_magic = 19800
                }, 
                __pthread_mutex_lock = {
                  __pthread_mutex_lock64 = {
                    __pthread_mutex_pad = "\000\000\000\000\000\000\000"
                  }, 
                  __pthread_mutex_lock32 = {
                    __pthread_ownerpid = 0, 
                    __pthread_lockword = 0
                  }, 
                  __pthread_mutex_owner64 = 0
                }, 
                __pthread_mutex_data = 0
              }, 
              m_psi = 0x0
            }
          }, {
                      m_first = 0x0, 
            m_last = 0x9b632d88, 
            m_lock = {
              m_mutex = {
                __pthread_mutex_flags = {
                  __pthread_mutex_flag1 = 4, 
                  __pthread_mutex_flag2 = 0 '\000', 
                  __pthread_mutex_ceiling = 0 '\000', 
                  __pthread_mutex_type = 0, 
                  __pthread_mutex_magic = 19800
                }, 
                __pthread_mutex_lock = {
                  __pthread_mutex_lock64 = {
                    __pthread_mutex_pad = "\000\000\000\000\000\000\000"
                  }, 
                  __pthread_mutex_lock32 = {
                    __pthread_ownerpid = 0, 
                    __pthread_lockword = 0
                  }, 
                  __pthread_mutex_owner64 = 0
                }, 
                __pthread_mutex_data = 0
              }, 
              m_psi = 0x0
            }
          }, {
            m_first = 0x0, 
            m_last = 0x9b632dc8, 
            m_lock = {
              m_mutex = {
                __pthread_mutex_flags = {
                  __pthread_mutex_flag1 = 4, 
                  __pthread_mutex_flag2 = 0 '\000', 
                  __pthread_mutex_ceiling = 0 '\000', 
                  __pthread_mutex_type = 0, 
                  __pthread_mutex_magic = 19800
                }, 
                __pthread_mutex_lock = {
                  __pthread_mutex_lock64 = {
                    __pthread_mutex_pad = "\000\000\000\000\000\000\000"
                  }, 
                  __pthread_mutex_lock32 = {
                    __pthread_ownerpid = 0, 
                    __pthread_lockword = 0
                  }, 
                  __pthread_mutex_owner64 = 0
                }, 
                __pthread_mutex_data = 0
              }, 
              m_psi = 0x0
            }
          }}, 
        m_cond_done = {
          m_cond = {
            __pthread_cond_flags = {
              __pthread_cond_flag = "\000\003\000", 
              __pthread_cond_type = 0, 
              __pthread_cond_magic = 17238
            }, 
            __pthread_cond_data = 0
                        }, 
          m_psi = 0x0
        }, 
        m_lock_done = {
          m_mutex = {
            __pthread_mutex_flags = {
              __pthread_mutex_flag1 = 4, 
              __pthread_mutex_flag2 = 0 '\000', 
              __pthread_mutex_ceiling = 0 '\000', 
              __pthread_mutex_type = 0, 
              __pthread_mutex_magic = 19800
            }, 
            __pthread_mutex_lock = {
              __pthread_mutex_lock64 = {
                __pthread_mutex_pad = "\000\000\000\000\000\000\000"
              }, 
              __pthread_mutex_lock32 = {
                __pthread_ownerpid = 0, 
                __pthread_lockword = 0
              }, 
              __pthread_mutex_owner64 = 0
            }, 
            __pthread_mutex_data = 0
          }, 
          m_psi = 0x0
        }
      }, 
      is_relay_log = false, 
      signal_cnt = 0, 
      checksum_alg_reset = 255 '\377', 
      relay_log_checksum_alg = 255 '\377', 
      previous_gtid_set = 0x0, 
      snapshot_lock_acquired = false
    }, 
    linfo = {
      log_file_name = '\000' <repeats 511 times>, 
      index_file_offset = 0, 
      index_file_start_offset = 0, 
      pos = 0, 
      fatal = false, 
      entry_index = 0, 
      lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
                      __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }
    }, 
    cache_buf = {
      pos_in_file = 0, 
      end_of_file = 0, 
      read_pos = 0x0, 
      read_end = 0x0, 
      buffer = 0x0, 
      request_pos = 0x0, 
      write_buffer = 0x0, 
      append_read_pos = 0x0, 
      write_pos = 0x0, 
      write_end = 0x0, 
      current_pos = 0x0, 
      current_end = 0x0, 
      append_buffer_lock = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 0, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 0
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      share = 0x0, 
      read_function = 0x0, 
      write_function = 0x0, 
      type = TYPE_NOT_SET, 
      pre_read = 0x0, 
      post_read = 0x0, 
      pre_close = 0x0, 
      disk_writes = 0, 
      arg = 0x0, 
      file_name = 0x0, 
      dir = 0x0, 
      prefix = 0x0, 
      file = 0, 
      seek_not_done = 0, 
      error = 0, 
      buffer_length = 0, 
      read_length = 0, 
      myflags = 0, 
      alloced_buffer = 0 '\000'
            }, 
    cur_log = 0x0, 
    is_relay_log_recovery = false, 
    save_temporary_tables = 0x0, 
    mi = 0x0, 
    cur_log_old_open_count = 0, 
    group_relay_log_name = "./qdbbackup2-relay-bin.000973", '\000' <repeats 482 times>, 
    group_relay_log_pos = 616886798, 
    event_relay_log_name = '\000' <repeats 511 times>, 
    event_relay_log_pos = 0, 
    future_event_relay_log_pos = 616887100, 
    group_master_log_name = "bin.003252", '\000' <repeats 501 times>, 
    group_master_log_pos = 616886776, 
    future_group_master_log_pos = 616887078, 
    gtid_set = {
      static default_string_format = {
        begin = 0x10acc3c "", 
        end = 0x10acc3c "", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10afe47 ",\n", 
        empty_set_string = 0x10acc3c "", 
        begin_length = 0, 
        end_length = 0, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
        gno_gno_separator_length = 1, 
        gno_sid_separator_length = 2, 
        empty_set_string_length = 0
      }, 
      static sql_string_format = {
        begin = 0x10ad498 "'", 
        end = 0x10ad498 "'", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10bd48c "',\n'", 
        empty_set_string = 0x10afd9d "''", 
        begin_length = 1, 
        end_length = 1, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
        gno_gno_separator_length = 1, 
        gno_sid_separator_length = 4, 
        empty_set_string_length = 2
      }, 
      static commented_string_format = {
        begin = 0x10af595 "# ", 
        end = 0x10acc3c "", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10af593 ",\n# ", 
        empty_set_string = 0x10bd482 "# [empty]", 
        begin_length = 2, 
        end_length = 0, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
        gno_gno_separator_length = 1, 
                  gno_sid_separator_length = 4, 
        empty_set_string_length = 9
      }, 
      static CHUNK_GROW_SIZE = 8, 
      sid_lock = 0x12e21b8, 
      free_intervals_mutex = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 4, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 19800
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      sid_map = 0x12f5a50, 
      intervals = {
        buffer = 0x9b28ff90 "p\207", <incomplete sequence \342>, 
        elements = 0, 
        max_element = 8, 
        alloc_increment = 8, 
        size_of_element = 8
      }, 
      free_intervals = 0x0, 
      chunks = 0x0, 
      cached_string_length = -1, 
      cached_string_format = 0x0
    }, 
    last_retrieved_gtid = {
      sidno = 0, 
      gno = 0, 
      static MAX_TEXT_LENGTH = 56
    }, 
    log_space_limit = 0, 
    log_space_total = 0, 
    ignore_log_space_limit = false, 
    sql_force_rotate_relay = false, 
    last_master_timestamp = 0, 
    slave_skip_counter = 0, 
    abort_pos_wait = 0, 
    log_space_lock = {
      m_mutex = {
        __pthread_mutex_flags = {
          __pthread_mutex_flag1 = 4, 
          __pthread_mutex_flag2 = 0 '\000', 
          __pthread_mutex_ceiling = 0 '\000', 
          __pthread_mutex_type = 0, 
                      __pthread_mutex_magic = 19800
        }, 
        __pthread_mutex_lock = {
          __pthread_mutex_lock64 = {
            __pthread_mutex_pad = "\000\000\000\000\000\000\000"
          }, 
          __pthread_mutex_lock32 = {
            __pthread_ownerpid = 0, 
            __pthread_lockword = 0
          }, 
          __pthread_mutex_owner64 = 0
        }, 
        __pthread_mutex_data = 0
      }, 
      m_psi = 0x0
    }, 
    log_space_cond = {
      m_cond = {
        __pthread_cond_flags = {
          __pthread_cond_flag = "\000\003\000", 
          __pthread_cond_type = 0, 
          __pthread_cond_magic = 17238
        }, 
        __pthread_cond_data = 0
      }, 
      m_psi = 0x0
    }, 
    until_condition = Relay_log_info::UNTIL_NONE, 
    until_log_name = '\000' <repeats 511 times>, 
    until_log_pos = 0, 
    until_log_name_extension = 0, 
    until_sql_gtids = {
      static default_string_format = {
        begin = 0x10acc3c "", 
        end = 0x10acc3c "", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10afe47 ",\n", 
        empty_set_string = 0x10acc3c "", 
        begin_length = 0, 
        end_length = 0, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
        gno_gno_separator_length = 1, 
        gno_sid_separator_length = 2, 
        empty_set_string_length = 0
      }, 
      static sql_string_format = {
        begin = 0x10ad498 "'", 
        end = 0x10ad498 "'", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10bd48c "',\n'", 
        empty_set_string = 0x10afd9d "''", 
        begin_length = 1, 
        end_length = 1, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
                  gno_gno_separator_length = 1, 
        gno_sid_separator_length = 4, 
        empty_set_string_length = 2
      }, 
      static commented_string_format = {
        begin = 0x10af595 "# ", 
        end = 0x10acc3c "", 
        sid_gno_separator = 0x10acf23 ":", 
        gno_start_end_separator = 0x10ad90b "-", 
        gno_gno_separator = 0x10acf23 ":", 
        gno_sid_separator = 0x10af593 ",\n# ", 
        empty_set_string = 0x10bd482 "# [empty]", 
        begin_length = 2, 
        end_length = 0, 
        sid_gno_separator_length = 1, 
        gno_start_end_separator_length = 1, 
        gno_gno_separator_length = 1, 
        gno_sid_separator_length = 4, 
        empty_set_string_length = 9
      }, 
      static CHUNK_GROW_SIZE = 8, 
      sid_lock = 0x0, 
      free_intervals_mutex = {
        m_mutex = {
          __pthread_mutex_flags = {
            __pthread_mutex_flag1 = 0, 
            __pthread_mutex_flag2 = 0 '\000', 
            __pthread_mutex_ceiling = 0 '\000', 
            __pthread_mutex_type = 0, 
            __pthread_mutex_magic = 0
          }, 
          __pthread_mutex_lock = {
            __pthread_mutex_lock64 = {
              __pthread_mutex_pad = "\000\000\000\000\000\000\000"
            }, 
            __pthread_mutex_lock32 = {
              __pthread_ownerpid = 0, 
              __pthread_lockword = 0
            }, 
            __pthread_mutex_owner64 = 0
          }, 
          __pthread_mutex_data = 0
        }, 
        m_psi = 0x0
      }, 
      sid_map = 0x12f5a50, 
      intervals = {
        buffer = 0x9b28ffd8 "", 
        elements = 0, 
        max_element = 8, 
        alloc_increment = 8, 
        size_of_element = 8
      }, 
      free_intervals = 0x0, 
      chunks = 0x0, 
      cached_string_length = -1, 
      cached_string_format = 0x0
    }, 
    until_sql_gtids_first_event = true, 
    until_log_names_cmp_result = Relay_log_info::UNTIL_LOG_NAMES_CMP_EQUAL, 
          cached_charset = "-\000-", <incomplete sequence \340>, 
    trans_retries = 0, 
    retried_trans = 0, 
    ign_master_log_name_end = '\000' <repeats 511 times>, 
    ign_master_log_pos_end = 0, 
    slave_patternload_file = '\000' <repeats 511 times>, 
    slave_patternload_file_size = 0, 
    last_clock = {
      tv_sec = 1403156644, 
      tv_nsec = 349992100
    }, 
    tables_to_lock = 0x0, 
    tables_to_lock_count = 0, 
    m_table_map = {
      m_mem_root = {
        free = 0x0, 
        used = 0x9b855950, 
        pre_alloc = 0x0, 
        min_malloc = 32, 
        block_size = 480, 
        block_num = 5, 
        first_block_usage = 0, 
        error_handler = 0x0
      }, 
      m_free = 0x9b855960, 
      m_table_ids = {
        key_offset = 0, 
        key_length = 8, 
        blength = 1, 
        records = 0, 
        flags = 0, 
        array = {
          buffer = 0x9b2fdbd0 "\377\377\377\377", 
          elements = 0, 
          max_element = 32, 
          alloc_increment = 64, 
          size_of_element = 16
        }, 
        get_key = 0x0, 
        free = 0x0, 
        charset = 0x123a540 <my_charset_bin>, 
        hash_function = 0xa967c0 <cset_hash_sort_adapter>
      }
    }, 
    rows_query_ev = 0x0, 
    last_event_start_time = 0, 
    deferred_events = 0x9b81d9f0, 
    deferred_events_collecting = true, 
    workers = {
      buffer = 0x9b27da98 "@9'\233", 
      elements = 8, 
      max_element = 10, 
      alloc_increment = 4, 
      size_of_element = 8
    }, 
    pending_jobs = 0, 
    pending_jobs_lock = {
      m_mutex = {
        __pthread_mutex_flags = {
          __pthread_mutex_flag1 = 4, 
                      __pthread_mutex_flag2 = 0 '\000', 
          __pthread_mutex_ceiling = 0 '\000', 
          __pthread_mutex_type = 0, 
          __pthread_mutex_magic = 19800
        }, 
        __pthread_mutex_lock = {
          __pthread_mutex_lock64 = {
            __pthread_mutex_pad = "\000\000\000\000\000\000\000"
          }, 
          __pthread_mutex_lock32 = {
            __pthread_ownerpid = 0, 
            __pthread_lockword = 0
          }, 
          __pthread_mutex_owner64 = 0
        }, 
        __pthread_mutex_data = 0
      }, 
      m_psi = 0x0
    }, 
    pending_jobs_cond = {
      m_cond = {
        __pthread_cond_flags = {
          __pthread_cond_flag = "\000\003\000", 
          __pthread_cond_type = 0, 
          __pthread_cond_magic = 17238
        }, 
        __pthread_cond_data = 0
      }, 
      m_psi = 0x0
    }, 
    mts_slave_worker_queue_len_max = 0, 
    mts_pending_jobs_size = 0, 
    mts_pending_jobs_size_max = 0, 
    mts_wq_oversize = false, 
    last_assigned_worker = 0x0, 
    gaq = 0x0, 
    curr_group_assigned_parts = {
      buffer = 0x0, 
      elements = 0, 
      max_element = 0, 
      alloc_increment = 0, 
      size_of_element = 0
    }, 
    curr_group_da = {
      buffer = 0x0, 
      elements = 0, 
      max_element = 0, 
      alloc_increment = 0, 
      size_of_element = 0
    }, 
    curr_group_seen_gtid = false, 
    curr_group_seen_begin = false, 
    curr_group_isolated = false, 
    mts_end_group_sets_max_dbs = false, 
    mts_wq_underrun_w_id = 0, 
    mts_wq_excess_cnt = 0, 
    mts_worker_underrun_level = 0, 
    mts_coordinator_basic_nap = 0, 
    opt_slave_parallel_workers = 0, 
    slave_parallel_workers = 0, 
          recovery_parallel_workers = 0, 
    checkpoint_seqno = 0, 
    checkpoint_group = 2048, 
    recovery_groups = {
      bitmap = 0x0, 
      n_bits = 0, 
      last_word_mask = 0, 
      last_word_ptr = 0x0, 
      mutex = 0x0
    }, 
    recovery_groups_inited = false, 
    mts_recovery_group_cnt = 0, 
    mts_recovery_index = 0, 
    mts_recovery_group_seen_begin = false, 
    mts_group_status = Relay_log_info::MTS_NOT_IN_GROUP, 
    mts_events_assigned = 0, 
    mts_groups_assigned = 0, 
    mts_wq_overrun_cnt = 0, 
    wq_size_waits_cnt = 0, 
    mts_wq_no_underrun_cnt = 0, 
    mts_wq_overfill_cnt = 0, 
    least_occupied_workers = {
      buffer = 0x0, 
      elements = 0, 
      max_element = 0, 
      alloc_increment = 0, 
      size_of_element = 0
    }, 
    mts_last_online_stat = 0, 
    reported_unsafe_warning = false, 
    slave_version_split = "\005\006\021", 
    rli_description_event = 0x9e1c7bc8, 
    sql_delay = 0, 
    sql_delay_end = 0, 
    m_flags = 1, 
    static LINES_IN_RELAY_LOG_INFO_WITH_DELAY = 5, 
    static LINES_IN_RELAY_LOG_INFO_WITH_WORKERS = 6, 
    static LINES_IN_RELAY_LOG_INFO_WITH_ID = 7, 
    row_stmt_start_timestamp = 0, 
    long_find_row_note_printed = false, 
    error_on_rli_init_info = false
  }, 
  members of Slave_worker: 
  jobs = {
    <circular_buffer_queue> = {
      Q = {
        buffer = 0x7a61f080 "\250Ӳ\233", 
        elements = 16384, 
        max_element = 16384, 
        alloc_increment = 1023, 
        size_of_element = 8
      }, 
      size = 16384, 
      avail = 864, 
      entry = 16384, 
      len = 0, 
      inited_queue = true
    }, 
    members of Slave_jobs_queue: 
    overfill = false, 
          waited_overfill = 0
  }, 
  jobs_lock = {
    m_mutex = {
      __pthread_mutex_flags = {
        __pthread_mutex_flag1 = 4, 
        __pthread_mutex_flag2 = 0 '\000', 
        __pthread_mutex_ceiling = 0 '\000', 
        __pthread_mutex_type = 0, 
        __pthread_mutex_magic = 19800
      }, 
      __pthread_mutex_lock = {
        __pthread_mutex_lock64 = {
          __pthread_mutex_pad = "\000\000\000\000\000\000\000"
        }, 
        __pthread_mutex_lock32 = {
          __pthread_ownerpid = 0, 
          __pthread_lockword = 0
        }, 
        __pthread_mutex_owner64 = 0
      }, 
      __pthread_mutex_data = 0
    }, 
    m_psi = 0x0
  }, 
  jobs_cond = {
    m_cond = {
      __pthread_cond_flags = {
        __pthread_cond_flag = "\000\003\001", 
        __pthread_cond_type = 0, 
        __pthread_cond_magic = 17238
      }, 
      __pthread_cond_data = 0
    }, 
    m_psi = 0x0
  }, 
  c_rli = 0x940cf938, 
  curr_group_exec_parts = {
    buffer = 0x9b2d7f50 "\320\001)\233", 
    elements = 1, 
    max_element = 4, 
    alloc_increment = 1, 
    size_of_element = 8
  }, 
  curr_group_seen_begin = true, 
  id = 8, 
  last_group_done_index = 2013, 
  wq_empty_waits = 193767, 
  events_done = 14222176, 
  groups_done = 3340409, 
  curr_jobs = 0, 
  usage_partition = 1, 
  end_group_sets_max_dbs = false, 
  relay_log_change_notified = false, 
  checkpoint_notified = true, 
  master_log_change_notified = true, 
  bitmap_shifted = 0, 
  wq_overrun_cnt = 0, 
  overrun_level = 14746, 
  underrun_level = 1638, 
      jobs_cond = {
    m_cond = {
      __pthread_cond_flags = {
        __pthread_cond_flag = "\000\003\001", 
        __pthread_cond_type = 0, 
        __pthread_cond_magic = 17238
      }, 
      __pthread_cond_data = 0
    }, 
    m_psi = 0x0
  }, 
  c_rli = 0x940cf938, 
  curr_group_exec_parts = {
    buffer = 0x9b2d7f50 "\320\001)\233", 
    elements = 1, 
    max_element = 4, 
    alloc_increment = 1, 
    size_of_element = 8
  }, 
  curr_group_seen_begin = true, 
  id = 8, 
  last_group_done_index = 2013, 
  wq_empty_waits = 193767, 
  events_done = 14222176, 
  groups_done = 3340409, 
  curr_jobs = 0, 
  usage_partition = 1, 
  end_group_sets_max_dbs = false, 
  relay_log_change_notified = false, 
  checkpoint_notified = true, 
  master_log_change_notified = true, 
  bitmap_shifted = 0, 
  wq_overrun_cnt = 0, 
  overrun_level = 14746, 
  underrun_level = 1638, 
---Type <return> to continue, or q <return> to quit---
  excess_cnt = 0, 
  checkpoint_relay_log_name = "./qdbbackup2-relay-bin.000973", '\000' <repeats 482 times>, 
  checkpoint_relay_log_pos = 616173836, 
  checkpoint_master_log_name = "bin.003252", '\000' <repeats 501 times>, 
  checkpoint_master_log_pos = 616173814, 
  group_executed = {
    bitmap = 0x9b25b120, 
    n_bits = 2048, 
    last_word_mask = 0, 
    last_word_ptr = 0x9b25b21c, 
    mutex = 0x0
  }, 
  group_shifted = {
    bitmap = 0x9b25b228, 
    n_bits = 2048, 
    last_word_mask = 0, 
    last_word_ptr = 0x9b25b324, 
    mutex = 0x0
  }, 
  checkpoint_seqno = 1973, 
  running_status = Slave_worker::RUNNING, 
  gaq_index = 2014, 
  master_log_pos = 616887078
}

Revision history for this message

Ovais Tariq (ovais-tariq) wrote on 2014-06-19:

#9

Download full text (3.4 KiB)

So based on the backtrace this is what we have as the position up to which the workers have executed everything:
group_relay_log_name = "./relay-bin.000973", '\000' <repeats 482 times>,
group_relay_log_pos = 616886798,

Looking at the relay log following are the events in the relay log starting at position 616886798:
# at 616886798
#140618 19:31:55 server id 11 end_log_pos 616886824 CRC32 0xca064602 GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'da2d1223-8151-11e3-8e1d-997ca3babb7c:4367700088'/*!*/;
# at 616886846
#140618 19:31:55 server id 11 end_log_pos 616886911 CRC32 0x893a663b Query thread_id=708866417 exec_time=0 error_code=0
SET TIMESTAMP=1403119915/*!*/;
BEGIN
/*!*/;
# at 616886933
#140618 19:31:55 server id 11 end_log_pos 616887078 CRC32 0xb7f1ec9f Query thread_id=708866417 exec_time=0 error_code=0
SET TIMESTAMP=1403119915/*!*/;
UPDATE some_table ...
/*!*/;
# at 616887100
#140618 19:32:05 server id 6 end_log_pos 616887123 CRC32 0xfdd70dd7 Stop
DELIMITER ;
# End of log file

So after the UPDATE there is no COMMIT event, but a STOP event. A STOP event is written when mysqld is being shutdown. The above UPDATE is what the worker thread executed in the transaction that is still open.

So what happened was that while IO thread was writing an event group to the relay log, mysqld was shutdown and the event group was written partially.

When MySQL comes back up again, the log is rotated, and IO thread starts writing from the event group which was partially written. So the next log has the following event group:
#140618 19:31:55 server id 11 end_log_pos 616886824 CRC32 0xca064602 GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'da2d1223-8151-11e3-8e1d-997ca3babb7c:4367700088'/*!*/;
# at 478
#140618 19:31:55 server id 11 end_log_pos 616886911 CRC32 0x893a663b Query thread_id=708866417 exec_time=0 error_code=0
SET TIMESTAMP=1403119915/*!*/;
SET @@session.pseudo_thread_id=708866417/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=224/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 565
#140618 19:31:55 server id 11 end_log_pos 616887078 CRC32 0xb7f1ec9f Query thread_id=708866417 exec_time=0 error_code=0
use `db2`/*!*/;
SET TIMESTAMP=1403119915/*!*/;
UPDATE some_tbl ....
/*!*/;
# at 732
#140618 19:31:55 server id 11 end_log_pos 616887109 CRC32 0x8f5b2f7c Xid = 30416488792
COMMIT/*!*/;

You can see that the "end_log_pos" values are the same for the partial event I showed earlier and this one. It is the same UPDATE transaction that was partially written.

Now comes the interesting part. When the coordinator reads the relay log, it sends the partial event to the worker, since the event is partial hence the worker never commits the transaction and the transaction is kept open. The coordinator reads the next event (which is the full version of the partial event) but the coordinator can...

	Status	Importance	Assigned to	Milestone
MySQL Server	Unknown	Unknown	mysql-bugs #73066
Percona Server moved to https://jira.percona.com/projects/PS	Fix Released	Medium	Sergei Glushchenko	Percona Server moved to https://jira.percona.com/projects/PS 5.6.21-70.0
5.6	Fix Released	Medium	Sergei Glushchenko	Percona Server moved to https://jira.percona.com/projects/PS 5.6.21-70.0

Percona Server moved to https://jira.percona.com/projects/PS

Replication stall with multi-threaded replication

Bug Description

Related branches

Other bug subscribers

Bug attachments

Remote bug watches