Comment 31 for bug 1398458

Revision history for this message
In , Dominique Leuenberger aka DimStar (dimstar) wrote :

NOTE: unloading and reloading iwlwifi brings back the 2 minute window - so it is definitively NOT related to a race on bootup: even if the system was up for 30 minutes already, simply do:

rmmod iwlwifi
modprobe iwlwifi
=> it will take again 2 minutes to load the firmware

some udevadm monitoring:

after 'modprobe iwlwifi'

KERNEL[3055.484684] add /module/iwlwifi (module)
UDEV [3055.485613] add /module/iwlwifi (module)
KERNEL[3055.485656] add /bus/pci/drivers/iwlwifi (drivers)
KERNEL[3055.485810] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-6.ucode (firmware)
UDEV [3055.486038] add /bus/pci/drivers/iwlwifi (drivers)
UDEV [3055.486638] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-6.ucode (firmware)
KERNEL[3055.487174] add /module/iwldvm (module)
UDEV [3055.487377] add /module/iwldvm (module)

one minute later (note: remove *-6.ucode, add *-5.ucode)

1KERNEL[3115.612278] remove /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-6.ucode (firmware)
KERNEL[3115.612320] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-5.ucode (firmware)
UDEV [3115.613263] remove /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-6.ucode (firmware)
UDEV [3115.613708] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-5.ucode (firmware)

one minute later (note: remove *-5.ucode; I assume it would add *-4*.ucode, BUT this is loaded in kernel, as this is the file that exists!)

KERNEL[3175.644300] remove /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-5.ucode (firmware)
UDEV [3175.645274] remove /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/firmware/iwlwifi-6000-5.ucode (firmware)
KERNEL[3175.660107] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/leds/phy3-led (leds)
KERNEL[3175.660145] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy3 (ieee80211)
KERNEL[3175.660220] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy3/rfkill6 (rfkill)
KERNEL[3175.660480] change /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/leds/phy3-led (leds)
KERNEL[3175.660507] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0 (net)
UDEV [3175.660525] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/leds/phy3-led (leds)
KERNEL[3175.660541] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/rx-0 (queues)
KERNEL[3175.660557] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-0 (queues)
KERNEL[3175.660572] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-1 (queues)
KERNEL[3175.660587] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-2 (queues)
KERNEL[3175.660602] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-3 (queues)
UDEV [3175.661026] change /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/leds/phy3-led (leds)
UDEV [3175.661060] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy3 (ieee80211)
UDEV [3175.661768] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy3/rfkill6 (rfkill)
UDEV [3175.666579] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0 (net)
UDEV [3175.667090] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/rx-0 (queues)
UDEV [3175.667520] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-2 (queues)
UDEV [3175.667705] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-1 (queues)
UDEV [3175.668393] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-3 (queues)
UDEV [3175.669080] add /devices/pci0000:00/0000:00:1c.1/0000:03:00.0/net/wlan0/queues/tx-0 (queues)

So the main issue is indeed that we pass off to udev for loading - and there is a 60s timeout (per try)