From mboxrd@z Thu Jan 1 00:00:00 1970 From: Jim Paris Date: Sun, 22 Apr 2012 14:11:06 +0000 Subject: Re: udev missing events? Message-Id: <20120422141106.GA3021@psychosis.jim.sh> List-Id: References: <20120422043655.GA27861@psychosis.jim.sh> In-Reply-To: MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable To: "Eric W. Biederman" Cc: linux-hotplug@vger.kernel.org, linux-kernel@vger.kernel.org Eric W. Biederman wrote: > Jim Paris wrote: >=20 > >(cc'd Eric and Milan because 5f71a296 and ebf4127c might be related) > > > >I'm trying to track down a problem that started with virt-manager not > >being able to connect to libvirtd. Long story short, the problem is > >that "udevadm settle" is timing out, with no events in the udev queue. > > > >(I know it's bad for libvirt to rely on "udevadm settle", but it seems > >that this is exposing some other problem). > > > >This is with 3.2.14 from Debian. > > > >I can trigger the problem easily by just starting libvirtd and killing > >it. Then, the counters are stuck here: > > > > # cat /sys/kernel/uevent_seqnum > > 13593 > > # od -t d2 /dev/.udev/queue.bin | head -1 > > 0000000 13592 > > > >During the libvirtd startup, I ran "udevadm monitor", which seems to > >indicate that 13593 never made it to udev: > > > > # udevadm monitor --kernel --property > > monitor will print the received events for: > > KERNEL - the kernel uevent > > =20 > >KERNEL[537903.765581] add /devices/virtual/net/lo/queues/rx-0 > >(queues) > > ACTION=ADd > > DEVPATH=3D/devices/virtual/net/lo/queues/rx-0 > > SEQNUM=13589 > > SUBSYSTEM=3Dqueues > > UDEV_LOG=3D3 > > =20 > >KERNEL[537903.765683] add /devices/virtual/net/lo/queues/tx-0 > >(queues) > > ACTION=ADd > > DEVPATH=3D/devices/virtual/net/lo/queues/tx-0 > > SEQNUM=13590 > > SUBSYSTEM=3Dqueues > > UDEV_LOG=3D3 > > =20 > >KERNEL[537903.844154] remove /devices/virtual/net/lo/queues/rx-0 > >(queues) > > ACTION=3Dremove > > DEVPATH=3D/devices/virtual/net/lo/queues/rx-0 > > SEQNUM=13591 > > SUBSYSTEM=3Dqueues > > UDEV_LOG=3D3 > > =20 > >KERNEL[537903.844192] remove /devices/virtual/net/lo/queues/tx-0 > >(queues) > > ACTION=3Dremove > > DEVPATH=3D/devices/virtual/net/lo/queues/tx-0 > > SEQNUM=13592 > > SUBSYSTEM=3Dqueues > > UDEV_LOG=3D3 > > > >To try to track it further, I wrote a systemtap script (available at > >http://jim.sh/~jim/tmp/monitor.stp). It dumps the result of > >netlink_broadcast_filtered at lib/kobject_uevent.c:248, and then dumps > >the uevent_seqnum and environment at the end of the same function. > >It seems to show that netlink_broadcast_filter is failing to send out > >the event, with -ESRCH: > > > > $ sudo ./monitor.stp=20 > > begin > > ----- > > netlink_broadcast_filtered: -3 (ESRCH) > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13588 > > "ACTION=ADd" > > "DEVPATH=3D/devices/virtual/net/lo" > > "SUBSYSTEM=3Dnet" > > "INTERFACE=3Dlo" > > "IFINDEXh" > > "SEQNUM=13588" > > ----- > > netlink_broadcast_filtered: 0x0 > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13589 > > "ACTION=ADd" > > "DEVPATH=3D/devices/virtual/net/lo/queues/rx-0" > > "SUBSYSTEM=3Dqueues" > > "SEQNUM=13589" > > ----- > > netlink_broadcast_filtered: 0x0 > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13590 > > "ACTION=ADd" > > "DEVPATH=3D/devices/virtual/net/lo/queues/tx-0" > > "SUBSYSTEM=3Dqueues" > > "SEQNUM=13590" > > ----- > > netlink_broadcast_filtered: 0x0 > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13591 > > "ACTION=3Dremove" > > "DEVPATH=3D/devices/virtual/net/lo/queues/rx-0" > > "SUBSYSTEM=3Dqueues" > > "SEQNUM=13591" > > ----- > > netlink_broadcast_filtered: 0x0 > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13592 > > "ACTION=3Dremove" > > "DEVPATH=3D/devices/virtual/net/lo/queues/tx-0" > > "SUBSYSTEM=3Dqueues" > > "SEQNUM=13592" > > ----- > > netlink_broadcast_filtered: -3 (ESRCH) > > netlink_broadcast_filtered: -3 (ESRCH) > > event was: > > uevent_seqnum: 13593 > > "ACTION=3Dremove" > > "DEVPATH=3D/devices/virtual/net/lo" > > "SUBSYSTEM=3Dnet" > > "INTERFACE=3Dlo" > > "IFINDEXh" > > "SEQNUM=13593" > > ----- > > ^Cend > > > > > >Is it expected that those events would not be sent like that? >=20 > Roughly. Events for network devices are only delivered to sockets in the = same netwoerk namespace. >=20 > So you really shouldn't see much of an event for the creationof a network= namespace. >=20 > >If not, is there something else I can do to track this further? >=20 > >Or, if that's expected behavior, is there anything "udevadm settle" > >can do to avoid the timeout? >=20 > I don't think so. Udev for the host should not see events for things tha= t happen inside a container. > > I am a little mystified that you see as much of the add of lo as you do i= n the udem monitor command. >=20 > I am infering what is going on with libvirt and your machine and assuming= containers are involved because of the additions and removals of lo. I'm not using them on purpose, but it's caused by a probing clone() in libvirt's lxcContainerAavilable, followed by a "ip link set lo netns -1" in lxcCheckNetNsSupport. It can be recreated with just: #include #include static int dummy(void *argv) { _exit(0); } main() { char stack[4096]; clone(dummy, stack+4096, CLONE_NEWNET, NULL); wait(); system("ip link set lo netns -1"); } Running that program causes "udevadm settle" to stop working due to the filtered events. -jim