mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Hello,

I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing
some throughput testing (with iperf) in 5GHz I got following failures:
[ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed

I checked which which size fails to allocate and it's 4096 bytes. I
was looking to changes in never kernel releases but I cannot find
anything obvious. When connected to 2.4GHz I cannot reproduce issue
though. I'm using FW version mwifiex 1.0 (14.68.29.p26).

Thank for any help/hints,

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

SGkgQlIsDQoNCj4gDQo+IEknbSB1c2luZyAzLjkgbWFpbmxpbmUgbXdpZmlleCBkcml2ZXIgZm9y
IHdpcmVsZXNzIHVzYiBjYXJkLiBEb2luZyBzb21lDQo+IHRocm91Z2hwdXQgdGVzdGluZyAod2l0
aCBpcGVyZikgaW4gNUdIeiBJIGdvdCBmb2xsb3dpbmcgZmFpbHVyZXM6DQo+IFsgMjIxLjUyMTc5
OV0gdXNiIDEtMTogbXdpZmlleF91c2Jfc3VibWl0X3J4X3VyYjogZGV2X2FsbG9jX3NrYiBmYWls
ZWQNCg0KVGhpcyBpcyBza2IgYWxsb2NhdGlvbiBmYWlsdXJlIHJldHVybmVkIGJ5IGtlcm5lbC4g
NGsgYnVmZmVyIGlzIGFsd2F5cyBhbGxvY2F0ZWQgZm9yIFJ4IHBhY2tldHMuIFRoaXMgaXNzdWUg
ZG9lc24ndCBzZWVtIHRvIGJlIHNwZWNpZmljIHRvIDVHaHouIA0KDQo+IA0KPiBJIGNoZWNrZWQg
d2hpY2ggd2hpY2ggc2l6ZSBmYWlscyB0byBhbGxvY2F0ZSBhbmQgaXQncyA0MDk2IGJ5dGVzLiBJ
IHdhcw0KPiBsb29raW5nIHRvIGNoYW5nZXMgaW4gbmV2ZXIga2VybmVsIHJlbGVhc2VzIGJ1dCBJ
IGNhbm5vdCBmaW5kIGFueXRoaW5nDQo+IG9idmlvdXMuIFdoZW4gY29ubmVjdGVkIHRvIDIuNEdI
eiBJIGNhbm5vdCByZXByb2R1Y2UgaXNzdWUgdGhvdWdoLiBJJ20NCj4gdXNpbmcgRlcgdmVyc2lv
biBtd2lmaWV4IDEuMCAoMTQuNjguMjkucDI2KS4NCj4gDQoNCkNvdWxkIHlvdSBwbGVhc2UgcHJv
dmlkZSB0aGUgcGxhdGZvcm0gZGV0YWlscz8NCkhvdyBvZnRlbiB0aGUgcHJvYmxlbSBvY2N1cnMg
ZHVyaW5nIHRocm91Z2hwdXQgdGVzdGluZz8gQXJlIHRoZXJlIGFueSBzcGVjaWZpYyBzdGVwcz8N
Cg0KUmVnYXJkcywNCkFtaXRrdW1hciBLYXJ3YXINCg==

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,

On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi BR,
>
>>
>> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing some
>> throughput testing (with iperf) in 5GHz I got following failures:
>> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
>
> This is skb allocation failure returned by kernel. 4k buffer is always allocated for Rx packets. This issue doesn't seem to be specific to 5Ghz.
OK. But I cannot reproduce this issue when connected to 2.4GHz (same
steps as described below).
>.
>>
>> I checked which which size fails to allocate and it's 4096 bytes. I was
>> looking to changes in never kernel releases but I cannot find anything
>> obvious. When connected to 2.4GHz I cannot reproduce issue though. I'm
>> using FW version mwifiex 1.0 (14.68.29.p26).
>>
>
> Could you please provide the platform details?
> How often the problem occurs during throughput testing? Are there any specific steps?
I can reproduce problem 100% by running iperf as server on board where
wifi is connected to  (iperf -s -u -w1M -i1)
and connecting with iperf client from other PC (iperf -c IPADDR -u -b 100m).
Then immediately I can see allocation failures. If you need more info
please let me know. Thanks.
>
> Regards,
> Amitkumar Karwar

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,

some additional info.

On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi BR,
>
>>
>> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing some
>> throughput testing (with iperf) in 5GHz I got following failures:
>> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
>
> This is skb allocation failure returned by kernel. 4k buffer is always allocated for Rx packets. This issue doesn't seem to be specific to 5Ghz.
Yes you're right. I can reproduce issue also with 2.4GHz (doing iperf
testing as mentioned in other email) by pinging device with card.
>
>>
>> I checked which which size fails to allocate and it's 4096 bytes. I was
>> looking to changes in never kernel releases but I cannot find anything
>> obvious. When connected to 2.4GHz I cannot reproduce issue though. I'm
>> using FW version mwifiex 1.0 (14.68.29.p26).
>>
>
> Could you please provide the platform details?
> How often the problem occurs during throughput testing? Are there any specific steps?
One more observation is that when problem occurred complete system is
unresponsive (console is almost completely dead).
I can workaround issue by decreasing iperf bandwidth to ~40m. I think
in this situation we're running out of memory by exhaustive skb
allocations.
>
> Regards,
> Amitkumar Karwar

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

SGkgQlIsDQoNCj4gRGVhciBBbWl0a3VtYXIgS2Fyd2FyLA0KPiANCj4gc29tZSBhZGRpdGlvbmFs
IGluZm8uDQo+IA0KPiBPbiBUaHUsIFNlcCAxMSwgMjAxNCBhdCA1OjA5IFBNLCBBbWl0a3VtYXIg
S2Fyd2FyIDxha2Fyd2FyQG1hcnZlbGwuY29tPg0KPiB3cm90ZToNCj4gPiBIaSBCUiwNCj4gPg0K
PiA+Pg0KPiA+PiBJJ20gdXNpbmcgMy45IG1haW5saW5lIG13aWZpZXggZHJpdmVyIGZvciB3aXJl
bGVzcyB1c2IgY2FyZC4gRG9pbmcNCj4gPj4gc29tZSB0aHJvdWdocHV0IHRlc3RpbmcgKHdpdGgg
aXBlcmYpIGluIDVHSHogSSBnb3QgZm9sbG93aW5nDQo+IGZhaWx1cmVzOg0KPiA+PiBbIDIyMS41
MjE3OTldIHVzYiAxLTE6IG13aWZpZXhfdXNiX3N1Ym1pdF9yeF91cmI6IGRldl9hbGxvY19za2IN
Cj4gPj4gZmFpbGVkDQo+ID4NCj4gPiBUaGlzIGlzIHNrYiBhbGxvY2F0aW9uIGZhaWx1cmUgcmV0
dXJuZWQgYnkga2VybmVsLiA0ayBidWZmZXIgaXMNCj4gYWx3YXlzIGFsbG9jYXRlZCBmb3IgUngg
cGFja2V0cy4gVGhpcyBpc3N1ZSBkb2Vzbid0IHNlZW0gdG8gYmUgc3BlY2lmaWMNCj4gdG8gNUdo
ei4NCj4gWWVzIHlvdSdyZSByaWdodC4gSSBjYW4gcmVwcm9kdWNlIGlzc3VlIGFsc28gd2l0aCAy
LjRHSHogKGRvaW5nIGlwZXJmDQo+IHRlc3RpbmcgYXMgbWVudGlvbmVkIGluIG90aGVyIGVtYWls
KSBieSBwaW5naW5nIGRldmljZSB3aXRoIGNhcmQuDQo+ID4NCj4gPj4NCj4gPj4gSSBjaGVja2Vk
IHdoaWNoIHdoaWNoIHNpemUgZmFpbHMgdG8gYWxsb2NhdGUgYW5kIGl0J3MgNDA5NiBieXRlcy4g
SQ0KPiA+PiB3YXMgbG9va2luZyB0byBjaGFuZ2VzIGluIG5ldmVyIGtlcm5lbCByZWxlYXNlcyBi
dXQgSSBjYW5ub3QgZmluZA0KPiA+PiBhbnl0aGluZyBvYnZpb3VzLiBXaGVuIGNvbm5lY3RlZCB0
byAyLjRHSHogSSBjYW5ub3QgcmVwcm9kdWNlIGlzc3VlDQo+ID4+IHRob3VnaC4gSSdtIHVzaW5n
IEZXIHZlcnNpb24gbXdpZmlleCAxLjAgKDE0LjY4LjI5LnAyNikuDQo+ID4+DQo+ID4NCj4gPiBD
b3VsZCB5b3UgcGxlYXNlIHByb3ZpZGUgdGhlIHBsYXRmb3JtIGRldGFpbHM/DQo+ID4gSG93IG9m
dGVuIHRoZSBwcm9ibGVtIG9jY3VycyBkdXJpbmcgdGhyb3VnaHB1dCB0ZXN0aW5nPyBBcmUgdGhl
cmUgYW55DQo+IHNwZWNpZmljIHN0ZXBzPw0KPiBPbmUgbW9yZSBvYnNlcnZhdGlvbiBpcyB0aGF0
IHdoZW4gcHJvYmxlbSBvY2N1cnJlZCBjb21wbGV0ZSBzeXN0ZW0gaXMNCj4gdW5yZXNwb25zaXZl
IChjb25zb2xlIGlzIGFsbW9zdCBjb21wbGV0ZWx5IGRlYWQpLg0KDQpUaGFua3MgZm9yIHRoZSBt
b3JlIGluZm9ybWF0aW9uLg0KU2tiIGFsbG9jIGZhaWx1cmUgc2hvdWxkIGJlIGdyYWNlZnVsbHkg
aGFuZGxlZC4gV2Ugd2lsbCBsb29rIGludG8gdGhpcyBpc3N1ZS4NCg0KPiBJIGNhbiB3b3JrYXJv
dW5kIGlzc3VlIGJ5IGRlY3JlYXNpbmcgaXBlcmYgYmFuZHdpZHRoIHRvIH40MG0uIEkgdGhpbmsN
Cj4gaW4gdGhpcyBzaXR1YXRpb24gd2UncmUgcnVubmluZyBvdXQgb2YgbWVtb3J5IGJ5IGV4aGF1
c3RpdmUgc2tiDQo+IGFsbG9jYXRpb25zLg0KDQpBY3R1YWxseSA2IDRLIHNpemUgYnVmZmVycyBh
cmUgYmVpbmcgYWxsb2NhdGVkIGZvciBSeCBhbmQgVHggZGF0YSBkdXJpbmcgdHJhZmZpYy4NClBy
b2JhYmx5IHlvdXIgcGxhdGZvcm0gcnVucyBvdXQgb2YgbWVtb3J5IGFmdGVyIHRoZXNlIGFsbG9j
YXRpb25zLg0KDQpDb3VsZCB5b3UgcGxlYXNlIHRyeSBjaGFuZ2luZyB0aGlzIG51bWJlcihNV0lG
SUVYX1RYX0RBVEFfVVJCL01XSUZJRVhfUlhfREFUQV9VUkIgbWFjcm9zKSB0byAzPw0KDQpSZWdh
cmRzLA0KQW1pdGt1bWFyIEthcndhcg0K

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,

On Wed, Sep 17, 2014 at 12:52 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi BR,
>
>> Dear Amitkumar Karwar,
>>
>> some additional info.
>>
>> On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com>
>> wrote:
>> > Hi BR,
>> >
>> >>
>> >> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing
>> >> some throughput testing (with iperf) in 5GHz I got following
>> failures:
>> >> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
>> >> failed
>> >
>> > This is skb allocation failure returned by kernel. 4k buffer is
>> always allocated for Rx packets. This issue doesn't seem to be specific
>> to 5Ghz.
>> Yes you're right. I can reproduce issue also with 2.4GHz (doing iperf
>> testing as mentioned in other email) by pinging device with card.
>> >
>> >>
>> >> I checked which which size fails to allocate and it's 4096 bytes. I
>> >> was looking to changes in never kernel releases but I cannot find
>> >> anything obvious. When connected to 2.4GHz I cannot reproduce issue
>> >> though. I'm using FW version mwifiex 1.0 (14.68.29.p26).
>> >>
>> >
>> > Could you please provide the platform details?
>> > How often the problem occurs during throughput testing? Are there any
>> specific steps?
>> One more observation is that when problem occurred complete system is
>> unresponsive (console is almost completely dead).
>
> Thanks for the more information.
> Skb alloc failure should be gracefully handled. We will look into this issue.
OK. Thanks. Can you please
>
>> I can workaround issue by decreasing iperf bandwidth to ~40m. I think
>> in this situation we're running out of memory by exhaustive skb
>> allocations.
>
> Actually 6 4K size buffers are being allocated for Rx and Tx data during traffic.
> Probably your platform runs out of memory after these allocations.
This could be the issue. I'm running some apps when performing
throughput test and this could lead
to out of memory. When I stop all apps and perform the test it behave
better (I cannot reproduce issue) except of
fact that whole system is unresponsive for ~ 10 secs as was already mentioned.
>
> Could you please try changing this number(MWIFIEX_TX_DATA_URB/MWIFIEX_RX_DATA_URB macros) to 3?
>
> Regards,
> Amitkumar Karwar

Best Regards,

marekb

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Hi,

I was too fast when hitting Send :)

On Wed, Sep 17, 2014 at 2:07 PM, Belisko Marek <marek.belisko@gmail.com> wrote:
> Dear Amitkumar Karwar,
>
> On Wed, Sep 17, 2014 at 12:52 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
>> Hi BR,
>>
>>> Dear Amitkumar Karwar,
>>>
>>> some additional info.
>>>
>>> On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com>
>>> wrote:
>>> > Hi BR,
>>> >
>>> >>
>>> >> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing
>>> >> some throughput testing (with iperf) in 5GHz I got following
>>> failures:
>>> >> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
>>> >> failed
>>> >
>>> > This is skb allocation failure returned by kernel. 4k buffer is
>>> always allocated for Rx packets. This issue doesn't seem to be specific
>>> to 5Ghz.
>>> Yes you're right. I can reproduce issue also with 2.4GHz (doing iperf
>>> testing as mentioned in other email) by pinging device with card.
>>> >
>>> >>
>>> >> I checked which which size fails to allocate and it's 4096 bytes. I
>>> >> was looking to changes in never kernel releases but I cannot find
>>> >> anything obvious. When connected to 2.4GHz I cannot reproduce issue
>>> >> though. I'm using FW version mwifiex 1.0 (14.68.29.p26).
>>> >>
>>> >
>>> > Could you please provide the platform details?
>>> > How often the problem occurs during throughput testing? Are there any
>>> specific steps?
>>> One more observation is that when problem occurred complete system is
>>> unresponsive (console is almost completely dead).
>>
>> Thanks for the more information.
>> Skb alloc failure should be gracefully handled. We will look into this issue.
> OK. Thanks. Can you please
Can you please ping me when you will have some patch so I can test it
also on my device.
>>
>>> I can workaround issue by decreasing iperf bandwidth to ~40m. I think
>>> in this situation we're running out of memory by exhaustive skb
>>> allocations.
>>
>> Actually 6 4K size buffers are being allocated for Rx and Tx data during traffic.
>> Probably your platform runs out of memory after these allocations.
> This could be the issue. I'm running some apps when performing
> throughput test and this could lead
> to out of memory. When I stop all apps and perform the test it behave
> better (I cannot reproduce issue) except of
> fact that whole system is unresponsive for ~ 10 secs as was already mentioned.
This is not fully true. I run loop iperf test (-t 600) and it will
fail after 4 minutes with (there was around 190MB free memory):

[  875.249551] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  875.256645] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  875.263694] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  875.270940] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  875.277993] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  875.285068] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  3]  0.0- 1.0 sec  81.8 KBytes    670 Kbits/sec  0.034 ms    0/   57 (0%)
[  3]  1.0- 2.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  2.0- 3.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  3.0- 4.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  4.0- 5.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  5.0- 6.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  6.0- 7.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  7.0- 8.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  8.0- 9.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3]  9.0-10.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3] 10.0-11.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3] 11.0-12.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3] 12.0-13.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3] 13.0-14.0 sec  0.00 Bytes  0.00 bits/sec  0.034 ms    0/    0 (nan%)
[  3] 14.0-15.0 sec  81.8 KBytes    670 Kbits/sec  24.506 ms   60/  117 (51%)


[ 1019.644302] usb 1-1: mwifiex_cmd_timeout_func: Timeout cmd id
(1410955919.418091) = 0x6, act = 0x3
[ 1019.653826] usb 1-1: num_data_h2c_failure = 0
[ 1019.658409] usb 1-1: num_cmd_h2c_failure = 0
[ 1019.662907] usb 1-1: num_cmd_timeout = 1
[ 1019.667072] usb 1-1: num_tx_timeout = 0
[ 1019.671117] usb 1-1: last_cmd_index = 4
[ 1019.675186] usb 1-1: last_cmd_id: 28 00 28 00 28 00 5b 00 06 00
[ 1019.681426] usb 1-1: last_cmd_act: 13 01 13 01 13 01 01 00 03 00
[ 1019.687778] usb 1-1: last_cmd_resp_index = 3
[ 1019.692281] usb 1-1: last_cmd_resp_id: 28 80 28 80 28 80 5b 80 28 80
[ 1019.698997] usb 1-1: last_event_index = 2
[ 1019.703223] usb 1-1: last_event: 17 00 33 00 08 00 33 00 08 00
[ 1019.709389] usb 1-1: data_sent=0 cmd_sent=0
[ 1019.713820] usb 1-1: ps_mode=1 ps_state=0
[ 1019.718211] usb 1-1: cmd timeout

>>
>> Could you please try changing this number(MWIFIEX_TX_DATA_URB/MWIFIEX_RX_DATA_URB macros) to 3?
I tried but it doesn't help (also sometimes I see odd driver crashes -
NULL pointer access)
>>
>> Regards,
>> Amitkumar Karwar
>
> Best Regards,
>
> marekb
>
> --
> as simple and primitive as possible
> -------------------------------------------------
> Marek Belisko - OPEN-NANDRA
> Freelance Developer
>
> Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
> Tel: +421 915 052 184
> skype: marekwhite
> twitter: #opennandra
> web: http://open-nandra.com

Best Regards,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[James Cameron]

On Wed, Sep 17, 2014 at 03:52:52AM -0700, Amitkumar Karwar wrote:
> Hi BR,
> 
> > Dear Amitkumar Karwar,
> > 
> > some additional info.
> > 
> > On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com>
> > wrote:
> > > Hi BR,
> > >
> > >>
> > >> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing
> > >> some throughput testing (with iperf) in 5GHz I got following
> > failures:
> > >> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
> > >> failed
> > >
> > > This is skb allocation failure returned by kernel. 4k buffer is
> > always allocated for Rx packets. This issue doesn't seem to be specific
> > to 5Ghz.
> > Yes you're right. I can reproduce issue also with 2.4GHz (doing iperf
> > testing as mentioned in other email) by pinging device with card.
> > >
> > >>
> > >> I checked which which size fails to allocate and it's 4096 bytes. I
> > >> was looking to changes in never kernel releases but I cannot find
> > >> anything obvious. When connected to 2.4GHz I cannot reproduce issue
> > >> though. I'm using FW version mwifiex 1.0 (14.68.29.p26).
> > >>
> > >
> > > Could you please provide the platform details?
> > > How often the problem occurs during throughput testing? Are there any
> > specific steps?
> > One more observation is that when problem occurred complete system is
> > unresponsive (console is almost completely dead).
> 
> Thanks for the more information.
> Skb alloc failure should be gracefully handled. We will look into
> this issue.

If you get time, I'd also appreciate a look into the issue on sdio.c
during data receive.

When dev_alloc_skb fails the interrupt handler does not rewind
the driver state in preparation for a retry.  This is not graceful.

http://dev.laptop.org/ticket/12694 has details, and an adequate
solution we are using in 3.5 to rewind the driver state:

http://dev.laptop.org/git/olpc-kernel/commit/?h=arm-3.5&id=59fcaf10cce5bbdc370ec1c262b12aeb66ed1dca

We're using 8787.

> 
> > I can workaround issue by decreasing iperf bandwidth to ~40m. I think
> > in this situation we're running out of memory by exhaustive skb
> > allocations.
> 
> Actually 6 4K size buffers are being allocated for Rx and Tx data during traffic.
> Probably your platform runs out of memory after these allocations.
> 
> Could you please try changing this number(MWIFIEX_TX_DATA_URB/MWIFIEX_RX_DATA_URB macros) to 3?
> 
> Regards,
> Amitkumar Karwar
> N?????r??y????b?X??ǧv?^?)޺{.n?+????{??*ޕ?,?{ay?\x1dʇڙ?,j\a??f???h???z?\x1e?w???\f???j:+v???w?j?m????\a????zZ+?????ݢj"??!

-- 
James Cameron
http://quozl.linux.org.au/

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,

On Wed, Sep 17, 2014 at 12:52 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi BR,
>
>> Dear Amitkumar Karwar,
>>
>> some additional info.
>>
>> On Thu, Sep 11, 2014 at 5:09 PM, Amitkumar Karwar <akarwar@marvell.com>
>> wrote:
>> > Hi BR,
>> >
>> >>
>> >> I'm using 3.9 mainline mwifiex driver for wireless usb card. Doing
>> >> some throughput testing (with iperf) in 5GHz I got following
>> failures:
>> >> [ 221.521799] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
>> >> failed
>> >
>> > This is skb allocation failure returned by kernel. 4k buffer is
>> always allocated for Rx packets. This issue doesn't seem to be specific
>> to 5Ghz.
>> Yes you're right. I can reproduce issue also with 2.4GHz (doing iperf
>> testing as mentioned in other email) by pinging device with card.
>> >
>> >>
>> >> I checked which which size fails to allocate and it's 4096 bytes. I
>> >> was looking to changes in never kernel releases but I cannot find
>> >> anything obvious. When connected to 2.4GHz I cannot reproduce issue
>> >> though. I'm using FW version mwifiex 1.0 (14.68.29.p26).
>> >>
>> >
>> > Could you please provide the platform details?
>> > How often the problem occurs during throughput testing? Are there any
>> specific steps?
>> One more observation is that when problem occurred complete system is
>> unresponsive (console is almost completely dead).
>
> Thanks for the more information.
> Skb alloc failure should be gracefully handled. We will look into this issue.
I did small investigation (will my limited networking knowledge :))
and to avoid usb issue
I did small hack to free received packet in skb (with specific size
1574 which sends iperf) before sending for
processing to driver workqueue. With this small hack I can run iperf
-b100m on client size without any
allocation issue. Bit more testing shows that 11n rx reordering is in
place when receiving packets send from iperf.
Is there any know issue in this area which could lead to issues
described in my report?

BTW I tested backports driver from 3.17-rc3 and issue is still present.

>
>> I can workaround issue by decreasing iperf bandwidth to ~40m. I think
>> in this situation we're running out of memory by exhaustive skb
>> allocations.
>
> Actually 6 4K size buffers are being allocated for Rx and Tx data during traffic.
> Probably your platform runs out of memory after these allocations.
>
> Could you please try changing this number(MWIFIEX_TX_DATA_URB/MWIFIEX_RX_DATA_URB macros) to 3?
>
> Regards,
> Amitkumar Karwar

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

SGkgTWFyZWssDQoNClNvcnJ5IGZvciBsYXRlIHJlcGx5LiBXZSBoYXZlIHRyaWVkIHRvIHNpbXVs
YXRlIGRldl9hbGxvY19za2IoKSBmYWlsdXJlIG9uIG91ciByZWZlcmVuY2UgcGxhdGZvcm0gYWZ0
ZXIgMTAwdGgsIDIwMHRoLCAzMDB0aCBldGMuIHBhY2tldHMuIE91ciBvYnNlcnZhdGlvbiBpcyB3
aGVuIHRoZSBmYWlsdXJlIG9jY3VycywgY29ycmVzcG9uZGluZyBVUkIgd29uJ3QgZ2V0IHN1Ym1p
dHRlZCwgYnV0IHRyYWZmaWMgY29udGludWVzLiBUcmFmZmljIHN0b3BzIHdoZW4gdGhlIGZhaWx1
cmUgY291bnQgcmVhY2hlcyA2IChtd2lmaWV4IFJ4IFVSQiBjb3VudCkuIFdlIGRvbid0IHNlZSBh
bnkgY3Jhc2ggb3Igc3lzdGVtIHVucmVzcG9uc2l2ZW5lc3MuDQoNCg0KPiBJIGRpZCBzbWFsbCBp
bnZlc3RpZ2F0aW9uICh3aWxsIG15IGxpbWl0ZWQgbmV0d29ya2luZyBrbm93bGVkZ2UgOikpIGFu
ZA0KPiB0byBhdm9pZCB1c2IgaXNzdWUgSSBkaWQgc21hbGwgaGFjayB0byBmcmVlIHJlY2VpdmVk
IHBhY2tldCBpbiBza2INCj4gKHdpdGggc3BlY2lmaWMgc2l6ZQ0KPiAxNTc0IHdoaWNoIHNlbmRz
IGlwZXJmKSBiZWZvcmUgc2VuZGluZyBmb3IgcHJvY2Vzc2luZyB0byBkcml2ZXINCj4gd29ya3F1
ZXVlLiBXaXRoIHRoaXMgc21hbGwgaGFjayBJIGNhbiBydW4gaXBlcmYgLWIxMDBtIG9uIGNsaWVu
dCBzaXplDQo+IHdpdGhvdXQgYW55IGFsbG9jYXRpb24gaXNzdWUuDQoNClRoYXQncyBnb29kIDop
IEFjdHVhbGx5IGtlcm5lbCB3aWxsIHRha2UgY2FyZSBvZiBmcmVlaW5nIHNrYiB3aGVuIGRyaXZl
ciBzdWJtaXRzIHJlY2VpdmVkIHBhY2tldCB1c2luZyBuZXRpZl9yeCgpLiBDb3VsZCB5b3UgcGxl
YXNlIHNoYXJlIHlvdXIgaGFjaz8NCg0KUmVnYXJkcywNCkFtaXQNCg==

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,


On Thu, Oct 9, 2014 at 11:30 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
> Sorry for late reply. We have tried to simulate dev_alloc_skb() failure on our reference platform after 100th, 200th, 300th etc. packets. Our observation is when the failure occurs, corresponding URB won't get submitted, but traffic continues. Traffic stops when the failure count reaches 6 (mwifiex Rx URB count). We don't see any crash or system unresponsiveness.
No I don't see such behavior. In my case usb still sending packets
over URB (also proven by below hack). My platform is am335x (same chip
as on beaglebone).
>
>
>> I did small investigation (will my limited networking knowledge :)) and
>> to avoid usb issue I did small hack to free received packet in skb
>> (with specific size
>> 1574 which sends iperf) before sending for processing to driver
>> workqueue. With this small hack I can run iperf -b100m on client size
>> without any allocation issue.
>
> That's good :) Actually kernel will take care of freeing skb when driver submits received packet using netif_rx(). Could you please share your hack?
Yes it should be freed when netif_rx() is processed but I have feeling
that sometimes (my case) during high load (-b 100m) packets are not
send to kernel (not free skb)
until skb allocation fails. I need to better understand 11n reordering code :).

Hack (it's dirty I know but packets of that size are send only during
iperf session):

diff --git a/drivers/net/wireless/mwifiex/usb.c
b/drivers/net/wireless/mwifiex/usb.c
index f90fe21..cc548a1 100644
--- a/drivers/net/wireless/mwifiex/usb.c
+++ b/drivers/net/wireless/mwifiex/usb.c
@@ -178,6 +178,12 @@ static void mwifiex_usb_rx_complete(struct urb *urb)
                dev_dbg(adapter->dev, "info: recv_length=%d, status=%d\n",
                        recv_length, status);
                if (status == -EINPROGRESS) {
+
+                       if (skb->len >= 1574) {
+                               dev_kfree_skb_any(skb);
+                               goto setup_for_next;
+                       }
+
                        queue_work(adapter->workqueue, &adapter->main_work);

                        /* urb for data_ep is re-submitted now;
>
> Regards,
> Amit

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

[-- Attachment #1: Type: text/plain, Size: 1625 bytes --]

Hi Marek,

>>
>> That's good :) Actually kernel will take care of freeing skb when
>driver submits received packet using netif_rx(). Could you please share
>your hack?
>Yes it should be freed when netif_rx() is processed but I have feeling
>that sometimes (my case) during high load (-b 100m) packets are not send
>to kernel (not free skb) until skb allocation fails. I need to better
>understand 11n reordering code :).

Rx reorder logic can buffer upto 32 packets, if they aren't received in correct order. You are right. Your platform may run out of memory in this case.
Could you please check if the problem fixes with any of the attached changes?
1) Change Rx window size from 32 to 8.
2) Disable AMPDU feature.

>
>Hack (it's dirty I know but packets of that size are send only during
>iperf session):
>
>diff --git a/drivers/net/wireless/mwifiex/usb.c
>b/drivers/net/wireless/mwifiex/usb.c
>index f90fe21..cc548a1 100644
>--- a/drivers/net/wireless/mwifiex/usb.c
>+++ b/drivers/net/wireless/mwifiex/usb.c
>@@ -178,6 +178,12 @@ static void mwifiex_usb_rx_complete(struct urb
>*urb)
>                dev_dbg(adapter->dev, "info: recv_length=%d,
>status=%d\n",
>                        recv_length, status);
>                if (status == -EINPROGRESS) {
>+
>+                       if (skb->len >= 1574) {
>+                               dev_kfree_skb_any(skb);
>+                               goto setup_for_next;
>+                       }
>+

The change doesn't look correct. The skb is being processed/used. We cannot free it here. This may create problem.

Regards,
Amit

[-- Attachment #2: disable_ampdu_feature.diff --]
[-- Type: application/octet-stream, Size: 1038 bytes --]

diff --git a/sta_event.c b/sta_event.c
index a1de2d3..0b408d2 100644
--- a/sta_event.c
+++ b/sta_event.c
@@ -439,10 +439,7 @@ int mwifiex_process_sta_event(struct mwifiex_private *priv)
 				HostCmd_ACT_GEN_GET, 0, NULL, false);
 		break;
 	case EVENT_ADDBA:
-		dev_dbg(adapter->dev, "event: ADDBA Request\n");
-		mwifiex_send_cmd(priv, HostCmd_CMD_11N_ADDBA_RSP,
-				 HostCmd_ACT_GEN_SET, 0,
-				 adapter->event_body, false);
+		dev_dbg(adapter->dev, "event: ADDBA Request ignoring...\n");
 		break;
 	case EVENT_DELBA:
 		dev_dbg(adapter->dev, "event: DELBA Request\n");
diff --git a/wmm.c b/wmm.c
index dc1f2ad..cb2c4cd 100644
--- a/wmm.c
+++ b/wmm.c
@@ -421,9 +421,9 @@ mwifiex_wmm_init(struct mwifiex_adapter *adapter)
 				priv->aggr_prio_tbl[i].amsdu =
 							BA_STREAM_NOT_ALLOWED;
 			priv->aggr_prio_tbl[i].ampdu_ap =
-							priv->tos_to_tid_inv[i];
+							BA_STREAM_NOT_ALLOWED;
 			priv->aggr_prio_tbl[i].ampdu_user =
-							priv->tos_to_tid_inv[i];
+							BA_STREAM_NOT_ALLOWED;
 		}
 
 		mwifiex_set_ba_params(priv);

[-- Attachment #3: reduce_Rx_window_size.diff --]
[-- Type: application/octet-stream, Size: 816 bytes --]

diff --git a/decl.h b/decl.h
index aad3a4b..6a59f6e 100644
--- a/decl.h
+++ b/decl.h
@@ -43,13 +43,13 @@
 #define MWIFIEX_MAX_RX_BASTREAM_SUPPORTED	16
 
 #define MWIFIEX_STA_AMPDU_DEF_TXWINSIZE        64
-#define MWIFIEX_STA_AMPDU_DEF_RXWINSIZE        64
+#define MWIFIEX_STA_AMPDU_DEF_RXWINSIZE        8
 #define MWIFIEX_UAP_AMPDU_DEF_TXWINSIZE        32
-#define MWIFIEX_UAP_AMPDU_DEF_RXWINSIZE        16
+#define MWIFIEX_UAP_AMPDU_DEF_RXWINSIZE        8
 #define MWIFIEX_11AC_STA_AMPDU_DEF_TXWINSIZE   64
-#define MWIFIEX_11AC_STA_AMPDU_DEF_RXWINSIZE   64
+#define MWIFIEX_11AC_STA_AMPDU_DEF_RXWINSIZE   8
 #define MWIFIEX_11AC_UAP_AMPDU_DEF_TXWINSIZE   64
-#define MWIFIEX_11AC_UAP_AMPDU_DEF_RXWINSIZE   64
+#define MWIFIEX_11AC_UAP_AMPDU_DEF_RXWINSIZE   8
 
 #define MWIFIEX_DEFAULT_BLOCK_ACK_TIMEOUT  0xffff
 

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear Amitkumar Karwar,

On Mon, Oct 13, 2014 at 3:41 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
>>>
>>> That's good :) Actually kernel will take care of freeing skb when
>>driver submits received packet using netif_rx(). Could you please share
>>your hack?
>>Yes it should be freed when netif_rx() is processed but I have feeling
>>that sometimes (my case) during high load (-b 100m) packets are not send
>>to kernel (not free skb) until skb allocation fails. I need to better
>>understand 11n reordering code :).
>
> Rx reorder logic can buffer upto 32 packets, if they aren't received in correct order. You are right. Your platform may run out of memory in this case.
> Could you please check if the problem fixes with any of the attached changes?
> 1) Change Rx window size from 32 to 8.
> 2) Disable AMPDU feature.
Thanks for patches.
I tried both (slightly modified as we're in 3.9 kernel) but issue is
still reproducible. My patch against 3.9 sources:
diff --git a/drivers/net/wireless/mwifiex/decl.h
b/drivers/net/wireless/mwifiex/decl.h
index e8a569a..916924c 100644
--- a/drivers/net/wireless/mwifiex/decl.h
+++ b/drivers/net/wireless/mwifiex/decl.h
@@ -42,7 +42,7 @@
 #define MWIFIEX_MAX_RX_BASTREAM_SUPPORTED      16

 #define MWIFIEX_AMPDU_DEF_TXWINSIZE        32
-#define MWIFIEX_AMPDU_DEF_RXWINSIZE        16
+#define MWIFIEX_AMPDU_DEF_RXWINSIZE        8
 #define MWIFIEX_DEFAULT_BLOCK_ACK_TIMEOUT  0xffff

 #define MWIFIEX_RATE_BITMAP_MCS0   32
diff --git a/drivers/net/wireless/mwifiex/sta_event.c
b/drivers/net/wireless/mwifiex/sta_event.c
index 41aafc7..05a36f0 100644
--- a/drivers/net/wireless/mwifiex/sta_event.c
+++ b/drivers/net/wireless/mwifiex/sta_event.c
@@ -378,10 +378,7 @@ int mwifiex_process_sta_event(struct mwifiex_private *priv)
                                HostCmd_ACT_GEN_GET, 0, NULL);
                break;
        case EVENT_ADDBA:
-               dev_dbg(adapter->dev, "event: ADDBA Request\n");
-               mwifiex_send_cmd_async(priv, HostCmd_CMD_11N_ADDBA_RSP,
-                                      HostCmd_ACT_GEN_SET, 0,
-                                      adapter->event_body);
+               dev_dbg(adapter->dev, "event: ADDBA Request ignoring\n");
                break;
        case EVENT_DELBA:
                dev_dbg(adapter->dev, "event: DELBA Request\n");
diff --git a/drivers/net/wireless/mwifiex/wmm.c
b/drivers/net/wireless/mwifiex/wmm.c
index 2670676..3d0aa02 100644
--- a/drivers/net/wireless/mwifiex/wmm.c
+++ b/drivers/net/wireless/mwifiex/wmm.c
@@ -415,8 +415,8 @@ mwifiex_wmm_init(struct mwifiex_adapter *adapter)

                for (i = 0; i < MAX_NUM_TID; ++i) {
                        priv->aggr_prio_tbl[i].amsdu = tos_to_tid_inv[i];
-                       priv->aggr_prio_tbl[i].ampdu_ap = tos_to_tid_inv[i];
-                       priv->aggr_prio_tbl[i].ampdu_user = tos_to_tid_inv[i];
+                       priv->aggr_prio_tbl[i].ampdu_ap = BA_STREAM_NOT_ALLOWED;
+                       priv->aggr_prio_tbl[i].ampdu_user =
BA_STREAM_NOT_ALLOWED;
                }

                priv->aggr_prio_tbl[6].amsdu

One thing which is not yet still clear to me why kernel console is
completely unresponsive when
receiving packets in high rates. When use iperf (on client) with -b40m
it is OK but when increase to -b100m then console
is completely unresponsive until iperf finish. Any other ideas what to
change to check? Thanks.

>
>>
>>Hack (it's dirty I know but packets of that size are send only during
>>iperf session):
>>
>>diff --git a/drivers/net/wireless/mwifiex/usb.c
>>b/drivers/net/wireless/mwifiex/usb.c
>>index f90fe21..cc548a1 100644
>>--- a/drivers/net/wireless/mwifiex/usb.c
>>+++ b/drivers/net/wireless/mwifiex/usb.c
>>@@ -178,6 +178,12 @@ static void mwifiex_usb_rx_complete(struct urb
>>*urb)
>>                dev_dbg(adapter->dev, "info: recv_length=%d,
>>status=%d\n",
>>                        recv_length, status);
>>                if (status == -EINPROGRESS) {
>>+
>>+                       if (skb->len >= 1574) {
>>+                               dev_kfree_skb_any(skb);
>>+                               goto setup_for_next;
>>+                       }
>>+
>
> The change doesn't look correct. The skb is being processed/used. We cannot free it here. This may create problem.
>
> Regards,
> Amit

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

[-- Attachment #1: Type: text/plain, Size: 821 bytes --]

Hi Marek,

>I tried both (slightly modified as we're in 3.9 kernel) but issue is
>still reproducible. My patch against 3.9 sources:

Thanks a lot for the tests.

>One thing which is not yet still clear to me why kernel console is
>completely unresponsive when receiving packets in high rates. When use
>iperf (on client) with -b40m it is OK but when increase to -b100m then
>console is completely unresponsive until iperf finish. 

Does the system recover when "-b100M" iperf is finished? Can we run iperf with "-b40M" later?
Do you see "dev_alloc_skb failed" messages in dmesg when console is unresponsive?

>Any other ideas
>what to change to check? Thanks.

Could you please share dmesg log with dynamic debug enabled (using attached script) captured when the problem occurs?

Best regards,
Amit

[-- Attachment #2: mwifiex_dynamic_debug.sh --]
[-- Type: application/octet-stream, Size: 429 bytes --]

# This script enables debug logs for mwifiex driver.
# Make sure that dynamic debug is enable in your kernel configuration (CONFIG_DYNAMIC_DEBUG=y)
mount -t debugfs debugfs /debugfs
echo "module mwifiex +p" > /debugfs/dynamic_debug/control
echo "module mwifiex_pcie +p" > /debugfs/dynamic_debug/control
echo "module mwifiex_usb +p" > /debugfs/dynamic_debug/control
echo "module mwifiex_sdio +p" > /debugfs/dynamic_debug/control

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Hi Amitkumar,

On Tue, Oct 14, 2014 at 9:08 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
>>I tried both (slightly modified as we're in 3.9 kernel) but issue is
>>still reproducible. My patch against 3.9 sources:
>
> Thanks a lot for the tests.
>
>>One thing which is not yet still clear to me why kernel console is
>>completely unresponsive when receiving packets in high rates. When use
>>iperf (on client) with -b40m it is OK but when increase to -b100m then
>>console is completely unresponsive until iperf finish.
>
> Does the system recover when "-b100M" iperf is finished? Can we run iperf with "-b40M" later?
> Do you see "dev_alloc_skb failed" messages in dmesg when console is unresponsive?
When we get "dev_alloc_skb failed" then interface is dead (cannot ping
...) so no recovery is possible only system reboot.
I don't see  dev_alloc_skb failed when console is unresponsive.
>
>>Any other ideas
>>what to change to check? Thanks.
>
> Could you please share dmesg log with dynamic debug enabled (using attached script) captured when the problem occurs?
I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
reproduce issue (running test > 30 minutes without allocation
failure).
>
> Best regards,
> Amit

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[James Cameron]

On Tue, Oct 14, 2014 at 10:25:01AM +0200, Belisko Marek wrote:
> Hi Amitkumar,
> 
> On Tue, Oct 14, 2014 at 9:08 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> > Hi Marek,
> >
> > > I tried both (slightly modified as we're in 3.9 kernel) but
> > > issue is still reproducible. My patch against 3.9 sources:
> >
> > Thanks a lot for the tests.
> >
> > > One thing which is not yet still clear to me why kernel console
> > > is completely unresponsive when receiving packets in high
> > > rates. When use iperf (on client) with -b40m it is OK but when
> > > increase to -b100m then console is completely unresponsive until
> > > iperf finish.
> >
> > Does the system recover when "-b100M" iperf is finished? Can we
> > run iperf with "-b40M" later?  Do you see "dev_alloc_skb failed"
> > messages in dmesg when console is unresponsive?
> When we get "dev_alloc_skb failed" then interface is dead (cannot
> ping ...) so no recovery is possible only system reboot.

This symptom was familiar to me, but on sdio.c, which is very
different code.

I've had a brief look at usb.c and offer the following comments:

- a list of six data endpoint urb is allocated in mwifiex_usb_rx_init,
  because MWIFIEX_RX_DATA_URB is 6,

- when data endpoint urb is submitted, a new skb is allocated, in
  mwifiex_usb_submit_rx_urb, and this is the only source of
  "dev_alloc_skb failed" message,

- in normal situation, when data endpoint urb is complete, skb is
  either freed or handed up to mwifiex_usb_recv, and the urb is
  resubmitted, which causes a new skb to be allocated.

- if "dev_alloc_skb failed" message appears, one data endpoint urb has
  been lost and is not re-used,

- if six "dev_alloc_skb failed" messages appear, the interface should
  be dead for data receive only.

Amitkumar mentioned this on 9th October; "corresponding URB won't get
submitted".  I think this should be fixed; dev_alloc_skb should be
harmless failure, please retry.

I don't see why interface is dead with only one "dev_alloc_skb
failed" message.

> I don't see  dev_alloc_skb failed when console is unresponsive.
> >
> > > Any other ideas
> > > what to change to check? Thanks.
> >
> > Could you please share dmesg log with dynamic debug enabled (using
> > attached script) captured when the problem occurs?
> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
> reproduce issue (running test > 30 minutes without allocation
> failure).

Yes, I've seen similar; turn on debugging, and timing critical bug
goes away.

Serial console?  If so, try turning it off, and logging to dmesg
buffer only.

-- 
James Cameron
http://quozl.linux.org.au/

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Dear James Cameron,

On Tue, Oct 14, 2014 at 12:20 PM, James Cameron <quozl@laptop.org> wrote:
> On Tue, Oct 14, 2014 at 10:25:01AM +0200, Belisko Marek wrote:
>> Hi Amitkumar,
>>
>> On Tue, Oct 14, 2014 at 9:08 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
>> > Hi Marek,
>> >
>> > > I tried both (slightly modified as we're in 3.9 kernel) but
>> > > issue is still reproducible. My patch against 3.9 sources:
>> >
>> > Thanks a lot for the tests.
>> >
>> > > One thing which is not yet still clear to me why kernel console
>> > > is completely unresponsive when receiving packets in high
>> > > rates. When use iperf (on client) with -b40m it is OK but when
>> > > increase to -b100m then console is completely unresponsive until
>> > > iperf finish.
>> >
>> > Does the system recover when "-b100M" iperf is finished? Can we
>> > run iperf with "-b40M" later?  Do you see "dev_alloc_skb failed"
>> > messages in dmesg when console is unresponsive?
>> When we get "dev_alloc_skb failed" then interface is dead (cannot
>> ping ...) so no recovery is possible only system reboot.
>
> This symptom was familiar to me, but on sdio.c, which is very
> different code.
>
> I've had a brief look at usb.c and offer the following comments:
>
> - a list of six data endpoint urb is allocated in mwifiex_usb_rx_init,
>   because MWIFIEX_RX_DATA_URB is 6,
>
> - when data endpoint urb is submitted, a new skb is allocated, in
>   mwifiex_usb_submit_rx_urb, and this is the only source of
>   "dev_alloc_skb failed" message,
>
> - in normal situation, when data endpoint urb is complete, skb is
>   either freed or handed up to mwifiex_usb_recv, and the urb is
>   resubmitted, which causes a new skb to be allocated.
>
> - if "dev_alloc_skb failed" message appears, one data endpoint urb has
>   been lost and is not re-used,
>
> - if six "dev_alloc_skb failed" messages appear, the interface should
>   be dead for data receive only.
>
> Amitkumar mentioned this on 9th October; "corresponding URB won't get
> submitted".  I think this should be fixed; dev_alloc_skb should be
> harmless failure, please retry.
>
> I don't see why interface is dead with only one "dev_alloc_skb
> failed" message.
Maybe my description wasn't  not correct. I see 6 "dev_alloc_skb
failed" messages and then interface is dead
as you wrote.
>
>> I don't see  dev_alloc_skb failed when console is unresponsive.
>> >
>> > > Any other ideas
>> > > what to change to check? Thanks.
>> >
>> > Could you please share dmesg log with dynamic debug enabled (using
>> > attached script) captured when the problem occurs?
>> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
>> reproduce issue (running test > 30 minutes without allocation
>> failure).
>
> Yes, I've seen similar; turn on debugging, and timing critical bug
> goes away.
>
> Serial console?  If so, try turning it off, and logging to dmesg
> buffer only.
When turning off serial console how then I get kernel messages from
dmesg buffer?
>
> --
> James Cameron
> http://quozl.linux.org.au/

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[James Cameron]

On Tue, Oct 14, 2014 at 12:48:07PM +0200, Belisko Marek wrote:
> Dear James Cameron,
> 
> On Tue, Oct 14, 2014 at 12:20 PM, James Cameron <quozl@laptop.org> wrote:
> > On Tue, Oct 14, 2014 at 10:25:01AM +0200, Belisko Marek wrote:
> >> Hi Amitkumar,
> >>
> >> On Tue, Oct 14, 2014 at 9:08 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> >> > Hi Marek,
> >> >
> >> > > I tried both (slightly modified as we're in 3.9 kernel) but
> >> > > issue is still reproducible. My patch against 3.9 sources:
> >> >
> >> > Thanks a lot for the tests.
> >> >
> >> > > One thing which is not yet still clear to me why kernel console
> >> > > is completely unresponsive when receiving packets in high
> >> > > rates. When use iperf (on client) with -b40m it is OK but when
> >> > > increase to -b100m then console is completely unresponsive until
> >> > > iperf finish.
> >> >
> >> > Does the system recover when "-b100M" iperf is finished? Can we
> >> > run iperf with "-b40M" later?  Do you see "dev_alloc_skb failed"
> >> > messages in dmesg when console is unresponsive?
> >> When we get "dev_alloc_skb failed" then interface is dead (cannot
> >> ping ...) so no recovery is possible only system reboot.
> >
> > This symptom was familiar to me, but on sdio.c, which is very
> > different code.
> >
> > I've had a brief look at usb.c and offer the following comments:
> >
> > - a list of six data endpoint urb is allocated in mwifiex_usb_rx_init,
> >   because MWIFIEX_RX_DATA_URB is 6,
> >
> > - when data endpoint urb is submitted, a new skb is allocated, in
> >   mwifiex_usb_submit_rx_urb, and this is the only source of
> >   "dev_alloc_skb failed" message,
> >
> > - in normal situation, when data endpoint urb is complete, skb is
> >   either freed or handed up to mwifiex_usb_recv, and the urb is
> >   resubmitted, which causes a new skb to be allocated.
> >
> > - if "dev_alloc_skb failed" message appears, one data endpoint urb has
> >   been lost and is not re-used,
> >
> > - if six "dev_alloc_skb failed" messages appear, the interface should
> >   be dead for data receive only.
> >
> > Amitkumar mentioned this on 9th October; "corresponding URB won't get
> > submitted".  I think this should be fixed; dev_alloc_skb should be
> > harmless failure, please retry.
> >
> > I don't see why interface is dead with only one "dev_alloc_skb
> > failed" message.
> Maybe my description wasn't  not correct. I see 6 "dev_alloc_skb
> failed" messages and then interface is dead
> as you wrote.

Thanks.  That is what I expected.

> >> I don't see  dev_alloc_skb failed when console is unresponsive.
> >> >
> >> > > Any other ideas
> >> > > what to change to check? Thanks.
> >> >
> >> > Could you please share dmesg log with dynamic debug enabled (using
> >> > attached script) captured when the problem occurs?
> >> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
> >> reproduce issue (running test > 30 minutes without allocation
> >> failure).
> >
> > Yes, I've seen similar; turn on debugging, and timing critical bug
> > goes away.
> >
> > Serial console?  If so, try turning it off, and logging to dmesg
> > buffer only.
> When turning off serial console how then I get kernel messages from
> dmesg buffer?

I use three techniques depending on how usable the system is afterwards:

0.  capture kernel messages to disk, using rsyslog or other user space
assistance; often there is enough information saved before the system
is unresponsive,

1.  type dmesg at a console shell prompt,

2.  watchdog trigger system reset, and in firmware locate the dmesg
buffer structures in memory, and dump them to serial.

http://lists.laptop.org/pipermail/devel/2012-January/034253.html

-- 
James Cameron
http://quozl.linux.org.au/

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Below reply I post by accident in html which was rejected by ML.
Re-posting again. Sorry about that.

On Tue, Oct 14, 2014 at 10:25 AM, Belisko Marek <marek.belisko@gmail.com> wrote:
> Hi Amitkumar,
>
> On Tue, Oct 14, 2014 at 9:08 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
>> Hi Marek,
>>
>>>I tried both (slightly modified as we're in 3.9 kernel) but issue is
>>>still reproducible. My patch against 3.9 sources:
>>
>> Thanks a lot for the tests.
>>
>>>One thing which is not yet still clear to me why kernel console is
>>>completely unresponsive when receiving packets in high rates. When use
>>>iperf (on client) with -b40m it is OK but when increase to -b100m then
>>>console is completely unresponsive until iperf finish.
>>
>> Does the system recover when "-b100M" iperf is finished? Can we run iperf with "-b40M" later?
>> Do you see "dev_alloc_skb failed" messages in dmesg when console is unresponsive?
> When we get "dev_alloc_skb failed" then interface is dead (cannot ping
> ...) so no recovery is possible only system reboot.
> I don't see  dev_alloc_skb failed when console is unresponsive.
>>
>>>Any other ideas
>>>what to change to check? Thanks.
>>
>> Could you please share dmesg log with dynamic debug enabled (using attached script) captured when the problem occurs?
> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
> reproduce issue (running test > 30 minutes without allocation
> failure).
Any update on this? Should I provide some other logs?
>>
>> Best regards,
>> Amit
>
> BR,
>
> marek
>
> --
> as simple and primitive as possible
> -------------------------------------------------
> Marek Belisko - OPEN-NANDRA
> Freelance Developer
>
> Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
> Tel: +421 915 052 184
> skype: marekwhite
> twitter: #opennandra
> web: http://open-nandra.com

Thanks,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

Hi Marek,

>> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
>> reproduce issue (running test > 30 minutes without allocation
>> failure).

Thanks for the testing. Yes. Sometimes timing issues won't get reproduced with debug messages enabled.

>Any update on this? Should I provide some other logs?

What's the size of Rx data packets? Is the Rx data AMSDU aggregated?(You can check if "if (rx_pkt_type == PKT_TYPE_AMSDU)" check is passed in mwifiex code) If so, disable AMSDU option in AP and try to reproduce the issue. 

As you suspected earlier, we might have missed to free skbs allocated for Rx data which leads to SKB allocation failure. There is very less probability for this. But we can try below experiment.  

1) I observed that debug variable "adapter->rx_pending" doesn;t get decremented when packet is submitted to kernel. Add below code change(valid only for AMSDU disabled case. Because multiple packets are submitted to kernel when AMSDU is enabled)

----------
--- a/drivers/net/wireless/mwifiex/util.c
+++ b/drivers/net/wireless/mwifiex/util.c
@@ -218,6 +218,7 @@ int mwifiex_recv_packet(struct mwifiex_private *priv, struct sk_buff *skb)
 
        priv->stats.rx_bytes += skb->len;
        priv->stats.rx_packets++;
+       atomic_dec(&priv->adapter->rx_pending);
        if (in_interrupt())
                netif_rx(skb);
----------

2) Add BUG_ON when first time SKB allocation is failed and print "rx_pending". If it's a huge number, we have missed freeing allocated SKB.

3) Also, get rx_pending info when Rx traffic works fine with 40M bandwidth option.

Btw, could you move to the firmware image (14.68.29.p38)
shared recently?

By any means(redirecting the log to serial console etc.), could you please capture and share kernel trace logs when system becomes unresponsive. It may give some clue and help us debug further.

Best Regards,
Amit

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

[-- Attachment #1: Type: text/plain, Size: 7598 bytes --]

Hi Amitkumar,

On Thu, Oct 23, 2014 at 2:40 PM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
>>> I tried to capture logs but when enable DYNAMIC_DEBUG I cannot
>>> reproduce issue (running test > 30 minutes without allocation
>>> failure).
>
> Thanks for the testing. Yes. Sometimes timing issues won't get reproduced with debug messages enabled.
>
>>Any update on this? Should I provide some other logs?
>
> What's the size of Rx data packets? Is the Rx data AMSDU aggregated?(You can check if "if (rx_pkt_type == PKT_TYPE_AMSDU)" check is passed in mwifiex code) If so, disable AMSDU option in AP and try to reproduce the issue.
Size of Rx data packets are : pkt type == 2, size - 1574bytes + BAR
pkt type, size - 34bytes. AMSDU isn't enabled on AP (verified by
adding debug message in mwifiex_process_sta_rx_packet()).
>
> As you suspected earlier, we might have missed to free skbs allocated for Rx data which leads to SKB allocation failure. There is very less probability for this. But we can try below experiment.
>
> 1) I observed that debug variable "adapter->rx_pending" doesn;t get decremented when packet is submitted to kernel. Add below code change(valid only for AMSDU disabled case. Because multiple packets are submitted to kernel when AMSDU is enabled)
>
> ----------
> --- a/drivers/net/wireless/mwifiex/util.c
> +++ b/drivers/net/wireless/mwifiex/util.c
> @@ -218,6 +218,7 @@ int mwifiex_recv_packet(struct mwifiex_private *priv, struct sk_buff *skb)
>
>         priv->stats.rx_bytes += skb->len;
>         priv->stats.rx_packets++;
> +       atomic_dec(&priv->adapter->rx_pending);
>         if (in_interrupt())
>                 netif_rx(skb);
> ----------
OK, patch applied.
>
> 2) Add BUG_ON when first time SKB allocation is failed and print "rx_pending". If it's a huge number, we have missed freeing allocated SKB.
[  167.624452] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed, rx_pending:26893
[  167.632885] ------------[ cut here ]------------
[  167.637743] Kernel BUG at bf8a22ae [verbose debug info unavailable]
so number seems to be huge and we seems miss free allocated skb.

I did some hacks to code which shows how many packets are received
between 2 BAR packets + I print every 500ms rx_pending packets (when
packet is received) and
also when packet is send to kernel. I also update counter how many
packets after reordering are sent to kernel. Log:
[   71.973800] usb 1-1: rx_pending:11
[   72.077308] usb 1-1: rx_pending kernel:10
[   72.477546] usb 1-1: rx_pending:868
[   72.587877] usb 1-1: rx_pending kernel:1096
[   72.818041] usb 1-1: Received between 2 BAR:6275
[   72.823127] usb 1-1: Networking send size:6271
[   72.987375] usb 1-1: rx_pending:1940
[   73.097504] usb 1-1: rx_pending kernel:2159
[   73.431973] usb 1-1: Received between 2 BAR:1602
[   73.437106] usb 1-1: Networking send size:1608
[   73.497381] usb 1-1: rx_pending:2983
[   73.608315] usb 1-1: rx_pending kernel:3091
[   74.007379] usb 1-1: rx_pending:3767
[   74.117879] usb 1-1: rx_pending kernel:3998
[   74.517375] usb 1-1: rx_pending:4854
[   74.543168] usb 1-1: Received between 2 BAR:3152
[   74.548371] usb 1-1: Networking send size:3152
[   74.627509] usb 1-1: rx_pending kernel:5062
[   74.743362] usb 1-1: Received between 2 BAR:495
[   74.748483] usb 1-1: Networking send size:494
[   75.027523] usb 1-1: rx_pending:5872
[   75.137961] usb 1-1: rx_pending kernel:6106
[   75.537485] usb 1-1: rx_pending:6959
[   75.647934] usb 1-1: rx_pending kernel:7188
[   75.656273] usb 1-1: Received between 2 BAR:2383
[   75.661528] usb 1-1: Networking send size:2382
[   76.047441] usb 1-1: rx_pending:8004
[   76.157712] usb 1-1: rx_pending kernel:8240
[   76.557547] usb 1-1: rx_pending:9095
[   76.667991] usb 1-1: rx_pending kernel:9326
[   76.769662] usb 1-1: Received between 2 BAR:2918
[   76.775047] usb 1-1: Networking send size:2914
[   77.067491] usb 1-1: rx_pending:10155
[   77.177524] usb 1-1: rx_pending kernel:10383
[   77.577547] usb 1-1: rx_pending:11237
[   77.687859] usb 1-1: rx_pending kernel:11461
[   78.087401] usb 1-1: rx_pending:12304
[   78.197992] usb 1-1: rx_pending kernel:12539
[   78.597442] usb 1-1: rx_pending:13391
[   78.707786] usb 1-1: rx_pending kernel:13628
[   79.107487] usb 1-1: rx_pending:14469
[   79.217812] usb 1-1: rx_pending kernel:14704
[   79.617528] usb 1-1: rx_pending:15555
[   79.727734] usb 1-1: rx_pending kernel:15781
[   80.127486] usb 1-1: rx_pending:16624
[   80.237756] usb 1-1: rx_pending kernel:16855
[   80.637423] usb 1-1: rx_pending:17699
[   80.747868] usb 1-1: rx_pending kernel:17926
[   81.147446] usb 1-1: rx_pending:18769
[   81.257800] usb 1-1: rx_pending kernel:18995
[   81.657399] usb 1-1: rx_pending:19851
[   81.767785] usb 1-1: rx_pending kernel:20083
[   82.167341] usb 1-1: rx_pending:20938
[   82.278005] usb 1-1: rx_pending kernel:21174
[   82.677527] usb 1-1: rx_pending:22025
[   82.787508] usb 1-1: rx_pending kernel:22246
[   83.187390] usb 1-1: rx_pending:23103
[   83.297690] usb 1-1: rx_pending kernel:23326
[   83.697376] usb 1-1: rx_pending:24182
[   83.807711] usb 1-1: rx_pending kernel:24404
[   84.207487] usb 1-1: rx_pending:25236
[   84.317747] usb 1-1: rx_pending kernel:25466
[   84.717378] usb 1-1: rx_pending:26308
[   84.827806] usb 1-1: rx_pending kernel:26522
[   85.070931] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27017
[   85.079788] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27019
[   85.088424] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27020
[   85.097029] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27020
[   85.105845] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27022
[   85.114468] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb
failed - rx_pending:27023
[   85.337391] usb 1-1: rx_pending kernel:22327
[   85.400153] usb 1-1: Received between 2 BAR:27875
[   85.405135] usb 1-1: Networking send size:27881
[   85.766194] usb 1-1: Received between 2 BAR:7781
[   85.771152] usb 1-1: Networking send size:7781
[   85.847374] usb 1-1: rx_pending kernel:11681
[   86.112809] usb 1-1: Received between 2 BAR:7263
[   86.117755] usb 1-1: Networking send size:7262
[   86.357378] usb 1-1: rx_pending kernel:827

According log it seems rx_pending is slowly increasing until
allocation fails. Code hacks are attached.

>
> 3) Also, get rx_pending info when Rx traffic works fine with 40M bandwidth option.
when -b40 is set then IMO 11n reordering isn't applied. I added some
debug code to mwifiex_11n_rx_reorder_pkt()
.. snip ..
tbl = mwifiex_11n_get_rx_reorder_tbl(priv, tid, ta);
 if (!tbl) {
.. snip ..

is always true (!tbl) so rx_pending after session is 0.

>
> Btw, could you move to the firmware image (14.68.29.p38)
> shared recently?
Tested with  14.68.29.p38 FW version. Issue still reproducible.
>
> By any means(redirecting the log to serial console etc.), could you please capture and share kernel trace logs when system becomes unresponsive. It may give some clue and help us debug further.
As I wrote earlier with DYNAMIC_DEBUG I cannot reproduce issue. Maybe
when we drop some debug code (received packet over USB) issue can be
reproducible again, but it's just guess.
>
> Best Regards,
> Amit

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

[-- Attachment #2: patch.txt --]
[-- Type: text/plain, Size: 8755 bytes --]

diff --git a/drivers/net/wireless/mwifiex/11n_rxreorder.c b/drivers/net/wireless/mwifiex/11n_rxreorder.c
index 5e796f8..f6a8d0d 100644
--- a/drivers/net/wireless/mwifiex/11n_rxreorder.c
+++ b/drivers/net/wireless/mwifiex/11n_rxreorder.c
@@ -26,6 +26,7 @@
 #include "11n.h"
 #include "11n_rxreorder.h"
 
+static int pkt_send = 0;
 /*
  * This function dispatches all packets in the Rx reorder table until the
  * start window.
@@ -36,7 +37,7 @@
  */
 static void
 mwifiex_11n_dispatch_pkt(struct mwifiex_private *priv,
-			 struct mwifiex_rx_reorder_tbl *tbl, int start_win)
+			 struct mwifiex_rx_reorder_tbl *tbl, int start_win, int *send_size)
 {
 	int pkt_to_send, i;
 	void *rx_tmp_ptr;
@@ -45,6 +46,7 @@ mwifiex_11n_dispatch_pkt(struct mwifiex_private *priv,
 	pkt_to_send = (start_win > tbl->start_win) ?
 		      min((start_win - tbl->start_win), tbl->win_size) :
 		      tbl->win_size;
+//	pr_info("%s - pkt_to_send:%d\n", __func__, pkt_to_send);
 
 	for (i = 0; i < pkt_to_send; ++i) {
 		spin_lock_irqsave(&priv->rx_pkt_lock, flags);
@@ -57,8 +59,11 @@ mwifiex_11n_dispatch_pkt(struct mwifiex_private *priv,
 		if (rx_tmp_ptr) {
 			if (priv->bss_role == MWIFIEX_BSS_ROLE_UAP)
 				mwifiex_handle_uap_rx_forward(priv, rx_tmp_ptr);
-			else
+			else {
 				mwifiex_process_rx_packet(priv, rx_tmp_ptr);
+				if (send_size)
+					*send_size += 1;
+			}
 		}
 	}
 
@@ -86,7 +91,7 @@ mwifiex_11n_dispatch_pkt(struct mwifiex_private *priv,
  */
 static void
 mwifiex_11n_scan_and_dispatch(struct mwifiex_private *priv,
-			      struct mwifiex_rx_reorder_tbl *tbl)
+			      struct mwifiex_rx_reorder_tbl *tbl, int *send_size)
 {
 	int i, j, xchg;
 	void *rx_tmp_ptr;
@@ -104,8 +109,10 @@ mwifiex_11n_scan_and_dispatch(struct mwifiex_private *priv,
 
 		if (priv->bss_role == MWIFIEX_BSS_ROLE_UAP)
 			mwifiex_handle_uap_rx_forward(priv, rx_tmp_ptr);
-		else
+		else {
 			mwifiex_process_rx_packet(priv, rx_tmp_ptr);
+			*send_size += 1;
+		}
 	}
 
 	spin_lock_irqsave(&priv->rx_pkt_lock, flags);
@@ -140,7 +147,7 @@ mwifiex_del_rx_reorder_entry(struct mwifiex_private *priv,
 		return;
 
 	mwifiex_11n_dispatch_pkt(priv, tbl, (tbl->start_win + tbl->win_size) &
-					    (MAX_TID_VALUE - 1));
+					    (MAX_TID_VALUE - 1), NULL);
 
 	del_timer(&tbl->timer_context.timer);
 
@@ -238,7 +245,7 @@ mwifiex_flush_data(unsigned long context)
 	dev_dbg(ctx->priv->adapter->dev, "info: flush data %d\n", start_win);
 	mwifiex_11n_dispatch_pkt(ctx->priv, ctx->ptr,
 				 (ctx->ptr->start_win + start_win + 1) &
-				 (MAX_TID_VALUE - 1));
+				 (MAX_TID_VALUE - 1), NULL);
 }
 
 /*
@@ -267,7 +274,7 @@ mwifiex_11n_create_rx_reorder_tbl(struct mwifiex_private *priv, u8 *ta,
 	 */
 	tbl = mwifiex_11n_get_rx_reorder_tbl(priv, tid, ta);
 	if (tbl) {
-		mwifiex_11n_dispatch_pkt(priv, tbl, seq_num);
+		mwifiex_11n_dispatch_pkt(priv, tbl, seq_num, NULL);
 		return;
 	}
 	/* if !tbl then create one */
@@ -434,11 +441,15 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 
 	tbl = mwifiex_11n_get_rx_reorder_tbl(priv, tid, ta);
 	if (!tbl) {
+		pr_info("!tbl\n");
 		if (pkt_type != PKT_TYPE_BAR) {
 			if (priv->bss_role == MWIFIEX_BSS_ROLE_UAP)
 				mwifiex_handle_uap_rx_forward(priv, payload);
 			else
 				mwifiex_process_rx_packet(priv, payload);
+		} else {
+			// missing free (maybe also rx_pending)
+			dev_kfree_skb_any(payload);
 		}
 		return 0;
 	}
@@ -485,7 +496,7 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 			start_win = (end_win - win_size) + 1;
 		else
 			start_win = (MAX_TID_VALUE - (win_size - seq_num)) + 1;
-		mwifiex_11n_dispatch_pkt(priv, tbl, start_win);
+		mwifiex_11n_dispatch_pkt(priv, tbl, start_win, &pkt_send);
 	}
 
 	if (pkt_type != PKT_TYPE_BAR) {
@@ -498,13 +509,16 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 			return -1;
 
 		tbl->rx_reorder_ptr[pkt_index] = payload;
+	} else if (pkt_type == PKT_TYPE_BAR) {
+		dev_info(priv->adapter->dev, "Networking send size:%d\n", pkt_send);
+		pkt_send = 0;
 	}
 
 	/*
 	 * Dispatch all packets sequentially from start_win until a
 	 * hole is found and adjust the start_win appropriately
 	 */
-	mwifiex_11n_scan_and_dispatch(priv, tbl);
+	mwifiex_11n_scan_and_dispatch(priv, tbl, &pkt_send);
 
 	return 0;
 }
diff --git a/drivers/net/wireless/mwifiex/sta_rx.c b/drivers/net/wireless/mwifiex/sta_rx.c
index b5c1095..bc1c0d7 100644
--- a/drivers/net/wireless/mwifiex/sta_rx.c
+++ b/drivers/net/wireless/mwifiex/sta_rx.c
@@ -122,6 +122,7 @@ int mwifiex_process_sta_rx_packet(struct mwifiex_private *priv,
 	struct rx_packet_hdr *rx_pkt_hdr;
 	u8 ta[ETH_ALEN];
 	u16 rx_pkt_type, rx_pkt_offset, rx_pkt_length, seq_num;
+	static int pkts_received = 0;
 
 	local_rx_pd = (struct rxpd *) (skb->data);
 	rx_pkt_type = le16_to_cpu(local_rx_pd->rx_pkt_type);
@@ -146,6 +147,7 @@ int mwifiex_process_sta_rx_packet(struct mwifiex_private *priv,
 	}
 
 	if (rx_pkt_type == PKT_TYPE_AMSDU) {
+		pr_info("AMSDU\n");
 		struct sk_buff_head list;
 		struct sk_buff *rx_skb;
 
@@ -168,6 +170,7 @@ int mwifiex_process_sta_rx_packet(struct mwifiex_private *priv,
 		ret = mwifiex_process_mgmt_packet(priv, skb);
 		if (ret)
 			dev_err(adapter->dev, "Rx of mgmt packet failed");
+		atomic_dec(&priv->adapter->rx_pending);
 		dev_kfree_skb_any(skb);
 		return ret;
 	}
@@ -191,10 +194,19 @@ int mwifiex_process_sta_rx_packet(struct mwifiex_private *priv,
 		       ETH_ALEN);
 	}
 
+	if (rx_pkt_type != PKT_TYPE_BAR && skb->len > 1500) {
+			pkts_received++;
+	}
+
+	if (rx_pkt_type == PKT_TYPE_BAR) {
+		dev_info(priv->adapter->dev, "Received between 2 BAR:%d\n", pkts_received);
+		pkts_received = 0;
+	}
 	/* Reorder and send to OS */
 	ret = mwifiex_11n_rx_reorder_pkt(priv, seq_num, local_rx_pd->priority,
 					 ta, (u8) rx_pkt_type, skb);
 
+
 	if (ret || (rx_pkt_type == PKT_TYPE_BAR)) {
 		if (adapter->if_ops.data_complete)
 			adapter->if_ops.data_complete(adapter, skb);
diff --git a/drivers/net/wireless/mwifiex/usb.c b/drivers/net/wireless/mwifiex/usb.c
index 7d9d10b..959daed 100644
--- a/drivers/net/wireless/mwifiex/usb.c
+++ b/drivers/net/wireless/mwifiex/usb.c
@@ -38,6 +38,7 @@ static struct usb_device_id mwifiex_usb_table[] = {
 
 MODULE_DEVICE_TABLE(usb, mwifiex_usb_table);
 
+unsigned long timeout = 0;
 /* Indicate if load FW in MFG (testing) mode */
 static int mfg_mode = 0;
 
@@ -178,8 +179,14 @@ static void mwifiex_usb_rx_complete(struct urb *urb)
 		atomic_inc(&adapter->rx_pending);
 		status = mwifiex_usb_recv(adapter, skb, context->ep);
 
+		if (time_after(jiffies, timeout)) {
+			dev_info(adapter->dev, "rx_pending:%d\n", atomic_read(&adapter->rx_pending));
+			timeout = jiffies + msecs_to_jiffies(500);
+		}
+
 		dev_dbg(adapter->dev, "info: recv_length=%d, status=%d\n",
 			recv_length, status);
+
 		if (status == -EINPROGRESS) {
 			queue_work(adapter->workqueue, &adapter->main_work);
 
@@ -259,7 +266,7 @@ static int mwifiex_usb_submit_rx_urb(struct urb_context *ctx, int size)
 		ctx->skb = dev_alloc_skb(size);
 		if (!ctx->skb) {
 			dev_err(adapter->dev,
-				"%s: dev_alloc_skb failed\n", __func__);
+				"%s: dev_alloc_skb failed - rx_pending:%d\n", __func__, atomic_read(&adapter->rx_pending));
 			return -ENOMEM;
 		}
 	}
@@ -344,6 +351,7 @@ static int mwifiex_usb_probe(struct usb_interface *intf,
 	bcd_usb = le16_to_cpu(udev->descriptor.bcdUSB);
 	pr_debug("info: VID/PID = %X/%X, Boot2 version = %X\n",
 		 id_vendor, id_product, bcd_device);
+	timeout = jiffies + msecs_to_jiffies(1000);
 
 	/* PID_1 is used for firmware downloading only */
 	if (id_product == USB8797_PID_1)
diff --git a/drivers/net/wireless/mwifiex/util.c b/drivers/net/wireless/mwifiex/util.c
index 2155397..b18ee13 100644
--- a/drivers/net/wireless/mwifiex/util.c
+++ b/drivers/net/wireless/mwifiex/util.c
@@ -25,6 +25,7 @@
 #include "wmm.h"
 #include "11n.h"
 
+unsigned long timeout = 0;
 /*
  * Firmware initialization complete callback handler.
  *
@@ -195,6 +196,9 @@ int mwifiex_recv_packet(struct mwifiex_private *priv, struct sk_buff *skb)
 	skb->protocol = eth_type_trans(skb, priv->netdev);
 	skb->ip_summed = CHECKSUM_NONE;
 
+	if (timeout == 0)
+		timeout = jiffies;
+
 	/* This is required only in case of 11n and USB as we alloc
 	 * a buffer of 4K only if its 11N (to be able to receive 4K
 	 * AMSDU packets). In case of SD we allocate buffers based
@@ -218,6 +222,12 @@ int mwifiex_recv_packet(struct mwifiex_private *priv, struct sk_buff *skb)
 
 	priv->stats.rx_bytes += skb->len;
 	priv->stats.rx_packets++;
+	atomic_dec(&priv->adapter->rx_pending);
+	if (time_after(jiffies, timeout)) {
+		dev_info(priv->adapter->dev, "rx_pending kernel:%d\n", atomic_read(&priv->adapter->rx_pending));
+		timeout = jiffies + msecs_to_jiffies(500);
+	}
+
 	if (in_interrupt())
 		netif_rx(skb);
 	else

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

[-- Attachment #1: Type: text/plain, Size: 752 bytes --]

Hi Marek,

We have one fix in Rx reorder logic and have handled dev_alloc_skb failure by resubmitting the urbs.
Could you please test attached experimental patches?

>[   76.769662] usb 1-1: Received between 2 BAR:2918
>[   76.775047] usb 1-1: Networking send size:2914
>[   77.067491] usb 1-1: rx_pending:10155
>[   77.177524] usb 1-1: rx_pending kernel:10383
>According log it seems rx_pending is slowly increasing until allocation
>fails. Code hacks are attached.

I am checking your hacks. The reason for huge rx_pending count is we might have missed to decrement the count at some place. The difference between " Received between 2 BAR" and "Networking send size" could be genuine leaks. We will look into this.

Regards,
Amit



[-- Attachment #2: 0001-mwifiex-restart-rxreorder-timer-correctly.patch --]
[-- Type: application/octet-stream, Size: 6015 bytes --]

From d4a6904b7c6315982e8f78a31f8ee3e9b27dbcc5 Mon Sep 17 00:00:00 2001
From: Marc Yang <yangyang@marvell.com>
Date: Tue, 28 Oct 2014 17:14:16 -0700
Subject: [PATCH] mwifiex: restart rxreorder timer correctly

When doing 11N RX reordering, if there is a hole in RX table,
driver will not send packets to kernel until the rxreorder
timer expires or the table is full. However, currently
driver always restarts rxreorder timer when receiving a
packet, which causes the timer hardly to expire. So, when
connected with some 11N AP in a busy environment, sometimes
ping packets are blocked for about 30 seconds.

The rxreorder timer should only be restarted when:
1. The timer is not set, OR
2. The start_win is changed

Signed-off-by: Marc Yang <yangyang@marvell.com>
Signed-off-by: Cathy Luo <cluo@marvell.com>
Signed-off-by: Chin-Ran Lo <crlo@marvell.com>
Signed-off-by: Plus Chen <pchen@marvell.com>
---
 drivers/net/wireless/mwifiex/11n_rxreorder.c | 53 +++++++++++++++++++++-------
 drivers/net/wireless/mwifiex/11n_rxreorder.h |  1 +
 drivers/net/wireless/mwifiex/main.h          |  1 +
 3 files changed, 43 insertions(+), 12 deletions(-)

diff --git a/drivers/net/wireless/mwifiex/11n_rxreorder.c b/drivers/net/wireless/mwifiex/11n_rxreorder.c
index 4005707..0ac404f 100644
--- a/drivers/net/wireless/mwifiex/11n_rxreorder.c
+++ b/drivers/net/wireless/mwifiex/11n_rxreorder.c
@@ -196,6 +196,7 @@ mwifiex_del_rx_reorder_entry(struct mwifiex_private *priv,
 	mwifiex_11n_dispatch_pkt_until_start_win(priv, tbl, start_win);
 
 	del_timer_sync(&tbl->timer_context.timer);
+	tbl->timer_context.timer_is_set = false;
 
 	spin_lock_irqsave(&priv->rx_reorder_tbl_lock, flags);
 	list_del(&tbl->list);
@@ -297,6 +298,7 @@ mwifiex_flush_data(unsigned long context)
 		(struct reorder_tmr_cnxt *) context;
 	int start_win, seq_num;
 
+	ctx->timer_is_set = false;
 	seq_num = mwifiex_11n_find_last_seq_num(ctx);
 
 	if (seq_num < 0)
@@ -385,6 +387,7 @@ mwifiex_11n_create_rx_reorder_tbl(struct mwifiex_private *priv, u8 *ta,
 
 	new_node->timer_context.ptr = new_node;
 	new_node->timer_context.priv = priv;
+	new_node->timer_context.timer_is_set = false;
 
 	init_timer(&new_node->timer_context.timer);
 	new_node->timer_context.timer.function = mwifiex_flush_data;
@@ -399,6 +402,23 @@ mwifiex_11n_create_rx_reorder_tbl(struct mwifiex_private *priv, u8 *ta,
 	spin_unlock_irqrestore(&priv->rx_reorder_tbl_lock, flags);
 }
 
+static void
+mwifiex_11n_rxreorder_timer_restart(struct mwifiex_rx_reorder_tbl *tbl)
+{
+	u32 min_flush_time = 0;
+#define BA_WIN_SIZE_32 32
+	if (tbl->win_size >= BA_WIN_SIZE_32)
+		min_flush_time = MIN_FLUSH_TIMER_15_MS;
+	else
+		min_flush_time = MIN_FLUSH_TIMER_MS;
+
+	del_timer(&tbl->timer_context.timer);
+	mod_timer(&tbl->timer_context.timer,
+		  jiffies + msecs_to_jiffies(min_flush_time * tbl->win_size));
+
+	tbl->timer_context.timer_is_set = true;
+}
+
 /*
  * This function prepares command for adding a BA request.
  *
@@ -523,31 +543,31 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 				u8 *ta, u8 pkt_type, void *payload)
 {
 	struct mwifiex_rx_reorder_tbl *tbl;
-	int start_win, end_win, win_size;
+	int prev_start_win, start_win, end_win, win_size;
 	u16 pkt_index;
 	bool init_window_shift = false;
+	int ret = 0;
 
 	tbl = mwifiex_11n_get_rx_reorder_tbl(priv, tid, ta);
 	if (!tbl) {
 		if (pkt_type != PKT_TYPE_BAR)
 			mwifiex_11n_dispatch_pkt(priv, payload);
-		return 0;
+		return ret;
 	}
 
 	if ((pkt_type == PKT_TYPE_AMSDU) && !tbl->amsdu) {
 		mwifiex_11n_dispatch_pkt(priv, payload);
-		return 0;
+		return ret;
 	}
 
 	start_win = tbl->start_win;
+	prev_start_win = start_win;
 	win_size = tbl->win_size;
 	end_win = ((start_win + win_size) - 1) & (MAX_TID_VALUE - 1);
 	if (tbl->flags & RXREOR_INIT_WINDOW_SHIFT) {
 		init_window_shift = true;
 		tbl->flags &= ~RXREOR_INIT_WINDOW_SHIFT;
 	}
-	mod_timer(&tbl->timer_context.timer,
-		  jiffies + msecs_to_jiffies(MIN_FLUSH_TIMER_MS * win_size));
 
 	if (tbl->flags & RXREOR_FORCE_NO_DROP) {
 		dev_dbg(priv->adapter->dev,
@@ -568,11 +588,14 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 		if ((start_win + TWOPOW11) > (MAX_TID_VALUE - 1)) {
 			if (seq_num >= ((start_win + TWOPOW11) &
 					(MAX_TID_VALUE - 1)) &&
-			    seq_num < start_win)
-				return -1;
+			    seq_num < start_win) {
+				ret = -1;
+				goto done;
+			}
 		} else if ((seq_num < start_win) ||
-			   (seq_num > (start_win + TWOPOW11))) {
-			return -1;
+			   (seq_num >= (start_win + TWOPOW11))) {
+			ret = -1;
+			goto done;
 		}
 	}
 
@@ -601,8 +624,10 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 		else
 			pkt_index = (seq_num+MAX_TID_VALUE) - start_win;
 
-		if (tbl->rx_reorder_ptr[pkt_index])
-			return -1;
+		if (tbl->rx_reorder_ptr[pkt_index]) {
+			ret = -1;
+			goto done;
+		}
 
 		tbl->rx_reorder_ptr[pkt_index] = payload;
 	}
@@ -613,7 +638,11 @@ int mwifiex_11n_rx_reorder_pkt(struct mwifiex_private *priv,
 	 */
 	mwifiex_11n_scan_and_dispatch(priv, tbl);
 
-	return 0;
+done:
+	if (!tbl->timer_context.timer_is_set ||
+	    prev_start_win != tbl->start_win)
+		mwifiex_11n_rxreorder_timer_restart(tbl);
+	return ret;
 }
 
 /*
diff --git a/drivers/net/wireless/mwifiex/11n_rxreorder.h b/drivers/net/wireless/mwifiex/11n_rxreorder.h
index 3a87bb0..6981e53 100644
--- a/drivers/net/wireless/mwifiex/11n_rxreorder.h
+++ b/drivers/net/wireless/mwifiex/11n_rxreorder.h
@@ -21,6 +21,7 @@
 #define _MWIFIEX_11N_RXREORDER_H_
 
 #define MIN_FLUSH_TIMER_MS		50
+#define MIN_FLUSH_TIMER_15_MS		15
 
 #define PKT_TYPE_BAR 0xE7
 #define MAX_TID_VALUE			(2 << 11)
diff --git a/drivers/net/wireless/mwifiex/main.h b/drivers/net/wireless/mwifiex/main.h
index e263574..f55658d 100644
--- a/drivers/net/wireless/mwifiex/main.h
+++ b/drivers/net/wireless/mwifiex/main.h
@@ -592,6 +592,7 @@ struct reorder_tmr_cnxt {
 	struct timer_list timer;
 	struct mwifiex_rx_reorder_tbl *ptr;
 	struct mwifiex_private *priv;
+	u8 timer_is_set;
 };
 
 struct mwifiex_rx_reorder_tbl {
-- 
1.8.0


[-- Attachment #3: 0001-mwifiex-resubmit-Rx-data-URBS-when-dev_alloc_skb-fai.patch --]
[-- Type: application/octet-stream, Size: 3204 bytes --]

From 6514e7338862430c498b9f07c6455d61b913dda0 Mon Sep 17 00:00:00 2001
From: Xinming Hu <huxm@marvell.com>
Date: Tue, 28 Oct 2014 06:00:29 -0700
Subject: [PATCH] mwifiex resubmit Rx data URBS when dev_alloc_skb fail

mwifiex use six urbs rx data packet , new urb request will be
submitted when previous urb request completed. sometimes, this cycle
might be broken (No available memeory .i.e)

when all the six rx urbs cycle are broken , some strange issues (crash .i.e)
will happen.

This patch enhance this case , by resubmit the broken urb request in
main process.

Signed-off-by: Xinming Hu <huxm@marvell.com>
Signed-off-by: Cathy Luo <cluo@marvell.com>
Signed-off-by: Avinash Patil <patila@marvell.com>

---
 drivers/net/wireless/mwifiex/main.c | 19 +++++++++++++++++++
 drivers/net/wireless/mwifiex/main.h |  1 +
 drivers/net/wireless/mwifiex/usb.c  |  1 +
 3 files changed, 21 insertions(+)

diff --git a/drivers/net/wireless/mwifiex/main.c b/drivers/net/wireless/mwifiex/main.c
index eab4956..2ab51be 100644
--- a/drivers/net/wireless/mwifiex/main.c
+++ b/drivers/net/wireless/mwifiex/main.c
@@ -21,6 +21,7 @@
 #include "wmm.h"
 #include "cfg80211.h"
 #include "11n.h"
+#include "usb.h"
 
 #define VERSION	"1.0"
 
@@ -182,6 +183,9 @@ int mwifiex_main_process(struct mwifiex_adapter *adapter)
 	int ret = 0;
 	unsigned long flags;
 	struct sk_buff *skb;
+	struct usb_card_rec *card;
+	struct urb_context urb;
+	int i;
 
 	spin_lock_irqsave(&adapter->main_proc_lock, flags);
 
@@ -199,6 +203,21 @@ process_start:
 		    (adapter->hw_status == MWIFIEX_HW_STATUS_NOT_READY))
 			break;
 
+		if (adapter->iface_type == MWIFIEX_USB) {
+			int sz = MWIFIEX_RX_DATA_BUF_SIZE;
+
+			card = (struct usb_card_rec *)adapter->card;
+			if (atomic_read(&card->rx_data_urb_pending) <
+					MWIFIEX_RX_DATA_URB/2) {
+				for (i = 0; i < MWIFIEX_RX_DATA_URB; i++) {
+					if (card->rx_data_list[i].skb)
+						continue;
+					urb = card->rx_data_list[i];
+					adapter->if_ops.submit_rx_urb(&urb, sz);
+				}
+			}
+		}
+
 		/* If we process interrupts first, it would increase RX pending
 		 * even further. Avoid this by checking if rx_pending has
 		 * crossed high threshold and schedule rx work queue
diff --git a/drivers/net/wireless/mwifiex/main.h b/drivers/net/wireless/mwifiex/main.h
index ede4493..6df1876 100644
--- a/drivers/net/wireless/mwifiex/main.h
+++ b/drivers/net/wireless/mwifiex/main.h
@@ -702,6 +702,7 @@ struct mwifiex_if_ops {
 	void (*fw_dump)(struct mwifiex_adapter *);
 	int (*clean_pcie_ring) (struct mwifiex_adapter *adapter);
 	void (*iface_work)(struct work_struct *work);
+	int (*submit_rx_urb)(struct urb_context *ctx, int size);
 };
 
 struct mwifiex_adapter {
diff --git a/drivers/net/wireless/mwifiex/usb.c b/drivers/net/wireless/mwifiex/usb.c
index 7118a18..3b0dbf7 100644
--- a/drivers/net/wireless/mwifiex/usb.c
+++ b/drivers/net/wireless/mwifiex/usb.c
@@ -998,6 +998,7 @@ static struct mwifiex_if_ops usb_ops = {
 	.event_complete =	mwifiex_usb_cmd_event_complete,
 	.data_complete =	mwifiex_usb_data_complete,
 	.host_to_card =		mwifiex_usb_host_to_card,
+	.submit_rx_urb = mwifiex_usb_submit_rx_urb,
 };
 
 /* This function initializes the USB driver module.
-- 
1.8.1.4

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Hi Amitkumar,

On Wed, Oct 29, 2014 at 10:54 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
> We have one fix in Rx reorder logic and have handled dev_alloc_skb failure by resubmitting the urbs.
> Could you please test attached experimental patches?
I tested both patches and I can still reproduce issue. With
0001-mwifiex-resubmit-Rx-data-URBS-when-dev_alloc_skb-fai.patch
I get kernel crash when allocation fails happens:
[  118.904307] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  118.911431] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  118.918328] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  118.925204] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  118.932291] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  118.939403] usb 1-1: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed
[  120.171372] ------------[ cut here ]------------
[  120.176288] WARNING: at drivers/usb/core/urb.c:327 usb_submit_urb+0x35/0x4c()
[  120.183776] URB ce411840 submitted while active
[  120.188528] Modules linked in: mwifiex_usb mwifiex btusb
beo_hh1_misc(O) beo_hh1_lsl(O) beo_hh1_summit(O) beo_hh1_tunnel(O)
beo_hh1_rtc(O) beo_hh1_power(O) beo_hh1_dsp(O) beo_hh1_fwupdate(O)
beo_hh1_input(O) beo_hh1_leds(O) beo_hh1_fep(O) beo_ase_fephw(O)
beo_ase_dsp(]
[  120.217461] [<c000ff19>] (unwind_backtrace+0x1/0x98) from
[<c0026e17>] (warn_slowpath_common+0x33/0x4c)
[  120.227332] [<c0026e17>] (warn_slowpath_common+0x33/0x4c) from
[<c0026e89>] (warn_slowpath_fmt+0x1d/0x28)
[  120.237386] [<c0026e89>] (warn_slowpath_fmt+0x1d/0x28) from
[<c022fd4d>] (usb_submit_urb+0x35/0x4c)
[  120.246907] [<c022fd4d>] (usb_submit_urb+0x35/0x4c) from
[<bf8a321b>] (mwifiex_usb_submit_rx_urb+0x72/0x10c [mwifiex_usb])
[  120.258592] [<bf8a321b>] (mwifiex_usb_submit_rx_urb+0x72/0x10c
[mwifiex_usb]) from [<bf8a34a9>] (mwifiex_usb_rx_complete+0xe0/0x2b0
[mwifiex_usb])
[  120.272388] [<bf8a34a9>] (mwifiex_usb_rx_complete+0xe0/0x2b0
[mwifiex_usb]) from [<c022dfd5>] (usb_hcd_giveback_urb+0x29/0x74)
[  120.284360] [<c022dfd5>] (usb_hcd_giveback_urb+0x29/0x74) from
[<c024730b>] (musb_giveback+0x23/0x2c)
[  120.294051] [<c024730b>] (musb_giveback+0x23/0x2c) from
[<c0247f21>] (musb_advance_schedule+0x35/0x16c)
[  120.303922] [<c0247f21>] (musb_advance_schedule+0x35/0x16c) from
[<c0246605>] (musb_interrupt+0x61/0x5e0)
[  120.313974] [<c0246605>] (musb_interrupt+0x61/0x5e0) from
[<c02492b5>] (dsps_interrupt+0x17d/0x234)
[  120.323492] [<c02492b5>] (dsps_interrupt+0x17d/0x234) from
[<c005cc73>] (handle_irq_event_percpu+0x33/0x11c)
[  120.333819] [<c005cc73>] (handle_irq_event_percpu+0x33/0x11c) from
[<c005cd85>] (handle_irq_event+0x29/0x3c)
[  120.344144] [<c005cd85>] (handle_irq_event+0x29/0x3c) from
[<c005e2f3>] (handle_level_irq+0x4f/0x88)
[  120.353738] [<c005e2f3>] (handle_level_irq+0x4f/0x88) from
[<c005c80f>] (generic_handle_irq+0x13/0x1c)
[  120.363525] [<c005c80f>] (generic_handle_irq+0x13/0x1c) from
[<c000d595>] (handle_IRQ+0x1d/0x54)
[  120.372758] [<c000d595>] (handle_IRQ+0x1d/0x54) from [<c0008495>]
(omap3_intc_handle_irq+0x5d/0x68)
[  120.382262] [<c0008495>] (omap3_intc_handle_irq+0x5d/0x68) from
[<c000c7ff>] (__irq_svc+0x3f/0x64)
[  120.391666] Exception stack(0xce569d68 to 0xce569db0)
[  120.396977] 9d60:                   00000001 ce122f98 00000000
00000001 a0000013 cf31e010
[  120.405567] 9d80: a0000013 00000000 cf00e480 ce015b04 ce411ac0
00000020 ce122b40 ce569db0
[  120.414151] 9da0: c0050b97 c037e914 40000033 ffffffff
[  120.419473] [<c000c7ff>] (__irq_svc+0x3f/0x64) from [<c037e914>]
(_raw_spin_unlock_irqrestore+0x24/0x30)
[  120.429435] [<c037e914>] (_raw_spin_unlock_irqrestore+0x24/0x30)
from [<c0247a4d>] (musb_urb_enqueue+0x4d/0x3b8)
[  120.440128] [<c0247a4d>] (musb_urb_enqueue+0x4d/0x3b8) from
[<c022e9d7>] (usb_hcd_submit_urb+0x6f/0x57c)
[  120.450094] [<c022e9d7>] (usb_hcd_submit_urb+0x6f/0x57c) from
[<bf8a321b>] (mwifiex_usb_submit_rx_urb+0x72/0x10c [mwifiex_usb])
[  120.462229] [<bf8a321b>] (mwifiex_usb_submit_rx_urb+0x72/0x10c
[mwifiex_usb]) from [<bf87ec27>] (mwifiex_main_process+0x2a2/0x3ac
[mwifiex])
[  120.475507] [<bf87ec27>] (mwifiex_main_process+0x2a2/0x3ac
[mwifiex]) from [<bf87ed3f>] (mwifiex_main_work_queue+0xe/0x10
[mwifiex])
[  120.488049] [<bf87ed3f>] (mwifiex_main_work_queue+0xe/0x10
[mwifiex]) from [<c0036cef>] (process_one_work+0x117/0x2b4)
[  120.499289] [<c0036cef>] (process_one_work+0x117/0x2b4) from
[<c00370e1>] (worker_thread+0xd9/0x280)
[  120.508893] [<c00370e1>] (worker_thread+0xd9/0x280) from
[<c003a1cf>] (kthread+0x6b/0x74)
[  120.517487] [<c003a1cf>] (kthread+0x6b/0x74) from [<c000cd95>]
(ret_from_fork+0x11/0x3c)
[  120.525978] ---[ end trace 67ca4bd7a80b7c08 ]---
[  120.530838] usb 1-1: usb_submit_urb failed

>
>>[   76.769662] usb 1-1: Received between 2 BAR:2918
>>[   76.775047] usb 1-1: Networking send size:2914
>>[   77.067491] usb 1-1: rx_pending:10155
>>[   77.177524] usb 1-1: rx_pending kernel:10383
>>According log it seems rx_pending is slowly increasing until allocation
>>fails. Code hacks are attached.
>
> I am checking your hacks. The reason for huge rx_pending count is we might have missed to decrement the count at some place. The difference between " Received between 2 BAR" and "Networking send size" could be genuine leaks. We will look into this.
Thanks.
>
> Regards,
> Amit
>
>

BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

[-- Attachment #1: Type: text/plain, Size: 411 bytes --]

Hi Marek,

Thanks a lot for testing. I have added flow control logic to limit pending Rx packets. Could you please check if attached patch fixes out of memory issue?
You can also backport below patch to your 3.9 kernel for rx_pending count imbalance issue.

http://www.spinics.net/lists/linux-wireless/msg115536.html

Your hacks to decrement rx_pending count won't be needed now.

Regards,
Amitkumar

[-- Attachment #2: 0001-mwifiex-add-flow-control-logic-to-Rx-data-on-USB-int.patch --]
[-- Type: application/octet-stream, Size: 3524 bytes --]

From 3d5a91fa8b17a0634276d32b2b40a847a6f6279d Mon Sep 17 00:00:00 2001
From: Amitkumar Karwar <akarwar@marvell.com>
Date: Thu, 30 Oct 2014 01:28:10 -0700
Subject: [PATCH] mwifiex: add flow control logic to Rx data on USB interface

Signed-off-by: Amitkumar Karwar <akarwar@marvell.com>
---
 drivers/net/wireless/mwifiex/main.c |    8 ++++++--
 drivers/net/wireless/mwifiex/main.h |    3 +++
 drivers/net/wireless/mwifiex/usb.c  |   23 ++++++++++++++++++++++-
 3 files changed, 31 insertions(+), 3 deletions(-)

diff --git a/drivers/net/wireless/mwifiex/main.c b/drivers/net/wireless/mwifiex/main.c
index 121443a..5f25855 100644
--- a/drivers/net/wireless/mwifiex/main.c
+++ b/drivers/net/wireless/mwifiex/main.c
@@ -199,9 +199,13 @@ process_start:
 		}
 
 		/* Check Rx data for USB */
-		if (adapter->iface_type == MWIFIEX_USB)
-			while ((skb = skb_dequeue(&adapter->usb_rx_data_q)))
+		if (adapter->iface_type == MWIFIEX_USB) {
+			while ((skb = skb_dequeue(&adapter->usb_rx_data_q))) {
 				mwifiex_handle_rx_packet(adapter, skb);
+				if (atomic_read(&adapter->rx_pending) < LOW_RX_PENDING)
+					adapter->if_ops.submit_rem_rx_urb(adapter);
+			}
+		}
 
 		/* Check for Cmd Resp */
 		if (adapter->cmd_resp_received) {
diff --git a/drivers/net/wireless/mwifiex/main.h b/drivers/net/wireless/mwifiex/main.h
index cab8a85..247b2a6 100644
--- a/drivers/net/wireless/mwifiex/main.h
+++ b/drivers/net/wireless/mwifiex/main.h
@@ -222,6 +222,8 @@ struct mwifiex_tid_tbl {
 #define HIGH_PRIO_TID				7
 #define LOW_PRIO_TID				0
 #define NO_PKT_PRIO_TID				(-1)
+#define LOW_RX_PENDING			20
+#define HIGH_RX_PENDING			50
 
 struct mwifiex_wmm_desc {
 	struct mwifiex_tid_tbl tid_tbl_ptr[MAX_NUM_TID];
@@ -616,6 +618,7 @@ struct mwifiex_if_ops {
 	int (*dnld_fw) (struct mwifiex_adapter *, struct mwifiex_fw_image *);
 	void (*card_reset) (struct mwifiex_adapter *);
 	int (*clean_pcie_ring) (struct mwifiex_adapter *adapter);
+	void (*submit_rem_rx_urb) (struct mwifiex_adapter *adapter);
 };
 
 struct mwifiex_adapter {
diff --git a/drivers/net/wireless/mwifiex/usb.c b/drivers/net/wireless/mwifiex/usb.c
index e3e2c62..7791748 100644
--- a/drivers/net/wireless/mwifiex/usb.c
+++ b/drivers/net/wireless/mwifiex/usb.c
@@ -226,7 +226,13 @@ setup_for_next:
 	else
 		size = MWIFIEX_RX_DATA_BUF_SIZE;
 
-	mwifiex_usb_submit_rx_urb(context, size);
+	if (card->rx_cmd_ep == context->ep) {
+		mwifiex_usb_submit_rx_urb(context, size);
+	} else {
+		context->skb = NULL;
+		if (atomic_read(&adapter->rx_pending) <= HIGH_RX_PENDING)
+			mwifiex_usb_submit_rx_urb(context, size);
+	}
 
 	return;
 }
@@ -985,6 +991,20 @@ static int mwifiex_pm_wakeup_card(struct mwifiex_adapter *adapter)
 	return 0;
 }
 
+static void mwifiex_usb_submit_rem_rx_urb(struct mwifiex_adapter *adapter)
+{
+	struct usb_card_rec *card = (struct usb_card_rec *)adapter->card;
+	int i;
+	struct urb_context *ctx;
+
+	for (i = 0; i < MWIFIEX_RX_DATA_URB; i++) {
+		if (card->rx_data_list[i].skb)
+			continue;
+		ctx = &card->rx_data_list[i];
+		mwifiex_usb_submit_rx_urb(ctx, MWIFIEX_RX_DATA_BUF_SIZE);
+	}
+}
+
 static struct mwifiex_if_ops usb_ops = {
 	.register_dev =		mwifiex_register_dev,
 	.wakeup =		mwifiex_pm_wakeup_card,
@@ -996,6 +1016,7 @@ static struct mwifiex_if_ops usb_ops = {
 	.event_complete =	mwifiex_usb_cmd_event_complete,
 	.data_complete =	mwifiex_usb_data_complete,
 	.host_to_card =		mwifiex_usb_host_to_card,
+	.submit_rem_rx_urb =	mwifiex_usb_submit_rem_rx_urb,
 };
 
 /* This function initializes the USB driver module.
-- 
1.7.3.4

Re: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Belisko Marek]

Hi Amitkumar,

On Thu, Oct 30, 2014 at 11:01 AM, Amitkumar Karwar <akarwar@marvell.com> wrote:
> Hi Marek,
>
> Thanks a lot for testing. I have added flow control logic to limit pending Rx packets. Could you please check if attached patch fixes out of memory issue?
> You can also backport below patch to your 3.9 kernel for rx_pending count imbalance issue.
With rx_pending count imbalance + your patch on top I cannot reproduce
allocation failure issue (tested on 1 hour iperf session).
Reason why console was completely blocked was that iperf server eats ~
55% cpu + kworker ~27 + ksoftirq ~14 so I think this is cause
why console was unresponsive. Thanks for patches. You can add my Tested-by ;)
>
> http://www.spinics.net/lists/linux-wireless/msg115536.html
>
> Your hacks to decrement rx_pending count won't be needed now.
>
> Regards,
> Amitkumar

BR,

marek
-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com

RE: mwifiex_usb_submit_rx_urb: dev_alloc_skb failed when conected to 5GHz

[Amitkumar Karwar]

Hi Marek,

>With rx_pending count imbalance + your patch on top I cannot reproduce
>allocation failure issue (tested on 1 hour iperf session).

Thanks for confirmation. I will prepare new patch for latest code and submit. It will be slightly different than the one shared with you due Rx work queue implementation in latest code.

>Reason why console was completely blocked was that iperf server eats ~
>55% cpu + kworker ~27 + ksoftirq ~14 so I think this is cause
>why console was unresponsive.

I see.

>Thanks for patches. You can add my Tested-by ;)

Sure.

Regards,
Amitkumar