Actions
Bug #16663
closed
[a-d-c] restarting a-d-c kills all running workflows
Story points:
-
Release:
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"}
...
Updated by Peter Amstutz almost 4 years 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.
Updated by Tom Clegg almost 4 years ago
16663-running-ctrs-unknown-workers @ 3aa3fb78afa46e98c9be345045f4fea9fea0f08c -- developer-run-tests: #1979
Updated by Peter Amstutz almost 4 years ago
- Target version changed from To Be Groomed to 2020-08-26 Sprint
Updated by Tom Clegg almost 4 years ago
16663-running-ctrs-unknown-workers @ b2a1842d611a2739066a819badafaa2d2f14015d -- developer-run-tests: #1980
(adds a test)
Updated by Tom Clegg almost 4 years ago
- Assigned To set to Tom Clegg
- Status changed from New to In Progress
Updated by Tom Clegg almost 4 years ago
- Target version changed from 2020-08-26 Sprint to 2020-08-12 Sprint
Updated by Ward Vandewege over 3 years ago
Tom Clegg wrote:
16663-running-ctrs-unknown-workers @ b2a1842d611a2739066a819badafaa2d2f14015d -- developer-run-tests: #1980
(adds a test)
Maybe add a comment that the test is inherently potentially racy? Otherwise LGTM, thanks!
Updated by Peter Amstutz over 3 years ago
- Target version changed from 2020-08-12 Sprint to 2020-08-26 Sprint
Updated by Anonymous over 3 years ago
- Status changed from In Progress to Resolved
Applied in changeset arvados|970061ceccf362fe0d9236d7ff16a5535b0d01af.
Actions