search

hashicorp / nomad-driver-podman

A nomad task driver plugin for sandboxing workloads in podman containers
https://developer.hashicorp.com/nomad/plugins/drivers/podman
Mozilla Public License 2.0
224 stars 61 forks source link

Plugin kill container about every 10 minutes #289

Closed MrDefacto closed 9 months ago

MrDefacto commented 9 months ago

command 'podman events' output: 2023-10-03 01:44:42.295682624 +0200 CEST container died c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:44:42.848359232 +0200 CEST container remove c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:44:56.059824618 +0200 CEST container create 223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:44:56.203938984 +0200 CEST container init 223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:44:56.208133504 +0200 CEST container start 223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:54:52.899702229 +0200 CEST container died 223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:54:53.474942108 +0200 CEST container remove 223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:55:04.653785922 +0200 CEST container create 40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:55:04.784097454 +0200 CEST container init 40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d) 2023-10-03 01:55:04.787590965 +0200 CEST container start 40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 (image=docker.io/library/busybox:1, name=web-1ded7dc4-b043-dd82-7860-bde579be5f3d)

nomad log: Oct 03 01:44:05 test.network.local nomad[3889]: 2023-10-03T01:44:05.017+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration=1.327159ms Oct 03 01:44:05 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration=1.327159ms Oct 03 01:44:15 test.network.local nomad[3889]: 2023-10-03T01:44:15.019+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="523.283µs" Oct 03 01:44:15 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="523.283µs" Oct 03 01:44:25 test.network.local nomad[3889]: 2023-10-03T01:44:25.021+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="589.572µs" Oct 03 01:44:25 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="589.572µs" Oct 03 01:44:33 test.network.local nomad[3889]: 2023-10-03T01:44:33.241+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Container is not running anymore: driver=podman container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 error="No such Container" @module=podman.podmanHandle timestamp="2023-10-03T01:44:33.241+0200" Oct 03 01:44:33 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Container is not running anymore: driver=podman container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 error="No such Container" @module=podman.podmanHandle timestamp="2023-10-03T01:44:33.241+0200" Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.238+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Stopping exitWatcher: driver=podman @module=podman.podmanHandle container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 timestamp="2023-10-03T01:44:34.238+0200" Oct 03 01:44:34 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Stopping exitWatcher: driver=podman @module=podman.podmanHandle container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 timestamp="2023-10-03T01:44:34.238+0200" Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.238+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Terminated msg="Exit Code: 0" failed=false Oct 03 01:44:34 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Terminated msg="Exit Code: 0" failed=false Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.240+0200 [INFO] client.alloc_runner.task_runner: restarting task: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web reason="Restart within policy" delay=17.717831571s Oct 03 01:44:34 test.network.local nomad[3889]: client.alloc_runner.task_runner: restarting task: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web reason="Restart within policy" delay=17.717831571s Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.240+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Restarting msg="Task restarting in 17.717831571s" failed=false Oct 03 01:44:34 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Restarting msg="Task restarting in 17.717831571s" failed=false Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.240+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Stopping statsEmitter: driver=podman container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 @module=podman.podmanHandle timestamp="2023-10-03T01:44:34.240+0200" Oct 03 01:44:34 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Stopping statsEmitter: driver=podman container=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 @module=podman.podmanHandle timestamp="2023-10-03T01:44:34.240+0200" Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.525+0200 [DEBUG] client: updated allocations: index=17476 total=1 pulled=0 filtered=1 Oct 03 01:44:34 test.network.local nomad[3889]: client: updated allocations: index=17476 total=1 pulled=0 filtered=1 Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.525+0200 [DEBUG] client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:44:34 test.network.local nomad[3889]: 2023-10-03T01:44:34.526+0200 [DEBUG] client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:44:34 test.network.local nomad[3889]: client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:44:34 test.network.local nomad[3889]: client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:44:35 test.network.local nomad[3889]: 2023-10-03T01:44:35.023+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="629.539µs" Oct 03 01:44:35 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="629.539µs" Oct 03 01:44:42 test.network.local nomad[3889]: 2023-10-03T01:44:42.848+0200 [INFO] client.driver_mgr.docker: removed untracked container: driver=docker container_id=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 Oct 03 01:44:42 test.network.local nomad[3889]: client.driver_mgr.docker: removed untracked container: driver=docker container_id=c474157abbeb148c40daae9b486e96936301a4296d5d02f7a15bdd8d99d68f49 Oct 03 01:44:45 test.network.local nomad[3889]: 2023-10-03T01:44:45.025+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="223.062µs" Oct 03 01:44:45 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="223.062µs" Oct 03 01:44:51 test.network.local nomad[3889]: 2023-10-03T01:44:51.959+0200 [DEBUG] client.alloc_runner.task_runner: lifecycle start condition has been met, proceeding: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web Oct 03 01:44:51 test.network.local nomad[3889]: client.alloc_runner.task_runner: lifecycle start condition has been met, proceeding: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web Oct 03 01:44:55 test.network.local nomad[3889]: 2023-10-03T01:44:55.027+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="296.234µs" Oct 03 01:44:55 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="296.234µs" Oct 03 01:44:55 test.network.local nomad[3889]: 2023-10-03T01:44:55.961+0200 [WARN] client.alloc_runner.task_runner.task_hook.logmon.nomad: timed out waiting for read-side of process output pipe to close: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: 2023-10-03T01:44:55.961+0200 [DEBUG] client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stdout.fifo timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: timed out waiting for read-side of process output pipe to close: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: 2023-10-03T01:44:55.961+0200 [DEBUG] client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stderr.fifo @module=logmon timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stdout.fifo timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stderr.fifo @module=logmon timestamp="2023-10-03T01:44:55.961+0200" Oct 03 01:44:55 test.network.local nomad[3889]: 2023-10-03T01:44:55.963+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: applied labels on the container: driver=podman @module=podman labels=map[] timestamp="2023-10-03T01:44:55.963+0200" Oct 03 01:44:55 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: applied labels on the container: driver=podman @module=podman labels=map[] timestamp="2023-10-03T01:44:55.963+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.039+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Found imageID: driver=podman busybox:1="in local storage" @module=podman a416a98b71e224a31ee99cff8e16063554498227d2b696152a9c3e0aa65e5824="for image" timestamp="2023-10-03T01:44:56.039+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Found imageID: driver=podman busybox:1="in local storage" @module=podman a416a98b71e224a31ee99cff8e16063554498227d2b696152a9c3e0aa65e5824="for image" timestamp="2023-10-03T01:44:56.039+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.217+0200 [INFO] client.driver_mgr.nomad-driver-podman: Completely started container: driver=podman @module=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 ip=10.88.0.27 taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.217+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.217+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Monitoring container: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:44:56.217+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Completely started container: driver=podman @module=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 ip=10.88.0.27 taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.217+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Monitoring container: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:44:56.217+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.218+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Started msg="Task started by client" failed=false Oct 03 01:44:56 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Started msg="Task started by client" failed=false Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.219+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: WaitTask called: driver=podman @module=podman task=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.219+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: TaskStats called: driver=podman @module=podman taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: WaitTask called: driver=podman @module=podman task=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.219+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Starting exitWatcher: driver=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 @module=podman.podmanHandle timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.219+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Starting statsEmitter: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: TaskStats called: driver=podman @module=podman taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/83b9e1ca timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Starting exitWatcher: driver=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 @module=podman.podmanHandle timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Starting statsEmitter: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:44:56.219+0200" Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.438+0200 [DEBUG] client: updated allocations: index=17477 total=1 pulled=0 filtered=1 Oct 03 01:44:56 test.network.local nomad[3889]: client: updated allocations: index=17477 total=1 pulled=0 filtered=1 Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.438+0200 [DEBUG] client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:44:56 test.network.local nomad[3889]: 2023-10-03T01:44:56.438+0200 [DEBUG] client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:44:56 test.network.local nomad[3889]: client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:44:56 test.network.local nomad[3889]: client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:45:05 test.network.local nomad[3889]: 2023-10-03T01:45:05.029+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="260.034µs" Oct 03 01:45:05 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="260.034µs" ... Oct 03 01:54:25 test.network.local nomad[3889]: 2023-10-03T01:54:25.137+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="248.471µs" Oct 03 01:54:25 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="248.471µs" Oct 03 01:54:35 test.network.local nomad[3889]: 2023-10-03T01:54:35.140+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="615.952µs" Oct 03 01:54:35 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="615.952µs" Oct 03 01:54:43 test.network.local nomad[3889]: 2023-10-03T01:54:43.601+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Container is not running anymore: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 error="No such Container" timestamp="2023-10-03T01:54:43.601+0200" Oct 03 01:54:43 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Container is not running anymore: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 error="No such Container" timestamp="2023-10-03T01:54:43.601+0200" Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.599+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Stopping exitWatcher: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:54:44.599+0200" Oct 03 01:54:44 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Stopping exitWatcher: driver=podman @module=podman.podmanHandle container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 timestamp="2023-10-03T01:54:44.599+0200" Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.599+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Terminated msg="Exit Code: 0" failed=false Oct 03 01:54:44 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Terminated msg="Exit Code: 0" failed=false Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.601+0200 [INFO] client.alloc_runner.task_runner: restarting task: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web reason="Restart within policy" delay=16.020490031s Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.601+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Restarting msg="Task restarting in 16.020490031s" failed=false Oct 03 01:54:44 test.network.local nomad[3889]: client.alloc_runner.task_runner: restarting task: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web reason="Restart within policy" delay=16.020490031s Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.601+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Stopping statsEmitter: driver=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 @module=podman.podmanHandle timestamp="2023-10-03T01:54:44.601+0200" Oct 03 01:54:44 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Restarting msg="Task restarting in 16.020490031s" failed=false Oct 03 01:54:44 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Stopping statsEmitter: driver=podman container=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 @module=podman.podmanHandle timestamp="2023-10-03T01:54:44.601+0200" Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.742+0200 [DEBUG] client: updated allocations: index=17489 total=1 pulled=0 filtered=1 Oct 03 01:54:44 test.network.local nomad[3889]: client: updated allocations: index=17489 total=1 pulled=0 filtered=1 Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.742+0200 [DEBUG] client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:54:44 test.network.local nomad[3889]: 2023-10-03T01:54:44.742+0200 [DEBUG] client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:54:44 test.network.local nomad[3889]: client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:54:44 test.network.local nomad[3889]: client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:54:45 test.network.local nomad[3889]: 2023-10-03T01:54:45.142+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="243.942µs" Oct 03 01:54:45 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="243.942µs" Oct 03 01:54:53 test.network.local nomad[3889]: 2023-10-03T01:54:53.475+0200 [INFO] client.driver_mgr.docker: removed untracked container: driver=docker container_id=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 Oct 03 01:54:53 test.network.local nomad[3889]: client.driver_mgr.docker: removed untracked container: driver=docker container_id=223f625976e9db0f9515f07cb0ffece8a54dd13b5e2d5afc17e8eb1d697030e1 Oct 03 01:54:55 test.network.local nomad[3889]: 2023-10-03T01:54:55.144+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="613.507µs" Oct 03 01:54:55 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="613.507µs" Oct 03 01:55:00 test.network.local nomad[3889]: 2023-10-03T01:55:00.622+0200 [DEBUG] client.alloc_runner.task_runner: lifecycle start condition has been met, proceeding: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web Oct 03 01:55:00 test.network.local nomad[3889]: client.alloc_runner.task_runner: lifecycle start condition has been met, proceeding: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.624+0200 [WARN] client.alloc_runner.task_runner.task_hook.logmon.nomad: timed out waiting for read-side of process output pipe to close: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.624+0200 [DEBUG] client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stdout.fifo @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.624+0200 [DEBUG] client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stderr.fifo @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: timed out waiting for read-side of process output pipe to close: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stdout.fifo @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web path=/opt/nomad/data/alloc/1ded7dc4-b043-dd82-7860-bde579be5f3d/alloc/logs/.web.stderr.fifo @module=logmon timestamp="2023-10-03T01:55:04.624+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.627+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: applied labels on the container: driver=podman labels=map[] @module=podman timestamp="2023-10-03T01:55:04.626+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: applied labels on the container: driver=podman labels=map[] @module=podman timestamp="2023-10-03T01:55:04.626+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.634+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Found imageID: driver=podman @module=podman a416a98b71e224a31ee99cff8e16063554498227d2b696152a9c3e0aa65e5824="for image" busybox:1="in local storage" timestamp="2023-10-03T01:55:04.634+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Found imageID: driver=podman @module=podman a416a98b71e224a31ee99cff8e16063554498227d2b696152a9c3e0aa65e5824="for image" busybox:1="in local storage" timestamp="2023-10-03T01:55:04.634+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.795+0200 [INFO] client.driver_mgr.nomad-driver-podman: Completely started container: driver=podman ip=10.88.0.28 taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 @module=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 timestamp="2023-10-03T01:55:04.795+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.795+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Monitoring container: driver=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 @module=podman.podmanHandle timestamp="2023-10-03T01:55:04.795+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Completely started container: driver=podman ip=10.88.0.28 taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 @module=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 timestamp="2023-10-03T01:55:04.795+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Monitoring container: driver=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 @module=podman.podmanHandle timestamp="2023-10-03T01:55:04.795+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.796+0200 [INFO] client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Started msg="Task started by client" failed=false Oct 03 01:55:04 test.network.local nomad[3889]: client.alloc_runner.task_runner: Task event: alloc_id=1ded7dc4-b043-dd82-7860-bde579be5f3d task=web type=Started msg="Task started by client" failed=false Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.796+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: TaskStats called: driver=podman @module=podman taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: TaskStats called: driver=podman @module=podman taskID=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.797+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Starting statsEmitter: driver=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 @module=podman.podmanHandle timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.797+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: WaitTask called: driver=podman @module=podman task=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: 2023-10-03T01:55:04.797+0200 [DEBUG] client.driver_mgr.nomad-driver-podman: Starting exitWatcher: driver=podman @module=podman.podmanHandle container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 timestamp="2023-10-03T01:55:04.797+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Starting statsEmitter: driver=podman container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 @module=podman.podmanHandle timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: WaitTask called: driver=podman @module=podman task=1ded7dc4-b043-dd82-7860-bde579be5f3d/web/686df254 timestamp="2023-10-03T01:55:04.796+0200" Oct 03 01:55:04 test.network.local nomad[3889]: client.driver_mgr.nomad-driver-podman: Starting exitWatcher: driver=podman @module=podman.podmanHandle container=40ac7ccc0bb0c6bb718d3af4655a54fa33b53f4efaa1bc76c277b33349cc9d28 timestamp="2023-10-03T01:55:04.797+0200" Oct 03 01:55:05 test.network.local nomad[3889]: 2023-10-03T01:55:05.063+0200 [DEBUG] client: updated allocations: index=17490 total=1 pulled=0 filtered=1 Oct 03 01:55:05 test.network.local nomad[3889]: 2023-10-03T01:55:05.063+0200 [DEBUG] client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:55:05 test.network.local nomad[3889]: 2023-10-03T01:55:05.063+0200 [DEBUG] client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:55:05 test.network.local nomad[3889]: client: updated allocations: index=17490 total=1 pulled=0 filtered=1 Oct 03 01:55:05 test.network.local nomad[3889]: client: allocation updates: added=0 removed=0 updated=0 ignored=1 Oct 03 01:55:05 test.network.local nomad[3889]: client: allocation updates applied: added=0 removed=0 updated=0 ignored=1 errors=0 Oct 03 01:55:05 test.network.local nomad[3889]: 2023-10-03T01:55:05.146+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="484.107µs" Oct 03 01:55:05 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="484.107µs" Oct 03 01:55:15 test.network.local nomad[3889]: 2023-10-03T01:55:15.148+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="573.039µs" Oct 03 01:55:15 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="573.039µs" Oct 03 01:55:25 test.network.local nomad[3889]: 2023-10-03T01:55:25.150+0200 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration="612.927µs" Oct 03 01:55:25 test.network.local nomad[3889]: http: request complete: method=GET path=/v1/agent/health?type=client duration="612.927µs"

Tested with Nomad 1.6.2, the latest plugin version 0.5.1, and also with the master version from GitHub. I tried Podman versions 2.3.x, 2.5.x, and 2.7.0, and received the same result. When a container is launched manually using Podman, it doesn't quit. I tested with two different containers to ensure the container itself wasn't the issue. It seems the problem lies with the plugin. I also tested the same job with Docker (simply by changing the driver), and it worked flawlessly.

MrDefacto commented 9 months ago

problem was with both docker and podman plugin enabled in nomad.

collinspeight commented 7 months ago

Thanks @MrDefacto! For future people who run into this issue, the fix is to add the following to your client agent config:

client {
...
  options = {
    "driver.denylist" = "docker"
  }
}