Bug #16663

[a-d-c] restarting a-d-c kills all running workflows

Added by Ward Vandewege about 2 months ago. Updated about 1 month ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Category:
-
Target version:
Start date:
08/07/2020
Due date:
% Done:

100%

Estimated time:
(Total: 0.00 h)
Story points:
-
Release relationship:
Auto

Description

Restarting a-d-c seems to have rather nasty consequences for running workflows. In this case, it looks like the API server was restarted at the same time.

1) All running jobs are aborted immediately (that's bad).

2) The CR then gets associated with a new container, which automatically restarts all jobs that are runnable and haven't run yet (I think). But, it's suddenly impossible to see the container that was associated with the CR originally, which means that it looks like all work is just gone, lost (that's also bad, but mostly a UX problem).

The old container is still there, and whatever was run under that will be reused if the jobs were not marked as non-deterministic (I think). Update 2020-08-05: it doesn't even look like reuse is working between the original container and the new container.

Example:

CR: pirca-xvhdp-dsi31r62tcg7lxi
original container: pirca-dz642-k1o7j58y4eholt0
new container: pirca-dz642-a4vyxbsz8himlpc

Question: a) is this expected or just a (nasty) bug? b) regardless of the answer to a, how do we make a-d-c not a thing that costs tons of money (and creates a lot of user confusion) when it dies?

a-d-c logs:

...
Aug 04 17:10:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-ke17qoxmaldqsxq","PID":3446,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:10:47.239763968Z"}
Aug 04 17:10:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.41","ContainerUUID":"pirca-dz642-k93dp0nuheqpm84","Instance":"i-00443138206318055","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:10:47.259274838Z"}
Aug 04 17:10:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-0yp7t9h6slmv8tq","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:10:47.295578887Z"}
Aug 04 17:10:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.193","ContainerUUID":"pirca-dz642-7s9dwapceualhrj","Instance":"i-04cec633ee58b57e0","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:10:47.309511102Z"}
Aug 04 17:10:53 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.185","Instance":"i-0b9509dcfc8f56e72","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:10:53.512323021Z","level":"info","msg":"probe reported broken instance","time":"2020-08-04T17:10:53.530771030Z"}
Aug 04 17:10:53 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.185","IdleBehavior":"drain","Instance":"i-0b9509dcfc8f56e72","InstanceType":"m5large","PID":3446,"level":"info","msg":"set idle behavior","time":"2020-08-04T17:10:53.530847732Z"}
Aug 04 17:10:53 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.185","ContainerUUID":"pirca-dz642-eubn9olqccox8lk","Instance":"i-0b9509dcfc8f56e72","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:10:53.530891693Z"}
Aug 04 17:11:01 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.185","IdleBehavior":"drain","IdleDuration":7.681330,"Instance":"i-0b9509dcfc8f56e72","InstanceType":"m5large","PID":3446,"State":"idle","level":"info","msg":"shutdown worker","time":"2020-08-04T17:11:01.212227991Z"}
Aug 04 17:11:01 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-eubn9olqccox8lk","InstanceType":"m5large","PID":3446,"level":"info","msg":"creating new instance","time":"2020-08-04T17:11:01.252294103Z"}
Aug 04 17:11:02 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","IdleBehavior":"run","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"State":"booting","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:11:02.693816858Z"}
Aug 04 17:11:33 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","Command":"sudo docker ps -q","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:11:33.783494016Z"}
Aug 04 17:11:33 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"cmd":"sudo sh -c 'set -e; dstdir=\"/var/lib/arvados/\"; dstfile=\"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e\"; mkdir -p \"$dstdir\"; touch \"$dstfile\"; chmod 0755 \"$dstdir\" \"$dstfile\"; cat \u003e\"$dstfile\"'","hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"installing runner bin
Aug 04 17:11:34 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:11:32.412227717Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:11:34.303597232Z"}
Aug 04 17:11:34 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:11:32.412227717Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:11:34.368318115Z"}
Aug 04 17:11:34 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-eubn9olqccox8lk","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:11:34.414515727Z"}
Aug 04 17:11:39 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Instance":"i-0b9509dcfc8f56e72","PID":3446,"WorkerState":"shutdown","level":"info","msg":"instance disappeared in cloud","time":"2020-08-04T17:11:39.559952459Z"}
Aug 04 17:11:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-7rs4fusdrq0iava","InstanceType":"m5large","PID":3446,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:11:47.160095747Z"}
Aug 04 17:11:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-eubn9olqccox8lk","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:11:47.160415106Z"}
Aug 04 17:11:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-oipubplk4un89ob","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":3446,"Reason":"state=Complete","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:11:47.160687885Z"}
Aug 04 17:11:47 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-7rs4fusdrq0iava","InstanceType":"m5large","PID":3446,"level":"info","msg":"creating new instance","time":"2020-08-04T17:11:47.209741061Z"}
Aug 04 17:11:48 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","IdleBehavior":"run","Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"State":"booting","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:11:48.604931132Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-eubn9olqccox8lk","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"Signal":15,"level":"info","msg":"sending signal","time":"2020-08-04T17:11:52.160602284Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-oipubplk4un89ob","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":3446,"Signal":15,"level":"info","msg":"sending signal","time":"2020-08-04T17:11:52.161127549Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-eubn9olqccox8lk","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:11:52.177643150Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-eubn9olqccox8lk","PID":3446,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:11:52.178264069Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-eubn9olqccox8lk","PID":3446,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:11:52.178291350Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-oipubplk4un89ob","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:11:52.178662311Z"}
Aug 04 17:11:52 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-7rs4fusdrq0iava","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:11:52.197159560Z"}
Aug 04 17:11:57 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-oipubplk4un89ob","PID":3446,"State":"Complete","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:11:57.123144140Z"}
Aug 04 17:12:07 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","InstanceType":"m5large","PID":3446,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:12:07.157071442Z"}
Aug 04 17:12:07 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.129","ContainerUUID":"pirca-dz642-qn3rgqp8oe34fgr","Instance":"i-051fd901be15dea8f","InstanceType":"m5large","PID":3446,"Reason":"state=Complete","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:12:07.157411632Z"}
Aug 04 17:12:07 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:12:07.221490447Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.129","ContainerUUID":"pirca-dz642-qn3rgqp8oe34fgr","Instance":"i-051fd901be15dea8f","InstanceType":"m5large","PID":3446,"Signal":15,"level":"info","msg":"sending signal","time":"2020-08-04T17:12:12.157597428Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.129","ContainerUUID":"pirca-dz642-qn3rgqp8oe34fgr","Instance":"i-051fd901be15dea8f","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:12:12.174818440Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.24","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:12:12.512249707Z","level":"info","msg":"probe reported broken instance","time":"2020-08-04T17:12:12.529557022Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.24","IdleBehavior":"drain","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":3446,"level":"info","msg":"set idle behavior","time":"2020-08-04T17:12:12.529624224Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.24","ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:12:12.529659115Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-qn3rgqp8oe34fgr","PID":3446,"State":"Complete","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:12:12.529927483Z"}
Aug 04 17:12:12 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-qn3rgqp8oe34fgr","PID":3446,"State":"Complete","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:12:12.529957424Z"}
Aug 04 17:12:15 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","Command":"sudo docker ps -q","Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:12:15.311747580Z"}
Aug 04 17:12:15 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"cmd":"sudo sh -c 'set -e; dstdir=\"/var/lib/arvados/\"; dstfile=\"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e\"; mkdir -p \"$dstdir\"; touch \"$dstfile\"; chmod 0755 \"$dstdir\" \"$dstfile\"; cat \u003e\"$dstfile\"'","hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"installing runner bin
Aug 04 17:12:15 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:12:13.512546222Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:12:15.936584624Z"}
Aug 04 17:12:15 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:12:13.512546222Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:12:15.973263896Z"}
Aug 04 17:12:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-bpj6okdu14441um","InstanceType":"m5large","PID":3446,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:12:17.154097918Z"}
Aug 04 17:12:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.198","ContainerUUID":"pirca-dz642-ug29en32ihh4rrq","Instance":"i-05733b3942da7b768","InstanceType":"m5large","PID":3446,"Reason":"state=Complete","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:12:17.154405017Z"}
Aug 04 17:12:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.24","ContainerUUID":"pirca-dz642-bpj6okdu14441um","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:12:17.214929565Z"}
Aug 04 17:12:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.129","ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","Instance":"i-051fd901be15dea8f","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:12:17.281954867Z"}
Aug 04 17:12:22 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.198","ContainerUUID":"pirca-dz642-ug29en32ihh4rrq","Instance":"i-05733b3942da7b768","InstanceType":"m5large","PID":3446,"Signal":15,"level":"info","msg":"sending signal","time":"2020-08-04T17:12:22.154585906Z"}
Aug 04 17:12:22 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.198","ContainerUUID":"pirca-dz642-ug29en32ihh4rrq","Instance":"i-05733b3942da7b768","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:12:22.172118647Z"}
Aug 04 17:12:27 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-ug29en32ihh4rrq","PID":3446,"State":"Complete","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:12:27.123200275Z"}
Aug 04 17:12:34 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-0yp7t9h6slmv8tq","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:12:34.729967770Z"}
Aug 04 17:12:37 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","InstanceType":"m5large","PID":3446,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:12:37.152390405Z"}
Aug 04 17:12:37 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-0yp7t9h6slmv8tq","PID":3446,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:12:37.201785654Z"}
Aug 04 17:12:37 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-0yp7t9h6slmv8tq","PID":3446,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:12:37.201827526Z"}
Aug 04 17:12:37 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:12:37.221342216Z"}
Aug 04 17:12:51 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.156","IdleBehavior":"run","IdleDuration":62.607413,"Instance":"i-0dd9d7730ca3e999a","InstanceType":"m5large","PID":3446,"State":"idle","level":"info","msg":"shutdown worker","time":"2020-08-04T17:12:51.212416733Z"}
Aug 04 17:13:21 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.198","IdleBehavior":"run","IdleDuration":68.782323,"Instance":"i-05733b3942da7b768","InstanceType":"m5large","PID":3446,"State":"idle","level":"info","msg":"shutdown worker","time":"2020-08-04T17:13:21.212275603Z"}
Aug 04 17:13:40 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Instance":"i-05733b3942da7b768","PID":3446,"WorkerState":"shutdown","level":"info","msg":"instance disappeared in cloud","time":"2020-08-04T17:13:40.406604678Z"}
Aug 04 17:13:40 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Instance":"i-0dd9d7730ca3e999a","PID":3446,"WorkerState":"shutdown","level":"info","msg":"instance disappeared in cloud","time":"2020-08-04T17:13:40.406705021Z"}
Aug 04 17:14:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-vnctpqx4g7xvjsc","InstanceType":"m5large","PID":3446,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:14:17.165494445Z"}
Aug 04 17:14:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.51","ContainerUUID":"pirca-dz642-aikjnf5a1u8yjln","Instance":"i-07cfbde1691a85047","InstanceType":"m5large","PID":3446,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:14:17.165857595Z"}
Aug 04 17:14:17 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-vnctpqx4g7xvjsc","InstanceType":"m5large","PID":3446,"level":"info","msg":"creating new instance","time":"2020-08-04T17:14:17.210366408Z"}
Aug 04 17:14:18 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.157","IdleBehavior":"run","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":3446,"State":"booting","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:14:18.559813911Z"}
Aug 04 17:14:21 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.51","ContainerUUID":"pirca-dz642-aikjnf5a1u8yjln","Instance":"i-07cfbde1691a85047","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:14:21.228891498Z"}
Aug 04 17:14:21 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-aikjnf5a1u8yjln","PID":3446,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:14:21.229503586Z"}
Aug 04 17:14:21 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-aikjnf5a1u8yjln","PID":3446,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:14:21.229533417Z"}
Aug 04 17:14:21 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.51","ContainerUUID":"pirca-dz642-vnctpqx4g7xvjsc","Instance":"i-07cfbde1691a85047","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:14:21.248817310Z"}
Aug 04 17:14:37 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:14:37.172529306Z"}
Aug 04 17:14:42 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"Signal":15,"level":"info","msg":"sending signal","time":"2020-08-04T17:14:42.172780532Z"}
Aug 04 17:14:42 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.59","ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:14:42.190224571Z"}
Aug 04 17:14:45 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.157","Command":"sudo docker ps -q","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":3446,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:14:45.866148399Z"}
Aug 04 17:14:45 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":3446,"cmd":"sudo sh -c 'set -e; dstdir=\"/var/lib/arvados/\"; dstfile=\"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e\"; mkdir -p \"$dstdir\"; touch \"$dstfile\"; chmod 0755 \"$dstdir\" \"$dstfile\"; cat \u003e\"$dstfile\"'","hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"installing runner bin
Aug 04 17:14:46 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:14:44.412246784Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:14:46.308575597Z"}
Aug 04 17:14:46 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":3446,"ProbeStart":"2020-08-04T17:14:44.412246784Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:14:46.347368820Z"}
Aug 04 17:14:46 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","PID":3446,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:14:46.347710130Z"}
Aug 04 17:14:46 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"ContainerUUID":"pirca-dz642-mvxpukxnq0kp175","PID":3446,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:14:46.347755302Z"}
Aug 04 17:14:53 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"Address":"10.254.254.120","ContainerUUID":"pirca-dz642-i78r777ugr4i2gf","Instance":"i-092dae32e3cecc766","InstanceType":"m5large","PID":3446,"level":"info","msg":"crunch-run process ended","time":"2020-08-04T17:14:53.329655898Z"}
Aug 04 17:14:57 ip-10-254-0-45 arvados-dispatch-cloud[3446]: {"PID":3446,"level":"error","msg":"error updating queue: Get https://pirca.arvadosapi.com/arvados/v1/containers?count=none\u0026filters=%5B%5B%22locked_by_uuid%22%2C%22%3D%22%2C%22gj3su-gj3su-000000000000000%22%5D%5D\u0026limit=1000\u0026order=uuid\u0026select=%5B%22uuid%22%2C%22state%22%2C%22priority%22%2C%22runtime_constraints%22%2C%22container_image%22%2C%22mounts%22%2C%22scheduling_parameters%22%5D: dial tcp 1
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: Stopping arvados-dispatch-cloud...
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: arvados-dispatch-cloud.service: Main process exited, code=killed, status=15/TERM
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: arvados-dispatch-cloud.service: Succeeded.
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: Stopped arvados-dispatch-cloud.
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: Starting arvados-dispatch-cloud...
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Listen":"10.254.0.45:9006","PID":21538,"Service":"arvados-dispatch-cloud","URL":"http://pirca.arvadosapi.com:9006","level":"info","msg":"listening","time":"2020-08-04T17:15:02.378888701Z"}
Aug 04 17:15:02 ip-10-254-0-45 systemd[1]: Started arvados-dispatch-cloud.
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","IdleBehavior":"run","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.924974019Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.168","IdleBehavior":"run","Instance":"i-0854ba6378173d57d","InstanceType":"m52xlarge","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.933169763Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.76","IdleBehavior":"run","Instance":"i-07bc3e5d53d5a7d2c","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.933499113Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","IdleBehavior":"drain","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.933692178Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.8","IdleBehavior":"run","Instance":"i-034bbb9ad1072ff6f","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.933880134Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","IdleBehavior":"run","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.934098181Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.237","IdleBehavior":"run","Instance":"i-054388d68026dd94f","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.934304207Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.216","IdleBehavior":"run","Instance":"i-057f3f37b28215257","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.934485492Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.115","IdleBehavior":"run","Instance":"i-064cf7f0058ed6928","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.934676618Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","IdleBehavior":"run","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.934862173Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.210","IdleBehavior":"drain","Instance":"i-047339046ae1edb1b","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935047749Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","IdleBehavior":"run","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935233684Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.52","IdleBehavior":"run","Instance":"i-0d6c2fe1c3f42f53b","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935417770Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","IdleBehavior":"drain","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935603055Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.167","IdleBehavior":"run","Instance":"i-0de2dfbaa2dcaa27f","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935791591Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","IdleBehavior":"run","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.935972636Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","IdleBehavior":"run","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.936151141Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","IdleBehavior":"run","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.936354708Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","IdleBehavior":"run","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.936543573Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","IdleBehavior":"run","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.936720908Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.129","IdleBehavior":"run","Instance":"i-051fd901be15dea8f","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.936897984Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","IdleBehavior":"run","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.937084089Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.53","IdleBehavior":"run","Instance":"i-027045b59b454d1ba","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.937271205Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","IdleBehavior":"drain","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.937460680Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","IdleBehavior":"run","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.937658046Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","IdleBehavior":"run","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.937845772Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.92","IdleBehavior":"drain","Instance":"i-05bc016d202eb0259","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938056848Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","IdleBehavior":"run","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938235493Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.219","IdleBehavior":"run","Instance":"i-0b6fea8a122899503","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938429649Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.84","IdleBehavior":"run","Instance":"i-07300bb910b9a059b","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938618635Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.51","IdleBehavior":"drain","Instance":"i-07cfbde1691a85047","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938808610Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.120","IdleBehavior":"run","Instance":"i-092dae32e3cecc766","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.938999186Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.41","IdleBehavior":"drain","Instance":"i-00443138206318055","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.939246903Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.59","IdleBehavior":"run","Instance":"i-09d3a731168d90a89","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.939503131Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","IdleBehavior":"drain","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.939734568Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.193","IdleBehavior":"run","Instance":"i-04cec633ee58b57e0","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.939986156Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","IdleBehavior":"run","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.940239163Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","IdleBehavior":"run","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"State":"unknown","level":"info","msg":"instance appeared in cloud","time":"2020-08-04T17:15:02.940497301Z"}
Aug 04 17:15:02 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"N":38,"PID":21538,"level":"info","msg":"loaded initial instance list","time":"2020-08-04T17:15:02.940764158Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825694601Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825771824Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-87n53kxywmdongp","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825809185Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-c05nb5y3h3fym1j","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825841876Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-hfeljlax86puuzv","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825874426Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k1o7j58y4eholt0","InstanceType":"t3small","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825910058Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-qsmrxzmevxa7g3r","InstanceType":"m52xlarge","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825941979Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-202pmq2yudghlce","InstanceType":"t3small","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.825974500Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4fr3rdylpb43rgw","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826033712Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-5bzpziva4hjxbsz","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826068322Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-ou1b7g429e7zjyy","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826103193Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-wojhv8i8wdrf7zi","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826134204Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-xmhvheu0w9pz1n4","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826167856Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-52g8fr7mc7mgeke","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826198147Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826231178Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826260228Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826287959Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-fvcl9pk068k3bip","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826321980Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-n1kneshcsbhhhm0","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826348481Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6r7lt7b9ix9kh5f","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826694281Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-9dhrcn5cpe5uisl","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826726902Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826761923Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826788954Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-0aqdaa9s56yswcs","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826820884Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826853136Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-jq1dub05ctzmuq4","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826884057Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826920678Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-m6led8h09z1ptvi","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826949439Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-2uz8zwlq1dsy0c2","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.826977500Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-u225at3zqa1p3z8","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.827006870Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-o7s9tyipfs2clog","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.827041101Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.827073002Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-utdiffsujn32kdo","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Running","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.827101483Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-994h8u96ftqapyj","InstanceType":"m5large","PID":21538,"Priority":562948356941527226,"State":"Queued","level":"info","msg":"adding container to queue","time":"2020-08-04T17:15:10.827142035Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"PID":21538,"level":"info","msg":"FixStaleLocks starting.","time":"2020-08-04T17:15:10.827192025Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"PID":21538,"level":"info","msg":"FixStaleLocks finished (67.763┬Ás), starting scheduling.","time":"2020-08-04T17:15:10.827267778Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.827678140Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828136854Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-5bzpziva4hjxbsz","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828215726Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828366540Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-qsmrxzmevxa7g3r","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828463394Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828503765Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828544246Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828575477Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-utdiffsujn32kdo","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828621588Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828650709Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828695361Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-202pmq2yudghlce","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828730451Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-u225at3zqa1p3z8","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828777173Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6r7lt7b9ix9kh5f","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828811924Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-hfeljlax86puuzv","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828854776Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-c05nb5y3h3fym1j","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828888767Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-jq1dub05ctzmuq4","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828942188Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4fr3rdylpb43rgw","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828972349Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829013330Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-xmhvheu0w9pz1n4","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829039371Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-9dhrcn5cpe5uisl","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829097562Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k1o7j58y4eholt0","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829172385Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829227847Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-fvcl9pk068k3bip","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829313449Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-87n53kxywmdongp","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828492765Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-n1kneshcsbhhhm0","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.828879356Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-2uz8zwlq1dsy0c2","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829315249Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-m6led8h09z1ptvi","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829182225Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-wojhv8i8wdrf7zi","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829191125Z"}
Aug 04 17:15:10 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-0aqdaa9s56yswcs","PID":21538,"level":"info","msg":"cancelling container because not running on any worker","time":"2020-08-04T17:15:10.829199836Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-5bzpziva4hjxbsz","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.436968528Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-5bzpziva4hjxbsz","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.437018318Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.463455825Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-vnaw8o1p71tf82s","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.463503206Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.493507777Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.493556828Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.647100012Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.647146673Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-qsmrxzmevxa7g3r","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.846225740Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-qsmrxzmevxa7g3r","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.846273950Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:11.851541628Z"}
Aug 04 17:15:11 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:11.851588178Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.012460720Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.012512091Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.186924724Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.186977596Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-utdiffsujn32kdo","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.232025555Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-utdiffsujn32kdo","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.232084277Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.274956250Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.275009252Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.487063774Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.490202787Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","Command":"sudo docker ps -q","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:15:12.719042437Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-jq1dub05ctzmuq4","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.725643774Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-jq1dub05ctzmuq4","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.725688705Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4fr3rdylpb43rgw","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.735246159Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-4fr3rdylpb43rgw","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.735300000Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","Command":"sudo docker ps -q","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:15:12.779941498Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:12.800584661Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.47885156Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:12.800693494Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6r7lt7b9ix9kh5f","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.856038569Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-6r7lt7b9ix9kh5f","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.856960266Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.47885156Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:12.857393160Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:12.863467819Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.576945905Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:12.863863811Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.24","ContainerUUID":"pirca-dz642-ou1b7g429e7zjyy","Instance":"i-0aa227d482ae4d947","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:15:12.878867977Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.576945905Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:12.881464735Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.184","ContainerUUID":"pirca-dz642-o7s9tyipfs2clog","Instance":"i-0389f7836ca97a8d1","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:15:12.899411028Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","Command":"sudo docker ps -q","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"0217fb4cd67d\n","time":"2020-08-04T17:15:12.925466322Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","Command":"sudo docker ps -q","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"88b83b890d4b\n","time":"2020-08-04T17:15:12.939677255Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-fvcl9pk068k3bip","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:12.956184735Z"}
Aug 04 17:15:12 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-fvcl9pk068k3bip","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:12.956245676Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-xmhvheu0w9pz1n4","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:13.077333615Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-xmhvheu0w9pz1n4","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:13.077440328Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.078264643Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.377075135Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.078296214Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.104554084Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.377011603Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.106733048Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.114226922Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.377075135Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.116415816Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","ContainerUUID":"pirca-dz642-u225at3zqa1p3z8","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.134576156Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.377011603Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.134703470Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","Command":"sudo docker ps -q","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"64e59d5d2ca5\n","time":"2020-08-04T17:15:13.176159632Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.132","ContainerUUID":"pirca-dz642-u225at3zqa1p3z8","Instance":"i-077ddceb36aa3e39e","InstanceType":"m5large","PID":21538,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:13.245291347Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","Command":"sudo docker ps -q","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"f300575ecfce\n","time":"2020-08-04T17:15:13.299157377Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","Command":"sudo docker ps -q","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"","time":"2020-08-04T17:15:13.319167492Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.338876618Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.776933468Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.338940150Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.364548101Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.776933468Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.364653904Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.212","ContainerUUID":"pirca-dz642-05cvjg5hkarv0u7","Instance":"i-07387e0c310eab5cf","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:13.364880441Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","Command":"sudo docker ps -q","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"eaf7b34ba285\n","time":"2020-08-04T17:15:13.366930281Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","Command":"sudo docker ps -q","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"dac040ed5956\n","time":"2020-08-04T17:15:13.394337356Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.398702155Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.076931093Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.399072096Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.076931093Z","RunningContainers":0,"State":"idle","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.416845034Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.157","ContainerUUID":"pirca-dz642-52g8fr7mc7mgeke","Instance":"i-019ad782e2e093dd6","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process started","time":"2020-08-04T17:15:13.434203681Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","Command":"sudo docker ps -q","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"5d715815cf43\n","time":"2020-08-04T17:15:13.434617963Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.467406097Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.676900485Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.467472339Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.505012445Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.976944422Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.506164749Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-n1kneshcsbhhhm0","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:13.506102867Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-n1kneshcsbhhhm0","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:13.507020395Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.507555670Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.676900485Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.507650634Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.158","ContainerUUID":"pirca-dz642-oqaih0tq5ebaxj4","Instance":"i-08596513dc99fbdf9","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:13.507914611Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","ContainerUUID":"pirca-dz642-m6led8h09z1ptvi","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.524691500Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.976944422Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.524803663Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.541710296Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.876912999Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.541791189Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:13.556756802Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"ProbeStart":"2020-08-04T17:15:13.176918795Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:13.556835905Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.563306168Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:12.876912999Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.563408950Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.139","ContainerUUID":"pirca-dz642-4ollnqz3aapd7bk","Instance":"i-0e48884ccbd29e2a8","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:13.563708470Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","ContainerUUID":"pirca-dz642-k1o7j58y4eholt0","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:13.584798846Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.177","Instance":"i-0e9596a8178d051de","InstanceType":"t3small","PID":21538,"ProbeStart":"2020-08-04T17:15:13.176918795Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:13.584913420Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-9dhrcn5cpe5uisl","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:13.654300561Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-9dhrcn5cpe5uisl","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:13.654341413Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-202pmq2yudghlce","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:13.759362224Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-202pmq2yudghlce","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:13.759408225Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","Command":"sudo docker ps -q","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"63977b8778d9\n","time":"2020-08-04T17:15:13.764450795Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","Command":"sudo docker ps -q","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"91c484df767f\n","time":"2020-08-04T17:15:13.906063493Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:13.914539106Z"}
Aug 04 17:15:13 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:13.914602097Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-c05nb5y3h3fym1j","PID":21538,"State":"Cancelled","level":"info","msg":"container finished -- dropping from queue","time":"2020-08-04T17:15:14.021293317Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"ContainerUUID":"pirca-dz642-c05nb5y3h3fym1j","PID":21538,"State":"Cancelled","level":"info","msg":"dropping container from queue","time":"2020-08-04T17:15:14.021358029Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.021636128Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.276933196Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.021668848Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","ContainerUUID":"pirca-dz642-hfeljlax86puuzv","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.047437315Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.26","Instance":"i-03ab2fabc10b7c748","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.276933196Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.047574129Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","Command":"sudo docker ps -q","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"423df507a5e7\n","time":"2020-08-04T17:15:14.048616889Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.053366671Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.47693188Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.053442813Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","ContainerUUID":"pirca-dz642-wojhv8i8wdrf7zi","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.070758257Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.47693188Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.070880662Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","Command":"sudo docker ps -q","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"7e9effead87b\n","time":"2020-08-04T17:15:14.084482086Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","Command":"sudo docker ps -q","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"32f2591fee02\n","time":"2020-08-04T17:15:14.178194631Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.91","ContainerUUID":"pirca-dz642-m6led8h09z1ptvi","Instance":"i-01e89e0ccad3682d5","InstanceType":"m5large","PID":21538,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.209812950Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.218471077Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.576922432Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.218546100Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.235583616Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.576922432Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.235710500Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.110","ContainerUUID":"pirca-dz642-6ubt5yazj3wa8ox","Instance":"i-0243b29c06dddc419","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.235948547Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","Command":"sudo docker ps -q","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"90762d17a577\n","time":"2020-08-04T17:15:14.275936476Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.281121119Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.376905178Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.281209512Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.322864140Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.376905178Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.322979143Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.9","ContainerUUID":"pirca-dz642-k11wegl0b40kqi4","Instance":"i-072bbce31258191f6","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.323257242Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.331138016Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.676907964Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.331199988Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.365138386Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.676907964Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.365259620Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.38","ContainerUUID":"pirca-dz642-l5xd87wbkq3x0ff","Instance":"i-0b641b506b751f60b","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.365581599Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.222","ContainerUUID":"pirca-dz642-vvpbxorzar9mjs7","Instance":"i-0932181412f56de83","InstanceType":"m5large","PID":21538,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.394035375Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","Command":"sudo docker ps -q","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"73ac2524ccc5\n","time":"2020-08-04T17:15:14.418319417Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.438693752Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"ProbeStart":"2020-08-04T17:15:13.776915115Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.438760974Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","Command":"sudo docker ps -q","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"261c66e790a8\n","time":"2020-08-04T17:15:14.438871987Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","Command":"sudo docker ps -q","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"ac24e5b05a3a\n","time":"2020-08-04T17:15:14.452140132Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","ContainerUUID":"pirca-dz642-202pmq2yudghlce","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.475017752Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"ProbeStart":"2020-08-04T17:15:13.776915115Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.475155345Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.12","ContainerUUID":"pirca-dz642-202pmq2yudghlce","Instance":"i-0aee28622542c3c73","InstanceType":"t3small","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.475564888Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.251","ContainerUUID":"pirca-dz642-wojhv8i8wdrf7zi","Instance":"i-0c9c080eb91f47308","InstanceType":"m5large","PID":21538,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.506722934Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.562073988Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.876921447Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.562156591Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.572098416Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.976895078Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.572193700Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.588427542Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.876921447Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.588544345Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.19","ContainerUUID":"pirca-dz642-a65n49a4z5zfvjp","Instance":"i-03f74a6f4f9c5e468","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.588908346Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.590617077Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:13.976895078Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.590720870Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.33","ContainerUUID":"pirca-dz642-07rqxt9vlmonf86","Instance":"i-080f7e15b25014800","InstanceType":"m5large","PID":21538,"Reason":"not in queue","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.591028909Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.602174810Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:14.076916611Z","level":"info","msg":"instance booted; will try probeRunning","time":"2020-08-04T17:15:14.602244882Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","ContainerUUID":"pirca-dz642-87n53kxywmdongp","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"level":"info","msg":"crunch-run process detected","time":"2020-08-04T17:15:14.619282329Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"ProbeStart":"2020-08-04T17:15:14.076916611Z","RunningContainers":1,"State":"running","level":"info","msg":"probes succeeded, instance is in service","time":"2020-08-04T17:15:14.619392562Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.85","ContainerUUID":"pirca-dz642-87n53kxywmdongp","Instance":"i-0eb317b86a7cae649","InstanceType":"m5large","PID":21538,"Reason":"state=Cancelled","level":"info","msg":"killing crunch-run process","time":"2020-08-04T17:15:14.674600813Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.92","Command":"sudo docker ps -q","Instance":"i-05bc016d202eb0259","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"fb676037bcfc\n","time":"2020-08-04T17:15:14.705413028Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.84","Command":"sudo docker ps -q","Instance":"i-07300bb910b9a059b","InstanceType":"m5large","PID":21538,"level":"info","msg":"boot probe succeeded","stderr":"","stdout":"7bad22df0031\n","time":"2020-08-04T17:15:14.717132487Z"}
Aug 04 17:15:14 ip-10-254-0-45 arvados-dispatch-cloud[21538]: {"Address":"10.254.254.84","Instance":"i-07300bb910b9a059b","InstanceType":"m5large","PID":21538,"hash":"dbad4bc32522fef657c32a5bc49fa11e","level":"info","msg":"runner binary already exists on worker, with correct hash","path":"/var/lib/arvados/crunch-run~dbad4bc32522fef657c32a5bc49fa11e","time":"2020-08-04T17:15:14.837430362Z"}
...


Subtasks

Task #16666: Review 16663-running-ctrs-unknown-workersResolvedTom Clegg

Associated revisions

Revision 970061ce
Added by Tom Clegg about 1 month ago

Merge branch '16663-running-ctrs-unknown-workers'

fixes #16663

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <>

History

#1 Updated by Ward Vandewege about 2 months ago

  • Description updated (diff)

#2 Updated by Ward Vandewege about 2 months ago

  • Description updated (diff)

#3 Updated by Peter Amstutz about 2 months ago

From an initial reading it looks like a startup race condition: it discovered all the compute nodes but hasn't yet probed them to determine if any containers are running, so it assumes all the containers are orphaned and kills them. It shouldn't do that until the compute nodes have reported status at least once.

#4 Updated by Peter Amstutz about 2 months ago

  • Release set to 25

#6 Updated by Peter Amstutz about 2 months ago

  • Target version changed from To Be Groomed to 2020-08-26 Sprint

#8 Updated by Tom Clegg about 2 months ago

  • Assigned To set to Tom Clegg
  • Status changed from New to In Progress

#9 Updated by Ward Vandewege about 2 months ago

  • Description updated (diff)

#10 Updated by Tom Clegg about 2 months ago

  • Target version changed from 2020-08-26 Sprint to 2020-08-12 Sprint

#11 Updated by Ward Vandewege about 1 month ago

Tom Clegg wrote:

16663-running-ctrs-unknown-workers @ b2a1842d611a2739066a819badafaa2d2f14015d -- https://ci.arvados.org/view/Developer/job/developer-run-tests/1980/

(adds a test)

Maybe add a comment that the test is inherently potentially racy? Otherwise LGTM, thanks!

#12 Updated by Peter Amstutz about 1 month ago

  • Target version changed from 2020-08-12 Sprint to 2020-08-26 Sprint

#13 Updated by Anonymous about 1 month ago

  • Status changed from In Progress to Resolved

Also available in: Atom PDF