问题最近使用sysbench测试MySQL。由于测试时间较长，我写了一个脚本按照prepare->run->cleanup的顺序后台运行。运行后查看日志，发现有问题。MySQL服务的错误日志中出现多条类似如下的错误信息：[ERROR]InnoDB:TryingtodoI/Otoatablespacewhichdoesnotexist.I/Otype:read,page:[pageid:space=32,pagenumber=57890],I/Olength:16384字节。看起来是I/O错误，但是MySQL进程并没有崩溃，sysbenchclient也没有报错。在查找问题的过程中，根据报错的时间记录和脚本输出各阶段时间点的对比，确定当时脚本执行的命令为：sysbench--tables=100--table-size=4000000--threads=50--mysql-db=sbtest--time=300oltp_deletecleanup再次手动执行这个用例，但同样的情况没有再次出现。但是在执行脚本的时候还是可以发现错误信息。初步怀疑是run和cleanup之间的间隔应该不会太长，才会触发这个问题。由于执行一个100G数据量的时间比较长，而且重新运行的成本很高，所以先尽量降低用例的数据量。将--table-size=4000000改为2000000，此时执行脚本不会触发该问题。最后，--table-size=3000000可以稳定触发，可以减少部分重现时间。为了确认是不是间隔太长无法重现，修改脚本在run和cleanup阶段休眠10秒，就不会触发这个错误信息了。如果改为休眠5秒，它仍然可以触发，但错误消息的数量已减少。问题排查查看对应版本mysql5.7.22的代码，发现这个错误只有一个位置：fil0fil.cc文件第5578行的fil_io()函数中。直接使用gdb调试，在此位置加断点，执行可重现的脚本，得到如下堆栈：(gdb)bt#0fil_io(type=...,sync=sync@entry=false,page_id=..。,page_size=...,byte_offset=byte_offset@entry=0,len=16384,buf=0x7f9ead544000,message=message@entry=0x7f9ea8ce9c78)atmysql-5.7.22/storage/innobase/fil/fil0fil.cc:5580#10x00000000010f99pagefainbuf(err=0x7f9ddaffc72c,sync=,type=0,mode=,page_id=...,page_size=...,unzip=true)atmysql-5.7.22/storage/innobase/buf/buf0rea.cc:195#20x00000000010fc5fainbuf_read_ibuf_merge_pages（sync=sync@entry=false，space_ids=space_ids@entry=0x7f9ddaffc7e0，page_nos=page_nos@entry=0x7f9ddaffc7a0，n_stored=2）atmysql-5.7.22/bunobase0/inbuf/storage/cc:834#30x0000000000f3a86cinibuf_merge_pages(n_pages=n_pages@entry=0x7f9ddaffce30,sync=sync@entry=false)atmysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2552#40x0000000000=falsemerge,syncfalsemerge=falsemif3a94同步=sync@entry=falsen_pages=0x7f9ddaffce30)atmysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2656#5ibuf_merge_in_background(full=full@entry=false)atmysql-5.7.22/storage/innobase/ibuf/ibuf0ibuf.cc:2721#60x000000000102bcf4insrv_master_do_active_tasks()atmysql-5.7.22/storage/innobase/srv/sr_2)atmysql-5.7.22/storage/innobase/srv/srv0srv.cc:2383#80x00007fa003eeddc5instart_thread()from/lib64/libpthread.so.0#90x00007fa002aab74dinclone()fromc。6很明显，这是后台线程在做insertbuffermerge操作。这时发现space->stop_new_ops为true，即正在删除待处理页面所属的空间。为什么要操作被删除的空间？这就需要考察insertbuffer函数，insertbuffermerge的过程，以及删除表的过程。insertbuffer背景知识insertbuffer是一种特殊的数据结构（B+树），当辅助索引页不在缓冲池中时，它会缓存变化，等到页面被其他读操作加载到缓冲池中时合并.MySQL刚推出这个功能的时候，只能缓存插入操作，所以叫insertbuffer。现在这些操作可以是INSERT，UPDATE，或DELETE（DML），所以称为changebuffer（本文仍描述为insertbuffer），但源码中仍使用ibuf作为标识。该函数将对同一页的多次更新缓存起来，合并成一次更新操作，减少了IO，将随机IO转化为顺序IO，可以避免随机IO带来的性能损失，提高数据库的写入性能。相关insertbuffermerge逻辑当bufferpage被读入bufferpool时，会执行insertbuffermerge。merge过程发生的场景主要有以下几种：当page被读入bufferpool时，读取完成后先进行ibufmerge，然后page可用；合并操作作为后台任务执行。innodb_io_capacity参数可以设置InnoDB后台任务每次合并进程的页数上限；崩溃恢复时，当索引页被读入缓冲池时，会执行对应页的insertbuffermerge；插入缓冲区是持久化的，系统崩溃不会导致它失败。重启后，insertbuffermerge操作会恢复正常；当服务器关闭时，--innodb-fast-shutdown=0可用于强制完全合并ibuf。我们这次的问题显然属于第二种情况。innodb主线程（svr_master_thread）每秒都会主动执行一次insertbuffer的merge操作。首先判断服务器在过去1秒内是否有活动（向页面中插入元组，对undo表进行行操作等），如果有，最大合并页数为innodb_io_capacity的5%环境。如果不是，合并的最大页数是innodb_io_capacity设置的值。innodb主线程（svr_master_thread）merge的主要流程如下：主线程从ibuf树的叶子节点读取页码和空间号，记录到二进制数组中（解锁）；主线程读取二进制组中的空间，检查是否在表空间缓存中，如果不在，说明已经删除，删除对应的ibuf记录；主线程判断是否对一个被删除的空间进行异步读操作，如果是则报错，并删除对应的ibuf记录Record，转流程2继续下一个数组元素的判断；如果判断一切正常，主线程发送asyncio请求，async读取需要合并的indexpage；I/Ohandler线程，在接收到完成的asyncI/O后，执行merge操作；在执行合并时调用fil_space_acquire以自动增加space->n_pending_ops。避免并发删除操作；执行后调用fil_space_release递减space->n_pending_ops。删除表的逻辑锁住fil_system->mutex，设置sp->stop_new_ops=true，标记该空间正在被删除，不允许对其进行新的操作，然后解锁fil_system->mutex；锁定fil_system->mutex，检测space->n_pending_ops，解锁fil_system->mutex。如果检测大于0，说明还有依赖操作没有完成。休眠20ms后重试；锁定fil_system->mutex，检测space->n_pending_flushes和(*node)->n_pending，并解锁fil_system->mutex。如果检测到大于0，说明有依赖I/O没有完成，休眠20ms后重试；此时认为没有冲突操作，将所有脏页刷出或删除给定表空间的所有页；从表空间缓存中删除指定空间的记录；删除相应的数据文件。问题的结论很明确。主线程获取ibuf(space,page)的进程和执行删除操作的进程没有锁来保证互斥。只有asyncI/O完成后的merge操作和delete操作是互斥的。如果后台线程启动ibufmerge已经执行了第二步检测，但是还没有执行到第三步检测，那么用户线程开始删除表并设置stop_new_ops标志但是还没有执行到第五步如果一步步删除表空间缓存，就会出现这个错误信息。两个线程的交互如下图所示：如果不出意外的话，断点断点的时候肯定有一个线程在执行对应表的删除操作。果然我们可以发现如下堆栈：Thread118(Thread0x7f9de0111700(LWP5234)):#00x00007fa003ef1e8einpthread_cond_broadcast@@GLIBC_2.3.2()from/lib64/libpthread.so.0#10x0000000000f82f41inbroadcast(this=0xd452ef8)atmysql-5.7.22/storage/innobase/os/os0event.cc:184#2set(this=0xd452ef8)atmysql-5.7.22/storage/innobase/os/os0event.cc:75#3os_event_set(event=0xd452ef8)atmysql-5.7.22/storage/innobase/os/os0event.cc:483#40x00000000010ec8a4insignal(this=)atmysql-5.7.22/storage/innobase/include/ut0mutex.ic:105#5exit(this=)atmysql-5.7.22/storage/innobase/include/ib0mutex.h:690#6exit(this=)atmysql-5.7.22/storage/innobase/include/ib0mutex.h:961#7buf_flush_yield(bpage=,buf_pool=)atmysql-5.7.22/storage/innobase/buf/buf0lru.cc:405#8buf_flush_try_yield(processed=,bpage=,buf_pool=)atmysql-5.7.22/storage/innobase/buf/buf0lru。抄送：449#9buf_flush_or_remove_pages(trx=,flush=,observer=,id=,buf_pool=)atmysql-5.7.22/storage/innobase/buf/buf0lru.cc:632#10buf_flush_dirty_pages(buf_pool=,id=,observer=,flush=,trx=)atmysql-5.7.22/storage/innobase/buf/buf0lru.cc:693#110x00000000010f6de7inbuf_LRU_remove_pages(trx=0x0,buf_remove=BUF_REMOVE_FLUSH_NO_WRITE,id=55,buf_pool=0x31e55e8)atmysql-5.7.22/storage/innobase/buf/buf0lru.cc:893#12buf_LRU_flush_or_remove_pages(id=id@entry=55,buf_remove=buf_remove@entry=BUF_REMOVE_FLUSH_NO_WRITE，trx=trx@entry=0x0)atmysql-5.7.22/storage/innobase/buf/buf0lru.cc:951#130x000000000114e488infil_delete_tablespace(id=id@entry=55，buf_remove=buf_remove_WSQL_REMOR=BUF5.7.22/storage/innobase/fil/fil0fil.cc:2800#140x0000000000fe77bdinrow_drop_single_table_tablespace(trx=0x0,is_encrypted=false,is_temp=false,filepath=0x7f9d7c209f38"./sbtest/sbtest25.ibd",tablename=0x7f9d7c209dc8"sbtest/sbtest25",space_id=55)atmysql-5.7.22/storage/innobase/行/row0mysql.cc:4189#15row_drop_table_for_mysql(name=name@entry=0x7f9de010e020"sbtest/sbtest25",trx=trx@entry=0x7f9ff9515750,drop_db=,nonatomic=,nonatomic@entry=true,handler=handler@entry=0x0)atmysql-5.7.22/storage/innobase/row/row0mysql.cc:4741#160x0000000000f092f3inha_innobase::delete_table(this=,name=0x7f9de010f5e0"./sbtest/sbtest25")atmysql-5.7.22/storage/innobase/handler/ha_innodb.cc:12539#170x0000000000801a30inha_delete_table(thd=thd@entry=0x7f9d7c1f6910,table_type=table_type@entry=0x2ebd100,path=path@entry=0x7f9dbde010f5",/s2b5",/s2b5"./s2b5"。db@entry=0x7f9d7c00e560"sbtest",别名=0x7f9d7c00df98"sbtest25",generate_warning=generate_warning@entry=true)atmysql-5.7.22/sql/handler.cc:2586#180x0000000000d0a6afinmysql_rm_table_no_locks(thd=thd@entry=0x7f9d7c1f6910,表=表@entry=0x7f9d7c00dfe0,if_exists=true=,falsedrop_temporentry=false,dont_log_query=dont_log_query@entry=false)atmysql-5.7.22/sql/sql_table.cc:2546#190x0000000000d0ba58inmysql_rm_table(thd=thd@entry=0x7f9d7c1f6910,tables=tables@entry=0x7f9d7c00existsdfe><,如果drop_temporary=)atmysql-5.7.22/sql/sql_table.cc:2196#200x0000000000c9d90binmysql_execute_command(thd=thd@entry=0x7f9d7c1f6910,first_level=first_level@entry=true)atmysql-5.7.22/sql/sql_parse.cc:3589#210x0000000000ca1eddinmysql_parse(thd=thd@entry=0x7f9d7c1f6910,parser_state=parser_state@entry=0x7f9de01107a0)atmysql-5.7.22/sql/sql_parse.cc:5582#220x0000000000ca2a20indispatch_command(thd=thd@entry=0x7f9d7c1f6910,com_data=com_data@entry=0x7f9de0110e00,command=COM_QUERY)atmysql-5.7.22/sql/sql_parse.cc:1458#230x00000000000000ca4377indo_command（connection_handler_per_thread.cc:300#250x0000000001223d74inpfs_spawn_thread(arg=0x10c48f40)atmysql-5.7.22/storage/perfschema/pfs.cc:2190#260x00007fa003eeddc5instart_thread()from/lib64/libpthread.so.0#270x00007fa002aab74dinclone()from/lib64/libc.so.6的解决方法是给buf_read_ibuf_merge_pages、buf_read_page_low、fil_io增加一个新的参数ignore_missing_space来忽略被删除的空间。默认为false，调用ibuf_merge_pages时设置为true。在报错的fil_io中，额外判断参数是否为真，为真则不报错，继续其他流程。或者直接在buf_read_ibuf_merge_pages调用buf_read_page_low时传入IORequest::IGNORE_MISSING参数。具体代码参考MariaDBcommit:8edbb1117a9e1fd81fbd08b8f1d06c72efe38f44查看受影响版本的相关信息。此问题是在修改Bug#19710564时删除表空间版本引入的。MySQLCommunityServer5.7.6引入，5.7.22版本未修复，8.0.0版本修复。MariaDB服务器10.2受到影响。MariaDBServer10.2.9、10.3.2已修复。优化建议可以优化性能：在buf_read_ibuf_merge_pages中记录出错的空间id，循环时判断下一页的空间id。如果空间id相同，直接删除对应的ibuf记录（系统表空间中记录了当前分配的***空间id，空间id占4个字节，低于0xFFFFFFF0UL，分配时读取值保存在系统表空间中，然后添加一个，这是唯一的）。
