podman.service fails to mkdir /overlay: operation not permitted

[lukasmrtvy]

Describe the bug

podman.service fails to

Feb 14 16:54:33 ip-10-1-43-209 systemd[1]: Starting podman.service - Podman API Service...
Feb 14 16:54:33 ip-10-1-43-209 systemd[1]: Started podman.service - Podman API Service.
Feb 14 16:54:33 ip-10-1-43-209 podman[3524]: time="2023-02-14T16:54:33Z" level=info msg="/usr/bin/podman filtering at log level info"
Feb 14 16:54:33 ip-10-1-43-209 podman[3524]: Error: mkdir /overlay: operation not permitted
Feb 14 16:54:33 ip-10-1-43-209 systemd[1]: podman.service: Main process exited, code=exited, status=125/n/a
Feb 14 16:54:33 ip-10-1-43-209 systemd[1]: podman.service: Failed with result 'exit-code'.

, rootless and rootful podman commands are working correctly

Reproduction steps

1. deploy 37.20230213.20.0 from testing-devel
2. systemctl status podman.service

Expected behavior

podman.service does not fail

Actual behavior

podman.service fails to Error: mkdir /overlay: operation not permitted

System details

FCOS 37.20230213.20.0 from testing-devel

Butane or Ignition config

No response

Additional information

No response

[travier]

Are you sure that this is not something from one of your containers?

[dustymabe]

Seems to be working fine if I just boot a system with no configuration and try to start the service:

[bound] -bash-5.2$ systemctl status podman
○ podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: ○ podman.socket
       Docs: man:podman-system-service(1)
[bound] -bash-5.2$ sudo systemctl start podman
[bound] -bash-5.2$ sudo systemctl status podman
● podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: active (running) since Tue 2023-02-14 17:36:17 UTC; 3s ago
TriggeredBy: ● podman.socket
       Docs: man:podman-system-service(1)
   Main PID: 1906 (podman)
      Tasks: 5 (limit: 9077)
     Memory: 25.3M
        CPU: 19ms
     CGroup: /system.slice/podman.service
             └─1906 /usr/bin/podman --log-level=info system service

Feb 14 17:36:17 ip-172-31-18-196 systemd[1]: Starting podman.service - Podman API Service...
Feb 14 17:36:17 ip-172-31-18-196 systemd[1]: Started podman.service - Podman API Service.
[bound] -bash-5.2$ 
[bound] -bash-5.2$ rpm-ostree status 
State: idle
Deployments:
● fedora:fedora/x86_64/coreos/testing-devel
                  Version: 37.20230213.20.0 (2023-02-13T22:20:51Z)
                   Commit: a66cea1f4f8b02f843c4fb20b29081a9592855d74158f8a0c36d1aeca50d89a3
             GPGSignature: Valid signature by ACB5EE4E831C74BB7C168D27F55AD3FB5323552A

Maybe the way you have your system configured is exposing a bug? Can you share your butane config?

[lukasmrtvy]

Got reproducer. ( https://pastebin.com/raw/aU81VPSS )

variant: fcos
version: 1.4.0
storage:
  files:
    - path: /etc/containers/storage.conf
      overwrite: true
      contents:
        inline: |
          [storage]
          driver = "overlay"
          graphroot = "/var/lib/containers/storage"

This one containers/storage#1471 might be related

[dustymabe]

ok I am able to reproduce locally with your reproducer. The key to triggering the failure is the sudo systemctl restart podman.service. Copying in the pastebin here:

[root@ip-10-1-88-222 core]# systemctl status podman
○ podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: inactive (dead)
TriggeredBy: ○ podman.socket
       Docs: man:podman-system-service(1)
[root@ip-10-1-88-222 core]# systemctl start podman
[root@ip-10-1-88-222 core]# systemctl status podman
● podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: active (running) since Wed 2023-02-15 14:58:28 UTC; 771ms ago
TriggeredBy: ● podman.socket
       Docs: man:podman-system-service(1)
   Main PID: 1946 (podman)
      Tasks: 13 (limit: 75836)
     Memory: 51.7M
        CPU: 67ms
     CGroup: /system.slice/podman.service
             └─1946 /usr/bin/podman --log-level=info system service

Feb 15 14:58:28 ip-10-1-88-222 systemd[1]: Starting podman.service - Podman API Service...
Feb 15 14:58:28 ip-10-1-88-222 systemd[1]: Started podman.service - Podman API Service.
Feb 15 14:58:28 ip-10-1-88-222 podman[1946]: time="2023-02-15T14:58:28Z" level=info msg="/usr/bin/podman filtering at log level info"
Feb 15 14:58:28 ip-10-1-88-222 podman[1946]: 2023-02-15 14:58:28.884554842 +0000 UTC m=+0.324852920 system refresh
Feb 15 14:58:28 ip-10-1-88-222 podman[1946]: time="2023-02-15T14:58:28Z" level=info msg="Setting parallel job count to 25"
Feb 15 14:58:28 ip-10-1-88-222 podman[1946]: time="2023-02-15T14:58:28Z" level=info msg="Using systemd socket activation to determine API endpoint"
Feb 15 14:58:28 ip-10-1-88-222 podman[1946]: time="2023-02-15T14:58:28Z" level=info msg="API service listening on \"/run/podman/podman.sock\". URI: \"/run/podman/podman.sock\""
[root@ip-10-1-88-222 core]# systemctl restart podman
[root@ip-10-1-88-222 core]# systemctl status podman
× podman.service - Podman API Service
     Loaded: loaded (/usr/lib/systemd/system/podman.service; disabled; preset: disabled)
     Active: failed (Result: exit-code) since Wed 2023-02-15 14:58:35 UTC; 1s ago
   Duration: 21ms
TriggeredBy: ● podman.socket
       Docs: man:podman-system-service(1)
    Process: 1965 ExecStart=/usr/bin/podman $LOGGING system service (code=exited, status=125)
   Main PID: 1965 (code=exited, status=125)
        CPU: 30ms

Feb 15 14:58:35 ip-10-1-88-222 systemd[1]: Starting podman.service - Podman API Service...
Feb 15 14:58:35 ip-10-1-88-222 systemd[1]: Started podman.service - Podman API Service.
Feb 15 14:58:35 ip-10-1-88-222 podman[1965]: time="2023-02-15T14:58:35Z" level=info msg="/usr/bin/podman filtering at log level info"
Feb 15 14:58:35 ip-10-1-88-222 podman[1965]: Error: mkdir /overlay: operation not permitted
Feb 15 14:58:35 ip-10-1-88-222 systemd[1]: podman.service: Main process exited, code=exited, status=125/n/a
Feb 15 14:58:35 ip-10-1-88-222 systemd[1]: podman.service: Failed with result 'exit-code'.

[dustymabe]

tagging in @giuseppe in case he might have an idea what's going on here.

[giuseppe]

what is the version of Podman you are using?

[lukasmrtvy]

podman-5:4.4.1-1.fc37.x86_64

[giuseppe]

cannot reproduce on a regular F37 machine. Does it make any difference if you remove the /etc/containers/storage.conf file?

[lukasmrtvy]

Its working correctly without /etc/containers/storage.conf file.

[giuseppe]

does it happen if you specify both runroot and graphroot?

[giuseppe]

I think the issue is with the empty runroot so the overlay directory is created on / which is not possible on CoreOS since it is mounted read-only

[giuseppe]

opened a PR to error out when this happens: containers/storage#1510

[dustymabe]

Thanks @giuseppe - so the summary here is that the configuration is incomplete? I guess this was not erroring out previously but is now with the new podman 4.4, but ultimately the solution is to update the user's configuration?

[giuseppe]

Thanks @giuseppe - so the summary here is that the configuration is incomplete? I guess this was not erroring out previously but is now with the new podman 4.4, but ultimately the solution is to update the user's configuration?

yes the issue is an incomplete configuration. In any case, Podman should detect it and not use the current working directory.

[dustymabe]

@lukasmrtvy - can you update your configuration and try again?

[dustymabe]

I'm going to close this out. @lukasmrtvy feel free to re-open if the updated configuration doesn't fix things.