mysql 超长记录_谁记录了mysql error log中的超长信息(记pt-stalk一个bug的定位过程)...
【問題】
最近查看MySQL的error log文件時，發現有很多服務器的文件中有大量的如下日志，內容很長(大小在200K左右)，從記錄的內容看，并沒有明顯的異常信息。
有一臺測試服務器也有類似的問題，為什么會記錄這些信息，是誰記錄的這些信息，分析的過程比較周折。Status information:
Current dir:
Running threads: 2452? Stack size: 262144
Current locks:
lock: 0x7f783f5233f0:
Key caches:
default
Buffer_size:?????? 8388608
Block_size:?????????? 1024
Division_limit:??????? 100
Age_limit:???????????? 300
blocks used:??????????? 10
not flushed:???????????? 0
w_requests:?????????? 6619
writes:????????????????? 1
r_requests:???????? 275574
reads:??????????????? 1235
handler status:
read_key:?? 32241480828
read_next:? 451035381896
read_rnd???? 149361175
read_first:??? 1090473
write:????? 4838429521
delete??????? 12155820
update:???? 3331297842
【分析過程】
1、首先在官方文檔中查到，當mysqld進程收到SIGHUP信號量時，就會輸出類似的信息，
On Unix, signals can be sent to processes.mysqldresponds to signals sent to it as follows:
SIGHUPcauses the server to reload the grant tables and to flush tables, logs, the thread cache, and the host cache. These actions are like various forms of theFLUSHstatement. The server also writes a status report to the error log that has this format:
2、有別的程序在kill mysqld進程嗎，用systemtap腳本監控kill命令probe nd_syscall.kill
{
target[tid()] = uint_arg(1);
signal[tid()] = uint_arg(2);
}
probe nd_syscall.kill.return
{
if (target[tid()] != 0) {
printf("%-6d %-12s %-5d %-6d %6d\n", pid(), execname(),
signal[tid()], target[tid()], int_arg(1));
delete target[tid()];
delete signal[tid()];
}
}
用下面命令測試，確實會在error log中記錄日志kill -SIGHUP 12455
從systemtap的輸出看到12455就是mysqld進程，被kill掉了，信號量是1，對應的就是SIGHUP
不過在測試環境后面問題重現時，卻沒有抓到SIGHUP的信號量。
FROM?? COMMAND????? SIG?? TO???? RESULT
17010? who????????? 0???? 12153? 1340429600
36681? bash???????? 1???? 12455???? 642
3、看來并不是kill導致的，后面用gdb attach到mysqld進程上，在error log的三個入口函數sql_print_error，sql_print_warning，sql_print_information加上斷點
但是在問題重現時，程序并沒有停在斷點處
4、寫error log還有別的分支嗎，翻源碼找到了答案，原來是通過mysql_print_status函數直接寫到error log中void mysql_print_status()
{
char current_dir[FN_REFLEN];
STATUS_VAR current_global_status_var;
printf("\nStatus information:\n\n");
(void) my_getwd(current_dir, sizeof(current_dir),MYF(0));
printf("Current dir: %s\n", current_dir);
printf("Running threads: %u? Stack size: %ld\n",
Global_THD_manager::get_instance()->get_thd_count(),
(long) my_thread_stack_size);
…
puts("");
fflush(stdout);
}
5、再次用gdb attach到mysqld進程上，在mysql_print_status函數上加斷點，在問題重現時，線程停在斷點處，通過ps的結果多次對比，判斷是pt-stalk工具運行時調用了mysql_print_status
6、從堆棧中看到dispatch_command調用了mysql_print_status，下面是具體的邏輯，當command=COM_DEBUG時就會執行到mysql_print_statuscase COM_DEBUG:
thd->status_var.com_other++;
if (check_global_access(thd, SUPER_ACL))
break;??????????????? /* purecov: inspected */
mysql_print_status();
query_logger.general_log_print(thd, command, NullS);
my_eof(thd);
break;
7、查看pt-stalk的代碼
if [ "$mysql_error_log" -a ! "$OPT_MYSQL_ONLY" ]; then
log "The MySQL error log seems to be $mysql_error_log"
tail -f "$mysql_error_log" >"$d/$p-log_error" &
tail_error_log_pid=$!
$CMD_MYSQLADMIN $EXT_ARGV debug
else
log "Could not find the MySQL error log"
在調用mysqladmin時使用了debug模式
debug???????? Instruct server to write debug information to log
8、在percona官網上搜到了相關的bug描述，目前bug還未修復，會在下個版本中3.0.13中修復。
https://jira.percona.com/browse/PT-1340
【解決方案】
定位到問題后，實際修復也比較簡單，將pt-stalk腳本中$CMD_MYSQLADMIN $EXT_ARGV debug中的debug去掉就可以了，測試生效。
創作挑戰賽新人創作獎勵來咯，堅持創作打卡瓜分現金大獎總結
以上是生活随笔為你收集整理的mysql 超长记录_谁记录了mysql error log中的超长信息(记pt-stalk一个bug的定位过程)...的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： laravel mysql 锁表_Lar
- 下一篇： mysql mycat one_Myca