Bug #73361 mutex contention caused by dummy table/index creation/free
Submitted: 23 Jul 2014 4:38 Modified: 19 Jan 2015 17:10
Reporter: zhai weixiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S5 (Performance)
Version:5.6.19 OS:Any
Assigned to: CPU Architecture:Any

[23 Jul 2014 4:38] zhai weixiang 
Description:
In MySQL5.6.19, stats_latch is delayed to be created until it's used.  So dummy table should never create stats_latch since it's not shared with other threads.

But still there are another two mutex  not  take into consideration
1.autoinc_mutex for dummy table
2.index->zip_pad.mutex for dummy index.

Because dummy table/index is not shared with other threads, So this overhead can be avoided completely

Actually same problem has been described in bug#71708 and Laurynas Biveinis even proved a patch to avoid autoinc_mutex creation for dummy table. Since bug#71708 is closed and I encountered this problem, I decide to  open a new bug report.

How to repeat:
Under heavy io-intensive workload using MySQL5.6.19
In my test, using sysbench,  200 tables with 1,000,000 records each.  Restart the server and adding update workload (using update_index.lua) without warming up the buffer pool. Then observed history length increased and you may find traces like this :

1 __lll_lock_wait(libpthread.so.0),_L_lock_995(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),os_fast_mutex_lock_func(os0sync.cc:873),pfs_os_fast_mutex_lock(os0sync.cc:873),os_mutex_enter(os0sync.cc:873),os_fast_mutex_free_func(os0sync.cc:925),pfs_os_fast_mutex_free(os0sync.ic:93),dict_mem_index_free(os0sync.ic:93),ibuf_dummy_index_free(ibuf0ibuf.cc:1574),ibuf_get_volume_buffered_count_func(ibuf0ibuf.cc:3066),ibuf_get_volume_buffered(ibuf0ibuf.cc:3137),ibuf_insert_low(ibuf0ibuf.cc:3137),ibuf_insert(ibuf0ibuf.cc:3913),btr_cur_search_to_nth_level(btr0cur.cc:625),row_ins_sec_index_entry_low(row0ins.cc:2655),row_ins_sec_index_entry(row0ins.cc:2938),row_upd_sec_index_entry(row0upd.cc:1840),row_upd_sec_step(row0upd.cc:1867),row_upd(row0upd.cc:1867),row_upd_step(row0upd.cc:1867),row_update_for_mysql(row0mysql.cc:1728),ha_innobase::update_row(ha_innodb.cc:7083),handler::ha_update_row(handler.cc:7298),mysql_update(sql_update.cc:818),mysql_execute_command(sql_parse.cc:3309),mysql_parse(sql_parse.cc:6247),dispatch_command(sql_parse.cc:1334),do_handle_one_connection(sql_connect.cc:982),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

      1 __lll_lock_wait(libpthread.so.0),_L_lock_995(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),os_fast_mutex_lock_func(os0sync.cc:873),pfs_os_fast_mutex_lock(os0sync.cc:873),os_mutex_enter(os0sync.cc:873),os_fast_mutex_init_func(os0sync.cc:852),pfs_os_fast_mutex_init(os0sync.ic:74),dict_mem_index_create(os0sync.ic:74),ibuf_dummy_index_create(ibuf0ibuf.cc:1537),ibuf_build_entry_from_ibuf_rec_func(ibuf0ibuf.cc:1537),ibuf_get_volume_buffered_count_func(ibuf0ibuf.cc:3062),ibuf_get_volume_buffered(ibuf0ibuf.cc:3137),ibuf_insert_low(ibuf0ibuf.cc:3137),ibuf_insert(ibuf0ibuf.cc:3913),btr_cur_search_to_nth_level(btr0cur.cc:638),btr_pcur_open_low(btr0pcur.ic:440),row_search_index_entry(btr0pcur.ic:440),row_upd_sec_index_entry(row0upd.cc:1752),row_upd_sec_step(row0upd.cc:1867),row_upd(row0upd.cc:1867),row_upd_step(row0upd.cc:1867),row_update_for_mysql(row0mysql.cc:1728),ha_innobase::update_row(ha_innodb.cc:7083),handler::ha_update_row(handler.cc:7298),mysql_update(sql_update.cc:818),mysql_execute_command(sql_parse.cc:3309),mysql_parse(sql_parse.cc:6247),dispatch_command(sql_parse.cc:1334),do_handle_one_connection(sql_connect.cc:982),handle_one_connection(sql_connect.cc:898),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

result from perf record:

-      1.16%        mysqld  mysqld                                  [.] os_mutex_enter(os_mutex_t*)                                                                                                    ▒
   - os_mutex_enter(os_mutex_t*)                                                                                                                                                                       ▒
      - 33.66% os_fast_mutex_free_func(pthread_mutex_t*)                                                                                                                                               ▒
         - 54.88% os_event_free(os_event*)                                                                                                                                                             ▒
              mutex_free_func(ib_mutex_t*)                                                                                                                                                             ▒
            + dict_mem_table_free(dict_table_t*)                                                                                                                                                       ▒
         - 45.12% dict_mem_index_free(dict_index_t*)                                                                                                                                                   ▒
            + 94.39% ibuf_dummy_index_free(dict_index_t*)                                                                                                                                              ▒
            + 4.18% ibuf_merge_or_delete_for_page(buf_block_t*, unsigned long, unsigned long, unsigned long, unsigned long)                                                                            ▒
            + 1.43% ibuf_rec_get_volume_func(unsigned char const*)                                                                                                                                     ▒
      - 32.46% os_event_create()                                                                                                                                                                       ▒
           mutex_create_func(ib_mutex_t*, char const*, unsigned long)                                                                                                                                  ▒
           dict_mem_table_create(char const*, unsigned long, unsigned long, unsigned long, unsigned long)                                                                                              ▒
         + ibuf_build_entry_from_ibuf_rec_func(unsigned char const*, mem_block_info_t*, dict_index_t**)                                                                                                ▒
      + 18.62% os_fast_mutex_init_func(pthread_mutex_t*)                                                                                                                                               ▒
      + 14.57% os_event_free(os_event*)

Suggested fix:
N/A
[23 Jul 2014 13:29] zhai weixiang 
patch based on Laurynas Biveinis's work (find the original patch on bug#71708)

Attachment: bug73361.diff (application/octet-stream, text), 9.59 KiB.
[9 Oct 2014 13:26] MySQL Verification Team 
I have analyzed this bug and I find it fully justified.

Verified as Performance related bug.
[19 Jan 2015 17:10] Daniel Price 
Posted by developer:
 
Fixed as of the upcoming 5.6.24, 5.7.6 releases, and here's the changelog entry:

 When dummy tables are created, the "autoinc_mutex" member of the of the
"dict_table_t" object was created unnecessarily. Similarly, the
"zip_pad.mutex" object of "dict_index_t" object was created unnecessarily
for dummy indexes. To avoid unnecessary mutex contention, "autoinc_mutex"
and "zip_pad.mutex" objects are now allocated and initialized on the first
lock attempt.
[27 Apr 2015 8:37] Laurynas Biveinis 
commit 3fbe15e6eea8c54915cb30d60eb6688acced8a0f
Author: Annamalai Gurusami <annamalai.gurusami@oracle.com>
Date:   Mon Jan 19 14:49:16 2015 +0530

    Bug #19788198 MUTEX CONTENTION CAUSED BY DUMMY TABLE/INDEX CREATION/FREE
    
    Problem:
    
    The autoinc_mutex member of the dict_table_t is not required for all the
    tables.  But this is being created for all the dict_table_t objects.
    Similar problem exists for dict_index_t::zip_pad::mutex.
    
    Solution:
    
    Make use of the lazy creation approach, whereby the autoinc_mutex member
    will be allocated and initialized when there is a first lock attempt.
    Apply same solution to dict_index_t::zip_pad::mutex.
    
    rb#7415 approved by Vasil.