These appear to be the important lines from the console output: [ 49.256810] qla1280: QLA1040 found [ 49.331029] qla1280 0000:01:00.0: firmware: requesting qlogic/1040.bin udevd[318]: msg_queue_insert: seq 249 queued, 'add' 'pci' udevd[318]: udev_event_run: seq 249 forked, pid [344], 'add' 'pci', 2 seconds old udevd-event[344]: run_program: '/sbin/modprobe --use-blacklist pci:v00001077d00001020sv00000000sd00000000bc01sc00i00' udevd[318]: msg_queue_insert: seq 252 queued, 'add' 'pci' udevd[318]: udev_event_run: seq 252 forked, pid [350], 'add' 'pci', 1 seconds old udevd-event[350]: run_program: '/sbin/modprobe --use-blacklist pci:v00001077d00001020sv00000000sd00000000bc01sc00i00' udevd[318]: msg_queue_insert: seq 257 queued, 'add' 'pci' udevd[318]: udev_event_run: seq 257 forked, pid [360], 'add' 'pci', 1 seconds old udevd-event[360]: run_program: '/sbin/modprobe --use-blacklist pci:v00001077d00001020sv00000000sd00000000bc01sc00i00' [ 109.435490] Failed to load image "qlogic/1040.bin" err -2 [ 109.640568] qla1280: QLA1040 found on PCI bus 2, dev 0 [ 109.719670] qla1280 0000:02:00.0: firmware: requesting qlogic/1040.bin [ 169.814366] Failed to load image "qlogic/1040.bin" err -2 [ 170.043858] qla1280: QLA1040 found on PCI bus 4, dev 0 [ 170.121983] qla1280 0001:04:00.0: firmware: requesting qlogic/1040.bin udevd[318]: msg_queue_insert: seq 397 queued, 'add' 'firmware' udevd[318]: udev_event_run: seq 397 forked, pid [514], 'add' 'firmware', 0 seconds old udevd-event[514]: run_program: 'firmware.agent' udevd-event[514]: run_program: '/lib/udev/firmware.agent' (stderr) '/sys//devices/pci0000:00/0000:00:04.0/0000:01:00.0/firmware/0000 udevd-event[514]: run_program: '/lib/udev/firmware.agent' returned with status 1 udevd-event[514]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[514]: udev_event_run: seq 397 finished with -1 udevd[318]: udev_done: seq 397, pid [514] exit with 1, 1 seconds old udevd[318]: msg_queue_insert: seq 411 queued, 'remove' 'firmware' udevd[318]: udev_event_run: seq 411 forked, pid [530], 'remove' 'firmware', 0 seconds old udevd[318]: msg_queue_insert: seq 412 queued, 'add' 'firmware' [ 186.302638] scsi(3:0): Resettin udevd-event[530]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[530]: udev_event_run: seq 411 finished with 0 udevd-event[532]: run_program: 'firmware.agent' udevd[318]: udev_event_run: seq 412 forked, pid [532], 'add' 'firmware', 0 seconds old udevd[318]: udev_done: seq 411, pid [530] exit with 0, 0 seconds old udevd[318]: msg_queue_insert: seq 413 queued, 'remove' 'firmware' udevd[318]: udev_event_run: seq 413 forked, pid [534], 'remove' 'firmware', 0 seconds old udevd[318]: msg_queue_insert: seq 414 queued, 'add' 'firmware' udevd[318]: udev_event_run: seq 414 forked, pid [535], 'add' 'firmware', 0 seconds old udevd-event[534]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[534]: udev_event_run: seq 413 finished with 0 udevd-event[535]: run_program: 'firmware.agent' udevd-event[535]: run_program: '/lib/udev/firmware.agent' returned with status 0 udevd-event[535]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[535]: udev_event_run: seq 414 finished with 0 udevd-event[532]: run_program: '/lib/udev/firmware.agent' (stderr) '/sys//devices/pci0000:00/0000:00:05.0/0000:02:00.0/firmware/0000 udevd-event[532]: run_program: '/lib/udev/firmware.agent' returned with status 1 udevd-event[532]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[532]: udev_event_run: seq 412 finished with -1 [ 189.365137] scsi3 : QLogic QLA1040 P [ 189.365137] Firmware version: 7.65.06, Driver version 3.26 udevd[318]: udev_done: seq 412, pid [532] exit with 1, 1 seconds old udevd[318]: udev_done: seq 413, pid [534] exit with 0, 1 seconds old udevd[318]: udev_done: seq 414, pid [535] exit with 0, 1 seconds old udevd-event[360]: run_program: '/sbin/modprobe' returned with status 0 udevd-event[360]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[360]: udev_event_run: seq 257 finished with 0 udevd-event[350]: run_program: '/sbin/modprobe' returned with status 0 udevd-event[350]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[350]: udev_event_run: seq 252 finished with 0 udevd-event[344]: run_program: '/sbin/modprobe' returned with status 0 udevd-event[344]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[344]: udev_event_run: seq 249 finished with 0 udevd[318]: udev_done: seq 249, pid [344] exit with 0, 148 seconds old udevd[318]: udev_done: seq 252, pid [350] exit with 0, 146 seconds old udevd[318]: udev_done: seq 257, pid [360] exit with 0, 143 seconds old udevd[318]: msg_queue_insert: seq 423 queued, 'remove' 'firmware' udevd[318]: udev_event_run: seq 423 forked, pid [555], 'remove' 'firmware', 0 seconds old udevd-event[555]: pass_env_to_socket: passed -1 bytes to socket '@/org/kernel/udev/monitor', udevd-event[555]: udev_event_run: seq 423 finished with 0 udevd[318]: udev_done: seq 423, pid [555] exit with 0, 0 seconds old
udev runs more slowly with logging set to 'debug' level, and the first two firmware requests both time-out, instead of just the first one. So this appears to be timing-related, rather than a one-time failure. Could the problem be simply that udev gets a huge backlog of device insertions to handle? Ben. -- Ben Hutchings If at first you don't succeed, you're doing about average.
signature.asc
Description: This is a digitally signed message part