[pkg-lxc-devel] Bug#1010469: Bug#1010469: lxc: as root, lxc-start fails to start with cgroups/cgfsng error setting up limits for devices

[Julian Gilbey]

On Mon, May 15, 2023 at 10:21:39PM +0200, Pierre-Elliott Bécue wrote:
> Ah, I don't remember seeing these logs before, maybe I forgot to ask for
> a full trace, sorry.
> 
> Do you see anything in /var/log/audit or /var/log/syslog or
> /var/log/kern.log about apparmor denies?

Hi Pierre-Elliott,

Thanks for all your time on this!

No, I don't think so; here's the relevant part of /var/log/syslog:

2023-05-15T21:47:21.645645+01:00 euler kernel: [94706.953337] audit: type=1400 audit(1684183641.640:92): apparmor="STATUS" operation="profile_load" profile="/usr/bin/lxc-start" name="lxc-debian-sid_</var/lib/lxc>" pid=547941 comm="apparmor_parser"
2023-05-15T21:47:21.741618+01:00 euler kernel: [94707.049379] lxcbr0: port 1(vethPUhTGL) entered blocking state
2023-05-15T21:47:21.741632+01:00 euler kernel: [94707.049385] lxcbr0: port 1(vethPUhTGL) entered disabled state
2023-05-15T21:47:21.741633+01:00 euler kernel: [94707.049489] device vethPUhTGL entered promiscuous mode
2023-05-15T21:47:21.741635+01:00 euler kernel: [94707.049738] lxcbr0: port 1(vethPUhTGL) entered blocking state
2023-05-15T21:47:21.741636+01:00 euler kernel: [94707.049741] lxcbr0: port 1(vethPUhTGL) entered forwarding state
2023-05-15T21:47:21.741637+01:00 euler kernel: [94707.049956] lxcbr0: port 1(vethPUhTGL) entered disabled state
2023-05-15T21:47:21.741637+01:00 euler kernel: [94707.050570] eth0: renamed from vethX4vupZ
2023-05-15T21:47:21.742023+01:00 euler NetworkManager[1647]: <info>  [1684183641.7416] manager: (vethPUhTGL): new Veth device (/org/freedesktop/NetworkManager/Devices/18)
2023-05-15T21:47:21.764024+01:00 euler NetworkManager[1647]: <info>  [1684183641.7639] device (vethPUhTGL): carrier: link connected
2023-05-15T21:47:21.764243+01:00 euler NetworkManager[1647]: <info>  [1684183641.7641] device (lxcbr0): carrier: link connected
2023-05-15T21:47:21.765623+01:00 euler kernel: [94707.072272] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
2023-05-15T21:47:21.765639+01:00 euler kernel: [94707.072351] IPv6: ADDRCONF(NETDEV_CHANGE): vethPUhTGL: link becomes ready
2023-05-15T21:47:21.765640+01:00 euler kernel: [94707.072481] lxcbr0: port 1(vethPUhTGL) entered blocking state
2023-05-15T21:47:21.765642+01:00 euler kernel: [94707.072487] lxcbr0: port 1(vethPUhTGL) entered forwarding state
2023-05-15T21:47:22.017893+01:00 euler kernel: [94707.323563] audit: type=1400 audit(1684183642.012:93): apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-debian-sid_</var/lib/lxc>" pid=547969 comm="apparmor_parser"
2023-05-15T21:47:22.085623+01:00 euler kernel: [94707.392045] lxcbr0: port 1(vethPUhTGL) entered disabled state
2023-05-15T21:47:22.085634+01:00 euler kernel: [94707.392996] device vethPUhTGL left promiscuous mode
2023-05-15T21:47:22.085635+01:00 euler kernel: [94707.393002] lxcbr0: port 1(vethPUhTGL) entered disabled state

and /var/log/kern.log, which seems very similar:

2023-05-15T21:47:21.645645+01:00 euler kernel: [94706.953337] audit: type=1400 a
udit(1684183641.640:92): apparmor="STATUS" operation="profile_load" profile="/us
r/bin/lxc-start" name="lxc-debian-sid_</var/lib/lxc>" pid=547941 comm="apparmor_
parser"
2023-05-15T21:47:21.741618+01:00 euler kernel: [94707.049379] lxcbr0: port 1(vet
hPUhTGL) entered blocking state
2023-05-15T21:47:21.741632+01:00 euler kernel: [94707.049385] lxcbr0: port 1(vet
hPUhTGL) entered disabled state
2023-05-15T21:47:21.741633+01:00 euler kernel: [94707.049489] device vethPUhTGL 
entered promiscuous mode
2023-05-15T21:47:21.741635+01:00 euler kernel: [94707.049738] lxcbr0: port 1(vet
hPUhTGL) entered blocking state
2023-05-15T21:47:21.741636+01:00 euler kernel: [94707.049741] lxcbr0: port 1(vet
hPUhTGL) entered forwarding state
2023-05-15T21:47:21.741637+01:00 euler kernel: [94707.049956] lxcbr0: port 1(vethPUhTGL) entered disabled state
2023-05-15T21:47:21.741637+01:00 euler kernel: [94707.050570] eth0: renamed from vethX4vupZ
2023-05-15T21:47:21.765623+01:00 euler kernel: [94707.072272] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
2023-05-15T21:47:21.765639+01:00 euler kernel: [94707.072351] IPv6: ADDRCONF(NETDEV_CHANGE): vethPUhTGL: link becomes ready
2023-05-15T21:47:21.765640+01:00 euler kernel: [94707.072481] lxcbr0: port 1(vethPUhTGL) entered blocking state
2023-05-15T21:47:21.765642+01:00 euler kernel: [94707.072487] lxcbr0: port 1(vethPUhTGL) entered forwarding state
2023-05-15T21:47:22.017893+01:00 euler kernel: [94707.323563] audit: type=1400 audit(1684183642.012:93): apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-debian-sid_</var/lib/lxc>" pid=547969 comm="apparmor_parser"
2023-05-15T21:47:22.085623+01:00 euler kernel: [94707.392045] lxcbr0: port 1(vethPUhTGL) entered disabled state
2023-05-15T21:47:22.085634+01:00 euler kernel: [94707.392996] device vethPUhTGL left promiscuous mode
2023-05-15T21:47:22.085635+01:00 euler kernel: [94707.393002] lxcbr0: port 1(vethPUhTGL) entered disabled state

(and I don't have a /var/log/audit).

Hmmm....

   Julian