From mboxrd@z Thu Jan 1 00:00:00 1970 From: Kay Sievers Date: Fri, 26 Mar 2004 17:39:58 +0000 Subject: Re: udev fails to add/remove devices Message-Id: <20040326173958.GB493@vrfy.org> List-Id: References: <20040326180855.37deecab.elfy666@gmx.de> In-Reply-To: <20040326180855.37deecab.elfy666@gmx.de> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable To: linux-hotplug@vger.kernel.org On Fri, Mar 26, 2004 at 06:08:55PM +0100, Oliver Paschke wrote: > Hi, >=20 > I have a problem with my current udev/hotplug configuration (023/2004_03_= 11) since i rebuilt my system (lfs-5.1_pre1, glibc-3.3 against 2.4.25 heade= rs). Udev worked perfectly before (lfs-3.1). >=20 > When I assign /sbin/udev as hotplugging-agent device-adding/-removal work= s the way it should, but when /proc/sys/kernel/hotplug points to /sbin/hotp= lug udev queues the events while hotplugging still works fine. Compiling ud= ev with or without klibc doesn't make a difference. All events are queued by udevd. /sbin/hotplug calls udevsend to send a message to udevd, which calls the real udev after a possibly reordering of the sequence numbers. What says your syslog after doing this as root. I've pasted in, what I get with a working setup. You can follow the udevsend->udevd->udev->udevd c= all: manual send without sequence number: ACTION=ADd DEVPATH=3D/test /sbin/udevsend test Mar 26 18:31:21 pim udevsend[2619]: main: daemon started Mar 26 18:31:21 pim udevd[2621]: udev_run: =3D> exec seq -1 [2622] workin= g at '/test' Mar 26 18:31:21 pim udevd[2621]: exec_queue_manager: moved seq -1 to runn= ing list Mar 26 18:31:21 pim udev[2622]: get_dirs: sysfs_path=3D'/sys' Mar 26 18:31:21 pim udev[2622]: parse_config_file: reading '/etc/udev/ude= v.conf' as config file Mar 26 18:31:21 pim udev[2622]: main: version 023 Mar 26 18:31:21 pim udev[2622]: udev_hotplug: looking at '/test' Mar 26 18:31:21 pim udev[2622]: udev_hotplug: not a block or class device Mar 26 18:31:21 pim udevd[2621]: udev_done: <=3D exec seq -1 came back =20 manual send with sequence number: SEQNUM=1000000 ACTION=ADd DEVPATH=3D/test /sbin/udevsend test Mar 26 18:34:03 pim udevsend[2623]: main: version 023 Mar 26 18:34:03 pim udevsend[2623]: main: subsystem =3D 'test' Mar 26 18:34:03 pim udevsend[2623]: main: DEVPATH =3D '/test' Mar 26 18:34:03 pim udevsend[2623]: main: ACTION =3D 'add' Mar 26 18:34:03 pim udevsend[2623]: main: SEQNUM =3D '1000000' Mar 26 18:34:03 pim udevd[2621]: msg_queue_insert: queued message seq 100= 0000 Mar 26 18:34:03 pim udevd[2621]: msg_queue_manager: msg queue manager, ne= xt expected is 0 Mar 26 18:34:03 pim udevd[2621]: msg_dump_queue: sequence 1000000 in queue Mar 26 18:34:03 pim udevd[2621]: msg_queue_manager: next event expires in= 5 seconds Mar 26 18:34:08 pim udevd[2621]: msg_queue_manager: msg queue manager, ne= xt expected is 0 Mar 26 18:34:08 pim udev[2624]: get_dirs: sysfs_path=3D'/sys' Mar 26 18:34:08 pim udev[2624]: parse_config_file: reading '/etc/udev/ude= v.conf' as config file Mar 26 18:34:08 pim udev[2624]: main: version 023 Mar 26 18:34:08 pim udev[2624]: udev_hotplug: looking at '/test' Mar 26 18:34:08 pim udevd[2621]: udev_run: =3D> exec seq 1000000 [2624] w= orking at '/test' Mar 26 18:34:08 pim udevd[2621]: exec_queue_manager: moved seq 1000000 to= running list Mar 26 18:34:08 pim udevd[2621]: msg_move_exec: moved seq 1000000 to exec= , next expected is 1000001 Mar 26 18:34:08 pim udev[2624]: udev_hotplug: not a block or class device Mar 26 18:34:08 pim udevd[2621]: udev_done: <=3D exec seq 1000000 came ba= ck > Any help would be appreciated, > thanks >=20 >=20 > Syslog debug-messages of a 'modprobe nvidia' call as example: > (nvidia module with sysfs patch - alsa behaves the same way..) >=20 > /sbin/hotplug: > Mar 26 16:53:08 pandora udevsend[1429]: main: version 023 > Mar 26 16:53:08 pandora udevsend[1429]: main: subsystem =3D 'nvidia' > Mar 26 16:53:08 pandora udevsend[1429]: main: DEVPATH =3D '/class/nvidia/= nvidiactl' > Mar 26 16:53:08 pandora udevsend[1429]: main: ACTION =3D 'add' > Mar 26 16:53:08 pandora udevsend[1429]: main: SEQNUM =3D '192' > Mar 26 16:53:08 pandora udevd[226]: msg_queue_insert: queued message seq = 192 > Mar 26 16:53:08 pandora udevd[226]: msg_queue_manager: msg queue manager,= next expected is 0 > Mar 26 16:53:08 pandora udevd[226]: msg_dump_queue: sequence 116 in queue > ... > Mar 26 16:53:08 pandora udevd[226]: msg_dump_queue: sequence 192 in queue > Mar 26 16:53:08 pandora udevd[226]: msg_queue_manager: next event expires= in 2907 seconds > Mar 26 16:53:08 pandora udevsend[1435]: main: version 023 > Mar 26 16:53:08 pandora udevsend[1435]: main: subsystem =3D 'nvidia' > Mar 26 16:53:08 pandora udevsend[1435]: main: DEVPATH =3D '/class/nvidia/= nvidia0' > Mar 26 16:53:08 pandora udevsend[1435]: main: ACTION =3D 'add' > Mar 26 16:53:08 pandora udevsend[1435]: main: SEQNUM =3D '193' > Mar 26 16:53:08 pandora udevd[226]: msg_queue_insert: queued message seq = 193 > Mar 26 16:53:08 pandora udevd[226]: msg_queue_manager: msg queue manager,= next expected is 0 > Mar 26 16:53:08 pandora udevd[226]: msg_dump_queue: sequence 116 in queue > ... > Mar 26 16:53:08 pandora udevd[226]: msg_dump_queue: sequence 193 in queue > Mar 26 16:53:08 pandora udevd[226]: msg_queue_manager: next event expires= in 2907 seconds Huh, what's this 2907 seconds? Sounds a bit too much :) > /sbin/udev: > Mar 26 16:50:59 pandora udev[1412]: get_dirs: sysfs_path=3D'/sys' > Mar 26 16:50:59 pandora udev[1412]: parse_config_file: reading '/etc/udev= /udev.conf' as config file > Mar 26 16:50:59 pandora udev[1412]: main: version 023 > Mar 26 16:50:59 pandora udev[1412]: udev_hotplug: looking at '/class/nvid= ia/nvidiactl' > ... > Mar 26 16:50:59 pandora udev[1413]: sleep_for_file: looking for '/sys/cla= ss/nvidia/nvidia0/dev' > Mar 26 16:51:00 pandora udev[1412]: sleep_for_file: looking for '/sys/cla= ss/nvidia/nvidiactl/dev' > Mar 26 16:51:00 pandora udev[1412]: get_class_dev: looking at '/sys/class= /nvidia/nvidiactl' > Mar 26 16:51:00 pandora udev[1412]: get_class_dev: class_dev->name=3D'nvi= diactl' > Mar 26 16:51:00 pandora udev[1412]: get_major_minor: dev=3D'195:255 ' > Mar 26 16:51:00 pandora udev[1412]: get_major_minor: found major=195, min= or%5 > Mar 26 16:51:00 pandora udev[1413]: sleep_for_file: looking for '/sys/cla= ss/nvidia/nvidia0/dev' > Mar 26 16:51:00 pandora udev[1413]: get_class_dev: looking at '/sys/class= /nvidia/nvidia0' > Mar 26 16:51:00 pandora udev[1413]: get_class_dev: class_dev->name=3D'nvi= dia0' > Mar 26 16:51:00 pandora udev[1413]: get_major_minor: dev=3D'195:0 ' > Mar 26 16:51:00 pandora udev[1413]: get_major_minor: found major=195, min= or=3D0 > Mar 26 16:51:00 pandora udev[1413]: sysfs_path_is_link: stat() failed=20 > Mar 26 16:51:00 pandora last message repeated 7 times > Mar 26 16:51:00 pandora udev[1413]: sysfs_open_device_path: Could not get= device 0000:01:00.0's driver=20 > Mar 26 16:51:00 pandora udev[1413]: get_sysfs_device: device 0000:01:00.0= is registered with bus 'pci' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: sysfs_device->pa= th=3D'/sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: sysfs_device->bu= s_id=3D'0000:01:00.0' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: sysfs_device->bu= s=3D'pci' > Mar 26 16:51:00 pandora udev[1413]: wait_for_device_to_initialize: lookin= g for file 'vendor' on bus 'pci' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: class_dev->name = =3D 'nvidia0' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: udev->kernel_nam= e =3D 'nvidia0' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: kernel_number=3D= '0' > Mar 26 16:51:00 pandora udev[1413]: namedev_name_device: name, 'nvidia0' = is going to have owner=3D'root', group=3D'video', mode =3D 0660 > Mar 26 16:51:00 pandora udev[1413]: udev_add_device: udevdb_add_dev faile= d, but we are going to try to create the node anyway. But remove might not = work properly for this device. > Mar 26 16:51:00 pandora udev[1413]: udev_add_device: name=3D'nvidia0' > Mar 26 16:51:00 pandora udev[1413]: creating device node '/dev/nvidia0' > Mar 26 16:51:00 pandora udev[1413]: make_node: chmod(/dev/nvidia0, 020660) > Mar 26 16:51:00 pandora udev[1413]: make_node: chown(/dev/nvidia0, 0, 12) > ... > Mar 26 16:51:00 pandora udev[1412]: sysfs_path_is_link: stat() failed=20 > Mar 26 16:51:00 pandora last message repeated 8 times > Mar 26 16:51:00 pandora udev[1412]: get_sysfs_device: timed out waiting f= or device symlink, continuing on anyway... > Mar 26 16:51:00 pandora udev[1412]: namedev_name_device: class_dev->name = =3D 'nvidiactl' > Mar 26 16:51:00 pandora udev[1412]: namedev_name_device: udev->kernel_nam= e =3D 'nvidiactl' > Mar 26 16:51:00 pandora udev[1412]: namedev_name_device: kernel_number=3D= '' > Mar 26 16:51:00 pandora udev[1412]: namedev_name_device: name, 'nvidiactl= ' is going to have owner=3D'root', group=3D'video', mode =3D 0660 > Mar 26 16:51:00 pandora udev[1412]: udev_add_device: udevdb_add_dev faile= d, but we are going to try to create the node anyway. But remove might not = work properly for this device. Are you sure, that you have removed to old db after upgrading? Normally 'make install' should do this. > Mar 26 16:51:00 pandora udev[1412]: udev_add_device: name=3D'nvidiactl' > Mar 26 16:51:00 pandora udev[1412]: creating device node '/dev/nvidiactl' > Mar 26 16:51:00 pandora udev[1412]: make_node: chmod(/dev/nvidiactl, 0206= 60) > Mar 26 16:51:00 pandora udev[1412]: make_node: chown(/dev/nvidiactl, 0, 1= 2) thanks, Kay ------------------------------------------------------- This SF.Net email is sponsored by: IBM Linux Tutorials Free Linux tutorial presented by Daniel Robbins, President and CEO of GenToo technologies. Learn everything from fundamentals to system administration.http://ads.osdn.com/?ad_id=1470&alloc_id638&op=3Dclick _______________________________________________ Linux-hotplug-devel mailing list http://linux-hotplug.sourceforge.net Linux-hotplug-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/linux-hotplug-devel