Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-13135

Very large console logs will cause Jenkins to crash or behave erratically

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Incomplete
    • Icon: Major Major
    • core
    • None

      When console logs are exceptionally large (due to user parameters we've had a 3Gb log go through at some point), and somebody tries to view this log, Jenkins will throw an exception there, and may also deny allocations to other threads - side effects being disconnected slave nodes, jobs failing to finish up correctly.

      Exception from catalina log:

      Mar 16, 2012 4:45:30 PM hudson.ExpressionFactory2$JexlExpression evaluate
      WARNING: Caught exception evaluating: item.why. Reason: java.lang.reflect.InvocationTargetException
      java.lang.reflect.InvocationTargetException
              at sun.reflect.GeneratedMethodAccessor321.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              at java.lang.reflect.Method.invoke(Method.java:597)
              at org.apache.commons.jexl.util.PropertyExecutor.execute(PropertyExecutor.java:125)
              at org.apache.commons.jexl.util.introspection.UberspectImpl$VelGetterImpl.invoke(UberspectImpl.java:314)
              at org.apache.commons.jexl.parser.ASTArrayAccess.evaluateExpr(ASTArrayAccess.java:185)
              at org.apache.commons.jexl.parser.ASTIdentifier.execute(ASTIdentifier.java:75)
              at org.apache.commons.jexl.parser.ASTReference.execute(ASTReference.java:83)
              at org.apache.commons.jexl.parser.ASTReference.value(ASTReference.java:57)
              at org.apache.commons.jexl.parser.ASTReferenceExpression.value(ASTReferenceExpression.java:51)
              at org.apache.commons.jexl.ExpressionImpl.evaluate(ExpressionImpl.java:80)
              at hudson.ExpressionFactory2$JexlExpression.evaluate(ExpressionFactory2.java:72)
              at org.apache.commons.jelly.expression.ExpressionSupport.evaluateRecurse(ExpressionSupport.java:61)
              at org.apache.commons.jelly.expression.ExpressionSupport.evaluateAsString(ExpressionSupport.java:46)
              at org.apache.commons.jelly.expression.CompositeExpression.evaluateAsString(CompositeExpression.java:256)
              at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.buildAttributes(ReallyStaticTagLibrary.java:111)
              at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:95)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.ForEachTag.doTag(ForEachTag.java:150)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.OtherwiseTag.doTag(OtherwiseTag.java:41)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.kohsuke.stapler.jelly.CallTagLibScript$1.run(CallTagLibScript.java:98)
              at org.apache.commons.jelly.tags.define.InvokeBodyTag.doTag(InvokeBodyTag.java:91)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)
              at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:119)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)
              at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:119)
              at org.kohsuke.stapler.jelly.CallTagLibScript$1.run(CallTagLibScript.java:98)
              at org.apache.commons.jelly.tags.define.InvokeBodyTag.doTag(InvokeBodyTag.java:91)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.OtherwiseTag.doTag(OtherwiseTag.java:41)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)
              at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:119)
              at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)
              at org.kohsuke.stapler.jelly.JellyViewScript.run(JellyViewScript.java:63)
              at org.kohsuke.stapler.jelly.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:63)
              at org.kohsuke.stapler.jelly.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:53)
              at org.kohsuke.stapler.jelly.JellyFacet$1.dispatch(JellyFacet.java:92)
              at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:561)
              at org.kohsuke.stapler.Stapler.invoke(Stapler.java:646)
              at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:612)
              at org.kohsuke.stapler.Stapler.invoke(Stapler.java:646)
              at org.kohsuke.stapler.Stapler.invoke(Stapler.java:477)
              at org.kohsuke.stapler.Stapler.service(Stapler.java:159)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:94)
              at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:185)
              at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:159)
              at net.bull.javamelody.PluginMonitoringFilter.doFilter(PluginMonitoringFilter.java:86)
              at org.jvnet.hudson.plugins.monitoring.HudsonMonitoringFilter.doFilter(HudsonMonitoringFilter.java:84)
              at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:97)
              at hudson.plugins.greenballs.GreenBallFilter.doFilter(GreenBallFilter.java:74)
              at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:97)
              at hudson.plugins.audit_trail.AuditTrailFilter.doFilter(AuditTrailFilter.java:66)
              at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:97)
              at hudson.util.PluginServletFilter.doFilter(PluginServletFilter.java:86)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at hudson.security.csrf.CrumbFilter.doFilter(CrumbFilter.java:47)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:84)
              at hudson.security.UnwrapSecurityExceptionFilter.doFilter(UnwrapSecurityExceptionFilter.java:51)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.ui.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:166)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.ui.rememberme.RememberMeProcessingFilter.doFilter(RememberMeProcessingFilter.java:142)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:271)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.ui.basicauth.BasicProcessingFilter.doFilter(BasicProcessingFilter.java:173)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:249)
              at hudson.security.HttpSessionContextIntegrationFilter2.doFilter(HttpSessionContextIntegrationFilter2.java:66)
              at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
              at hudson.security.ChainedServletFilter.doFilter(ChainedServletFilter.java:76)
              at hudson.security.HudsonFilter.doFilter(HudsonFilter.java:164)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at hudson.util.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:81)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
              at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:433)
              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
              at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:859)
              at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:574)
              at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1527)
              at java.lang.Thread.run(Thread.java:619)
      Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
              at java.util.Arrays.copyOfRange(Arrays.java:3209)
              at java.lang.String.<init>(String.java:215)
              at java.lang.StringBuilder.toString(StringBuilder.java:430)
              at hudson.model.Run.getUrl(Run.java:784)
              at sun.reflect.GeneratedMethodAccessor142.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              at java.lang.reflect.Method.invoke(Method.java:597)
              at org.apache.commons.jexl.util.PropertyExecutor.execute(PropertyExecutor.java:125)
              at org.apache.commons.jexl.util.introspection.UberspectImpl$VelGetterImpl.invoke(UberspectImpl.java:314)
              at org.apache.commons.jexl.parser.ASTArrayAccess.evaluateExpr(ASTArrayAccess.java:185)
              at org.apache.commons.jexl.parser.ASTIdentifier.execute(ASTIdentifier.java:75)
              at org.apache.commons.jexl.parser.ASTReference.execute(ASTReference.java:83)
              at org.apache.commons.jexl.parser.ASTReference.value(ASTReference.java:57)
              at org.apache.commons.jexl.parser.ASTReferenceExpression.value(ASTReferenceExpression.java:51)
              at org.apache.commons.jexl.ExpressionImpl.evaluate(ExpressionImpl.java:80)
              at hudson.ExpressionFactory2$JexlExpression.evaluate(ExpressionFactory2.java:72)
              at org.apache.commons.jelly.expression.ExpressionSupport.evaluateRecurse(ExpressionSupport.java:61)
              at org.apache.commons.jelly.expression.ExpressionSupport.evaluateAsString(ExpressionSupport.java:46)
              at org.apache.commons.jelly.expression.CompositeExpression.evaluateAsString(CompositeExpression.java:256)
              at org.apache.commons.jelly.expression.CompositeExpression.evaluate(CompositeExpression.java:248)
              at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:58)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)
              at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:119)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.WhenTag.doTag(WhenTag.java:46)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
              at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)
              at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)
              at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38)
              at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:270)
      

      This occurred twice (the user tried to refresh the browser to view the raw log when it failed the first time). Following this:

      Mar 16, 2012 4:45:33 PM hudson.remoting.Channel$ReaderThread run
      SEVERE: I/O error in channel platform_test_slave_hudsonmaster1
      java.io.IOException: Unexpected termination of the channel
              at hudson.remoting.Channel$ReaderThread.run(Channel.java:1037)
      Caused by: java.io.EOFException
              at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2554)
              at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1297)
              at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
              at hudson.remoting.Channel$ReaderThread.run(Channel.java:1031)
      Mar 16, 2012 4:45:36 PM hudson.remoting.ProxyOutputStream$Chunk$1 run
      WARNING: Failed to ack the stream
      java.io.IOException: SSH channel is closed. (Close requested by remote)
              at com.trilead.ssh2.channel.ChannelManager.sendData(ChannelManager.java:383)
              at com.trilead.ssh2.channel.ChannelOutputStream.write(ChannelOutputStream.java:63)
              at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1838)
              at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1747)
              at java.io.ObjectOutputStream.writeNonProxyDesc(ObjectOutputStream.java:1249)
              at java.io.ObjectOutputStream.writeClassDesc(ObjectOutputStream.java:1203)
              at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1387)
              at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150)
              at java.io.ObjectOutputStream.writeFatalException(ObjectOutputStream.java:1538)
              at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:329)
              at hudson.remoting.Channel.send(Channel.java:491)
              at hudson.remoting.ProxyOutputStream$Chunk$1.run(ProxyOutputStream.java:226)
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
              at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
              at java.util.concurrent.FutureTask.run(FutureTask.java:138)
              at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
              at java.lang.Thread.run(Thread.java:619)
      
      Mar 16, 2012 4:45:53 PM hudson.model.AbstractBuild$AbstractRunner performAllBuildSteps
      WARNING: Publisher hudson.tasks.junit.JUnitResultArchiver aborted due to exception
      java.lang.NullPointerException
              at hudson.tasks.junit.JUnitParser.parse(JUnitParser.java:83)
              at hudson.tasks.junit.JUnitResultArchiver.parse(JUnitResultArchiver.java:123)
              at hudson.tasks.junit.JUnitResultArchiver.perform(JUnitResultArchiver.java:135)
              at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
              at hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:682)
              at hudson.model.AbstractBuild$AbstractRunner.performAllBuildSteps(AbstractBuild.java:657)
              at hudson.model.AbstractBuild$AbstractRunner.performAllBuildSteps(AbstractBuild.java:635)
              at hudson.model.Build$RunnerImpl.post2(Build.java:161)
              at hudson.model.AbstractBuild$AbstractRunner.post(AbstractBuild.java:604)
              at hudson.model.Run.run(Run.java:1400)
              at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
              at hudson.model.ResourceController.execute(ResourceController.java:88)
              at hudson.model.Executor.run(Executor.java:175)
      Mar 16, 2012 4:46:38 PM hudson.slaves.SlaveComputer tryReconnect
      INFO: Attempting to reconnect platform_test_slave_hudsonmaster1
      Mar 16, 2012 4:47:51 PM hudson.remoting.Channel$ReaderThread run
      SEVERE: I/O error in channel platform_test_slave_hudsonmaster1
      java.io.IOException: Unexpected termination of the channel
              at hudson.remoting.Channel$ReaderThread.run(Channel.java:1037)
      Caused by: java.io.EOFException
              at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2554)
              at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1297)
              at java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
              at hudson.remoting.Channel$ReaderThread.run(Channel.java:1031)
      Mar 16, 2012 4:48:12 PM hudson.slaves.SlaveComputer tryReconnect
      INFO: Attempting to reconnect platform_test_slave_hudsonmaster1
      

            Unassigned Unassigned
            dannystaple Danny Staple
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: