b43: firmware loading problem and sleeping BUG

b43: firmware loading problem and sleeping BUG

[Martin Fuzzey]

I posted a couple of days ago to the bcm43xx_dev list about problems
getting b43 to run on a
arm (MX21 SoC). That list appears to have died recently (at least
nothing added to the archives
since last month)

That problem is fixed now (and patch posted)

However I now get:
pcmcia_socket pcmcia_socket0: pccard: PCMCIA card inserted into slot 0
pcmcia 0.0: pcmcia: registering new device pcmcia0.0
ssb: Core 0 found: ChipCommon (cc 0x800, rev 0x0D, vendor 0x4243)
ssb: Core 1 found: IEEE 802.11 (cc 0x812, rev 0x09, vendor 0x4243)
ssb: Core 2 found: PCI (cc 0x804, rev 0x0C, vendor 0x4243)
ssb: Core 3 found: PCMCIA (cc 0x80D, rev 0x07, vendor 0x4243)
BUG: sleeping function called from invalid context at mm/vmalloc.c:1367
in_atomic(): 1, irqs_disabled(): 128, pid: 1361, name: modprobe
2 locks held by modprobe/1361:
 #0:  (buses_mutex){+.+.+.}, at: [<bf03761c>] ssb_bus_register+0x48/0x1a4 [ssb]
 #1:  (&bus->bar_lock){......}, at: [<bf038e38>]
ssb_pcmcia_read32+0x24/0x74 [ssb]
irq event stamp: 105917
hardirqs last  enabled at (105916): [<c027cf34>]
__mutex_unlock_slowpath+0x120/0x150
hardirqs last disabled at (105917): [<c027eee0>] _spin_lock_irqsave+0x20/0x60
softirqs last  enabled at (105853): [<c0042f60>] irq_exit+0x50/0x64
softirqs last disabled at (105832): [<c0042f60>] irq_exit+0x50/0x64
------------[ cut here ]------------
WARNING: at kernel/lockdep.c:2465 lockdep_trace_alloc+0xac/0xec()
Modules linked in: b43(+) ssb mac80211 mxc_pcmcia
---[ end trace 7a542bbcadb0bb88 ]---
ssb: Sonics Silicon Backplane found on PCMCIA device pcmcia0.0
b43-phy0: Broadcom 4318 WLAN found (core revision 9)
b43-phy0 debug: Found PHY: Analog 3, Type 2, Revision 7
b43-phy0 debug: Found Radio: Manuf 0x17F, Version 0x2050, Revision 8
phy0: Selected rate control algorithm 'minstrel'
Broadcom 43xx driver loaded [ Features: M, Firmware-ID: FW13 ]

And then when I do ifconfig wlan0 up:

b43 ssb0:0: firmware: requesting b43/ucode5.fw
b43 ssb0:0: firmware: requesting b43/pcm5.fw
b43 ssb0:0: firmware: requesting b43/b0g0initvals5.fw
b43 ssb0:0: firmware: requesting b43/b0g0bsinitvals5.fw
b43-phy0: Loading firmware version 410.2160 (2007-05-26 15:32:10)
b43-phy0 ERROR: Initial Values Firmware file-format error.
b43-phy0 ERROR: You must go to
http://wireless.kernel.org/en/users/Drivers/b43#devicefirmware
and download the correct firmware for this driver version. Please
carefully read all instructions on this website.

I am using firmware broadcom-wl-4.150.10.5 extracted with
b43-fwcutter-012 as described
http://wireless.kernel.org/en/users/Drivers/b43#devicefirmware


Any ideas why the versions don't match?
The firmware files are arch independant right? (since I run fwcutter
on x86 and run the kernel on ARM)

Kernel version is 2.6.32-rc5
The PCMCIA controller driver is new (I recently posted it to
linux-pcmcia and linux-arm)

Cheers,

Martin

Re: b43: firmware loading problem and sleeping BUG

[Michael Buesch]

On Friday 06 November 2009 17:19:51 Martin Fuzzey wrote:
> I posted a couple of days ago to the bcm43xx_dev list about problems
> getting b43 to run on a
> arm (MX21 SoC). That list appears to have died recently (at least
> nothing added to the archives
> since last month)

Well, it never really worked. It's hosted on berlios. That's why it's crap. ;)

> However I now get:
> pcmcia_socket pcmcia_socket0: pccard: PCMCIA card inserted into slot 0
> pcmcia 0.0: pcmcia: registering new device pcmcia0.0
> ssb: Core 0 found: ChipCommon (cc 0x800, rev 0x0D, vendor 0x4243)
> ssb: Core 1 found: IEEE 802.11 (cc 0x812, rev 0x09, vendor 0x4243)
> ssb: Core 2 found: PCI (cc 0x804, rev 0x0C, vendor 0x4243)
> ssb: Core 3 found: PCMCIA (cc 0x80D, rev 0x07, vendor 0x4243)
> BUG: sleeping function called from invalid context at mm/vmalloc.c:1367
> in_atomic(): 1, irqs_disabled(): 128, pid: 1361, name: modprobe
> 2 locks held by modprobe/1361:
>  #0:  (buses_mutex){+.+.+.}, at: [<bf03761c>] ssb_bus_register+0x48/0x1a4 [ssb]
>  #1:  (&bus->bar_lock){......}, at: [<bf038e38>]
> ssb_pcmcia_read32+0x24/0x74 [ssb]
> irq event stamp: 105917
> hardirqs last  enabled at (105916): [<c027cf34>]
> __mutex_unlock_slowpath+0x120/0x150
> hardirqs last disabled at (105917): [<c027eee0>] _spin_lock_irqsave+0x20/0x60
> softirqs last  enabled at (105853): [<c0042f60>] irq_exit+0x50/0x64
> softirqs last disabled at (105832): [<c0042f60>] irq_exit+0x50/0x64
> ------------[ cut here ]------------
> WARNING: at kernel/lockdep.c:2465 lockdep_trace_alloc+0xac/0xec()
> Modules linked in: b43(+) ssb mac80211 mxc_pcmcia
> ---[ end trace 7a542bbcadb0bb88 ]---

These logs look weird. Is that the full log from "dmesg" command?
I guess the pcmcia_access_configuration_register() is doing nonatomic vmalloc stuff.

I think this is easy to fix, because we can replace the spinlock by a mutex, as
the b43 driver (which is the only user of the code) always allows sleeping now.
I'll send a patch for testing soon.

> ssb: Sonics Silicon Backplane found on PCMCIA device pcmcia0.0
> b43-phy0: Broadcom 4318 WLAN found (core revision 9)
> b43-phy0 debug: Found PHY: Analog 3, Type 2, Revision 7
> b43-phy0 debug: Found Radio: Manuf 0x17F, Version 0x2050, Revision 8
> phy0: Selected rate control algorithm 'minstrel'
> Broadcom 43xx driver loaded [ Features: M, Firmware-ID: FW13 ]
> 
> And then when I do ifconfig wlan0 up:
> 
> b43 ssb0:0: firmware: requesting b43/ucode5.fw
> b43 ssb0:0: firmware: requesting b43/pcm5.fw
> b43 ssb0:0: firmware: requesting b43/b0g0initvals5.fw
> b43 ssb0:0: firmware: requesting b43/b0g0bsinitvals5.fw
> b43-phy0: Loading firmware version 410.2160 (2007-05-26 15:32:10)
> b43-phy0 ERROR: Initial Values Firmware file-format error.
> b43-phy0 ERROR: You must go to
> http://wireless.kernel.org/en/users/Drivers/b43#devicefirmware
> and download the correct firmware for this driver version. Please
> carefully read all instructions on this website.
> 
> I am using firmware broadcom-wl-4.150.10.5 extracted with
> b43-fwcutter-012 as described
> http://wireless.kernel.org/en/users/Drivers/b43#devicefirmware
> 
> 
> Any ideas why the versions don't match?

These are two different version numbers. One for the broadcom driver
and one for the firmware.

> The firmware files are arch independant right? (since I run fwcutter
> on x86 and run the kernel on ARM)

Yes.

> Kernel version is 2.6.32-rc5
> The PCMCIA controller driver is new (I recently posted it to
> linux-pcmcia and linux-arm)

Thanks for testing. The ssb-pcmcia code is not tested a lot, so
I'm not surprised that there are bugs.

-- 
Greetings, Michael.

Re: b43: firmware loading problem and sleeping BUG

[Martin Fuzzey]

On Fri, Nov 6, 2009 at 6:22 PM, Michael Buesch <mb@bu3sch.de> wrote:
> These logs look weird. Is that the full log from "dmesg" command?
Yes - I've just stripped the timestamps

> I guess the pcmcia_access_configuration_register() is doing nonatomic vmalloc stuff.
>
Indeed looks like its iounmap() that eventually gets called from there.

> I think this is easy to fix, because we can replace the spinlock by a mutex, as
> the b43 driver (which is the only user of the code) always allows sleeping now.
> I'll send a patch for testing soon.
>
Great - happy to test it.

>> b43-phy0: Loading firmware version 410.2160 (2007-05-26 15:32:10)
>> b43-phy0 ERROR: Initial Values Firmware file-format error.
>> b43-phy0 ERROR: You must go to
>>
>> Any ideas why the versions don't match?
>
> These are two different version numbers. One for the broadcom driver
> and one for the firmware.
>
Ok so I do have the correct firmware.

I seem to be having very non deterministic behaviour regarding
the firmware loading.

Sometimes I get the behaviour above (which I trace to the first test
in b43_write_initvals().

And sometimes I get this behaviour:

pcmcia driver load:
[  102.850000] ssb: Sonics Silicon Backplane found on PCMCIA device pcmcia0.0

[  102.880000] b43-phy0: Broadcom 4318 WLAN found (core revision 9)

[  102.990000] b43-phy0 debug: Found PHY: Analog 3, Type 2, Revision 7

[  103.010000] b43-phy0 debug: Found Radio: Manuf 0x17F, Version
0x2050, Revision 8

[  105.610000] phy0: Selected rate control algorithm 'minstrel'

[  105.650000] Broadcom 43xx driver loaded [ Features: M, Firmware-ID: FW13 ]


First ifconfig wlan0 up (note it's trying to use the open firmware -
which I don't have):
[  108.770000] b43 ssb0:0: firmware: requesting b43/ucode5.fw

[  108.910000] b43 ssb0:0: firmware: requesting b43/pcm5.fw

[  109.170000] b43 ssb0:0: firmware: requesting b43-open/ucode5.fw

[  109.330000] b43 ssb0:0: firmware: requesting b43-open/pcm5.fw

[  109.520000] b43 ssb0:0: firmware: requesting b43-open/b0g0initvals5.fw

[  109.690000] b43-phy0 ERROR: Firmware file "b43/pcm5.fw" format error.

[  109.760000] b43-phy0 ERROR: Firmware file
"b43-open/b0g0initvals5.fw" not found

[  109.960000] b43-phy0 ERROR: You must go to
http://wireless.kernel.org/en/users/Drivers/b43#devicefirmware and
download the correct firmware for this driver version. Please
carefully read all instructions on this website.


Second ifconfig wlan0 up (no reboot):
[  157.730000] b43 ssb0:0: firmware: requesting b43/ucode5.fw

[  157.860000] b43 ssb0:0: firmware: requesting b43/pcm5.fw

[  158.040000] b43 ssb0:0: firmware: requesting b43/b0g0initvals5.fw

[  158.310000] b43 ssb0:0: firmware: requesting b43/b0g0bsinitvals5.fw

[  158.940000] b43-phy0: Loading firmware version 410.2160 (2007-05-26 15:32:10)

[  159.010000] b43-phy0 debug: Chip initialized

[  159.030000] b43-phy0 debug: PIO initialized

[  159.040000] b43-phy0 debug: QoS enabled

[  159.070000] b43-phy0 debug: Wireless interface started

[  159.130000] b43-phy0 debug: Adding Interface type 2


Yay - and iwlist scanning works (haven't tried associating yet)

And sometimes even after mutiple ups it gives up and the microcode
doesn't reply...

So any suggestions on figuring out what is going on?
>
> Thanks for testing. The ssb-pcmcia code is not tested a lot, so
> I'm not surprised that there are bugs.
>
You're welcome

Cheers,

Martin

Re: b43: firmware loading problem and sleeping BUG

[Michael Buesch]

On Friday 06 November 2009 19:27:17 Martin Fuzzey wrote:
> [  109.690000] b43-phy0 ERROR: Firmware file "b43/pcm5.fw" format error.

> So any suggestions on figuring out what is going on?

Your userspace firmware helper (I guess it's not udev on your device?)
might be throwing crap at the kernel.

-- 
Greetings, Michael.

Re: b43: firmware loading problem and sleeping BUG

[Martin Fuzzey]

For the archives:

On Fri, Nov 6, 2009 at 7:31 PM, Michael Buesch <mb@bu3sch.de> wrote:
>
> Your userspace firmware helper (I guess it's not udev on your device?)
> might be throwing crap at the kernel.
>
Yes it is udev (at least for the moment - running on NFS root and
concentrating on kernel stuff)

My problem was that I had _two_ udev rules invoking /lib/udev/firmware.sh
this resulted in a race between them and the kernel sometimes getting the
firmware for the previous request - hilarity ensued!

One of the rules (50-udev-default.rules) was from the upstream udev source
The other (udev.rules) was put there by openembedded.
Have reported this to the OE list.

With that sorted out it all seems to work fine - I haven't done any stress tests
yet though.

Thanks for your help

Cheers,
Martin

Re: b43: firmware loading problem and sleeping BUG

[Michael Buesch]

On Friday 06 November 2009 19:27:17 Martin Fuzzey wrote:
> > I think this is easy to fix, because we can replace the spinlock by a mutex, as
> > the b43 driver (which is the only user of the code) always allows sleeping now.
> > I'll send a patch for testing soon.
> >
> Great - happy to test it.

There you go. Note that I did not test it, as trying to use my pcmcia card throws
a hell of a lot oopses at me and the firmware finally force-resets the hardware
for some reason. This needs some debugging first...


Index: wireless-testing/drivers/ssb/main.c
===================================================================
--- wireless-testing.orig/drivers/ssb/main.c	2009-10-09 19:50:16.000000000 +0200
+++ wireless-testing/drivers/ssb/main.c	2009-11-06 19:47:18.000000000 +0100
@@ -740,7 +740,7 @@ static int ssb_bus_register(struct ssb_b
 {
 	int err;
 
-	spin_lock_init(&bus->bar_lock);
+	mutex_init(&bus->register_mutex);
 	INIT_LIST_HEAD(&bus->list);
 #ifdef CONFIG_SSB_EMBEDDED
 	spin_lock_init(&bus->gpio_lock);
Index: wireless-testing/drivers/ssb/pcmcia.c
===================================================================
--- wireless-testing.orig/drivers/ssb/pcmcia.c	2009-07-28 22:53:08.000000000 +0200
+++ wireless-testing/drivers/ssb/pcmcia.c	2009-11-06 19:35:59.000000000 +0100
@@ -238,15 +238,14 @@ static int select_core_and_segment(struc
 static u8 ssb_pcmcia_read8(struct ssb_device *dev, u16 offset)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 	u8 value = 0xFF;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err))
 		value = readb(bus->mmio + offset);
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 
 	return value;
 }
@@ -254,15 +253,14 @@ static u8 ssb_pcmcia_read8(struct ssb_de
 static u16 ssb_pcmcia_read16(struct ssb_device *dev, u16 offset)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 	u16 value = 0xFFFF;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err))
 		value = readw(bus->mmio + offset);
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 
 	return value;
 }
@@ -270,17 +268,16 @@ static u16 ssb_pcmcia_read16(struct ssb_
 static u32 ssb_pcmcia_read32(struct ssb_device *dev, u16 offset)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 	u32 lo = 0xFFFFFFFF, hi = 0xFFFFFFFF;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err)) {
 		lo = readw(bus->mmio + offset);
 		hi = readw(bus->mmio + offset + 2);
 	}
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 
 	return (lo | (hi << 16));
 }
@@ -290,11 +287,10 @@ static void ssb_pcmcia_block_read(struct
 				  size_t count, u16 offset, u8 reg_width)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	void __iomem *addr = bus->mmio + offset;
 	int err;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (unlikely(err)) {
 		memset(buffer, 0xFF, count);
@@ -339,52 +335,49 @@ static void ssb_pcmcia_block_read(struct
 		SSB_WARN_ON(1);
 	}
 unlock:
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 }
 #endif /* CONFIG_SSB_BLOCKIO */
 
 static void ssb_pcmcia_write8(struct ssb_device *dev, u16 offset, u8 value)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err))
 		writeb(value, bus->mmio + offset);
 	mmiowb();
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 }
 
 static void ssb_pcmcia_write16(struct ssb_device *dev, u16 offset, u16 value)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err))
 		writew(value, bus->mmio + offset);
 	mmiowb();
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 }
 
 static void ssb_pcmcia_write32(struct ssb_device *dev, u16 offset, u32 value)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	int err;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (likely(!err)) {
 		writew((value & 0x0000FFFF), bus->mmio + offset);
 		writew(((value & 0xFFFF0000) >> 16), bus->mmio + offset + 2);
 	}
 	mmiowb();
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 }
 
 #ifdef CONFIG_SSB_BLOCKIO
@@ -392,11 +385,10 @@ static void ssb_pcmcia_block_write(struc
 				   size_t count, u16 offset, u8 reg_width)
 {
 	struct ssb_bus *bus = dev->bus;
-	unsigned long flags;
 	void __iomem *addr = bus->mmio + offset;
 	int err;
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
+	mutex_lock(&bus->register_mutex);
 	err = select_core_and_segment(dev, &offset);
 	if (unlikely(err))
 		goto unlock;
@@ -440,7 +432,7 @@ static void ssb_pcmcia_block_write(struc
 	}
 unlock:
 	mmiowb();
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
+	mutex_unlock(&bus->register_mutex);
 }
 #endif /* CONFIG_SSB_BLOCKIO */
 
Index: wireless-testing/include/linux/ssb/ssb.h
===================================================================
--- wireless-testing.orig/include/linux/ssb/ssb.h	2009-11-01 13:58:49.000000000 +0100
+++ wireless-testing/include/linux/ssb/ssb.h	2009-11-06 19:32:32.000000000 +0100
@@ -278,9 +278,8 @@ struct ssb_bus {
 		/* Current SSB base address window for SDIO. */
 		u32 sdio_sbaddr;
 	};
-	/* Lock for core and segment switching.
-	 * On PCMCIA-host busses this is used to protect the whole MMIO access. */
-	spinlock_t bar_lock;
+	/* Mutex to enforce one hardware register read/write is an atomic operation. */
+	struct mutex register_mutex;
 
 	/* The host-bus this backplane is running on. */
 	enum ssb_bustype bustype;
Index: wireless-testing/drivers/ssb/pci.c
===================================================================
--- wireless-testing.orig/drivers/ssb/pci.c	2009-10-09 19:50:16.000000000 +0200
+++ wireless-testing/drivers/ssb/pci.c	2009-11-06 20:04:11.000000000 +0100
@@ -63,7 +63,6 @@ int ssb_pci_switch_core(struct ssb_bus *
 			struct ssb_device *dev)
 {
 	int err;
-	unsigned long flags;
 
 #if SSB_VERBOSE_PCICORESWITCH_DEBUG
 	ssb_printk(KERN_INFO PFX
@@ -72,11 +71,9 @@ int ssb_pci_switch_core(struct ssb_bus *
 		   dev->core_index);
 #endif
 
-	spin_lock_irqsave(&bus->bar_lock, flags);
 	err = ssb_pci_switch_coreidx(bus, dev->core_index);
 	if (!err)
 		bus->mapped_device = dev;
-	spin_unlock_irqrestore(&bus->bar_lock, flags);
 
 	return err;
 }


-- 
Greetings, Michael.

Re: b43: firmware loading problem and sleeping BUG

[Michael Buesch]

On Friday 06 November 2009 20:08:04 Michael Buesch wrote:
> On Friday 06 November 2009 19:27:17 Martin Fuzzey wrote:
> > > I think this is easy to fix, because we can replace the spinlock by a mutex, as
> > > the b43 driver (which is the only user of the code) always allows sleeping now.
> > > I'll send a patch for testing soon.
> > >
> > Great - happy to test it.
> 
> There you go.

This doesn't actually work, because the lowlevel interrupt handler is atomic on PCMCIA.
So scratch that patch, it will just oops your machine.

-- 
Greetings, Michael.