[22/05/2019 21:19:57:455 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Scheduling job 'picalc/5244'
[22/05/2019 21:20:27:371 | a.e.u.r.n.r.s.OpenSSHClient | TRACE] Executing command: ssh -q -o PasswordAuthentication=no -o StrictHostKeyChecking=no np-compute-20 -- mkdir -p /mnt/nimrod/agent-33e070cc-5831-43e9-877b-320afc0bc549
[22/05/2019 21:20:28:293 | a.e.u.r.n.r.s.OpenSSHClient | TRACE] Executing command: ssh -q -o PasswordAuthentication=no -o StrictHostKeyChecking=no np-compute-20 -- /home/nimrod/.nimrod/d33f7f73-ca03-4010-9f32-15fc48555621/agent-x86_64-pc-linux-musl --uuid 33e070cc-5831-43e9-877b-320afc0bc549 --amqp-uri amqp://nimrod:[email protected]/nimrod --amqp-routing-key nimrod --work-root /mnt/nimrod/agent-33e070cc-5831-43e9-877b-320afc0bc549 --batch --output workroot
[22/05/2019 21:20:30:027 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:30:040 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:30:784 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:30:784 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:31:443 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:31:443 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:31:855 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:31:855 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:32:600 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:32:600 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:33:310 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:33:310 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:34:090 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:34:090 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:35:041 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:35:041 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:35:672 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:35:672 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:36:142 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:36:142 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:37:113 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:37:113 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:37:952 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:37:952 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:39:268 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:39:269 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:40:542 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/5244' on agent 'c3ac4cd2-727c-421b-9f1d-00e32348f8c1'
[22/05/2019 21:20:40:961 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.hello)
[22/05/2019 21:20:40:961 | a.e.u.r.n.m.Master | TRACE] Received agent.hello with (uuid, queue) = (33e070cc-5831-43e9-877b-320afc0bc549, amq.gen-iCyuqTcCwtudGsCAvxjD-g)
[22/05/2019 21:20:40:962 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from WAITING_FOR_HELLO -> READY
[22/05/2019 21:20:42:047 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, WAITING_FOR_HELLO, READY)
[22/05/2019 21:20:42:164 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' failed on attempt 1, rescheduling...
[22/05/2019 21:20:42:164 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' failed on attempt 2, rescheduling...
[22/05/2019 21:20:42:164 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' failed on attempt 3, rescheduling...
[22/05/2019 21:20:42:224 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Scheduling job 'picalc/5244'
[22/05/2019 21:20:42:224 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Scheduling job 'picalc/5244'
[22/05/2019 21:20:42:225 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Scheduling job 'picalc/5244'
[22/05/2019 21:20:43:592 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/5594' on agent '33e070cc-5831-43e9-877b-320afc0bc549'
[22/05/2019 21:20:43:592 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from READY -> BUSY
[22/05/2019 21:20:45:916 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:20:45:918 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:20:45:918 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:20:45:959 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, READY, BUSY)
[22/05/2019 21:37:29:922 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 4!
[22/05/2019 21:48:42:627 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:48:42:627 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from BUSY -> READY
[22/05/2019 21:48:42:628 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, BUSY, READY)
[22/05/2019 21:48:42:631 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/7101' on agent '33e070cc-5831-43e9-877b-320afc0bc549'
[22/05/2019 21:48:42:632 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from READY -> BUSY
[22/05/2019 21:48:42:735 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:48:42:736 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, READY, BUSY)
[22/05/2019 21:48:42:835 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 21:48:42:936 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:17:24:480 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:17:24:480 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from BUSY -> READY
[22/05/2019 22:17:24:480 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, BUSY, READY)
[22/05/2019 22:17:24:484 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/8622' on agent '33e070cc-5831-43e9-877b-320afc0bc549'
[22/05/2019 22:17:24:485 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from READY -> BUSY
[22/05/2019 22:17:24:605 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:17:24:605 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, READY, BUSY)
[22/05/2019 22:17:24:711 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:17:24:826 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:46:52:051 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/5244' on agent '92c20286-4e0e-4e53-85df-caaedb3a4f5a'
[22/05/2019 22:46:52:157 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 5!
[22/05/2019 22:46:52:168 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 6!
[22/05/2019 22:46:52:168 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 7!
[22/05/2019 22:46:52:820 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/5244' on agent 'a716c476-543e-4078-b9e6-cb22c840095d'
[22/05/2019 22:46:52:938 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 8!
[22/05/2019 22:46:53:047 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 9!
[22/05/2019 22:46:53:056 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 10!
[22/05/2019 22:46:55:440 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:46:55:440 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from BUSY -> READY
[22/05/2019 22:46:55:441 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, BUSY, READY)
[22/05/2019 22:46:55:447 | a.e.u.r.n.m.Master | INFO] Run job 'picalc/5244' on agent '33e070cc-5831-43e9-877b-320afc0bc549'
[22/05/2019 22:46:55:448 | a.e.u.r.n.m.Master | DEBUG] Agent 33e070cc-5831-43e9-877b-320afc0bc549: State change from READY -> BUSY
[22/05/2019 22:46:55:560 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:46:55:560 | .u.r.n.m.s.DefaultAgentScheduler | TRACE] onAgentStateUpdate(33e070cc-5831-43e9-877b-320afc0bc549, np_compute_20, READY, BUSY)
[22/05/2019 22:46:55:561 | .e.u.r.n.m.s.DefaultJobScheduler | INFO] Job 'picalc/5244' succeeded on attempt 11!
[22/05/2019 22:46:55:562 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:46:55:564 | a.e.u.r.n.m.Master | ERROR] Caught exception during RUN:
[22/05/2019 22:46:55:564 | a.e.u.r.n.m.Master | ERROR] Catching
java.lang.NullPointerException: null
at au.edu.uq.rcc.nimrodg.master.sched.DefaultJobScheduler.tickJobAttempt(DefaultJobScheduler.java:172) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.sched.DefaultJobScheduler.onJobUpdate(DefaultJobScheduler.java:143) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master$_AgentListener.lambda$onJobUpdate$3(Master.java:912) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.lambda$processQueue$14(Master.java:502) ~[nimrodg-master-1.1.1.jar:?]
at java.util.ArrayList.forEach(ArrayList.java:1540) ~[?:?]
at au.edu.uq.rcc.nimrodg.master.Master.processQueue(Master.java:502) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.startProc(Master.java:436) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.tick(Master.java:304) [nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.commands.MasterCmd.execute(MasterCmd.java:137) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLICommand.execute(NimrodCLICommand.java:42) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.DefaultCLICommand.execute(DefaultCLICommand.java:36) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLI.cliMain(NimrodCLI.java:124) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLI.main(NimrodCLI.java:137) [nimrodg-cli-1.1.1.jar:?]
[22/05/2019 22:46:56:078 | a.e.u.r.n.m.AAAAA | TRACE] Cancelling pending launches...
[22/05/2019 22:46:56:290 | a.e.u.r.n.m.Master | TRACE] Terminating agent '33e070cc-5831-43e9-877b-320afc0bc549'
[22/05/2019 22:46:56:415 | a.e.u.r.n.m.Master | DEBUG] doProcessAgentMessage(33e070cc-5831-43e9-877b-320afc0bc549, agent.update)
[22/05/2019 22:46:56:419 | a.e.u.r.n.m.Master | ERROR] Caught exception during RUN:
[22/05/2019 22:46:56:419 | a.e.u.r.n.m.Master | ERROR] Catching
java.lang.NullPointerException: null
at au.edu.uq.rcc.nimrodg.master.sched.DefaultJobScheduler.tickJobAttempt(DefaultJobScheduler.java:172) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.sched.DefaultJobScheduler.onJobUpdate(DefaultJobScheduler.java:143) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master$_AgentListener.lambda$onJobUpdate$3(Master.java:912) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.lambda$processQueue$14(Master.java:502) ~[nimrodg-master-1.1.1.jar:?]
at java.util.ArrayList.forEach(ArrayList.java:1540) ~[?:?]
at au.edu.uq.rcc.nimrodg.master.Master.processQueue(Master.java:502) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.stoppingProc(Master.java:639) ~[nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.master.Master.tick(Master.java:304) [nimrodg-master-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.commands.MasterCmd.execute(MasterCmd.java:137) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLICommand.execute(NimrodCLICommand.java:42) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.DefaultCLICommand.execute(DefaultCLICommand.java:36) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLI.cliMain(NimrodCLI.java:124) [nimrodg-cli-1.1.1.jar:?]
at au.edu.uq.rcc.nimrodg.cli.NimrodCLI.main(NimrodCLI.java:137) [nimrodg-cli-1.1.1.jar:?]
[22/05/2019 22:46:58:255 | a.e.u.r.n.m.AAAAA | INFO] Waiting on 40 actuator(s)...