这几天有个Java Web 项目,跑着跑着,tomcat就假死了,用Jstack PID 打印堆栈信息,发现大量的线程处于blocked状态。下图就是其中一个blocked线程.其它blocked线程报错内容和下图类似。
"http-bio-8080-exec-34" daemon prio=6 tid=0x042b4c00 nid=0x17b8 waiting for monitor entry [0x093af000..0x093afae8]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.io.PrintStream.println(PrintStream.java:756)
- waiting to lock <0x23c04208> (a java.io.PrintStream)
at org.apache.tomcat.util.log.SystemLogHandler.println(SystemLogHandler.java:264)
at com.security.MyUsernamePasswordAuthenticationFilter.attemptAuthentication(MyUsernamePasswordAuthenticationFilter.java:33)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199)
...........
我定位到MyUsernamePasswordAuthenticationFilter.java:33行发现此处使用了System.out.println(),查看println()源码,发现System.out.println()方法是synchronized方法,也就是说可能是System.out.println()这个同步方法造成了死锁。
然而我查看了整个堆栈信息,也没发现有2个线程相互等待锁(业务代码中这一块也没有用线程同步,应该不是业务代码造成的死锁),那么死锁是如何发生的呢?
我找到最后一个处于RUNNABLE状态的线程,如下图:
"http-bio-8080-exec-13" daemon prio=6 tid=0x04ccc000 nid=0x22a0 runnable [0x0583d000..0x0583fae8]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:260)
at java.io.BufferedOutputStream.write(BufferedOutputStream.java:105)
- locked <0x23c0ab18> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:430)
- locked <0x23c04208> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:85)
- locked <0x23c0ab58> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:168)
at java.io.PrintStream.write(PrintStream.java:477)
- locked <0x23c04208> (a java.io.PrintStream)
at java.io.PrintStream.print(PrintStream.java:619)
at java.io.PrintStream.println(PrintStream.java:756)
- locked <0x23c04208> (a java.io.PrintStream)
at org.apache.tomcat.util.log.SystemLogHandler.println(SystemLogHandler.java:264)
at com.energy.web.EnergyAction.findRealtimeEnergyDataByEquipmentName(EnergyAction.java:60)
at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:452)
at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:291)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:254)
at com.opensymphony.xwork2.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:176)
at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:98)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:248)
at com.opensymphony.xwork2.validator.ValidationInterceptor.doIntercept(ValidationInterceptor.java:263)
..............
这个“”http-bio-8080-exec-13“”线程,获取了锁locked <0x23c04208> (a java.io.PrintStream),但是没有释放它...为什么不释放呢?求大神解释下原因。堆栈中有sun.nio,死锁是否和nio有关(只是我的猜测)
还有个问题,从堆栈信息中可以看出,在tomcat 中调用System.out.println,println被定向到了org.apache.tomcat.util.log.SystemLogHandler.println(SystemLogHandler.java:264),这是否说明java 的system.out.println被tomcat的SystemLogHandler接管了呢?
求有经验的Java大牛帮忙看看
新手们写代码,总避免不了习惯性使用System.out.println,我只是不懂为何System.out.println会造成死锁
打日志用sytem.out.println,涨姿势了.
回复 @不日小鸡:都说是新手了....就不要纠结这个了。我们项目中配了日志框架,可是新加入的同学总是习惯性的用System.out.println。问题不是为什么会用System.out.println,而是为什么tomcat会假死...回复 @ZhangFinder:你这个当然,我就表示呵呵了打印日志当然用log4j,我只是不明白为何system.out.println会死锁...你这个是IO阻塞了吧
"http-bio-8080-exec-13"daemonprio=6tid=0x04ccc000nid=0x22a0runnable[0x0583d000..0x0583fae8]java.lang.Thread.State:RUNNABLE
看看这个线程在做啥,从栈信息来看,
java.lang.Thread.State:RUNNABLEatjava.io.FileOutputStream.writeBytes(NativeMethod)atjava.io.FileOutputStream.write(FileOutputStream.java:260)atjava.io.BufferedOutputStream.write(BufferedOutputStream.java:105)-locked<0x23c0ab18>(ajava.io.BufferedOutputStream)atjava.io.PrintStream.write(PrintStream.java:430)
应该是在写文件,写文件怎么会用到java.io.PrintStream对象呢,是不是初始化为printStream给OutputStream了,结合上下文看看
我检查了上下文,上下文除了System.out.println就没有其他IO操作了。这里很奇怪,为什么会出现NIO"http-bio-8080-exec-13"daemonprio=6tid=0x04ccc000nid=0x22a0runnable[0x0583d000..0x0583fae8]java.lang.Thread.State:RUNNABLE
看看这个线程在做啥,从栈信息来看,
java.lang.Thread.State:RUNNABLEatjava.io.FileOutputStream.writeBytes(NativeMethod)atjava.io.FileOutputStream.write(FileOutputStream.java:260)atjava.io.BufferedOutputStream.write(BufferedOutputStream.java:105)-locked<0x23c0ab18>(ajava.io.BufferedOutputStream)atjava.io.PrintStream.write(PrintStream.java:430)
应该是在写文件,写文件怎么会用到java.io.PrintStream对象呢,是不是初始化为printStream给OutputStream了,结合上下文看看
多线程打印sytem.out.println是没问题的,这个死锁感觉按道理不会成立才对。。。
刚刚在CSDN上发现有个人遇到了和我类似的问题,但是没有人给出解决方案:http://bbs.csdn.net/topics/390954714?page=1
catalina文件太大了,flush的时候阻塞了吧;
cmd窗口我就遇过卡死,就是阻塞,程序不走了,应该不是死锁
catalina.out是一个tomcat下所有app公用的日志文件,会不会是有别的程序抢占不放而导致其它程序一直等待呢
版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。