{"id":79,"date":"2013-05-02T13:22:46","date_gmt":"2013-05-02T05:22:46","guid":{"rendered":"http:\/\/www.gpfeng.com\/?p=79"},"modified":"2013-08-23T22:41:53","modified_gmt":"2013-08-23T14:41:53","slug":"percona-bug1162085-bug1070856","status":"publish","type":"post","link":"http:\/\/www.gpfeng.com\/?p=79","title":{"rendered":"percona bug#1162085, bug#1070856"},"content":{"rendered":"

\u672c\u6587\u4ecb\u7ecdpercona\u4fee\u590d\u7684\u4e24\u4e2abinlog cache\u76f8\u5173\u7684bug\uff0cpercona bug#1162085<\/a> (mysql bug#66237<\/a>) \u548cpercona bug#1070856<\/a>\uff0c\u5176\u4e2dpercona bug#1070856\u662f\u4fee\u590dpercona bug#1162085\u65f6\u5f15\u5165\u7684<\/p>\n

percona bug#1162085<\/h3>\n

\u8fd9\u4e2abug\u4f1a\u5bfc\u81f4tmp\u76ee\u5f55\u88ab\u5199\u6ee1\uff0c\u5bf9\u4e8e\u4e00\u4e2a\u5199\u5165\u8f83\u5927\u7684\u64cd\u4f5c\uff0c\u5982LOAD DATA \/ INSERT large_dataset, \u5168\u8868UPDATE \/ DELETE, \u4e8b\u52a1\u5bf9\u5e94\u7684binlog cache\u4f1a\u4f7f\u7528\u5230\u4e34\u65f6\u6587\u4ef6\uff08ML\u5f00\u5934\uff0c\u7c7b\u4f3c\uff1a\/tmp\/MLjw4ecJ\uff0c\u7528lsof\u67e5\u770b\uff0c\u72b6\u6001\u4e3adeleted\uff09\u4f5c\u4e3a\u7f13\u51b2\uff08IO_CACHE\uff09\uff0c\u4e8b\u52a1\u5728\u63d0\u4ea4\u540e\uff0cbinlog_cache_data.truncate\u51fd\u6570\u88ab\u88ab\u8c03\u7528\uff0c\u4f46\u662f\u6b64\u51fd\u6570\u53ea\u4f1a\u521d\u59cb\u5316IO_CACHE\u4e2d\u7684\u5185\u5b58\u7f13\u51b2\uff0c\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u4e0d\u505a\u6e05\u7406\uff0c\u53ea\u6709\u5728session\u88ab\u5173\u95ed\u65f6\uff0cclose_cached_file\u88ab\u8c03\u7528\uff0cIO_CACHE\u5bf9\u8c61\u88ab\u9500\u6bc1\uff0c\u8fd9\u79cd\u7b56\u7565\u8bbe\u8ba1\u521d\u8877\u5e94\u8be5\u662f\uff1asession\u9000\u51fa\u4e4b\u524d\uff0c\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u80fd\u591f\u4e00\u76f4\u88ab\u4f7f\u7528\uff1b\u7136\u800c\u4f1a\u51fa\u73b0\u4e00\u4e2a\u95ee\u9898\uff1a\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u4f1a\u4e00\u76f4\u5b58\u5728\uff0c\u4e14\u53ea\u4f1a\u8d8a\u53d8\u8d8a\u5927\uff0c\u5982\u679c\u6709\u5f88\u591asession\u4e00\u76f4\u4e0d\u9000\u51fa\u4e14\u6267\u884c\u8fc7\u5f88\u5927\u7684\u64cd\u4f5c\uff0c\u5c31\u4f1a\u6709tmp\u76ee\u5f55\u88ab\u5199\u6ee1\u7684\u98ce\u9669<\/strong><\/p>\n

percona bug#1162085<\/a>\u5bf9\u5e94\u7684patch\u7684\u89e3\u51b3\u529e\u6cd5\u662f\uff1abinlog_cache_data.truncate\u4e2d\u589e\u52a0truncate\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u7684\u64cd\u4f5c\uff0c\u5373\u5bf9\u4e8e\u5927\u64cd\u4f5c\uff08\u8d85\u8fc7binlog_cache_size\uff09\uff0c\u6bcf\u6b21\u5b8c\u6210\u540e\u5bf9\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u505a\u4e00\u6b21truncate\u64cd\u4f5c: binlog_cache_mngr.reset –> binlog_cache_data.reset –> binlog_cache_data.truncate\uff0c\u90e8\u5206patch\uff1a<\/p>\n

\r\n--- Percona-Server\/mysys\/mf_cache.c\t2011-06-30 15:46:53 +0000\r\n+++ Percona-Server\/mysys\/mf_cache.c\t2012-10-26 05:11:24 +0000\r\n@@ -119,3 +119,21 @@\r\n   }\r\n   DBUG_VOID_RETURN;\r\n }\r\n+\r\n+\/*\r\n+  Truncate the cached file to a given offset. The cache must be reinitialized\r\n+  with reinit_io_cache() after this call.\r\n+*\/\r\n+\r\n+my_bool truncate_cached_file(IO_CACHE *cache, my_off_t pos)\r\n+{\r\n+  DBUG_ENTER(\"truncate_cached_file\");\r\n+\r\n+  if (my_b_inited(cache) && cache->file > -1)\r\n+  {\r\n+    if (my_chsize(cache->file, pos, 0, MYF(MY_WME)))\r\n+      DBUG_RETURN(TRUE);\r\n+  }\r\n+\r\n+  DBUG_RETURN(FALSE);\r\n+}\r\n\r\n--- Percona-Server\/sql\/log.cc\t2012-10-17 03:47:45 +0000\r\n+++ Percona-Server\/sql\/log.cc\t2012-10-26 05:11:24 +0000\r\n@@ -395,6 +395,11 @@\r\n       delete pending();\r\n       set_pending(0);\r\n     }\r\n+    \/*\r\n+      Truncate the temporary file to reclaim disk space occupied by cached\r\n+      transactions on COMMIT\/ROLLBACK.\r\n+    *\/\r\n+    truncate_cached_file(&cache_log, pos);\r\n     reinit_io_cache(&cache_log, WRITE_CACHE, pos, 0, 0);\r\n     cache_log.end_of_file= saved_max_binlog_cache_size;\r\n   }\r\n<\/pre>\n
percona bug#1070856<\/h3>\n
\u7136\u800c\uff0cpercona bug#1162085\u7684patch\u5374\u5f15\u5165\u4e86percona bug#1070856<\/a>\uff0cbinlog_cache_data.truncate\u9664\u4e86\u88abbinlog_cache_data.reset\u8c03\u7528\u4e4b\u5916\uff0c\u8fd8\u4f1a\u88abbinlog_cache_data.restore_savepoint\/restore_prev_posiiton\u8c03\u7528\uff0c\u8fd9\u4e24\u4e2a\u51fd\u6570\u90fd\u662f\u5904\u7406savepoint\/rollback\u76f8\u5173\u7684\uff0c\u65b0\u5efa\u4e00\u4e2asavepoint\u7684\u8c03\u7528\u51fd\u6570\u6808\uff1a<\/p>\n
\r\n#0  binlog_savepoint_set (hton=0x2002d60, thd=0x62637c0, sv=0x7fb6e0006d50) at sql\/log.cc:2043\r\n#1  0x0000000000768bde in ha_savepoint (thd=0x62637c0, sv=0x7fb6e0006d20) at sql\/handler.cc:1876\r\n#2  0x00000000006ed477 in trans_savepoint (thd=0x62637c0, name=...) at sql\/transaction.cc:422\r\n#3  0x00000000005fdd10 in mysql_execute_command (thd=0x62637c0) at sql\/sql_parse.cc:3961\r\n#4  0x0000000000602478 in mysql_parse (thd=0x62637c0, rawbuf=0x7fb6e0004c90 \"SAVEPOINT savepoint_1\", length=21, parser_state=0x7fb6ec5d0ae0) at sql\/sql_parse.cc:5805\r\n#5  0x00000000005f5fa1 in dispatch_command (command=COM_QUERY, thd=0x62637c0, packet=0x62fefe1 \"SAVEPOINT savepoint_1\", packet_length=21) at sql_parse.cc:1060\r\n#6  0x00000000005f5240 in do_command (thd=0x62637c0) at sql\/sql_parse.cc:788\r\n#7  0x00000000006dbfc0 in do_handle_one_connection (thd_arg=0x62637c0) at sql\/sql_connect.cc:1409\r\n#8  0x00000000006dba77 in handle_one_connection (arg=0x62637c0) at sql\/sql_connect.cc:1315\r\n#9  0x0000003659e077e1 in start_thread () from \/lib64\/libpthread.so.0\r\n#10 0x0000003659ae68ed in clone () from \/lib64\/libc.so.6\r\n<\/pre>\n
binlog_savepoint_set \u51fd\u6570\u4e2dmy_off_t *sv\u662f\u4f20\u5165\u53c2\u6570\uff0c\u8bb0\u5f55\u4e86\u5f53\u524dbinlog cache\u5199\u5165\u4f4d\u7f6e\uff0c\u4e8b\u52a1\u4e2d\u6240\u6709savepoint\u901a\u8fc7thd->transaction.savepoints\u94fe\u8868\u7ba1\u7406\uff0c\u5f53rollback\u65f6\uff0c\u5148\u5728\u94fe\u8868\u4e2d\u627e\u5230\u5bf9\u5e94\u7684savepoint\u8282\u70b9\uff0c\u7136\u540e\u5f97\u5230\u5176\u5728binlog cache\u4e2d\u7684\u4f4d\u7f6e\uff0c\u5bf9\u8be5\u4f4d\u7f6e\u4e4b\u540e\u7684binlog\u505atruncate\u64cd\u4f5c\uff0cROLLBACK TO SAVEPOINT sv_name\u5bf9\u5e94\u7684\u51fd\u6570\u6808\uff1a<\/p>\n
\r\n#0  0x000000000081b4f3 in binlog_cache_data::truncate (this=0x7fb6e000a0c0, pos=49558) at sql\/log.cc:400\r\n#1  0x000000000081b323 in binlog_cache_data::restore_savepoint (this=0x7fb6e000a0c0, pos=49558) at sql\/log.cc:286\r\n#2  0x000000000080c2e9 in binlog_trans_log_truncate (thd=0x62637c0, pos=49558) at sql\/log.cc:1582\r\n#3  0x000000000080d56f in binlog_savepoint_rollback (hton=0x2002d60, thd=0x62637c0, sv=0x7fb6e0006e30) at sql\/log.cc:2083\r\n#4  0x0000000000768935 in ha_rollback_to_savepoint (thd=0x62637c0, sv=0x7fb6e0006e00) at sql\/handler.cc:1819\r\n#5  0x00000000006ed605 in trans_rollback_to_savepoint (thd=0x62637c0, name=...) at sql\/transaction.cc:479\r\n#6  0x00000000005fdcbe in mysql_execute_command (thd=0x62637c0) at sql\/sql_parse.cc:3956\r\n#7  0x0000000000602478 in mysql_parse (thd=0x62637c0, rawbuf=0x7fb6e0004c90 \"ROLLBACK TO SAVEPOINT savepoint_1\", length=33, parser_state=0x7fb6ec5d0ae0) at sql\/sql_parse.cc:5805\r\n#8  0x00000000005f5fa1 in dispatch_command (command=COM_QUERY, thd=0x62637c0, packet=0x62fefe1 \"ROLLBACK TO SAVEPOINT savepoint_1\", packet_length=33) at sql\/sql_parse.cc:1060\r\n#9  0x00000000005f5240 in do_command (thd=0x62637c0) at sql\/sql_parse.cc:788\r\n#10 0x00000000006dbfc0 in do_handle_one_connection (thd_arg=0x62637c0) at sql\/sql_connect.cc:1409\r\n#11 0x00000000006dba77 in handle_one_connection (arg=0x62637c0) at sql\/sql_connect.cc:1315\r\n#12 0x0000003659e077e1 in start_thread () from \/lib64\/libpthread.so.0\r\n#13 0x0000003659ae68ed in clone () from \/lib64\/libc.so.6\r\n<\/pre>\n
\u95ee\u9898\u51fa\u73b0\u5728patch\u4e4b\u540e\u7684binlog_cache_data::truncate\u51fd\u6570\uff0c\u7531\u4e8e\u589e\u52a0\u4e86truncate_cached_file\uff08\u5728linux\u73af\u5883\u4e0b\u6700\u7ec8\u4f1a\u8c03\u7528ftruncate\uff09\uff0c\u5982\u679c\u4f20\u5165\u53c2\u6570pos\u5927\u4e8eIO_CACHE\u4e2d\u7684\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u5927\u5c0f\uff0c\u5219\u6587\u4ef6\u672b\u5c3e\u4f1a\u88ab\u586b\u51450\uff0c\u586b\u5145\u540e\u7684\u6587\u4ef6\u5927\u5c0f\u4e3apos\uff0c\u6b64\u65f6\u4e8b\u52a1\u5bf9\u5e94\u7684binlog cache\u5c31\u88ab\u5199\u810f\u6570\u636e\u4e86\uff0c\u539f\u56e0\u662fIO_CACHE\u7684\u5199\u5165\u7b56\u7565\u662f\uff1a\u5982\u679c\u5185\u5b58\u7f13\u51b2\u533a\u6709\u7a7a\u95f2\uff0c\u5199\u5230\u5185\u5b58\uff0c\u5185\u5b58\u7f13\u51b2\u533a\u5199\u6ee1\u540e\u5199\u56de\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\uff0c\u56e0\u6b64\u5b9e\u9645\u4e0a\u6574\u4e2abinlog cache\u7684\u5927\u5c0f\u4e3a\uff1a\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6+\u5185\u5b58\u7f13\u51b2\u533a\uff0c\u4ece\u83b7\u53d6IO_CACHE\u4e2d\u5f53\u524d\u6570\u636e\u5927\u5c0f\u7684\u5b8fmy_b_tell\u7684\u8ba1\u7b97\u65b9\u6cd5\u4e2d\u53ef\u4ee5\u770b\u51fa\u6765\uff0c\u56e0\u6b64\u5728\u5185\u5b58\u7f13\u51b2\u4e2d\u7684\u6570\u636e\u5237\u5230\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u4e4b\u524d\uff0c\u6574\u4e2a\u7f13\u51b2\u5176\u5b9e\u662f\u4e24\u90e8\u5206\uff0c\u53ea\u4e0d\u8fc7\u5bf9\u5916\u90e8\u8c03\u7528\u662f\u900f\u660e\u7684<\/p>\n
\u800c\u5b9e\u9645\u4e0a\uff0c\u53ea\u8981IO_CACHE\u4e2d\u7684\u5185\u5b58\u7f13\u51b2\u533a\u6709\u6570\u636e\u6ca1\u6709\u5237\u5230\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u4e2d\uff0c\u6b64\u65f6truncate_cached_file\u7684\u4f20\u5165\u53c2\u6570pos\u5c31\u4f1a\u5927\u4e8e\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u5927\u5c0f\uff0ctruncate_cached_file\u8c03\u7528\u7ed3\u675f\u540e\uff0cbinlog cache\u4e2d\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u548c\u5185\u5b58\u7f13\u51b2\u6587\u4ef6\u4e4b\u95f4\u88ab\u63d2\u5165\u4e86\u5f88\u591a0\uff0c\u6700\u7ec8\u4f1a\u5bfc\u81f4mysqld hang\uff0c\u7a0b\u5e8f\u8fdb\u5165\u4e86\u6b7b\u5faa\u73af\uff1a<\/p>\n
\r\nMYSQL_BIN_LOG::write_cache\r\n...\r\n      while (hdr_offs < length)\r\n      {\r\n        \/*\r\n          partial header only? save what we can get, process once\r\n          we get the rest.\r\n        *\/\r\n\r\n        if (hdr_offs + LOG_EVENT_HEADER_LEN > length)\r\n        {\r\n          carry= length - hdr_offs;\r\n          memcpy(header, (char *)cache->read_pos + hdr_offs, carry);\r\n          length= hdr_offs;\r\n        }\r\n        else\r\n        {\r\n          \/* we've got a full event-header, and it came in one piece *\/\r\n          uchar *log_pos= (uchar *)cache->read_pos + hdr_offs + LOG_POS_OFFSET;\r\n\r\n          \/* fix end_log_pos *\/\r\n          val= uint4korr(log_pos) + group;\r\n          int4store(log_pos, val);\r\n\r\n          \/* next event header at ... *\/\r\n          log_pos= (uchar *)cache->read_pos + hdr_offs + EVENT_LEN_OFFSET;\r\n          hdr_offs += uint4korr(log_pos);\r\n        }\r\n      }\r\n...\r\n<\/pre>\n
MySQL hang\u539f\u56e0<\/h3>\n
\u5c06IO_CACHE\u4e2d\u7684binlog cache\u5199\u5165\u5230binlog\u4e2d\u65f6\uff0c\u4f1a\u901a\u8fc7\u6bcf\u4e2abinlog event\u7684\u5934\u90e8\u6765\u83b7\u53d6binlog event\u7684\u957f\u5ea6\u7684\uff0c\u7531\u4e8ebinlog cache\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u672b\u5c3e\u88ab\u586b\u5145\u4e86\u5f88\u591a0\uff0c\u5bfc\u81f4while\u5faa\u73af\u65e0\u6cd5\u9000\u51fa\uff0c\u901a\u8fc7perf top\u53ef\u4ee5\u770b\u51faMYSQL_BIN_LOG::write_cache\u5360\u7528\u4e8696%\u7684cpu<\/p>\n
\r\n   samples  pcnt function                                            DSO\r\n   _______ _____ ___________________________________________________ _________________________________________________________________________________\r\n\r\n  14095.00 96.4% _ZN13MYSQL_BIN_LOG11write_cacheEP3THDP11st_io_cache \/u01\/mysql\/bin\/mysqld                                                            \r\n     61.00  0.4% find_busiest_group                                  [kernel.kallsyms]                                                                \r\n     42.00  0.3% _spin_lock                                          [kernel.kallsyms]                                                                \r\n     41.00  0.3% port_inb                                            \/lib\/modules\/2.6.32-220.17.1.tb619.el6.x86_64\/kernel\/drivers\/char\/ipmi\/ipmi_si.ko\r\n     36.00  0.2% sync_array_print_long_waits                         \/u01\/mysql\/bin\/mysqld                                                            \r\n     33.00  0.2% srv_lock_timeout_thread                             \/u01\/mysql\/bin\/mysqld \r\n<\/pre>\n
\u89e3\u51b3\u65b9\u6848<\/h3>\n
truncate_cached_file\u4e2d\uff0c\u5728\u5bf9cache file\u8fdb\u884ctruncate\u4e4b\u524d\uff0c\u5224\u65ad\u4f20\u5165\u53c2\u6570pos\u4e0e\u4e34\u65f6\u7f13\u51b2\u6587\u4ef6\u5927\u5c0f\u7684\u5173\u7cfb\uff0c\u53ea\u6709\u5f53pos\u5c0f\u4e8e\u6587\u4ef6\u5927\u5c0f\u65f6\u624d\u505aftruncate\u64cd\u4f5c\uff0c\u5b8c\u6574patch<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"
\u672c\u6587\u4ecb\u7ecdpercona\u4fee\u590d\u7684\u4e24\u4e2abinlog cache\u76f8\u5173\u7684bug\uff0cpercona bug#1162085  … \u7ee7\u7eed\u9605\u8bfbpercona bug#1162085, bug#1070856<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"jetpack_post_was_ever_published":false,"_jetpack_newsletter_access":"","_jetpack_dont_email_post_to_subs":false,"_jetpack_newsletter_tier_id":0,"_jetpack_memberships_contains_paywalled_content":false,"_jetpack_memberships_contains_paid_content":false,"footnotes":"","jetpack_publicize_message":"","jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":false,"jetpack_social_options":{"image_generator_settings":{"template":"highway","enabled":false}}},"categories":[1],"tags":[],"jetpack_publicize_connections":[],"jetpack_featured_media_url":"","jetpack_shortlink":"https:\/\/wp.me\/p3tPZp-1h","jetpack_sharing_enabled":true,"jetpack-related-posts":[],"_links":{"self":[{"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/posts\/79"}],"collection":[{"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=79"}],"version-history":[{"count":40,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/posts\/79\/revisions"}],"predecessor-version":[{"id":389,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=\/wp\/v2\/posts\/79\/revisions\/389"}],"wp:attachment":[{"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=79"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=79"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/www.gpfeng.com\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=79"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}