Re: Apparmor (and other) Issues

4 Feb 2025

On Monday, February 3rd, 2025 at 2:20 PM, Stefano Brivio &lt;sbrivio(a)redhat.com&gt;
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=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'?
 Yes, it is loaded.

...
  Do you have this line:

 /usr/bin/passt Cx -> passt,
  Yes, it is there.
...

 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?
  $ grep -A5 -B5 passt /var/log/audit/audit.log # Debian Trixie
type=SERVICE_STOP msg=audit(1738501179.991:119): pid=1 uid=0 auid=4294967295
ses=4294967295 subj=unconfined msg='unit=libvirtd comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=?
res=success'UID="root" AUID="unset"
type=USER_ACCT msg=audit(1738501259.697:120): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_CMD msg=audit(1738501259.697:121): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='cwd="/home/larryboy"
cmd=61612D656E666F726365202F6574632F61707061726D6F722E642F7573722E62696E2E7061737374
exe="/usr/bin/sudo" terminal=pts/0 res=success'UID="larryboy"
AUID="larryboy"
type=CRED_REFR msg=audit(1738501259.697:122): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_START msg=audit(1738501259.697:123): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=AVC msg=audit(1738501259.829:124): apparmor="STATUS"
operation="profile_load" profile="unconfined" name="passt"
pid=1935 comm="apparmor_parser"
type=SYSCALL msg=audit(1738501259.829:124): arch=c000003e syscall=1 success=yes exit=38258
a0=5 a1=564749519130 a2=9572 a3=0 items=0 ppid=1934 pid=1935 auid=1000 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 ses=1 comm="apparmor_parser"
exe="/usr/sbin/apparmor_parser" subj=unconfined key=(null)ARCH=x86_64
SYSCALL=write AUID="larryboy" UID="root" GID="root"
EUID="root" SUID="root" FSUID="root" EGID="root"
SGID="root" FSGID="root"
type=PROCTITLE msg=audit(1738501259.829:124):
proctitle=2F7362696E2F61707061726D6F725F706172736572002D492F6574632F61707061726D6F722E64002D2D62617365002F6574632F61707061726D6F722E64002D72002F6574632F61707061726D6F722E642F7573722E62696E2E7061737374
type=USER_END msg=audit(1738501259.837:125): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=CRED_DISP msg=audit(1738501259.837:126): pid=1931 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_ACCT msg=audit(1738501267.430:127): pid=1937 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
--
type=USER_START msg=audit(1738501267.430:130): pid=1937 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_END msg=audit(1738501267.430:131): pid=1937 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=CRED_DISP msg=audit(1738501267.430:132): pid=1937 uid=1000 auid=1000 ses=1
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=BPF msg=audit(1738501309.002:133): prog-id=71 op=LOAD
type=SERVICE_START msg=audit(1738501309.082:134): pid=1 uid=0 auid=4294967295
ses=4294967295 subj=unconfined msg='unit=polkit comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=?
res=success'UID="root" AUID="unset"
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=PROCTITLE msg=audit(1738501309.118:135): proctitle="(null)"
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"
type=USER_ACCT msg=audit(1738501327.534:137): pid=2031 uid=0 auid=4294967295
ses=4294967295 subj=unconfined msg='op=PAM:accounting grantors=pam_permit
acct="larryboy" exe="/usr/lib/openssh/sshd-session"
hostname=192.168.100.166 addr=192.168.100.166 terminal=ssh
res=success'UID="root" AUID="unset"
type=CRED_ACQ msg=audit(1738501327.538:138): pid=2031 uid=0 auid=4294967295 ses=4294967295
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="larryboy"
exe="/usr/lib/openssh/sshd-session" hostname=192.168.100.166
addr=192.168.100.166 terminal=ssh res=success'UID="root"
AUID="unset"
type=LOGIN msg=audit(1738501327.538:139): pid=2031 uid=0 subj=unconfined
old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=3
res=1UID="root" OLD-AUID="unset" AUID="larryboy"
type=SYSCALL msg=audit(1738501327.538:139): arch=c000003e syscall=1 success=yes exit=4
a0=5 a1=7ffdba6bed30 a2=4 a3=0 items=0 ppid=607 pid=2031 auid=1000 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=3 comm="sshd-session"
exe="/usr/lib/openssh/sshd-session" subj=unconfined key=(null)ARCH=x86_64
SYSCALL=write AUID="larryboy" UID="root" GID="root"
EUID="root" SUID="root" FSUID="root" EGID="root"
SGID="root" FSGID="root"
type=PROCTITLE msg=audit(1738501327.538:139):
proctitle=737368642D73657373696F6E3A206C61727279626F79205B707269765D
--
type=USER_AUTH msg=audit(1738501345.602:143): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:authentication grantors=pam_permit
acct="larryboy" exe="/usr/bin/sudo" hostname=? addr=?
terminal=/dev/pts/1 res=success'UID="larryboy" AUID="larryboy"
type=USER_ACCT msg=audit(1738501345.602:144): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_CMD msg=audit(1738501345.602:145): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='cwd="/home/larryboy"
cmd=7461696C202D66202F7661722F6C6F672F61756469742F61756469742E6C6F67
exe="/usr/bin/sudo" terminal=pts/1 res=success'UID="larryboy"
AUID="larryboy"
type=CRED_REFR msg=audit(1738501345.602:146): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_START msg=audit(1738501345.602:147): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="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=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=PROCTITLE msg=audit(1738501923.727:148): proctitle="(null)"
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=SERVICE_START msg=audit(1738501960.339:150): pid=1 uid=0 auid=4294967295
ses=4294967295 subj=unconfined msg='unit=systemd-tmpfiles-clean
comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=?
terminal=? res=success'UID="root" AUID="unset"
type=SERVICE_STOP msg=audit(1738501960.339:151): pid=1 uid=0 auid=4294967295
ses=4294967295 subj=unconfined msg='unit=systemd-tmpfiles-clean
comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=?
terminal=? res=success'UID="root" AUID="unset"
type=USER_END msg=audit(1738502065.759:152): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=CRED_DISP msg=audit(1738502065.763:153): pid=2043 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_ACCT msg=audit(1738502103.155:154): pid=2096 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
--
type=USER_CMD msg=audit(1738502295.487:169): pid=2106 uid=1000 auid=1000 ses=3
subj=unconfined msg='cwd="/home/larryboy"
cmd=67726570207061737374202F7661722F6C6F672F61756469742F61756469742E6C6F67
exe="/usr/bin/sudo" terminal=pts/1 res=success'UID="larryboy"
AUID="larryboy"
type=CRED_REFR msg=audit(1738502295.487:170): pid=2106 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_START msg=audit(1738502295.487:171): pid=2106 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_END msg=audit(1738502295.491:172): pid=2106 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=CRED_DISP msg=audit(1738502295.491:173): pid=2106 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="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=PROCTITLE msg=audit(1738502301.651:174): proctitle="(null)"
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"
type=USER_ACCT msg=audit(1738502318.063:176): pid=2146 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_CMD msg=audit(1738502318.063:177): pid=2146 uid=1000 auid=1000 ses=3
subj=unconfined msg='cwd="/home/larryboy"
cmd=67726570207061737374202F7661722F6C6F672F61756469742F61756469742E6C6F67
exe="/usr/bin/sudo" terminal=pts/1 res=success'UID="larryboy"
AUID="larryboy"
type=CRED_REFR msg=audit(1738502318.063:178): pid=2146 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_START msg=audit(1738502318.063:179): pid=2146 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
type=USER_END msg=audit(1738502318.063:180): pid=2146 uid=1000 auid=1000 ses=3
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1
res=success'UID="larryboy" AUID="larryboy"
--
type=USER_AUTH msg=audit(1738507044.714:414): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:authentication grantors=pam_permit
acct="larryboy" exe="/usr/bin/sudo" hostname=? addr=?
terminal=/dev/pts/0 res=success'UID="larryboy" AUID="larryboy"
type=USER_ACCT msg=audit(1738507044.714:415): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:accounting grantors=pam_permit acct="larryboy"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_CMD msg=audit(1738507044.714:416): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='cwd="/home/larryboy"
cmd=61612D64697361626C65202F6574632F61707061726D6F722E642F7573722E62696E2E7061737374
exe="/usr/bin/sudo" terminal=pts/0 res=success'UID="larryboy"
AUID="larryboy"
type=CRED_REFR msg=audit(1738507044.714:417): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_START msg=audit(1738507044.714:418): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:session_open
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=AVC msg=audit(1738507044.818:419): apparmor="STATUS"
operation="profile_remove" profile="unconfined" name="passt"
pid=3263 comm="apparmor_parser"
type=SYSCALL msg=audit(1738507044.818:419): arch=c000003e syscall=1 success=yes exit=6
a0=4 a1=7ffe35c30830 a2=6 a3=0 items=0 ppid=3262 pid=3263 auid=1000 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts2 ses=30 comm="apparmor_parser"
exe="/usr/sbin/apparmor_parser" subj=unconfined key=(null)ARCH=x86_64
SYSCALL=write AUID="larryboy" UID="root" GID="root"
EUID="root" SUID="root" FSUID="root" EGID="root"
SGID="root" FSGID="root"
type=PROCTITLE msg=audit(1738507044.818:419):
proctitle=2F7362696E2F61707061726D6F725F706172736572002D492F6574632F61707061726D6F722E64002D2D62617365002F6574632F61707061726D6F722E64002D52002F6574632F61707061726D6F722E642F7573722E62696E2E7061737374
type=USER_END msg=audit(1738507044.830:420): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:session_close
grantors=pam_limits,pam_permit,pam_umask,pam_unix acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=CRED_DISP msg=audit(1738507044.830:421): pid=3259 uid=1000 auid=1000 ses=30
subj=unconfined msg='op=PAM:setcred grantors=pam_permit acct="root"
exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0
res=success'UID="larryboy" AUID="larryboy"
type=USER_END msg=audit(1738507343.621:422): pid=2482 uid=0 auid=1000 ses=12
subj=unconfined msg='op=PAM:session_close
grantors=pam_selinux,pam_loginuid,pam_keyinit,pam_permit,pam_umask,pam_unix,pam_systemd,pam_mail,pam_limits,pam_env,pam_env,pam_selinux
acct="larryboy" exe="/usr/lib/openssh/sshd-session"
hostname=192.168.100.166 addr=192.168.100.166 terminal=ssh
res=success'UID="root" AUID="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

$ ./pasta --config-net --trace --pcap /tmp/dns.pcap -- nslookup fsf.org # On
Debian Trixie, dns.pcap attached
0.0002: No interfaces with usable IPv6 routes
0.0002: Failed to detect external interface for IPv6
0.0035: Template interface: enp1s0 (IPv4)
0.0035: Namespace interface: enp1s0
0.0035: MAC:
0.0035:     host: 9a:55:9a:55:9a:55
0.0035:     NAT to host 127.0.0.1: 192.168.100.1
0.0036: DHCP:
0.0036:     assign: 192.168.100.157
0.0036:     mask: 255.255.255.0
0.0036:     router: 192.168.100.1
0.0036: DNS:
0.0036:     192.168.100.1
0.0036: DNS search list:
0.0036:     .
0.0204: SO_PEEK_OFF supported
0.0204: TCP_INFO tcpi_snd_wnd field  supported
0.0205: TCP_INFO tcpi_bytes_acked field  supported
0.0205: TCP_INFO tcpi_min_rtt field  supported
0.0205: Saving packet capture to /tmp/dns.pcap
0.0281: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
0.0413: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
0.0414: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
0.0414: tap: protocol 17, 192.168.100.157:56205 -> 192.168.100.1:53 (1 packet)
0.0415: Flow 0 (NEW): FREE -> NEW
0.0415: Flow 0 (INI): NEW -> INI
0.0415: Flow 0 (INI): TAP [192.168.100.157]:56205 -> [192.168.100.1]:53 => ?
0.0416: Flow 0 (TGT): INI -> TGT
0.0416: Flow 0 (TGT): TAP [192.168.100.157]:56205 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:56205 -> [192.168.100.1]:53
0.0416: Flow 0 (UDP flow): TGT -> TYPED
0.0416: Flow 0 (UDP flow): TAP [192.168.100.157]:56205 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:56205 -> [192.168.100.1]:53
0.0417: Flow 0 (UDP flow): Side 0 hash table insert: bucket: 121236
0.0417: Flow 0 (UDP flow): TYPED -> ACTIVE
0.0417: Flow 0 (UDP flow): TAP [192.168.100.157]:56205 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:56205 -> [192.168.100.1]:53
0.3059: pasta: epoll event on UDP reply socket 96 (events: 0x00000001)
0.3059: Flow 0 (UDP flow): Received 1 datagrams on reply socket
Server:		192.168.100.1
Address:	192.168.100.1#53

Non-authoritative answer:
Name:	fsf.org
Address: 209.51.188.174
0.3173: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
0.3175: tap: protocol 17, 192.168.100.157:50006 -> 192.168.100.1:53 (1 packet)
0.3175: Flow 1 (NEW): FREE -> NEW
0.3176: Flow 1 (INI): NEW -> INI
0.3177: Flow 1 (INI): TAP [192.168.100.157]:50006 -> [192.168.100.1]:53 => ?
0.3177: Flow 1 (TGT): INI -> TGT
0.3178: Flow 1 (TGT): TAP [192.168.100.157]:50006 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:50006 -> [192.168.100.1]:53
0.3179: Flow 1 (UDP flow): TGT -> TYPED
0.3179: Flow 1 (UDP flow): TAP [192.168.100.157]:50006 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:50006 -> [192.168.100.1]:53
0.3181: Flow 1 (UDP flow): Side 0 hash table insert: bucket: 167789
0.3182: Flow 1 (UDP flow): TYPED -> ACTIVE
0.3183: Flow 1 (UDP flow): TAP [192.168.100.157]:50006 -> [192.168.100.1]:53 => HOST
[0.0.0.0]:50006 -> [192.168.100.1]:53
0.3406: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
1.3645: pasta: epoll event on /dev/net/tun device 16 (events: 0x00000001)
1.7900: pasta: epoll event on UDP reply socket 97 (events: 0x00000001)
1.7903: Flow 1 (UDP flow): Received 1 datagrams on reply socket
Name:	fsf.org
Address: 2001:470:142:4::a

...
  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.
  # Apparmor is enabled
$ virsh start --domain vm1 # Debian-supplied `passt`
error: Failed to start domain 'vm1'
error: internal error: Child process (passt --one-off --socket
/run/user/1000/libvirt/qemu/run/passt/3-vm1-net0.socket --pid
/run/user/1000/libvirt/qemu/run/passt/3-vm1-net0-passt.pid --log-file /tmp/vm-1-passt.log)
unexpected fatal signal 11

$ $ virsh start --domain vm1 # `make install`-ed `passt`
error: Failed to start domain 'vm1'
error: internal error: Child process (passt --one-off --socket
/run/user/1000/libvirt/qemu/run/passt/4-vm1-net0.socket --pid
/run/user/1000/libvirt/qemu/run/passt/4-vm1-net0-passt.pid --log-file /tmp/vm-1-passt.log)
unexpected exit status 126: libvirt:  error : cannot execute binary passt: Permission
denied

Just a side note, once these issues are resolved, please don't hesitate to ping me to
test things out on Debian: this has been horizon-broadening. I never knew about b4 and
stuff. Pretty awesome stuff!

2025

2024

2023

2022

2021

Re: Apparmor (and other) Issues