1503894 - EC2 instances rebooting in mid-task

Status: RESOLVED FIXED

(Taskcluster :: Operations and Service Requests, task)

Description

[Dustin J. Mitchell [:dustin] (he/him)]

Bug 1503819 mentions one time I saw this (on i-0cc7d94dba8b93b61)

https://tools.taskcluster.net/groups/GiC_VlzeQ2evaShgCCVXWA/tasks/GiC_VlzeQ2evaShgCCVXWA/runs/0 shows another, on i-0896564d7c1a22d4a


Nov 01 13:59:42 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0896564d7c1a22d4a","workerGroup":"us-east-1","workerType":"gecko-3-decision","workerNodeType":"m5d.xlarge","alive":true,"uptime":807,"interval":30000}
Nov 01 14:00:12 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0896564d7c1a22d4a","workerGroup":"us-east-1","workerType":"gecko-3-decision","workerNodeType":"m5d.xlarge","alive":true,"uptime":837,"interval":30000}
Nov 01 14:00:42 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0896564d7c1a22d4a","workerGroup":"us-east-1","workerType":"gecko-3-decision","workerNodeType":"m5d.xlarge","efficiency":61.33800461361015,"uptime":867,"totalRunTime":1063601}
Nov 01 14:00:42 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0896564d7c1a22d4a","workerGroup":"us-east-1","workerType":"gecko-3-decision","workerNodeType":"m5d.xlarge","alive":true,"uptime":867,"interval":30000}
Nov 01 14:01:12 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0896564d7c1a22d4a","workerGroup":"us-east-1","workerType":"gecko-3-decision","workerNodeType":"m5d.xlarge","alive":true,"uptime":897,"interval":30000}
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a rsyslogd: [origin software="rsyslogd" swVersion="7.4.4" x-pid="1061" x-info="http://www.rsyslog.com"] start
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a rsyslogd-2307: warning: ~ action is deprecated, consider using the 'stop' statement instead [try http://www.rsyslog.com/e/2307 ]
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a rsyslogd: rsyslogd's groupid changed to 104
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a rsyslogd: rsyslogd's userid changed to 101
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a rsyslogd-2039: Could no open output pipe '/dev/xconsole': No such file or directory [try http://www.rsyslog.com/e/2039 ]
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a kernel: [    0.000000] Initializing cgroup subsys cpuset
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a kernel: [    0.000000] Initializing cgroup subsys cpu
Nov 01 14:01:57 docker-worker.aws-provisioner.us-east-1b.ami-17373968.m5d-xlarge.i-0896564d7c1a22d4a kernel: [    0.000000] Initializing cgroup subsys cpuacct

Comment 1

[Dustin J. Mitchell [:dustin] (he/him)]

https://tools.taskcluster.net/groups/AwXwzsaFQFOMq6WNlloFvA/tasks/AwXwzsaFQFOMq6WNlloFvA/runs/0


Nov 01 13:48:52 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [10202.588740] docker0: port 6(vethb48f54b) entered forwarding state
Nov 01 13:49:08 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","alive":true,"uptime":10218,"interval":30000}
Nov 01 13:49:09 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","efficiency":62.131343575692334,"uptime":10219,"totalRunTime":12698404}
Nov 01 13:49:38 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","alive":true,"uptime":10248,"interval":30000}
Nov 01 13:50:08 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","alive":true,"uptime":10278,"interval":30000}
Nov 01 13:50:09 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","efficiency":62.35248565035509,"uptime":10279,"totalRunTime":12818424}
Nov 01 13:50:38 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","alive":true,"uptime":10308,"interval":30000}
Nov 01 13:51:08 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"aliveness check","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","alive":true,"uptime":10338,"interval":30000}
Nov 01 13:51:09 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"aws-provisioner-v1","workerId":"i-0d66f0a44e775d956","workerGroup":"us-west-1","workerType":"gecko-3-decision","workerNodeType":"c5.xlarge","efficiency":62.57197988200019,"uptime":10339,"totalRunTime":12938634}
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 rsyslogd: [origin software="rsyslogd" swVersion="7.4.4" x-pid="1044" x-info="http://www.rsyslog.com"] start
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 rsyslogd-2307: warning: ~ action is deprecated, consider using the 'stop' statement instead [try http://www.rsyslog.com/e/2307 ]
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 rsyslogd: rsyslogd's groupid changed to 104
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 rsyslogd: rsyslogd's userid changed to 101
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] Initializing cgroup subsys cpuset
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] Initializing cgroup subsys cpu
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] Initializing cgroup subsys cpuacct
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] Linux version 4.4.0-1014-aws (buildd@lcy01-amd64-019) (gcc version 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04.4) ) #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 (Ubuntu 4.4.0-1014.14taskcluster1-aws 4.4.98)
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-4.4.0-1014-aws root=UUID=1d28c249-e3c3-41af-a774-40d31c3580f1 ro console=tty1 console=ttyS0
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000] KERNEL supported cpus:
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000]   Intel GenuineIntel
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000]   AMD AuthenticAMD
Nov 01 13:51:28 docker-worker.aws-provisioner.us-west-1c.ami-6a5ab709.c5-xlarge.i-0d66f0a44e775d956 kernel: [    0.000000]   Centaur CentaurHauls

Comment 2

[Dustin J. Mitchell [:dustin] (he/him)]

So *possibly* related: at the second when the instance in the previous comment exited, I see in papertrail, with the system name taken literally:


Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686442.448424] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686588.054434] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686671.051688] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686020.900591] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686994.931733] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [685856.092404] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687224.592040] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687508.389608] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686094.417673] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [683488.867198] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686378.925916] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687407.767079] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686512.855415] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687267.522448] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687099.644120] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687590.037026] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [687309.417179] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686514.721764] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686413.793178] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"terraform-packet","workerId":"machine-2","workerGroup":"packet-sjc1","workerType":"gecko-t-linux","workerNodeType":"packet.net","efficiency":10.56730150479002,"uptime":7973870,"totalRunTime":1685245769}
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686443.158365] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: {"type":"reporting efficiency","source":"top","provisionerId":"terraform-packet","workerId":"machine-0","workerGroup":"packet-sjc1","workerType":"gecko-t-linux","workerNodeType":"packet.net","efficiency":10.443570174205401,"uptime":7973863,"totalRunTime":1665511956}
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686671.749690] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686588.794958] init: docker-worker main process ended, respawning
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker: AssertionError [ERR_ASSERTION]: Must provide a rootUrl to taskcluster-lib-monitor
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at monitor (/root/docker_worker/node_modules/taskcluster-lib-monitor/src/index.js:59:3)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at __dirname (/root/docker_worker/src/bin/worker.js:162:23)
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at <anonymous>
Nov 01 13:51:09 docker-worker.aws-provisioner.... docker-worker:     at process._tickDomainCallback (internal/process/next_tick.js:228:7)
Nov 01 13:51:09 docker-worker.aws-provisioner.... kernel: [686995.647357] init: docker-worker main process ended, respawning

Comment 3

[Dustin J. Mitchell [:dustin] (he/him)]

Searching for "unknown server error", which is the error docker-worker logs when it starts up for the second time on a host,
  https://papertrailapp.com/groups/853883/events?q=program%3Adocker-worker%20error%20retrieving%20secrets
shows about 30 events per hour.

Comment 4

[Dustin J. Mitchell [:dustin] (he/him)]

Current hypothesis is that this is OOM related.  OOMs lead to panics in our kernel configuration, and panics lead to reboots.  And it's unlikely we'd see logging about any of that.  So everything matches.

This is mostly occurring on gecko-3-decision (but not exclusively) so the thought is that something in the decision task is using gobs of memory.  Capacity=2 for that workerType, so it's possible that the memory usage would cause another task to crash, e.g.,
  https://tools.taskcluster.net/groups/Hv-7sfamQgyW6qvHIneRqQ/tasks/Hv-7sfamQgyW6qvHIneRqQ/runs/0/logs/public%2Flogs%2Flive.log

I've set the capacity of this workerType to 1 for the moment.  Let's see if that improves the situation at all.  Note that it will take a bit for the existing workers to finish their jobs (I've quarantined some of them).

We're also going to try to look back through system logs to find when this began.

Comment 5

[Dustin J. Mitchell [:dustin] (he/him)]

Attachment: hg-loop.txt

So I tried running
  https://tools.taskcluster.net/groups/JZF3zWbVS3WTiyXu1zFJYw/tasks/JZF3zWbVS3WTiyXu1zFJYw/details
manually on my laptop.  The `hg robustcheckout` failed, and failed in such a way that hg rapidly increased its memory usage. Output is attached, with some progress-bar stuff omitted.

Greg, can you have a look at this?  I'm guessing this is because it's somehow trying to clone comm-central and not gecko-central?

Comment 6

[Dustin J. Mitchell [:dustin] (he/him)]

I should say, this seems to be the smoking gun for memory consumption.  The task I mentioned in comment 5 ran into claim-expired 3 times before hitting its deadline.

Two things have changed recently:
 * we upgraded the decision image used in a few of the more "corner" cases.  This included cron tasks.  It updated the hg version
 * rjl just landed .cron.yml changes to do comm-central things a few days ago, so tasks like the above would not have been run before that.

Comment 7

[Dustin J. Mitchell [:dustin] (he/him)]

Activities in progress / planned:

* Greg or delegate to investigate the memory leak in hg
* Irene is working on setting up visibility into "old" papertrail logs via AWS Athena; we can use this to figure out when the issue started
* The change to the instance capacity will help, as it will mean that wayward tasks can only hurt themselves
* I will revert the change to add the taskcluster-cron feature to the comm repos (in 20-20 hindsight this was a bad idea)
* Wander will work to add memory usage report to docker-worker (new bug)
* In generic-worker, we should have a way to limit task memory via docker/cgroups (new bug)

Comment 8

[Dustin J. Mitchell [:dustin] (he/him)]

Attachment: Bug 1503894 - disable taskcluster-cron for comm-central repos

The cron hook expects that it is checking out a gecko tree.  Robustcheckout
kind of loses its mind when it clones mozilla-unified, then finds no ancestor
in common with a comm-central pull.

Comment 9

[Dustin J. Mitchell [:dustin] (he/him)]

(we can figure out a way to run cron-tasks for comm-central, but the priority for now is to stop the crashing)

Comment 11

[Rob Lemley [:rjl]]

I think I found the problem.

https://hg.mozilla.org/build/ci-admin/file/tip/ciadmin/generate/cron_tasks.py#l22

Look at project.parent_repo to determine if running on a Mozilla or Comm repo.

Looking at the project configurations:

https://hg.mozilla.org/build/ci-admin/file/tip/ciadmin/generate/cron_tasks.py#l22
comm-central:
  repo: https://hg.mozilla.org/comm-central
  repo_type: hg
  access: scm_level_3
  trust_domain: comm
  parent_repo: https://hg.mozilla.org/mozilla-central
  features:
    gecko-roles: true
    gecko-actions: true
    taskcluster-cron: false
    taskcluster-push: true
    is-trunk: true

comm-central has a field named "parent_repo".

However, comm-esr60 does not:

https://hg.mozilla.org/build/ci-configuration/file/tip/projects.yml#l94
comm-esr60:
  repo: https://hg.mozilla.org/releases/comm-esr60
  repo_type: hg
  access: scm_level_3
  trust_domain: comm
  features:
    gecko-roles: true
    gecko-actions: true
    taskcluster-cron: false
    taskcluster-push: true

That would explain the funky hg command from Dustin's run in comment 5.

Do we have run output from a cron job that ran on comm-beta? It has parent_repo set, so going off this theory it should have run fine.

https://hg.mozilla.org/build/ci-configuration/file/tip/projects.yml#l143
comm-beta:
  repo: https://hg.mozilla.org/releases/comm-beta
  repo_type: hg
  access: scm_level_3
  trust_domain: comm
  parent_repo: https://hg.mozilla.org/releases/mozilla-beta
  features:
    gecko-roles: true
    gecko-actions: true
    taskcluster-cron: false
    taskcluster-push: true

Comment 12

[Rob Lemley [:rjl]]

Attachment: Bug 1503894 - reenable taskcluster-cron for comm-central repo. r?tomprince

This goes along with a .cron.yml update in comm-central that removes the
periodic-file-update cron configuration. (Bug 1499590 comment 15)

This will get comm-central nightly builds working again.

Comment 13

[Dustin J. Mitchell [:dustin] (he/him)]

Over to Rob to wrap this up (I'm happy to help)

Comment 14

[Intermittent Failures Robot]

1 failures in 2485 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503894&startday=2018-12-10&endday=2018-12-16&tree=all

Comment 15

[Rob Lemley [:rjl]]

I'm going to close this bug. I'm tracking the original task of getting these jobs running in bug 1499590. I'll submit another bug when ready to enable cron on comm-esr60 and comm-beta again.

Comment 16

[Intermittent Failures Robot]

2 failures in 4625 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 1

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 1
  • debug: 1
• android-em-7-0-x86_64-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1503894&startday=2024-06-10&endday=2024-06-16&tree=all