podman network rm: blocks previously-used ports #10806

edsantiago · 2021-06-28T21:18:33Z

This one has plagued me for months but I knew it would be a pain to track down. Here it is (DO NOT TRY THIS ON YOUR LAPTOP UNLESS YOU WANT TO REBOOT):

# port=55557       # <--- bump this up as needed, for subsequent iterations of the test, because once this port is used it's gone forever
# podman network create --subnet 192.168.240.0/24 nnn
/etc/cni/net.d/nnn.conflist
# podman run -d --name ccc --network nnn -p 127.0.0.1:$port:$port  quay.io/libpod/testimage:20210427 nc -l -n -v -p $port
8e3463fe803fffbfce9165ec05a2ba5d8ee17ddb7a95ebe034f6a41189d44988
# echo hi | nc 127.0.0.1 $port
# podman rm ccc
ccc
# echo hi | nc 127.0.0.1 $port
Ncat: Connection refused.       <--- this is as expected
# podman network rm nnn
nnn
# echo hi | nc 127.0.0.1 $port
Ncat: TIMEOUT.                  <--- THIS IS NOT NORMAL. THIS IS REALLY BAD.

That is: once the container stops, connecting to the port fails with ECONNREFUSED, which is the proper thing to do. But after running podman network rm, the previously-used port somehow becomes busy and completely unusable. It remains unusable forever or until the next reboot, whichever comes first.

Root only, both local and remote. Everything works perfectly fine when rootless.

OBTW netstat --inet -n | grep 555 does not show the port in use.

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

Luap99 · 2021-06-29T12:41:18Z

I cannot reproduce, does it happens always? Can you share more details about your environment.

edsantiago · 2021-06-29T12:45:07Z

I was afraid of that. Can you try with podman-remote?

# podman system service --timeout=0 &> /tmp/foo.log&
...
...and s/podman/podman-remote/ in all of the above

I initially only saw it in podman-remote, but decided to test with plain podman, and saw it happening there too so I changed my report. But maybe the fact that I had used podman-remote got the system screwed up in such a way that even plain podman caused the error.

Luap99 · 2021-06-29T13:51:21Z

Still no luck, can you check if you see errors in the journal. Also iptables -t nat -nvL would be helpful.

edsantiago · 2021-06-29T14:01:23Z

# journalctl -b 0
...
Jun 29 09:57:31 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com podman[4970]: 2021-06-29 09:57:31.19812397 -0400 EDT m=+35.823724698 container init 9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3 (image=quay.io/libpod/testimage:20210427, name=ccc, io.buildah.version=1.20.1, created_at=2021-04-27T20:53:39Z, created_by=test/system/build-testimage)
Jun 29 09:57:31 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com podman[4970]: 2021-06-29 09:57:31.2079887 -0400 EDT m=+35.833589437 container start 9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3 (image=quay.io/libpod/testimage:20210427, name=ccc, created_at=2021-04-27T20:53:39Z, created_by=test/system/build-testimage, io.buildah.version=1.20.1)
Jun 29 09:57:32 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975052.5748] policy: set-hostname: current hostname was changed outside NetworkManager: 'ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com'
Jun 29 09:57:37 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: libpod-9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3.scope: Deactivated successfully.
Jun 29 09:57:37 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com podman[5194]: 2021-06-29 09:57:37.827262403 -0400 EDT m=+0.061563494 container died 9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3 (image=quay.io/libpod/testimage:20210427, name=ccc)
Jun 29 09:57:38 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com podman[5194]: 2021-06-29 09:57:38.148993943 -0400 EDT m=+0.383295116 container cleanup 9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3 (image=quay.io/libpod/testimage:20210427, name=ccc, created_at=2021-04-27T20:53:39Z, created_by=test/system/build-testimage, io.buildah.version=1.20.1)
Jun 29 09:57:38 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: libpod-conmon-9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3.scope: Deactivated successfully.
Jun 29 09:57:40 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Jun 29 09:57:40 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 29 09:57:43 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com podman[5256]: 2021-06-29 09:57:43.921185028 -0400 EDT m=+0.082237566 container remove 9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3 (image=quay.io/libpod/testimage:20210427, name=ccc, io.buildah.version=1.20.1, created_at=2021-04-27T20:53:39Z, created_by=test/system/build-testimage)
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com kernel: device vethbdb11bfc left promiscuous mode
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com kernel: cni-podman1: port 1(vethbdb11bfc) entered disabled state
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com audit: ANOM_PROMISCUOUS dev=vethbdb11bfc prom=0 old_prom=256 auid=0 uid=0 gid=0 ses=3
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975084.9713] policy: set-hostname: current hostname was changed outside NetworkManager: 'ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com'
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975084.9723] policy: set-hostname: current hostname was changed outside NetworkManager: 'ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com'
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975084.9761] device (cni-podman1): state change: activated -> unmanaged (reason 'unmanaged', sys-iface-state: 'removed')
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975084.9828] policy: set-hostname: current hostname was changed outside NetworkManager: 'ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com'
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: Starting Network Manager Script Dispatcher Service...
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com NetworkManager[476]: <info>  [1624975084.9935] policy: set-hostname: current hostname was changed outside NetworkManager: 'ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com'
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: Started Network Manager Script Dispatcher Service.
Jun 29 09:58:04 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 29 09:58:14 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Jun 29 09:58:14 ci-vm-10-0-138-127.hosted.upshift.rdu2.redhat.com audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

# iptables -t nat -nvL
Chain PREROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    0     0 CNI-HOSTPORT-DNAT  all  --  *      *       0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    6   360 CNI-HOSTPORT-DNAT  all  --  *      *       0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    7   492 CNI-HOSTPORT-MASQ  all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* CNI portfwd requiring masquerade */
    0     0 CNI-d24a60b7369e92d5454662cf  all  --  *      *       192.168.240.2        0.0.0.0/0            /* name: "nnn" id: "9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3" */

Chain CNI-DN-d24a60b7369e92d545466 (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 CNI-HOSTPORT-SETMARK  tcp  --  *      *       192.168.240.0/24     127.0.0.1            tcp dpt:55557
    6   360 CNI-HOSTPORT-SETMARK  tcp  --  *      *       127.0.0.1            127.0.0.1            tcp dpt:55557
    6   360 DNAT       tcp  --  *      *       0.0.0.0/0            127.0.0.1            tcp dpt:55557 to:192.168.240.2:55557

Chain CNI-HOSTPORT-DNAT (2 references)
 pkts bytes target     prot opt in     out     source               destination
    6   360 CNI-DN-d24a60b7369e92d545466  tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            /* dnat name: "nnn" id: "9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3" */ multiport dports 55557

Chain CNI-HOSTPORT-MASQ (1 references)
 pkts bytes target     prot opt in     out     source               destination
    2   120 MASQUERADE  all  --  *      *       0.0.0.0/0            0.0.0.0/0            mark match 0x2000/0x2000

Chain CNI-HOSTPORT-SETMARK (2 references)
 pkts bytes target     prot opt in     out     source               destination
    6   360 MARK       all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* CNI portfwd masquerade mark */ MARK or 0x2000

Chain CNI-d24a60b7369e92d5454662cf (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 ACCEPT     all  --  *      *       0.0.0.0/0            192.168.240.0/24     /* name: "nnn" id: "9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3" */
    0     0 MASQUERADE  all  --  *      *       0.0.0.0/0           !224.0.0.0/4          /* name: "nnn" id: "9005e6319a2c1213030063896666463267e8c8b7604a6f174c81582b25b3eaf3" */

edsantiago · 2021-06-29T14:02:58Z

VM available if you want it (for next few hours, say until 2000 CET). Ping me (esm) on Libera or internal IRC for access details.

Luap99 · 2021-06-29T16:08:48Z

I don't have time today but I would like to take a look at it later this week.

mheon · 2021-06-29T17:49:50Z

This looks like more of a podman rm issue - the iptables rules should have been torn down when the container was removed? Why would we expect them to last longer than that?

stewartadam · 2021-07-08T03:46:02Z

This likely explains what I recently discovered was going on with my podman containers that intermittently caused some of their port mappings to fail with 'No route to host' when trying to curl http://localhost:XYZ against a forwarded port. After lots and lots of debugging I came to the same conclusion as above -- iptables rules lingered after container removal that caused subsequent deployments using that port mapping to fail.

I haven't been able to find a consistent repro yet, but seemed to happen pretty quickly when I was using docker-compose against podman.socket (rootful) to spin up and down a bunch of containers repeatedly as I was testing my network setup.

stewartadam · 2021-07-08T04:04:41Z

Perhaps duplicate of #10745, affecting rootful containers and named networks?

Luap99 · 2021-07-08T07:49:29Z

Perhaps duplicate of #10745, affecting rootful containers and named networks?

It could be related but I don't think so. I doubt that systemd is setting XDG_RUNTIME_DIR=/run/user/0 for the podman service.

edsantiago · 2021-08-05T16:48:38Z

I am able to reproduce this on a freshly-booted 1minutetip VM. f34. podman-3.3.0-0.2.rc1.fc34.x86_64 5.12.10-300.fc34

# iptables -t nat -nvL
Chain PREROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    0     0 CNI-HOSTPORT-DNAT  all  --  *      *       0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    6   360 CNI-HOSTPORT-DNAT  all  --  *      *       0.0.0.0/0            0.0.0.0/0            ADDRTYPE match dst-type LOCAL

Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
    8   568 CNI-HOSTPORT-MASQ  all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* CNI portfwd requiring masquerade */
    0     0 CNI-0acdcfaa03ae3de9fd1263d1  all  --  *      *       192.168.240.2        0.0.0.0/0            /* name: "nnn" id: "bf9dfd27d2965438a194df9093fbe98feae0ca45c58a3ac197c080fa155694c9" */

Chain CNI-0acdcfaa03ae3de9fd1263d1 (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 ACCEPT     all  --  *      *       0.0.0.0/0            192.168.240.0/24     /* name: "nnn" id: "bf9dfd27d2965438a194df9093fbe98feae0ca45c58a3ac197c080fa155694c9" */
    0     0 MASQUERADE  all  --  *      *       0.0.0.0/0           !224.0.0.0/4          /* name: "nnn" id: "bf9dfd27d2965438a194df9093fbe98feae0ca45c58a3ac197c080fa155694c9" */

Chain CNI-DN-0acdcfaa03ae3de9fd126 (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 CNI-HOSTPORT-SETMARK  tcp  --  *      *       192.168.240.0/24     127.0.0.1            tcp dpt:55557
    6   360 CNI-HOSTPORT-SETMARK  tcp  --  *      *       127.0.0.1            127.0.0.1            tcp dpt:55557
    6   360 DNAT       tcp  --  *      *       0.0.0.0/0            127.0.0.1            tcp dpt:55557 to:192.168.240.2:55557

Chain CNI-HOSTPORT-DNAT (2 references)
 pkts bytes target     prot opt in     out     source               destination
    6   360 CNI-DN-0acdcfaa03ae3de9fd126  tcp  --  *      *       0.0.0.0/0            0.0.0.0/0            /* dnat name: "nnn" id: "bf9dfd27d2965438a194df9093fbe98feae0ca45c58a3ac197c080fa155694c9" */ multiport dports 55557

Chain CNI-HOSTPORT-MASQ (1 references)
 pkts bytes target     prot opt in     out     source               destination
    2   120 MASQUERADE  all  --  *      *       0.0.0.0/0            0.0.0.0/0            mark match 0x2000/0x2000

Chain CNI-HOSTPORT-SETMARK (2 references)
 pkts bytes target     prot opt in     out     source               destination
    6   360 MARK       all  --  *      *       0.0.0.0/0            0.0.0.0/0            /* CNI portfwd masquerade mark */ MARK or 0x2000

Run as root. No podman-remote has ever been run on this vm.

edsantiago · 2021-08-05T16:49:50Z

And, FWIW, I see this on every system-test run I do, and I've been doing a lot of them lately for the spate of recent releases.

stewartadam · 2021-08-09T20:42:31Z

Per #10886 whatever is adjusting the iptables rules should really adopt a naming scheme or use the comment module to label its commands, so podman can effectively cleanup or overwrite leftover rules as necessary, instead of leaving clutter in the iptables chains.

Luap99 · 2021-08-10T12:48:20Z

And, FWIW, I see this on every system-test run I do, and I've been doing a lot of them lately for the spate of recent releases.

@edsantiago So you just run PODMAN=./bin/podman bats ./test/system/ and the system test succeeded but the iptables rules are still there?

edsantiago · 2021-08-10T12:57:19Z

I haven't run a before/after comparison of iptables rules. I'm just reporting that, after running the test, that port is forever gone.

Luap99 · 2021-08-10T13:24:45Z

OK, I think I know the problem. Can you confim that XDG_RUNTIME_DIR is set to /run/user/0 when you run the tests? If so can you unset XDG_RUNTIME_DIR and try if it now works correctly.

edsantiago · 2021-08-10T13:51:46Z

Confirmed: by default, on login on a 1minutetip f34 VM:

# env|grep XDG
XDG_SESSION_TYPE=tty
XDG_SESSION_CLASS=user
XDG_SESSION_ID=4
XDG_RUNTIME_DIR=/run/user/0

If I unset XDG_RUNTIME_DIR before running the first command in the reproducer, the final nc fails with ECONNREFUSED (good) instead of timeout.

According to the cni spec[1], a plugin should not return an error on del. If a plugin returns an error cni will not call the following plugins. Since the plugins are invoked in reverse order on del, the portmapping and bridge plugins won't get invoked and therefore leave iptables rules around. Fixes containers#67 Fixes containers/podman#10806 Fixes containers/podman#10745 [1] https://github.com/containernetworking/cni/blob/master/SPEC.md#del-remove-container-from-network-or-un-apply-modifications Signed-off-by: Paul Holzinger <[email protected]>

Depending how the user logs in to the root account, XDG_RUNTIME_DIR is set to /run/user/0 or it is unset. For conmon we already set it always to an empty string. The inconsistency is causing issues for the dnsname plugin. To fix it unset XDG_RUNTIME_DIR for the podman process. [NO TESTS NEEDED] Fixes containers#10806 Fixes containers#10745 Signed-off-by: Paul Holzinger <[email protected]>

One test was using a hardcoded fixed port, with a comment referring to containers#10806. That issue seems fixed, so let's try switching to a pseudorandom open port. Does not actually fix containers#16289 but I'm going to close that anyway, will reopen if it recurs. Signed-off-by: Ed Santiago <[email protected]>

stewartadam mentioned this issue Jul 9, 2021

podman system reset should reset the configuration for plugins it uses #10886

Closed

Luap99 self-assigned this Aug 10, 2021

Luap99 added In Progress This issue is actively being worked by the assignee, please do not work on this at this time. kind/bug Categorizes issue or PR as related to a bug. labels Aug 10, 2021

Luap99 mentioned this issue Aug 11, 2021

rootful: unset XDG_RUNTIME_DIR #11195

Merged

Luap99 mentioned this issue Aug 11, 2021

Do not error on del command containers/dnsname#73

Merged

openshift-ci bot closed this as completed in containers/dnsname#73 Aug 11, 2021

Luap99 mentioned this issue Oct 25, 2022

network create test: rootless: bind: address already in use #16289

Closed

edsantiago mentioned this issue Oct 25, 2022

system tests: podman network create: use random port #16293

Merged

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 bot locked as resolved and limited conversation to collaborators Sep 21, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

podman network rm: blocks previously-used ports #10806

podman network rm: blocks previously-used ports #10806

edsantiago commented Jun 28, 2021 •

edited

Loading

Luap99 commented Jun 29, 2021

edsantiago commented Jun 29, 2021

Luap99 commented Jun 29, 2021

edsantiago commented Jun 29, 2021

edsantiago commented Jun 29, 2021

Luap99 commented Jun 29, 2021

mheon commented Jun 29, 2021

stewartadam commented Jul 8, 2021

stewartadam commented Jul 8, 2021

Luap99 commented Jul 8, 2021

edsantiago commented Aug 5, 2021

edsantiago commented Aug 5, 2021

stewartadam commented Aug 9, 2021

Luap99 commented Aug 10, 2021

edsantiago commented Aug 10, 2021

Luap99 commented Aug 10, 2021

edsantiago commented Aug 10, 2021

podman network rm: blocks previously-used ports #10806

podman network rm: blocks previously-used ports #10806

Comments

edsantiago commented Jun 28, 2021 • edited Loading

Luap99 commented Jun 29, 2021

edsantiago commented Jun 29, 2021

Luap99 commented Jun 29, 2021

edsantiago commented Jun 29, 2021

edsantiago commented Jun 29, 2021

Luap99 commented Jun 29, 2021

mheon commented Jun 29, 2021

stewartadam commented Jul 8, 2021

stewartadam commented Jul 8, 2021

Luap99 commented Jul 8, 2021

edsantiago commented Aug 5, 2021

edsantiago commented Aug 5, 2021

stewartadam commented Aug 9, 2021

Luap99 commented Aug 10, 2021

edsantiago commented Aug 10, 2021

Luap99 commented Aug 10, 2021

edsantiago commented Aug 10, 2021

edsantiago commented Jun 28, 2021 •

edited

Loading