Exploring Metadata Locks with gdb - How One Can Use This?

In the previous post in this series I've concluded that metadata locks are acquired in "batches" and the function that implements this is called MDL_context::acquire_locks. Let's check quickly what it does to confirm where wait for metadata lock really happens. We need this to proceed finally from studying what locks are set and when (this is a long and complicated topic to spend time on out of general interest) to more practical topic: how to find the session that holds the blocking metadata lock in MySQL versions before 5.7.x.

I'll continue to use Percona Server 5.6.27 for now, just because I have it installed and have a source code at hand. So, MDL_context class is defined in sql/mdl.h file as follows:

/**
  Context of the owner of metadata locks. I.e. each server
  connection has such a context.
*/

class MDL_context
{
public:
  typedef I_P_List<MDL_ticket,
                   I_P_List_adapter<MDL_ticket,
                                    &MDL_ticket::next_in_context,
                                    &MDL_ticket::prev_in_context> >
          Ticket_list;

  typedef Ticket_list::Iterator Ticket_iterator;

  MDL_context();
...
  bool try_acquire_lock(MDL_request *mdl_request);
  bool acquire_lock(MDL_request *mdl_request, ulong lock_wait_timeout);
  bool acquire_locks(MDL_request_list *requests, ulong lock_wait_timeout);...
  unsigned long get_lock_owner(MDL_key *mdl_key);...
private:
  THD *get_thd() const { return m_owner->get_thd(); }...
};

I've highlighted some of the functions that we may use later. Now, this is how MDL_context::aquire_locks() implementation looks like in mdl.cc:

/**
  Acquire exclusive locks. There must be no granted locks in the
  context.

  This is a replacement of lock_table_names(). It is used in
  RENAME, DROP and other DDL SQL statements.

  @param  mdl_requests  List of requests for locks to be acquired.

  @param lock_wait_timeout  Seconds to wait before timeout.

  @note The list of requests should not contain non-exclusive lock requests.
        There should not be any acquired locks in the context.

  @note Assumes that one already owns scoped intention exclusive lock.

  @retval FALSE  Success
  @retval TRUE   Failure
*/

bool MDL_context::acquire_locks(MDL_request_list *mdl_requests,
                                ulong lock_wait_timeout)
{
...
  for (p_req= sort_buf; p_req < sort_buf + req_count; p_req++)
  {
    if (acquire_lock(*p_req, lock_wait_timeout))
      goto err;
  }
  my_free(sort_buf);
  return FALSE;

err:
  /*
    Release locks we have managed to acquire so far.
    Use rollback_to_savepoint() since there may be duplicate
    requests that got assigned the same ticket.
  */
  rollback_to_savepoint(mdl_svp);
  /* Reset lock requests back to its initial state. */
...
  my_free(sort_buf);
  return TRUE;
}

Comments make me think that for some metadata locks we may see some different function called, but let's deal with exclusive ones for now, those that can be blocked. Now, the MDL_context::aquire_lock() we eventually call for each request:

/**
  Acquire one lock with waiting for conflicting locks to go away if needed.

  @param mdl_request [in/out] Lock request object for lock to be acquired

  @param lock_wait_timeout [in] Seconds to wait before timeout.

  @retval  FALSE   Success. MDL_request::ticket points to the ticket
                   for the lock.
  @retval  TRUE    Failure (Out of resources or waiting is aborted),
*/

bool
MDL_context::acquire_lock(MDL_request *mdl_request, ulong lock_wait_timeout)
{
  MDL_lock *lock;
  MDL_ticket *ticket= NULL;
  struct timespec abs_timeout;
  MDL_wait::enum_wait_status wait_status;
...
  /*
    Our attempt to acquire lock without waiting has failed.
    As a result of this attempt we got MDL_ticket with m_lock
    member pointing to the corresponding MDL_lock object which
    has MDL_lock::m_rwlock write-locked.
  */
  lock= ticket->m_lock;

  lock->m_waiting.add_ticket(ticket);

  /*
    Once we added a pending ticket to the waiting queue,
    we must ensure that our wait slot is empty, so
    that our lock request can be scheduled. Do that in the
    critical section formed by the acquired write lock on MDL_lock.
  */
  m_wait.reset_status();

  /*
    Don't break conflicting locks if timeout is 0 as 0 is used
    To check if there is any conflicting locks...
  */
  if (lock->needs_notification(ticket) && lock_wait_timeout)
    lock->notify_conflicting_locks(this);

  mysql_prlock_unlock(&lock->m_rwlock);

  will_wait_for(ticket);

  /* There is a shared or exclusive lock on the object. */
  DEBUG_SYNC(get_thd(), "mdl_acquire_lock_wait");

  find_deadlock();

  struct timespec abs_shortwait;
  set_timespec(abs_shortwait, 1);
  wait_status= MDL_wait::EMPTY;

  while (cmp_timespec(abs_shortwait, abs_timeout) <= 0)
  {
    /* abs_timeout is far away. Wait a short while and notify locks. */
    wait_status= m_wait.timed_wait(m_owner, &abs_shortwait, FALSE,
                                   mdl_request->key.get_wait_state_name());

    if (wait_status != MDL_wait::EMPTY)
      break;
    /* Check if the client is gone while we were waiting. */
    if (! m_owner->is_connected())
    {
      /*
       * The client is disconnected. Don't wait forever:
       * assume it's the same as a wait timeout, this
       * ensures all error handling is correct.
       */
      wait_status= MDL_wait::TIMEOUT;
     break;
    }

    mysql_prlock_wrlock(&lock->m_rwlock);
    if (lock->needs_notification(ticket))
      lock->notify_conflicting_locks(this);
    mysql_prlock_unlock(&lock->m_rwlock);
    set_timespec(abs_shortwait, 1);
  }
...

So, here we check if our request is deadlocking and then we wait. It's clear that any session that is hanging while waiting for the metadata lock will have MDL_context::aquire_lock() in the backtrace.

To check this assumption let me set up a usual test with SELECT * FROM t1 executed in active transaction and TRUNCATE TABLE blocked. This is how it may look like in the SHOW PROCESSLIST:

mysql> show processlist;
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
| Id | User | Host      | db   | Command | Time | State                           | Info              | Rows_sent | Rows_examined |
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
|  2 | root | localhost | test | Query   |  121 | Waiting for table metadata lock | truncate table t1 |         0 |             0 |
|  3 | root | localhost | test | Sleep   |    2 |                                 | NULL              |         1 |             0 |
|  4 | root | localhost | test | Query   |    0 | init                            | show processlist  |         0 |             0 |
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
3 rows in set (0.00 sec)
In general (and in this case) we may NOT be able to find a thread that is executing some statement for longer than out blocked session is waiting for the metadata lock. So, which one is the blocking one?

Let's try to find a thread that mentions  MDL_context::aquire_lock() in the backtrace:

[root@centos percona-server]# gdb -p `pidof mysqld` -ex "set pagination 0" -ex "thread apply all bt" -batch 2>/dev/null | grep 'MDL_context::acquire_lock'
#3  0x000000000064a74b in MDL_context::acquire_lock (this=0x7fc005ff5140, mdl_request=0x7fc00614e488, lock_wait_timeout=) at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:2380
#4  0x000000000064ae1b in MDL_context::acquire_locks (this=0x7fc005ff5140, mdl_requests=) at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:2500
[root@centos percona-server]#
Note that I've executed the command as root, because mysqld process is owned by root in this case.

So, we see exactly one backtrace with this call:

MDL_context::acquire_lock (this=0x7fc005ff5140, mdl_request=0x7fc00614e488, lock_wait_timeout=)

and from the code review we know that 0x7fc00614e488 is of type MDL_request *. We also know that 0x7fc005ff5140 is of type MDL_context * (this pointer in the method of that class). Now we can attach gdb to the mysqld running and try to see what we can do with that pointers:

[root@centos percona-server]# gdb -p `pidof mysqld`
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-83.el6)
...
(gdb) set $pmdlr=(MDL_request *)0x7fc00614e488
(gdb) p $pmdlr
$1 = (MDL_request *) 0x7fc00614e488
(gdb) p $pmdlr->key
$2 = {m_length = 9, m_db_name_length = 4,
  m_ptr = "\003test\000t1", '\000' <repeats 378 times>,
  static m_namespace_to_wait_state_name = {{m_key = 102,
      m_name = 0xb9eb8c "Waiting for global read lock", m_flags = 0}, {
      m_key = 103, m_name = 0xb9eba9 "Waiting for backup lock", m_flags = 0}, {
      m_key = 104, m_name = 0xb9ed68 "Waiting for schema metadata lock",
      m_flags = 0}, {m_key = 105,
      m_name = 0xb9ed90 "Waiting for table metadata lock", m_flags = 0}, {
      m_key = 106,
      m_name = 0xb9edb0 "Waiting for stored function metadata lock",
      m_flags = 0}, {m_key = 107,
      m_name = 0xb9ede0 "Waiting for stored procedure metadata lock",
      m_flags = 0}, {m_key = 108,
      m_name = 0xb9ee10 "Waiting for trigger metadata lock", m_flags = 0}, {
      m_key = 109, m_name = 0xb9ee38 "Waiting for event metadata lock",
      m_flags = 0}, {m_key = 110, m_name = 0xb9ebc1 "Waiting for commit lock",
      m_flags = 0}, {m_key = 79, m_name = 0xb9295a "User lock", m_flags = 0}, {
      m_key = 111, m_name = 0xb9ebd9 "Waiting for binlog lock", m_flags = 0}}}
(gdb) p &($pmdlr->key)
$3 = (MDL_key *) 0x7fc00614e4a8

So, we can get a pointer to the MDL_key. Now, in MDL_context class we had seen the following method:

  unsigned long get_lock_owner(MDL_key *mdl_key);

that returns the id of the owning thread, and lucky we are, we have a pointer to MDL_context, so we can refer to this function and call it if needed:

(gdb) set $pmdlc=(MDL_context *)0x7fc005ff5140
(gdb) p $pmdlc
$4 = (MDL_context *) 0x7fc005ff5140
(gdb) p $pmdlc->get_lock_owner(&($pmdlr->key))
$5 = 3

Now, what's that value printed, 3? It's the id of thread in the SHOW PROCESSLIST that holds the blocking metadata lock. So, we quit from gdb:

(gdb) q
A debugging session is active.

        Inferior 1 [process 3003] will be detached.

Quit anyway? (y or n) y
Detaching from program: /usr/sbin/mysqld, process 3003

and then we know what thread to kill to release the blocking lock and let TRUNCATE to proceed:

mysql> show processlist;
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
| Id | User | Host      | db   | Command | Time | State                           | Info              | Rows_sent | Rows_examined |
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
|  2 | root | localhost | test | Query   | 1291 | Waiting for table metadata lock | truncate table t1 |         0 |             0 |
|  3 | root | localhost | test | Sleep   | 1172 |                                 | NULL              |         1 |             0 |
|  4 | root | localhost | test | Query   |    0 | init                            | show processlist  |         0 |             0 |
+----+------+-----------+------+---------+------+---------------------------------+-------------------+-----------+---------------+
3 rows in set (0.00 sec)

mysql> kill 3;
Query OK, 0 rows affected (0.05 sec)

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+-----------+---------------+
| Id | User | Host      | db   | Command | Time | State | Info             | Rows_sent | Rows_examined |
+----+------+-----------+------+---------+------+-------+------------------+-----------+---------------+
|  2 | root | localhost | test | Sleep   | 1305 |       | NULL             |         0 |             0 |
|  4 | root | localhost | test | Query   |    0 | init  | show processlist |         0 |             0 |
+----+------+-----------+------+---------+------+-------+------------------+-----------+---------------+
2 rows in set (0.00 sec)

So, from now on you know how to find out in MySQL 5.6 the blocking session/thread for any session that is waiting on metadata with just gdb and some grep.

This is not the only way, you can get the same result from different functions in different MDL-related classes. Your findings may depend on what part of the code you traced or read first, but essentially that's it: you can easily find a blocking thread for any waiting MDL lock request, using just a couple of gdb commands! No need to kill them one by one in a hope.

For any MySQL DBA gdb can be the tool useful in their routine work, NOT only while studying core dumps.

In the following blog posts in this series I'll get back to studying source code and will try to work with MySQL 5.7 in a similar way. Stay tuned!

Exploring Metadata Locks with gdb - Double Checking the Initial Results

Some results in my initial post in this series led me to questions that I'll try to answer here. First of all, I noted that SELECT from a single table ended up with just one metadata lock request:

(gdb) b MDL_request::init
Breakpoint 1 at 0x648f13: file /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc, line 1266.
Breakpoint 2 at 0x648e70: file /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc, line 1245.
warning: Multiple breakpoints were set.
Use the "delete" command to delete unwanted breakpoints.
(gdb) c
Continuing.
[Switching to Thread 0x7ff224c9f700 (LWP 2017)]

Breakpoint 2, MDL_request::init (this=0x7ff1fbe425a8,
    mdl_namespace=MDL_key::TABLE, db_arg=0x7ff1fbe421c8 "test",
    name_arg=0x7ff1fbe421d0 "t1", mdl_type_arg=MDL_SHARED_READ,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {

MDL_SHARED_READ lock on the table is expected, we read it after all. Let's check with backtrace where this request happens:






(gdb) bt
#0  MDL_request::init (this=0x7ff1fbe425a8, mdl_namespace=MDL_key::TABLE,
    db_arg=0x7ff1fbe421c8 "test", name_arg=0x7ff1fbe421d0 "t1",
    mdl_type_arg=MDL_SHARED_READ, mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x00000000006d3033 in st_select_lex::add_table_to_list (this=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:7479
#2  0x000000000077eb6d in MYSQLparse (YYTHD=0x7ff1fbb65000)
    at /var/lib/jenkins/jobs/percona-server-5.6-source-tarballs/workspace/sql/sql_yacc.yy:10888
#3  0x00000000006decef in parse_sql (thd=0x7ff1fbb65000,
    parser_state=0x7ff224c9e130, creation_ctx=0x0)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:9005
#4  0x00000000006df1b1 in mysql_parse (thd=0x7ff1fbb65000, rawbuf=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:6878
#5  0x00000000006e0d1f in dispatch_command (command=<value optimized out>,
    thd=0x7ff1fbb65000, packet=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:1442
#6  0x00000000006ad692 in do_handle_one_connection (thd_arg=Unhandled dwarf expression opcode 0xf3
)
...

So, it happens as soon as we noted a table to read from while parsing the query text. What surprised me initially is no other MDL lock requests, nothing at schema level, for example. I expected that metadata locks should prevent dropping the schema when I read from some table there, but had not seen the schema-level lock for this.

To get more details on this and try to make sure I do not miss anything by studying a corner case, I've added a row to the table and then tried to do the same SELECT in explicit transaction, and (after SELECT completed, but transaction remained active) I tried to DROP DATABASE from the second session while this transaction was still active. (This test will also let us understand what metadata locks are requested for DROP DATABASE, by the way.) I've got the following in gdb:

[New Thread 0x7ff224c5e700 (LWP 2048)]
[Switching to Thread 0x7ff224c5e700 (LWP 2048)]

Breakpoint 2, MDL_request::init (this=0x7ff224c5a040,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff224c5a040, mdl_namespace=MDL_key::GLOBAL,
    db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x00000000007d1ed7 in lock_schema_name (thd=0x7ff1fbbb5000,
    db=0x7ff1e581d0b0 "test")
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/lock.cc:794
#2  0x00000000006b03d4 in mysql_rm_db (thd=0x7ff1fbbb5000,
    db=0x7ff1e581d0b0 "test", if_exists=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_db.cc:787
...
---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a1f0,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a3a0,
    mdl_namespace=MDL_key::SCHEMA, db_arg=0x7ff1e581d0b0 "test",
    name_arg=0xba2ae4 "", mdl_type_arg=MDL_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff224c5a3a0, mdl_namespace=MDL_key::SCHEMA,
    db_arg=0x7ff1e581d0b0 "test", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_EXCLUSIVE, mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x00000000007d1fb2 in lock_schema_name (thd=0x7ff1fbbb5000,
    db=0x7ff1e581d0b0 "test")
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/lock.cc:801
#2  0x00000000006b03d4 in mysql_rm_db (thd=0x7ff1fbbb5000,
    db=0x7ff1e581d0b0 "test", if_exists=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_db.cc:787
#3  0x00000000006daaa2 in mysql_execute_command (thd=0x7ff1fbbb5000)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:4371
#4  0x00000000006df518 in mysql_parse (thd=0x7ff1fbbb5000, rawbuf=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_parse.cc:6972
...
---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff1e58313b0,
    mdl_namespace=MDL_key::TABLE, db_arg=0x7ff1e5831570 "test",
    name_arg=0x7ff1e5831575 "t1", mdl_type_arg=MDL_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff1e58313b0, mdl_namespace=MDL_key::TABLE,
    db_arg=0x7ff1e5831570 "test", name_arg=0x7ff1e5831575 "t1",
    mdl_type_arg=MDL_EXCLUSIVE, mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x00000000006b0857 in find_db_tables_and_rm_known_files (
    thd=0x7ff1fbbb5000, db=0x7ff1e581d0b0 "test", if_exists=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_db.cc:1108
#2  mysql_rm_db (thd=0x7ff1fbbb5000, db=0x7ff1e581d0b0 "test", if_exists=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_db.cc:812
...

Now it's clear what happens, eventually we have to drop the table while dropping the schema, and here we surely hit a blocking metadata lock that SELECT set! Let's continue:

---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff1e581ece0,
    mdl_namespace=MDL_key::SCHEMA, db_arg=0x7ff1e5831570 "test",
    name_arg=0xba2ae4 "", mdl_type_arg=MDL_INTENTION_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff1e581ece0, mdl_namespace=MDL_key::SCHEMA,
    db_arg=0x7ff1e5831570 "test", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x000000000068da14 in lock_table_names (thd=0x7ff1fbbb5000,
    tables_start=0x7ff1e5831010, tables_end=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:5033
#2  0x00000000006b05df in mysql_rm_db (thd=0x7ff1fbbb5000,
    db=0x7ff1e581d0b0 "test", if_exists=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_db.cc:834
...

So, while our request for MDL_EXCLUSIVE lock for the table surely could not be satisfied, server continued with some further requests:

---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a1f0,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a3a0,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

and only at this stage it hanged (waiting for the transaction where SELECT happened to complete). As soon as I committed there:

Breakpoint 2, MDL_request::init (this=0x7ff224c5a260,
    mdl_namespace=MDL_key::TABLE, db_arg=0xb925ef "mysql",
    name_arg=0xb94906 "proc", mdl_type_arg=MDL_SHARED_READ,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a360,
    mdl_namespace=MDL_key::TABLE, db_arg=0xb925ef "mysql",
    name_arg=0xb94906 "proc", mdl_type_arg=MDL_SHARED_WRITE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {



So, we tried to read and then maybe change the mysql.proc table (to drop procedures created in this database, honestly I was not sure if there was any one there at the moment). Next:

(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c59cb0,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c599c0,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5a250,
    mdl_namespace=MDL_key::TABLE, db_arg=0xb925ef "mysql",
    name_arg=0xc111a8 "event", mdl_type_arg=MDL_SHARED_WRITE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.



That is, some lock requests and we try to delete events in this database from mysql.event table obviously. Let's continue:

Breakpoint 2, MDL_request::init (this=0x7ff224c59900,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff224c59900, mdl_namespace=MDL_key::GLOBAL,
    db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x000000000068c13a in open_table (thd=0x7ff1fbbb5000,
    table_list=0x7ff224c59eb0, ot_ctx=0x7ff224c59c10)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:2895
#2  0x0000000000694585 in open_and_process_table (thd=0x7ff1fbbb5000,
    start=0x7ff224c59e48, counter=0x7ff224c59e50, flags=2048,
    prelocking_strategy=0x7ff224c59ea0)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:4797
#3  open_tables (thd=0x7ff1fbbb5000, start=0x7ff224c59e48,
    counter=0x7ff224c59e50, flags=2048, prelocking_strategy=0x7ff224c59ea0)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:5304
#4  0x0000000000694d74 in open_and_lock_tables (thd=0x7ff1fbbb5000,
    tables=0x7ff224c59eb0, derived=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:5960

#5  0x000000000085039d in open_and_lock_tables (thd=0x7ff1fbbb5000, lock_type=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.h:477
#6  Event_db_repository::open_event_table (thd=0x7ff1fbbb5000, lock_type=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/event_db_repository.cc:619
#7  0x0000000000850bfc in Event_db_repository::drop_schema_events (this=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/event_db_repository.cc:1011---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c59610,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) bt
#0  MDL_request::init (this=0x7ff224c59610, mdl_namespace=MDL_key::BACKUP,
    db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
#1  0x00000000007d1dfe in Global_backup_lock::acquire_protection (
    this=0x7ff1fbbb6a08, thd=0x7ff1fbbb5000, duration=MDL_STATEMENT,
    lock_wait_timeout=31536000)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/lock.cc:1225
#2  0x000000000068ce20 in open_table (thd=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:3258
#3  0x0000000000694585 in open_and_process_table (thd=0x7ff1fbbb5000,
    start=0x7ff224c59e48, counter=0x7ff224c59e50, flags=2048,
    prelocking_strategy=0x7ff224c59ea0)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:4797
#4  open_tables (thd=0x7ff1fbbb5000, start=0x7ff224c59e48,
    counter=0x7ff224c59e50, flags=2048, prelocking_strategy=0x7ff224c59ea0)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:5304
#5  0x0000000000694d74 in open_and_lock_tables (thd=0x7ff1fbbb5000,
    tables=0x7ff224c59eb0, derived=Unhandled dwarf expression opcode 0xf3
)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/sql_base.cc:5960
...
---Type <return> to continue, or q <return> to quit---q
 at /uQuit
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c5ab00,
    mdl_namespace=MDL_key::BINLOG, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.
We ended up with writing to the binary log and DROP DATABASE was completed.

Let's summarize this experience. First of all, it seems in current implementation there is no need to set metadata locks at schema level to prevent dropping the database we read from with SELECT - table level metadata lock will eventually block the DROP DATABASE request. If we have many tables in the database this may happen not at the very first one, so we can drop some tables before getting blocked. This is something to study later. I'd really prefer DROP DATABASE to be atomic and do not even start if it can not complete at the moment. See Bug #79610 also.

We see table-level metadata lock requests for mysql.proc and mysql.events tables when DROP DATABASE is executed. This is expected and reasonable - we can NOT drop the database (schema) if there are some stored functions, procedures or events are defined there that are used.

We had also noted that even if some metadata lock is requested but can not be obtained, processing may continue for some time until stopped, and then processing resumes when we finally get the required metadata lock.

This is the code to study in sql/lock.cc:

 760 /**
 761   Obtain an exclusive metadata lock on a schema name.
 762
 763   @param thd         Thread handle.
 764   @param db          The database name.
 765
 766   This function cannot be called while holding LOCK_open mutex.
 767   To avoid deadlocks, we do not try to obtain exclusive metadata
 768   locks in LOCK TABLES mode, since in this mode there may be
 769   other metadata locks already taken by the current connection,
 770   and we must not wait for MDL locks while holding locks.
 771
 772   @retval FALSE  Success.
 773   @retval TRUE   Failure: we're in LOCK TABLES mode, or out of memory,
 774                  or this connection was killed.
 775 */
 776
 777 bool lock_schema_name(THD *thd, const char *db)
 778 {
 779   MDL_request_list mdl_requests;
 780   MDL_request global_request;
 781   MDL_request backup_request;
 782   MDL_request mdl_request;
 783
 784   if (thd->locked_tables_mode)
 785   {
 786     my_message(ER_LOCK_OR_ACTIVE_TRANSACTION,
 787                ER(ER_LOCK_OR_ACTIVE_TRANSACTION), MYF(0));
 788     return TRUE;
 789   }
 790
 791   if (thd->global_read_lock.can_acquire_protection())
 792     return TRUE;
 793   global_request.init(MDL_key::GLOBAL, "", "", MDL_INTENTION_EXCLUSIVE,
 794                       MDL_STATEMENT);
 795
 796   if (thd->backup_tables_lock.abort_if_acquired())
 797     return true;
 798   thd->backup_tables_lock.init_protection_request(&backup_request,
 799                                                   MDL_STATEMENT);
 800
 801   mdl_request.init(MDL_key::SCHEMA, db, "", MDL_EXCLUSIVE, MDL_TRANSACTION)     ;
 802
 803   mdl_requests.push_front(&mdl_request);
 804   mdl_requests.push_front(&backup_request);
 805   mdl_requests.push_front(&global_request);
 806
 807   if (thd->mdl_context.acquire_locks(&mdl_requests,
 808                                      thd->variables.lock_wait_timeout))
 809     return TRUE;
 810
 811   DEBUG_SYNC(thd, "after_wait_locked_schema_name");
 812   return FALSE;

From this code we see that actually we acquire metadata locks in batches(!). This explaines why we had not stopped at our first "blocked" request immediately, and complicates tracing in gdb. We also see that we have some mdl_context object in THD structure, and we may use this later to study pending requests per thread. One day I'll start setting breakpoints at MDLcontext::acquire_locks as well.

It's also more or less clear what MDL_key::GLOBAL namespace is used for - this is a metadata lock requested by FLUSH TABLES WITH READ LOCK global lock, and thus we check it for any "write" operation, even before we try to do it. If I execute FLUSH TABLES WITH READ LOCK, I get the following in my gdb session with a breakpoint set:

[Switching to Thread 0x7ff224c9f700 (LWP 2017)]

Breakpoint 2, MDL_request::init (this=0x7ff224c9c9f0,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_SHARED, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7ff224c9c9f0,
    mdl_namespace=MDL_key::COMMIT, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_SHARED, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

and then it's completed. Now, on UNLOCK TABLES nothing happens at MDL level.

The last topic I'd like to discuss in this post are metadata locks with namespace defined like this: mdl_namespace=MDL_key::BACKUP, "backup locks". Manual for 5.7 does not mention them, but they still exist in the code even there:

[openxs@centos ~]$ grep -rn MDL_key::BACKUP ~/git/mysql-server/*
[openxs@centos ~]$ echo $?
1
In MySQL we see the following in mdl.h:

  enum enum_mdl_namespace { GLOBAL=0,
                            TABLESPACE,
                            SCHEMA,
                            TABLE,
                            FUNCTION,
                            PROCEDURE,
                            TRIGGER,
                            EVENT,
                            COMMIT,
                            USER_LEVEL_LOCK,
                            LOCKING_SERVICE,
                            /* This should be the last ! */
                            NAMESPACE_END };

So, backup locks is the unique feature of Percona Server, explained in the manual. It is implemented with MDL locks. As soon as we run LOCK TABLES FOR BACKUP, we see in gdb session:

Breakpoint 2, MDL_request::init (this=0x7ff224c9ca90,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_SHARED, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {

This reminded me about the difference Percona Server can make, so I'll try to re-check my results with MySQL 5.6 next time as well. Stay tuned!

Exploring Metadata Locks with gdb - First Steps

Metadata locks are used in MySQL since version 5.5.3 and are available in GA MySQL versions for 6 years already. Still they are far from clearly documented (even less their implementation is documented in details - try to find anything about metadata locks in current MySQL Internals manual) and often causes "unexpected" problems for users.

Only since MySQL 5.7.3 (and only for a few months in GA releases since 5.7.9) we have an easy, official and documented way to check metadata locks set by different sessions using the metadata_locks table in  Performance Schema. I've already explained how to use it in my blog post at Percona's blog. Still, most of MySQL servers in production are NOT 5.7.x today, so majority of MySQL users have to wonder what metadata locks are set and when, desperately killing old sessions in a hope to blindly find one holding the blocking metadata lock. In some cases the blocking session is easy to identify from SHOW PROCESSLIST or SHOW ENGINE INNODB STATUS, but if we have several long running sessions that executes nothing at the moment (or something that does not refer to the table we can not TRUNCATE or ALTER, and there are no table level locks mentioned in INNODB STATUS to help us as a hint), there is not so much one can do...

I was not ready to give up easily on this and just suggest to check/kill longest active transactions/sessions one by one, check for running mysqldump --single-transaction etc every time somebody asks why TRUNCATE TABLE is blocked on MySQL 5.5.x or 5.6.x. Based on my recent preferences of using gdb for every task that does not have official "SQL way" to complete, I decided last year to spend some time checking the source code (in mdl.cc and mdl.h) and try to use gdb to find out what metadata locks are set/requested and in what order when specific SQL statements are executed, how to "see" all the metadata locks if you are NOT on MySQL 5.7.x and, most importantly for real life cases, how to find out what exact session is holding the blocking metadata lock. It seems I've collected enough logs of debugging sessions and spent enough time reading the code to start sharing my findings that may become useful for wider audience. Hence this my first post in the series I plan to devote to metadata lock studies.

In this post I'll concentrate on how to check what metadata locks are requested and in what order. For this, we should concentrate on MDL_request class (yes, metadata locks are implemented in C++, with classes, methods, overloaded operators, friend classes etc), see mdl.h:




/**
  A pending metadata lock request.

  A lock request and a granted metadata lock are represented by
  different classes because they have different allocation
  sites and hence different lifetimes. The allocation of lock requests is
  controlled from outside of the MDL subsystem, while allocation of granted
  locks (tickets) is controlled within the MDL subsystem.

  MDL_request is a C structure, you don't need to call a constructor
  or destructor for it.
*/

class MDL_request
{
public:
  /** Type of metadata lock. */
  enum          enum_mdl_type type;  /** Duration for requested lock. */
  enum enum_mdl_duration duration;
  /**
    Pointers for participating in the list of lock requests for this context.
  */
  MDL_request *next_in_list;
  MDL_request **prev_in_list;
  /**
    Pointer to the lock ticket object for this lock request.
    Valid only if this lock request is satisfied.
  */
  MDL_ticket *ticket;
  /** A lock is requested based on a fully qualified name and type. */
  MDL_key key;
public:
  static void *operator new(size_t size, MEM_ROOT *mem_root) throw ()
  { return alloc_root(mem_root, size); }
  static void operator delete(void *ptr, MEM_ROOT *mem_root) {}

  void init(MDL_key::enum_mdl_namespace namespace_arg,
            const char *db_arg, const char *name_arg,
            enum_mdl_type mdl_type_arg,
            enum_mdl_duration mdl_duration_arg);  void init(const MDL_key *key_arg, enum_mdl_type mdl_type_arg,
            enum_mdl_duration mdl_duration_arg);
...
};

I've highlighted class members that will be important for further checks. Metadata lock types are defined in mdl.h as follows (most comments were removed, read them in the source code!):

enum enum_mdl_type {
  /*
    An intention exclusive metadata lock. Used only for scoped locks.
    Owner of this type of lock can acquire upgradable exclusive locks on
    individual objects.
    Compatible with other IX locks, but is incompatible with scoped S and
    X locks.
  */
  MDL_INTENTION_EXCLUSIVE= 0,
  MDL_SHARED,
  MDL_SHARED_HIGH_PRIO,
  MDL_SHARED_READ,
  MDL_SHARED_WRITE,
  MDL_SHARED_UPGRADABLE,
  MDL_SHARED_NO_WRITE,
  /*
    An exclusive metadata lock.
    A connection holding this lock can modify both table's metadata and data.
    No other type of metadata lock can be granted while this lock is held.
    To be used for CREATE/DROP/RENAME TABLE statements and for execution of
    certain phases of other DDL statements.
  */
  MDL_EXCLUSIVE,
  /* This should be the last !!! */
  MDL_TYPE_END};

Metadata locks can be hold for different duration (till the end of statement, till the end of transactions -most of them), defined as follows:

enum enum_mdl_duration {
  /**
    Locks with statement duration are automatically released at the end
    of statement or transaction.
  */
  MDL_STATEMENT= 0,
  /**
    Locks with transaction duration are automatically released at the end
    of transaction.
  */
  MDL_TRANSACTION,
  /**
    Locks with explicit duration survive the end of statement and transaction.
    They have to be released explicitly by calling MDL_context::release_lock().
  */
  MDL_EXPLICIT,
  /* This should be the last ! */
  MDL_DURATION_END };

With this in mind, we are almost ready to start with gdb, the idea is to set breakpoint on MDL_request::init and then see what requests are made and in what order. This is how it's defined in mdl.cc:

/**
  Initialize a lock request.

  This is to be used for every lock request.

  Note that initialization and allocation are split into two
  calls. This is to allow flexible memory management of lock
  requests. Normally a lock request is stored in statement memory
  (e.g. is a member of struct TABLE_LIST), but we would also like
  to allow allocation of lock requests in other memory roots,
  for example in the grant subsystem, to lock privilege tables.

  The MDL subsystem does not own or manage memory of lock requests.

  @param  mdl_namespace  Id of namespace of object to be locked
  @param  db             Name of database to which the object belongs
  @param  name           Name of of the object
  @param  mdl_type       The MDL lock type for the request.
*/

void MDL_request::init(MDL_key::enum_mdl_namespace mdl_namespace,
                       const char *db_arg,
                       const char *name_arg,
                       enum_mdl_type mdl_type_arg,
                       enum_mdl_duration mdl_duration_arg)
{
  key.mdl_key_init(mdl_namespace, db_arg, name_arg);
  type= mdl_type_arg;
  duration= mdl_duration_arg;
  ticket= NULL;
}

I've got a lot of "hints" from the above, up to the idea that MDL_keys can probably be created "manually" in gdb (not that it worked well). What we miss in the above is the list of metadata lock namespaces, so let's get back to mdl.h:

class MDL_key
{
public:
#ifdef HAVE_PSI_INTERFACE
  static void init_psi_keys();
#endif

  /**
    Object namespaces.
    Sic: when adding a new member to this enum make sure to
    update m_namespace_to_wait_state_name array in mdl.cc!

    Different types of objects exist in different namespaces
     - TABLE is for tables and views.
     - FUNCTION is for stored functions.
     - PROCEDURE is for stored procedures.
     - TRIGGER is for triggers.
     - EVENT is for event scheduler events
    Note that although there isn't metadata locking on triggers,
    it's necessary to have a separate namespace for them since
    MDL_key is also used outside of the MDL subsystem.
  */
  enum enum_mdl_namespace { GLOBAL=0,
                            BACKUP,
                            SCHEMA,
                            TABLE,
                            FUNCTION,
                            PROCEDURE,
                            TRIGGER,
                            EVENT,
                            COMMIT,
                            USER_LOCK,           /* user level locks. */
                            BINLOG,
                            /* This should be the last ! */
                            NAMESPACE_END };
...

As a side note, I quoted the code and worked with Percona Server 5.6.27, but this should not matter much - these parts of related code in 5.5.x and 5.6.x is more or less similar/same. In 5.7 there were many notable changes. For example, there is no BINLOG namespace, but there is one for the locking service...

So, with all these details in mind, let's try to use the gdb to find out what metadata locks are requested by a couple of simple statements, SELECT and TRUNCATE. I attached gdb to Percona Server 5.6.27 with binary log enabled (and debug symbols installed), and did the following:

[root@centos openxs]# gdb -p `pidof mysqld`
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-83.el6)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
...
Reading symbols from /usr/lib64/mysql/plugin/tokudb_backup.so...Reading symbols from /usr/lib/debug/usr/lib64/mysql/plugin/tokudb_backup.so.debug...done.
done.
Loaded symbols for /usr/lib64/mysql/plugin/tokudb_backup.so
0x00007feb2d145113 in poll () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.166.el6_7.3.x86_64 jemalloc-3.6.0-1.el6.x86_64 keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-42.el6.x86_64 libaio-0.3.107-10.el6.x86_64 libcom_err-1.41.12-22.el6.x86_64 libgcc-4.4.7-16.el6.x86_64 libselinux-2.0.94-5.8.el6.x86_64 libstdc++-4.4.7-16.el6.x86_64 nss-softokn-freebl-3.14.3-23.el6_7.x86_64 numactl-2.0.9-2.el6.x86_64 openssl-1.0.1e-42.el6_7.1.x86_64 zlib-1.2.3-29.el6.x86_64
(gdb) b MDL_request::init
Breakpoint 1 at 0x648f13: file /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc, line 1266.
Breakpoint 2 at 0x648e70: file /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc, line 1245.
warning: Multiple breakpoints were set.
Use the "delete" command to delete unwanted breakpoints.
(gdb) c
Continuing.

Now, in a separate session connected to the test database with simple (InnoDB) table t1, I did:

mysql> select * from t1;

and got the following in the gdb session:






[Switching to Thread 0x7feb2f44a700 (LWP 2319)]

Breakpoint 2, MDL_request::init (this=0x7feb064445a0,
    mdl_namespace=MDL_key::TABLE, db_arg=0x7feb06444760 "test",
    name_arg=0x7feb064441c8 "t1", mdl_type_arg=MDL_SHARED_READ,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.




As soon as I continued, select returned me results. So, we see that SELECT had requested an MDL_SHARED_READ lock till the end of transaction for the table t1 in the database test. This already forces me to ask some followup questions to myself, but let's postpone them (and replies) to some later post. Let's try to do TRUNCATE TABLE:

mysql> truncate table t1;

I've got the following in the gdb session:

Breakpoint 2, MDL_request::init (this=0x7feb06444488,
    mdl_namespace=MDL_key::TABLE, db_arg=0x7feb06444648 "test",
    name_arg=0x7feb064440b0 "t1", mdl_type_arg=MDL_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb06444660,
    mdl_namespace=MDL_key::SCHEMA, db_arg=0x7feb06444648 "test",
    name_arg=0xba2ae4 "", mdl_type_arg=MDL_INTENTION_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f447720,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f4478d0,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb06444808,
    mdl_namespace=MDL_key::SCHEMA, db_arg=0x7feb06444648 "test",
    name_arg=0xba2ae4 "", mdl_type_arg=MDL_INTENTION_EXCLUSIVE,
    mdl_duration_arg=MDL_TRANSACTION)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f4472c0,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f447470,
    mdl_namespace=MDL_key::BACKUP, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f447410,
    mdl_namespace=MDL_key::GLOBAL, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_STATEMENT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f447a60,
    mdl_namespace=MDL_key::COMMIT, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

Breakpoint 2, MDL_request::init (this=0x7feb2f446900,
    mdl_namespace=MDL_key::BINLOG, db_arg=0xba2ae4 "", name_arg=0xba2ae4 "",
    mdl_type_arg=MDL_INTENTION_EXCLUSIVE, mdl_duration_arg=MDL_EXPLICIT)
    at /usr/src/debug/percona-server-5.6.27-76.0/sql/mdl.cc:1245
1245    {
(gdb) c
Continuing.

and only after all these 10 (if I am not mistaking) MDL requests I've got TRUNCATE TABLE executed. Some of these requests are clear, like the very first MDL_EXCLUSIVE for the table we were truncating, or the next MDL_INTENTION_EXCLUSIVE one, for the test schema. Surely we need exclusive access to the table until the end of transaction, and if you read comments in mdl.h carefully it's clear that any active SELECT from the table will block TRUNCATE (this was a big surprise to many old MySQL users now upgrading to version 5.5+). Some other lock requests at the end (the one for COMMIT and BINLOG namespaces) also look reasonable - we do have to commit the TRUNCATE and write it to the binary log. Other requests may be far from clear.

We'll discuss them all eventually, but for now my goal was to show that the method of metadata locks study works (in a same way as it worked for studying InnoDB lock requests), we probably picked up a useful function to set a breakpoint on, to begin with, and that the method shows a very detailed information on what happens with metadata locks even if compared with what MySQL 5.7 officially provides via metadata_locks table in Performance Schema (where many requests can be missed with simple query, for example because they do not "live" for a long time and may be "gone" at the moment when we query the table).

More posts will appear in this series soon. Stay tuned!

New Year Wishes for Providers of MySQL Support Services

Three years ago I shared my wishes for customers of Oracle's MySQL Support Services. There I basically asked them to report any problem that they suspect to be caused by the bug in MySQL software at http://bugs.mysql.com.This year I want to share wishes mostly for myself (and other providers of MySQL Support services).

I have a job of MySQL Support Engineer for almost 10.5 years. I did it in MySQL AB, Sun, Oracle and Percona. I had enough opportunities to see all kinds of approaches, types, kinds and qualities of services. But I still have some dreams in this area that I'd like to see fulfilled for both myself as a provider of service and for customers of such a service:

1. I wish to see MySQL Support mostly done in an asynchronous way, via emails and (when absolutely needed and possible) remote login sessions.
   
   In most cases it's enough for customer to know that she will get a detailed, best possible answer to any her initial question (or problem statement) or any followups question or request in a predictable, well defined time. There is no need for engineer and customer to always work in sync, by talking on phone, chatting or doing a shared screen sessions.
   
   Support should work the same way UNIX operating system does: by sharing all available resources (engineers) among all tasks (support requests) at hand, allocating resources for the task for some small amount of time and then forcing the resource to switch to other task, either when time unit allocated is ended or immediately when we have to wait for something to complete. Surely this mode is beneficial for support providers (because of ability to work for more customers concurrently than they have engineers online), but customers also get clear benefits. They can move on and work on something else until they get email back (or time to get a reply passes), and they may get a reply based on concurrent (but asynchronous) work of several engineers ("fan-out").
   
   
2. At the same time, I wish each support provider to have a well defined SLA (time of getting a guaranteed useful technical reply, either a solution, suggestion or further question) not only for the initial reply (as we can see here and, honestly, almost everywhere), but also for the followups, for each and every customer email.
   
   Ideally both sides should be able to negotiate the date(time) of the next reply (even if it's different from formal official SLA), and then make sure to meet this deadline in 100% of cases. Some steps towards this goal are visible here, but so far no well know Support provider is perfect with followups in time, based on my knowledge.
   
   
3. I wish Support engineers to never be involved in phone conferences with customers without a clearly defined agenda related to MySQL and limited time to be spent on phone (see item 1 above for the reasons).
   
   Sometimes somebody from "services" side should be "there", in case of questions during some long discussion. I think this is a job for customer's TAM (technical assistance manager), Sales Engineer (if the topic is related to purchasing some service or software) or anyone who is paid per hour (like Consultant).
   
   
4. I wish Support engineers, no matter what Support provider they work for, to always report upstream MySQL bugs at http://bugs.mysql.com/ and fork-specific bugs at their public bug trackers, as openly available (public) to all MySQL users.
   
   Some bugs may be repeatable only with customer-specific and confidential data, and some bugs may have security implications. Ideally, Support engineers should always work on a repeatable test case or otherwise well grounded bug report NOT containing customer data. As for security problems, there is always a way to explain in public important details of the possible security attack vector and list versions affected, without giving enough details for "script kiddies" to just blindly copy-paste the test case to get unauthorized access or crash well-managed public MySQL server.
   
   
5. I wish Support engineers to present their work and share their experience in public.
   
   We all should try to share knowledge we have and get while working with customers, not only internally to our colleagues in services or via internal knowledge bases, but also in our own blogs, articles, on public MySQL forums and on MySQL-related conferences.
   
   MySQL Support providers should encourage support engineers to make the results of their work public whenever possible. Not only bugs, but problem solving approaches, code written (if any), experience gained should be shared with MySQL community. This will give us all customers who known more about MySQL and will help us not to re-invent the wheel.

 
To summarize, I wish our customers in the New Year of 2016 to get a simple, but well-defined, responsible, and reliable 24x7 Support service provided by the engineers who are well known to the Community based on their public work on MySQL (via blog posts, bug reports and conference presentations). I wish all MySQL Support Service providers to deliver what they promise (or more) in 100% of cases. I wish myself to work for MySQL Support Provider that cares about my wishes and tries to help me to see my dreams expressed here coming true.

Happy New Year, MySQL Community!

Tricking the Optimizer, or How Checking Bug Reports Help to Solve Real Problems

I've got several useful habits over the years of work in MySQL Support. One of them is to start working on every problem with search for known MySQL bugs related to the problem at hand. I'd like to share one recent case where this habit helped me to get a solution for customer almost instantly.

It was one of rare cases when customer opened a support request with a very clear question and even a test case. The problem was described very precisely, more or less as follows (with table and column names, and data changed for this blog post, surely).

Let's assume we have two tables created like these:

mysql> create table t1(id int auto_increment primary key, c1 varchar(2), c2 varchar(100));Query OK, 0 rows affected (0.27 sec)

mysql> create table t2(id int auto_increment primary key, t1_id int, ctime datetime, cvalue decimal(10,2), key(t1_id, ctime));
Query OK, 0 rows affected (0.15 sec)

So, we have a couple of tables with assumed (even if not formally declared) relation, of a "master-details" kind. We have few rows in the "master" table:

mysql>  insert into t1(c1,c2) values ('UA','Val'),('US','Tom'),('UK','Jerry');
Query OK, 3 rows affected (0.06 sec)
Records: 3  Duplicates: 0  Warnings: 0

and usually several (or very many) rows for each row from "master" in the "details" table:

mysql>  insert into t2(t1_id, ctime, cvalue) values(1,NOW(),10),(1,NOW(),20),(1,NOW(),30),(2,NOW(),10),(2,NOW(),50),(3,NOW(),100);
Query OK, 6 rows affected (0.07 sec)
Records: 6  Duplicates: 0  Warnings: 0

Just to double check, this is what we have to begin with in our tables:

mysql> select * from t1;
+----+------+-------+
| id | c1   | c2    |
+----+------+-------+
|  1 | UA   | Val   |
|  2 | US   | Tom   |
|  3 | UK   | Jerry |
+----+------+-------+
3 rows in set (0.01 sec)

mysql> select * from t2;
+----+-------+---------------------+--------+
| id | t1_id | ctime               | cvalue |
+----+-------+---------------------+--------+
|  1 |     1 | 2015-12-19 17:30:59 |  10.00 |
|  2 |     1 | 2015-12-19 17:30:59 |  20.00 |
|  3 |     1 | 2015-12-19 17:30:59 |  30.00 |
|  4 |     2 | 2015-12-19 17:30:59 |  10.00 |
|  5 |     2 | 2015-12-19 17:30:59 |  50.00 |
|  6 |     3 | 2015-12-19 17:30:59 | 100.00 |
+----+-------+---------------------+--------+
6 rows in set (0.00 sec)

Now, let's try to get many more rows to the "details" table (do not mind the warnings, I did that on the server with binary log enabled and binlog_format = STATEMENT):

mysql>  insert into t2(t1_id, ctime, cvalue) select t1_id, NOW(), cvalue from t2;
Query OK, 6 rows affected, 1 warning (0.04 sec)
Records: 6  Duplicates: 0  Warnings: 1

...

mysql>  insert into t2(t1_id, ctime, cvalue) select t1_id, NOW(), cvalue from t2;
Query OK, 196608 rows affected, 1 warning (25.63 sec)
Records: 196608  Duplicates: 0  Warnings: 1

Now, we have index on both (t1_id, ctime) columns in our t2 table, so queries like the following are executed in a fast and efficient way:

mysql> explain select * from t1 join t2 on t1.id = t2.t1_id where t1.id = 3 and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10'\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: t1
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: const
         rows: 1
        Extra: NULL
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: t2
         type: range
possible_keys: t1_id
          key: t1_id
      key_len: 11
          ref: NULL
         rows: 1
        Extra: Using index condition
2 rows in set (0.01 sec)

mysql> select sql_no_cache * from t1 join t2 on t1.id = t2.t1_id where t1.id = 3 and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10';
+----+------+-------+----+-------+---------------------+--------+
| id | c1   | c2    | id | t1_id | ctime               | cvalue |
+----+------+-------+----+-------+---------------------+--------+
|  3 | UK   | Jerry |  6 |     3 | 2015-12-19 17:30:59 | 100.00 |
+----+------+-------+----+-------+---------------------+--------+
1 row in set (0.00 sec)

Note range access and both columns used for the t1_id index of the t2 table. But what if we specify rows from the "master" (t1) table indirectly? Like this:

mysql> explain select * from t1 join t2 on t1.id = t2.t1_id where t1.c1 = 'UK' and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10'\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: t1
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 4
        Extra: Using where
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: t2
         type: ref
possible_keys: t1_id
          key: t1_id
      key_len: 5
          ref: test.t1.id
         rows: 1
        Extra: Using index condition
2 rows in set (0.00 sec)

mysql> select sql_no_cache * from t1 join t2 on t1.id = t2.t1_id where t1.c1 = 'UK' and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10';
+----+------+-------+----+-------+---------------------+--------+
| id | c1   | c2    | id | t1_id | ctime               | cvalue |
+----+------+-------+----+-------+---------------------+--------+
|  3 | UK   | Jerry |  6 |     3 | 2015-12-19 17:30:59 | 100.00 |
+----+------+-------+----+-------+---------------------+--------+
1 row in set (0.22 sec)

We see that all rows from the "master" table are checked (this is expected, and we have only 3 there anyway), but then we see "ref" access via t1_id index of the "details" (t2) table, and, what's more important, we get the result notably slower than before.

Now the question: Why we are only using the t1_id element of the compound key? This becomes an issue when the leading element of the key is not highly selective.

Another question: Is there any way we can prompt the optimizer to make better use of the index so that when it has evaluated the t1_id values it scans the t2 table using the full depth of the index?

So, this was the customer request I've got. Based on my good habit, I started to search for known optimizer bugs, using the following search string in Google:

site:bugs.mysql.com join range compound index

On the very first page of results I've got a link to the following bug (that was reported by my former colleague Justin Swanhart, probably for some other customer issue, and maybe we even discussed it in the past with him, but still, I just googled for the string above, without any specific details in mind):

• Bug #70002 - "very low performance join - eq_ref and ref access broken for compound indexes"

The bug was declared a "Duplicate" of an older Bug #52030, "WHERE clause with != primary key check slows a query from 0.06 sec to 4 min", and their similarity was far from clear to me. That older bug was reported for 5.1.x and still is "Verified". But there was no need to understand the relation, as the last comment (by Jørgen Løland) in the bug I found stated:

"Thanks for the bug report. This looks like a duplicate of BUG#52030 but with a much less obscure reproducible. I'll link the two bugs together and request that the implementor verifies your test case as well when the issue has been fixed.

A short summary of what happens: MySQL can only do '[eq_]ref' access if the comparison operator is =. That happens to be the case for the first keypart. If MySQL is to make use of the BETWEEN predicate when looking up rows in the index, 'dynamic range' access has to be used. This is the kind that says "Range checked for each record (index 0x...)" in EXPLAIN. 'Dynamic range' is more costly to use than 'ref' because parts of the optimizer has to be invoked for every row in the referred-to table (cust_car in this case). Because of this higher cost, 'dynamic range' will not be chosen by MySQL if 'ref' access is possible. Admittedly, this heuristic sometimes fail like in this bug report."

This gives the answer to the first customer question: we are using only the first column of the compound index there is a heuristic inside optimizer that prefers ref access, and this can be considered a bug/known limitation of current MySQL's optimizer.

Moreover, I've immediately tried to trick optimizer to use dynamic range access path:

mysql> explain select * from t1 join t2 on (t1.id >= t2.t1_id and t1.id <= t2.t1_id) where t1.c1 = 'UK' and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10'\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: t1
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 4
        Extra: Using where
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: t2
         type: ALL
possible_keys: t1_id
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 392850
        Extra: Range checked for each record (index map: 0x2)
2 rows in set (0.00 sec)

mysql> select * from t1 join t2 on (t1.id >= t2.t1_id and t1.id <= t2.t1_id) where t1.c1 = 'UK' and ctime between '2015-12-19 17:30:59' and '2015-12-19 17:31:10';
+----+------+-------+----+-------+---------------------+--------+
| id | c1   | c2    | id | t1_id | ctime               | cvalue |
+----+------+-------+----+-------+---------------------+--------+
|  3 | UK   | Jerry |  6 |     3 | 2015-12-19 17:30:59 | 100.00 |
+----+------+-------+----+-------+---------------------+--------+
1 row in set (0.01 sec)
and, as you can see, got both the desired plan (on MySQL 5.6.27) and fast execution.

So, I've immediately suggested to customer to use the trick of replacing the join condition with the one that prevents "ref" access, and this workaround helped to get fast execution time for the real case as well! This was the answer to the second question: replace '=' in WHERE clause with logically equal condition that bypasses the heuristics and let the entire index to be used for each row selected for the outer table.

Problem was solved for customer in 20 minutes or so after he had opened the support request! This is the power of good habit and the result of using the Community and Oracle engineer's work on maintaining public bugs database! We do not know if the bug will ever be fixed, but we are able to use the results of its discussion to solve problems.

Side note: the same trick applied to older version, without dynamic range optimization, does not give any real benefit. The resulting query on 5.5.x, for example, is notably slower. So, another good habit to mention is: check the suggested solution on the exact version customer used before recommending it!

Fun with Bugs #40 - Bugs fixed in MySQL 5.7.10

MySQL 5.7.10, the first release after MySQL 5.7 GA announcement, appeared almost a week ago. It's interesting to check what bugs reported by MySQL Community were fixed in this version, hence this post (that had to wait during the weekdays busy with usual support work). As usual, I'll concentrate mostly on InnoDB, replication and optimizer-related bug fixes and highlight names of those who reported and verified each bug.

Let's start with InnoDB. The following bugs reported by MySQL Community users were fixed:

• Bug #78623 - "Small tablespaces with BLOBs take up to 80 times more space in 5.7 than in 5.6". This serious regression was reported by my colleague Laurynas Biveinis and verified by Umesh well before 5.7.9 release, but probably too late to get fixed there. This is not the only example of bugs that could be fixed in the first 5.7 GA release theoretically. Either MySQL release process is too long in Oracle now, or they were just in a hurry to announce 5.7GA "in time"...
• Bug #78494 - "InnoDB: Failing assertion: !(&buf_pool->mutex)->is_owned() buf0buf.cc line 3388", was reported by  Roel Van de Paar and verified by Umesh. As well as some other bugs I am going to mention today, it shows that when proper QA efforts are applied community users may still find cases that are missed by Oracle MySQL QA.
• Bug #77321 - "Import tablespace may fail with invalid corruption error". This bug was originally found in MySQL 5.6 by Santosh Praneeth Banda, who had also suggested a way to fix, and verified by Shaohua Wang (probably).  
• Bug #78410 is still private, so we can not get the details. I do not understand why this bug is still hidden, as according to the release notes:
  

  "After a crash on Windows, copying the data directory to a non-Windows platform to perform the restore caused a crash recovery failure on startup. The code did not convert file path separators from “\” to “/” in the redo log."

• Bug #78336 - "handle_fatal_signal (sig=11) in dict_table_t::get_ref_count". It was reported for debug build by  Roel Van de Paar and verified by Shane Bester, who had provided an even simpler test case and clarified the impact. I just do not get it while, with the fix ready back on September 22 (according to the last comment), it was NOT included in 5.7.9...
• Bug #78197 - "COMPRESSION column in innodb_sys_tablespaces is not correct", was reported by Zhai Weixiang and verified by Umesh.
• Bug #77572 - "The bogus duplicate key error in online ddl with incorrect key name". It also affects 5.6 and was reported (with both MTR test case and patch suggested) by Zhang Yingqiang. Surely, it was easy for Sinisa Milivojevic to verify it.
• Bug #77128 - "Regression in dealing with filesystem limits", was reported for 5.6 and 5.7 by my colleagues Przemyslaw Malkowski and verified by Umesh.
• Bug #73225 - "If tablespace exists, can't CREATE table, but can ALTER ENGINE=InnoDB". It was reported for 5.6 by Federico Razzoli and verified by my colleague Sveta Smirnova while she was still working in Oracle... 
• Bug #78728 - "InnoDB: Failing assertion: 0 in file ha_innopart.cc line 3526 ". This debug-binaries only assertion failure was reported by Roel Van de Paar and verified by Umesh.

There are many more bugs fixed in InnoDB, but they were internal-only, probably found by Oracle QA.

I see only two replication-related bugs from Community users fixed in 5.7.10:

• Bug #76795 - "2pc succeeds even though binlog flush/sync fails". It was originally reported for MySQL 5.6 by  Santosh Praneeth Banda, who had suggested the patch, and verified by Umesh. See also Bug #68953 reported long time ago as a regression bug in 5.6 by Laurynas Biveinis.

As for optimizer, the list is also really short:

• Bug #78260  - "handle_fatal_signal (sig=11) in Partition_helper::ph_read_range_first on SELECT". It was reported by Roel Van de Paar and verified by Umesh. The bug is related to partition pruning, so we can blame optimizer as well.
• Bug #78665 - "GCOLS: GCOL VALUE CHANGES WHEN SESSION CHANGES SQL_MODE". Guilhem Bichot had reported this for MySQL Community to note, and probably he had fixed the bug himself later.The bug was verified by Miguel Solorzano.
• Bug #78641 - "cast of too big HEX literal to BIGINT UNSIGNED: bad result and no warning". It was reported by Guilhem Bichot and verified by Umesh. MySQL 5.6 was also affected, and the fix is in 5.6.28.
• Bug #77480 - "Wrong results for truncated column and aggregation". It was reported by Daniël van Eeden and verified by Umesh. Shane Bester had added a very simple test case later that also demonstrates the problem in MySQL 5.5 and 5.6 (where it is NOT fixed).

To summarize, we see a lot of fixes in InnoDB and 5.7.10 finally fixed some problems known for a long time (now that it's the latest GA release we'll probably get most fixes in 5.7 and only some of them will be back ported to 5.6), but there is still a long way to go. If you are interested in bugs I considered important in 5.7.9, check this post. Only 6 bugs listed there are closed.