Christian,
Many thanks for the renaming of the firmware for p54usb. With this change, I can
keep an old version of the firmware (2.5.8.0.arm) named isl3887usb_bare and a
new one (2.13.1.0.arm.1) named isl3887usb in /lib/firmware and run the trees
from Linus and wireless-testing without messing with the firmware.
I have discovered one anomaly that shows up with firmware 2.5.8.0.arm. If the
USB device is unplugged and replugged, mac80211 will log the warning from
net/mac80211/main.c:234 because p54_config() returns an error. The source of the
error is p54_assign_address(), where target_skb is NULL. That happens because
priv->rx_end - last_addr is 32 whereas the value of len is 160 - thus target_skb
never gets set.
I have not seen this problem with firmware 2.13.1.arm.1, nor does it occur if
the driver is removed before the USB device is replugged.
If you have any suggestions regarding debugging, please let me know.
Larry
On Friday 17 October 2008 01:40:02 Larry Finger wrote:
Hi!
> Many thanks for the renaming of the firmware for p54usb. With this change, I can
> keep an old version of the firmware (2.5.8.0.arm) named isl3887usb_bare and a
> new one (2.13.1.0.arm.1) named isl3887usb in /lib/firmware and run the trees
> from Linus and wireless-testing without messing with the firmware.
>
> I have discovered one anomaly that shows up with firmware 2.5.8.0.arm. If the
> USB device is unplugged and replugged, mac80211 will log the warning from
> net/mac80211/main.c:234 because p54_config() returns an error. The source of the
> error is p54_assign_address(), where target_skb is NULL. That happens because
> priv->rx_end - last_addr is 32 whereas the value of len is 160 - thus target_skb
> never gets set.
hmm, either p54_assign_address, p54_free_skb & p54_rx_frame_sent have a
major flaw, or simple the device ran out of "free" memory.
Now, normally this won't happen very often since the "window" is about 32kb,
which should be really enough. So, the question is why doesn't the firmware
notify the driver to free up space again... so the window fills up, until
everything collapse.
>
> I have not seen this problem with firmware 2.13.1.arm.1, nor does it occur if
> the driver is removed before the USB device is replugged.
Well, I avoid 2.5.8.0 firmware. It reports "LM86", so technically it should made
for the first generation USB devices and not for the ISL3887 chip.
> If you have any suggestions regarding debugging, please let me know.
I've attached a debug function that could help to take a look inside the memory
management. what does it look like when put p54_dump_txqueue into
p54_start/p54_stop or p54_add_interface and replug your device?
or... something totally different. p54_rx_frame_sent could be culprit,
maybe we should check if the printk
>
goto out;
}
+ printk(KERN_ERR "p54: leaked frame %p\n", entry);
spin_unlock_irqrestore(&priv->tx_queue.lock, flags);
out:
<
get's triggered.
Regards,
Chr
---
static void p54_dump_txqueue(struct ieee80211_hw *dev)
{
struct p54_common *priv = dev->priv;
struct sk_buff *skb = priv->tx_queue.next;
struct ieee80211_tx_info *info;
struct memrecord *range;
unsigned long flags;
u32 last_addr = priv->rx_start, free = 0, total_free = 0;
u32 queue_len, biggest_free_hole = 0;
spin_lock_irqsave(&priv->tx_queue.lock, flags);
queue_len = skb_queue_len(&priv->tx_queue);
printk(KERN_DEBUG "%s: Tx queue entries: %d\n",
wiphy_name(dev->wiphy), queue_len);
while (queue_len--) {
info = IEEE80211_SKB_CB(skb);
range = (void *)info->rate_driver_data;
free = range->start_addr - last_addr;
if (free > biggest_free_hole)
biggest_free_hole = free;
total_free += free;
printk(KERN_DEBUG "\tentry: %p (range: [%x-%x]=(%x) free:%x)\n",
skb, range->start_addr, range->end_addr,
range->end_addr - range->start_addr, free);
last_addr = range->end_addr;
skb = skb->next;
}
spin_unlock_irqrestore(&priv->tx_queue.lock, flags);
free = priv->rx_end - last_addr;
if (free > biggest_free_hole)
biggest_free_hole = free;
total_free += free;
printk(KERN_DEBUG "\tlast entry: (range: [%x-%x] free: %d)\n",
last_addr, priv->rx_end, free);
printk(KERN_DEBUG "\ttotal_free:%d bytes, biggest free hole:%d bytes\n",
total_free, biggest_free_hole);
}
Christian Lamparter wrote:
> I've attached a debug function that could help to take a look inside the memory
> management. what does it look like when put p54_dump_txqueue into
> p54_start/p54_stop or p54_add_interface and replug your device?
Thanks. I placed a call to the dump routine into p54_add_interface() and in
p54_hw_config(). The resulting output is shown below.
> or... something totally different. p54_rx_frame_sent could be culprit,
> maybe we should check if the printk
> goto out;
> }
> + printk(KERN_ERR "p54: leaked frame %p\n", entry);
> spin_unlock_irqrestore(&priv->tx_queue.lock, flags);
This printk never gets triggered.
At initial startup, printed from p54_add_interface:
kernel: phy26: Tx queue entries: 5
kernel: entry: ffff8800986c7f00 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800986c7500 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff8800986c7000 (range: [20380-20420]=(a0) free:0)
kernel: entry: ffff8800986c7c00 (range: [20420-204c0]=(a0) free:0)
kernel: entry: ffff8800986c7800 (range: [204c0-2053c]=(7c) free:0)
kernel: last entry: (range: [2053c-24214] free: 15576)
kernel: total_free:15576 bytes, biggest free hole:15576 bytes
When the driver works normally, by the time p54_config is called, we have:
kernel: phy26: Tx queue entries: 3
kernel: entry: ffff8800986c7700 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800986c7500 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff8800986c7900 (range: [20380-20470]=(f0) free:0)
kernel: last entry: (range: [20470-24214] free: 15780)
kernel: total_free:15780 bytes, biggest free hole:15780 bytes
As I see it, the second one persists but the other 4 have been freed, and two
new ones added. When the device works correctly, the same pattern persists and
the second entry is constant but the total number stays at 3 or 4.
When failure occurs, We get the following calls:
kernel: phy31: Tx queue entries: 5
kernel: entry: ffff8800b8de6500 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff8800a80c5800 (range: [20380-20420]=(a0) free:0)
kernel: entry: ffff88009872d000 (range: [20420-204c0]=(a0) free:0)
kernel: entry: ffff88009872d100 (range: [204c0-2053c]=(7c) free:0)
kernel: last entry: (range: [2053c-24214] free: 15576)
kernel: total_free:15576 bytes, biggest free hole:15576 bytes
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: p54: In p54_config
kernel: phy31: Tx queue entries: 3
kernel: entry: ffff88009872d500 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff88009872d400 (range: [20380-20470]=(f0) free:0)
kernel: last entry: (range: [20470-24214] free: 15780)
kernel: total_free:15780 bytes, biggest free hole:15780 bytes
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: p54: In p54_config
kernel: phy31: Tx queue entries: 3
kernel: entry: ffff88009871fc00 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff88009871f100 (range: [20380-20470]=(f0) free:0)
kernel: last entry: (range: [20470-24214] free: 15780)
kernel: total_free:15780 bytes, biggest free hole:15780 bytes
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: In p54u_tx_cb
kernel: In p54u_tx_reuse_skb_cb
kernel: p54: In p54_config
kernel: phy31: Tx queue entries: 4
kernel: entry: ffff88009871f800 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff88009871f700 (range: [20380-20548]=(1c8) free:0)
kernel: entry: ffff88009871ff00 (range: [20548-20638]=(f0) free:0)
kernel: last entry: (range: [20638-24214] free: 15324)
kernel: total_free:15324 bytes, biggest free hole:15324 bytes
kernel: In p54u_tx_cb
kernel: In p54u_tx_free_skb_cb
kernel: Entered p54_free_skb
kernel: p54: In p54_config
kernel: phy31: Tx queue entries: 6
kernel: entry: ffff88009871f800 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff88009871f700 (range: [20380-20548]=(1c8) free:0)
kernel: entry: ffff88009871f200 (range: [20548-20710]=(1c8) free:0)
kernel: entry: ffff88009871fd00 (range: [20710-20800]=(f0) free:0)
kernel: entry: ffff88009871f500 (range: [20800-208c0]=(c0) free:0)
kernel: last entry: (range: [208c0-24214] free: 14676)
kernel: total_free:14676 bytes, biggest free hole:14676 bytes
kernel: p54: In p54_config
kernel: phy31: Tx queue entries: 9
kernel: entry: ffff88009871f800 (range: [20200-202c0]=(c0) free:0)
kernel: entry: ffff8800b8de6600 (range: [202c0-20380]=(c0) free:0)
kernel: entry: ffff88009871f700 (range: [20380-20548]=(1c8) free:0)
kernel: entry: ffff88009871f200 (range: [20548-20710]=(1c8) free:0)
kernel: entry: ffff88009871fd00 (range: [20710-20800]=(f0) free:0)
kernel: entry: ffff88009871f500 (range: [20800-208c0]=(c0) free:0)
kernel: entry: ffff88009871f300 (range: [208c0-20a88]=(1c8) free:0)
kernel: entry: ffff88009871f900 (range: [20a88-20b78]=(f0) free:0)
kernel: entry: ffff88009871f000 (range: [20b78-20c38]=(c0) free:0)
kernel: last entry: (range: [20c38-24214] free: 13788)
kernel: total_free:13788 bytes, biggest free hole:13788 bytes
Note that none of the p54u callback routines are entered. From here, each
successive call to p54_config() adds 3 new queue entries, non of which are ever
removed. Eventually, the number of entries gets to 59 and the free space is less
that the requested length causing the failure.
I'm still trying to analyze the output from usbmon and to correlate it with the
data in /var/log/messages, but callbacks stop occurring at a certain point,
which is consistent with what is seen above. Unless you have other ideas, I'm
content to attribute this problem to the old firmware. If I see similar troubles
with newer firmware, I'll be back.
Larry
On Sat, 2008-10-18 at 16:15 -0700, Larry Finger wrote:
> Note that none of the p54u callback routines are entered. From here, each
> successive call to p54_config() adds 3 new queue entries, non of which are ever
> removed. Eventually, the number of entries gets to 59 and the free space is less
> that the requested length causing the failure.
>
> I'm still trying to analyze the output from usbmon and to correlate it with the
> data in /var/log/messages, but callbacks stop occurring at a certain point,
> which is consistent with what is seen above. Unless you have other ideas, I'm
> content to attribute this problem to the old firmware. If I see similar troubles
> with newer firmware, I'll be back.
Looks to me like that for some reason the firmware doesn't tell the
driver when the config callback was completed, which will lead to the
space invariably filling up over time. It probably should be possible to
work around it (say by recycling the config once the firmware has
transmitted the next frame, since by then it should be reconfigured) but
I'm not sure it's worth it.
Btw, I tried getting my hands on a p54 device but it ended up being
acx111... I'll try again.
johannes