test-bpf fails under lxc #9666
Description
systemd version the issue has been seen with
v239
Used distribution
Debian sid
This is a follow-up for #9649.
I'm using LXC (2.0.9) and autopkgtest to run the root-unittests test. With a default lxc config, test-bpf is skipped, but turning off AA via lxc.aa_profile = unconfined the test is now executed. After ensuring, /bin/ping is installed, it fails with the following message:
root@autopkgtest-lxc-pwobei:/tmp/autopkgtest-lxc.0ctkdqu5/downtmp/build.kVR/src# /usr/lib/systemd/tests/test-bpf
Found cgroup2 on /sys/fs/cgroup/unified, unified hierarchy for systemd controller
Got EBADF when using BPF_F_ALLOW_MULTI, which indicates it is supported. Yay!
BPF firewalling with BPF_F_ALLOW_MULTI supported. Yay!
Found cgroup2 on /sys/fs/cgroup/unified, unified hierarchy for systemd controller
Unified cgroup hierarchy is located at /sys/fs/cgroup/unified/56b685af60ebdda. Controllers are on legacy hierarchies.
Controller 'cpu' supported: yes
Controller 'cpuacct' supported: yes
Controller 'io' supported: no
Controller 'blkio' supported: yes
Controller 'memory' supported: yes
Controller 'devices' supported: yes
Controller 'pids' supported: yes
Looking for unit files in (higher priority first):
/usr/lib/systemd/tests/testdata
Unit type .device is not supported on this system.
Unit type .automount is not supported on this system.
Found container virtualization lxc.
Unit type .swap is not supported on this system.
Unit type .device is not supported on this system.
Unit type .automount is not supported on this system.
Unit type .swap is not supported on this system.
root.mount: Failed to load configuration: No such file or directory
dev.mount: Failed to load configuration: No such file or directory
proc.mount: Failed to load configuration: No such file or directory
tmp.mount: Failed to load configuration: No such file or directory
sys.mount: Failed to load configuration: No such file or directory
sys-fs.mount: Failed to load configuration: No such file or directory
sys-fs-fuse.mount: Failed to load configuration: No such file or directory
sys-devices.mount: Failed to load configuration: No such file or directory
sys-devices-virtual.mount: Failed to load configuration: No such file or directory
proc-sys.mount: Failed to load configuration: No such file or directory
Successfully created private D-Bus server.
Bus bus-system: changing state UNSET → OPENING
Bus bus-system: changing state OPENING → AUTHENTICATING
Successfully connected to system bus.
Invoking unit coldplug() handlers…
proc-swaps.mount: Changed dead -> mounted
dev-tty3.mount: Changed dead -> mounted
-.mount: Changed dead -> mounted
dev-tty4.mount: Changed dead -> mounted
init.scope changed dead -> running
dev-tty1.mount: Changed dead -> mounted
proc-sysrq\x2dtrigger.mount: Changed dead -> mounted
proc-cpuinfo.mount: Changed dead -> mounted
proc-meminfo.mount: Changed dead -> mounted
dev-hugepages.mount: Changed dead -> mounted
dev-mqueue.mount: Changed dead -> mounted
proc-sys-net.mount: Changed dead -> mounted
proc-uptime.mount: Changed dead -> mounted
tmp-autopkgtest\x2dlxc.0ctkdqu5.mount: Changed dead -> mounted
sys-devices-virtual-net.mount: Changed dead -> mounted
dev-tty2.mount: Changed dead -> mounted
proc-diskstats.mount: Changed dead -> mounted
proc-stat.mount: Changed dead -> mounted
sys-fs-fuse-connections.mount: Changed dead -> mounted
-.slice changed dead -> active
dev-ptmx.mount: Changed dead -> mounted
Invoking unit catchup() handlers…
-> Unit foo.service:
Description: foo.service
Instance: n/a
Unit Load State: loaded
Unit Active State: inactive
State Change Timestamp: n/a
Inactive Exit Timestamp: n/a
Active Enter Timestamp: n/a
Active Exit Timestamp: n/a
Inactive Enter Timestamp: n/a
May GC: no
Need Daemon Reload: no
Transient: no
Perpetual: yes
Garbage Collection Mode: inactive
Slice: n/a
CGroup: n/a
CGroup realized: no
CGroup own mask: memory pids
Name: foo.service
StopWhenUnneeded: no
RefuseManualStart: no
RefuseManualStop: no
DefaultDependencies: yes
OnFailureJobMode: replace
IgnoreOnIsolate: no
Service State: dead
Result: success
Reload Result: success
PermissionsStartOnly: no
RootDirectoryStartOnly: no
RemainAfterExit: no
GuessMainPID: yes
Type: oneshot
Restart: no
NotifyAccess: none
NotifyState: unknown
RestartSec: 100ms
TimeoutStartSec: 1min 30s
TimeoutStopSec: 1min 30s
RuntimeMaxSec: infinity
WatchdogSec: 0
KillMode: control-group
KillSignal: SIGTERM
SendSIGKILL: yes
SendSIGHUP: no
UMask: 0022
WorkingDirectory: /
RootDirectory: /
NonBlocking: no
PrivateTmp: no
PrivateDevices: no
ProtectKernelTunables: no
ProtectKernelModules: no
ProtectControlGroups: no
PrivateNetwork: no
PrivateUsers: no
ProtectHome: no
ProtectSystem: no
MountAPIVFS: no
IgnoreSIGPIPE: yes
MemoryDenyWriteExecute: no
RestrictRealtime: no
KeyringMode: inherit
RuntimeDirectoryPreserve: no
RuntimeDirectoryMode: 0755
StateDirectoryMode: 0755
CacheDirectoryMode: 0755
LogsDirectoryMode: 0755
ConfigurationDirectoryMode: 0755
StandardInput: null
StandardOutput: inherit
StandardError: inherit
DynamicUser: no
LockPersonality: no
-> ExecStart:
Command Line: /bin/ping -c 1 127.0.0.2 -W 5
Command Line: /bin/ping -c 1 127.0.0.3 -W 5
CPUAccounting=no
IOAccounting=no
BlockIOAccounting=no
MemoryAccounting=yes
TasksAccounting=yes
IPAccounting=yes
CPUWeight=18446744073709551615
StartupCPUWeight=18446744073709551615
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecSec=infinity
IOWeight=18446744073709551615
StartupIOWeight=18446744073709551615
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryLow=0
MemoryHigh=18446744073709551615
MemoryMax=18446744073709551615
MemorySwapMax=18446744073709551615
MemoryLimit=18446744073709551615
TasksMax=18446744073709551615
DevicePolicy=auto
Delegate=no
IPAddressAllow=10.0.1.0/24
IPAddressAllow=127.0.0.2/32
IPAddressDeny=10.0.3.0/24
IPAddressDeny=127.0.0.0/25
log:
-------
0: (bf) r6 = r1
1: (61) r7 = *(u32 *)(r6 +16)
2: (b4) (u32) r8 = (u32) 0
3: (55) if r7 != 0x8 goto pc+14
R1=ctx(id=0,off=0,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv0 R10=fp0,call_-1
4: (bf) r1 = r6
5: (b4) (u32) r2 = (u32) 12
6: (bf) r3 = r10
7: (07) r3 += -4
8: (b4) (u32) r4 = (u32) 4
9: (85) call bpf_skb_load_bytes#26
10: (18) r1 = 0xffff8b64085c7f00
12: (bf) r2 = r10
13: (07) r2 += -8
14: (62) *(u32 *)(r2 +0) = 32
15: (85) call bpf_map_lookup_elem#1
16: (15) if r0 == 0x0 goto pc+1
R0=map_value(id=0,off=0,ks=8,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv0 R10=fp0,call_-1
17: (44) (u32) r8 |= (u32) 2
18: (55) if r7 != 0x8 goto pc+14
19: (bf) r1 = r6
20: (b4) (u32) r2 = (u32) 12
21: (bf) r3 = r10
22: (07) r3 += -4
23: (b4) (u32) r4 = (u32) 4
24: (85) call bpf_skb_load_bytes#26
25: (18) r1 = 0xffff8b64085c7b40
27: (bf) r2 = r10
28: (07) r2 += -8
29: (62) *(u32 *)(r2 +0) = 32
30: (85) call bpf_map_lookup_elem#1
31: (15) if r0 == 0x0 goto pc+1
R0=map_value(id=0,off=0,ks=8,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv2 R10=fp0,call_-1
32: (44) (u32) r8 |= (u32) 1
33: (b7) r0 = 1
34: (55) if r8 != 0x2 goto pc+1
36: (15) if r0 == 0x0 goto pc+21
37: (b7) r0 = 0
38: (63) *(u32 *)(r10 -4) = r0
39: (bf) r2 = r10
40: (07) r2 += -4
41: (18) r1 = 0xffff8b648f160c00
43: (85) call bpf_map_lookup_elem#1
44: (15) if r0 == 0x0 goto pc+2
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
45: (b7) r1 = 1
46: (db) lock *(u64 *)(r0 +0) += r1
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R1_w=inv1 R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R1_w=inv1 R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
47: (b7) r0 = 1
48: (63) *(u32 *)(r10 -4) = r0
49: (bf) r2 = r10
50: (07) r2 += -4
51: (18) r1 = 0xffff8b648f160c00
53: (85) call bpf_map_lookup_elem#1
54: (15) if r0 == 0x0 goto pc+2
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
55: (61) r1 = *(u32 *)(r6 +0)
56:
-------
log:
-------
0: (bf) r6 = r1
1: (61) r7 = *(u32 *)(r6 +16)
2: (b4) (u32) r8 = (u32) 0
3: (55) if r7 != 0x8 goto pc+14
R1=ctx(id=0,off=0,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv0 R10=fp0,call_-1
4: (bf) r1 = r6
5: (b4) (u32) r2 = (u32) 16
6: (bf) r3 = r10
7: (07) r3 += -4
8: (b4) (u32) r4 = (u32) 4
9: (85) call bpf_skb_load_bytes#26
10: (18) r1 = 0xffff8b64085c7f00
12: (bf) r2 = r10
13: (07) r2 += -8
14: (62) *(u32 *)(r2 +0) = 32
15: (85) call bpf_map_lookup_elem#1
16: (15) if r0 == 0x0 goto pc+1
R0=map_value(id=0,off=0,ks=8,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv0 R10=fp0,call_-1
17: (44) (u32) r8 |= (u32) 2
18: (55) if r7 != 0x8 goto pc+14
19: (bf) r1 = r6
20: (b4) (u32) r2 = (u32) 16
21: (bf) r3 = r10
22: (07) r3 += -4
23: (b4) (u32) r4 = (u32) 4
24: (85) call bpf_skb_load_bytes#26
25: (18) r1 = 0xffff8b64085c7b40
27: (bf) r2 = r10
28: (07) r2 += -8
29: (62) *(u32 *)(r2 +0) = 32
30: (85) call bpf_map_lookup_elem#1
31: (15) if r0 == 0x0 goto pc+1
R0=map_value(id=0,off=0,ks=8,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv2 R10=fp0,call_-1
32: (44) (u32) r8 |= (u32) 1
33: (b7) r0 = 1
34: (55) if r8 != 0x2 goto pc+1
36: (15) if r0 == 0x0 goto pc+21
37: (b7) r0 = 0
38: (63) *(u32 *)(r10 -4) = r0
39: (bf) r2 = r10
40: (07) r2 += -4
41: (18) r1 = 0xffff8b648f160200
43: (85) call bpf_map_lookup_elem#1
44: (15) if r0 == 0x0 goto pc+2
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
45: (b7) r1 = 1
46: (db) lock *(u64 *)(r0 +0) += r1
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R1_w=inv1 R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R1_w=inv1 R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
47: (b7) r0 = 1
48: (63) *(u32 *)(r10 -4) = r0
49: (bf) r2 = r10
50: (07) r2 += -4
51: (18) r1 = 0xffff8b648f160200
53: (85) call bpf_map_lookup_elem#1
54: (15) if r0 == 0x0 goto pc+2
R0=map_value(id=0,off=0,ks=4,vs=8,imm=0) R6=ctx(id=0,off=0,imm=0) R7=inv8 R8=inv3 R10=fp0,call_-1
55: (61) r1 = *(u32 *)(r6 +0)
56:
-------
foo.service: Passing 0 fds to service
foo.service: About to execute: /bin/ping -c 1 127.0.0.2 -W 5
foo.service: Forked /bin/ping as 2134
foo.service: Changed dead -> start
Bus bus-system: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=AddMatch cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
foo.service: Executing: /bin/ping -c 1 127.0.0.2 -W 5
Got message type=method_return sender=org.freedesktop.DBus destination=:1.26 path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus bus-system: changing state HELLO → RUNNING
Got message type=signal sender=org.freedesktop.DBus destination=:1.26 path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.26 path=n/a interface=n/a member=n/a cookie=3 reply_cookie=2 signature=n/a error-name=n/a error-message=n/a
Match type='signal',path='/org/freedesktop/systemd1/agent',interface='org.freedesktop.systemd1.Agent',member='Released' successfully installed.
PING 127.0.0.2 (127.0.0.2) 56(84) bytes of data.
64 bytes from 127.0.0.2: icmp_seq=1 ttl=64 time=0.030 ms
--- 127.0.0.2 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.030/0.030/0.030/0.000 ms
Received SIGCHLD from PID 2134 (ping).
Child 2134 (ping) died (code=exited, status=0/SUCCESS)
foo.service: Child 2134 belongs to foo.service.
foo.service: Main process exited, code=exited, status=0/SUCCESS
foo.service: Running next main command for state start.
foo.service: Passing 0 fds to service
foo.service: About to execute: /bin/ping -c 1 127.0.0.3 -W 5
foo.service: Forked /bin/ping as 2135
foo.service: Executing: /bin/ping -c 1 127.0.0.3 -W 5
PING 127.0.0.3 (127.0.0.3) 56(84) bytes of data.
64 bytes from 127.0.0.3: icmp_seq=1 ttl=64 time=0.033 ms
--- 127.0.0.3 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.033/0.033/0.033/0.000 ms
Received SIGCHLD from PID 2135 (ping).
Child 2135 (ping) died (code=exited, status=0/SUCCESS)
foo.service: Child 2135 belongs to foo.service.
foo.service: Main process exited, code=exited, status=0/SUCCESS
foo.service: Changed start -> dead
foo.service: Received 0B IP traffic, sent 0B IP traffic
Assertion 'SERVICE(u)->exec_command[SERVICE_EXEC_START]->command_next->exec_status.code != CLD_EXITED || SERVICE(u)->exec_command[SERVICE_EXEC_START]->command_next->exec_status.status != EXIT_SUCCESS' failed at ../src/test/test-bpf.c:148, function main(). Aborting.
I can't reproduce the failure if I use autopkgtest in combination with qemu.
Inside the container, I have the following network config:
# ip -c a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default 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
74: eth0@if75: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
link/ether 00:16:3e:90:3a:e1 brd ff:ff:ff:ff:ff:ff link-netnsid 0
inet 10.0.3.236/24 brd 10.0.3.255 scope global eth0
valid_lft forever preferred_lft forever
inet6 fe80::216:3eff:fe90:3ae1/64 scope link
valid_lft forever preferred_lft forever
and pinging 127.0.0.3 works fine:
root@autopkgtest-lxc-pwobei:/tmp/autopkgtest-lxc.0ctkdqu5/downtmp/build.kVR/src# ping 127.0.0.3 -c 3
PING 127.0.0.3 (127.0.0.3) 56(84) bytes of data.
64 bytes from 127.0.0.3: icmp_seq=1 ttl=64 time=0.070 ms
64 bytes from 127.0.0.3: icmp_seq=2 ttl=64 time=0.078 ms
64 bytes from 127.0.0.3: icmp_seq=3 ttl=64 time=0.076 ms
--- 127.0.0.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 29ms
rtt min/avg/max/mdev = 0.070/0.074/0.078/0.010 ms