"no running process found" Errors in worker logs

[schmurfy]

Hello, I have been having these errors for a few versions now, they may have started when I switched to containerd.

I run one web process and 5 ephemeral workers on preemptible gcp compute instance on dedicated vms, they are running with this configuration:

concourse worker \
  --ephemeral \
  --work-dir /mnt/disk2 \
  --log-level=error \
  --baggageclaim-log-level=error \
  --tsa-host concourse.service.consul:2222 \
  --tsa-public-key /etc/concourse/keys/tsa_host_key.pub \
  --tsa-worker-private-key /etc/concourse/keys/worker_key \
  --runtime=containerd \
  --containerd-dns-server=10.0.16.57 \
  --containerd-dns-server=169.254.169.254

and here are the logs:

Sep 14 04:05:41 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T04:05:41.387237368Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"ce751adf-7b45-4163-4916-7d9d0a6423d9","session":"1.2.17"}}
Sep 14 04:05:48 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T04:05:48.883422915Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"c26aea4a-7b51-4170-7f58-21cb644cd98b","session":"1.2.24"}}
Sep 14 04:06:25 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T04:06:25.301091547Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"4d53f281-b783-435d-6a7b-b15f72f4b33e","session":"1.2.45"}}
Sep 14 04:13:43 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T04:13:43.170467290Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"e1af082f-6f47-4cf9-6176-def49073c6cc","session":"1.2.711"}}
Sep 14 04:13:52 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T04:13:52.786657238Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"ee3692b6-025d-48d8-6e15-e09ab6509d68","session":"1.2.721"}}
Sep 14 05:04:57 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T05:04:57.832896730Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"71d7f06b-2db4-4564-6669-82c778704cc8","session":"1.2.7353"}}
Sep 14 06:28:56 concourse-workers-6jh0 concourse[1487]: {"timestamp":"2021-09-14T06:28:56.225774032Z","level":"error","source":"worker","message":"worker.garden.garden-server.attach.failed","data":{"error":"load proc: no running process found: process does not exist resource: not found","handle":"db965590-1fa0-4a3e-680f-c21d98011e0c","session":"1.2.17528"}}

I not am sure what is the incidence of these errors but I have been struggling for a while trying to understand why sometimes my tasks take a long time to spawn once a worker is assigned, volume streaming between workers was one of the issue and I tried to switch to zstd but not sure if it improved much.

Here is the web process config:

CONCOURSE_SESSION_SIGNING_KEY=/etc/concourse/keys/session_signing_key
CONCOURSE_TSA_HOST_KEY=/etc/concourse/keys/tsa_host_key
CONCOURSE_TSA_AUTHORIZED_KEYS=/etc/concourse/keys/worker_key.pub
CONCOURSE_API_MAX_CONNS=10
CONCOURSE_BACKEND_MAX_CONNS=10

CONCOURSE_ENABLE_GLOBAL_RESOURCES=1
CONCOURSE_AUTH_DURATION=168h

CONCOURSE_PROMETHEUS_BIND_IP="0.0.0.0"
CONCOURSE_PROMETHEUS_BIND_PORT="9100"

CONCOURSE_LOG_LEVEL=error
CONCOURSE_TSA_LOG_LEVEL=error

CONCOURSE_STREAMING_ARTIFACTS_COMPRESSION=zstd
CONCOURSE_VAULT_LOOKUP_TEMPLATES=/main/{{.Pipeline}}/{{.Secret}},/main/{{.Secret}}

CONCOURSE_EXTERNAL_URL=https://xxxx
CONCOURSE_GITHUB_CLIENT_ID=xxx
CONCOURSE_GITHUB_CLIENT_SECRET=xxx
CONCOURSE_POSTGRES_USER=xxx
CONCOURSE_POSTGRES_PASSWORD=xxx
CONCOURSE_MAIN_TEAM_GITHUB_ORG=xxx

[schmurfy]

I am still having these and still have no idea what the hell it means.
This seems to be directly related to really slow operation of our pipelines, sometimes waiting for minutes to spawn a task

[klas-s]

It is not the case you're getting OOM events? If on containerd, cAdvisor will tell you about memory and CPU usage.

[schmurfy]

Hello, I looked at containerd logs and I don't see anything obvious:

7e90 namespace=concourse
Nov 26 18:08:13 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:13.034545849Z" level=info msg="cleaning up dead shim"
Nov 26 18:08:13 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:13.045009761Z" level=warning msg="cleanup warnings time=\"2021-11-26T18:08:13Z\" level=info msg=\"startin
g signal loop\" namespace=concourse pid=748065\n"
Nov 26 18:08:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:43.034449282Z" level=info msg="shim disconnected" id=813cc6c0-b937-435f-5b77-fad75b6e5434
Nov 26 18:08:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:43.034758475Z" level=warning msg="cleaning up after shim disconnected" id=813cc6c0-b937-435f-5b77-fad75b6
e5434 namespace=concourse
Nov 26 18:08:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:43.034789937Z" level=info msg="cleaning up dead shim"
Nov 26 18:08:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:08:43.045006446Z" level=warning msg="cleanup warnings time=\"2021-11-26T18:08:43Z\" level=info msg=\"startin
g signal loop\" namespace=concourse pid=748254\n"
Nov 26 18:10:16 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:10:16.203607681Z" level=info msg="starting signal loop" namespace=concourse path=/run/containerd/io.containe
rd.runtime.v2.task/concourse/2aaeac77-e2e6-49aa-56bd-08aee3697a99 pid=750219
Nov 26 18:10:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:10:43.059370262Z" level=info msg="shim disconnected" id=2aaeac77-e2e6-49aa-56bd-08aee3697a99
Nov 26 18:10:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:10:43.059971000Z" level=warning msg="cleaning up after shim disconnected" id=2aaeac77-e2e6-49aa-56bd-08aee36
97a99 namespace=concourse
Nov 26 18:10:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:10:43.060134059Z" level=info msg="cleaning up dead shim"
Nov 26 18:10:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:10:43.070954426Z" level=warning msg="cleanup warnings time=\"2021-11-26T18:10:43Z\" level=info msg=\"startin
g signal loop\" namespace=concourse pid=750596\n"
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.051962392Z" level=info msg="shim disconnected" id=8a8c5348-c92b-4fbf-70f2-38070e7d88e9
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.052044072Z" level=warning msg="cleaning up after shim disconnected" id=8a8c5348-c92b-4fbf-70f2-38070e7
d88e9 namespace=concourse
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.052056530Z" level=info msg="cleaning up dead shim"
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.064939609Z" level=warning msg="cleanup warnings time=\"2021-11-26T18:11:43Z\" level=info msg=\"startin
g signal loop\" namespace=concourse pid=751086\n"
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.067001241Z" level=info msg="shim disconnected" id=0ea5d824-7cd1-4192-7638-821629d62ed5
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.067078948Z" level=warning msg="cleaning up after shim disconnected" id=0ea5d824-7cd1-4192-7638-821629d
62ed5 namespace=concourse
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.067095652Z" level=info msg="cleaning up dead shim"
Nov 26 18:11:43 concourse-workers-7qf9 containerd[545]: time="2021-11-26T18:11:43.078414634Z" level=warning msg="cleanup warnings time=\"2021-11-26T18:11:43Z\" level=info msg=\"startin
g signal loop\" namespace=concourse pid=751124\n"

my concourse web and workers are all running on dedicated vms

[Yuriy6735]

Have the same issue.
concourse 7.6.0 with containerd.
@schmurfy did you fix these errors?

[schmurfy]

a bit late but no and... yes, it somehow fixed itself...