Re: Apparmor (and other) Issues

On Sun, 02 Feb 2025 14:21:49 +0000
Prafulla Giri <prafulla.giri(a)protonmail.com> wrote:

...
  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:
   
  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.
    
 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=0FSUID="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=1AUID="larryboy" UID="larryboy" GID="larryboy" 
System call number 59 (this seems to be x86_64) is "execve":

  $ ausyscall 59
  execve

and this seems to be libvirt failing to execute passt itself, but:

 
https://gitlab.com/libvirt/libvirt/-/blob/0264a7704ada52f686cafe8f6402d5b60…

Do you see the libvirtd profile loaded if you run 'aa-status'?

Do you have this line:

  /usr/bin/passt Cx -> passt,

in /etc/apparmor.d/abstractions/libvirt-qemu? I wonder if something
bad happened during installation.

Can you perhaps grep a bit before and after those messages (say, grep
-A5 -B5) to see if we spot something else related to libvirt?

...
  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=0FSUID="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=1AUID="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=0FSUID="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=1AUID="larryboy" UID="larryboy" GID="larryboy"
 
 
  $ 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.1   
 
 
 So, 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: yes   
 
 
 Everything 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, exiting   
 
 
 Unfortunately 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
 
 ?   
 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 
Ouch. I just sent a patch for this, you can test it by checking out
passt locally:

  git clone git://passt.top/passt; cd passt

applying it (you might need to install 'b4'):

  b4 shazam
  https://archives.passt.top/passt-dev/20250203082210.2114348-1-sbrivio@redha…

then:

  make

and ./pasta --config-net --trace --pcap /tmp/dns.pcap -- nslookup
fsf.org

You can also install it to /usr/local with 'make install', it's just a
couple of files and will uninstall cleanly with 'make uninstall' if
needed. Note that AppArmor profiles don't apply to binaries under
/usr/local/bin.

...
  [...]

 This is rather strange: from the shell I successfully managed to `ping fsf.org` and `ping
gnu.org`. 
That's because they were already cached on your host at this point (I
suppose by systemd-resolved) and ping didn't need to resolve anything,
just call getaddrinfo() and get the addresses back. There's no UDP at
all in the output below:

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