Running nerdctl compose up immediately exists with "no such file or directory" on -json.log file

[davebarkerxyz]

Description

Running nerdctl compose up (without the -d detach flag) immediately exits with an error that the container -json.log file does not exist.

Running nerdctl compose up -d; sleep 2; nerdctl compose logs -f works; the containers are created and the log files exist and are tailed to stdout.

This behaviour occurs with both v0.20.0 (as installed by Lima) and current master (ddad500) compiled from source.

Steps to reproduce the issue

1. Create docker-compose.yml file as below
2. Run nerdctl compose up

version: '3.1'

services:

  db:
    image: postgres:latest
    environment:
      POSTGRES_PASSWORD: postgres
    ports:
      - 5432:5432

Describe the results you received and expected

Expected results:

Container starts and log file is tailed to stdout.

Received results:

nerdctl immediately exists, with the following output (with -debug flag):

dave@lima-default psql-example % nerdctl compose up --debug
DEBU[0000] stateDir: /run/user/501/containerd-rootless
DEBU[0000] rootless parent main: executing "/usr/bin/nsenter" with [-r/ -w/home/dave.linux/dev/containers/psql-example --preserve-credentials -m -n -U -t 1610 -F nerdctl compose up --debug]
INFO[0000] Ensuring image postgres:latest
DEBU[0000] filters: [labels."com.docker.compose.project"==psql-example,labels."com.docker.compose.service"==db]
INFO[0000] Creating container psql-example_db_1
DEBU[0000] failed to run [aa-exec -p nerdctl-default -- true]: "aa-exec: ERROR: profile 'nerdctl-default' does not exist\n\n"  error="exit status 1"
DEBU[0000] verification process skipped
DEBU[0000] creating anonymous volume "43cd122bfc77156a7e186835af920a0ece71334be29f77c931860b073a872ca7", for "VOLUME /var/lib/postgresql/data"
DEBU[0000] final cOpts is [0x6e5a40 0xaafa50 0x6e5e60 0x6e5bc0 0x6e58b0 0xab0e00 0xab1fa0 0x6e62f0]
INFO[0000] Attaching to logs
DEBU[0000] filters: [labels."com.docker.compose.project"==psql-example,labels."com.docker.compose.service"==db]
db_1 |time="2022-05-20T20:39:51Z" level=fatal msg="failed to open \"/home/dave.linux/.local/share/nerdctl/1935db59/containers/default/d3c03ca1e0c65d0bba6e43d24ab8bd5fc5820d276cf9ebda97894d07b2991d57/d3c03ca1e0c65d0bba6e43d24ab8bd5fc5820d276cf9ebda97894d07b2991d57-json.log\", container is not created with `nerdctl run -d`?: stat /home/dave.linux/.local/share/nerdctl/1935db59/containers/default/d3c03ca1e0c65d0bba6e43d24ab8bd5fc5820d276cf9ebda97894d07b2991d57/d3c03ca1e0c65d0bba6e43d24ab8bd5fc5820d276cf9ebda97894d07b2991d57-json.log: no such file or directory"
INFO[0000] Container "psql-example_db_1" exited
INFO[0000] All the containers have exited
INFO[0000] Stopping containers (forcibly)
INFO[0000] Stopping container psql-example_db_1

What version of nerdctl are you using?

Client:
Version: v0.20.0
OS/Arch: linux/arm64
Git commit: e77e05b

Server:
containerd:
Version: v1.6.4
GitCommit: 212e8b6fa2f44b9c21b2798135fc6fb7c53efc16

Are you using a variant of nerdctl? (e.g., Rancher Desktop)

Lima

Host information

Client:
Namespace: default
Debug Mode: false

Server:
Server Version: v1.6.4
Storage Driver: fuse-overlayfs
Logging Driver: json-file
Cgroup Driver: systemd
Cgroup Version: 2
Plugins:
Log: json-file
Storage: native overlayfs stargz fuse-overlayfs
Security Options:
apparmor
seccomp
Profile: default
cgroupns
rootless
Kernel Version: 5.10.0-13-arm64
Operating System: Debian GNU/Linux 11 (bullseye)
OSType: linux
Architecture: aarch64
CPUs: 4
Total Memory: 3.831GiB
Name: lima-default
ID: a2e0f2fe-8b65-4b55-b746-945a35e37c9f

WARNING: AppArmor profile "nerdctl-default" is not loaded.
Use 'sudo nerdctl apparmor load' if you prefer to use AppArmor with rootless mode.
This warning is negligible if you do not intend to use AppArmor.
WARNING: bridge-nf-call-iptables is disabled
WARNING: bridge-nf-call-ip6tables is disabled

[fahedouch]

we should merge this https://github.com/containerd/nerdctl/pull/1062/files than I will push a fix for this issue.
I will take care of it @davebarkerxyz ;)

[samgranieri]

This is impacting me. Thank you @fahedouch for taking care of this

[davebarkerxyz]

Thanks @fahedouch - much appreciated! If you need me to test your fix then please let me know and I'd be happy to help.

[AkihiroSuda]

@fahedouch Do you have a plan to open a PR?

[fahedouch]

@AkihiroSuda Yes, I looked at this yesterday, I made a fix ASAP!

[nsiepmann]

Using the workaround above doesn't seem to fix it for me. I have a compose file with three containers. Two of them start as expected, but one fails with this error message and exits:

foo_bar_1         |time="2022-06-09T10:35:28Z" level=fatal msg="failed to open \"/var/lib/nerdctl/dbb19c5e/containers/default/9326ba0edf486870a2d605b197a3516c5d8091899844b058dfa365b5ceb2fa95/9326ba0edf486870a2d605b197a3516c5d8091899844b058dfa365b5ceb2fa95-json.log\", container is not created with `nerdctl run -d`?: stat /var/lib/nerdctl/dbb19c5e/containers/default/9326ba0edf486870a2d605b197a3516c5d8091899844b058dfa365b5ceb2fa95/9326ba0edf486870a2d605b197a3516c5d8091899844b058dfa365b5ceb2fa95-json.log: no such file or directory"

Take note that I'm running nerdctl bundled with Rancher Desktop.

Using the workaround produces the same result. Two containers are running, one of them fails.

[davebarkerxyz]

@nsiepmann I've managed to use the workaround with mutli-container compose files, but I suspect it's highly dependent on timing (how quickly the container starts). You could try increasing the sleep to see if that helps until a fix is available, e.g. nerdctl compose up -d; sleep 10; nerdctl compose logs -f

[AkihiroSuda]

Fixed in nerdctl v0.21.0
https://github.com/containerd/nerdctl/releases/tag/v0.21.0

[nicolasespiau]

I'm running a Gitlab CI step with image ghcr.io/containerd/nerdctl:v0.21.0 and I have a similar error:

time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[92] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
90time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
91time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[93] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
92time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
93time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[94] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
94time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
95time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[95] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
96time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
97time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[96] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
98time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
99time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[97] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
100time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
101time="2022-07-15T15:30:02Z" level=debug msg="failed to run [aa-exec -p nerdctl-default -- true]: \"[98] aa-exec: ERROR: profile 'nerdctl-default' does not exist\\n\"" error="exit status 1"
102time="2022-07-15T15:30:02Z" level=debug msg="verification process skipped"
103time="2022-07-15T15:30:02Z" level=fatal msg="no such file or directory"
104time="2022-07-15T15:30:02Z" level=fatal msg="no such file or directory"
105time="2022-07-15T15:30:03Z" level=fatal msg="no such file or directory"
106time="2022-07-15T15:30:03Z" level=fatal msg="no such file or directory"
107time="2022-07-15T15:30:03Z" level=fatal msg="no such file or directory"
108time="2022-07-15T15:30:03Z" level=fatal msg="no such file or directory"
109time="2022-07-15T15:30:03Z" level=fatal msg="no such file or directory"
110time="2022-07-15T15:30:03Z" level=fatal msg="error while creating container users: exit status 1"

But nothing about log files or sthing like that.