数据库架构,分布式与并行编程

Enjoy life! Love Program!

  • 博客访问: 454223
  • 博文数量: 42
  • 用 户 组: 普通用户
  • 注册时间: 2015-01-01 22:46
  • 认证徽章:
个人简介

资深Oracle RAC及Exadata部署实施运维专家,曾从事PostgreSQL内核开发与性能优化。丰富的大规模数据库管理架构设计经验。目前在阿里巴巴从事数据库架构工作以及新技术引进,对分布式存储,云计算及并行编程有一定研究。技术讨论请加微信:ljs521688

ITPUB论坛APP

ITPUB论坛APP



APP发帖 享双倍积分

文章分类

全部博文(42)

文章存档

2017年(13)

2015年(29)

微信关注

IT168企业级官微



微信号:IT168qiye



系统架构师大会



微信号:SACC2013

订阅
热词专题
InnoDB IO路径源码分析 2017-04-07 19:39:33

分类: 开源技术

InnoDB实现IO Flush通过“os_file_flush”宏收敛,macro展开后为”os_file_flush_func”。

接下来,我们重点看一下,还有其它哪些场景会调用到这个os_file_flush_func函数:

1. buf_dblwr_init_or_load_pages中,在double buffer 做crash恢复时,如果设置了reset_space_ids为”true”

2. fil_create_new_single_table_tablespace中,创建表数据文件时

3. fil_user_tablespace_restore_page中,从double writer buffer中copy page时

4. fil_tablespace_iterate中,如果iterate page失败时,会做一次sync

5. os_file_set_size中,在文件新创建时初始化文件大小时

从上面可以看出,直接调用os_file_flush_func还是非常少的。那么系统中还有一些是调用os_file_flush_func的上层函数fil_flush:

1. buf_dblwr_flush_buffered_writes中,flush double write buffer到disk

2. buf_dblwr_write_single_page中,单页flush到disk中

3. buf_flush_write_block_low中,flush block到disk中,一般在调double write buffer“buf_dblwr_flush_buffered_writes“之后调用

4. buf_LRU_remove_pages中,delete某个tablespace中的page时,做sync调用

5. fil_rename_tablespace中,rename一个tablespace时调用

6. fil_extend_space_to_desired_size中,extend space时

7. fil_flush_file_spaces中,flush 批量tablespace的page时,被ha_innodb的force checkpoint时调用,shutdown DB时调用等

8. log_io_complete中,log io完成时,checkpoint write以及其它,是否调用受sync方式影响,非commit依赖

9. log_write_up_to中,commit事务时,这个是重点,innodb 的log file都会调用,而且是同步

10. create_log_files_rename中,rename log file时

11. innobase_start_or_create_for_mysql中,创建新的文件时

在fil_flush函数中,所有文件的flush cache行为受fil_system->mutex保护。因此不管是data file还是log file,文件级别的flush是串化的。那么具体是怎么来控制的呢?

1. 检查file node中的n_pending_flushes,如果大于“0”就一直retry

2. 如果为“0”,进入flush阶段,在正式开始flush之前,先将n_pending_flushe加“1”,这个操作受上文提到的“fil->mutex“保护

3. 调用“os_file_flush“ flush完成之后,n_pending_flushes减“1”,也同样由“fil->mutex“保护

下面是MySQL中retry的代码:

retry:

if (node->n_pending_flushes > 0) {

/* We want to avoid calling os_file_flush() on

            the file twice at the same time,   because we do

            not know what bugs OS's may   contain in file

            i/o */

ib_int64_t sig_count =

                os_event_reset(node->sync_event);

            mutex_exit(&fil_system->mutex);

            os_event_wait_low(node->sync_event, sig_count);

            mutex_enter(&fil_system->mutex);

if (node->flush_counter >= old_mod_counter) {

goto skip_flush;

            }

goto retry;

        }

下面是MySQL中flush的代码:

        ut_a(node->open);

        file = node->handle;

        node->n_pending_flushes++;

        mutex_exit(&fil_system->mutex);

        os_file_flush(file);

        mutex_enter(&fil_system->mutex);

        os_event_set(node->sync_event);

        node->n_pending_flushes--;

        node->flush_size = node->size;

上面提到的逻辑,对于log file也同样处理。Log file的tablespace为log space。对于log file,还受到log_sys->mutex的保护,在log_write_up_to函数中。

Log file的flush行为收敛到“log_write_up_to”函数体中,再调用fil_flush,最终走到os_file_flush_func。

MySQL在commit的时候,如果”innodb_flush_log_at_trx_commit=1”时,调用两次同步的log_write_up_to,一次是innobase log file 的flush,一次是bin log的flush。

如果关掉bin log,则在ordered_commit函数中,不会走sync_blog分支。以下是关掉和不关掉时,innobase flush log file的执行路径。

不带binlog时的Innobase 的pstack如下:

fsync,os_file_fsync,os_file_flush_func,fil_flush,log_write_up_to,trx_flush_log_if_needed_low,trx_flush_log_if_needed,trx_commit_complete_for_mysql,innobase_commit,ha_commit_low,TC_LOG_DUMMY::commit,ha_commit_trans,trans_commit_stmt,mysql_execute_command,mysql_parse,dispatch_command,do_command,do_handle_one_connection,handle_one_connection,start_thread,clone

带Binlog的flush pstack如下:

fsync,os_file_fsync,os_file_flush_func,fil_flush,log_write_up_to,innobase_flush_logs,flush_handlerton,plugin_foreach_with_mask,ha_flush_logs,MYSQL_BIN_LOG::process_flush_stage_queue,MYSQL_BIN_LOG::ordered_commit,MYSQL_BIN_LOG::commit,ha_commit_trans,trans_commit_stmt,mysql_execute_command,mysql_parse,dispatch_command,do_command,do_handle_one_connection,handle_one_connection,start_thread,clone

从上面大致的调用来看,log_write_up_to()和log_io_complete()将是重点,因为这些flush在file级别是串行的,commit时的rt主要由这些串化带来。

接下来我们看一下log_write_up_to的调用者都有那些:

1. buf_flush_write_block_low,在force flush中调用,保证日志必须先于数据落地,刷脏页时,由page_cleaner_do_flush_batch()发起调用到此函数

2. innobase_flush_logs,在commit时调用,主要由flush binlog分支调用

3. trx_flush_log_if_needed_low,在commit时调用,主要由flush innodb log file时调用

4. log_buffer_flush_to_disk,log buffer刷日志到disk

5. log_buffer_sync_in_background,后台线程同步log buffer到disk,由srv_master_thread 线程调srv_sync_log_buffer_in_background()调用到,每秒一次

6. log_flush_margin,主要为腾挪log buffer空间时调用

7. log_checkpoint,主要在做checkpoint时调用到,由srv_master线程调用srv_master_do_idle_tasks(),每秒做一次

log_io_complete()函数的调用情况:

1. fil_aio_wait,aio wait中如果是log io将会调用此方法

从上面分析可以看到,主要影响RT比较严重的还是因为刷脏页导致的log_sys->mutex争用。另外,log_buffer_sync_in_background和log_checkpoint,这两个都是由后台srv_master_thread线程每隔一秒调用到。

但是这两个方法不一定会执行fil_flush,所以不是影响的主因。gdb挂上去后,大致会走到fil_flush争用的pstack如下:


Breakpoint 13, fil_flush   (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000c890e5 in log_write_up_to (lsn=,   wait=, flush_to_disk=1, caller=) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1674

#2    0x0000000000c45330 in innobase_flush_logs (hton=,   target_lsn=) at /u01/mysql-5.6/storage/innobase/handler/ha_innodb.cc:4210

#3    0x00000000006a80b9 in flush_handlerton (thd=thd@entry=0x0,   plugin=, arg=arg@entry=0x7fc6b802f760) at   /u01/mysql-5.6/sql/handler.cc:2385

#4    0x0000000000819312 in plugin_foreach_with_mask (thd=0x0,   func=func@entry=0x6a8050 ,   type=type@entry=1, state_mask=4294967287, state_mask@entry=8,   arg=0x7fc6b802f760)

      at /u01/mysql-5.6/sql/sql_plugin.cc:2168

#5    0x00000000006aba87 in ha_flush_logs (db_type=db_type@entry=0x0, engine_map=) at /u01/mysql-5.6/sql/handler.cc:2395

#6    0x00000000009cd7c4 in MYSQL_BIN_LOG::process_flush_stage_queue   (this=this@entry=0x16c3100 ,   total_bytes_var=total_bytes_var@entry=0x7fc6e40cfac0,   rotate_var=rotate_var@entry=0x7fc6e40cfab0,

      out_queue_var=out_queue_var@entry=0x7fc6e40cfad0,   async=async@entry=false) at /u01/mysql-5.6/sql/binlog.cc:7120

#7    0x00000000009cd967 in MYSQL_BIN_LOG::ordered_commit   (this=this@entry=0x16c3100 , thd=thd@entry=0x2165100, all=all@entry=false,   skip_commit=skip_commit@entry=false, async=async@entry=false)

      at /u01/mysql-5.6/sql/binlog.cc:7587

#8    0x00000000009ce69d in MYSQL_BIN_LOG::commit (this=0x16c3100   , thd=0x2165100, all=,   async=) at /u01/mysql-5.6/sql/binlog.cc:7021

#9    0x00000000006b1889 in ha_commit_trans (thd=thd@entry=0x2165100,   all=all@entry=false, async=,   ignore_global_read_lock=ignore_global_read_lock@entry=false) at   /u01/mysql-5.6/sql/handler.cc:1539

#10 0x0000000000895ecd in   trans_commit_stmt (thd=thd@entry=0x2165100, async=) at   /u01/mysql-5.6/sql/transaction.cc:452

#11 0x0000000000808670 in   mysql_execute_command (thd=thd@entry=0x2165100,   statement_start_time=statement_start_time@entry=0x7fc6e40d1950,   post_parse=post_parse@entry=0x7fc6e40d1b10) at   /u01/mysql-5.6/sql/sql_parse.cc:5922

#12 0x000000000080f6be in mysql_parse   (thd=thd@entry=0x2165100, rawbuf=, length=, parser_state=parser_state@entry=0x7fc6e40d1c40,   last_timer=last_timer@entry=0x7fc6e40d1b10,

      async_commit=async_commit@entry=0x7fc6e40d1af0 "",   db="",   exit_admission_control=exit_admission_control@entry=0x7fc6e40d1b00   "") at /u01/mysql-5.6/sql/sql_parse.cc:7677

#13 0x0000000000811136 in   dispatch_command (command=COM_QUERY, thd=0x2165100, packet=0x2178b71   "update sbtest.sbtest1 set k=k+1 where id=1",   packet_length=) at /u01/mysql-5.6/sql/sql_parse.cc:1691

#14 0x0000000000813003 in do_command   (thd=) at /u01/mysql-5.6/sql/sql_parse.cc:1133

#15 0x00000000007d705f in   do_handle_one_connection (thd_arg=) at   /u01/mysql-5.6/sql/sql_connect.cc:1108

#16 0x00000000007d71d9 in   handle_one_connection (arg=) at   /u01/mysql-5.6/sql/sql_connect.cc:929

#17 0x00007fd950ef9dc5 in start_thread ()   from /lib64/libpthread.so.0

#18 0x00007fd94ef4a28d in clone () from   /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e5957700 (LWP   39002)]

Breakpoint 15,   log_buffer_sync_in_background (flush=flush@entry=1) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1749

1749      {

(gdb) bt

#0    log_buffer_sync_in_background (flush=flush@entry=1) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1749

#1    0x0000000000d06c33 in srv_sync_log_buffer_in_background () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:2757

#2    srv_master_do_active_tasks () at /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:2887

#3    srv_master_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3145

#4    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#5    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

Breakpoint 14, log_checkpoint   (sync=sync@entry=1, write_always=write_always@entry=0) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

2154      {

(gdb) bt

#0    log_checkpoint (sync=sync@entry=1, write_always=write_always@entry=0)   at /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

#1    0x0000000000d07199 in srv_master_do_active_tasks () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:2929

#2    srv_master_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3145

#3    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#4    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dd7fa700 (LWP   39007)]

Breakpoint 13, fil_flush   (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000c890e5 in log_write_up_to (lsn=,   wait=, flush_to_disk=1, caller=) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1674

#2    0x0000000000d79d26 in buf_flush_write_block_low (sync=false,   flush_type=BUF_FLUSH_LIST, bpage=0x7fd706332330) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:902

#3    buf_flush_page (buf_pool=, bpage=0x7fd706332330,   flush_type=BUF_FLUSH_LIST, sync=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1061

#4    0x0000000000d7a43e in buf_flush_try_neighbors (space=0,   offset=offset@entry=5, flush_type=flush_type@entry=BUF_FLUSH_LIST,   n_flushed=n_flushed@entry=1, n_to_flush=n_to_flush@entry=250)

      at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1271

#5    0x0000000000d7b1b1 in buf_flush_page_and_try_neighbors   (flush_type=BUF_FLUSH_LIST, count=, n_to_flush=250,   bpage=) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1355

#6    buf_do_flush_list_batch (buf_pool=buf_pool@entry=0x1f817d8,   min_n=min_n@entry=250, lsn_limit=lsn_limit@entry=18446744073709551615) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1623

#7    0x0000000000d7b308 in buf_flush_batch (flush_type=BUF_FLUSH_LIST,   lsn_limit=18446744073709551615, min_n=,   buf_pool=0x1f817d8) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1693

#8    buf_flush_list (min_n=,   n_processed=n_processed@entry=0x7fc6dd7f9bd8, lsn_limit=18446744073709551615)   at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1939

#9    0x0000000000d7c79b in page_cleaner_do_flush_batch   (lsn_limit=18446744073709551615, n_to_flush=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2216

#10 buf_flush_page_cleaner_thread   (arg=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2588

#11 0x00007fd950ef9dc5 in start_thread ()   from /lib64/libpthread.so.0

#12 0x00007fd94ef4a28d in clone () from   /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dcff9700 (LWP   39008)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000d7636c in buf_dblwr_flush_buffered_writes () at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:1135

#2    0x0000000000d7c419 in buf_flush_end (flush_type=BUF_FLUSH_LRU,   buf_pool=0x1f817d8) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1794

#3    buf_flush_LRU_tail () at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2150

#4    0x0000000000d7d446 in buf_flush_lru_manager_thread (arg=) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2712

#5    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#6    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e995f700 (LWP   38990)]

Breakpoint 13, fil_flush (space_id=104,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=104, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000db8970 in fil_flush_file_spaces   (purpose=purpose@entry=501, from=from@entry=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6668

#2    0x0000000000d75f0b in buf_dblwr_update (bpage=bpage@entry=0x7fd70665d550,   flush_type=) at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:803

#3    0x0000000000d79699 in buf_flush_write_complete   (bpage=bpage@entry=0x7fd70665d550) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:691

#4    0x0000000000d71e16 in buf_page_io_complete (bpage=0x7fd70665d550,   evict=evict@entry=false) at   /u01/mysql-5.6/storage/innobase/buf/buf0buf.cc:6157

#5    0x0000000000db5ac0 in fil_aio_wait (segment=segment@entry=10) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6460

#6    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#7    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#8    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dcff9700 (LWP   39008)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000d7636c in buf_dblwr_flush_buffered_writes () at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:1135

#2    0x0000000000d7c41e in buf_flush_common (page_count=, flush_type=BUF_FLUSH_LRU) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1723

#3    buf_flush_LRU_tail () at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2152

#4    0x0000000000d7d446 in buf_flush_lru_manager_thread (arg=) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2712

#5    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#6    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e995f700 (LWP   38990)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000db8970 in fil_flush_file_spaces   (purpose=purpose@entry=501, from=from@entry=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6668

#2    0x0000000000d75f0b in buf_dblwr_update (bpage=bpage@entry=0x7fd706332330,   flush_type=) at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:803

#3    0x0000000000d79699 in buf_flush_write_complete   (bpage=bpage@entry=0x7fd706332330) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:691

#4    0x0000000000d71e16 in buf_page_io_complete (bpage=0x7fd706332330,   evict=evict@entry=false) at   /u01/mysql-5.6/storage/innobase/buf/buf0buf.cc:6157

#5    0x0000000000db5ac0 in fil_aio_wait (segment=segment@entry=10) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6460

#6    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#7    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#8    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dd7fa700 (LWP   39007)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000d7636c in buf_dblwr_flush_buffered_writes () at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:1135

#2    0x0000000000d7b384 in buf_flush_end (flush_type=BUF_FLUSH_LIST,   buf_pool=0x1f81e08) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1794

#3    buf_flush_list (min_n=,   n_processed=n_processed@entry=0x7fc6dd7f9bd8, lsn_limit=18446744073709551615)   at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1942

#4    0x0000000000d7c79b in page_cleaner_do_flush_batch   (lsn_limit=18446744073709551615, n_to_flush=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2216

#5    buf_flush_page_cleaner_thread (arg=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2588

#6    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#7    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e915e700 (LWP   38991)]

Breakpoint 13, fil_flush (space_id=104,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=104, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000db8970 in fil_flush_file_spaces   (purpose=purpose@entry=501, from=from@entry=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6668

#2    0x0000000000d75f0b in buf_dblwr_update   (bpage=bpage@entry=0x7fd4c76da870, flush_type=) at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:803

#3    0x0000000000d79699 in buf_flush_write_complete   (bpage=bpage@entry=0x7fd4c76da870) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:691

#4    0x0000000000d71e16 in buf_page_io_complete (bpage=0x7fd4c76da870,   evict=evict@entry=false) at   /u01/mysql-5.6/storage/innobase/buf/buf0buf.cc:6157

#5    0x0000000000db5ac0 in fil_aio_wait (segment=segment@entry=11) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6460

#6    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#7    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#8    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dd7fa700 (LWP   39007)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000d7636c in buf_dblwr_flush_buffered_writes () at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:1135

#2    0x0000000000d7b384 in buf_flush_end (flush_type=BUF_FLUSH_LIST,   buf_pool=0x1f82a68) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1794

#3    buf_flush_list (min_n=,   n_processed=n_processed@entry=0x7fc6dd7f9bd8, lsn_limit=18446744073709551615)   at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1942

#4    0x0000000000d7c79b in page_cleaner_do_flush_batch   (lsn_limit=18446744073709551615, n_to_flush=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2216

#5    buf_flush_page_cleaner_thread (arg=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2588

#6    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#7    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e815c700 (LWP   38993)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000db8970 in fil_flush_file_spaces (purpose=purpose@entry=501,   from=from@entry=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6668

#2    0x0000000000d75f0b in buf_dblwr_update   (bpage=bpage@entry=0x7fd049dfe2a0, flush_type=) at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:803

#3    0x0000000000d79699 in buf_flush_write_complete   (bpage=bpage@entry=0x7fd049dfe2a0) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:691

#4    0x0000000000d71e16 in buf_page_io_complete (bpage=0x7fd049dfe2a0,   evict=evict@entry=false) at /u01/mysql-5.6/storage/innobase/buf/buf0buf.cc:6157

#5    0x0000000000db5ac0 in fil_aio_wait (segment=segment@entry=13) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6460

#6    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#7    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#8    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6dd7fa700 (LWP   39007)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000d7636c in buf_dblwr_flush_buffered_writes () at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:1135

#2    0x0000000000d7b384 in buf_flush_end (flush_type=BUF_FLUSH_LIST,   buf_pool=0x1f83098) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1794

#3    buf_flush_list (min_n=,   n_processed=n_processed@entry=0x7fc6dd7f9bd8, lsn_limit=18446744073709551615)   at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1942

#4    0x0000000000d7c79b in page_cleaner_do_flush_batch   (lsn_limit=18446744073709551615, n_to_flush=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2216

#5    buf_flush_page_cleaner_thread (arg=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2588

#6    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#7    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e795b700 (LWP   38994)]

Breakpoint 13, fil_flush (space_id=0,   from=FLUSH_FROM_DOUBLEWRITE) at /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=0, from=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000db8970 in fil_flush_file_spaces   (purpose=purpose@entry=501, from=from@entry=FLUSH_FROM_DOUBLEWRITE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6668

#2    0x0000000000d75f0b in buf_dblwr_update   (bpage=bpage@entry=0x7fce0b251e10, flush_type=) at   /u01/mysql-5.6/storage/innobase/buf/buf0dblwr.cc:803

#3    0x0000000000d79699 in buf_flush_write_complete   (bpage=bpage@entry=0x7fce0b251e10) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:691

#4    0x0000000000d71e16 in buf_page_io_complete (bpage=0x7fce0b251e10,   evict=evict@entry=false) at   /u01/mysql-5.6/storage/innobase/buf/buf0buf.cc:6157

#5    0x0000000000db5ac0 in fil_aio_wait (segment=segment@entry=14) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6460

#6    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#7    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#8    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6e5957700 (LWP   39002)]

Breakpoint 15,   log_buffer_sync_in_background (flush=flush@entry=1) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1749

1749      {

(gdb) bt

#0    log_buffer_sync_in_background (flush=flush@entry=1) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1749

#1    0x0000000000d07043 in srv_sync_log_buffer_in_background () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:2757

#2    srv_master_do_idle_tasks () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:2992

#3    srv_master_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3147

#4    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#5    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

Breakpoint 14, log_checkpoint   (sync=sync@entry=1, write_always=write_always@entry=0) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

2154      {

(gdb) bt

#0    log_checkpoint (sync=sync@entry=1, write_always=write_always@entry=0)   at /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

#1    0x0000000000d06f56 in srv_master_do_idle_tasks () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3002

#2    srv_master_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3147

#3    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#4    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

[Switching to Thread 0x7fc6ee168700 (LWP   38981)]

Breakpoint 13, fil_flush   (space_id=4294967280, from=FLUSH_FROM_LOG_IO_COMPLETE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=4294967280, from=FLUSH_FROM_LOG_IO_COMPLETE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000c86c78 in log_io_complete (group=) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1239

#2    0x0000000000db5a4b in fil_aio_wait (segment=segment@entry=1) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6463

#3    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#4    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#5    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.

bt[Switching to Thread 0x7fc6e5957700   (LWP 39002)]

Breakpoint 14, log_checkpoint   (sync=sync@entry=1, write_always=write_always@entry=0) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

2154      {

(gdb) bt

#0    log_checkpoint (sync=sync@entry=1, write_always=write_always@entry=0)   at /u01/mysql-5.6/storage/innobase/log/log0log.cc:2154

#1    0x0000000000d06f56 in srv_master_do_idle_tasks () at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3002

#2    srv_master_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0srv.cc:3147

#3    0x00007fd950ef9dc5 in start_thread () from /lib64/libpthread.so.0

#4    0x00007fd94ef4a28d in clone () from /lib64/libc.so.6

(gdb) c

Continuing.


大部分都是double write buffer的刷出,但是这个不会与log_sys->mutex争用,我们这里不关心。下面这个是刷脏页导致的log flush,这个会跟commit时的log flush争用。

Breakpoint 13, fil_flush   (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=4294967280, from=FLUSH_FROM_LOG_WRITE_UP_TO) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000c890e5 in log_write_up_to (lsn=,   wait=, flush_to_disk=1, caller=) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1674

#2    0x0000000000d79d26 in buf_flush_write_block_low (sync=false,   flush_type=BUF_FLUSH_LIST, bpage=0x7fd706332330) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:902

#3    buf_flush_page (buf_pool=, bpage=0x7fd706332330,   flush_type=BUF_FLUSH_LIST, sync=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1061

#4    0x0000000000d7a43e in buf_flush_try_neighbors (space=0,   offset=offset@entry=5, flush_type=flush_type@entry=BUF_FLUSH_LIST,   n_flushed=n_flushed@entry=1, n_to_flush=n_to_flush@entry=250)

      at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1271

#5    0x0000000000d7b1b1 in buf_flush_page_and_try_neighbors   (flush_type=BUF_FLUSH_LIST, count=, n_to_flush=250,   bpage=) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1355

#6    buf_do_flush_list_batch (buf_pool=buf_pool@entry=0x1f817d8,   min_n=min_n@entry=250, lsn_limit=lsn_limit@entry=18446744073709551615) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1623

#7    0x0000000000d7b308 in buf_flush_batch (flush_type=BUF_FLUSH_LIST,   lsn_limit=18446744073709551615, min_n=,   buf_pool=0x1f817d8) at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1693

#8    buf_flush_list (min_n=,   n_processed=n_processed@entry=0x7fc6dd7f9bd8, lsn_limit=18446744073709551615)   at /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:1939

#9    0x0000000000d7c79b in page_cleaner_do_flush_batch   (lsn_limit=18446744073709551615, n_to_flush=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2216

#10 buf_flush_page_cleaner_thread   (arg=) at   /u01/mysql-5.6/storage/innobase/buf/buf0flu.cc:2588

#11 0x00007fd950ef9dc5 in start_thread ()   from /lib64/libpthread.so.0

#12 0x00007fd94ef4a28d in clone () from   /lib64/libc.so.6

Breakpoint 5, fil_flush   (space_id=4294967280, from=FLUSH_FROM_LOG_IO_COMPLETE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

6478      {

(gdb) bt

#0    fil_flush (space_id=4294967280, from=FLUSH_FROM_LOG_IO_COMPLETE) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6478

#1    0x0000000000c86c78 in log_io_complete (group=) at   /u01/mysql-5.6/storage/innobase/log/log0log.cc:1239

#2    0x0000000000db5a4b in fil_aio_wait (segment=segment@entry=1) at   /u01/mysql-5.6/storage/innobase/fil/fil0fil.cc:6463

#3    0x0000000000d09ba0 in io_handler_thread (arg=) at   /u01/mysql-5.6/storage/innobase/srv/srv0start.cc:498

#4    0x00007fb818efddc5 in start_thread () from /lib64/libpthread.so.0

#5    0x00007fb816f4e28d in clone () from /lib64/libc.so.6

1: *node = {space = 0x30aa218, name =   0x30aa948 "/mnt/mysql-redo/my3308/data/ib_logfile0", open = 1,   handle = 10, sync_event = 0x30aa980, is_raw_disk = 0, size = 262144,   n_pending = 0, n_pending_flushes = 0,

    being_extended = 0, modification_counter = 49, flush_counter = 41,   flush_size = 262144, chain = {prev = 0x0, next = 0x30aaa78}, LRU = {prev =   0x0, next = 0x0}, magic_n = 89389}


因此,总结起来,应该是commit做的两次fsync加上一次page cleaner做的log_write_up_to()。另外,还有一个fil_aio_wait完成时,如果是log io,就会做一次log_io_complete()。

这四次fsync都会对用户的rt有影响,commit的两次无可避免,后面两次最多也就是调整频率。另外是否可以改变fsync的方式?这个读者可以思考。

比oracle实现差,oracle不会作强制的,我记得是给一个标记,策略还是按redo自己的策略来做。oracle的实现应该是考虑到这一点了.

附:facebook的优化,http://yoshinorimatsunobu.blogspot.com/2009/05/overwriting-is-much-faster-than_28.html

阅读(802) | 评论(0) | 转发(0) |
给主人留下些什么吧!~~
评论热议
请登录后评论。

登录 注册