mysqld --debug-sync

http://hedengcheng.com/?p=238
https://dev.mysql.com/doc/internals/en/debug-sync-facility.html


mysqld --datadir=/data --basedir=/usr/local/mysql56 --user=mysql --gdb  --debug-sync

SET DEBUG_SYNC= ‘RESET‘;

SET DEBUG_SYNC= ‘before_lock_tables_takes_lock SIGNAL opened WAIT_FOR flushed‘;

mysql> insert into t2 select 1;     卡住

Thread 2 (Thread 0x7f7c2f1fe940 (LWP 16108)):
#0  0x00007f7c989cd280 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000000000abe163 in safe_cond_timedwait (cond=0x17ecd70 <debug_sync_global+48>, mp=0x17ecda8 <debug_sync_global+104>, abstime=0x7f7c2f1fbc00, file=0xee85d8 "/usr/src/mysql-5.6.28/include/mysql/psi/mysql_thread.h", line=1199) at /usr/src/mysql-5.6.28/mysys/thr_mutex.c:278
#2  0x0000000000613ada in inline_mysql_cond_timedwait (that=0x17ecd70 <debug_sync_global+48>, mutex=0x17ecda8 <debug_sync_global+104>, abstime=0x7f7c2f1fbc00, src_file=0xee81c8 "/usr/src/mysql-5.6.28/sql/debug_sync.cc", src_line=1863) at /usr/src/mysql-5.6.28/include/mysql/psi/mysql_thread.h:1199
#3  0x00000000006141aa in debug_sync_execute (thd=0x48f3f20, action=0x4a9d780) at /usr/src/mysql-5.6.28/sql/debug_sync.cc:1861
#4  0x00000000006147ce in debug_sync (thd=0x48f3f20, sync_point_name=0xf12440 "before_lock_tables_takes_lock", name_len=29) at /usr/src/mysql-5.6.28/sql/debug_sync.cc:1973
#5  0x00000000007604bd in lock_tables (thd=0x48f3f20, tables=0x4a948e0, count=0, flags=0) at /usr/src/mysql-5.6.28/sql/sql_base.cc:6046
#6  0x00000000008082be in mysql_select (thd=0x48f3f20, tables=0x4a948e0, wild_num=0, fields=..., conds=0x0, order=0x48f6680, group=0x48f65b8, having=0x0, select_options=2684619520, result=0x4a955c8, unit=0x48f5e70, select_lex=0x48f64b8) at /usr/src/mysql-5.6.28/sql/sql_select.cc:1202
#7  0x000000000080854d in handle_select (thd=0x48f3f20, result=0x4a955c8, setup_tables_done_option=0) at /usr/src/mysql-5.6.28/sql/sql_select.cc:110
#8  0x00000000007cdc4e in execute_sqlcom_select (thd=0x48f3f20, all_tables=0x4a948e0) at /usr/src/mysql-5.6.28/sql/sql_parse.cc:5134
#9  0x00000000007cf185 in mysql_execute_command (thd=0x48f3f20) at /usr/src/mysql-5.6.28/sql/sql_parse.cc:2656
#10 0x00000000007d67c4 in mysql_parse (thd=0x48f3f20, rawbuf=0x4a946c0 "show databases", length=14, parser_state=0x7f7c2f1fd910) at /usr/src/mysql-5.6.28/sql/sql_parse.cc:6386
#11 0x00000000007d83f4 in dispatch_command (command=COM_QUERY, thd=0x48f3f20, packet=0x4a8c251 "show databases", packet_length=14) at /usr/src/mysql-5.6.28/sql/sql_parse.cc:1340
#12 0x00000000007d9c80 in do_command (thd=0x48f3f20) at /usr/src/mysql-5.6.28/sql/sql_parse.cc:1037
#13 0x000000000078e3fb in do_handle_one_connection (thd_arg=0x48f3f20) at /usr/src/mysql-5.6.28/sql/sql_connect.cc:982
#14 0x000000000078e4c1 in handle_one_connection (arg=0x48f3f20) at /usr/src/mysql-5.6.28/sql/sql_connect.cc:898
#15 0x0000000000b11172 in pfs_spawn_thread (arg=0x479cd00) at /usr/src/mysql-5.6.28/storage/perfschema/pfs.cc:1860
#16 0x00007f7c989c883d in start_thread () from /lib64/libpthread.so.0
#17 0x00007f7c97e75fdd in clone () from /lib64/libc.so.6
#18 0x0000000000000000 in ?? ()

sql_base.cc:6046

DEBUG_SYNC(thd, "before_lock_tables_takes_lock");

    if (! (thd->lock= mysql_lock_tables(thd, start, (uint) (ptr - start),
                                        flags)))
      DBUG_RETURN(TRUE);

DEBUG_SYNC(thd, "after_lock_tables_takes_lock");

sql_base.cc:1351

void close_thread_tables(THD *thd)
{
  TABLE *table;
  DBUG_ENTER("close_thread_tables");

#ifdef EXTRA_DEBUG
  DBUG_PRINT("tcache", ("open tables:"));
  for (table= thd->open_tables; table; table= table->next)
    DBUG_PRINT("tcache", ("table: ‘%s‘.‘%s‘ 0x%lx", table->s->db.str,
                          table->s->table_name.str, (long) table));
#endif

#if defined(ENABLED_DEBUG_SYNC)
  /* debug_sync may not be initialized for some slave threads */
  if (thd->debug_sync_control)
    DEBUG_SYNC(thd, "before_close_thread_tables");
#endif

  DBUG_ASSERT(thd->transaction.stmt.is_empty() || thd->in_sub_stmt ||
              (thd->state_flags & Open_tables_state::BACKUPS_AVAIL));

  /* Detach MERGE children after every statement. Even under LOCK TABLES. */
  for (table= thd->open_tables; table; table= table->next)
  {
    /* Table might be in use by some outer statement. */
    DBUG_PRINT("tcache", ("table: ‘%s‘  query_id: %lu",
                          table->s->table_name.str, (ulong) table->query_id));
    if (thd->locked_tables_mode <= LTM_LOCK_TABLES ||
        table->query_id == thd->query_id)
    {
      DBUG_ASSERT(table->file);
      table->file->extra(HA_EXTRA_DETACH_CHILDREN);
    }
  }

mysql> SET DEBUG_SYNC= ‘now WAIT_FOR opened‘;
Query OK, 0 rows affected (0.00 sec)

mysql> SET DEBUG_SYNC= ‘after_flush_unlock SIGNAL flushed‘;
Query OK, 0 rows affected (0.01 sec)

mysql> FLUSH TABLE t1;
Query OK, 0 rows affected (0.20 sec)

mysql> insert into t2 select 1;
Query OK, 1 row affected (1 min 25.42 sec)
Records: 1  Duplicates: 0  Warnings: 0