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.

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

rawhide: MAC address changed after podman network reload #9720

Closed
edsantiago opened this issue Mar 15, 2021 · 19 comments
Closed

rawhide: MAC address changed after podman network reload #9720

edsantiago opened this issue Mar 15, 2021 · 19 comments
Labels
locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Comments

@edsantiago
Copy link
Member

podman gating tests regularly failing on rawhide with:

not ok 159 podman network reload
# (from function `is' in file ./helpers.bash, line 411,
#  in test file ./500-networking.bats, line 201)
#   `is "$output" "$mac" "MAC address changed after podman network reload"' failed with status 124
# # podman rm --all --force
# # podman ps --all --external --format {{.ID}} {{.Names}}
# # podman images --all --format {{.Repository}}:{{.Tag}} {{.ID}}
# quay.io/libpod/testimage:20210223 4abe85964f5c
# # podman run -d --name myweb -p 12345:80 -v /tmp/podman_bats.wxyZIQ/hello.txt:/var/www/index.txt -w /var/www quay.io/libpod/testimage:20210223 /bin/busybox-extras httpd -f -p 80
# f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4
# # podman inspect f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4 --format {{.NetworkSettings.IPAddress}}
# 10.88.0.205
# # podman inspect f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4 --format {{.NetworkSettings.MacAddress}}
# 3e:9e:0c:47:2d:7e
# # podman network reload f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4
# f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4
# # podman inspect f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4 --format {{.NetworkSettings.IPAddress}}
# 10.88.0.205
# # podman inspect f389693aa841d7c8043dc85c4797421d0e55b6f2bea4d8f703e506875ad5c5c4 --format {{.NetworkSettings.MacAddress}}
# e6:fa:fb:68:81:eb
# #/vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
# #|     FAIL: MAC address changed after podman network reload
# #| expected: '3e:9e:0c:47:2d:7e'
# #|   actual: 'e6:fa:fb:68:81:eb'
# #\^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
@Luap99
Copy link
Member

Luap99 commented Mar 15, 2021

Can you add --log-level debug to the podman network reload command? This contains useful information to see if this is a problem with podman or the cni plugins.

@edsantiago
Copy link
Member Author

 ✗ podman network reload
   (from function `is' in file /usr/share/podman/test/system/helpers.bash, line 406,
    in test file /usr/share/podman/test/system/500-networking.bats, line 201)
     `is "$output" "$mac" "MAC address changed after podman network reload"' failed with status 124
   # podman rm --all --force
   # podman ps --all --external --format {{.ID}} {{.Names}}
   # podman images --all --format {{.Repository}}:{{.Tag}} {{.ID}}
   quay.io/libpod/testimage:20200929 766ff5a3a7e4
   # podman run -d --name myweb -p 12345:80 -v /tmp/podman_bats.3FPoqn/hello.txt:/var/www/index.txt -w /var/www quay.io/libpod/testimage:20200929 /bin/busybox-extras httpd -f -p 80
   5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0
   # podman inspect 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 --format {{.NetworkSettings.IPAddress}}
   10.88.0.7
   # podman inspect 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 --format {{.NetworkSettings.MacAddress}}
   9a:87:c9:40:c8:a8
   # podman --log-level=debug network reload 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0
   time="2021-03-16T08:29:45-04:00" level=info msg="podman filtering at log level debug"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Called reload.PersistentPreRunE(podman --log-level=debug network reload 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0)"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Reading configuration file \"/usr/share/containers/containers.conf\""
   time="2021-03-16T08:29:45-04:00" level=debug msg="Merged system config \"/usr/share/containers/containers.conf\": &{Containers:{Devices:[] Volumes:[] ApparmorProfile:containers-default-0.34.3-dev Annotations:[] CgroupNS:private Cgroups:enabled DefaultCapabilities:[CHOWN DAC_OVERRIDE FOWNER FSETID KILL NET_BIND_SERVICE SETFCAP SETGID SETPCAP SETUID SYS_CHROOT] DefaultSysctls:[net.ipv4.ping_group_range=0 0] DefaultUlimits:[nproc=4194304:4194304] DefaultMountsFile: DNSServers:[] DNSOptions:[] DNSSearches:[] EnableKeyring:true EnableLabeling:true Env:[PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin TERM=xterm] EnvHost:false HTTPProxy:true Init:false InitPath: IPCNS:private LogDriver:k8s-file LogSizeMax:-1 NetNS:bridge NoHosts:false PidsLimit:2048 PidNS:private SeccompProfile:/usr/share/containers/seccomp.json ShmSize:65536k TZ: Umask:0022 UTSNS:private UserNS:host UserNSSize:65536} Engine:{CgroupCheck:false CgroupManager:systemd ConmonEnvVars:[PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin] ConmonPath:[/usr/libexec/podman/conmon /usr/local/libexec/podman/conmon /usr/local/lib/podman/conmon /usr/bin/conmon /usr/sbin/conmon /usr/local/bin/conmon /usr/local/sbin/conmon /run/current-system/sw/bin/conmon] DetachKeys:ctrl-p,ctrl-q EnablePortReservation:true Env:[] EventsLogFilePath:/run/libpod/events/events.log EventsLogger:journald HooksDir:[/usr/share/containers/oci/hooks.d] ImageBuildFormat:oci ImageDefaultTransport:docker:// ImageParallelCopies:0 ImageDefaultFormat: InfraCommand: InfraImage:k8s.gcr.io/pause:3.2 InitPath:/usr/libexec/podman/catatonit LockType:shm MultiImageArchive:false Namespace: NetworkCmdPath: NetworkCmdOptions:[] NoPivotRoot:false NumLocks:2048 OCIRuntime:crun OCIRuntimes:map[crun:[/usr/bin/crun /usr/sbin/crun /usr/local/bin/crun /usr/local/sbin/crun /sbin/crun /bin/crun /run/current-system/sw/bin/crun] kata:[/usr/bin/kata-runtime /usr/sbin/kata-runtime /usr/local/bin/kata-runtime /usr/local/sbin/kata-runtime /sbin/kata-runtime /bin/kata-runtime /usr/bin/kata-qemu /usr/bin/kata-fc] runc:[/usr/bin/runc /usr/sbin/runc /usr/local/bin/runc /usr/local/sbin/runc /sbin/runc /bin/runc /usr/lib/cri-o-runc/sbin/runc /run/current-system/sw/bin/runc]] PullPolicy:missing Remote:false RemoteURI: RemoteIdentity: ActiveService: ServiceDestinations:map[] RuntimePath:[] RuntimeSupportsJSON:[crun runc] RuntimeSupportsNoCgroups:[crun] RuntimeSupportsKVM:[kata kata-runtime kata-qemu kata-fc] SetOptions:{StorageConfigRunRootSet:false StorageConfigGraphRootSet:false StorageConfigGraphDriverNameSet:false StaticDirSet:false VolumePathSet:false TmpDirSet:false} SignaturePolicyPath:/etc/containers/policy.json SDNotify:false StateType:3 StaticDir:/var/lib/containers/storage/libpod StopTimeout:10 TmpDir:/run/libpod VolumePath:/var/lib/containers/storage/volumes VolumePlugins:map[]} Network:{CNIPluginDirs:[/usr/libexec/cni /usr/lib/cni /usr/local/lib/cni /opt/cni/bin] DefaultNetwork:podman NetworkConfigDir:/etc/cni/net.d/}}"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using conmon: \"/usr/bin/conmon\""
   time="2021-03-16T08:29:45-04:00" level=debug msg="Initializing boltdb state at /var/lib/containers/storage/libpod/bolt_state.db"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using graph driver overlay"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using graph root /var/lib/containers/storage"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using run root /run/containers/storage"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using static dir /var/lib/containers/storage/libpod"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using tmp dir /run/libpod"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Using volume path /var/lib/containers/storage/volumes"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Set libpod namespace to \"\""
   time="2021-03-16T08:29:45-04:00" level=debug msg="[graphdriver] trying provided driver \"overlay\""
   time="2021-03-16T08:29:45-04:00" level=debug msg="cached value indicated that overlay is supported"
   time="2021-03-16T08:29:45-04:00" level=debug msg="cached value indicated that metacopy is being used"
   time="2021-03-16T08:29:45-04:00" level=debug msg="cached value indicated that native-diff is not being used"
   time="2021-03-16T08:29:45-04:00" level=info msg="Not using native diff for overlay, this may cause degraded performance for building images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled"
   time="2021-03-16T08:29:45-04:00" level=debug msg="backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=true"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Initializing event backend journald"
   time="2021-03-16T08:29:45-04:00" level=debug msg="using runtime \"/usr/bin/runc\""
   time="2021-03-16T08:29:45-04:00" level=info msg="Error initializing configured OCI runtime kata: no valid executable found for OCI runtime kata: invalid argument"
   time="2021-03-16T08:29:45-04:00" level=debug msg="using runtime \"/usr/bin/crun\""
   time="2021-03-16T08:29:45-04:00" level=info msg="Found CNI network podman (type=bridge) at /etc/cni/net.d/87-podman-bridge.conflist"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Default CNI network name podman is unchangeable"
   time="2021-03-16T08:29:45-04:00" level=info msg="Setting parallel job count to 4"
   time="2021-03-16T08:29:45-04:00" level=info msg="Going to reload container 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 network"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Going to preserve container 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 IP address 10.88.0.7"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Going to preserve container 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 MAC address 9a:87:c9:40:c8:a8"
   time="2021-03-16T08:29:45-04:00" level=debug msg="Tearing down network namespace at /run/netns/cni-f8f0c938-c633-fb8d-8dd6-8c0ddf2d72ea for container 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0"
   time="2021-03-16T08:29:45-04:00" level=info msg="Got pod network &{Name:myweb Namespace:myweb ID:5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 NetNS:/run/netns/cni-f8f0c938-c633-fb8d-8dd6-8c0ddf2d72ea Networks:[{Name:podman Ifname:}] RuntimeConfig:map[podman:{IP:10.88.0.7 MAC:9a:87:c9:40:c8:a8 PortMappings:[{HostPort:12345 ContainerPort:80 Protocol:tcp HostIP:}] Bandwidth:<nil> IpRanges:[]}] Aliases:map[]}"
   time="2021-03-16T08:29:45-04:00" level=info msg="About to del CNI network podman (type=bridge)"
   time="2021-03-16T08:29:45-04:00" level=info msg="Got pod network &{Name:myweb Namespace:myweb ID:5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 NetNS:/run/netns/cni-f8f0c938-c633-fb8d-8dd6-8c0ddf2d72ea Networks:[{Name:podman Ifname:eth0}] RuntimeConfig:map[podman:{IP:10.88.0.7 MAC:9a:87:c9:40:c8:a8 PortMappings:[{HostPort:12345 ContainerPort:80 Protocol:tcp HostIP:}] Bandwidth:<nil> IpRanges:[]}] Aliases:map[]}"
   time="2021-03-16T08:29:45-04:00" level=info msg="About to add CNI network podman (type=bridge)"
   time="2021-03-16T08:29:46-04:00" level=debug msg="[0] CNI result: &{0.4.0 [{Name:cni-podman0 Mac:ea:b4:55:7e:97:11 Sandbox:} {Name:vethb7d1a3b1 Mac:ba:26:63:9a:fc:29 Sandbox:} {Name:eth0 Mac:b6:ee:e1:4d:7d:6f Sandbox:/run/netns/cni-f8f0c938-c633-fb8d-8dd6-8c0ddf2d72ea}] [{Version:4 Interface:0xc00034e538 Address:{IP:10.88.0.7 Mask:ffff0000} Gateway:10.88.0.1}] [{Dst:{IP:0.0.0.0 Mask:00000000} GW:<nil>}] {[]  [] []}}"
   5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0
   time="2021-03-16T08:29:46-04:00" level=debug msg="Called reload.PersistentPostRunE(podman --log-level=debug network reload 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0)"
   # podman inspect 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 --format {{.NetworkSettings.IPAddress}}
   10.88.0.7
   # podman inspect 5c002d240fb947279f732f8436080b0eb0b8043ba2f2e8b9c01949bcf7c47cd0 --format {{.NetworkSettings.MacAddress}}
   b6:ee:e1:4d:7d:6f
   #/vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
   #|     FAIL: MAC address changed after podman network reload
   #| expected: '9a:87:c9:40:c8:a8'
   #|   actual: 'b6:ee:e1:4d:7d:6f'
   #\^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

I'll keep this VM up for a few hours, say until 1200 EDT / 1700 CET, please ping me here or on Freenode if there's anything else you need me to test.

@edsantiago
Copy link
Member Author

Forgot to mention: containernetworking-plugins-0.9.1-9.1.git2989aba.fc35.x86_64

@Luap99
Copy link
Member

Luap99 commented Mar 16, 2021

Looks like something on the cni side is not working correctly.
Can you do a podman exec $cid ip link show after the reload. Would be interested to see if the mac is actually wrong or only wrong reported.
Also how often does it fail?

@edsantiago
Copy link
Member Author

edsantiago commented Mar 16, 2021

Oh, good idea:

# podman exec cid ip link show          ! before
3: eth0@if27: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1500 qdisc noqueue state UP
    link/ether 62:48:46:79:a5:77 brd ff:ff:ff:ff:ff:ff
# podman network reload cid
# podman exec cid ip link show          ! after
5: eth0@if4: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1500 qdisc noqueue state UP
    link/ether 62:48:46:79:a5:77 brd ff:ff:ff:ff:ff:ff
# podman inspect 0ec51ce24e0efb1a89253d68adbf033da4da4de139b93921fec280b78813bc8c --format {{.NetworkSettings.MacAddress}}
7a:d1:69:bd:ed:f8
#/vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
#|     FAIL: MAC address changed after podman network reload
#| expected: '62:48:46:79:a5:77'
#|   actual: '7a:d1:69:bd:ed:f8'
#\^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

@Luap99
Copy link
Member

Luap99 commented Mar 16, 2021

When did this start failing? And fails it every time or is it a flake?

@edsantiago
Copy link
Member Author

Sorry, forgot to reply to that part: it seems to be 100% failure, i.e. not a flake. I don't know when it started failing because we have another failure (#9507) that made me stop bothering to look at gating tests until it was fixed. I don't think the #9507 failure included this MAC address error, but unfortunately the logs have disappeared. The MAC address error was there last Wednesday when I looked, but I was on PTO. So, let's say some time between Feb 24 and Mar 10.

@Luap99
Copy link
Member

Luap99 commented Mar 16, 2021

OK I just compiled the cni plugins from master and can reproduce. I will bisect and report the error there.

@Luap99
Copy link
Member

Luap99 commented Mar 16, 2021

@edsantiago
Copy link
Member Author

@Luap99 thank you for tracking that down so quickly; and @mheon, thank you for writing the test that caught it.

@Luap99
Copy link
Member

Luap99 commented Mar 16, 2021

@edsantiago That's my test :)

@edsantiago
Copy link
Member Author

Oops! I blame tig blame! (But I should've double-checked the signed-off-by headers, so it's my fault for misattributing, and I sincerely apologize). Thank you @Luap99 !

@github-actions
Copy link

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

@zhangguanzhang
Copy link
Collaborator

zhangguanzhang commented Apr 16, 2021

It seems Has been fixed

[root@Centos8 ~]# podman  run --init -ti --name cid -d  --mac-address 44:9b:6f:0d:3d:a1 $IMG top -n10
22ced71e11b1062523c7e5fa646e4840f2ca6040312b150b826dd3575aa7ccac
[root@Centos8 ~]# pod^C
[root@Centos8 ~]# podman network reload cid
22ced71e11b1062523c7e5fa646e4840f2ca6040312b150b826dd3575aa7ccac
[root@Centos8 ~]# podman exec cid ip a s 
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
5: eth0@if4: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1500 qdisc noqueue state UP 
    link/ether 44:9b:6f:0d:3d:a1 brd ff:ff:ff:ff:ff:ff
    inet 10.88.0.5/16 brd 10.88.255.255 scope global eth0
       valid_lft forever preferred_lft forever
    inet6 fe80::1ce2:48ff:fe76:9e4a/64 scope link 
       valid_lft forever preferred_lft forever
[root@Centos8 ~]# podman inspect cid  --format {{.NetworkSettings.MacAddress}}
44:9b:6f:0d:3d:a1
[root@Centos8 ~]# 

@Luap99
Copy link
Member

Luap99 commented Apr 16, 2021

@zhangguanzhang You have to use the cni plugins compiled from master. This still reproduces with the latest changes.

@edsantiago
Copy link
Member Author

Not fixed. Log from last night's podman-3.2.0-0.1.dev.git373f15f.fc35 build.

@rhatdan
Copy link
Member

rhatdan commented Apr 16, 2021

Not sure what was just said. @Luap99 are you saying it is fixed in the latest cni plugins, or broken in the latest cni plugins?

@Luap99
Copy link
Member

Luap99 commented Apr 16, 2021

It is broken with the latest builds from master but works fine with the latest release 0.9.1.

@Luap99
Copy link
Member

Luap99 commented May 5, 2021

This should be fixed upstream containernetworking/plugins#626

@Luap99 Luap99 closed this as completed May 5, 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 22, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 22, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.
Projects
None yet
Development

No branches or pull requests

4 participants