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

IOException in FileLogStorage maybeFlush

    Details

    • Similar Issues:

      Description

      Some jobs get stuck in a state where they're unable to continue to write data to the console log.  The system log contains multiple entries of the following form until the job ends:

       

      failed to flush /net/users/jenkins/configuration/jobs/XXX/builds/5/log
      java.io.IOException: Stream Closed
      at java.io.FileOutputStream.writeBytes(Native Method)
      at java.io.FileOutputStream.write(FileOutputStream.java:326)
      at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:134)
      at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
      at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
      at java.io.FilterOutputStream.flush(FilterOutputStream.java:140)
      at org.jenkinsci.plugins.workflow.log.FileLogStorage.maybeFlush(FileLogStorage.java:190)
      at org.jenkinsci.plugins.workflow.log.FileLogStorage.overallLog(FileLogStorage.java:198)
      at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogText(WorkflowRun.java:1018)
      at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogInputStream(WorkflowRun.java:1026)
      at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.notLogged(GenericWebhookEnvironmentContributor.java:54)
      at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.buildEnvironmentFor(GenericWebhookEnvironmentContributor.java:30)
      at hudson.model.Run.getEnvironment(Run.java:2373)
      at org.jenkinsci.plugins.workflow.job.WorkflowRun.getEnvironment(WorkflowRun.java:468)
      at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:86)
      at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:67)
      at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:72)
      at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.start(DurableTaskStep.java:305)
      at org.jenkinsci.plugins.workflow.cps.DSL.invokeStep(DSL.java:268)
      at org.jenkinsci.plugins.workflow.cps.DSL.invokeMethod(DSL.java:176)
      at org.jenkinsci.plugins.workflow.cps.CpsScript.invokeMethod(CpsScript.java:122)
      at sun.reflect.GeneratedMethodAccessor387.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
      at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1213)
      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
      at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
      at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
      at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
      at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:157)
      at org.kohsuke.groovy.sandbox.GroovyInterceptor.onMethodCall(GroovyInterceptor.java:23)
      at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:155)
      at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:155)
      at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:159)
      at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:129)
      at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.methodCall(SandboxInvoker.java:17)
      at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:57)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
      at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:103)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
      at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
      at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:60)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
      at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
      at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
      at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
      at com.cloudbees.groovy.cps.Next.step(Next.java:83)
      at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
      at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
      at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:129)
      at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:268)
      at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
      at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$101(SandboxContinuable.java:34)
      at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.lambda$run0$0(SandboxContinuable.java:59)
      at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox.runInSandbox(GroovySandbox.java:121)
      at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:58)
      at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:182)
      at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:332)
      at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$200(CpsThreadGroup.java:83)
      at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:244)
      at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:232)
      at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:64)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:131)
      at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
      at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)

       

      When enabling DelayBufferedOutputStream logging, we also see this in the log:

      null
      java.io.IOException: Stream Closed
      at java.io.FileOutputStream.writeBytes(Native Method)
      at java.io.FileOutputStream.write(FileOutputStream.java:326)
      at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:134)
      at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
      at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
      at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream.flushBuffer(DelayBufferedOutputStream.java:82)
      at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream.flushAndReschedule(DelayBufferedOutputStream.java:91)
      at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$Flush.run(DelayBufferedOutputStream.java:114)
      at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)

        Attachments

          Activity

          rshade Robert Shade created issue -
          rshade Robert Shade made changes -
          Field Original Value New Value
          Environment workflow-api-plugin v2.33
          Jenkins v2.150.3
          rshade Robert Shade made changes -
          Description Some jobs get stuck in a state where they're unable to continue to write data to the console log.  The system log contains multiple entries of the following form until the job ends:

           

          failed to flush /net/users/jenkins/configuration/jobs/XXX/builds/5/log
          java.io.IOException: Stream Closed
           at java.io.FileOutputStream.writeBytes(Native Method)
           at java.io.FileOutputStream.write(FileOutputStream.java:326)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:134)
           at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
           at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
           at java.io.FilterOutputStream.flush(FilterOutputStream.java:140)
           at org.jenkinsci.plugins.workflow.log.FileLogStorage.maybeFlush(FileLogStorage.java:190)
           at org.jenkinsci.plugins.workflow.log.FileLogStorage.overallLog(FileLogStorage.java:198)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogText(WorkflowRun.java:1018)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogInputStream(WorkflowRun.java:1026)
           at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.notLogged(GenericWebhookEnvironmentContributor.java:54)
           at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.buildEnvironmentFor(GenericWebhookEnvironmentContributor.java:30)
           at hudson.model.Run.getEnvironment(Run.java:2373)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getEnvironment(WorkflowRun.java:468)
           at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:86)
           at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:67)
           at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:72)
           at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.start(DurableTaskStep.java:305)
           at org.jenkinsci.plugins.workflow.cps.DSL.invokeStep(DSL.java:268)
           at org.jenkinsci.plugins.workflow.cps.DSL.invokeMethod(DSL.java:176)
           at org.jenkinsci.plugins.workflow.cps.CpsScript.invokeMethod(CpsScript.java:122)
           at sun.reflect.GeneratedMethodAccessor387.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
           at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
           at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1213)
           at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
           at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
           at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
           at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
           at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:157)
           at org.kohsuke.groovy.sandbox.GroovyInterceptor.onMethodCall(GroovyInterceptor.java:23)
           at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:155)
           at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:155)
           at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:159)
           at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:129)
           at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.methodCall(SandboxInvoker.java:17)
           at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:57)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:103)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:60)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
           at com.cloudbees.groovy.cps.Next.step(Next.java:83)
           at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
           at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
           at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:129)
           at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:268)
           at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$101(SandboxContinuable.java:34)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.lambda$run0$0(SandboxContinuable.java:59)
           at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox.runInSandbox(GroovySandbox.java:121)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:58)
           at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:182)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:332)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$200(CpsThreadGroup.java:83)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:244)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:232)
           at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:64)
           at java.util.concurrent.FutureTask.run(FutureTask.java:266)
           at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:131)
           at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
           at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
           at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
           at java.util.concurrent.FutureTask.run(FutureTask.java:266)
           at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
           at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
           at java.lang.Thread.run(Thread.java:748)
          Some jobs get stuck in a state where they're unable to continue to write data to the console log.  The system log contains multiple entries of the following form until the job ends:

           

          failed to flush /net/users/jenkins/configuration/jobs/XXX/builds/5/log
           java.io.IOException: Stream Closed
           at java.io.FileOutputStream.writeBytes(Native Method)
           at java.io.FileOutputStream.write(FileOutputStream.java:326)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:134)
           at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
           at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
           at java.io.FilterOutputStream.flush(FilterOutputStream.java:140)
           at org.jenkinsci.plugins.workflow.log.FileLogStorage.maybeFlush(FileLogStorage.java:190)
           at org.jenkinsci.plugins.workflow.log.FileLogStorage.overallLog(FileLogStorage.java:198)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogText(WorkflowRun.java:1018)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogInputStream(WorkflowRun.java:1026)
           at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.notLogged(GenericWebhookEnvironmentContributor.java:54)
           at org.jenkinsci.plugins.gwt.GenericWebhookEnvironmentContributor.buildEnvironmentFor(GenericWebhookEnvironmentContributor.java:30)
           at hudson.model.Run.getEnvironment(Run.java:2373)
           at org.jenkinsci.plugins.workflow.job.WorkflowRun.getEnvironment(WorkflowRun.java:468)
           at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:86)
           at org.jenkinsci.plugins.workflow.cps.EnvActionImpl.getEnvironment(EnvActionImpl.java:67)
           at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:72)
           at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.start(DurableTaskStep.java:305)
           at org.jenkinsci.plugins.workflow.cps.DSL.invokeStep(DSL.java:268)
           at org.jenkinsci.plugins.workflow.cps.DSL.invokeMethod(DSL.java:176)
           at org.jenkinsci.plugins.workflow.cps.CpsScript.invokeMethod(CpsScript.java:122)
           at sun.reflect.GeneratedMethodAccessor387.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
           at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
           at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1213)
           at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
           at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
           at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
           at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
           at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:157)
           at org.kohsuke.groovy.sandbox.GroovyInterceptor.onMethodCall(GroovyInterceptor.java:23)
           at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:155)
           at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:155)
           at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:159)
           at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:129)
           at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.methodCall(SandboxInvoker.java:17)
           at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:57)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:103)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:60)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:109)
           at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:82)
           at sun.reflect.GeneratedMethodAccessor384.invoke(Unknown Source)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:498)
           at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
           at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
           at com.cloudbees.groovy.cps.Next.step(Next.java:83)
           at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
           at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
           at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:129)
           at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:268)
           at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$101(SandboxContinuable.java:34)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.lambda$run0$0(SandboxContinuable.java:59)
           at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox.runInSandbox(GroovySandbox.java:121)
           at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:58)
           at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:182)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:332)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$200(CpsThreadGroup.java:83)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:244)
           at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:232)
           at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:64)
           at java.util.concurrent.FutureTask.run(FutureTask.java:266)
           at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:131)
           at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
           at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
           at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
           at java.util.concurrent.FutureTask.run(FutureTask.java:266)
           at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
           at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
           at java.lang.Thread.run(Thread.java:748)

           

          When enabling DelayBufferedOutputStream logging, we also see this in the log:

          null
          java.io.IOException: Stream Closed
           at java.io.FileOutputStream.writeBytes(Native Method)
           at java.io.FileOutputStream.write(FileOutputStream.java:326)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:134)
           at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
           at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream.flushBuffer(DelayBufferedOutputStream.java:82)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream.flushAndReschedule(DelayBufferedOutputStream.java:91)
           at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$Flush.run(DelayBufferedOutputStream.java:114)
           at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
           at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
           at java.util.concurrent.FutureTask.run(FutureTask.java:266)
           at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
           at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
           at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
           at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
           at java.lang.Thread.run(Thread.java:748)
          rshade Robert Shade made changes -
          Priority Minor [ 4 ] Critical [ 2 ]
          Hide
          johnlengeling John Lengeling added a comment -

          Ran into this issue under Jenkins 2.176.3 with workflow-api 2.37, mailer 1.27 , email-ext 2.66.   It occurred thou in the job post section trying to send an email notification.   Over a couple of days, the stacktraces filled up the partition since it outputs about every 30s-60s.

          Tried to abort the job but it would not die.   Tried to kill the thread from Melody but it would not die.   Had to restart Jenkins and the job started running again after the restart.  Then I quickly killed it.

           

          ```

          {{Sep 25, 2019 8:22:34 AM org.jenkinsci.plugins.workflow.log.FileLogStorage maybeFlush
          WARNING: failed to flush /opt/apache/.jenkins/jobs/Reprogramming/jobs/verify/branches/master/builds/604/log
          java.io.IOException: Stream Closed
          at java.io.FileOutputStream.writeBytes(Native Method)
          at java.io.FileOutputStream.write(FileOutputStream.java:326)
          at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:129)
          at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
          at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
          at java.io.FilterOutputStream.flush(FilterOutputStream.java:140)
          at org.jenkinsci.plugins.workflow.log.FileLogStorage.maybeFlush(FileLogStorage.java:190)
          at org.jenkinsci.plugins.workflow.log.FileLogStorage.overallLog(FileLogStorage.java:198)
          at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogText(WorkflowRun.java:1019)
          at hudson.plugins.emailext.AttachmentUtils$LogFileDataSource.getInputStream(AttachmentUtils.java:100)
          at javax.mail.internet.MimeUtility.getEncoding(MimeUtility.java:197)
          at javax.mail.internet.MimeUtility.getEncoding(MimeUtility.java:256)
          at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1366)
          at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1021)
          at javax.mail.internet.MimeMultipart.updateHeaders(MimeMultipart.java:419)
          at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1345)
          at javax.mail.internet.MimeMessage.updateHeaders(MimeMessage.java:2106)
          at javax.mail.internet.MimeMessage.saveChanges(MimeMessage.java:2074)
          at javax.mail.internet.MimeMessage.writeTo(MimeMessage.java:1769)
          at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1099)
          at hudson.plugins.emailext.ExtendedEmailPublisher.sendMail(ExtendedEmailPublisher.java:484)
          at hudson.plugins.emailext.EmailExtStep$EmailExtStepExecution.run(EmailExtStep.java:224)
          at hudson.plugins.emailext.EmailExtStep$EmailExtStepExecution.run(EmailExtStep.java:163)
          at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1$1.call(AbstractSynchronousNonBlockingStepExecution.java:47)
          at hudson.security.ACL.impersonate(ACL.java:290)
          at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1.run(AbstractSynchronousNonBlockingStepExecution.java:44)
          at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
          at java.lang.Thread.run(Thread.java:748)}}

          ```

           

           

          Show
          johnlengeling John Lengeling added a comment - Ran into this issue under Jenkins 2.176.3 with workflow-api 2.37, mailer 1.27 , email-ext 2.66.   It occurred thou in the job post section trying to send an email notification.   Over a couple of days, the stacktraces filled up the partition since it outputs about every 30s-60s. Tried to abort the job but it would not die.   Tried to kill the thread from Melody but it would not die.   Had to restart Jenkins and the job started running again after the restart.  Then I quickly killed it.   ``` {{Sep 25, 2019 8:22:34 AM org.jenkinsci.plugins.workflow.log.FileLogStorage maybeFlush WARNING: failed to flush /opt/apache/.jenkins/jobs/Reprogramming/jobs/verify/branches/master/builds/604/log java.io.IOException: Stream Closed at java.io.FileOutputStream.writeBytes(Native Method) at java.io.FileOutputStream.write(FileOutputStream.java:326) at org.jenkinsci.plugins.workflow.log.DelayBufferedOutputStream$FlushControlledOutputStream.write(DelayBufferedOutputStream.java:129) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.FilterOutputStream.flush(FilterOutputStream.java:140) at org.jenkinsci.plugins.workflow.log.FileLogStorage.maybeFlush(FileLogStorage.java:190) at org.jenkinsci.plugins.workflow.log.FileLogStorage.overallLog(FileLogStorage.java:198) at org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogText(WorkflowRun.java:1019) at hudson.plugins.emailext.AttachmentUtils$LogFileDataSource.getInputStream(AttachmentUtils.java:100) at javax.mail.internet.MimeUtility.getEncoding(MimeUtility.java:197) at javax.mail.internet.MimeUtility.getEncoding(MimeUtility.java:256) at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1366) at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1021) at javax.mail.internet.MimeMultipart.updateHeaders(MimeMultipart.java:419) at javax.mail.internet.MimeBodyPart.updateHeaders(MimeBodyPart.java:1345) at javax.mail.internet.MimeMessage.updateHeaders(MimeMessage.java:2106) at javax.mail.internet.MimeMessage.saveChanges(MimeMessage.java:2074) at javax.mail.internet.MimeMessage.writeTo(MimeMessage.java:1769) at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1099) at hudson.plugins.emailext.ExtendedEmailPublisher.sendMail(ExtendedEmailPublisher.java:484) at hudson.plugins.emailext.EmailExtStep$EmailExtStepExecution.run(EmailExtStep.java:224) at hudson.plugins.emailext.EmailExtStep$EmailExtStepExecution.run(EmailExtStep.java:163) at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1$1.call(AbstractSynchronousNonBlockingStepExecution.java:47) at hudson.security.ACL.impersonate(ACL.java:290) at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1.run(AbstractSynchronousNonBlockingStepExecution.java:44) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)}} ```    
          dnusbaum Devin Nusbaum made changes -
          Labels pipeline

            People

            • Assignee:
              Unassigned
              Reporter:
              rshade Robert Shade
            • Votes:
              4 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

              • Created:
                Updated: