Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

docker-compose times out trying to use the user socket #10857

Closed
networkException opened this issue Jul 4, 2021 · 11 comments · Fixed by #10865
Closed

docker-compose times out trying to use the user socket #10857

networkException opened this issue Jul 4, 2021 · 11 comments · Fixed by #10865
Assignees
@Luap99
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Comments

@networkException
Copy link

networkException commented Jul 4, 2021 •
edited
Loading

/kind bug

Description

When trying to start a container using docker-compose in rootless mode with podman, docker-compose hangs and podman commands run afterwards do not respond.

Steps to reproduce the issue:

  1. Enable the podman user socket with systemd systemctl --user start podman.socket
  2. Navigate into a directory that contains a docker-compose.yml file (for example the following)
version: "3.8"

services:
    nginx:
        image: nginx:latest
        container_name: nginx
        ports:
            - 1111:80
  1. Run docker-compose -H unix:///run/user/1000/podman/podman.sock --log-level DEBUG up to make docker-compose use the previously started podman socket and let it start the container as specified

Describe the results you received:

docker-compose hangs for 60s (the default timeout set by COMPOSE_HTTP_TIMEOUT), then errors with UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60). Stdout gets spammed with Pending: set() while it hangs.

Additionally, running podman commands (like podman ps, not just podman however) also hang / don't return any output. Looking at htop, two processes with the command /usr/bin/podman --log-level=info system service are using ~150% and ~90% of cpu respectively, The only way to get podman responding again is by killing those processes.

Describe the results you expected:

docker-compose should start the container without any issues and podman commands should react normally after.

Additional information you deem important (e.g. issue happens only occasionally):

The issue is reproducible and happens every time.

Output of podman version:

Version:      3.2.2
API Version:  3.2.2
Go Version:   go1.15.2
Built:        Thu Jan  1 01:00:00 1970
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.21.0
  cgroupControllers: []
  cgroupManager: cgroupfs
  cgroupVersion: v1
  conmon:
    package: 'conmon: /usr/libexec/podman/conmon'
    path: /usr/libexec/podman/conmon
    version: 'conmon version 2.0.27, commit: '
  cpus: 8
  distribution:
    distribution: ubuntu
    version: "20.04"
  eventLogger: journald
  hostname: earth
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
  kernel: 5.4.0-71-generic
  linkmode: dynamic
  memFree: 290385920
  memTotal: 8213098496
  ociRuntime:
    name: crun
    package: 'crun: /usr/bin/crun'
    path: /usr/bin/crun
    version: |-
      crun version 0.20.1.5-925d-dirty
      commit: 0d42f1109fd73548f44b01b3e84d04a279e99d2e
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    exists: true
    path: /run/user/1000/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: 'slirp4netns: /usr/bin/slirp4netns'
    version: |-
      slirp4netns version 1.1.8
      commit: unknown
      libslirp: 4.3.1-git
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.4.3
  swapFree: 1723703296
  swapTotal: 2147479552
  uptime: 1896h 50m 40.01s (Approximately 79.00 days)
registries:
  search:
  - docker.io
  - quay.io
store:
  configFile: /home/networkexception/.config/containers/storage.conf
  containerStore:
    number: 2
    paused: 0
    running: 0
    stopped: 2
  graphDriverName: overlay
  graphOptions:
    overlay.mount_program:
      Executable: /usr/bin/fuse-overlayfs
      Package: 'fuse-overlayfs: /usr/bin/fuse-overlayfs'
      Version: |-
        fusermount3 version: 3.9.0
        fuse-overlayfs: version 1.5
        FUSE library version 3.9.0
        using FUSE kernel interface version 7.31
  graphRoot: /home/networkexception/.local/share/containers/storage
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  imageStore:
    number: 3
  runRoot: /run/user/1000/containers
  volumePath: /home/networkexception/.local/share/containers/storage/volumes
version:
  APIVersion: 3.2.2
  Built: 0
  BuiltTime: Thu Jan  1 01:00:00 1970
  GitCommit: ""
  GoVersion: go1.15.2
  OsArch: linux/amd64
  Version: 3.2.2

Package info (e.g. output of rpm -q podman or apt list podman):

apt list podman (podman installed from the Kubic Project OBS Repository as described in the install guide)

podman/unknown,now 100:3.2.2-1 amd64 [installed]
podman/unknown 100:3.2.2-1 arm64
podman/unknown 100:3.2.2-1 armhf
podman/unknown 100:3.2.2-1 s390x

Have you tested with the latest version of Podman and have you checked the Podman Troubleshooting Guide? (https://github.com/containers/podman/blob/master/troubleshooting.md)

Yes

Additional environment details (AWS, VirtualBox, physical, etc.):

Physical machine, host operating system
@openshift-ci openshift-ci bot added the kind/bug Categorizes issue or PR as related to a bug. label Jul 4, 2021
@networkException networkException mentioned this issue Jul 4, 2021
Closed
@Luap99
Copy link
Member

Luap99 commented Jul 5, 2021

I cannot reproduce on fedora, please run the podman service with log level debug, podman --log-level debug system service -t0 and provide the output. Hopefully this will show where it hangs.

@networkException
Copy link
Author

This is the full log

INFO[0000] podman filtering at log level debug          
DEBU[0000] Called service.PersistentPreRunE(podman --log-level debug system service -t0) 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Merged system config "/usr/share/containers/containers.conf" 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Using conmon: "/usr/libexec/podman/conmon"   
DEBU[0000] Initializing boltdb state at /home/networkexception/.local/share/containers/storage/libpod/bolt_state.db 
DEBU[0000] Using graph driver overlay                   
DEBU[0000] Using graph root /home/networkexception/.local/share/containers/storage 
DEBU[0000] Using run root /run/user/1000/containers     
DEBU[0000] Using static dir /home/networkexception/.local/share/containers/storage/libpod 
DEBU[0000] Using tmp dir /run/user/1000/libpod/tmp      
DEBU[0000] Using volume path /home/networkexception/.local/share/containers/storage/volumes 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Set libpod namespace to ""                   
DEBU[0000] [graphdriver] trying provided driver "overlay" 
DEBU[0000] overlay: mount_program=/usr/bin/fuse-overlayfs 
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false 
DEBU[0000] Initializing event backend journald          
DEBU[0000] configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument 
DEBU[0000] configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument 
DEBU[0000] Using OCI runtime "/usr/bin/crun"            
INFO[0000] Found CNI network podman_default (type=bridge) at /home/networkexception/.config/cni/net.d/podman_default.conflist 
INFO[0000] Found CNI network vertretungsbot_default (type=bridge) at /home/networkexception/.config/cni/net.d/vertretungsbot_default.conflist 
DEBU[0000] Default CNI network name podman is unchangeable 
INFO[0000] Setting parallel job count to 25             
INFO[0000] using API endpoint: 'unix:/run/user/1000/podman/podman.sock' 
DEBU[0000] registered SIGHUP watcher for config         
INFO[0000] API server listening on "/run/user/1000/podman/podman.sock" 
DEBU[0000] waiting for SIGHUP to reload configuration   
DEBU[0000] API Server idle for 0s                       
DEBU[0000] APIServer.Shutdown ignored as Duration is UnlimitedService 
DEBU[0011] IdleTracker 0xc000010010:new 0m+0h/0t connection(s) 
DEBU[0011] IdleTracker 0xc000010010:active 0m+0h/1t connection(s) 
INFO[0011] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- GET /version BEGIN 
DEBU[0011] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- Header: Connection=[keep-alive] 
DEBU[0011] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0011] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0011] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- Header: Accept=[*/*] 
DEBU[0012] Loading registries configuration "/etc/containers/registries.conf" 
DEBU[0012] Loading registries configuration "/etc/containers/registries.conf.d/000-shortnames.conf" 
DEBU[0012] APIHandler(eb2bb254-8eab-4aa2-b5e7-63495fb2d72a) -- GET /version END 
DEBU[0012] IdleTracker 0xc000010010:idle 1m+0h/1t connection(s) 
DEBU[0012] IdleTracker 0xc0008903d0:new 1m+0h/1t connection(s) 
DEBU[0012] IdleTracker 0xc0008903d0:active 1m+0h/2t connection(s) 
INFO[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- GET /v1.40/networks/podman_default BEGIN 
DEBU[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(35b4ef02-c691-488f-83da-532a8b0f8b84) -- GET /v1.40/networks/podman_default END 
DEBU[0012] IdleTracker 0xc0008903d0:idle 2m+0h/2t connection(s) 
DEBU[0012] IdleTracker 0xc000516018:new 2m+0h/2t connection(s) 
DEBU[0012] IdleTracker 0xc000516018:active 2m+0h/3t connection(s) 
INFO[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- GET /v1.40/info BEGIN 
DEBU[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(d6627872-c038-46b4-a99b-fa5a8bb20ea2) -- GET /v1.40/info END 
DEBU[0012] IdleTracker 0xc000516018:idle 3m+0h/3t connection(s) 
DEBU[0012] IdleTracker 0xc0008903d0:active 3m+0h/3t connection(s) 
INFO[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- GET /v1.40/networks/podman_default BEGIN 
DEBU[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(7df9ab63-2045-47fe-af5d-91d5ca2bc755) -- GET /v1.40/networks/podman_default END 
DEBU[0012] IdleTracker 0xc0008903d0:idle 3m+0h/3t connection(s) 
DEBU[0012] IdleTracker 0xc000010f88:new 3m+0h/3t connection(s) 
DEBU[0012] IdleTracker 0xc000010f88:active 3m+0h/4t connection(s) 
INFO[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(a874341d-5dc4-4761-a128-ba70d58e49c1) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0012] IdleTracker 0xc000010f88:idle 4m+0h/4t connection(s) 
DEBU[0012] IdleTracker 0xc000010f88:active 4m+0h/4t connection(s) 
INFO[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(0bfa9c40-da5c-487b-bfac-364dc46f3e7c) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0012] IdleTracker 0xc000010f88:idle 4m+0h/4t connection(s) 
DEBU[0012] IdleTracker 0xc0005171e8:new 4m+0h/4t connection(s) 
DEBU[0012] IdleTracker 0xc0005171e8:active 4m+0h/5t connection(s) 
INFO[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(b2789c94-21d2-4c37-b902-3baa78fe6c81) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0012] IdleTracker 0xc0005171e8:idle 5m+0h/5t connection(s) 
DEBU[0012] IdleTracker 0xc000517450:new 5m+0h/5t connection(s) 
DEBU[0012] IdleTracker 0xc000517450:active 5m+0h/6t connection(s) 
INFO[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(9b5df1a2-372d-4723-a396-123e864e57fc) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0012] IdleTracker 0xc000517450:idle 6m+0h/6t connection(s) 
DEBU[0012] IdleTracker 0xc000010018:new 6m+0h/6t connection(s) 
DEBU[0012] IdleTracker 0xc000010018:active 6m+0h/7t connection(s) 
INFO[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(74462aee-f68f-4c57-b2c2-5d1d709baf74) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0012] IdleTracker 0xc000010018:idle 7m+0h/7t connection(s) 
DEBU[0012] IdleTracker 0xc000517450:active 7m+0h/7t connection(s) 
INFO[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(4fd599f3-f6ec-4f3f-a551-28a4e02a156d) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0012] IdleTracker 0xc000517450:idle 7m+0h/7t connection(s) 
DEBU[0012] IdleTracker 0xc000010268:new 7m+0h/7t connection(s) 
DEBU[0012] IdleTracker 0xc000010268:active 7m+0h/8t connection(s) 
INFO[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- GET /v1.40/images/nginx:latest/json BEGIN 
DEBU[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- Header: Connection=[keep-alive] 
DEBU[0012] Looking up image "nginx:latest" in local containers storage 
DEBU[0012] Trying "nginx:latest" ...                    
DEBU[0012] Trying "localhost/nginx:latest" ...          
DEBU[0012] Trying "docker.io/library/nginx:latest" ...  
DEBU[0012] parsed reference into "[overlay@/home/networkexception/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs]@4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] Found image "nginx:latest" as "docker.io/library/nginx:latest" in local containers storage 
DEBU[0012] Inspecting image 4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] APIHandler(d813a125-3405-4645-8c8a-9f72b499f591) -- GET /v1.40/images/nginx:latest/json END 
DEBU[0012] IdleTracker 0xc000010268:idle 8m+0h/8t connection(s) 
DEBU[0012] IdleTracker 0xc000010018:active 8m+0h/8t connection(s) 
INFO[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(be6cadeb-7995-4669-ae13-18b091d9595e) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0012] IdleTracker 0xc000010018:idle 8m+0h/8t connection(s) 
DEBU[0012] IdleTracker 0xc000010268:active 8m+0h/8t connection(s) 
INFO[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- GET /v1.40/images/nginx:latest/json BEGIN 
DEBU[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- Header: Connection=[keep-alive] 
DEBU[0012] Looking up image "nginx:latest" in local containers storage 
DEBU[0012] Trying "nginx:latest" ...                    
DEBU[0012] Trying "localhost/nginx:latest" ...          
DEBU[0012] Trying "docker.io/library/nginx:latest" ...  
DEBU[0012] parsed reference into "[overlay@/home/networkexception/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs]@4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] Found image "nginx:latest" as "docker.io/library/nginx:latest" in local containers storage 
DEBU[0012] Inspecting image 4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0012] APIHandler(444f811a-5c8c-44aa-bfb4-9a52bab4d2b7) -- GET /v1.40/images/nginx:latest/json END 
DEBU[0012] IdleTracker 0xc000010268:idle 8m+0h/8t connection(s) 
DEBU[0012] IdleTracker 0xc000517450:active 8m+0h/8t connection(s) 
INFO[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(3e107ca3-39a5-4f78-926d-9f39b9f5e68f) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0012] IdleTracker 0xc000517450:idle 8m+0h/8t connection(s) 
DEBU[0012] IdleTracker 0xc000135550:new 8m+0h/8t connection(s) 
DEBU[0012] IdleTracker 0xc000135550:active 8m+0h/9t connection(s) 
INFO[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- POST /v1.40/networks/podman_default/disconnect BEGIN 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: Content-Length=[81] 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: Accept=[*/*] 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: Connection=[keep-alive] 
DEBU[0012] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- Header: Content-Type=[application/json] 
DEBU[0013] APIHandler(4fb19162-64cb-45cc-8c27-ebb6b3cba2b1) -- POST /v1.40/networks/podman_default/disconnect END 
DEBU[0013] IdleTracker 0xc000135550:idle 9m+0h/9t connection(s) 
DEBU[0013] IdleTracker 0xc000135750:new 9m+0h/9t connection(s) 
DEBU[0013] IdleTracker 0xc000135750:active 9m+0h/10t connection(s) 
INFO[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- POST /v1.40/networks/podman_default/connect BEGIN 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: Accept=[*/*] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: Connection=[keep-alive] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: Content-Type=[application/json] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: Content-Length=[139] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0013] APIHandler(5b74d418-becd-4aad-9a77-f10de6d372ad) -- POST /v1.40/networks/podman_default/connect END 
DEBU[0013] IdleTracker 0xc000135750:idle 10m+0h/10t connection(s) 
DEBU[0013] IdleTracker 0xc000890008:new 10m+0h/10t connection(s) 
DEBU[0013] IdleTracker 0xc000890008:active 10m+0h/11t connection(s) 
INFO[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- POST /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/start BEGIN 
DEBU[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- Header: Accept=[*/*] 
DEBU[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- Header: Connection=[keep-alive] 
DEBU[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- Header: Content-Length=[0] 
DEBU[0013] APIHandler(f18ca804-b77b-4900-a94f-74a2f722d8f0) -- Header: User-Agent=[docker-compose/1.28.6 docker-py/4.4.4 Linux/5.4.0-71-generic] 
DEBU[0013] [graphdriver] trying provided driver "overlay" 
DEBU[0013] overlay: mount_program=/usr/bin/fuse-overlayfs 
DEBU[0013] Made network namespace at /run/user/1000/netns/cni-651e8082-5e5f-76a2-c039-d27fb677c55d for container 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 
DEBU[0013] creating rootless cni network namespace      
DEBU[0013] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false 
DEBU[0013] overlay: mount_data=,lowerdir=/home/networkexception/.local/share/containers/storage/overlay/l/3UBBU2GDA5NNHMPYB7KBNASTPA:/home/networkexception/.local/share/containers/storage/overlay/l/J3BVHIHHFQVMQ75C4FFDWD2X56:/home/networkexception/.local/share/containers/storage/overlay/l/4J2MORGWWLB3X62RTJRTAGWGWE:/home/networkexception/.local/share/containers/storage/overlay/l/UCP6L6POBEHHSNAI7Z4VDHDIBA:/home/networkexception/.local/share/containers/storage/overlay/l/HDVMNCBLU5DVS3KS34COIBDRYO:/home/networkexception/.local/share/containers/storage/overlay/l/R2NHLV26I7FFEVQPT6CBTI7XUV,upperdir=/home/networkexception/.local/share/containers/storage/overlay/df467ac0093312f49570bf3794c49e65277992ce8da45aaf5b87081d1456cc9c/diff,workdir=/home/networkexception/.local/share/containers/storage/overlay/df467ac0093312f49570bf3794c49e65277992ce8da45aaf5b87081d1456cc9c/work 
DEBU[0013] slirp4netns command: /usr/bin/slirp4netns --disable-host-loopback --mtu=65520 --enable-sandbox --enable-seccomp -c -r 3 --netns-type=path /run/user/1000/netns/rootless-cni-ns tap0 
DEBU[0013] mounted container "062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575" at "/home/networkexception/.local/share/containers/storage/overlay/df467ac0093312f49570bf3794c49e65277992ce8da45aaf5b87081d1456cc9c/merged" 
DEBU[0013] Created root filesystem for container 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 at /home/networkexception/.local/share/containers/storage/overlay/df467ac0093312f49570bf3794c49e65277992ce8da45aaf5b87081d1456cc9c/merged 
DEBU[0032] IdleTracker 0xc000010010:closed 11m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc000516018:closed 10m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc0008903d0:closed 9m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc000010f88:closed 8m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc0005171e8:closed 7m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc000010018:closed 6m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc000010268:closed 5m+0h/11t connection(s) 
DEBU[0032] IdleTracker 0xc000517450:closed 4m+0h/11t connection(s) 
DEBU[0033] IdleTracker 0xc000135550:closed 3m+0h/11t connection(s) 
DEBU[0033] IdleTracker 0xc000135750:closed 2m+0h/11t connection(s)

@networkException
Copy link
Author

Ok my docker-compose was not up to date, upgrading it to 1.29.2 changed the behavior but still doesn't work:

Using configuration files: ./docker-compose.yml
nginx has diverged: 8f50dcbb8a26f49f98d31439e88c352ba1c125779aa7d6f9b28f292172819627 != a9d82a3eaba4061b1106e599a621fa6f358dd8ca125fcf59ec9913b7a6f0ecbe
Pending: {<Service: nginx>}
Starting producer thread for <Service: nginx>
Recreating nginx ... 
Pending: {<Container: nginx (062cac)>}
Starting producer thread for <Container: nginx (062cac)>
Recreating nginx ... error
Pending: set()

ERROR: for nginx  can only stop created or running containers. 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 is in state configured: container state improper
Failed: <Service: nginx>
Pending: set()

ERROR: for nginx  can only stop created or running containers. 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 is in state configured: container state improper
ERROR: Encountered errors while bringing up the project.

INFO[0000] podman filtering at log level debug          
DEBU[0000] Called service.PersistentPreRunE(podman --log-level debug system service -t0) 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Merged system config "/usr/share/containers/containers.conf" 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Using conmon: "/usr/libexec/podman/conmon"   
DEBU[0000] Initializing boltdb state at /home/networkexception/.local/share/containers/storage/libpod/bolt_state.db 
DEBU[0000] Using graph driver overlay                   
DEBU[0000] Using graph root /home/networkexception/.local/share/containers/storage 
DEBU[0000] Using run root /run/user/1000/containers     
DEBU[0000] Using static dir /home/networkexception/.local/share/containers/storage/libpod 
DEBU[0000] Using tmp dir /run/user/1000/libpod/tmp      
DEBU[0000] Using volume path /home/networkexception/.local/share/containers/storage/volumes 
DEBU[0000] overlay storage already configured with a mount-program 
DEBU[0000] Set libpod namespace to ""                   
DEBU[0000] [graphdriver] trying provided driver "overlay" 
DEBU[0000] overlay: mount_program=/usr/bin/fuse-overlayfs 
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false 
DEBU[0000] Initializing event backend journald          
DEBU[0000] configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument 
DEBU[0000] configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument 
DEBU[0000] Using OCI runtime "/usr/bin/crun"            
INFO[0000] Found CNI network podman_default (type=bridge) at /home/networkexception/.config/cni/net.d/podman_default.conflist 
INFO[0000] Found CNI network vertretungsbot_default (type=bridge) at /home/networkexception/.config/cni/net.d/vertretungsbot_default.conflist 
DEBU[0000] Default CNI network name podman is unchangeable 
INFO[0000] Setting parallel job count to 25             
INFO[0000] using API endpoint: 'unix:/run/user/1000/podman/podman.sock' 
DEBU[0000] registered SIGHUP watcher for config         
INFO[0000] API server listening on "/run/user/1000/podman/podman.sock" 
DEBU[0000] waiting for SIGHUP to reload configuration   
DEBU[0000] API Server idle for 0s                       
DEBU[0000] APIServer.Shutdown ignored as Duration is UnlimitedService 
DEBU[0006] IdleTracker 0xc00043a028:new 0m+0h/0t connection(s) 
DEBU[0006] IdleTracker 0xc00043a028:active 0m+0h/1t connection(s) 
INFO[0006] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- GET /version BEGIN 
DEBU[0006] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0006] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0006] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- Header: Accept=[*/*] 
DEBU[0006] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- Header: Connection=[keep-alive] 
DEBU[0007] Loading registries configuration "/etc/containers/registries.conf" 
DEBU[0007] Loading registries configuration "/etc/containers/registries.conf.d/000-shortnames.conf" 
DEBU[0007] APIHandler(8be8f8b5-ef10-46d4-b647-7244b0e40d3a) -- GET /version END 
DEBU[0007] IdleTracker 0xc00043a028:idle 1m+0h/1t connection(s) 
DEBU[0007] IdleTracker 0xc00043a148:new 1m+0h/1t connection(s) 
DEBU[0007] IdleTracker 0xc00043a148:active 1m+0h/2t connection(s) 
INFO[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- GET /v1.40/networks/podman_default BEGIN 
DEBU[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(76141a43-8f42-42c5-b428-cc48bfb83954) -- GET /v1.40/networks/podman_default END 
DEBU[0007] IdleTracker 0xc00043a148:idle 2m+0h/2t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa8d0:new 2m+0h/2t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa8d0:active 2m+0h/3t connection(s) 
INFO[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- GET /v1.40/info BEGIN 
DEBU[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(a168fde6-a49b-43ae-9880-f7a6bf2a6175) -- GET /v1.40/info END 
DEBU[0007] IdleTracker 0xc0007aa8d0:idle 3m+0h/3t connection(s) 
DEBU[0007] IdleTracker 0xc00043a148:active 3m+0h/3t connection(s) 
INFO[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- GET /v1.40/networks/podman_default BEGIN 
DEBU[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(2dce2df6-2ed2-41eb-8b3a-5b27176ce77c) -- GET /v1.40/networks/podman_default END 
DEBU[0007] IdleTracker 0xc00043a148:idle 3m+0h/3t connection(s) 
DEBU[0007] IdleTracker 0xc000138fb8:new 3m+0h/3t connection(s) 
DEBU[0007] IdleTracker 0xc000138fb8:active 3m+0h/4t connection(s) 
INFO[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(70256d26-30c9-4db8-9a0b-f8edff4c4754) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0007] IdleTracker 0xc000138fb8:idle 4m+0h/4t connection(s) 
DEBU[0007] IdleTracker 0xc000138fb8:active 4m+0h/4t connection(s) 
INFO[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(94fd601b-92f6-44bd-87ea-94668e01368f) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0007] IdleTracker 0xc000138fb8:idle 4m+0h/4t connection(s) 
DEBU[0007] IdleTracker 0xc000139c70:new 4m+0h/4t connection(s) 
DEBU[0007] IdleTracker 0xc000139c70:active 4m+0h/5t connection(s) 
INFO[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(a8c6aa54-874b-41c8-876a-2d99cd3edb8b) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0007] IdleTracker 0xc000139c70:idle 5m+0h/5t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa0c0:new 5m+0h/5t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa0c0:active 5m+0h/6t connection(s) 
INFO[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(1e79aed4-813d-45cd-8f87-b25c067eae25) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0007] IdleTracker 0xc0007aa0c0:idle 6m+0h/6t connection(s) 
DEBU[0007] IdleTracker 0xc000135410:new 6m+0h/6t connection(s) 
DEBU[0007] IdleTracker 0xc000135410:active 6m+0h/7t connection(s) 
INFO[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(ee692a67-7278-4871-8da6-a292e2b6ae15) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0007] IdleTracker 0xc000135410:idle 7m+0h/7t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa0c0:active 7m+0h/7t connection(s) 
INFO[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(73e3fa54-fe1e-42b4-a17e-a227a324f08d) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0007] IdleTracker 0xc0007aa0c0:idle 7m+0h/7t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa258:new 7m+0h/7t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa258:active 7m+0h/8t connection(s) 
INFO[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- GET /v1.40/images/nginx:latest/json BEGIN 
DEBU[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- Header: Connection=[keep-alive] 
DEBU[0007] Looking up image "nginx:latest" in local containers storage 
DEBU[0007] Trying "nginx:latest" ...                    
DEBU[0007] Trying "localhost/nginx:latest" ...          
DEBU[0007] Trying "docker.io/library/nginx:latest" ...  
DEBU[0007] parsed reference into "[overlay@/home/networkexception/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs]@4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] Found image "nginx:latest" as "docker.io/library/nginx:latest" in local containers storage 
DEBU[0007] Inspecting image 4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] APIHandler(79af8f5a-cd22-49eb-b1c9-a735564efd33) -- GET /v1.40/images/nginx:latest/json END 
DEBU[0007] IdleTracker 0xc0007aa258:idle 8m+0h/8t connection(s) 
DEBU[0007] IdleTracker 0xc000135410:active 8m+0h/8t connection(s) 
INFO[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(708a2805-d0b9-420f-8e62-8cb545e2c205) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dpodman%22%2C+%22com.docker.compose.service%3Dnginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0007] IdleTracker 0xc000135410:idle 8m+0h/8t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa258:active 8m+0h/8t connection(s) 
INFO[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- GET /v1.40/images/nginx:latest/json BEGIN 
DEBU[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- Header: Connection=[keep-alive] 
DEBU[0007] Looking up image "nginx:latest" in local containers storage 
DEBU[0007] Trying "nginx:latest" ...                    
DEBU[0007] Trying "localhost/nginx:latest" ...          
DEBU[0007] Trying "docker.io/library/nginx:latest" ...  
DEBU[0007] parsed reference into "[overlay@/home/networkexception/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs]@4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] Found image "nginx:latest" as "docker.io/library/nginx:latest" in local containers storage 
DEBU[0007] Inspecting image 4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] exporting opaque data as blob "sha256:4f380adfc10f4cd34f775ae57a17d2835385efd5251d6dfe0f246b0018fb0399" 
DEBU[0007] APIHandler(3af20239-f590-45d2-a620-3eb1076de9bc) -- GET /v1.40/images/nginx:latest/json END 
DEBU[0007] IdleTracker 0xc0007aa258:idle 8m+0h/8t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa0c0:active 8m+0h/8t connection(s) 
INFO[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json BEGIN 
DEBU[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(9c9413dc-a3a5-49e3-bb73-75e1ecc8464a) -- GET /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/json END 
DEBU[0007] IdleTracker 0xc0007aa0c0:idle 8m+0h/8t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa228:new 8m+0h/8t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa228:active 8m+0h/9t connection(s) 
INFO[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- POST /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/stop?t=10 BEGIN 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.0 Linux/5.4.0-71-generic] 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- Header: Accept=[*/*] 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- Header: Connection=[keep-alive] 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- Header: Content-Length=[0] 
DEBU[0007] Starting parallel job on container 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 
INFO[0007] Request Failed(Internal Server Error): can only stop created or running containers. 062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575 is in state configured: container state improper 
DEBU[0007] APIHandler(bc8c2a25-5894-4357-be5b-2c9a953749db) -- POST /v1.40/containers/062cac6d9f927546c299ff52ecfab1391ea9821a6a29d2f3ac66667f40a25575/stop?t=10 END 
DEBU[0007] IdleTracker 0xc0007aa228:idle 9m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc000138fb8:closed 9m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa228:closed 8m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc00043a028:closed 7m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc00043a148:closed 6m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa258:closed 5m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc000135410:closed 4m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa0c0:closed 3m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc000139c70:closed 2m+0h/9t connection(s) 
DEBU[0007] IdleTracker 0xc0007aa8d0:closed 1m+0h/9t connection(s)

@Luap99
Copy link
Member

Luap99 commented Jul 5, 2021

Can you try podman network create testnet && podman run --rm --network testnet alpine ip a

@networkException
Copy link
Author

That prints the following

/home/networkexception/.config/cni/net.d/testnet.conflist
Resolved "alpine" as an alias (/etc/containers/registries.conf.d/000-shortnames.conf)
Trying to pull docker.io/library/alpine:latest...
Getting image source signatures
Copying blob 5843afab3874 done  
Copying config d4ff818577 done  
Writing manifest to image destination
Storing signatures

but does not terminate. Also htop shows similar CPU usage to what I observed in the beginning (just the command of the processes is podman run --rm --network testnet alpine ip a instead of /usr/bin/podman --log-level=info system service)

@Luap99
Copy link
Member

Luap99 commented Jul 5, 2021

OK, so there is an infinity loop somewhere. Do you know if this worked with 3.2.1?

@Luap99
Copy link
Member

Luap99 commented Jul 5, 2021

I found the bug, as a workaround please create the /var/lib/cni directory. This should make it work for now.

@Luap99 Luap99 self-assigned this Jul 5, 2021
@networkException
Copy link
Author

I just compiled 3.2.1 from source and #10857 (comment) works

@networkException
Copy link
Author

After creating the /var/lib/cni directory the command from #10857 (comment) also works in 3.2.2, however docker-compose still errors on both versions with this error #10857 (comment)

@Luap99
Copy link
Member

Luap99 commented Jul 5, 2021

I think you have to remove the container manually with podman rm -f <NAME> as it is stuck in a wrong state due to the bug.

@networkException
Copy link
Author

oh I see, thank you that worked 🎉

@Luap99 Luap99 mentioned this issue Jul 6, 2021
Merged
Luap99 added a commit to Luap99/libpod that referenced this issue Jul 6, 2021
@Luap99
Make rootless-cni setup more robust
2c7c679 
The rootless cni namespace needs a valid /etc/resolv.conf file. On some
distros is a symlink to somewhere under /run. Because the kernel will
follow the symlink before mounting, it is not possible to mount a file
at exactly /etc/resolv.conf. We have to ensure that the link target will
be available in the rootless cni mount ns.

Fixes containers#10855

Also fixed a bug in the /var/lib/cni directory lookup logic. It used
`filepath.Base` instead of `filepath.Dir` and thus looping infinitely.

Fixes containers#10857

[NO TESTS NEEDED]

Signed-off-by: Paul Holzinger <[email protected]>
Luap99 added a commit to Luap99/libpod that referenced this issue Jul 15, 2021
@Luap99
Make rootless-cni setup more robust
1469af2 
The rootless cni namespace needs a valid /etc/resolv.conf file. On some
distros is a symlink to somewhere under /run. Because the kernel will
follow the symlink before mounting, it is not possible to mount a file
at exactly /etc/resolv.conf. We have to ensure that the link target will
be available in the rootless cni mount ns.

Fixes containers#10855

Also fixed a bug in the /var/lib/cni directory lookup logic. It used
`filepath.Base` instead of `filepath.Dir` and thus looping infinitely.

Fixes containers#10857

[NO TESTS NEEDED]

Signed-off-by: Paul Holzinger <[email protected]>
@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Sep 21, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 21, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@Luap99 Luap99

Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Make rootless-cni setup more robust Luap99/libpod
2 participants
@networkException @Luap99