记一次jvm crash

昨天下午4:30,系统发生了有史以来最刺激的崩溃,一开始是2台挂了(线上共5台),这个基本上很少见,一般情况下都是偶尔一台挂掉。

赶紧手动重启,搞笑的是重启起来的机器里马也挂了,结果就出现了一种尴尬的局面,我们不停的重启,机器不断地报警,不断地挂,整个过程持续了20多分钟。


其实上个礼拜系统就挂过两次,第1次挂了无任何信息没有出现常见的hs*.log这样的jvm crash日志,cpu、内存、流量等指标也没有异常,打算打开ulimit -c 获取系统core,还没弄上去第二次crash又发生了,于是把所有能看得日志都查了一遍,也在/var/log/messages中找到了

"Jul510:25:46cms-web1kernel:java[24016]:segfaultat00000000457ebd28rip00002aaab75a35cdrsp00000000457ebd10error6"

臭名昭著的segfault出现了,于是赶紧在每台机器加上了ulimit -c unlimited


20分钟的忙碌终于过去了,于是赶紧分析core日志

gdb java core-java-**.log

看到重要信息

Corewasgeneratedby`/usr/xx/java/bin/java-Dprogram.name=run.sh-server-Xmx2g-Xms2g-Xmn512m'.

Programterminatedwithsignal11,Segmentationfault.


接下来通过gdb的bt看栈信息

(gdb)bt
#00x00002aaab6cc75cdinJava_java_net_SocketOutputStream_socketWrite0()from/usr/xx/install/jdk1.6.0_25/jre/lib/amd64/libnet.so
#10x00002aaaab041b0cin??()
#20x0000000000000000in??()


只能看到最后在访问网络的时候挂了,但栈信息太少了


于是通过jstack/path/to/javacoredumpfile 终于看到了有用的信息

Thread26089:(state=IN_NATIVE)

-java.net.SocketOutputStream.socketWrite0(java.io.FileDescriptor,byte[],int,int)@bci=0(Interpretedframe)

-java.net.SocketOutputStream.socketWrite(byte[],int,int)@bci=44,line=92(Interpretedframe)

-java.net.SocketOutputStream.write(byte[],int,int)@bci=4,line=136(Interpretedframe)

-oracle.net.ns.DataPacket.send(int)@bci=50(Interpretedframe)

-oracle.net.ns.NetOutputStream.flush()@bci=15(Interpretedframe)

-oracle.net.ns.NetInputStream.getNextPacket()@bci=41(Interpretedframe)

-oracle.net.ns.NetInputStream.read(byte[],int,int)@bci=33(Compiledframe)

-oracle.net.ns.NetInputStream.read(byte[])@bci=5(Compiledframe)

-oracle.net.ns.NetInputStream.read()@bci=5(Compiledframe)

-oracle.jdbc.driver.T4CMAREngine.unmarshalUB1()@bci=6,line=1099(Compiledframe)

-oracle.jdbc.driver.T4CMAREngine.unmarshalSB1()@bci=1,line=1070(Interpretedframe)

-oracle.jdbc.driver.T4C8Oall.receive()@bci=52,line=478(Interpretedframe)

-oracle.jdbc.driver.T4CPreparedStatement.doOall8(boolean,boolean,boolean,boolean)@bci=619,line=216(Interpretedframe)

-oracle.jdbc.driver.T4CPreparedStatement.executeForRows(boolean)@bci=16,line=955(Interpretedframe)

-oracle.jdbc.driver.OracleStatement.executeMaybeDescribe()@bci=154,line=1060(Interpretedframe)

-oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe()@bci=11,line=839(Interpretedframe)

-oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout()@bci=132,line=1132(Interpretedframe)

-oracle.jdbc.driver.OraclePreparedStatement.executeInternal()@bci=94,line=3316(Interpretedframe)

-oracle.jdbc.driver.OraclePreparedStatement.executeQuery()@bci=17,line=3361(Interpretedframe)

-com.xx.druid.filter.FilterChainImpl.preparedStatement_executeQuery(com.xx.druid.proxy.jdbc.PreparedStatementProxy)@bci=29,line=2564(Interpretedframe)

-com.xx.druid.filter.FilterAdapter.preparedStatement_executeQuery(com.xx.druid.filter.FilterChain,com.xx.druid.proxy.jdbc.PreparedStatementProxy)@bci=2,line=931(Interpretedframe)

-com.xx.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(com.xx.druid.filter.FilterChain,com.xx.druid.proxy.jdbc.PreparedStatementProxy)@bci=14,line=459(Interpretedframe)

-com.xx.druid.filter.FilterChainImpl.preparedStatement_executeQuery(com.xx.druid.proxy.jdbc.PreparedStatementProxy)@bci=17,line=2561(Interpretedframe)

-com.xx.druid.proxy.jdbc.PreparedStatementProxyImpl.executeQuery()@bci=5,line=83(Interpretedframe)

-org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeQuery()@bci=4,line=90(Interpretedframe)

-org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery()@bci=12,line=236(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.resourceloader.PreviewTemplateResourceLoader.getResourceStream(java.lang.String)@bci=80,line=65(Interpretedframe)

-org.apache.velocity.Template.process()@bci=20,line=98(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.resourceloader.PreviewResourceManagerImpl.loadResource(java.lang.String,int,java.lang.String)@bci=115,line=116(Interpretedframe)

-org.apache.velocity.runtime.resource.ResourceManagerImpl.getResource(java.lang.String,int,java.lang.String)@bci=132,line=354(Interpretedframe)

-org.apache.velocity.runtime.RuntimeInstance.getTemplate(java.lang.String,java.lang.String)@bci=11,line=1400(Interpretedframe)

-org.apache.velocity.runtime.RuntimeInstance.getTemplate(java.lang.String)@bci=6,line=1380(Interpretedframe)

-org.apache.velocity.app.VelocityEngine.getTemplate(java.lang.String)@bci=5,line=401(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.mergeTemplate(org.apache.velocity.context.Context,java.lang.String,int)@bci=15,line=415(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.previewTemplate(java.util.Map,java.lang.String,int)@bci=13,line=310(Interpretedframe)

-com.xx.china.cmshollywood.cms.biz.tdprender.OfferRender.getOfferAndTradeInfoByOfferIds(java.lang.String,java.lang.String,java.lang.String,java.lang.String)@bci=129,line=275(Interpretedframe)

-sun.reflect.GeneratedMethodAccessor283.invoke(java.lang.Object,java.lang.Object[])@bci=64(Interpretedframe)

-sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object,java.lang.Object[])@bci=6,line=25(Compiledframe)

-java.lang.reflect.Method.invoke(java.lang.Object,java.lang.Object[])@bci=161,line=597(Compiledframe)

-org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(java.lang.Object,java.lang.Object[])@bci=6,line=389(Interpretedframe)

-org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(java.lang.Object,java.lang.Object[])@bci=66,line=378(Interpretedframe)

-org.apache.velocity.runtime.parser.node.ASTMethod.execute(java.lang.Object,org.apache.velocity.context.InternalContextAdapter)@bci=449,line=270(Interpretedframe)

-org.apache.velocity.runtime.parser.node.ASTReference.execute(java.lang.Object,org.apache.velocity.context.InternalContextAdapter)@bci=192,line=252(Compiledframe)

-org.apache.velocity.runtime.parser.node.ASTReference.render(org.apache.velocity.context.InternalContextAdapter,java.io.Writer)@bci=30,line=332(Interpretedframe)

-org.apache.velocity.runtime.parser.node.SimpleNode.render(org.apache.velocity.context.InternalContextAdapter,java.io.Writer)@bci=21,line=336(Interpretedframe)

-org.apache.velocity.Template.merge(org.apache.velocity.context.Context,java.io.Writer,java.util.List)@bci=251,line=328(Interpretedframe)

-org.apache.velocity.Template.merge(org.apache.velocity.context.Context,java.io.Writer)@bci=4,line=235(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.mergeTemplate(org.apache.velocity.context.Context,java.lang.String,int)@bci=25,line=416(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.previewTemplate(java.util.Map,java.lang.String,int)@bci=13,line=310(Interpretedframe)

-com.xx.china.cmshollywood.cms.biz.tdprender.OfferRender.getOfferAndTradeInfoByOfferIds(java.lang.String,java.lang.String,java.lang.String,java.lang.String)@bci=129,line=275(Interpretedframe)

-sun.reflect.GeneratedMethodAccessor283.invoke(java.lang.Object,java.lang.Object[])@bci=64(Interpretedframe)

-sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object,java.lang.Object[])@bci=6,line=25(Compiledframe)

-java.lang.reflect.Method.invoke(java.lang.Object,java.lang.Object[])@bci=161,line=597(Compiledframe)

-org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(java.lang.Object,java.lang.Object[])@bci=6,line=389(Interpretedframe)

-org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(java.lang.Object,java.lang.Object[])@bci=66,line=378(Interpretedframe)

-org.apache.velocity.runtime.parser.node.ASTMethod.execute(java.lang.Object,org.apache.velocity.context.InternalContextAdapter)@bci=449,line=270(Interpretedframe)

-org.apache.velocity.runtime.parser.node.ASTReference.execute(java.lang.Object,org.apache.velocity.context.InternalContextAdapter)@bci=192,line=252(Compiledframe)

-org.apache.velocity.runtime.parser.node.ASTReference.render(org.apache.velocity.context.InternalContextAdapter,java.io.Writer)@bci=30,line=332(Interpretedframe)

-org.apache.velocity.runtime.parser.node.SimpleNode.render(org.apache.velocity.context.InternalContextAdapter,java.io.Writer)@bci=21,line=336(Interpretedframe)

-org.apache.velocity.Template.merge(org.apache.velocity.context.Context,java.io.Writer,java.util.List)@bci=251,line=328(Interpretedframe)

-org.apache.velocity.Template.merge(org.apache.velocity.context.Context,java.io.Writer)@bci=4,line=235(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.mergeTemplate(org.apache.velocity.context.Context,java.lang.String,int)@bci=25,line=416(Interpretedframe)

-com.xx.china.cmshollywood.cms.engine.DefaultVelocityTemplateEngine.previewTemplate(java.util.Map,java.lang.String,int)@bci=13,line=310(Interpretedframe)

-com.xx.china.cmshollywood.cms.biz.tdprender.OfferRender.getOfferAndTradeInfoByOfferIds(java.lang.String,java.lang.String,java.lang.String,java.lang.String)@bci=129,line=275(Interpretedframe)

............



标绿的这段代码执行了101次,整个栈的长度到1500层,看上去是进入一个循环递归的过程,导致最后栈溢出挂掉


于是接下来开始查找代码,发现了问题

在一个velocity的模板a.vm中写了一段代码$xxmethod("a.vm","params")

这个方法会获取数据在渲染a.vm,于是造成了死循环​,这个死循环连jvm都未感知到就被操作系统给终结了


小结

  • 看起来velocity必须小心使用
  • 获取core日志也是必须的,否则没那么容易定位问题
  • 系统挂的时候在访问网络,这个会让人误解为在访问网络出了什么问题(虽然很多时候都是挂的时候的最后那个方法出了问题),其实此时只是系统在常规的压栈,但碰巧在这个时候,栈溢出了




  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值