View previous topic :: View next topic |
Author |
Message |
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Sun Mar 31, 2013 1:45 pm Post subject: [solved worka.] udev-200 /lib/udev/accelerometer start delay |
|
|
Hi,
I did an udev upgrade to udev-200 yesterday and now my machine hangs for 60s at 'waiting for uevents to be processed ...'. I did what the news item suggested. I don't have a persistent-net.rules but the 80-net-name-slot.rules file is present. I wish to use the old naming scheme. My rc.log spits the following out (only relevant section):
Code: | libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.1/ata5/host4/target4:0:0/4:0:0:0/block/sr0'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda1'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda2'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda3'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda4'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda5'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda6'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda7'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop0'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop1'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop2'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop3'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop4'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop5'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop6'
libudev: udev_device_new_from_syspath: device 0x2578350 has devpath '/devices/virtual/block/loop7'
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.1/ata5/host4/target4:0:0/4:0:0:0/block/sr0'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda1'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda2'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda3'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda4'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda5'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda6'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda7'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop0'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop1'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop2'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop3'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop4'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop5'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop6'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2568aa0 has devpath '/devices/virtual/block/loop7'
libudev: udev_device_read_db: device 0x2568aa0 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.1/ata5/host4/target4:0:0/4:0:0:0/block/sr0'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda1'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda2'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda3'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda4'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda5'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda6'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda7'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop0'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop1'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop2'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop3'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop4'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop5'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop6'
libudev: udev_device_new_from_syspath: device 0x2549760 has devpath '/devices/virtual/block/loop7'
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.1/ata5/host4/target4:0:0/4:0:0:0/block/sr0'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda1'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda2'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda3'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda4'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda5'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda6'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/pci0000:00/0000:00:1f.2/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda7'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop0'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop1'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop2'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop3'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop4'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop5'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop6'
libudev: udev_device_read_db: device 0x2569970 filled with db file data
libudev: udev_device_new_from_syspath: device 0x2569970 has devpath '/devices/virtual/block/loop7'
libudev: udev_device_read_db: device 0x2569970 filled with db file data |
Here is some information about my kernel: (it is the same issue with either linux-3.8 and linux-3.9)
Code: | zcat /proc/config.gz | grep DEVTMPFS
CONFIG_DEVTMPFS=y
CONFIG_DEVTMPFS_MOUNT=y
|
Code: | zcat /proc/config.gz | grep FIRMWARE
# CONFIG_PREVENT_FIRMWARE_BUILD is not set
# CONFIG_FIRMWARE_IN_KERNEL is not set
CONFIG_EXTRA_FIRMWARE=""
# CONFIG_DRM_LOAD_EDID_FIRMWARE is not set
# CONFIG_FIRMWARE_EDID is not set
CONFIG_FIRMWARE_MEMMAP=y
# CONFIG_GOOGLE_FIRMWARE is not set |
Is there any way to get rid of this useless waiting? I don't like to wait for my laptop for 60s. Any help is greatly appreciated.
Greetings morpheus
Last edited by morpheus2051 on Mon Apr 08, 2013 12:20 pm; edited 2 times in total |
|
Back to top |
|
|
depontius Advocate
Joined: 05 May 2004 Posts: 3509
|
Posted: Mon Apr 01, 2013 12:49 pm Post subject: |
|
|
I'm not sure that this is what's happening, but this morning I did updates and saw the sys-fs.udev-200, and noticed that by default the USE flag "firmware-loader" was set to off. Reading the USE descriptions, it said that the userspace firmware loader is deprecated in favor of the kernel firmware loader present in the 3.8+ kernels.
Looking at your kernel configs, you've got the kernel firmware loader turned off. I would suggest either rebuilding your kernel with "FIRMWARE_IN_KERNEL" set, or re-emerge udev with USE="firmware-loader". _________________ .sigs waste space and bandwidth |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Mon Apr 01, 2013 11:15 pm Post subject: |
|
|
With the current configuration I have the firmware-loader use flag enabled. I will try out your suggestion and will get back with the results. |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Tue Apr 02, 2013 7:53 am Post subject: |
|
|
With FIRMWARE_IN_KERNEL and -firmware-loader this thing boots faster but still the udevadm settle aka 'waiting for uevents to be processed ...' process takes the most time in booting. It takes more time than loading kde. There has to be something wrong. Is udev able to spit out times and things it is doing? The udev log level debug does not help as seen above.
My other two upgraded gentoo machines do not show this problem. Software wise they are all almost identical. |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Tue Apr 02, 2013 4:05 pm Post subject: |
|
|
Now I put
Code: | udev.log-priority=debug udev.children-max=1 |
on the kernel command line. The output scrolls to fast by to read it. How can I record that output? |
|
Back to top |
|
|
SamuliSuominen Retired Dev
Joined: 30 Sep 2005 Posts: 2133 Location: Finland
|
Posted: Tue Apr 02, 2013 4:10 pm Post subject: |
|
|
morpheus2051 wrote: | Now I put
Code: | udev.log-priority=debug udev.children-max=1 |
on the kernel command line. The output scrolls to fast by to read it. How can I record that output? |
I believe you can edit /etc/udev/udev.conf to set the debug level, and then also /etc/conf.d/udev and enable both udev_debug="YES" and udev_monitor="YES" and logs will appear to dmesg/messages, and /run/udev*.log |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Wed Apr 03, 2013 8:14 am Post subject: |
|
|
Thanks for the tip ssuominen! I think this is the relevant part of the log:
Code: | Apr 3 09:58:43 LAPPI [ 25.159340] udevd[870]: device 0x104a1e0 has devpath '/devices/platform/lis3lv02d'
Apr 3 09:58:43 LAPPI [ 25.159365] udevd[870]: device 0x10507e0 has devpath '/devices/platform'
Apr 3 09:58:43 LAPPI [ 25.159441] udevd[870]: IMPORT builtin 'path_id' /lib64/udev/rules.d/60-persistent-input.rules:31
Apr 3 09:58:43 LAPPI [ 25.159460] udevd[870]: LINK 'input/by-path/platform-lis3lv02d-event' /lib64/udev/rules.d/60-persistent-input.rules:36
Apr 3 09:58:43 LAPPI [ 25.159473] udevd[870]: IMPORT 'accelerometer /devices/platform/lis3lv02d/input/input6/event6' /lib64/udev/rules.d/61-accelerometer.rules:3
Apr 3 09:58:43 LAPPI [ 25.159787] udevd[919]: starting 'accelerometer /devices/platform/lis3lv02d/input/input6/event6'
Apr 3 09:58:43 LAPPI [ 28.162049] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 31.165133] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 34.168209] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 37.171292] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 40.174373] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 43.177456] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 46.180538] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 49.183615] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 52.186695] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 55.189771] udevd[851]: worker [870] /devices/platform/lis3lv02d/input/input6/event6 timeout; kill it
Apr 3 09:58:43 LAPPI [ 55.189792] udevd[851]: seq 1242 '/devices/platform/lis3lv02d/input/input6/event6' killed
Apr 3 09:58:43 LAPPI [ 55.189887] udevd[851]: seq 1242 done with -64
Apr 3 09:58:43 LAPPI [ 55.189911] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 55.190169] udevd[851]: worker [870] exit
Apr 3 09:58:43 LAPPI [ 55.190204] udevd[851]: worker [870] terminated by signal 9 (Killed)
Apr 3 09:58:43 LAPPI [ 55.190211] udevd[851]: worker [870] cleaned up |
The whole log can be found here: http://pastebin.com/L9ucMpQg
The accelerometer is part of the HP Drive Guard 3D Protection system. I tried to blacklist the module but nothing changed. Has somebody a suggestion how to fix this?
Greetings
morpheus |
|
Back to top |
|
|
SamuliSuominen Retired Dev
Joined: 30 Sep 2005 Posts: 2133 Location: Finland
|
Posted: Wed Apr 03, 2013 9:27 am Post subject: |
|
|
morpheus2051 wrote: | Thanks for the tip ssuominen! I think this is the relevant part of the log:
Code: | Apr 3 09:58:43 LAPPI [ 25.159340] udevd[870]: device 0x104a1e0 has devpath '/devices/platform/lis3lv02d'
Apr 3 09:58:43 LAPPI [ 25.159365] udevd[870]: device 0x10507e0 has devpath '/devices/platform'
Apr 3 09:58:43 LAPPI [ 25.159441] udevd[870]: IMPORT builtin 'path_id' /lib64/udev/rules.d/60-persistent-input.rules:31
Apr 3 09:58:43 LAPPI [ 25.159460] udevd[870]: LINK 'input/by-path/platform-lis3lv02d-event' /lib64/udev/rules.d/60-persistent-input.rules:36
Apr 3 09:58:43 LAPPI [ 25.159473] udevd[870]: IMPORT 'accelerometer /devices/platform/lis3lv02d/input/input6/event6' /lib64/udev/rules.d/61-accelerometer.rules:3
Apr 3 09:58:43 LAPPI [ 25.159787] udevd[919]: starting 'accelerometer /devices/platform/lis3lv02d/input/input6/event6'
Apr 3 09:58:43 LAPPI [ 28.162049] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 31.165133] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 34.168209] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 37.171292] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 40.174373] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 43.177456] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 46.180538] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 49.183615] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 52.186695] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 55.189771] udevd[851]: worker [870] /devices/platform/lis3lv02d/input/input6/event6 timeout; kill it
Apr 3 09:58:43 LAPPI [ 55.189792] udevd[851]: seq 1242 '/devices/platform/lis3lv02d/input/input6/event6' killed
Apr 3 09:58:43 LAPPI [ 55.189887] udevd[851]: seq 1242 done with -64
Apr 3 09:58:43 LAPPI [ 55.189911] udevd[851]: validate module index
Apr 3 09:58:43 LAPPI [ 55.190169] udevd[851]: worker [870] exit
Apr 3 09:58:43 LAPPI [ 55.190204] udevd[851]: worker [870] terminated by signal 9 (Killed)
Apr 3 09:58:43 LAPPI [ 55.190211] udevd[851]: worker [870] cleaned up |
The whole log can be found here: http://pastebin.com/L9ucMpQg
The accelerometer is part of the HP Drive Guard 3D Protection system. I tried to blacklist the module but nothing changed. Has somebody a suggestion how to fix this?
Greetings
morpheus |
EDIT:
Option 1, the most likely reason) The changed worker code. Set udev.children-max=500 to your kernel command line in at grub / grub's config.
Some more options that I have serious doubts about below. Please just try the udev.children-max=500 before anything else.
Option 2, poor workaround) What if you select your own modules through /etc/conf.d/modules and set rc_coldplug="YES" in /etc/conf.d/udev?
Option 3, poor workaround) What if you symlink /etc/udev/rules.d/61-accelerometer.rules to /dev/null to override it, or just `touch` it so it'll be empty file. That will override /lib/udev/rules.d/61-accelerometer.rules.
Option 4, well, we could do this) And I'm even more intrested in knowing if this patch fixes the problem without overriding/removing/using rc_coldplug/... so we can get it fixed for everyone:
Code: |
# wget "http://cgit.freedesktop.org/systemd/systemd/patch/src/udev/accelerometer/accelerometer.c?id=7a2262061252a33f6f0a009e89556fbee5b0cb41" -O foobar.patch
|
Copy it to the files/ directory of /usr/portage/sys-fs/udev/files/ and apply it using line "epatch foobar.patch" in the ebuild's src_prepare() function, where inside the function shouldn't matter.
Or what if the problem is in the actual hardware and it simply wasn't enabled before as udev didn't have this support before?! That'd be bad. Lets hope it doesn't come down to that. |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Wed Apr 03, 2013 12:47 pm Post subject: |
|
|
Option 1) Setting udev.children-max made no noticeable difference.
Option 2) I did not test this option
Option 3) Overriding 61-accelerometer.rules makes this problem with udev go away.
Option 4) Applied the patch. It did not help.
I am willing to test this further. Are there more patches I can try? |
|
Back to top |
|
|
SamuliSuominen Retired Dev
Joined: 30 Sep 2005 Posts: 2133 Location: Finland
|
Posted: Wed Apr 03, 2013 1:32 pm Post subject: |
|
|
morpheus2051 wrote: | Option 1) Setting udev.children-max made no noticeable difference. |
I don't really doubt you got it wrong, or not, but you can still verify using /proc/cmdline if it was passed or not.
If you compare your old log (the one you pasted earlier in this thread) to the current one, did the "lots of maximum number (12) of children reached" warnings go away?
morpheus2051 wrote: | Option 3) Overriding 61-accelerometer.rules makes this problem with udev go away. |
Nice, at least it's "solved" for you now temporarily!
morpheus2051 wrote: | I am willing to test this further. Are there more patches I can try? |
It would help to know when this problem was introduced, as in, if it's a regression or not, so testing 199-r1, then 198-r6, and then 197-r8 would help too to narrow the possibilities down, so
I can then look what happened around the code between the releases.
All of these versions are "safe to use" and I left them in Portage for exactly this (testing) reason temporarily.
EDIT:
You can also make use of strace. Example:
Code: |
# strace -o filename.log -f /lib/udev/accelerometer <devicenode>
|
Replace <devicenode> with something input6 (as your log refers) in /dev/input/ (for that to appear you likely have to remove the created "empty" file from /etc/udev/rules.d, I'm not sure)
Would you be kind to change the subject of this thread to say something like "sys-fs/udev-200: /lib/udev/accelerometer causing startup delay"? I mean, we have had 3 different types of startup delays recently, and I've already managed to mix them up few times, so others will too. |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Wed Apr 03, 2013 7:25 pm Post subject: |
|
|
Option 1) I meant it did not make any difference speed wise. Of course the warnings went away. For now I leave that option on.
With udev.children-max=500 option enabled I tested the following udev versions:
udev-200 (for reference reasons): boot is delayed
Log: http://pastebin.com/XNz8kRLH
udev-199-r1: boot is delayed
Log: http://pastebin.com/BGfCVF9Y
udev-198-r6: boot is delayed
Log: http://pastebin.com/LTh9T6GE
udev-197-r8: boot is not delayed
Log: http://pastebin.com/zivx2eRM
So some change between udev-197-r8 and 198-r6 is causing the delay.
I will post the strace results some time later.
Last edited by morpheus2051 on Wed Apr 03, 2013 8:07 pm; edited 1 time in total |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Wed Apr 03, 2013 8:06 pm Post subject: |
|
|
Result of strace with udev-200 and 61-accelerometer.rules file removed:
Code: | 2618 execve("/lib/udev/accelerometer", ["/lib/udev/accelerometer", "/devices/platform/lis3lv02d/inpu"...], [/* 40 vars */]) = 0
2618 brk(0) = 0x24d4000
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836e000
2618 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
2618 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
2618 fstat(3, {st_mode=S_IFREG|0644, st_size=195116, ...}) = 0
2618 mmap(NULL, 195116, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7feb9833e000
2618 close(3) = 0
2618 open("/lib64/libudev.so.1", O_RDONLY|O_CLOEXEC) = 3
2618 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200V\0\0\0\0\0\0"..., 832) = 832
2618 fstat(3, {st_mode=S_IFREG|0755, st_size=79728, ...}) = 0
2618 mmap(NULL, 2177128, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7feb97f3a000
2618 mprotect(0x7feb97f4c000, 2097152, PROT_NONE) = 0
2618 mmap(0x7feb9814c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12000) = 0x7feb9814c000
2618 close(3) = 0
2618 open("/lib64/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
2618 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20h\0\0\0\0\0\0"..., 832) = 832
2618 fstat(3, {st_mode=S_IFREG|0755, st_size=1001656, ...}) = 0
2618 mmap(NULL, 3096872, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7feb97c45000
2618 mprotect(0x7feb97d39000, 2093056, PROT_NONE) = 0
2618 mmap(0x7feb97f38000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xf3000) = 0x7feb97f38000
2618 close(3) = 0
2618 open("/lib64/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
2618 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200(\0\0\0\0\0\0"..., 832) = 832
2618 fstat(3, {st_mode=S_IFREG|0755, st_size=35656, ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9833d000
2618 mmap(NULL, 2133016, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7feb97a3c000
2618 mprotect(0x7feb97a44000, 2093056, PROT_NONE) = 0
2618 mmap(0x7feb97c43000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7feb97c43000
2618 close(3) = 0
2618 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
2618 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 G\2\0\0\0\0\0"..., 832) = 832
2618 fstat(3, {st_mode=S_IFREG|0755, st_size=1720536, ...}) = 0
2618 mmap(NULL, 3832928, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7feb97694000
2618 mprotect(0x7feb97833000, 2093056, PROT_NONE) = 0
2618 mmap(0x7feb97a32000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19e000) = 0x7feb97a32000
2618 mmap(0x7feb97a38000, 15456, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7feb97a38000
2618 close(3) = 0
2618 open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
2618 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P|\0\0\0\0\0\0"..., 832) = 832
2618 fstat(3, {st_mode=S_IFREG|0755, st_size=135104, ...}) = 0
2618 mmap(NULL, 2212784, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7feb97477000
2618 mprotect(0x7feb9748f000, 2093056, PROT_NONE) = 0
2618 mmap(0x7feb9768e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0x7feb9768e000
2618 mmap(0x7feb97690000, 13232, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7feb97690000
2618 close(3) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9833c000
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9833b000
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9833a000
2618 arch_prctl(ARCH_SET_FS, 0x7feb9833b700) = 0
2618 mprotect(0x7feb97a32000, 16384, PROT_READ) = 0
2618 mprotect(0x7feb9768e000, 4096, PROT_READ) = 0
2618 mprotect(0x7feb97c43000, 4096, PROT_READ) = 0
2618 mprotect(0x7feb97f38000, 4096, PROT_READ) = 0
2618 mprotect(0x7feb9814c000, 4096, PROT_READ) = 0
2618 mprotect(0x606000, 4096, PROT_READ) = 0
2618 mprotect(0x7feb9836f000, 4096, PROT_READ) = 0
2618 munmap(0x7feb9833e000, 195116) = 0
2618 set_tid_address(0x7feb9833b9d0) = 2618
2618 set_robust_list(0x7feb9833b9e0, 24) = 0
2618 futex(0x7fffd12b8ccc, FUTEX_WAKE_PRIVATE, 1) = 0
2618 futex(0x7fffd12b8ccc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1, NULL, 7feb9833b700) = -1 EAGAIN (Resource temporarily unavailable)
2618 rt_sigaction(SIGRTMIN, {0x7feb9747e6b0, [], SA_RESTORER|SA_SIGINFO, 0x7feb97487bf0}, NULL, 8) = 0
2618 rt_sigaction(SIGRT_1, {0x7feb9747e740, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7feb97487bf0}, NULL, 8) = 0
2618 rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
2618 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
2618 brk(0) = 0x24d4000
2618 brk(0x24f5000) = 0x24f5000
2618 open("/etc/udev/udev.conf", O_RDONLY|O_CLOEXEC) = 3
2618 fcntl(3, F_GETFD) = 0x1 (flags FD_CLOEXEC)
2618 fstat(3, {st_mode=S_IFREG|0644, st_size=44, ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836d000
2618 read(3, "# see udev(7) for details\n\n#udev"..., 4096) = 44
2618 read(3, "", 4096) = 0
2618 close(3) = 0
2618 munmap(0x7feb9836d000, 4096) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6", 0x7fffd12b68e0, 1024) = -1 EINVAL (Invalid argument)
2618 stat("/sys//devices/platform/lis3lv02d/input/input6/event6", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6", 0x7fffd12b63f0, 1024) = -1 EINVAL (Invalid argument)
2618 stat("/sys//devices/platform/lis3lv02d/input/input6/event6", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6/subsystem", "../../../../../../class/input", 1024) = 29
2618 openat(AT_FDCWD, "/sys//devices/platform/lis3lv02d/input/input6/event6", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
2618 getdents(3, /* 7 entries */, 32768) = 200
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6/power", 0x7fffd12b63b0, 1024) = -1 EINVAL (Invalid argument)
2618 stat("/sys//devices/platform/lis3lv02d/input/input6/event6/power", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6/power/subsystem", 0x7fffd12b6a60, 1024) = -1 ENOENT (No such file or directory)
2618 openat(AT_FDCWD, "/sys//devices/platform/lis3lv02d/input/input6/event6/power", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
2618 getdents(4, /* 7 entries */, 32768) = 248
2618 getdents(4, /* 0 entries */, 32768) = 0
2618 close(4) = 0
2618 getdents(3, /* 0 entries */, 32768) = 0
2618 close(3) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6", 0x7fffd12b68e0, 1024) = -1 EINVAL (Invalid argument)
2618 stat("/sys//devices/platform/lis3lv02d/input/input6/event6", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
2618 open("/sys//devices/platform/lis3lv02d/input/input6/event6/uevent", O_RDONLY|O_CLOEXEC) = 3
2618 fstat(3, {st_mode=S_IFREG|0644, st_size=4096, ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836d000
2618 read(3, "MAJOR=13\nMINOR=70\nDEVNAME=input/"..., 4096) = 39
2618 read(3, "", 4096) = 0
2618 close(3) = 0
2618 munmap(0x7feb9836d000, 4096) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6/power", 0x7fffd12b68e0, 1024) = -1 EINVAL (Invalid argument)
2618 stat("/sys//devices/platform/lis3lv02d/input/input6/event6/power", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
2618 open("/sys//devices/platform/lis3lv02d/input/input6/event6/uevent", O_RDONLY|O_CLOEXEC) = 3
2618 fstat(3, {st_mode=S_IFREG|0644, st_size=4096, ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836d000
2618 read(3, "MAJOR=13\nMINOR=70\nDEVNAME=input/"..., 4096) = 39
2618 read(3, "", 4096) = 0
2618 close(3) = 0
2618 munmap(0x7feb9836d000, 4096) = 0
2618 readlink("/sys//devices/platform/lis3lv02d/input/input6/event6/subsystem", "../../../../../../class/input", 1024) = 29
2618 open("/run/udev/data/c13:70", O_RDONLY|O_CLOEXEC) = 3
2618 fstat(3, {st_mode=S_IFREG|0644, st_size=151, ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836d000
2618 read(3, "S:input/by-path/platform-lis3lv0"..., 4096) = 151
2618 read(3, "", 4096) = 0
2618 close(3) = 0
2618 munmap(0x7feb9836d000, 4096) = 0
2618 open("/dev/input/event6", O_RDONLY) = 3
2618 read(3, "K\213\\Q\0\0\0\0\212\217\16\0\0\0\0\0\3\0\0\0\312\377\377\377K\213\\Q\0\0\0\0"..., 1536) = 144
2618 read(3, "L\213\\Q\0\0\0\0\302\364\f\0\0\0\0\0\3\0\2\0\362\3\0\0L\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "L\213\\Q\0\0\0\0\t/\17\0\0\0\0\0\3\0\2\0\364\3\0\0L\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "M\213\\Q\0\0\0\0\370\264\7\0\0\0\0\0\3\0\2\0\362\3\0\0M\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "M\213\\Q\0\0\0\0\221B\r\0\0\0\0\0\3\0\2\0\364\3\0\0M\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "O\213\\Q\0\0\0\0+\202\t\0\0\0\0\0\3\0\2\0\362\3\0\0O\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "P\213\\Q\0\0\0\0\206\352\0\0\0\0\0\0\3\0\2\0\364\3\0\0P\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "h\213\\Q\0\0\0\0\375\321\2\0\0\0\0\0\3\0\2\0\361\3\0\0h\213\\Q\0\0\0\0"..., 1536) = 48
2618 read(3, "h\213\\Q\0\0\0\0h\354\3\0\0\0\0\0\3\0\1\0\367\377\377\377h\213\\Q\0\0\0\0"..., 1536) = 48
2618 close(3) = 0
2618 fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 1), ...}) = 0
2618 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb9836d000
2618 write(1, "ID_INPUT_ACCELEROMETER_ORIENTATI"..., 45) = 45
2618 exit_group(0) = ?
2618 +++ exited with 0 +++ |
|
|
Back to top |
|
|
SamuliSuominen Retired Dev
Joined: 30 Sep 2005 Posts: 2133 Location: Finland
|
Posted: Tue Apr 09, 2013 11:41 am Post subject: |
|
|
Try udev-201 if the delay is solved.
If not, I would suggest opening a bug at http://bugs.freedesktop.org/ against the systemd target with the information you have collected here.
I would leave out distribution specific unnecessary information out from the upstream report, it's not relevant to this problem and would only cause futher confusion. |
|
Back to top |
|
|
morpheus2051 Tux's lil' helper
Joined: 07 May 2006 Posts: 95
|
Posted: Fri Apr 19, 2013 7:55 pm Post subject: |
|
|
Sorry for the delayed answer. udev-201 does not solve the delay. I will file a bug report when I have the time. |
|
Back to top |
|
|
feiticeir0 Apprentice
Joined: 13 Jul 2005 Posts: 288 Location: Castelo Branco, Portugal
|
Posted: Fri May 17, 2013 2:27 pm Post subject: |
|
|
Quote: | Posted: Fri Apr 19, 2013 7:55 pm Post subject:
Sorry for the delayed answer. udev-201 does not solve the delay. I will file a bug report when I have the time. |
Morpheus2051,
have you submitted the bug yet ?
I'm having the same problem, but my machines hangs for ever, and not for 60s...
I've enabled udev logging, but my battery is dead and i need to get home so I can connect the laptop to power.
If you have already filled a bug report, can you please send me the bug id so I can also fill in ?
Thank you
Cheers,
Bruno Santos _________________ Do It With Rhythm |
|
Back to top |
|
|
|
|
You cannot post new topics in this forum You cannot reply to topics in this forum You cannot edit your posts in this forum You cannot delete your posts in this forum You cannot vote in polls in this forum
|
|