Job fails with error (Failure reading from Agent Connection - java.io.IOException: EOF), when running on z/OS build forge agent
Using Build Forge 8.0.0.4 server/management console. Agent version is also 8.0.0.4 and agent is running on zOS. We have a job that basically runs a script, on the zOS agent, to unzip a file e.g.:
unzip -o release.zip
When you run the job, it starts and then after some random period, it fails with the following error:
1254 10/20/16 2:08 PM ERROR java.io.IOException: EOF
1255 10/20/16 2:08 PM ERROR at com.ibm.jas.agent.AgentConnection.readLine(AgentConnection.java:393)
1256 10/20/16 2:08 PM ERROR at com.ibm.jas.agent.AgentConnection.readMessage(AgentConnection.java:331)
1257 10/20/16 2:08 PM ERROR at com.ibm.jas.agent.AgentConnection.readMessage(AgentConnection.java:324)
1258 10/20/16 2:08 PM ERROR at com.ibm.jas.agent.action.ReadAgentConnection.action(ReadAgentConnection.java:79)
1259 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1260 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.action(Block.java:100)
1261 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1262 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.server.impl.AgentServerProvider.finishExecute(AgentServerProvider.java:354)
1263 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.server.impl.AgentServerProvider.execute(AgentServerProvider.java:320)
1264 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.impl.MJCStepProvider.executeCommand(MJCStepProvider.java:142)
1265 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.impl.MJCStepProvider.execute(MJCStepProvider.java:82)
1266 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.SimpleStepProviderFiberAction.executeStepProvider(SimpleStepProviderFiberAction.java:185)
1267 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.SimpleStepProviderFiberAction.action(SimpleStepProviderFiberAction.java:140)
1268 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1269 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.action(SelectingStepProviderFiberAction.java:156)
1270 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1271 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.action(Block.java:123)
1272 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.callInlinedBlock(Block.java:153)
1273 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.InliningStepProviderFiberAction.action(InliningStepProviderFiberAction.java:111)
1274 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1275 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.action(SelectingStepProviderFiberAction.java:156)
1276 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1277 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.action(Block.java:123)
1278 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.callInlinedBlock(Block.java:153)
1279 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.step.InliningStepProviderFiberAction.action(InliningStepProviderFiberAction.java:111)
1280 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1281 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.action.flow.Block.action(Block.java:100)
1282 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202)
1283 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.Fiber.runFiber(Fiber.java:786)
1284 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberThread.runFibers(FiberThread.java:263)
1285 10/20/16 2:08 PM ERROR at com.ibm.jas.fiber.FiberThread.run(FiberThread.java:250)
1286 10/20/16 2:08 PM ERROR at com.ibm.jas.mjc.ProcessThread.run(ProcessThread.java:93)
1287 10/20/16 2:08 PM ERROR Unexpected exception during execute operation
What could be causing such an error?
The issue was caused by a lack of resources on the zOS machine. They had run out of memory and had to allocate additional memory.
In z/OS, added a “region” parameter to the JCL that starts the agent and both the unzip command and the script now execute fine.
Other issue that was seen when the zOS ran out of resources was scripts failing on the bfagent machine. In the build log you would see RESULT 137.
In the associated jas-0.log, the following stack trace would be seen:
Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread$ProcessThreadExceptionHandler uncaughtException SEVERE: Exception during Job (f0c47d890c7a1000d82ebbfda3b9927a) execution, marking Job as failure... com.ibm.jas.fiber.FiberDeath at com.ibm.jas.fiber.FiberThread.cancelFibers(FiberThread.java:108) at com.ibm.jas.mjc.ProcessThread.signalJobFailed(ProcessThread.java:344) at com.ibm.jas.mjc.model.ServerStepProviderContext.propagateResult(ServerStepProviderContext.java:470) at com.ibm.jas.mjc.model.ServerStepProviderContext.propagateResult(ServerStepProviderContext.java:417) at com.ibm.jas.mjc.step.AbstractStepProviderFiberAction.ensureTerminalResultState(AbstractStepProviderFiberAction.java:311) at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.cleanup(SelectingStepProviderFiberAction.java:186) at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.action(SelectingStepProviderFiberAction.java:173) at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202) at com.ibm.jas.fiber.action.flow.Block.action(Block.java:100) at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202) at com.ibm.jas.fiber.Fiber.runFiber(Fiber.java:786) at com.ibm.jas.fiber.FiberThread.runFibers(FiberThread.java:263) at com.ibm.jas.fiber.FiberThread.run(FiberThread.java:250) at com.ibm.jas.mjc.ProcessThread.run(ProcessThread.java:93)
Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.model.JobImpl onJobFailed INFO: onJobFailed JobUuid:f0c47d890c7a1000d82ebbfda3b9927a,Target:d86809670c7a1000ea54bbfd87c14591 Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread recordJobState INFO: Set Job:[f0c47d890c7a1000d82ebbfda3b9927a] Stage Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread run INFO: Finished Job 'BUILD_9' (f0c47d890c7a1000d82ebbfda3b9927a) : FAILED
The issue was caused by a lack of resources on the zOS machine. They had run out of memory and had to allocate additional memory.
In z/OS, added a “region” parameter to the JCL that starts the agent and both the unzip command and the script now execute fine
The issue was caused by a lack of resources on the zOS machine. They had run out of memory and had to allocate additional memory.
In z/OS, added a “region” parameter to the JCL that starts the agent and both the unzip command and the script now execute fine.
Other issue that was seen when the zOS ran out of resources was scripts failing on the bfagent machine. In the build log you would see RESULT 137.
In the associated jas-0.log, the following stack trace would be seen:
Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread$ProcessThreadExceptionHandler uncaughtException SEVERE: Exception during Job (f0c47d890c7a1000d82ebbfda3b9927a) execution, marking Job as failure... com.ibm.jas.fiber.FiberDeath at com.ibm.jas.fiber.FiberThread.cancelFibers(FiberThread.java:108) at com.ibm.jas.mjc.ProcessThread.signalJobFailed(ProcessThread.java:344) at com.ibm.jas.mjc.model.ServerStepProviderContext.propagateResult(ServerStepProviderContext.java:470) at com.ibm.jas.mjc.model.ServerStepProviderContext.propagateResult(ServerStepProviderContext.java:417) at com.ibm.jas.mjc.step.AbstractStepProviderFiberAction.ensureTerminalResultState(AbstractStepProviderFiberAction.java:311) at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.cleanup(SelectingStepProviderFiberAction.java:186) at com.ibm.jas.mjc.step.SelectingStepProviderFiberAction.action(SelectingStepProviderFiberAction.java:173) at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202) at com.ibm.jas.fiber.action.flow.Block.action(Block.java:100) at com.ibm.jas.fiber.FiberAction.call(FiberAction.java:202) at com.ibm.jas.fiber.Fiber.runFiber(Fiber.java:786) at com.ibm.jas.fiber.FiberThread.runFibers(FiberThread.java:263) at com.ibm.jas.fiber.FiberThread.run(FiberThread.java:250) at com.ibm.jas.mjc.ProcessThread.run(ProcessThread.java:93)
Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.model.JobImpl onJobFailed INFO: onJobFailed JobUuid:f0c47d890c7a1000d82ebbfda3b9927a,Target:d86809670c7a1000ea54bbfd87c14591 Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread recordJobState INFO: Set Job:[f0c47d890c7a1000d82ebbfda3b9927a] Stage Oct 26, 2016 9:29:32 AM com.ibm.jas.mjc.ProcessThread run INFO: Finished Job 'BUILD_9' (f0c47d890c7a1000d82ebbfda3b9927a) : FAILED