Bug 129155

Created attachment 103083 [details]
ifup-doesnt-load-firmware.patch

When ifup checks if an interface requires the module to be loaded (through
is_available), it disables hotplug completely making the firmware load fail. I
see this problem with a builtin Intel Pro Wireless card (3rd-party ipw2200
module) and with an Atmel Actiontec card (atmel_cs driver).

The patch disables all of the hotplug, apart from the firmware loading.
I would require the patch to land on both rawhide, and as an FC2 erratum.

Fixed in CVS, will be in 7.69-1.

This does not solve the problem for me under FC2 because is_available
is only getting called for devices configured NOT to come up at boot time.

Nope, is_available is called in every call to ifup.
Before doing the ifup, make sure that the module for your device has
been removed.

If that doesn't solve the problem, send the output of "sh -x
/sbin/ifup ethX" where ethX is your device, and tell us the error
messages seen in "dmesg" as well as the location of the firmware
you've installed.

Created attachment 103304 [details]
output of failing /etc/init.d/network

Here is the output of /etc/init.d/network when it fails, as given by 'sh -x
/etc/init.d/network start'

Created attachment 103305 [details]
failing ifup output

Here is the output of the failing ./ifup when it was called by
/etc/init.d/network. This goes with the previous attachment.

You are right about is_available being called. I was confused because
some debugging output I put in was not showing, swallowed up by
redirection I suppose.

I attached the sh -x output you requested, but I did it from
/etc/init.d/network because it's the ifup call from that script which
fails. If I call ifup directly everything works fine. It even works
without your patch.

The dmesg output in the failure case is:
eth1: islpci_open()
eth1: resetting device...
eth1: uploading firmware...
prism54: request_firmware() failed for 'isl3890'
eth1: could not upload firmware ('isl3890')

It seems the name of the firmware is not being passed to
firmware.agent. when it is called directly instead of from
/sbin/hotplug. I added some debug output and the failure case sees:

Aug 31 13:48:15 localhost firmware.agent[11554]: Entered firmware.agent
Aug 31 13:48:15 localhost firmware.agent[11554]: Waiting for:
/sys//class/net/eth1/loading
Aug 31 13:48:15 localhost kernel: Loaded prism54 driver, version 1.2
Aug 31 13:48:15 localhost kernel: ACPI: PCI interrupt 0000:00:0c.0[A]
-> GSI 18 (level, low) -> IRQ 177
Aug 31 13:48:15 localhost ifup: interface 'eth1' not found
Aug 31 13:48:15 localhost ifup:
Aug 31 13:48:15 localhost ifup: interface 'eth1' not found
Aug 31 13:48:15 localhost ifup:
Aug 31 13:48:15 localhost ifup: Error for wireless request "Set Bit
Rate" (8B20) :
Aug 31 13:48:15 localhost ifup:     SET failed on device eth1 ;
Input/output error.
Aug 31 13:48:15 localhost ifup:
Aug 31 13:48:15 localhost ifup: Determining IP information for eth1...
Aug 31 13:48:16 localhost firmware.agent[11554]: Firmware missing:
/usr/lib/hotplug/firmware/
Aug 31 13:48:25 localhost kernel: prism54: request_firmware() failed
for 'isl3890'

But in the success case (where hotplug is not set to /bin/true in
/etc/init.d/network) we see:

Aug 31 13:58:41 localhost firmware.agent[12266]: Entered firmware.agent
Aug 31 13:58:41 localhost firmware.agent[12266]: Waiting for:
/sys//class/net/eth1/loading
Aug 31 13:58:41 localhost kernel: Loaded prism54 driver, version 1.2
Aug 31 13:58:41 localhost kernel: ACPI: PCI interrupt 0000:00:0c.0[A]
-> GSI 18 (level, low) -> IRQ 177
Aug 31 13:58:41 localhost default.hotplug[12310]: arguments (firmware)
env (OLDPWD=/ DEVPATH=/class/firmware/0000:00:0c.0 FIRMWARE=isl3890
PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/
SHLVL=2 DEBUG=yes SEQNUM=415 _=/bin/env)
Aug 31 13:58:41 localhost default.hotplug[12310]: invoke
/etc/hotplug/firmware.agent ()
Aug 31 13:58:41 localhost firmware.agent[12310]: Entered firmware.agent
Aug 31 13:58:41 localhost firmware.agent[12310]: Loading firmware
/usr/lib/hotplug/firmware/isl3890
Aug 31 13:58:41 localhost default.hotplug[12328]: arguments (firmware)
env (OLDPWD=/ DEVPATH=/class/firmware/0000:00:0c.0 FIRMWARE=isl3890
PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=remove PWD=/etc/hotplug
HOME=/ SHLVL=2 DEBUG=yes SEQNUM=416 _=/bin/env)
Aug 31 13:58:41 localhost default.hotplug[12328]: invoke
/etc/hotplug/firmware.agent ()
Aug 31 13:58:41 localhost firmware.agent[12328]: Entered firmware.agent
Aug 31 13:58:41 localhost ifup: interface 'eth1' not found
Aug 31 13:58:41 localhost ifup:
Aug 31 13:58:41 localhost ifup: Determining IP information for eth1...
Aug 31 13:58:41 localhost ifup:
Aug 31 13:58:41 localhost ifup: interface 'eth1' not found
Aug 31 13:58:41 localhost ifup: Error for wireless request "Set Bit
Rate" (8B20) :
Aug 31 13:58:41 localhost ifup:     SET failed on device eth1 ;
Input/output error.
Aug 31 13:58:41 localhost dhclient: sit0: unknown hardware address
type 776
Aug 31 13:58:42 localhost firmware.agent[12266]: Firmware missing:
/usr/lib/hotplug/firmware/
Aug 31 13:58:43 localhost dhclient: sit0: unknown hardware address
type 776
Aug 31 13:58:46 localhost dhclient: DHCPREQUEST on eth1 to
255.255.255.255 port 67
Aug 31 13:58:46 localhost dhclient: DHCPACK from 192.168.10.1
Aug 31 13:58:46 localhost dhclient: bound to 192.168.1.157 -- renewal
in 36925 seconds.
Aug 31 13:58:46 localhost ifup:  done.
Aug 31 13:58:46 localhost network: Bringing up interface eth1Copy0: 
succeeded

Notice the 12310 iteration of firmware.agent. It gets the correct
firmware filename.

Hopefully that gives you enough information to find the problem. If
not I'll dig some more.

Could you uncomment the debug statement in the firmware hotplug
script, and add the line:
debug_mesg "arguments ($*) env (`env`)"

This should tell us which parameters are passed to the script.

As requested.

Sep  3 10:35:17 d157 firmware.agent[4451]: arguments (net) env
(OLDPWD=/ DEVPATH=/class/net/eth1 PATH=/bin:/sbin:/usr/sbin:/usr/bin
ACTION=add PWD=/etc/hotplug SHLVL=1 HOME=/ INTERFACE=eth1 DEBUG=yes
SEQNUM=312 _=/bin/env)

Fedora Core 2 is now maintained by the Fedora Legacy project for
security updates only. If this problem is a security issue, please
reopen and reassign to the Fedora Legacy product. If it is not a
security issue and hasn't been resolved in the current FC3 updates or
in the FC4 test release, reopen and change the version to match.

This should be fixed in recent versions of Fedora Core.