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 cannot start containers with static ip addresses with Podman as a backend #11493

Closed
pclass-sensonix opened this issue Sep 8, 2021 · 30 comments
Closed

Docker-Compose cannot start containers with static ip addresses with Podman as a backend #11493

pclass-sensonix opened this issue Sep 8, 2021 · 30 comments
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. stale-issue

Comments

@pclass-sensonix
Copy link

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

I am using Podman and Docker-Compose to start a docker-compose.yml container environment on an embedded Linux device with static ip addresses assigned to each container in the environment with the following syntax:

networks:
      company_internal_net:
        ipv4_address: "10.89.0.2"

If I do not use static ip addresses for each of the 3 containers in the yml file, Podman correctly starts the environment and it works as expected.

When I attempt to start the environment with static ip addresses in the yml file, I get the following errors and the environment fails to start:

From podman system service logs:

ERRO[0071] error loading cached network config: network "docker-compose_company_internal_net" not found in CNI cache

From docker-compose output:

ERROR: for app1  error preparing container c9ca5a02ca80c7e2add55645502ebf9fd18e94dd17cc486acdcd0366708d1e33 for attach: error configuring network namespace for container c9ca5a02ca80c7e2add55645502ebf9fd18e94dd17cc486acdcd0366708d1e33: error adding pod app1_app1 to CNI network "docker-compose_company_internal_net": failed to allocate all requested IPs: 10.89.0.2

The only workaround I have found so far is to manually delete the CNI-created last_reserved_ip.0 and 10.89.0.x files between multiple attempts to bring up the environment:

root@device:/persistent-storage/docker-compose# for retry in 1 2 3; \
> do (/usr/bin/docker-compose --ansi never -f ./docker-compose.yml up ; \
> cd /var/lib/cni/networks/docker-compose_company_internal_net/ ; \
> rm -rf last_reserved_ip.0 10.89.0.* 2>/dev/null || true); \
> done

I have tried many different methods of cleaning the 'CNI Cache'. None of the following commands remedy the error:

rm -rf /var/lib/cni/networks/docker-compose_company_internal_net*/
rm -rf /var/lib/cni/results/docker-compose_company_internal_net*
rm -rf /etc/cni/net.d/docker-compose_company_internal_net*
rm -rf /container-storage/etc/cni/net.d/docker-compose_company_internal_net*.conflist
rm -rf /run/containers/cni/dnsname/docker-compose_company_internal_net*
rm -rf /var/volatile/lib/cni/networks/docker-compose_company_internal_net*
ifconfig cni-podman0 down
ip link delete cni-podman0
ifconfig cni-podman1 down
ip link delete cni-podman1
pgrep -f dnsmasq | xargs kill -9 2>/dev/null
/usr/bin/docker-compose -f ./docker-compose.yml down
rm -rf /container-storage/containers/storage/libpod/bolt_state.db
rm -rf /container-storage/containers/storage/cache/blob-info-cache-v1.boltdb
systemctl restart podman
/usr/bin/podman network create --subnet=10.89.0.0/16 docker-compose_company_internal_net
/usr/bin/docker-compose -f ./docker-compose.yml up
/usr/bin/podman --log-level=debug system service --time=0

The docker-compose.yml file is:

version: "2.4"
services:
  app1:
    container_name: "app1"
    hostname: "app1"
    image: "company-base:1.4"
    init: true
    security_opt:
      - "seccomp=unconfined"
    tty: true
    restart: "always"
    volumes:
      - "./app1:/app"
      - "./shared_data:/shared_data"
    networks:
      company_internal_net:
        ipv4_address: "10.89.0.2"
    entrypoint:
      - "python3"
      - "/app/app.py"
    environment: {}
  app2:
    container_name: "app2"
    hostname: "app2"
    image: "company-base:1.4"
    init: true
    security_opt:
      - "seccomp=unconfined"
    tty: true
    restart: "always"
    volumes:
      - "./app2:/app"
      - "./shared_data:/shared_data"
    networks:
      company_internal_net:
        ipv4_address: "10.89.0.3"
    entrypoint:
      - "python3"
      - "/app/app.py"
    environment: {}
    depends_on:
      - "app1"
  app3:
    container_name: "app3"
    hostname: "app3"
    image: "company-base:1.4"
    init: true
    security_opt:
      - "seccomp=unconfined"
    tty: true
    restart: "always"
    volumes:
      - "./app3:/app"
      - "./shared_data:/shared_data"
    networks:
      company_internal_net:
        ipv4_address: "10.89.0.4"
    entrypoint:
      - "sh"
      - "/app/run-http-script.sh"
    environment: {}
    depends_on:
      - "app1"
      - "app2"
volumes:
  shared_data: null
networks:
  company_internal_net:
    driver: "bridge"

Steps to reproduce the issue:

Create the yaml file above and try to use docker-compose to start the environment.

You should see output such as:

Creating network "docker-compose_company_internal_net" with driver "bridge"
Creating app1 ... 
Creating app1 ... done
Creating app2 ... 
Creating app2 ... error

ERROR: for app2  error preparing container a1db0d170366652fab3d6106169f782688d43d4c0d6f452e73df67bb4800f543 for attach: error configuring network namespace for container a1db0d170366652fab3d6106169f782688d43d4c0d6f452e73df67bb4800f543: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.255.254

Describe the results you received:

The errors described above under "Description".

Describe the results you expected:

The docker-compose environment is successfully started with Podman using static IP address assignment for each container.

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

This issue happens every single time I try to start the environment with static IP addresses enabled in the docker-compose.yml file.

Output of podman version:

root@device:/persistent-storage/docker-compose# podman --version
podman version 3.3.2-dev

root@device:/persistent-storage/docker-compose# uname -r
5.4.41-linux4sam-2020.04

root@device:/persistent-storage/docker-compose# conmon --version
conmon version 2.0.29
commit: 7e6de6678f6ed8a18661e1d5721b81ccee293b9b

root@device:/persistent-storage/docker-compose# /usr/bin/docker-compose --version
docker-compose version 1.29.2, build unknown

root@device:/persistent-storage/docker-compose# crun --version
crun version 1.0.10-1453a
commit: 1453a0edd690fc34d0bc829b194a55f11245be9b
spec: 1.0.0
+SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +YAJL

Output of podman info --debug:

root@scompany:/persistent-storage/docker-compose# podman info --debug
host:
  arch: arm
  buildahVersion: 1.22.3
  cgroupControllers:
  - cpu
  - io
  - memory
  - pids
  - rdma
  cgroupManager: cgroupfs
  cgroupVersion: v2
  conmon:
    package: Unknown
    path: /usr/bin/conmon
    version: 'conmon version 2.0.29, commit: 7e6de6678f6ed8a18661e1d5721b81ccee293b9b'
  cpus: 1
  distribution:
    distribution: poky-atmel
    version: 3.1.3
  eventLogger: journald
  hostname: scompany
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 5.4.41-linux4sam-2020.04
  linkmode: dynamic
  memFree: 65867776
  memTotal: 254709760
  ociRuntime:
    name: crun
    package: Unknown
    path: /usr/bin/crun
    version: |-
      crun version 1.0.10-1453a
      commit: 1453a0edd690fc34d0bc829b194a55f11245be9b
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +YAJL
  os: linux
  remoteSocket:
    exists: true
    path: /run/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: false
    seccompEnabled: false
    seccompProfilePath: ""
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: Unknown
    version: |-
      slirp4netns version 0.4.1
      commit: unknown
  swapFree: 215740416
  swapTotal: 251654144
  uptime: 47m 15.4s
registries:
  search:
  - docker.io
  - registry.fedoraproject.org
  - quay.io
  - registry.access.redhat.com
  - registry.centos.org
store:
  configFile: /etc/containers/storage.conf
  containerStore:
    number: 2
    paused: 0
    running: 0
    stopped: 2
  graphDriverName: overlay
  graphOptions:
    overlay.mountopt: nodev
  graphRoot: /container-storage/containers/storage
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Using metacopy: "false"
  imageStore:
    number: 9
  runRoot: /container-storage/containers/storage
  volumePath: /container-storage/containers/storage/volumes
version:
  APIVersion: 3.3.2-dev
  Built: 1630355671
  BuiltTime: Mon Aug 30 20:34:31 2021
  GitCommit: 364efce396d0b0f73935cfacd0b95e639afe86bc-dirty
  GoVersion: go1.14.7
  OsArch: linux/arm
  Version: 3.3.2-dev

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

None - this is a Yocto build. Versions are shown above under 'Output of podman version'.

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.):

Embedded Linux Yocto build for Microchip SAMA5D27 ARM device.
@mheon
Copy link
Member

mheon commented Sep 9, 2021

That error message usually pops up when the requested IP address isn't present inside of the network. I notice you're not specifying a subnet for the network you create - are you absolutely certain it's always being assigned a 10.89.0.0/24 subnet?

@pclass-sensonix
Copy link
Author

@mheon - Yes I create the docker-compose network outside of docker-compose explicitley in my systemd service file. The file shown below fails because of the error described in the bug.

[Unit]
Description=Company Docker-Compose Environment
Requires=podman.service
After=podman.service
ConditionPathExists=/persistent-storage/docker-compose/docker-compose.yml

[Service]
Environment=HOME=/home/root
Environment=COMPOSE_HTTP_TIMEOUT=600
TimeoutStartSec=600
TimeoutStopSec=600
CPUWeight=1000
MemorySwapMax=0
IOSchedulingClass=realtime
IOSchedulingPriority=0
Restart=always
WorkingDirectory=/persistent-storage/docker-compose
ExecStartPre=-/bin/sh -c "/usr/bin/podman network create --subnet=10.88.0.0/16 podman"
ExecStartPre=-/bin/sh -c "/usr/bin/podman network create --subnet=10.89.0.0/16 docker-compose_company_internal_net"
ExecStart=/bin/sh -c "/usr/bin/docker-compose --ansi never -f ./docker-compose.yml up"
ExecStop=/bin/sh -c "/usr/bin/docker-compose --ansi never -f ./docker-compose.yml down"

[Install]
WantedBy=sysinit.target

@mheon
Copy link
Member

mheon commented Sep 9, 2021

I'm fairly certain docker-compose will create the network itself - I'm not 100% sure what it does when a network exists, but I would still be a bit suspicious.

@pclass-sensonix
Copy link
Author

@mheon - Yes, docker-compose does create the network ( and remove it when stopped ). However, if I let docker-compose create it I still get the assignment bug:

Sep 09 14:30:15 gw sh[4058]: Creating network "docker-compose_company_internal_net" with driver "bridge"
Sep 09 14:30:18 gw sh[4058]: Creating app1 ...
Sep 09 14:30:33 gw sh[4058]: Creating app1 ... done
Sep 09 14:30:34 gw sh[4058]: Creating app2 ...
Sep 09 14:30:48 gw sh[4058]: Creating app2 ... error
Sep 09 14:30:48 gw sh[4058]: ERROR: for app2  error preparing container 85794f4c6e9adb2600c03ad83843bb8d709c49ddc0216398bcbac131540e4e5c for attach: error configuring network namespace for container 85794f4c6e9adb2600c03ad83843bb8d709c49ddc0216398bcbac131540e4e5c: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.255.254

@Luap99
Copy link
Member

Luap99 commented Sep 9, 2021

I think cleanup is not working, can you run the podman service with --log-level debug and share the output when you call docker-compose down.
rm -rf /var/lib/cni/networks/docker-compose_company_internal_net should make docker-compose up succeed

@pclass-sensonix
Copy link
Author

pclass-sensonix commented Sep 9, 2021 •
edited
Loading

@Luap99 - I agree, there is an issue with the cleanup.

A few issues shown in the Podman API debugging output:

INFO[0094] Request Failed(Not Found): unable to find network configuration for dockercompose_company_internal_net: network not found

time="2021-09-09T14:43:04Z" level=error msg="stat /run/user/0/containers/cni/dnsname/docker-compose_company_internal_net: no such file or directory"

Here is how I get the error to happen:

root@gw:/persistent-storage/docker-compose# podman system prune
WARNING! This will remove:
	- all stopped containers
	- all networks not used by at least one container
	- all dangling images
	- all dangling build cache

Are you sure you want to continue? [y/N] y
Deleted Containers
894513eb52ed6cefe59014b7b6b811a7a6ac57be3a8537adb8444f72fe065360
Deleted Images
Total reclaimed space: 0B
root@gw:/persistent-storage/docker-compose# /usr/bin/docker-compose -f ./docker-compose.yml up --remove-orphans --force-recreate
Recreating app1 ... done
Creating app2   ... error

ERROR: for app2  error preparing container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 for attach: error configuring network namespace for container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.255.254

ERROR: for app2  error preparing container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 for attach: error configuring network namespace for container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.255.254
ERROR: Encountered errors while bringing up the project.
root@gw:/persistent-storage/docker-compose# 
root@gw:/persistent-storage/docker-compose# 
root@gw/persistent-storage/docker-compose# /usr/bin/docker-compose -f ./docker-compose.yml down
Stopping app1 ... done
Removing app2 ... done
Removing app1 ... done
Removing network docker-compose_company_internal_net

And here is the total debugging output from the Podman API:

DEBU[0093] IdleTracker 0x2dc5970:new 0m+0h/0t connection(s) 
DEBU[0093] IdleTracker 0x2dc5970:active 0m+0h/1t connection(s) 
INFO[0093] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- GET /version BEGIN 
DEBU[0093] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0093] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0093] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- Header: Accept=[*/*] 
DEBU[0093] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- Header: Connection=[keep-alive] 
DEBU[0094] Loading registries configuration "/etc/containers/registries.conf" 
DEBU[0094] APIHandler(7cc787b4-5b0e-4e43-9fe1-e20deb186257) -- GET /version END 
DEBU[0094] IdleTracker 0x2dc5970:idle 1m+0h/1t connection(s) 
DEBU[0094] IdleTracker 0x2818cd0:new 1m+0h/1t connection(s) 
DEBU[0094] IdleTracker 0x2818cd0:active 1m+0h/2t connection(s) 
INFO[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- GET /v1.40/networks/dockercompose_company_internal_net BEGIN 
DEBU[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- Header: Accept=[*/*] 
DEBU[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- Header: Connection=[keep-alive] 
DEBU[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- Header: Accept-Encoding=[gzip, deflate] 
INFO[0094] Request Failed(Not Found): unable to find network configuration for dockercompose_company_internal_net: network not found 
DEBU[0094] APIHandler(2d745f83-b8d3-490e-bd52-aac75364a556) -- GET /v1.40/networks/dockercompose_company_internal_net END 
DEBU[0094] IdleTracker 0x2818cd0:idle 2m+0h/2t connection(s) 
DEBU[0094] IdleTracker 0x2913a00:new 2m+0h/2t connection(s) 
DEBU[0094] IdleTracker 0x2913a00:active 2m+0h/3t connection(s) 
INFO[0094] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%5D%7D BEGIN 
DEBU[0094] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0094] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0094] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- Header: Accept=[*/*] 
DEBU[0094] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- Header: Connection=[keep-alive] 
DEBU[0095] APIHandler(02007202-19cd-4ffa-bfae-09ca20f2be0c) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%5D%7D END 
DEBU[0095] IdleTracker 0x2913a00:idle 3m+0h/3t connection(s) 
DEBU[0095] IdleTracker 0x2dc4008:new 3m+0h/3t connection(s) 
DEBU[0095] IdleTracker 0x2dc4008:active 3m+0h/4t connection(s) 
INFO[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json BEGIN 
DEBU[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- Header: Accept=[*/*] 
DEBU[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- Header: Connection=[keep-alive] 
DEBU[0095] APIHandler(f0f374dd-489d-4fc6-b38b-562da0167658) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json END 
DEBU[0095] IdleTracker 0x2dc4008:idle 4m+0h/4t connection(s) 
DEBU[0095] IdleTracker 0x2e616e8:new 4m+0h/4t connection(s) 
DEBU[0095] IdleTracker 0x2e616e8:active 4m+0h/5t connection(s) 
INFO[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- POST /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/stop?t=10 BEGIN 
DEBU[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- Header: Connection=[keep-alive] 
DEBU[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- Header: Content-Length=[0] 
DEBU[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0095] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- Header: Accept=[*/*] 
DEBU[0095] Starting parallel job on container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0095] Stopping ctr bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a (timeout 10) 
DEBU[0095] Stopping container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a (PID 7051) 
DEBU[0095] Sending signal 15 to container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0096] Cleaning up container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0096] Tearing down network namespace at /run/netns/cni-e53c005b-b3fb-417d-2bb4-c8c9dea71036 for container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
INFO[0097] Got pod network &{Name:app1 Namespace:app1 ID:bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a NetNS:/run/netns/cni-e53c005b-b3fb-417d-2bb4-c8c9dea71036 Networks:[{Name:docker-compose_company_internal_net Ifname:eth0}] RuntimeConfig:map[docker-compose_company_internal_net:{IP:10.89.0.2 MAC: PortMappings:[] Bandwidth:<nil> IpRanges:[]}] Aliases:map[]} 
INFO[0097] Deleting pod app1_app1 from CNI network "docker-compose_company_internal_net" (type=bridge) 
time="2021-09-09T14:43:04Z" level=error msg="stat /run/user/0/containers/cni/dnsname/docker-compose_company_internal_net: no such file or directory"
DEBU[0100] Successfully cleaned up container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0101] unmounted container "bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a" 
DEBU[0101] APIHandler(3feb4646-87de-493d-bf0a-78f42b507c81) -- POST /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/stop?t=10 END 
DEBU[0101] IdleTracker 0x2e616e8:idle 5m+0h/5t connection(s) 
DEBU[0101] IdleTracker 0x2c48000:new 5m+0h/5t connection(s) 
DEBU[0101] IdleTracker 0x2c48000:active 5m+0h/6t connection(s) 
INFO[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- Header: Accept=[*/*] 
DEBU[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- Header: Connection=[keep-alive] 
DEBU[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0101] APIHandler(947544fe-8f5b-4a87-b83a-e0aec0077049) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0101] IdleTracker 0x2c48000:idle 6m+0h/6t connection(s) 
DEBU[0101] IdleTracker 0x2c48b58:new 6m+0h/6t connection(s) 
DEBU[0102] IdleTracker 0x2c48b58:active 6m+0h/7t connection(s) 
INFO[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddockercompose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(3019e691-4d94-467b-8128-f4c6657afbe0) -- GET /v1.40/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddockercompose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0102] IdleTracker 0x2c48b58:idle 7m+0h/7t connection(s) 
DEBU[0102] IdleTracker 0x2c493c8:new 7m+0h/7t connection(s) 
DEBU[0102] IdleTracker 0x2c493c8:active 7m+0h/8t connection(s) 
INFO[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D BEGIN 
DEBU[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0102] [graphdriver] trying provided driver "overlay" 
DEBU[0102] cached value indicated that overlay is supported 
DEBU[0102] cached value indicated that metacopy is not being used 
DEBU[0102] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=true, usingMetacopy=false 
DEBU[0102] APIHandler(34f663a9-e114-481f-8998-df7af59da711) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D END 
DEBU[0102] IdleTracker 0x2c493c8:idle 8m+0h/8t connection(s) 
DEBU[0102] IdleTracker 0x2a5ee88:new 8m+0h/8t connection(s) 
DEBU[0102] IdleTracker 0x2a5ee88:active 8m+0h/9t connection(s) 
INFO[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- GET /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9/json BEGIN 
DEBU[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(13da0d77-0648-450c-9780-8db67363fdb8) -- GET /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9/json END 
DEBU[0102] IdleTracker 0x2a5ee88:idle 9m+0h/9t connection(s) 
DEBU[0102] IdleTracker 0x2dc4008:active 9m+0h/9t connection(s) 
INFO[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json BEGIN 
DEBU[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0102] APIHandler(6a2d401c-e5c3-475e-9365-07773a1a2eb5) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json END 
DEBU[0102] IdleTracker 0x2dc4008:idle 9m+0h/9t connection(s) 
DEBU[0102] IdleTracker 0x29d6698:new 9m+0h/9t connection(s) 
DEBU[0102] IdleTracker 0x29d6698:active 9m+0h/10t connection(s) 
INFO[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%5D%7D BEGIN 
DEBU[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(84cb9fac-0813-440c-a170-166dadac8905) -- GET /v1.40/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddocker-compose%22%5D%7D END 
DEBU[0102] IdleTracker 0x29d6698:idle 10m+0h/10t connection(s) 
DEBU[0102] IdleTracker 0x2a5ee88:active 10m+0h/10t connection(s) 
INFO[0102] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- GET /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9/json BEGIN 
DEBU[0102] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0102] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- Header: Accept=[*/*] 
DEBU[0102] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- Header: Connection=[keep-alive] 
DEBU[0102] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0103] APIHandler(2f50990f-a152-4af1-a32d-8c995cab266e) -- GET /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9/json END 
DEBU[0103] IdleTracker 0x2a5ee88:idle 10m+0h/10t connection(s) 
DEBU[0103] IdleTracker 0x2dc4008:active 10m+0h/10t connection(s) 
INFO[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json BEGIN 
DEBU[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- Header: Accept=[*/*] 
DEBU[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- Header: Connection=[keep-alive] 
DEBU[0103] APIHandler(0524789d-48d6-475a-9b8a-9d1ab150ad70) -- GET /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a/json END 
DEBU[0103] IdleTracker 0x2dc4008:idle 10m+0h/10t connection(s) 
DEBU[0103] IdleTracker 0x29a1168:new 10m+0h/10t connection(s) 
DEBU[0103] IdleTracker 0x29a1168:active 10m+0h/11t connection(s) 
INFO[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- DELETE /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9?v=False&link=False&force=False BEGIN 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- Header: Accept=[*/*] 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- Header: Connection=[keep-alive] 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- Header: Content-Length=[0] 
DEBU[0103] IdleTracker 0x29a1390:new 11m+0h/11t connection(s) 
DEBU[0103] IdleTracker 0x29a1390:active 11m+0h/12t connection(s) 
INFO[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- DELETE /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a?v=False&link=False&force=False BEGIN 
DEBU[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- Header: Accept=[*/*] 
DEBU[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- Header: Connection=[keep-alive] 
DEBU[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- Header: Content-Length=[0] 
DEBU[0103] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0103] Starting parallel job on container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 
DEBU[0103] Starting parallel job on container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0103] Removing container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 
DEBU[0103] Removing all exec sessions for container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 
DEBU[0103] Cleaning up container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 
DEBU[0103] Network is already cleaned up, skipping...   
DEBU[0103] Container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 storage is already unmounted, skipping... 
DEBU[0103] Container 6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9 storage is already unmounted, skipping... 
DEBU[0103] APIHandler(de5b123d-097c-4f21-a2a2-afbd9de105a7) -- DELETE /v1.40/containers/6b7e026b234767967b7ce3c80e32fa3efe9dad1df759a0d399bb32f41198b7e9?v=False&link=False&force=False END 
DEBU[0103] Removing container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0103] IdleTracker 0x29a1168:idle 12m+0h/12t connection(s) 
DEBU[0103] Removing all exec sessions for container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0103] Cleaning up container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a 
DEBU[0104] Network is already cleaned up, skipping...   
DEBU[0104] Container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a storage is already unmounted, skipping... 
DEBU[0104] Container bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a storage is already unmounted, skipping... 
DEBU[0104] APIHandler(374103bb-bc88-4adc-b632-71bb04212174) -- DELETE /v1.40/containers/bda057643f00b85d1e7fa6a8b2dccb9a60bca7083ba566e6c70ea87fbc00357a?v=False&link=False&force=False END 
DEBU[0104] IdleTracker 0x29a1390:idle 12m+0h/12t connection(s) 
DEBU[0104] IdleTracker 0x2912350:new 12m+0h/12t connection(s) 
DEBU[0104] IdleTracker 0x2912350:active 12m+0h/13t connection(s) 
INFO[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- DELETE /v1.40/networks/docker-compose_company_internal_net BEGIN 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04] 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- Header: Accept-Encoding=[gzip, deflate] 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- Header: Accept=[*/*] 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- Header: Connection=[keep-alive] 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- Header: Content-Length=[0] 
DEBU[0104] APIHandler(31373c0f-6b22-48a5-a979-b65e33fdd88e) -- DELETE /v1.40/networks/docker-compose_company_internal_net END 
DEBU[0105] IdleTracker 0x2912350:idle 13m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2dc5970:closed 13m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2818cd0:closed 12m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2913a00:closed 11m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2e616e8:closed 10m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2c48000:closed 9m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2c48b58:closed 8m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2c493c8:closed 7m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x29d6698:closed 6m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2a5ee88:closed 5m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2dc4008:closed 4m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x29a1168:closed 3m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x29a1390:closed 2m+0h/13t connection(s) 
DEBU[0105] IdleTracker 0x2912350:closed 1m+0h/13t connection(s)

@Luap99
Copy link
Member

Luap99 commented Sep 9, 2021

Can you provide the output of /usr/libexec/cni/dnsname. I think you have to update the dnsname plugin. How is podman installed?
A workaround which could work, add Environment=XDG_RUNTIME_DIR= to the podman service unit file.

@pclass-sensonix
Copy link
Author

pclass-sensonix commented Sep 9, 2021 •
edited
Loading

Podman is installed with Yocto.

Here is the output - I grabbed the latest tagged version 2 days ago:

root@gw:/persistent-storage/docker-compose# /usr/libexec/cni/dnsname
CNI dnsname plugin
version: 1.3.1
commit: 18822f9a4fb35d1349eb256f4cd2bfd372474d84

I'll try that workaround now.

@pclass-sensonix
Copy link
Author

pclass-sensonix commented Sep 9, 2021 •
edited
Loading

I tried the workaround - unfortunately it did not work.

Error:

INFO[0941] Adding pod app2_app2 to CNI network "docker-compose_company_internal_net" (type=bridge) 
INFO[0945] Got pod network &{Name:app2 Namespace:app2 ID:151957fb2ea0770b33f1f213a5e01936308b84ea47ec4ae6294e0f1310eaf7d2 NetNS:/run/netns/cni-a1e85580-646c-8a3a-9c0e-15fd56a0b551 Networks:[{Name:docker-compose_company_internal_net Ifname:eth0}] RuntimeConfig:map[docker-compose_company_internal_net:{IP:10.89.0.3 MAC: PortMappings:[] Bandwidth:<nil> IpRanges:[]}] Aliases:map[docker-compose_company_internal_net:[app2]]} 
ERRO[0945] error loading cached network config: network "docker-compose_company_internal_net" not found in CNI cache

Here is the systemd service file I used:

[Unit]
Description=Docker-Compose Environment
Requires=podman.service
After=podman.service gateway-main-webapp.service
ConditionPathExists=/persistent-storage/docker-compose/docker-compose.yml

[Service]
Environment=HOME=/home/root
Environment=COMPOSE_HTTP_TIMEOUT=600
Environment=XDG_RUNTIME_DIR=
TimeoutStartSec=600
TimeoutStopSec=600
CPUWeight=1000
MemorySwapMax=0
IOSchedulingClass=realtime
IOSchedulingPriority=0
Restart=always
WorkingDirectory=/persistent-storage/docker-compose
ExecStart=/bin/sh -c "/usr/bin/docker-compose --ansi never -f ./docker-compose.yml up"
ExecStop=/bin/sh -c "/usr/bin/docker-compose --ansi never -f ./docker-compose.yml rm -f"

[Install]
WantedBy=sysinit.target

@Luap99
Copy link
Member

Luap99 commented Sep 9, 2021

You have to add Environment=XDG_RUNTIME_DIR= to the podman.service unit file, not your docker-compose one

@Luap99
Copy link
Member

Luap99 commented Sep 9, 2021

I also recommend to reboot before you test again to get rid of the tmpfiles.

@pclass-sensonix
Copy link
Author

I appreciate the help with this - Okay, I rebooted and tried with this service file:

[Unit]
Description=Podman API Service
Requires=podman.socket
After=podman.socket
Documentation=man:podman-system-service(1)
StartLimitIntervalSec=0

[Service]
Environment=XDG_RUNTIME_DIR=
CPUWeight=1000
Type=exec
KillMode=process
Environment=LOGGING="--log-level=debug"
ExecStart=/usr/bin/podman $LOGGING system service --time=0

Unfortunately it still fails:

root@gw:/persistent-storage/docker-compose# /usr/bin/company/docker-compose -f ./docker-compose.yml up
Creating network "docker-compose_company_internal_net" with driver "bridge"
Creating app1 ... done
Creating app2 ... error

ERROR: for app2  error preparing container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f for attach: error configuring network namespace for container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.0.254

ERROR: for app2  error preparing container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f for attach: error configuring network namespace for container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.0.254
ERROR: Encountered errors while bringing up the project.

Logs:

Sep 09 15:08:25 gw dnsmasq[1562]: using nameserver 192.168.1.1#53
Sep 09 15:08:26 gw podman[484]: time="2021-09-09T15:08:26Z" level=info msg="Got pod network &{Name:app2 Namespace:app2 ID:dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f NetNS:/run/netns/cni-6b7daef4-ee0b-92b0-c58e-415d5bb9e118 Networks:[{Name:docker-compose_company_internal_net Ifname:eth0}] RuntimeConfig:map[docker-compose_company_internal_net:{IP:10.89.0.3 MAC: PortMappings:[] Bandwidth:<nil> IpRanges:[]}] Aliases:map[docker-compose_company_internal_net:[app2]]}"
Sep 09 15:08:26 gw podman[484]: time="2021-09-09T15:08:26Z" level=error msg="error loading cached network config: network \"docker-compose_company_internal_net\" not found in CNI cache"
Sep 09 15:08:26 gw podman[484]: time="2021-09-09T15:08:26Z" level=warning msg="falling back to loading from existing plugins on disk"
Sep 09 15:08:26 gw podman[484]: time="2021-09-09T15:08:26Z" level=info msg="Deleting pod app2_app2 from CNI network \"docker-compose_company_internal_net\" (type=bridge)"
Sep 09 15:08:27 gw dnsmasq[1562]: reading /etc/resolv.conf
Sep 09 15:08:27 gw dnsmasq[1562]: using only locally-known addresses for domain dns.podman
Sep 09 15:08:27 gw dnsmasq[1562]: using nameserver 8.8.8.8#53
Sep 09 15:08:27 gw dnsmasq[1562]: using nameserver 192.168.1.1#53
Sep 09 15:08:27 gw dnsmasq[1562]: reading /etc/resolv.conf
Sep 09 15:08:27 gw dnsmasq[1562]: using only locally-known addresses for domain dns.podman
Sep 09 15:08:27 gw dnsmasq[1562]: using nameserver 8.8.8.8#53
Sep 09 15:08:27 gw dnsmasq[1562]: using nameserver 192.168.1.1#53
Sep 09 15:08:28 gw dnsmasq[1562]: reading /etc/resolv.conf
Sep 09 15:08:28 gw dnsmasq[1562]: using only locally-known addresses for domain dns.podman
Sep 09 15:08:28 gw dnsmasq[1562]: using nameserver 8.8.8.8#53
Sep 09 15:08:28 gw dnsmasq[1562]: using nameserver 192.168.1.1#53
Sep 09 15:08:28 gw dnsmasq[1562]: reading /etc/resolv.conf
Sep 09 15:08:28 gw dnsmasq[1562]: using only locally-known addresses for domain dns.podman
Sep 09 15:08:28 gw dnsmasq[1562]: using nameserver 8.8.8.8#53
Sep 09 15:08:28 gw dnsmasq[1562]: using nameserver 192.168.1.1#53
Sep 09 15:08:32 gw podman[484]: time="2021-09-09T15:08:32Z" level=debug msg="unmounted container \"dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f\""
Sep 09 15:08:32 gw podman[484]: time="2021-09-09T15:08:32Z" level=debug msg="Network is already cleaned up, skipping..."
Sep 09 15:08:32 gw podman[484]: time="2021-09-09T15:08:32Z" level=debug msg="Cleaning up container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f"
Sep 09 15:08:33 gw dnsmasq[1562]: reading /etc/resolv.conf
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="Network is already cleaned up, skipping..."
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="Container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f storage is already unmounted, skipping..."
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=info msg="Request Failed(Conflict): error preparing container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f for attach: error configuring network namespace for container dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f: error adding pod app2_app2 to CNI network \"docker-compose_company_internal_net\": failed to allocate for range 0: requested IP address 10.89.0.3 is not available in range set 10.89.0.1-10.89.0.254"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(43e24275-4e69-447e-b422-faad61f2ceef) -- POST /v1.40/containers/dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f/attach?logs=0&stdout=1&stderr=1&stream=1 END"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="IdleTracker 0x2a58328:idle 24m+1h/37t connection(s)"
Sep 09 15:08:33 gw dnsmasq[1562]: using only locally-known addresses for domain dns.podman
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="IdleTracker 0x2c735c8:active 24m+1h/37t connection(s)"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=info msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- GET /v1.40/containers/dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f/json BEGIN"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- Header: Accept=[*/*]"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- Header: Connection=[keep-alive]"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- Header: User-Agent=[docker-compose/1.29.2 docker-py/5.0.2 Linux/5.4.41-linux4sam-2020.04]"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- Header: Accept-Encoding=[gzip, deflate]"
Sep 09 15:08:33 gw podman[484]: time="2021-09-09T15:08:33Z" level=debug msg="APIHandler(7f6af85c-50cc-4547-aa85-ee84a0a06290) -- GET /v1.40/containers/dd94c86bbbd72ea2fde5c81c472631b2968cd8d955ca7f1d08b6d8b032bf511f/json END"

@Luap99
Copy link
Member

Luap99 commented Sep 10, 2021

It is very hard to debug. I would recommend to start removing stuff from your compose file? Does it fail if you only have one container with a static ip, etc...

@mheon
Copy link
Member

mheon commented Sep 10, 2021

I would also try different IPs. If they work first time but subsequently fail, we have a bug with CNI where it's not removing address leases on exit.

@pclass-sensonix
Copy link
Author

I tried the following outside of docker-compose and I can start the containers with static ip addresses, remove them, and start new instances - and they work consistently.

It seems to have to do with docker-compose interaction with the Podman API?

/usr/bin/podman network rm -f docker-compose_company_internal_net 2>/dev/null
/usr/bin/podman network create --subnet=10.89.0.0/16 docker-compose_company_internal_net
/usr/bin/podman run -it --name app1 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.2 company-base:1.4 sh
/usr/bin/podman run -it --name app2 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.3 company-base:1.4 sh
/usr/bin/podman run -it --name app3 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.4 company-base:1.4 sh

Output:

root@gw:~# /usr/bin/podman network rm -f docker-compose_company_internal_net 2>/dev/null
docker-compose_company_internal_net
root@gw:~# /usr/bin/podman network create --subnet=10.89.0.0/16 docker-compose_company_internal_net
/etc/cni/net.d/docker-compose_company_internal_net.conflist
root@gw:~# /usr/bin/podman run -it --name app1 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.2 company-base:1.4 sh
/ # ifconfig 
eth0      Link encap:Ethernet  HWaddr DA:92:88:2A:A5:AB  
          inet addr:10.89.0.2  Bcast:10.89.255.255  Mask:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:33 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:5223 (5.1 KiB)  TX bytes:42 (42.0 B)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

/ # 




root@gw:~# /usr/bin/podman run -it --name app2 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.3 company-base:1.4 sh
/ # ifconfig 
eth0      Link encap:Ethernet  HWaddr 3E:82:B8:C8:5F:B7  
          inet addr:10.89.0.3  Bcast:10.89.255.255  Mask:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:11 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:1848 (1.8 KiB)  TX bytes:42 (42.0 B)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

/ # 




root@gw:~# /usr/bin/podman run -it --name app3 --security-opt=seccomp=unconfined --network=docker-compose_company_internal_net --ip=10.89.0.4 company-base:1.4 sh
/ # ifconfig 
eth0      Link encap:Ethernet  HWaddr 3A:3D:F6:A9:56:3F  
          inet addr:10.89.0.4  Bcast:10.89.255.255  Mask:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:10 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:1806 (1.7 KiB)  TX bytes:42 (42.0 B)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

/ #

@pclass-sensonix
Copy link
Author

@mheon - I tried with different IP Addresses per your suggestion. Interestingly, the bringup failed the very first time. However, just like the initial set of IP Addresses, the very first container works, but not the second one. No container had ever used the 3 new addresses that I assigned.

root@gw:/persistent-storage/docker-compose# /usr/bin/company/docker-compose -f ./docker-compose.yml up
Creating network "docker-compose_company_internal_net" with driver "bridge"
Creating app1 ... done
Creating app2 ... error

ERROR: for app2  error preparing container d5271cff7a9b525943f72cfed123fb43ddc6cfe4c60d37f94f7b1a519aa79290 for attach: error configuring network namespace for container d5271cff7a9b525943f72cfed123fb43ddc6cfe4c60d37f94f7b1a519aa79290: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.7 is not available in range set 10.89.0.1-10.89.255.254

ERROR: for app2  error preparing container d5271cff7a9b525943f72cfed123fb43ddc6cfe4c60d37f94f7b1a519aa79290 for attach: error configuring network namespace for container d5271cff7a9b525943f72cfed123fb43ddc6cfe4c60d37f94f7b1a519aa79290: error adding pod app2_app2 to CNI network "docker-compose_company_internal_net": failed to allocate for range 0: requested IP address 10.89.0.7 is not available in range set 10.89.0.1-10.89.255.254
ERROR: Encountered errors while bringing up the project.

@pclass-sensonix
Copy link
Author

pclass-sensonix commented Sep 10, 2021 •
edited
Loading

If I have the following static addresses set in my docker-compose.yml file:

  • 10.89.0.6
  • 10.89.0.7
  • 10.89.0.8

And then run the following commands - the docker-compose environment starts up. Perhaps something is not clearing the files 10.89.0.X files that get stored in /var/lib/cni/networks/docker-compose_company_internal_net/:

 /usr/bin/docker-compose -f ./docker-compose.yml up
 rm /var/lib/cni/networks/docker-compose_company_internal_net/10.89.0.7 
 /usr/bin/docker-compose -f ./docker-compose.yml up
 ls /var/lib/cni/networks/docker-compose_company_internal_net/
 rm /var/lib/cni/networks/docker-compose_company_internal_net/10.89.0.8
 /usr/bin/docker-compose -f ./docker-compose.yml up

However, I do not need to cleanup those files outside of docker-compose - if I use the 'podman run' commands directly.

@Luap99
Copy link
Member

Luap99 commented Sep 10, 2021

So there is only one dangling ip file in this directory? It sounds like the docker compat api parses the ip wrong and all containers end up with the same thus failing when the network is setup.

@pclass-sensonix
Copy link
Author

I think that is exactly it.

@pclass-sensonix
Copy link
Author

Okay, I think this proves it. I hacked together a patch for docker-compose that just clears out those IP address files prior to creating the container and now it works as expected:

diff -Naur git/compose/service.py git.new/compose/service.py
--- git/compose/service.py	2021-09-10 14:31:23.303557000 +0000
+++ git.new/compose/service.py	2021-09-10 14:33:37.832692000 +0000
@@ -334,6 +334,15 @@
             previous_container=previous_container,
         )
 
+        # Podman Docker-Compose Compat API does not work to 
+        # cleanup CNI lease files
+        import os
+        try:
+            os.system("rm /var/lib/cni/networks/docker-compose_company_internal_net/10.89.0.*")
+        except:
+            pass
+
         if 'name' in container_options and not quiet:
             log.info("Creating %s" % container_options['name'])

@Luap99 Luap99 added the kind/bug Categorizes issue or PR as related to a bug. label Sep 12, 2021
@Luap99
Copy link
Member

Luap99 commented Sep 12, 2021

Can you try with docker-compose up -d instead of docker-compose up

@pclass-sensonix
Copy link
Author

@Luap99 - Yes, I actually did try that during testing. It still happens in detached mode.

@Luap99 Luap99 mentioned this issue Sep 23, 2021
Closed
@pclass-sensonix
Copy link
Author

Not sure if it is relevant - but the test/system/200-pod.bats file in the podman 3.3.1 source code has this line:

# Create a pod with all the desired options
    # FIXME: --ip=$ip fails:
    #      Error adding network: failed to allocate all requested IPs

@Luap99
Copy link
Member

Luap99 commented Sep 27, 2021

Not sure if it is relevant - but the test/system/200-pod.bats file in the podman 3.3.1 source code has this line:

# Create a pod with all the desired options
    # FIXME: --ip=$ip fails:
    #      Error adding network: failed to allocate all requested IPs

I don't think this is related.

@Luap99
Copy link
Member

Luap99 commented Sep 27, 2021

Any chance that you could try this with #11751?

@pclass-sensonix
Copy link
Author

@Luap99 - it looks like your branch is working!

root@gw:/# podman --version
podman version 4.0.0-dev
root@gw:/# /usr/bin/company/docker-compose -f ./docker-compose.yml ps
Name            Command             State   Ports
-------------------------------------------------
app1   python3 /app/app.py          Up ()        
app2   python3 /app/app.py          Up ()        
app3   sh /app/run-http-script.sh   Up ()

@Luap99
Copy link
Member

Luap99 commented Sep 28, 2021

OK, just to confirm could you try with the main branch and check if this fails? I just want to be sure that my PR fixed it and not some other change since v3.3.

@pclass-sensonix
Copy link
Author

Yes, I can try that. Yesterday afternoon it did fail with the latest in Tag v3.4.0-rc2.

@github-actions
Copy link

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Oct 29, 2021

I believe this is fixed, since we have not heard back. Reopen if I am mistaken.

@rhatdan rhatdan closed this as completed Oct 29, 2021
@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
No one assigned
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. stale-issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rhatdan @mheon @Luap99 @pclass-sensonix