记录一个__lll_lock_wait_private错误
2014-05-28 10:12
351 查看
一个DBA同事昨天在执行一个命令行工具的时候发现程序hang住,问题挺有意思,值得记录下。
首先用pstack看了下程序的调用栈,这是个多线程程序,pstack结果看到几乎所有的线程都等在write调用上。如下是pt-pmp的输出结果:
直觉上觉得是磁盘空间满了,让他看了下,磁盘空间还很富裕,touch创建文件也没任何问题,当时此机器上还在跑一个备份程序,IO压力不小,不过和问题本身应该关系不大。Google了下__lll_lock_wait_private这个错误,也没任何有用的信息。这个工具程序本身会向一个命令行指定的日志文件输出很多程序执行结果,同时会向stderr输出程序的执行状态,gdb attach看了下程序具体的调用栈,发现程序都阻塞在fprintf(stderr)上。咨询了下同事,他使用这个工具是通过一个python脚本调用的,调用的程序类似如下:
cmd是调用程序的命令行,包括一系列选项。问题看起来很清晰了,通过python调用此命令行工具时,stdout和stderr都被重定向了subprocess.PIPE,但没有程序从此PIPE读取,那么很快这个PIPE自身的buffer都写满了,pstack看到的结果就是所有write都阻塞。
写了个小程序重现了下,程序如下(随手写的..):
调用的python脚本如下:
执行此python脚本,会发现很快a.out就被hang住了,表现是/tmp/log不再有新的输出,程序调用栈如下:
解决此问题,1)maybe subprocess.Popen这个程序参数可以改改?2)或者在cmd里边将stdout/stderr都重定向掉;3)写命令行程序的时候要注意,调用的脚本各种写法都可能有,因此写日志尽量还是要规范,不要向stdout/stderr输出过多的东西。
组里开发的同事补充了下MySQL遇到__lll_lock_wait_private 错误的常见场景:
"这个函数调用在mysql上最典型的场景就是开启cgroup时会经常碰到这个,例如memcpy, mem alloc, free , mutext lock/unlock...."
首先用pstack看了下程序的调用栈,这是个多线程程序,pstack结果看到几乎所有的线程都等在write调用上。如下是pt-pmp的输出结果:
Tue May 27 18:30:06 CST 2014 55 __lll_lock_wait_private,_L_lock_51,fwrite,LoadConsumer::run,CThread::hook,start_thread,clone 1 write,_IO_new_file_write,_IO_new_file_xsputn,buffered_vfprintf,vfprintf,fprintf,LoadManager::dump,LoadProducer::load_file,LoadProducer::run,CThread::hook,start_thread,clone
直觉上觉得是磁盘空间满了,让他看了下,磁盘空间还很富裕,touch创建文件也没任何问题,当时此机器上还在跑一个备份程序,IO压力不小,不过和问题本身应该关系不大。Google了下__lll_lock_wait_private这个错误,也没任何有用的信息。这个工具程序本身会向一个命令行指定的日志文件输出很多程序执行结果,同时会向stderr输出程序的执行状态,gdb attach看了下程序具体的调用栈,发现程序都阻塞在fprintf(stderr)上。咨询了下同事,他使用这个工具是通过一个python脚本调用的,调用的程序类似如下:
p = subprocess.Popen(cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,close_fds=True)
cmd是调用程序的命令行,包括一系列选项。问题看起来很清晰了,通过python调用此命令行工具时,stdout和stderr都被重定向了subprocess.PIPE,但没有程序从此PIPE读取,那么很快这个PIPE自身的buffer都写满了,pstack看到的结果就是所有write都阻塞。
写了个小程序重现了下,程序如下(随手写的..):
1 #include <stdio.h> 2 #include <pthread.h> 3 #include <unistd.h> 4 void *thr_fn(void *arg) 5 { 6 int i =0; 7 while(true) 8 { 9 i++; 10 fprintf(stderr, "helloworld %d\t\t\t\t",i); 11 fprintf(stdout, "kkkkkkkkkk %d\t\t\t\t",i); 12 sleep(1); 13 } 14 } 15 16 int main(void) 17 { 18 for (int i = 0; i!= 50; i++) 19 { 20 pthread_t tid; 21 pthread_create(&tid, NULL, thr_fn, NULL); 22 } 23 24 sleep(100000); 25 }
调用的python脚本如下:
1 import subprocess 2 import os 3 import time 4 5 ret = {} 6 7 cmd = "./a.out >/tmp/log" 8 9 p = subprocess.Popen(cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,close_fds=True) 10 11 ret['status'] = p.wait() 12 ret['msg'] = p.stdout.readlines() 13 14 time.sleep(100000000);
执行此python脚本,会发现很快a.out就被hang住了,表现是/tmp/log不再有新的输出,程序调用栈如下:
49 __lll_lock_wait_private,_L_lock_12956,buffered_vfprintf,vfprintf,fprintf,thr_fn,start_thread,clone 1 write,_IO_new_file_write,_IO_new_file_xsputn,buffered_vfprintf,vfprintf,fprintf,thr_fn,start_thread,clone 1 nanosleep,sleep,main
解决此问题,1)maybe subprocess.Popen这个程序参数可以改改?2)或者在cmd里边将stdout/stderr都重定向掉;3)写命令行程序的时候要注意,调用的脚本各种写法都可能有,因此写日志尽量还是要规范,不要向stdout/stderr输出过多的东西。
组里开发的同事补充了下MySQL遇到__lll_lock_wait_private 错误的常见场景:
"这个函数调用在mysql上最典型的场景就是开启cgroup时会经常碰到这个,例如memcpy, mem alloc, free , mutext lock/unlock...."
相关文章推荐
- __lll_mutex_lock_wait的错误原因
- java写循环,犯了一个小错误,记录下来以鞭策
- SSAS实践问题记录--后端数据库访问模块中存在错误。 为绑定指定的大小太小,导致一个或多个列值被截断。
- 记录一个原因不明的段错误(libxml2 proc activemq的三角恋)
- mysql错误: Lock wait timeout exceeded; try restarting transaction
- Mysql出现“ Lock wait timeout exceeded; try restarting transaction”错误
- __lll_mutex_lock_wait出现的分析
- 遇到一个android错误,记录一下
- 记录一个思路 错误【消息: 'NTES.one(...)' 为空或不是对象 】Chrome没事,ie等内核浏览器报错
- 一个小错误,记录一下
- 记录一个惨绝人寰的错误(cocos2dx解决方案内工程之间的连接错误)
- 一个GDI资源泄漏的错误 记录下来 以后用的到
- 【记录】导致notifyDataSetChanged无效的一个错误
- 还是犯了一个优先级的错误_sql,记录下,提醒自己
- 记录一个原因不明的段错误(libxml2 proc activemq的三角恋)
- 安装使用MySQL时一个典型错误的解决、临时记录下
- __lll_mutex_lock_wait
- 实现一个lockfree的队列——错误修改
- 一辈子都难遇见的一个Exception啊,具体错误信息已经记录下来,忙过这段时间后就着手分析了
- 对一个长度为100000条指令的程序进行集成测试期间记录如下面的数据: (A)7月1日集成测试开始没有发现错误 (B)8月2日总共改正了100个错误,此时MTTF=0.4H (C)9月1日:总共改正3