On Saturday, February 1st, 2025 at 2:05 AM, Stefano Brivio <sbrivio(a)redhat.com> wrote:On Thu, 30 Jan 2025 10:05:14 +0000 Prafulla Giri prafulla.giri(a)protonmail.com wrote:The following is the output of grep-ping 'passt' after re-enforcing the apparmor config and trying to start a VM: $ grep passt /var/log/audit/audit.log # Debian Trixie type=AVC msg=audit(1738501259.829:124): apparmor="STATUS" operation="profile_load" profile="unconfined" name="passt" pid=1935 comm="apparmor_parser" type=AVC msg=audit(1738501309.118:135): apparmor="DENIED" operation="file_mmap" class="file" profile="passt" name="/usr/bin/passt" pid=2030 comm="passt" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0 FSUID="larryboy" OUID="root" type=SYSCALL msg=audit(1738501309.118:135): arch=c000003e syscall=59 success=no exit=-13 a0=7faf24035fc0 a1=7faf24035210 a2=7ffc063280d0 a3=0 items=0 ppid=1964 pid=2030 auid=1000 uid=1000 gid=1000 euid=1000 suid=1000 fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=(none) ses=1 comm="passt" exe="/usr/bin/passt" subj=passt key=(null) ARCH=x86_64 SYSCALL=execve AUID="larryboy" UID="larryboy" GID="larryboy" EUID="larryboy" SUID="larryboy" FSUID="larryboy" EGID="larryboy" SGID="larryboy" FSGID="larryboy" type=ANOM_ABEND msg=audit(1738501309.118:136): auid=1000 uid=1000 gid=1000 ses=1 subj=passt pid=2030 comm="passt" exe="/usr/bin/passt" sig=11 res=1 AUID="larryboy" UID="larryboy" GID="larryboy" type=AVC msg=audit(1738501923.727:148): apparmor="DENIED" operation="file_mmap" class="file" profile="passt" name="/usr/bin/passt" pid=2088 comm="passt" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0 FSUID="larryboy" OUID="root" type=SYSCALL msg=audit(1738501923.727:148): arch=c000003e syscall=59 success=no exit=-13 a0=7ff564035d40 a1=7ff564039d00 a2=7fffe9aa1de0 a3=0 items=0 ppid=2060 pid=2088 auid=1000 uid=1000 gid=1000 euid=1000 suid=1000 fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=(none) ses=1 comm="passt" exe="/usr/bin/passt" subj=passt key=(null) ARCH=x86_64 SYSCALL=execve AUID="larryboy" UID="larryboy" GID="larryboy" EUID="larryboy" SUID="larryboy" FSUID="larryboy" EGID="larryboy" SGID="larryboy" FSGID="larryboy" type=ANOM_ABEND msg=audit(1738501923.727:149): auid=1000 uid=1000 gid=1000 ses=1 subj=passt pid=2088 comm="passt" exe="/usr/bin/passt" sig=11 res=1 AUID="larryboy" UID="larryboy" GID="larryboy" type=AVC msg=audit(1738502301.651:174): apparmor="DENIED" operation="file_mmap" class="file" profile="passt" name="/usr/bin/passt" pid=2145 comm="passt" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0 FSUID="larryboy" OUID="root" type=SYSCALL msg=audit(1738502301.651:174): arch=c000003e syscall=59 success=no exit=-13 a0=7fe208034ce0 a1=7fe208034350 a2=7fffd2e60120 a3=0 items=0 ppid=2117 pid=2145 auid=1000 uid=1000 gid=1000 euid=1000 suid=1000 fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=(none) ses=1 comm="passt" exe="/usr/bin/passt" subj=passt key=(null) ARCH=x86_64 SYSCALL=execve AUID="larryboy" UID="larryboy" GID="larryboy" EUID="larryboy" SUID="larryboy" FSUID="larryboy" EGID="larryboy" SGID="larryboy" FSGID="larryboy" type=ANOM_ABEND msg=audit(1738502301.651:175): auid=1000 uid=1000 gid=1000 ses=1 subj=passt pid=2145 comm="passt" exe="/usr/bin/passt" sig=11 res=1 AUID="larryboy" UID="larryboy" GID="larryboy"I didn't have auditd installed on Debian and installed it, and running everything with the default auditd config (with my Apparmor disabled for passt, as mentioned previously) does not result in anything. Do I have to configure auditd manually? Any pointers on that, please?No, the default configuration is just fine. But you should re-enable AppArmor for passt so that we can see meaningful messages in the logs.This one errors out. dns.pcap is attached. $ pasta --config-net --trace --pcap /tmp/dns.pcap -- nslookup fsf.org # Debian Trixie/Testing 0.0015: No interfaces with usable IPv6 routes 0.0015: Failed to detect external interface for IPv6 0.0073: Template interface: enp1s0 (IPv4) 0.0073: Namespace interface: enp1s0 0.0074: MAC: 0.0074: host: 9a:55:9a:55:9a:55 0.0074: NAT to host 127.0.0.1: 192.168.100.1 0.0074: DHCP: 0.0074: assign: 192.168.100.157 0.0074: mask: 255.255.255.0 0.0075: router: 192.168.100.1 0.0075: DNS: 0.0075: 192.168.100.1 0.0076: DNS search list: 0.0076: . 0.0146: SO_PEEK_OFF supported 0.0146: TCP_INFO tcpi_snd_wnd field supported 0.0146: TCP_INFO tcpi_bytes_acked field supported 0.0146: TCP_INFO tcpi_min_rtt field supported 0.0147: Saving packet capture to /tmp/dns.pcap 0.0197: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0371: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0372: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0372: tap: protocol 17, 192.168.100.157:41892 -> 192.168.100.1:53 (1 packet) 0.0372: Flow 0 (NEW): FREE -> NEW 0.0372: Flow 0 (INI): NEW -> INI 0.0372: Flow 0 (INI): TAP [192.168.100.157]:41892 -> [192.168.100.1]:53 => ? 0.0372: Flow 0 (TGT): INI -> TGT 0.0373: Flow 0 (TGT): TAP [192.168.100.157]:41892 -> [192.168.100.1]:53 => HOST [0.0.0.0]:41892 -> [127.0.0.1]:53 0.0373: Flow 0 (UDP flow): TGT -> TYPED 0.0373: Flow 0 (UDP flow): TAP [192.168.100.157]:41892 -> [192.168.100.1]:53 => HOST [0.0.0.0]:41892 -> [127.0.0.1]:53 0.0373: Flow 0 (UDP flow): Side 0 hash table insert: bucket: 31049 0.0374: Flow 0 (UDP flow): TYPED -> ACTIVE 0.0374: Flow 0 (UDP flow): TAP [192.168.100.157]:41892 -> [192.168.100.1]:53 => HOST [0.0.0.0]:41892 -> [127.0.0.1]:53 0.0374: pasta: epoll event on UDP reply socket 95 (events: 0x00000008) 0.0374: ICMP error on UDP socket 95: Connection refused 0.5320: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.8201: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 1.5560: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 2.3240: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) ;; communications error to 192.168.100.1#53: timed out 5.0431: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 5.0431: tap: protocol 17, 192.168.100.157:46013 -> 192.168.100.1:53 (1 packet) 5.0432: Flow 1 (NEW): FREE -> NEW 5.0432: Flow 1 (INI): NEW -> INI 5.0432: Flow 1 (INI): TAP [192.168.100.157]:46013 -> [192.168.100.1]:53 => ? 5.0432: Flow 1 (TGT): INI -> TGT 5.0432: Flow 1 (TGT): TAP [192.168.100.157]:46013 -> [192.168.100.1]:53 => HOST [0.0.0.0]:46013 -> [127.0.0.1]:53 5.0432: Flow 1 (UDP flow): TGT -> TYPED 5.0432: Flow 1 (UDP flow): TAP [192.168.100.157]:46013 -> [192.168.100.1]:53 => HOST [0.0.0.0]:46013 -> [127.0.0.1]:53 5.0433: Flow 1 (UDP flow): Side 0 hash table insert: bucket: 100062 5.0433: Flow 1 (UDP flow): TYPED -> ACTIVE 5.0433: Flow 1 (UDP flow): TAP [192.168.100.157]:46013 -> [192.168.100.1]:53 => HOST [0.0.0.0]:46013 -> [127.0.0.1]:53 5.0434: pasta: epoll event on UDP reply socket 160 (events: 0x00000008) 5.0434: ICMP error on UDP socket 160: Connection refused 5.4924: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) ;; communications error to 192.168.100.1#53: timed out 10.0478: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 10.0478: tap: protocol 17, 192.168.100.157:55861 -> 192.168.100.1:53 (1 packet) 10.0478: Flow 2 (NEW): FREE -> NEW 10.0478: Flow 2 (INI): NEW -> INI 10.0478: Flow 2 (INI): TAP [192.168.100.157]:55861 -> [192.168.100.1]:53 => ? 10.0478: Flow 2 (TGT): INI -> TGT 10.0479: Flow 2 (TGT): TAP [192.168.100.157]:55861 -> [192.168.100.1]:53 => HOST [0.0.0.0]:55861 -> [127.0.0.1]:53 10.0479: Flow 2 (UDP flow): TGT -> TYPED 10.0479: Flow 2 (UDP flow): TAP [192.168.100.157]:55861 -> [192.168.100.1]:53 => HOST [0.0.0.0]:55861 -> [127.0.0.1]:53 10.0480: Flow 2 (UDP flow): Side 0 hash table insert: bucket: 342763 10.0481: Flow 2 (UDP flow): TYPED -> ACTIVE 10.0481: Flow 2 (UDP flow): TAP [192.168.100.157]:55861 -> [192.168.100.1]:53 => HOST [0.0.0.0]:55861 -> [127.0.0.1]:53 10.0482: pasta: epoll event on UDP reply socket 161 (events: 0x00000008) 10.0483: ICMP error on UDP socket 161: Connection refused 13.4282: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) ;; communications error to 192.168.100.1#53: timed out ;; no servers could be reached$ passt -f -d # on Debian Testing/Trixie 0.0016: No interfaces with usable IPv6 routes 0.0017: Failed to detect external interface for IPv6 0.0028: UNIX domain socket bound at /tmp/passt_1.socket 0.0029: Template interface: enp1s0 (IPv4) 0.0029: MAC: 0.0029: host: 9a:55:9a:55:9a:55 0.0029: NAT to host 127.0.0.1: 192.168.100.1 0.0029: DHCP: 0.0029: assign: 192.168.100.157 0.0029: mask: 255.255.255.0 0.0029: router: 192.168.100.1 0.0029: DNS: 0.0029: 192.168.100.1So, judging from this configuration, it looks like we advertise to the guest (via DHCP) 192.168.100.1 as resolver (copied from the host), and when we receive packets from the guest for 192.168.100.1, we'll re-map them to the host. Nothing strange so far, systemd-resolved is running on the host, it should get our queries and reply to them.$ cat /etc/resolv.conf # On Debian Trixie # This is /run/systemd/resolve/resolv.conf managed by man:systemd-resolved(8). [...] nameserver 192.168.100.1 search . $ cat /etc/resolv.conf # On a Debian 11 OS # Generated by NetworkManager nameserver 192.168.100.1 Also the output of `resolvectl status` for good measure: # On Fedora 41 Global Protocols: LLMNR=resolve -mDNS -DNSOverTLS DNSSEC=no/unsupported resolv.conf mode: stub Link 2 (wlp0s20f3) Current Scopes: DNS LLMNR/IPv4 LLMNR/IPv6 Protocols: +DefaultRoute LLMNR=resolve -mDNS -DNSOverTLS DNSSEC=no/unsupported Current DNS Server: 192.168.100.1 DNS Servers: 192.168.100.1 # On Debian Trixie Global Protocols: +LLMNR +mDNS -DNSOverTLS DNSSEC=no/unsupported resolv.conf mode: uplink Link 2 (enp1s0) Current Scopes: DNS LLMNR/IPv4 LLMNR/IPv6 Protocols: +DefaultRoute +LLMNR -mDNS -DNSOverTLS DNSSEC=no/unsupported DNS Servers: 192.168.100.1 Default Route: yesEverything as expected here, I don't see any obvious reason why systemd-resolved should discard our queries.The log from Debian Trixie host for VM1: passt 0.0~git20250121.4f2c8e7-1: /usr/bin/passt.avx2 (6428) 0.0017: info: No interfaces with usable IPv6 routes 0.0029: info: UNIX domain socket bound at /run/user/1000/libvirt/qemu/run/passt/2-vm1-net0.socket 0.0030: info: Template interface: enp1s0 (IPv4) 0.0030: info: MAC: 0.0030: info: host: 9a:55:9a:55:9a:55 0.0030: info: NAT to host 127.0.0.1: 192.168.100.1 0.0030: info: DHCP: 0.0031: info: assign: 192.168.100.157 0.0031: info: mask: 255.255.255.0 0.0031: info: router: 192.168.100.1 0.0031: info: DNS: 0.0031: info: 192.168.100.1 0.0031: info: DNS search list: 0.0031: info: . 0.0066: info: You can now start qemu (>= 7.2, with commit 13c6be96618c): 0.0066: info: kvm ... -device virtio-net-pci,netdev=s -netdev stream,id=s,server=off,addr.type=unix,addr.path=/run/user/1000/libvirt/qemu/run/passt/2-vm1-net0.socket 0.0066: info: or qrap, for earlier qemu versions: 0.0066: info: ./qrap 5 kvm ... -net socket,fd=5 -net nic,model=virtio 0.0617: info: accepted connection from PID 0 38.6257: info: DHCP: offer to discover 38.6257: info: from 52:54:00:a0:e1:7c 38.6471: info: DHCP: ack to request 38.6471: info: from 52:54:00:a0:e1:7c 451.4989: info: Client connection closed, exitingUnfortunately libvirt doesn't let us enable more verbose logging. I hoped to see DNS queries there, but without --debug given to passt, that won't work. Another idea: pasta(1) does the same job as passt(1) (it's the same code and same binary) and it's intended for containers, but it has a stand-alone mode that can probably help us to debug this, because it's a network namespace that will look like your guest, and it can also take packet captures. What happens if you run: pasta --config-net --trace --pcap /tmp/dns.pcap -- nslookup fsf.org ?If the query fails (that's what I would expect), can you please attach the output and the resulting packet capture? Note that the packet capture might have sensitive data, please have a look at it with e.g. Wireshark/tshark before sharing it. By the way, if you run this without specifying any command, for example: pasta --config-net --pcap /tmp/dns.pcap you will get a shell where you can play around in a separate network namespace and with a network stack that looks pretty much the same as passt for your guest.This is rather strange: from the shell I successfully managed to `ping fsf.org` and `ping gnu.org`. I went back and ran $ pasta --config-net --trace --pcap /tmp/ping.pcap -- ping -c 5 fsf.org # and the following output followed (ping.pcap is also attached) 0.0013: No interfaces with usable IPv6 routes 0.0013: Failed to detect external interface for IPv6 0.0091: Template interface: enp1s0 (IPv4) 0.0091: Namespace interface: enp1s0 0.0092: MAC: 0.0092: host: 9a:55:9a:55:9a:55 0.0092: NAT to host 127.0.0.1: 192.168.100.1 0.0092: DHCP: 0.0092: assign: 192.168.100.157 0.0093: mask: 255.255.255.0 0.0093: router: 192.168.100.1 0.0093: DNS: 0.0093: 192.168.100.1 0.0093: DNS search list: 0.0094: . 0.0161: SO_PEEK_OFF supported 0.0161: TCP_INFO tcpi_snd_wnd field supported 0.0161: TCP_INFO tcpi_bytes_acked field supported 0.0161: TCP_INFO tcpi_min_rtt field supported 0.0162: Saving packet capture to /tmp/ping.pcap PING fsf.org (209.51.188.174) 56(84) bytes of data. 0.0181: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0181: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0182: tap: protocol 1, 192.168.100.157 -> 209.51.188.174 (1 packet) 0.0182: Flow 0 (NEW): FREE -> NEW 0.0182: Flow 0 (INI): NEW -> INI 0.0182: Flow 0 (INI): TAP [192.168.100.157]:11 -> [209.51.188.174]:11 => ? 0.0182: Flow 0 (TGT): INI -> TGT 0.0182: Flow 0 (TGT): TAP [192.168.100.157]:11 -> [209.51.188.174]:11 => HOST [0.0.0.0]:0 -> [209.51.188.174]:11 0.0182: Flow 0 (ICMP ping sequence): TGT -> TYPED 0.0183: Flow 0 (ICMP ping sequence): TAP [192.168.100.157]:11 -> [209.51.188.174]:11 => HOST [0.0.0.0]:0 -> [209.51.188.174]:11 0.0183: Flow 0 (ICMP ping sequence): new socket 95 for echo ID 11 0.0183: Flow 0 (ICMP ping sequence): Side 0 hash table insert: bucket: 150766 0.0184: Flow 0 (ICMP ping sequence): TYPED -> ACTIVE 0.0184: Flow 0 (ICMP ping sequence): TAP [192.168.100.157]:11 -> [209.51.188.174]:11 => HOST [0.0.0.0]:0 -> [209.51.188.174]:11 0.0184: Flow 0 (ICMP ping sequence): echo request to socket, ID: 11, seq: 1 0.0214: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.0538: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 0.4423: pasta: epoll event on ICMP/ICMPv6 ping socket 95 (events: 0x00000001) 0.4424: Flow 0 (ICMP ping sequence): echo reply to tap, ID: 11, seq: 1 64 bytes from www.fsf.org (209.51.188.174): icmp_seq=1 ttl=255 time=424 ms 0.7857: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 1.0188: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 1.0189: tap: protocol 1, 192.168.100.157 -> 209.51.188.174 (1 packet) 1.0189: Flow 0 (ICMP ping sequence): echo request to socket, ID: 11, seq: 2 1.0736: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 1.1777: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 1.4302: pasta: epoll event on ICMP/ICMPv6 ping socket 95 (events: 0x00000001) 1.4303: Flow 0 (ICMP ping sequence): echo reply to tap, ID: 11, seq: 2 64 bytes from www.fsf.org (209.51.188.174): icmp_seq=2 ttl=255 time=412 ms 2.0188: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 2.0189: tap: protocol 1, 192.168.100.157 -> 209.51.188.174 (1 packet) 2.0190: Flow 0 (ICMP ping sequence): echo request to socket, ID: 11, seq: 3 2.4837: pasta: epoll event on ICMP/ICMPv6 ping socket 95 (events: 0x00000001) 2.4837: Flow 0 (ICMP ping sequence): echo reply to tap, ID: 11, seq: 3 64 bytes from www.fsf.org (209.51.188.174): icmp_seq=3 ttl=255 time=465 ms 3.0191: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 3.0191: tap: protocol 1, 192.168.100.157 -> 209.51.188.174 (1 packet) 3.0192: Flow 0 (ICMP ping sequence): echo request to socket, ID: 11, seq: 4 3.6917: pasta: epoll event on ICMP/ICMPv6 ping socket 95 (events: 0x00000001) 3.6918: Flow 0 (ICMP ping sequence): echo reply to tap, ID: 11, seq: 4 64 bytes from www.fsf.org (209.51.188.174): icmp_seq=4 ttl=255 time=673 ms 4.0186: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001) 4.0187: tap: protocol 1, 192.168.100.157 -> 209.51.188.174 (1 packet) 4.0188: Flow 0 (ICMP ping sequence): echo request to socket, ID: 11, seq: 5 4.4281: pasta: epoll event on ICMP/ICMPv6 ping socket 95 (events: 0x00000001) 4.4282: Flow 0 (ICMP ping sequence): echo reply to tap, ID: 11, seq: 5 64 bytes from www.fsf.org (209.51.188.174): icmp_seq=5 ttl=255 time=410 ms --- fsf.org ping statistics --- 5 packets transmitted, 5 received, 0% packet loss, time 4001ms rtt min/avg/max/mdev = 409.797/476.856/673.012/100.088 ms There were no entries on the auditlog regarding pasta. I wonder if these 2 issues are mutually exclusive: If I disable apparmor and let passt run, it doesn't get DNS configs right; however, if I don't make any changes to apparmor configs, while passt won't be able to create the socket at /run/*, it will get DNS configs right (?) Curioser and curioser.-- Stefano