Running tests locally #148

optiz0r · 2022-01-05T10:59:03Z

Hi,

Thinking about starting to write some PRs against this project, I was looking to run the tests locally to confirm everything was clean before starting, and that any changes I make still pass tests. I'm having a difficult time getting the tests to run at all, and am seeing lots of failures that don't appear to be happening when running under Github Actions. Are there some undocumented environmental steps required to make tests run?

go test fails with t.Parallel called multiple times. Running the test suite with env CI=1 appears to fix this:

Stack trace

> go test
--- FAIL: TestPodmanDriver_Pull (0.00s)
panic: testing: t.Parallel called multiple times [recovered]
        panic: testing: t.Parallel called multiple times

goroutine 75 [running]:
testing.tRunner.func1.2({0xdec660, 0x10c3090})
        /home/ben/go/src/testing/testing.go:1209 +0x24e
testing.tRunner.func1()
        /home/ben/go/src/testing/testing.go:1212 +0x218
panic({0xdec660, 0x10c3090})
        /home/ben/go/src/runtime/panic.go:1038 +0x215
testing.(*T).Parallel(0xf6d332)
        /home/ben/go/src/testing/testing.go:1077 +0x298
github.com/hashicorp/nomad-driver-podman.startDestroyInspect(_, {{0x1758ff0, 0x4, 0x4}, {{0x0, 0x0}, {0x0, 0x0}}, {0x0, 0x0, ...}, ...}, ...)
        /home/ben/git/nomad-driver-podman/driver_test.go:1973 +0xf6
github.com/hashicorp/nomad-driver-podman.startDestroyInspectImage(0xc000150ea0, {0xf7929f, 0x10}, {0xf728c0, 0x8})
        /home/ben/git/nomad-driver-podman/driver_test.go:1744 +0x165
github.com/hashicorp/nomad-driver-podman.TestPodmanDriver_Pull(0xc000150b60)
        /home/ben/git/nomad-driver-podman/driver_test.go:1738 +0x138
testing.tRunner(0xc000150ea0, 0xfc1918)
        /home/ben/go/src/testing/testing.go:1259 +0x102
created by testing.(*T).Run
        /home/ben/go/src/testing/testing.go:1306 +0x35a
exit status 2
FAIL    github.com/hashicorp/nomad-driver-podman        0.027s

Tests appear to expect podman system service is running. Running podman system service --time=0 unix:///run/user/1093000004/podman/podman.sock & before starting the test suite appears to fix this error

dial unix /run/user/1093000004/podman/podman.sock connect: no such file or directory

> go test
2022-01-05T10:18:55.545Z [ERROR] nomad-driver-podman/driver.go:224: podman: Could not get podman info: error="Get "http://u/v1.0.0/libpod/info": dial unix /run/user/1093000004/podman/podman.sock: connect: no such file or directory"

On my corporate workstation (which requires a web proxy for internet access, the pull test appears to fail, despite having appropriate env vars setup. Manually pulling busybox:musl before running the test suite appears to work around the error
On my corp system (CentOS 8, podman 3.0.1, selinux disabled), I'm getting three failed tests

Failed tests

--- FAIL: TestPodmanDriver_Tmpfs (5.29s)
    driver_test.go:1203: 
                Error Trace:    driver_test.go:1203
                Error:          "2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /alloc type tmpfs (rw,relatime,size=2097152k)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /local type tmpfs (rw,relatime,size=2097152k)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /secrets type tmpfs (rw,relatime,size=2097152k)\n2022-01-05T10:37:16.755501020+00:00 stdout F /tmpdata1 on tmpfs type rw,nosuid,nodev,relatime,uid=1234,gid=10000 (0)\n2022-01-05T10:37:16.755501020+00:00 stdout F /tmpdata2 on tmpfs type rw,nosuid,nodev,relatime,uid=1234,gid=10000 (0)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /dev type tmpfs (rw,nosuid,size=65536k,mode=755,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F shm on /dev/shm type tmpfs (rw,nosuid,nodev,noexec,relatime,size=64000k,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /run/.containerenv type tmpfs (rw,nosuid,nodev,relatime,size=2034096k,mode=700,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /run/secrets type tmpfs (rw,nosuid,nodev,relatime,size=2034096k,mode=700,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /etc/resolv.conf type tmpfs (rw,nosuid,nodev,relatime,size=2034096k,mode=700,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /etc/hosts type tmpfs (rw,nosuid,nodev,relatime,size=2034096k,mode=700,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /etc/hostname type tmpfs (rw,nosuid,nodev,relatime,size=2034096k,mode=700,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/null type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/random type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/full type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/tty type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/zero type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /dev/urandom type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /proc/acpi type tmpfs (ro,relatime,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /proc/kcore type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /proc/keys type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /proc/timer_list type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F devtmpfs on /proc/sched_debug type devtmpfs (rw,nosuid,size=10153300k,nr_inodes=2538325,mode=755)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /proc/scsi type tmpfs (ro,relatime,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /sys/firmware type tmpfs (ro,relatime,uid=1234,gid=10000)\n2022-01-05T10:37:16.755501020+00:00 stdout F tmpfs on /sys/dev/block type tmpfs (ro,relatime,uid=1234,gid=10000)\n" does not contain " on /tmpdata1 type tmpfs "
                Test:           TestPodmanDriver_Tmpfs
--- FAIL: TestPodmanDriver_NetworkModes (21.83s)
    --- FAIL: TestPodmanDriver_NetworkModes/TestPodmanDriver_NetworkModes_mode_bridge (5.48s)
        driver_test.go:1484: 
                Error Trace:    driver_test.go:1484
                Error:          Not equal: 
                                expected: "10.88.0.1"
                                actual  : ""
                                
                                Diff:
                                --- Expected
                                +++ Actual
                                @@ -1 +1 @@
                                -10.88.0.1
                                +
                Test:           TestPodmanDriver_NetworkModes/TestPodmanDriver_NetworkModes_mode_bridge
--- FAIL: TestPodmanDriver_Sysctl (4.25s)
    driver_test.go:1703: 
                Error Trace:    driver_test.go:1703
                Error:          Received unexpected error:
                                rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"OCI runtime attempted to invoke a command that was not found","message":"container_linux.go:380: starting container process caused: process_linux.go:545: container init caused: write sysctl key net.core.somaxconn: open /proc/sys/net/core/somaxconn: no such file or directory: OCI runtime attempted to invoke a command that was not found","response":500}
                Test:           TestPodmanDriver_Sysctl

On my home system (Fedora 35, podman 3.4.4, selinux enforcing) I'm getting a different and larger set of failed tests

Failed tests

--- FAIL: TestPodmanDriver_logNomad (5.66s)
    driver_test.go:487:
                Error Trace:    driver_test.go:487
                Error:          "" does not contain "ceb424d4-efbf-2733-6df7-814e1f4bf574"
                Test:           TestPodmanDriver_logNomad
                Messages:       stdoutMagic in stdout

--- FAIL: TestPodmanDriver_Hostname (5.66s)
    driver_test.go:535:
                Error Trace:    driver_test.go:535
                Error:          "" does not contain "host_55198663-ee1e-5dfd-ed79-290efd80d3e5"
                Test:           TestPodmanDriver_Hostname

--- FAIL: TestPodmanDriver_Init (6.48s)
    driver_test.go:920:
                Error Trace:    driver_test.go:920
                Error:          "" does not contain "/dev/init"
                Test:           TestPodmanDriver_Init

--- FAIL: TestPodmanDriver_User (5.45s)
    driver_test.go:1036:
                Error Trace:    driver_test.go:1036
                Error:          "" does not contain "www-data"
                Test:           TestPodmanDriver_User

--- FAIL: TestPodmanDriver_Device (6.47s)
    driver_test.go:1077:
                Error Trace:    driver_test.go:1077
                Error:          Should be true
                Test:           TestPodmanDriver_Device

--- FAIL: TestPodmanDriver_Tmpfs (5.94s)
    driver_test.go:1203:
                Error Trace:    driver_test.go:1203
                Error:          "" does not contain " on /tmpdata1 type tmpfs "
                Test:           TestPodmanDriver_Tmpfs

--- FAIL: TestPodmanDriver_Mount (4.39s)
    driver_test.go:1241:
                Error Trace:    driver_test.go:1241
                Error:          Received unexpected error:
                                rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"SELinux relabeling of /tmp is not allowed","message":"SELinux relabeling of /tmp is not allowed","response":500}

--- FAIL: TestPodmanDriver_Dns (5.47s)
    driver_test.go:1412:
                Error Trace:    driver_test.go:1412
                Error:          "" does not contain "nameserver 1.1.1.1"
                Test:           TestPodmanDriver_Dns

--- FAIL: TestPodmanDriver_NetworkMode_Container (10.62s)
    driver_test.go:1559:
                Error Trace:    driver_test.go:1559
                Error:          "" does not contain "127.0.0.1:6748"
                Test:           TestPodmanDriver_NetworkMode_Container

--- FAIL: TestPodmanDriver_NetworkMode_Task (10.71s)
    driver_test.go:1632:
                Error Trace:    driver_test.go:1632
                Error:          "" does not contain "127.0.0.1:6748"
                Test:           TestPodmanDriver_NetworkMode_Task

--- FAIL: TestPodmanDriver_Sysctl (4.44s)
    driver_test.go:1703:
                Error Trace:    driver_test.go:1703
                Error:          Received unexpected error:
                                rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"OCI runtime attempted to invoke a command that was not found","message":"open /proc/sys/net/core/somaxconn: No such file or directory: OCI runtime attempted to invoke a command that was not found","response":500}
                Test:           TestPodmanDriver_Sysctl

FAIL
exit status 1
FAIL    github.com/hashicorp/nomad-driver-podman        315.758s

I'm also seeing lots of warnings during the test suite run, which I'm not sure if indicates a problem with environment or with the test suite:

Warnings

2022-01-05T10:27:27.105Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-05T10:27:27.105Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

Is there a magic incantation or pre-requisite setup required to make these all pass outside of Github Actions?

The text was updated successfully, but these errors were encountered:

lgfa29 · 2022-01-07T17:39:53Z

I thought I was able to run the tests using the provided Vagrantfile because they at least started running. But now that they've completed I see some (but not all) of the failed tests you are seeing as well.

They also started happening in CI (https://github.com/hashicorp/nomad-driver-podman/runs/4740622562?check_suite_focus=true), so I wonder if it's related to some change in Podman itself 🤔

But in general, I would suggest using the Vagrant box for running the tests since it's a way to keep environment consistent. It would be hard for us to support multiple environments at this point.

This PR has the changes that I had to make to get the tests running in the Vagrant box.

optiz0r · 2022-01-07T17:47:11Z

Understood, thanks. I will see if I can get the vagrant tests running on Monday in our environment.

optiz0r · 2022-01-11T21:12:22Z

~~I cannot get the vagrant box running on my work machines at all (already workong on a VM, so nested virtualisation pain, plus vagrant symbol pain with CentOS 8).~~ I got vagrant up and running the tests on my work machine and personal laptop as described in the PR, but seeing the similar failures as on CI or non-vagrant on my work machine.

DONE 59 tests, 2 skipped, 12 failures in 393.831s

optiz0r · 2022-01-12T15:26:51Z

CI uses podman from the build containers. Current version is 3.4.2, published November 18th 2021, and is failing. The last commit in master was run 2nd November against podman 3.3.1 and was successful.
I'm testing with 3.2.3 (centos 8.4), and 3.4.0 (fedora 35), both of which are failing.

The kubic repository does not maintain old versions of podman.
Ubuntu 20.04 does not natively include a version of podman, so can only be tested with 3.4.2 from kubic which fails.
Ubuntu 21.04 ships podman 3.0.1 natively. This results in 34 failures
Ubuntu 21.10 ships podman 3.2.1 natively. This results in 6 failures
Ubuntu "jammy" (what will be 22.04?) didn't provision correctly, but since it's not a stable release I didn't look into why podman package didn't exist.

Given failures across a wide range of podman versions, I'm not sure these failures are being caused by just a change in podman version.

towe75 · 2022-01-12T18:52:55Z

A quick check on a dev machine with a recent fedora and podman 3.4.0 was fine, "works on my machine". We're further running the plugin in prod since a while. Currently with podman 3.4.2 on Ubuntu with a few thousand containers. So i'm relatively sure that is not a bigger problem/change in podman.

I took a glance at the failed GH action runs. My assumption is that GH might inflict some new restrictions on machines. I can see that most tests are network or device as well as mountpoint related. Further i believe that it's useless to try with 3.2.x or even older versions.

@optiz0r can you maybe post some details regarding the failed tests on kubic 3.4.2 on ubuntu 20.04?

optiz0r · 2022-01-12T21:10:04Z

Failed tests from the Ubuntu 20.04 vagrant box

✓  api (6.965s)
✖  . (5m14.512s)

=== Skipped
=== SKIP: . TestPodmanDriver_OOM (0.00s)
    driver_test.go:932: Skipping oom test because of podman cgroup v2 bugs

=== SKIP: . Test_createImageArchives (0.00s)
    driver_test.go:1789: Skipping image archive test. Missing "ARCHIVE_DIR" environment variable

=== Failed
=== FAIL: . TestPodmanDriver_logNomad (6.35s)
2022-01-12T21:01:38.502Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:01:38.731Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-064715085/alloc/logs/.logNomad.stdout.fifo
2022-01-12T21:01:38.731Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-064715085/alloc/logs/.logNomad.stderr.fifo
2022-01-12T21:01:38.737Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:01:38.831Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=0b39f5bb-909d-e873-4e9b-0ca1613ba658 container=c929605c5cbb8e00bacc00f911376b5387a5aa1eaabadf4324e9575d7e576fca ip=
2022-01-12T21:01:38.831Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=c929605c5cbb8e00bacc00f911376b5387a5aa1eaabadf4324e9575d7e576fca
2022-01-12T21:01:38.831Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=0b39f5bb-909d-e873-4e9b-0ca1613ba658
2022-01-12T21:01:38.831Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=c929605c5cbb8e00bacc00f911376b5387a5aa1eaabadf4324e9575d7e576fca
2022-01-12T21:01:38.833Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:01:39.833Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=c929605c5cbb8e00bacc00f911376b5387a5aa1eaabadf4324e9575d7e576fca error="Container has wrong state"
2022-01-12T21:01:40.840Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=c929605c5cbb8e00bacc00f911376b5387a5aa1eaabadf4324e9575d7e576fca
    driver_test.go:492: 
        	Error Trace:	driver_test.go:492
        	Error:      	"" does not contain "8fb02772-f682-3fdc-41d2-19ae573bf8cd"
        	Test:       	TestPodmanDriver_logNomad
        	Messages:   	stdoutMagic in stdout
2022-01-12T21:01:44.849Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:01:44.849Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Hostname (6.33s)
2022-01-12T21:01:44.850Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:01:45.057Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-110980168/alloc/logs/.stdout.stdout.fifo
2022-01-12T21:01:45.057Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-110980168/alloc/logs/.stdout.stderr.fifo
2022-01-12T21:01:45.062Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:01:45.160Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=d4b94b48-56c4-19b0-2f94-41e60229be84 container=91b6fb69d06ab655ad27db5e64f7fddeddbdd1d66bfbbf345acd8accf5ac4304 ip=
2022-01-12T21:01:45.160Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=91b6fb69d06ab655ad27db5e64f7fddeddbdd1d66bfbbf345acd8accf5ac4304
2022-01-12T21:01:45.161Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=d4b94b48-56c4-19b0-2f94-41e60229be84
2022-01-12T21:01:45.161Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=91b6fb69d06ab655ad27db5e64f7fddeddbdd1d66bfbbf345acd8accf5ac4304
2022-01-12T21:01:45.163Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:01:46.165Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=91b6fb69d06ab655ad27db5e64f7fddeddbdd1d66bfbbf345acd8accf5ac4304 error="Container has wrong state"
2022-01-12T21:01:47.163Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=91b6fb69d06ab655ad27db5e64f7fddeddbdd1d66bfbbf345acd8accf5ac4304
    driver_test.go:540: 
        	Error Trace:	driver_test.go:540
        	Error:      	"" does not contain "host_ac227080-a57a-6677-a6e0-575969541814"
        	Test:       	TestPodmanDriver_Hostname
2022-01-12T21:01:51.177Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:01:51.177Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Init (6.36s)
2022-01-12T21:02:14.286Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:14.515Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-258125966/alloc/logs/.init.stdout.fifo
2022-01-12T21:02:14.515Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-258125966/alloc/logs/.init.stderr.fifo
2022-01-12T21:02:14.521Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:14.620Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=f79ad045-c3ce-b460-aa8f-be17671957be container=bcc93470e0f7873baafec3e04c2d13cca9512bda4ae32df01c2b0552875c8d2b ip=
2022-01-12T21:02:14.620Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=bcc93470e0f7873baafec3e04c2d13cca9512bda4ae32df01c2b0552875c8d2b
2022-01-12T21:02:14.622Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:14.622Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=f79ad045-c3ce-b460-aa8f-be17671957be
2022-01-12T21:02:14.622Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=bcc93470e0f7873baafec3e04c2d13cca9512bda4ae32df01c2b0552875c8d2b
2022-01-12T21:02:15.623Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=bcc93470e0f7873baafec3e04c2d13cca9512bda4ae32df01c2b0552875c8d2b error="Container has wrong state"
2022-01-12T21:02:16.628Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=bcc93470e0f7873baafec3e04c2d13cca9512bda4ae32df01c2b0552875c8d2b
    driver_test.go:925: 
        	Error Trace:	driver_test.go:925
        	Error:      	"" does not contain "/dev/init"
        	Test:       	TestPodmanDriver_Init
2022-01-12T21:02:20.640Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:20.640Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_User (5.36s)
2022-01-12T21:02:20.642Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:20.877Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-868104341/alloc/logs/.user.stdout.fifo
2022-01-12T21:02:20.877Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-868104341/alloc/logs/.user.stderr.fifo
2022-01-12T21:02:20.883Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:20.980Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=d653dfac-b6e7-595c-9ef2-5bcdab4f63ff container=a3f68abed35f85d6585beb2e586abbb1fc303246789e8baaa80b7a920e1d2ca8 ip=
2022-01-12T21:02:20.981Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=a3f68abed35f85d6585beb2e586abbb1fc303246789e8baaa80b7a920e1d2ca8
2022-01-12T21:02:20.981Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=d653dfac-b6e7-595c-9ef2-5bcdab4f63ff
2022-01-12T21:02:20.981Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=a3f68abed35f85d6585beb2e586abbb1fc303246789e8baaa80b7a920e1d2ca8
2022-01-12T21:02:20.985Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=a3f68abed35f85d6585beb2e586abbb1fc303246789e8baaa80b7a920e1d2ca8 error="Container has wrong state"
2022-01-12T21:02:21.981Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=a3f68abed35f85d6585beb2e586abbb1fc303246789e8baaa80b7a920e1d2ca8
    driver_test.go:1041: 
        	Error Trace:	driver_test.go:1041
        	Error:      	"" does not contain "www-data"
        	Test:       	TestPodmanDriver_User
2022-01-12T21:02:25.992Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:26.001Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Device (6.42s)
2022-01-12T21:02:26.005Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:26.265Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-609410800/alloc/logs/.device.stdout.fifo
2022-01-12T21:02:26.266Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-609410800/alloc/logs/.device.stderr.fifo
2022-01-12T21:02:26.272Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:26.388Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=421cb49a-79ae-e362-540c-5c040b146d46 container=867de9cb7bd6c87781c6979b3f983f002b0a1887f141acdf8813208feacc5292 ip=
2022-01-12T21:02:26.389Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=867de9cb7bd6c87781c6979b3f983f002b0a1887f141acdf8813208feacc5292
2022-01-12T21:02:26.389Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=421cb49a-79ae-e362-540c-5c040b146d46
2022-01-12T21:02:26.389Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=867de9cb7bd6c87781c6979b3f983f002b0a1887f141acdf8813208feacc5292
2022-01-12T21:02:26.392Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:27.393Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=867de9cb7bd6c87781c6979b3f983f002b0a1887f141acdf8813208feacc5292 error="Container has wrong state"
2022-01-12T21:02:28.393Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=867de9cb7bd6c87781c6979b3f983f002b0a1887f141acdf8813208feacc5292
    driver_test.go:1089: 
        	Error Trace:	driver_test.go:1089
        	Error:      	"" does not contain "dev/net/tun"
        	Test:       	TestPodmanDriver_Device
2022-01-12T21:02:32.420Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:32.420Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Swap (13.67s)
2022-01-12T21:02:32.429Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:32.711Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-113773455/alloc/logs/.swap.stdout.fifo
2022-01-12T21:02:32.712Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-113773455/alloc/logs/.swap.stderr.fifo
2022-01-12T21:02:32.724Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:32.742Z [WARN]  nomad-driver-podman/driver.go:547: podman: Create Warning: warning="Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap."
2022-01-12T21:02:32.832Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=3b22e63e-4c3b-1d04-0693-8fa443dec9ea container=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae ip=
2022-01-12T21:02:32.833Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae
2022-01-12T21:02:32.834Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=3b22e63e-4c3b-1d04-0693-8fa443dec9ea
2022-01-12T21:02:32.834Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae
2022-01-12T21:02:32.835Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:33.835Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:34.835Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:35.836Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:36.839Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:37.848Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:38.850Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:39.851Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
    driver_test.go:1143: 
        	Error Trace:	driver_test.go:1143
        	Error:      	Not equal: 
        	            	expected: 104857600
        	            	actual  : 0
        	Test:       	TestPodmanDriver_Swap
2022-01-12T21:02:40.926Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae
2022-01-12T21:02:40.926Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:41.923Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae error="Container has wrong state"
2022-01-12T21:02:42.922Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=8b65bf7f31b0f09ac243eadf8ca87419ae58e3ab4cfc6d69ff0255631289c6ae
2022-01-12T21:02:46.101Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:46.101Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Tmpfs (6.39s)
2022-01-12T21:02:46.103Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:46.316Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-989640098/alloc/logs/.tmpfs.stdout.fifo
2022-01-12T21:02:46.316Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-989640098/alloc/logs/.tmpfs.stderr.fifo
2022-01-12T21:02:46.323Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:46.444Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=f3277a41-3274-9c68-b001-f801b7c1756f container=aaac35ecfe847eaa019f689d9e60c95bc98d7a98624ab5bbc2799411aebfecfb ip=
2022-01-12T21:02:46.444Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=aaac35ecfe847eaa019f689d9e60c95bc98d7a98624ab5bbc2799411aebfecfb
2022-01-12T21:02:46.445Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=f3277a41-3274-9c68-b001-f801b7c1756f
2022-01-12T21:02:46.445Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=aaac35ecfe847eaa019f689d9e60c95bc98d7a98624ab5bbc2799411aebfecfb
2022-01-12T21:02:46.452Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:02:47.486Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=aaac35ecfe847eaa019f689d9e60c95bc98d7a98624ab5bbc2799411aebfecfb error="Container has wrong state"
2022-01-12T21:02:48.482Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=aaac35ecfe847eaa019f689d9e60c95bc98d7a98624ab5bbc2799411aebfecfb
    driver_test.go:1208: 
        	Error Trace:	driver_test.go:1208
        	Error:      	"" does not contain " on /tmpdata1 type tmpfs "
        	Test:       	TestPodmanDriver_Tmpfs
2022-01-12T21:02:52.495Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:52.495Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Mount (5.35s)
2022-01-12T21:02:52.497Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:02:52.718Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-200255641/alloc/logs/.Mount.stdout.fifo
2022-01-12T21:02:52.718Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-200255641/alloc/logs/.Mount.stderr.fifo
2022-01-12T21:02:52.724Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:02:52.829Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=c3124fca-c9d3-c1b4-20aa-a1b25bf30617 container=8ea3b8b1c0ebaa20258b223373a35ce098b906bb887ef1618745033671b69ebe ip=
2022-01-12T21:02:52.830Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=8ea3b8b1c0ebaa20258b223373a35ce098b906bb887ef1618745033671b69ebe
2022-01-12T21:02:52.830Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=c3124fca-c9d3-c1b4-20aa-a1b25bf30617
2022-01-12T21:02:52.830Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=8ea3b8b1c0ebaa20258b223373a35ce098b906bb887ef1618745033671b69ebe
2022-01-12T21:02:52.832Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=8ea3b8b1c0ebaa20258b223373a35ce098b906bb887ef1618745033671b69ebe error="Container has wrong state"
2022-01-12T21:02:53.830Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=8ea3b8b1c0ebaa20258b223373a35ce098b906bb887ef1618745033671b69ebe
    driver_test.go:1298: 
        	Error Trace:	driver_test.go:1298
        	Error:      	"" does not contain " on /checka type "
        	Test:       	TestPodmanDriver_Mount
2022-01-12T21:02:57.846Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:02:57.846Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Dns (6.61s)
2022-01-12T21:04:02.553Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:02.908Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-288726295/alloc/logs/.dns.stdout.fifo
2022-01-12T21:04:02.909Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-288726295/alloc/logs/.dns.stderr.fifo
2022-01-12T21:04:02.927Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:03.047Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=c8e5019f-6a0d-e094-5004-3af29ba15b5a container=2b1b5c4b40c1704e22adfbacce10eb6ecb7a057b73cb5154f5aa0d6d751222db ip=
2022-01-12T21:04:03.047Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=2b1b5c4b40c1704e22adfbacce10eb6ecb7a057b73cb5154f5aa0d6d751222db
2022-01-12T21:04:03.048Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=c8e5019f-6a0d-e094-5004-3af29ba15b5a
2022-01-12T21:04:03.048Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=2b1b5c4b40c1704e22adfbacce10eb6ecb7a057b73cb5154f5aa0d6d751222db
2022-01-12T21:04:03.050Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:04.050Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=2b1b5c4b40c1704e22adfbacce10eb6ecb7a057b73cb5154f5aa0d6d751222db error="Container has wrong state"
2022-01-12T21:04:05.150Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=2b1b5c4b40c1704e22adfbacce10eb6ecb7a057b73cb5154f5aa0d6d751222db
    driver_test.go:1417: 
        	Error Trace:	driver_test.go:1417
        	Error:      	"" does not contain "nameserver 1.1.1.1"
        	Test:       	TestPodmanDriver_Dns
2022-01-12T21:04:09.164Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:09.164Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Container (10.42s)
2022-01-12T21:04:31.651Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:31.869Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-150885470/alloc/logs/.maintask.stdout.fifo
2022-01-12T21:04:31.869Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-150885470/alloc/logs/.maintask.stderr.fifo
2022-01-12T21:04:31.875Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:31.983Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=b5b25025-4dfc-9cce-94ff-cf3d0c1a9429 container=b90e65007647c9082453babcd3f059e66bb156ad79a14559444d9d79385b9567 ip=
2022-01-12T21:04:31.983Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=b90e65007647c9082453babcd3f059e66bb156ad79a14559444d9d79385b9567
2022-01-12T21:04:31.985Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:31.986Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:32.225Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-143255077/alloc/logs/.sidecar.stdout.fifo
2022-01-12T21:04:32.225Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-143255077/alloc/logs/.sidecar.stderr.fifo
2022-01-12T21:04:32.232Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:32.357Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=336ce77d-c286-b640-55bb-ab0d6ef4616b container=3e94dbbced008e223e36388a88e5790e8cc9bf130e0889c189e657258ea25ec8 ip=
2022-01-12T21:04:32.357Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=3e94dbbced008e223e36388a88e5790e8cc9bf130e0889c189e657258ea25ec8
2022-01-12T21:04:32.358Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=336ce77d-c286-b640-55bb-ab0d6ef4616b
2022-01-12T21:04:32.358Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=3e94dbbced008e223e36388a88e5790e8cc9bf130e0889c189e657258ea25ec8
2022-01-12T21:04:32.359Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=3e94dbbced008e223e36388a88e5790e8cc9bf130e0889c189e657258ea25ec8 error="Container has wrong state"
2022-01-12T21:04:32.985Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:33.358Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=3e94dbbced008e223e36388a88e5790e8cc9bf130e0889c189e657258ea25ec8
    driver_test.go:1564: 
        	Error Trace:	driver_test.go:1564
        	Error:      	"" does not contain "127.0.0.1:6748"
        	Test:       	TestPodmanDriver_NetworkMode_Container
2022-01-12T21:04:33.988Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:34.988Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:35.987Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:36.989Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:37.371Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:37.371Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:37.372Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=b90e65007647c9082453babcd3f059e66bb156ad79a14559444d9d79385b9567
2022-01-12T21:04:37.990Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=b90e65007647c9082453babcd3f059e66bb156ad79a14559444d9d79385b9567 error="Container has wrong state"
2022-01-12T21:04:42.064Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:42.064Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Task (10.73s)
2022-01-12T21:04:42.066Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:42.302Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-216141632/alloc/logs/.maintask.stdout.fifo
2022-01-12T21:04:42.303Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-216141632/alloc/logs/.maintask.stderr.fifo
2022-01-12T21:04:42.308Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:42.425Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=0d4c6358-e79c-236d-8409-1d1ae3f660b6 container=6dd58c38372bad58085f4cede4c961c05b35ff3c7246ba25e33ae1367caf2127 ip=
2022-01-12T21:04:42.425Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=6dd58c38372bad58085f4cede4c961c05b35ff3c7246ba25e33ae1367caf2127
2022-01-12T21:04:42.427Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:42.430Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:42.699Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-307426207/alloc/logs/.sidecar.stdout.fifo
2022-01-12T21:04:42.699Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-307426207/alloc/logs/.sidecar.stderr.fifo
2022-01-12T21:04:42.706Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:42.825Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=c51b80a6-b63a-15bc-84aa-3d3d76cf97c8 container=a10761da0ff179c629d7f6724238b1e7c62d5020cbb242d4b8826d39ea0396f4 ip=
2022-01-12T21:04:42.825Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=a10761da0ff179c629d7f6724238b1e7c62d5020cbb242d4b8826d39ea0396f4
2022-01-12T21:04:42.826Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=c51b80a6-b63a-15bc-84aa-3d3d76cf97c8
2022-01-12T21:04:42.826Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=a10761da0ff179c629d7f6724238b1e7c62d5020cbb242d4b8826d39ea0396f4
2022-01-12T21:04:42.827Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=a10761da0ff179c629d7f6724238b1e7c62d5020cbb242d4b8826d39ea0396f4 error="Container has wrong state"
2022-01-12T21:04:43.430Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:43.899Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=a10761da0ff179c629d7f6724238b1e7c62d5020cbb242d4b8826d39ea0396f4
    driver_test.go:1637: 
        	Error Trace:	driver_test.go:1637
        	Error:      	"" does not contain "127.0.0.1:6748"
        	Test:       	TestPodmanDriver_NetworkMode_Task
2022-01-12T21:04:44.430Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:45.430Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:46.469Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:47.469Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-12T21:04:48.001Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:48.001Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:48.003Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=6dd58c38372bad58085f4cede4c961c05b35ff3c7246ba25e33ae1367caf2127
2022-01-12T21:04:48.476Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=6dd58c38372bad58085f4cede4c961c05b35ff3c7246ba25e33ae1367caf2127 error="Container has wrong state"
2022-01-12T21:04:52.792Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:04:52.792Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Sysctl (4.32s)
2022-01-12T21:04:58.725Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1000/podman/podman.sock
2022-01-12T21:04:58.948Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-979311913/alloc/logs/.sysctl.stdout.fifo
2022-01-12T21:04:58.948Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-979311913/alloc/logs/.sysctl.stderr.fifo
2022-01-12T21:04:58.954Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:04:59.029Z [DEBUG] nomad-driver-podman/driver.go:556: podman: Cleaning up: container=d10b987659eee053a03852c86750367ca8393758441b8d530973b9e64a203541
    driver_test.go:1708: 
        	Error Trace:	driver_test.go:1708
        	Error:      	Received unexpected error:
        	            	rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"OCI runtime attempted to invoke a command that was not found","message":"open /proc/sys/net/core/somaxconn: No such file or directory: OCI runtime attempted to invoke a command that was not found","response":500}
        	Test:       	TestPodmanDriver_Sysctl
2022-01-12T21:05:03.041Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:05:03.041Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 59 tests, 2 skipped, 12 failures in 400.977s

And since you say a recent fedora works for you, @towe75 , this is what I get on Fedora 35, go 1.17.6, podman 3.4.4, (selinux enabled, which I mention since I saw an avc denial on ls /dev/net/tun while the test suite was running):

✓  api (7.962s)
✖  . (5m7.041s)

=== Skipped
=== SKIP: . TestPodmanDriver_OOM (0.00s)
    driver_test.go:927: Skipping oom test because of podman cgroup v2 bugs

=== SKIP: . Test_createImageArchives (0.00s)
    driver_test.go:1784: Skipping image archive test. Missing "ARCHIVE_DIR" environment variable

=== Failed
=== FAIL: . TestPodmanDriver_logNomad (5.28s)
2022-01-12T21:50:47.607Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:50:47.657Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:50:47.659Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2612490541/alloc/logs/.logNomad.stdout.fifo
2022-01-12T21:50:47.659Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2612490541/alloc/logs/.logNomad.stderr.fifo
2022-01-12T21:50:47.664Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:50:47.814Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=8e47b13c-1cf1-4329-9434-02af8e6c0a0e container=5021cbda41768f2ef37069d016efa16999df1eb22d8fc8ddec5735bf727ac467 ip=
2022-01-12T21:50:47.814Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=5021cbda41768f2ef37069d016efa16999df1eb22d8fc8ddec5735bf727ac467
2022-01-12T21:50:47.815Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=8e47b13c-1cf1-4329-9434-02af8e6c0a0e
2022-01-12T21:50:47.815Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=5021cbda41768f2ef37069d016efa16999df1eb22d8fc8ddec5735bf727ac467
2022-01-12T21:50:47.815Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=5021cbda41768f2ef37069d016efa16999df1eb22d8fc8ddec5735bf727ac467 error="Container has wrong state"
2022-01-12T21:50:48.815Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=5021cbda41768f2ef37069d016efa16999df1eb22d8fc8ddec5735bf727ac467
    driver_test.go:487: 
                Error Trace:    driver_test.go:487
                Error:          "" does not contain "f6beb9b1-99e8-85cb-a116-89e8aa237d46"
                Test:           TestPodmanDriver_logNomad
                Messages:       stdoutMagic in stdout
2022-01-12T21:50:52.880Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:50:52.880Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Hostname (5.26s)
2022-01-12T21:50:52.883Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:50:52.939Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:50:52.941Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3222397366/alloc/logs/.stdout.stdout.fifo
2022-01-12T21:50:52.941Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3222397366/alloc/logs/.stdout.stderr.fifo
2022-01-12T21:50:52.948Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:50:53.087Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=17b33eb4-0378-6dcc-3b43-1c2531779a06 container=685e2f57f7cc0559f613f73ea57b90ad7f7a106c571a5e15c3d294e348016fe5 ip=
2022-01-12T21:50:53.088Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=685e2f57f7cc0559f613f73ea57b90ad7f7a106c571a5e15c3d294e348016fe5
2022-01-12T21:50:53.088Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=17b33eb4-0378-6dcc-3b43-1c2531779a06
2022-01-12T21:50:53.088Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=685e2f57f7cc0559f613f73ea57b90ad7f7a106c571a5e15c3d294e348016fe5
2022-01-12T21:50:53.139Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=685e2f57f7cc0559f613f73ea57b90ad7f7a106c571a5e15c3d294e348016fe5 error="Container has wrong state"
2022-01-12T21:50:54.089Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=685e2f57f7cc0559f613f73ea57b90ad7f7a106c571a5e15c3d294e348016fe5
    driver_test.go:535: 
                Error Trace:    driver_test.go:535
                Error:          "" does not contain "host_af8189c9-e49b-cf62-627d-79fba4008e14"
                Test:           TestPodmanDriver_Hostname
2022-01-12T21:50:58.138Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:50:58.138Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Init (5.32s)
2022-01-12T21:51:21.381Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:51:21.441Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:51:21.443Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3391058444/alloc/logs/.init.stdout.fifo
2022-01-12T21:51:21.443Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3391058444/alloc/logs/.init.stderr.fifo
2022-01-12T21:51:21.449Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:51:21.627Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=92f7ae1a-da09-5fc9-fb0b-759b24978531 container=1bf47ec79968f67618060e20751b8b384ec27a45562139d726bce2f373300c30 ip=
2022-01-12T21:51:21.627Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=1bf47ec79968f67618060e20751b8b384ec27a45562139d726bce2f373300c30
2022-01-12T21:51:21.627Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=92f7ae1a-da09-5fc9-fb0b-759b24978531
2022-01-12T21:51:21.628Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=1bf47ec79968f67618060e20751b8b384ec27a45562139d726bce2f373300c30
2022-01-12T21:51:21.628Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=1bf47ec79968f67618060e20751b8b384ec27a45562139d726bce2f373300c30 error="Container has wrong state"
2022-01-12T21:51:22.629Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=1bf47ec79968f67618060e20751b8b384ec27a45562139d726bce2f373300c30
    driver_test.go:920: 
                Error Trace:    driver_test.go:920
                Error:          "" does not contain "/dev/init"
                Test:           TestPodmanDriver_Init
2022-01-12T21:51:26.689Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:51:26.690Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_User (5.30s)
2022-01-12T21:51:26.692Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:51:26.744Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:51:26.746Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-609639577/alloc/logs/.user.stdout.fifo
2022-01-12T21:51:26.746Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-609639577/alloc/logs/.user.stderr.fifo
2022-01-12T21:51:26.753Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:51:26.935Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=7b7e62a7-45c2-8c8e-5871-3482b53f8181 container=87af59a2bc7090787ede0f9c3f1f629cbebbddb78632b9a98c5af8da4e4400c6 ip=
2022-01-12T21:51:26.935Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=87af59a2bc7090787ede0f9c3f1f629cbebbddb78632b9a98c5af8da4e4400c6
2022-01-12T21:51:26.936Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=7b7e62a7-45c2-8c8e-5871-3482b53f8181
2022-01-12T21:51:26.936Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=87af59a2bc7090787ede0f9c3f1f629cbebbddb78632b9a98c5af8da4e4400c6 error="Container has wrong state"
2022-01-12T21:51:26.936Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=87af59a2bc7090787ede0f9c3f1f629cbebbddb78632b9a98c5af8da4e4400c6
2022-01-12T21:51:27.937Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=87af59a2bc7090787ede0f9c3f1f629cbebbddb78632b9a98c5af8da4e4400c6
    driver_test.go:1036: 
                Error Trace:    driver_test.go:1036
                Error:          "" does not contain "www-data"
                Test:           TestPodmanDriver_User
2022-01-12T21:51:31.986Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:51:31.986Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Device (6.26s)
2022-01-12T21:51:31.988Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:51:32.035Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:51:32.036Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3896192914/alloc/logs/.device.stdout.fifo
2022-01-12T21:51:32.036Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3896192914/alloc/logs/.device.stderr.fifo
2022-01-12T21:51:32.042Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:51:32.177Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=7841650a-b433-56e8-31d3-cf05ffc0b319 container=88cfb4cab9dacc160e9b939931d128a67c81d914ce14e995364aedc2be0612cc ip=
2022-01-12T21:51:32.177Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=88cfb4cab9dacc160e9b939931d128a67c81d914ce14e995364aedc2be0612cc
2022-01-12T21:51:32.178Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=7841650a-b433-56e8-31d3-cf05ffc0b319
2022-01-12T21:51:32.178Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=88cfb4cab9dacc160e9b939931d128a67c81d914ce14e995364aedc2be0612cc
2022-01-12T21:51:33.184Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=88cfb4cab9dacc160e9b939931d128a67c81d914ce14e995364aedc2be0612cc error="Container has wrong state"
2022-01-12T21:51:34.178Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=88cfb4cab9dacc160e9b939931d128a67c81d914ce14e995364aedc2be0612cc
    driver_test.go:1077: 
                Error Trace:    driver_test.go:1077
                Error:          Should be true
                Test:           TestPodmanDriver_Device
2022-01-12T21:51:38.243Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:51:38.243Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Tmpfs (5.34s)
2022-01-12T21:51:51.820Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:51:51.881Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:51:51.882Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2598674898/alloc/logs/.tmpfs.stdout.fifo
2022-01-12T21:51:51.882Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2598674898/alloc/logs/.tmpfs.stderr.fifo
2022-01-12T21:51:51.889Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:51:52.095Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=0dcdd19f-0926-c1bb-e3d9-16845214de25 container=eede9b38bd7a5ae473cbfeb034f279372386f64c54bf189e8e9092ef6f47fc07 ip=
2022-01-12T21:51:52.095Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=eede9b38bd7a5ae473cbfeb034f279372386f64c54bf189e8e9092ef6f47fc07
2022-01-12T21:51:52.096Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=0dcdd19f-0926-c1bb-e3d9-16845214de25
2022-01-12T21:51:52.096Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=eede9b38bd7a5ae473cbfeb034f279372386f64c54bf189e8e9092ef6f47fc07
2022-01-12T21:51:52.146Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=eede9b38bd7a5ae473cbfeb034f279372386f64c54bf189e8e9092ef6f47fc07 error="Container has wrong state"
2022-01-12T21:51:53.096Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=eede9b38bd7a5ae473cbfeb034f279372386f64c54bf189e8e9092ef6f47fc07
    driver_test.go:1203: 
                Error Trace:    driver_test.go:1203
                Error:          "" does not contain " on /tmpdata1 type tmpfs "
                Test:           TestPodmanDriver_Tmpfs
2022-01-12T21:51:57.155Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:51:57.156Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Mount (4.20s)
2022-01-12T21:51:57.158Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:51:57.213Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:51:57.215Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-402617847/alloc/logs/.Mount.stdout.fifo
2022-01-12T21:51:57.215Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-402617847/alloc/logs/.Mount.stderr.fifo
2022-01-12T21:51:57.221Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:51:57.302Z [DEBUG] nomad-driver-podman/driver.go:550: podman: Cleaning up: container=fb26ed40de9576aa41469349d3b859804013822470be95614e4dd67141a6301d
    driver_test.go:1241: 
                Error Trace:    driver_test.go:1241
                Error:          Received unexpected error:
                                rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"SELinux relabeling of /tmp is not allowed","message":"SELinux relabeling of /tmp is not allowed","response":500}
                Test:           TestPodmanDriver_Mount
2022-01-12T21:52:01.351Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:52:01.351Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Dns (5.29s)
2022-01-12T21:53:07.747Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:53:07.806Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:53:07.808Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1260862233/alloc/logs/.dns.stdout.fifo
2022-01-12T21:53:07.808Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1260862233/alloc/logs/.dns.stderr.fifo
2022-01-12T21:53:07.814Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:53:07.967Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=3ebb586e-ba87-2b36-d0bc-90756614d746 container=d8c1324b76a69c2aac4a68be252d8d6f86d1a4a3a0467f103ac7c7755a5d82f8 ip=
2022-01-12T21:53:07.967Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=d8c1324b76a69c2aac4a68be252d8d6f86d1a4a3a0467f103ac7c7755a5d82f8
2022-01-12T21:53:07.968Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=3ebb586e-ba87-2b36-d0bc-90756614d746
2022-01-12T21:53:07.968Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=d8c1324b76a69c2aac4a68be252d8d6f86d1a4a3a0467f103ac7c7755a5d82f8
2022-01-12T21:53:07.968Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=d8c1324b76a69c2aac4a68be252d8d6f86d1a4a3a0467f103ac7c7755a5d82f8 error="Container has wrong state"
2022-01-12T21:53:08.969Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=d8c1324b76a69c2aac4a68be252d8d6f86d1a4a3a0467f103ac7c7755a5d82f8
    driver_test.go:1412: 
                Error Trace:    driver_test.go:1412
                Error:          "" does not contain "nameserver 1.1.1.1"
                Test:           TestPodmanDriver_Dns
2022-01-12T21:53:13.032Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:13.033Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Container (10.49s)
2022-01-12T21:53:34.943Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:53:34.997Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:53:34.999Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1883219408/alloc/logs/.maintask.stdout.fifo
2022-01-12T21:53:34.999Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1883219408/alloc/logs/.maintask.stderr.fifo
2022-01-12T21:53:35.005Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:53:35.139Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=bbd63447-3a06-baee-708a-83a99e67e3bb container=1eb8b3b4e0141b9dd05c44e6a58a5f136c48562810700e0e3bf9c0a40c478db9 ip=
2022-01-12T21:53:35.139Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=1eb8b3b4e0141b9dd05c44e6a58a5f136c48562810700e0e3bf9c0a40c478db9
2022-01-12T21:53:35.139Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:53:35.190Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:53:35.191Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3660209483/alloc/logs/.sidecar.stdout.fifo
2022-01-12T21:53:35.191Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-3660209483/alloc/logs/.sidecar.stderr.fifo
2022-01-12T21:53:35.197Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:53:35.375Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=151fecd5-0476-9eb1-6608-284e5becdee2 container=5231955fc7633387afbc6abad8cce4d2b6694e85c566fd20993c5f1aa3e4d3a5 ip=
2022-01-12T21:53:35.375Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=5231955fc7633387afbc6abad8cce4d2b6694e85c566fd20993c5f1aa3e4d3a5
2022-01-12T21:53:35.376Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=151fecd5-0476-9eb1-6608-284e5becdee2
2022-01-12T21:53:35.376Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=5231955fc7633387afbc6abad8cce4d2b6694e85c566fd20993c5f1aa3e4d3a5
2022-01-12T21:53:35.376Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=5231955fc7633387afbc6abad8cce4d2b6694e85c566fd20993c5f1aa3e4d3a5 error="Container has wrong state"
2022-01-12T21:53:36.377Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=5231955fc7633387afbc6abad8cce4d2b6694e85c566fd20993c5f1aa3e4d3a5
    driver_test.go:1559: 
                Error Trace:    driver_test.go:1559
                Error:          "" does not contain "127.0.0.1:6748"
                Test:           TestPodmanDriver_NetworkMode_Container
2022-01-12T21:53:40.438Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:40.438Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:40.441Z [DEBUG] nomad-driver-podman/driver.go:825: podman: Have to destroyTask but container is still running: containerID=1eb8b3b4e0141b9dd05c44e6a58a5f136c48562810700e0e3bf9c0a40c478db9
2022-01-12T21:53:41.145Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=1eb8b3b4e0141b9dd05c44e6a58a5f136c48562810700e0e3bf9c0a40c478db9 error="Container has wrong state"
2022-01-12T21:53:45.434Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:45.435Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Task (10.46s)
2022-01-12T21:53:45.437Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:53:45.493Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:53:45.494Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1852082407/alloc/logs/.maintask.stdout.fifo
2022-01-12T21:53:45.494Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-1852082407/alloc/logs/.maintask.stderr.fifo
2022-01-12T21:53:45.500Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:53:45.631Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=36c9f72e-2565-1cac-0163-ddde77452755 container=640208d20d8e0381c0073d807d905546f2dd90c7ff02a8295b920c84edb0465d ip=
2022-01-12T21:53:45.631Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=640208d20d8e0381c0073d807d905546f2dd90c7ff02a8295b920c84edb0465d
2022-01-12T21:53:45.631Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:53:45.676Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:53:45.677Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2800164028/alloc/logs/.sidecar.stdout.fifo
2022-01-12T21:53:45.678Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-2800164028/alloc/logs/.sidecar.stderr.fifo
2022-01-12T21:53:45.685Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:53:45.835Z [INFO]  nomad-driver-podman/driver.go:612: podman: Completely started container: taskID=fa4d6f27-3109-cb84-ae98-cc45c9ad2eb0 container=b53b4ff961b65146c666257324bd4789cb1d72d00ac32a0f037a830114a85619 ip=
2022-01-12T21:53:45.835Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=b53b4ff961b65146c666257324bd4789cb1d72d00ac32a0f037a830114a85619
2022-01-12T21:53:45.835Z [DEBUG] nomad-driver-podman/driver.go:773: podman: WaitTask called: task=fa4d6f27-3109-cb84-ae98-cc45c9ad2eb0
2022-01-12T21:53:45.835Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=b53b4ff961b65146c666257324bd4789cb1d72d00ac32a0f037a830114a85619
2022-01-12T21:53:45.836Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=b53b4ff961b65146c666257324bd4789cb1d72d00ac32a0f037a830114a85619 error="Container has wrong state"
2022-01-12T21:53:46.836Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=b53b4ff961b65146c666257324bd4789cb1d72d00ac32a0f037a830114a85619
    driver_test.go:1632: 
                Error Trace:    driver_test.go:1632
                Error:          "" does not contain "127.0.0.1:6748"
                Test:           TestPodmanDriver_NetworkMode_Task
2022-01-12T21:53:50.906Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:50.906Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:50.909Z [DEBUG] nomad-driver-podman/driver.go:825: podman: Have to destroyTask but container is still running: containerID=640208d20d8e0381c0073d807d905546f2dd90c7ff02a8295b920c84edb0465d
2022-01-12T21:53:51.639Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=640208d20d8e0381c0073d807d905546f2dd90c7ff02a8295b920c84edb0465d error="Container has wrong state"
2022-01-12T21:53:55.898Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:53:55.898Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Sysctl (4.21s)
2022-01-12T21:54:01.765Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/user/1093000004/podman/podman.sock
2022-01-12T21:54:01.819Z [INFO]  nomad-driver-podman/driver_test.go:78: podman: Enabling SelinuxLabel
2022-01-12T21:54:01.821Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-490832769/alloc/logs/.sysctl.stdout.fifo
2022-01-12T21:54:01.821Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-490832769/alloc/logs/.sysctl.stderr.fifo
2022-01-12T21:54:01.828Z [DEBUG] nomad-driver-podman/driver.go:713: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-12T21:54:01.926Z [DEBUG] nomad-driver-podman/driver.go:550: podman: Cleaning up: container=9f59c17df2c9ad68a489a299a4eb19e512851428547c1fe0811586ff80763211
    driver_test.go:1703: 
                Error Trace:    driver_test.go:1703
                Error:          Received unexpected error:
                                rpc error: code = Unknown desc = failed to start task, could not start container: unknown error, status code: 500: {"cause":"OCI runtime attempted to invoke a command that was not found","message":"open /proc/sys/net/core/somaxconn: No such file or directory: OCI runtime attempted to invoke a command that was not found","response":500}
                Test:           TestPodmanDriver_Sysctl
2022-01-12T21:54:05.972Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-12T21:54:05.972Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 52 tests, 2 skipped, 11 failures in 309.771s

towe75 · 2022-01-13T06:09:17Z

You're running the tests as uid=1000. The driver is still not fully adopted to rootless, hence the tests also assume to run against a rootful podman. Please try to rerun as root or with sudo.

optiz0r · 2022-01-13T16:25:52Z

I've had to jump through a few more environmental hoops to get the vagrant box running tests in rootful mode:

sudo -E doesn't pass through PATH env var and /usr/local/go/bin is not in root's PATH
http_proxy env vars (set via vagrant-proxyconf, and which are passing through sudo -E) aren't getting passed through to rootful podman, I had to set the following to get image fetching tests to pass:

# /etc/containers/containers.conf
[engine]
env=[
  "http_proxy=...",
  "https_proxy=...",
  "no_proxy=...",
]

Running the tests with: PATH=/usr/local/go/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin CI=1 ./build/bin/gotestsum --junitfile ./build/test/result.xml -- -timeout=15m . ./api

I still see similar looking failures however:

root@ubuntu-focal:/home/vagrant/nomad-driver-podman# PATH=/usr/local/go/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin CI=1 ./build/bin/gotestsum --junitfile ./build/test/result.xml -- -timeout=15m . ./api
✓  api (9.129s)
✖  . (5m13.502s)

=== Skipped
=== SKIP: . TestPodmanDriver_OOM (0.00s)
    driver_test.go:932: Skipping oom test because of podman cgroup v2 bugs

=== SKIP: . Test_createImageArchives (0.00s)
    driver_test.go:1789: Skipping image archive test. Missing "ARCHIVE_DIR" environment variable

=== Failed
=== FAIL: . TestPodmanDriver_logNomad (5.55s)
2022-01-13T10:35:36.483Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:35:36.680Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-904450268/alloc/logs/.logNomad.stdout.fifo
2022-01-13T10:35:36.681Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-904450268/alloc/logs/.logNomad.stderr.fifo
2022-01-13T10:35:36.691Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:35:37.007Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=e2e15441-8246-098f-3aee-6c2e9759f994 container=8bc0d434b4fa7d28409ba095d7bd2f300649da2dd41e0fc610b9f6866bb72238 ip=10.88.0.9
2022-01-13T10:35:37.007Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=8bc0d434b4fa7d28409ba095d7bd2f300649da2dd41e0fc610b9f6866bb72238
2022-01-13T10:35:37.008Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=e2e15441-8246-098f-3aee-6c2e9759f994
2022-01-13T10:35:37.008Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=8bc0d434b4fa7d28409ba095d7bd2f300649da2dd41e0fc610b9f6866bb72238
2022-01-13T10:35:37.009Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=8bc0d434b4fa7d28409ba095d7bd2f300649da2dd41e0fc610b9f6866bb72238 error="Container has wrong state"
2022-01-13T10:35:38.008Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=8bc0d434b4fa7d28409ba095d7bd2f300649da2dd41e0fc610b9f6866bb72238
    driver_test.go:492: 
        	Error Trace:	driver_test.go:492
        	Error:      	"" does not contain "dc49b3b5-4cfc-dd5b-6c1e-a4f87abbe2cc"
        	Test:       	TestPodmanDriver_logNomad
        	Messages:   	stdoutMagic in stdout
2022-01-13T10:35:42.031Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:35:42.031Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Hostname (6.52s)
2022-01-13T10:35:42.034Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:35:42.227Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-404219019/alloc/logs/.stdout.stdout.fifo
2022-01-13T10:35:42.227Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-404219019/alloc/logs/.stdout.stderr.fifo
2022-01-13T10:35:42.238Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:35:42.540Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=c21d1f0d-c378-678b-26fb-536eaa0bf98d container=b545822180ce5314af91dfdd4b5420a3d694542cc099844066525e478d846254 ip=10.88.0.10
2022-01-13T10:35:42.541Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=b545822180ce5314af91dfdd4b5420a3d694542cc099844066525e478d846254
2022-01-13T10:35:42.542Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=c21d1f0d-c378-678b-26fb-536eaa0bf98d
2022-01-13T10:35:42.542Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=b545822180ce5314af91dfdd4b5420a3d694542cc099844066525e478d846254
2022-01-13T10:35:42.547Z [DEBUG] nomad-driver-podman/handle.go:242: podman.podmanHandle: Could not get container stats, unknown error: error="&errors.errorString{s:"unknown error, status code: 500"}"
2022-01-13T10:35:43.543Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=b545822180ce5314af91dfdd4b5420a3d694542cc099844066525e478d846254 error="Container has wrong state"
2022-01-13T10:35:44.542Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=b545822180ce5314af91dfdd4b5420a3d694542cc099844066525e478d846254
    driver_test.go:540: 
        	Error Trace:	driver_test.go:540
        	Error:      	"" does not contain "host_53479402-a543-5948-872c-a93a534cf230"
        	Test:       	TestPodmanDriver_Hostname
2022-01-13T10:35:48.554Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:35:48.554Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Init (5.52s)
2022-01-13T10:36:13.013Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:13.203Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-226130169/alloc/logs/.init.stdout.fifo
2022-01-13T10:36:13.203Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-226130169/alloc/logs/.init.stderr.fifo
2022-01-13T10:36:13.212Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:13.498Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=9338fa08-4453-7057-c35c-d5e6abec8b4f container=e0a7f15dd069ed255c7d4c2af7491cd34a166a8206ad295fda674af48b31f52b ip=10.88.0.13
2022-01-13T10:36:13.498Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=e0a7f15dd069ed255c7d4c2af7491cd34a166a8206ad295fda674af48b31f52b
2022-01-13T10:36:13.500Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=9338fa08-4453-7057-c35c-d5e6abec8b4f
2022-01-13T10:36:13.500Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=e0a7f15dd069ed255c7d4c2af7491cd34a166a8206ad295fda674af48b31f52b
2022-01-13T10:36:13.501Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=e0a7f15dd069ed255c7d4c2af7491cd34a166a8206ad295fda674af48b31f52b error="Container has wrong state"
2022-01-13T10:36:14.500Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=e0a7f15dd069ed255c7d4c2af7491cd34a166a8206ad295fda674af48b31f52b
    driver_test.go:925: 
        	Error Trace:	driver_test.go:925
        	Error:      	"" does not contain "/dev/init"
        	Test:       	TestPodmanDriver_Init
2022-01-13T10:36:18.524Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:18.524Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_User (5.59s)
2022-01-13T10:36:18.537Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:18.761Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-032607236/alloc/logs/.user.stdout.fifo
2022-01-13T10:36:18.762Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-032607236/alloc/logs/.user.stderr.fifo
2022-01-13T10:36:18.770Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:19.085Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=2b2ded10-58da-9403-71b8-7b1880b73c45 container=3ad07d9bb76fb35f1757ee26f399375ad9cf78243b4f0c4c540bc1840524a20e ip=10.88.0.14
2022-01-13T10:36:19.085Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=3ad07d9bb76fb35f1757ee26f399375ad9cf78243b4f0c4c540bc1840524a20e
2022-01-13T10:36:19.086Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=2b2ded10-58da-9403-71b8-7b1880b73c45
2022-01-13T10:36:19.086Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=3ad07d9bb76fb35f1757ee26f399375ad9cf78243b4f0c4c540bc1840524a20e
2022-01-13T10:36:19.088Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=3ad07d9bb76fb35f1757ee26f399375ad9cf78243b4f0c4c540bc1840524a20e error="Container has wrong state"
2022-01-13T10:36:20.088Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=3ad07d9bb76fb35f1757ee26f399375ad9cf78243b4f0c4c540bc1840524a20e
    driver_test.go:1041: 
        	Error Trace:	driver_test.go:1041
        	Error:      	"" does not contain "www-data"
        	Test:       	TestPodmanDriver_User
2022-01-13T10:36:24.121Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:24.121Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Device (6.53s)
2022-01-13T10:36:24.125Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:24.311Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-906188179/alloc/logs/.device.stdout.fifo
2022-01-13T10:36:24.312Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-906188179/alloc/logs/.device.stderr.fifo
2022-01-13T10:36:24.320Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:24.617Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=5076f9a4-9fa6-95df-ea2e-70ba528ee60c container=88c5dcfee7111c5cebdf441a550515a1d525d562a2068d584e17b06de54d74e5 ip=10.88.0.15
2022-01-13T10:36:24.618Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=88c5dcfee7111c5cebdf441a550515a1d525d562a2068d584e17b06de54d74e5
2022-01-13T10:36:24.619Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=5076f9a4-9fa6-95df-ea2e-70ba528ee60c
2022-01-13T10:36:24.619Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=88c5dcfee7111c5cebdf441a550515a1d525d562a2068d584e17b06de54d74e5
2022-01-13T10:36:25.623Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=88c5dcfee7111c5cebdf441a550515a1d525d562a2068d584e17b06de54d74e5 error="Container has wrong state"
2022-01-13T10:36:26.620Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=88c5dcfee7111c5cebdf441a550515a1d525d562a2068d584e17b06de54d74e5
    driver_test.go:1089: 
        	Error Trace:	driver_test.go:1089
        	Error:      	"" does not contain "dev/net/tun"
        	Test:       	TestPodmanDriver_Device
2022-01-13T10:36:30.636Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:30.636Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Swap (12.78s)
2022-01-13T10:36:30.653Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:30.835Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-227069398/alloc/logs/.swap.stdout.fifo
2022-01-13T10:36:30.835Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-227069398/alloc/logs/.swap.stderr.fifo
2022-01-13T10:36:30.846Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:30.865Z [WARN]  nomad-driver-podman/driver.go:547: podman: Create Warning: warning="Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap."
2022-01-13T10:36:31.103Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=ab229c92-aef4-962f-916f-1b291f458118 container=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108 ip=10.88.0.16
2022-01-13T10:36:31.103Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108
2022-01-13T10:36:31.104Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=ab229c92-aef4-962f-916f-1b291f458118
2022-01-13T10:36:31.104Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108
    driver_test.go:1143: 
        	Error Trace:	driver_test.go:1143
        	Error:      	Not equal: 
        	            	expected: 104857600
        	            	actual  : 0
        	Test:       	TestPodmanDriver_Swap
2022-01-13T10:36:39.108Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108
2022-01-13T10:36:39.130Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108 error="Container has wrong state"
2022-01-13T10:36:40.167Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=36d10d77385e0cbd82e753bc5b04d48814a79b77c6593b3934135f27dfd8b108
2022-01-13T10:36:43.431Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:43.431Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Tmpfs (5.59s)
2022-01-13T10:36:43.434Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:43.672Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-660628797/alloc/logs/.tmpfs.stdout.fifo
2022-01-13T10:36:43.672Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-660628797/alloc/logs/.tmpfs.stderr.fifo
2022-01-13T10:36:43.680Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:43.991Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=af549209-1fdc-739a-0db3-c060e8ae33d3 container=be942e47e4176af0c89e080bdb4e291d17e52a1ce95747dbfb669993a0c9a2ea ip=10.88.0.17
2022-01-13T10:36:43.992Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=be942e47e4176af0c89e080bdb4e291d17e52a1ce95747dbfb669993a0c9a2ea
2022-01-13T10:36:43.998Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=af549209-1fdc-739a-0db3-c060e8ae33d3
2022-01-13T10:36:43.998Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=be942e47e4176af0c89e080bdb4e291d17e52a1ce95747dbfb669993a0c9a2ea
2022-01-13T10:36:43.998Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=be942e47e4176af0c89e080bdb4e291d17e52a1ce95747dbfb669993a0c9a2ea error="Container has wrong state"
2022-01-13T10:36:44.999Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=be942e47e4176af0c89e080bdb4e291d17e52a1ce95747dbfb669993a0c9a2ea
    driver_test.go:1208: 
        	Error Trace:	driver_test.go:1208
        	Error:      	"" does not contain " on /tmpdata1 type tmpfs "
        	Test:       	TestPodmanDriver_Tmpfs
2022-01-13T10:36:49.021Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:49.021Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Mount (5.46s)
2022-01-13T10:36:49.025Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:36:49.195Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-109870968/alloc/logs/.Mount.stdout.fifo
2022-01-13T10:36:49.196Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-109870968/alloc/logs/.Mount.stderr.fifo
2022-01-13T10:36:49.201Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:36:49.457Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=c771f0c1-51d1-30ab-4e93-b5f93469cfe7 container=f9703e4c36089018f63582fbf5f6ce743422d9263cf6b2fcb0fc00aa2c2ec01f ip=10.88.0.18
2022-01-13T10:36:49.458Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=f9703e4c36089018f63582fbf5f6ce743422d9263cf6b2fcb0fc00aa2c2ec01f
2022-01-13T10:36:49.459Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=c771f0c1-51d1-30ab-4e93-b5f93469cfe7
2022-01-13T10:36:49.459Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=f9703e4c36089018f63582fbf5f6ce743422d9263cf6b2fcb0fc00aa2c2ec01f
2022-01-13T10:36:49.460Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=f9703e4c36089018f63582fbf5f6ce743422d9263cf6b2fcb0fc00aa2c2ec01f error="Container has wrong state"
2022-01-13T10:36:50.459Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=f9703e4c36089018f63582fbf5f6ce743422d9263cf6b2fcb0fc00aa2c2ec01f
    driver_test.go:1298: 
        	Error Trace:	driver_test.go:1298
        	Error:      	"" does not contain " on /checka type "
        	Test:       	TestPodmanDriver_Mount
2022-01-13T10:36:54.477Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:36:54.477Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Dns (5.48s)
2022-01-13T10:37:59.078Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:37:59.269Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-085564990/alloc/logs/.dns.stdout.fifo
2022-01-13T10:37:59.269Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-085564990/alloc/logs/.dns.stderr.fifo
2022-01-13T10:37:59.279Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:37:59.537Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=910d4fa3-fcce-1a75-a7ac-f5680ca4f406 container=4ce9c4f328fe26d6b1945e5db0b92f06473e20680cfaff48692307d309fd45bc ip=10.88.0.24
2022-01-13T10:37:59.538Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=4ce9c4f328fe26d6b1945e5db0b92f06473e20680cfaff48692307d309fd45bc
2022-01-13T10:37:59.538Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=910d4fa3-fcce-1a75-a7ac-f5680ca4f406
2022-01-13T10:37:59.538Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=4ce9c4f328fe26d6b1945e5db0b92f06473e20680cfaff48692307d309fd45bc
2022-01-13T10:37:59.540Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=4ce9c4f328fe26d6b1945e5db0b92f06473e20680cfaff48692307d309fd45bc error="Container has wrong state"
2022-01-13T10:38:00.538Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=4ce9c4f328fe26d6b1945e5db0b92f06473e20680cfaff48692307d309fd45bc
    driver_test.go:1417: 
        	Error Trace:	driver_test.go:1417
        	Error:      	"" does not contain "nameserver 1.1.1.1"
        	Test:       	TestPodmanDriver_Dns
2022-01-13T10:38:04.560Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:04.560Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Container (10.88s)
2022-01-13T10:38:26.983Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:38:27.197Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-582987145/alloc/logs/.maintask.stdout.fifo
2022-01-13T10:38:27.197Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-582987145/alloc/logs/.maintask.stderr.fifo
2022-01-13T10:38:27.205Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:38:27.549Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=2d9d9ebb-b14b-c43f-f733-0c41429b0632 container=12c636f96e27f05c2658070ab9e617e8ccc294c10dbc9de12d2a0b88a369b7a3 ip=10.88.0.26
2022-01-13T10:38:27.549Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=12c636f96e27f05c2658070ab9e617e8ccc294c10dbc9de12d2a0b88a369b7a3
2022-01-13T10:38:27.550Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:38:27.750Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-205012308/alloc/logs/.sidecar.stdout.fifo
2022-01-13T10:38:27.751Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-205012308/alloc/logs/.sidecar.stderr.fifo
2022-01-13T10:38:27.759Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:38:27.892Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=3ff6ab2e-787b-a085-3466-76427161b466 container=02b09ced9958a07d23009fd20531d013f80b62d259e7637d8d047e5e4a8741ea ip=10.88.0.26
2022-01-13T10:38:27.892Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=02b09ced9958a07d23009fd20531d013f80b62d259e7637d8d047e5e4a8741ea
2022-01-13T10:38:27.893Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=3ff6ab2e-787b-a085-3466-76427161b466
2022-01-13T10:38:27.893Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=02b09ced9958a07d23009fd20531d013f80b62d259e7637d8d047e5e4a8741ea
2022-01-13T10:38:27.899Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=02b09ced9958a07d23009fd20531d013f80b62d259e7637d8d047e5e4a8741ea error="Container has wrong state"
2022-01-13T10:38:29.008Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=02b09ced9958a07d23009fd20531d013f80b62d259e7637d8d047e5e4a8741ea
    driver_test.go:1564: 
        	Error Trace:	driver_test.go:1564
        	Error:      	"" does not contain "127.0.0.1:6748"
        	Test:       	TestPodmanDriver_NetworkMode_Container
2022-01-13T10:38:33.028Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:33.028Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:33.043Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=12c636f96e27f05c2658070ab9e617e8ccc294c10dbc9de12d2a0b88a369b7a3
2022-01-13T10:38:33.590Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=12c636f96e27f05c2658070ab9e617e8ccc294c10dbc9de12d2a0b88a369b7a3 error="Container has wrong state"
2022-01-13T10:38:37.859Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:37.859Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_NetworkMode_Task (10.90s)
2022-01-13T10:38:37.862Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:38:38.071Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-297843363/alloc/logs/.maintask.stdout.fifo
2022-01-13T10:38:38.072Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-297843363/alloc/logs/.maintask.stderr.fifo
2022-01-13T10:38:38.078Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:38:38.396Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=7ca63c5a-d302-0ce6-b3ce-43fde6850be1 container=de033a9d423b30d8deb375f0359eeccf82a392fdfadf4937280f74a43de929d9 ip=10.88.0.27
2022-01-13T10:38:38.396Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=de033a9d423b30d8deb375f0359eeccf82a392fdfadf4937280f74a43de929d9
2022-01-13T10:38:38.398Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:38:38.638Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-036758438/alloc/logs/.sidecar.stdout.fifo
2022-01-13T10:38:38.638Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-036758438/alloc/logs/.sidecar.stderr.fifo
2022-01-13T10:38:38.669Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:38:38.821Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=b1dbdab6-4bc6-68ce-99fd-fea61e8fecd9 container=5efa34c70292fb4ae3215225c80e0002866ee91b6f2a4d97969e10683908ca0f ip=10.88.0.27
2022-01-13T10:38:38.822Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=5efa34c70292fb4ae3215225c80e0002866ee91b6f2a4d97969e10683908ca0f
2022-01-13T10:38:38.822Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=b1dbdab6-4bc6-68ce-99fd-fea61e8fecd9
2022-01-13T10:38:38.822Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=5efa34c70292fb4ae3215225c80e0002866ee91b6f2a4d97969e10683908ca0f
2022-01-13T10:38:38.823Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=5efa34c70292fb4ae3215225c80e0002866ee91b6f2a4d97969e10683908ca0f error="Container has wrong state"
2022-01-13T10:38:39.823Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=5efa34c70292fb4ae3215225c80e0002866ee91b6f2a4d97969e10683908ca0f
    driver_test.go:1637: 
        	Error Trace:	driver_test.go:1637
        	Error:      	"" does not contain "127.0.0.1:6748"
        	Test:       	TestPodmanDriver_NetworkMode_Task
2022-01-13T10:38:43.847Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:43.847Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:43.852Z [DEBUG] nomad-driver-podman/driver.go:853: podman: Have to destroyTask but container is still running: containerID=de033a9d423b30d8deb375f0359eeccf82a392fdfadf4937280f74a43de929d9
2022-01-13T10:38:44.412Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=de033a9d423b30d8deb375f0359eeccf82a392fdfadf4937280f74a43de929d9 error="Container has wrong state"
2022-01-13T10:38:48.760Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:38:48.761Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

=== FAIL: . TestPodmanDriver_Sysctl (5.53s)
2022-01-13T10:38:54.907Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-13T10:38:55.112Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-028711368/alloc/logs/.sysctl.stdout.fifo
2022-01-13T10:38:55.112Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-028711368/alloc/logs/.sysctl.stderr.fifo
2022-01-13T10:38:55.120Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-13T10:38:55.415Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=7315af8f-725a-c92b-dc89-8d29b6fecf7e container=fcec2cac46ac3251a49dbf102878e45f4fd54440281872194e3e996d3673e79c ip=10.88.0.29
2022-01-13T10:38:55.415Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=fcec2cac46ac3251a49dbf102878e45f4fd54440281872194e3e996d3673e79c
2022-01-13T10:38:55.416Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=7315af8f-725a-c92b-dc89-8d29b6fecf7e
2022-01-13T10:38:55.416Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=fcec2cac46ac3251a49dbf102878e45f4fd54440281872194e3e996d3673e79c
2022-01-13T10:38:55.417Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=fcec2cac46ac3251a49dbf102878e45f4fd54440281872194e3e996d3673e79c error="Container has wrong state"
2022-01-13T10:38:56.416Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=fcec2cac46ac3251a49dbf102878e45f4fd54440281872194e3e996d3673e79c
    driver_test.go:1723: 
        	Error Trace:	driver_test.go:1723
        	Error:      	"" does not contain "net.core.somaxconn = 12321"
        	Test:       	TestPodmanDriver_Sysctl
2022-01-13T10:39:00.431Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-13T10:39:00.431Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 59 tests, 2 skipped, 12 failures in 319.140s

Perhaps it would be best generally to skip the tests that require rootful podman, rather than have the test suite fail if running rootless, like the cgroupv2 tests are skipped?

towe75 · 2022-01-13T16:52:30Z

Can you reproduce the failures if you run one failed test after another? I did not have time to check the code yet. Any chance that all those tests boil down to read the result from stdout and/or stderr? Maybe stdout handling is broken/misconfigured/changed somehow.

optiz0r · 2022-01-19T12:35:54Z

Sorry for the delay in responding, have been looking at other things this week. Running failing tests standalone does not cause them to pass (still in the normal Ubuntu 20.04 vagrant VM). Picking a couple of examples:

root@ubuntu-focal:/home/vagrant/nomad-driver-podman# PATH=/usr/local/go/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin CI=1 ./build/bin/gotestsum --junitfile ./build/test/result.xml -- -timeout=15m . ./api -run TestPodmanDriver_Sysctl
∅  api (20ms)
✖  . (6.259s)

=== Failed
=== FAIL: . TestPodmanDriver_Sysctl (6.21s)
2022-01-19T12:30:25.040Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-19T12:30:25.792Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-157909650/alloc/logs/.sysctl.stdout.fifo
2022-01-19T12:30:25.794Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-157909650/alloc/logs/.sysctl.stderr.fifo
2022-01-19T12:30:25.813Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-19T12:30:26.227Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=d6d095ab-e359-9f45-1554-27f32fb8d9f6 container=e97a31e8596cd76dbdf56e818ce95771a5365771ef8575e86a4ee3884d551613 ip=10.88.0.64
2022-01-19T12:30:26.227Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=e97a31e8596cd76dbdf56e818ce95771a5365771ef8575e86a4ee3884d551613
2022-01-19T12:30:26.228Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=d6d095ab-e359-9f45-1554-27f32fb8d9f6
2022-01-19T12:30:26.228Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=e97a31e8596cd76dbdf56e818ce95771a5365771ef8575e86a4ee3884d551613
2022-01-19T12:30:26.233Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=e97a31e8596cd76dbdf56e818ce95771a5365771ef8575e86a4ee3884d551613 error="Container has wrong state"
2022-01-19T12:30:27.229Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=e97a31e8596cd76dbdf56e818ce95771a5365771ef8575e86a4ee3884d551613
    driver_test.go:1723: 
        	Error Trace:	driver_test.go:1723
        	Error:      	"" does not contain "net.core.somaxconn = 12321"
        	Test:       	TestPodmanDriver_Sysctl
2022-01-19T12:30:31.245Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-19T12:30:31.245Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 1 tests, 1 failure in 12.375s

root@ubuntu-focal:/home/vagrant/nomad-driver-podman# PATH=/usr/local/go/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin CI=1 ./build/bin/gotestsum --junitfile ./build/test/result.xml -- -timeout=15m . ./api -run TestPodmanDriver_Dns
∅  api (16ms)
✖  . (5.917s)

=== Failed
=== FAIL: . TestPodmanDriver_Dns (5.88s)
2022-01-19T12:32:53.691Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-19T12:32:54.110Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-851290171/alloc/logs/.dns.stdout.fifo
2022-01-19T12:32:54.112Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-851290171/alloc/logs/.dns.stderr.fifo
2022-01-19T12:32:54.120Z [DEBUG] nomad-driver-podman/driver.go:741: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-19T12:32:54.495Z [INFO]  nomad-driver-podman/driver.go:618: podman: Completely started container: taskID=a3313e02-695c-fbca-5969-53dc4a873040 container=a0aaf2c01c30b098c09ed4e2ac4dfd33d14bde12a4bf7efece7edcd433490135 ip=10.88.0.67
2022-01-19T12:32:54.496Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=a0aaf2c01c30b098c09ed4e2ac4dfd33d14bde12a4bf7efece7edcd433490135
2022-01-19T12:32:54.496Z [DEBUG] nomad-driver-podman/driver.go:801: podman: WaitTask called: task=a3313e02-695c-fbca-5969-53dc4a873040
2022-01-19T12:32:54.496Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=a0aaf2c01c30b098c09ed4e2ac4dfd33d14bde12a4bf7efece7edcd433490135
2022-01-19T12:32:54.500Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=a0aaf2c01c30b098c09ed4e2ac4dfd33d14bde12a4bf7efece7edcd433490135 error="Container has wrong state"
2022-01-19T12:32:55.544Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=a0aaf2c01c30b098c09ed4e2ac4dfd33d14bde12a4bf7efece7edcd433490135
    driver_test.go:1417: 
        	Error Trace:	driver_test.go:1417
        	Error:      	"" does not contain "nameserver 1.1.1.1"
        	Test:       	TestPodmanDriver_Dns
2022-01-19T12:32:59.563Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close
2022-01-19T12:32:59.563Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 1 tests, 1 failure in 11.459s

towe75 · 2022-01-20T06:50:36Z

@optiz0r i took a minute to test on a completely new system. I can reproduce the issue now and the culprit seems to be that podman defaults now to the "journald" logdriver. Hence we're configuring a filename for stdout in some tests but we don't switch the driver to "json-file".

Coming back to my previous statements:

the dev machine had an older podman, not affected
my productive machines are writing to journald anyways, thus also not affected (although unittests would fail there...)

I tried this and it fixes the issue:

	// Logging
	if driverConfig.Logging.Driver == "" || driverConfig.Logging.Driver == LOG_DRIVER_NOMAD {
		// Only modify container loggin path if LogCollection is not disabled
		if !d.config.DisableLogCollection {

                        // MUST SET LOGGING DRIVER HERE:
                        createOpts.LogConfiguration.Driver = "json-file"

			createOpts.ContainerBasicConfig.LogConfiguration.Path = cfg.StdoutPath

		}
	} else if driverConfig.Logging.Driver == LOG_DRIVER_JOURNALD {
		createOpts.LogConfiguration.Driver = "journald"
	} else {
		return nil, nil, fmt.Errorf("Invalid logging.driver option")
	}

Have to create a branch/commit later.

Sorry for the inconvenience. Some periodic GH action run might have caught this automatically. @lgfa29 : WDYT?

optiz0r · 2022-01-20T16:24:56Z

This looks better. I'm down to just a single failure with the above local modification

=== FAIL: . TestPodmanDriver_Swap (13.58s)
2022-01-20T16:17:12.694Z [DEBUG] api/api.go:56: podman: http baseurl: url=unix:/run/podman/podman.sock
2022-01-20T16:17:12.912Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-164555002/alloc/logs/.swap.stdout.fifo
2022-01-20T16:17:12.912Z [INFO]  logmon/logmon.go:198: driver_harness.logmon: opening fifo: path=/tmp/nomad_driver_harness-164555002/alloc/logs/.swap.stderr.fifo
2022-01-20T16:17:12.921Z [DEBUG] nomad-driver-podman/driver.go:744: podman: Found imageID: beae173ccac6ad749f76713cf4440fe3d21d1043fe616dfbe30775815d1d0f6a="for image" docker.io/library/busybox:latest="in local storage"
2022-01-20T16:17:12.935Z [WARN]  nomad-driver-podman/driver.go:550: podman: Create Warning: warning="Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap."
2022-01-20T16:17:13.171Z [INFO]  nomad-driver-podman/driver.go:621: podman: Completely started container: taskID=0ea93bac-51b0-e9c4-86cb-29a35db2a239 container=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac ip=10.88.0.82
2022-01-20T16:17:13.171Z [DEBUG] nomad-driver-podman/handle.go:193: podman.podmanHandle: Monitoring container: container=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac
2022-01-20T16:17:13.172Z [DEBUG] nomad-driver-podman/driver.go:804: podman: WaitTask called: task=0ea93bac-51b0-e9c4-86cb-29a35db2a239
2022-01-20T16:17:13.172Z [DEBUG] nomad-driver-podman/handle.go:75: podman.podmanHandle: Starting exitWatcher: container=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac
    driver_test.go:1143: 
        	Error Trace:	driver_test.go:1143
        	Error:      	Not equal: 
        	            	expected: 104857600
        	            	actual  : 0
        	Test:       	TestPodmanDriver_Swap
2022-01-20T16:17:21.183Z [DEBUG] nomad-driver-podman/driver.go:856: podman: Have to destroyTask but container is still running: containerID=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac
2022-01-20T16:17:22.182Z [DEBUG] nomad-driver-podman/handle.go:213: podman.podmanHandle: Container is not running anymore: container=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac error="Container has wrong state"
2022-01-20T16:17:23.198Z [DEBUG] nomad-driver-podman/handle.go:78: podman.podmanHandle: Stopping exitWatcher: container=a2b0bc1d7ab8f99afa298989d3fce12987d25dcace80a20d943c08963ac3e2ac
2022-01-20T16:17:26.272Z [WARN]  logmon/logmon.go:292: driver_harness.logmon: timed out waiting for read-side of process output pipe to close

DONE 59 tests, 2 skipped, 1 failure in 311.136s

At first I thought this might have been because the vagrant box run under VirtualBox doesn't have any swap configured by default. I added 200MB swap via a loop mount, but that didn't change the behaviour

fallocate -l 200M /root/swap.img
losetup /dev/loop3 /root/swap.img
mkswap /dev/loop3
swapon /dev/loop3

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes hashicorp#148

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes #148

optiz0r mentioned this issue Jan 6, 2022

Add cpu_hard_limit and cpu_cfs_period options #149

Merged

optiz0r added a commit to optiz0r/nomad-driver-podman that referenced this issue Jan 20, 2022

Set default logging driver to json-file

b261ccf

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes hashicorp#148

optiz0r mentioned this issue Jan 20, 2022

Set default logging driver to json-file #151

Merged

optiz0r added a commit to optiz0r/nomad-driver-podman that referenced this issue Jan 20, 2022

:Set default logging driver to json-file

8475c3e

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes hashicorp#148

optiz0r added a commit to optiz0r/nomad-driver-podman that referenced this issue Jan 20, 2022

Set default logging driver to json-file

640c6f9

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes hashicorp#148

optiz0r added a commit to optiz0r/nomad-driver-podman that referenced this issue Jan 28, 2022

Set default logging driver to k8s-file

fc69970

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes hashicorp#148

towe75 closed this as completed in #151 Jan 29, 2022

towe75 pushed a commit that referenced this issue Jan 29, 2022

Set default logging driver to k8s-file (#151)

ab81292

Restores the previous default logging driver to json-file following upstream podman change to journald. Fixes #148

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Running tests locally #148

Running tests locally #148

optiz0r commented Jan 5, 2022

lgfa29 commented Jan 7, 2022

optiz0r commented Jan 7, 2022

optiz0r commented Jan 11, 2022 •

edited

Loading

optiz0r commented Jan 12, 2022

towe75 commented Jan 12, 2022

optiz0r commented Jan 12, 2022 •

edited

Loading

towe75 commented Jan 13, 2022

optiz0r commented Jan 13, 2022

towe75 commented Jan 13, 2022

optiz0r commented Jan 19, 2022

towe75 commented Jan 20, 2022 •

edited

Loading

optiz0r commented Jan 20, 2022 •

edited

Loading

Running tests locally #148

Running tests locally #148

Comments

optiz0r commented Jan 5, 2022

lgfa29 commented Jan 7, 2022

optiz0r commented Jan 7, 2022

optiz0r commented Jan 11, 2022 • edited Loading

optiz0r commented Jan 12, 2022

towe75 commented Jan 12, 2022

optiz0r commented Jan 12, 2022 • edited Loading

towe75 commented Jan 13, 2022

optiz0r commented Jan 13, 2022

towe75 commented Jan 13, 2022

optiz0r commented Jan 19, 2022

towe75 commented Jan 20, 2022 • edited Loading

optiz0r commented Jan 20, 2022 • edited Loading

optiz0r commented Jan 11, 2022 •

edited

Loading

optiz0r commented Jan 12, 2022 •

edited

Loading

towe75 commented Jan 20, 2022 •

edited

Loading

optiz0r commented Jan 20, 2022 •

edited

Loading