Re: intel 5100/iwlagn bug in 2.6.35-rc2 during large file transfer

[Richard Farina <sidhayn@gmail.com>]

reinette chatre wrote:
> On Mon, 2010-06-28 at 10:01 -0700, Richard Farina wrote:
>   
>> reinette chatre wrote:
>>     
>>> On Sun, 2010-06-27 at 10:14 -0700, Richard Farina wrote:
>>>   
>>>       
>>>>> ---
>>>>>  drivers/net/wireless/iwlwifi/iwl-agn-lib.c |    5 +++--
>>>>>  drivers/net/wireless/iwlwifi/iwl-fh.h      |    2 +-
>>>>>  2 files changed, 4 insertions(+), 3 deletions(-)
>>>>>
>>>>> diff --git a/drivers/net/wireless/iwlwifi/iwl-agn-lib.c b/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
>>>>> index 0f292a2..2815ee7 100644
>>>>> --- a/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
>>>>> +++ b/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
>>>>> @@ -613,7 +613,8 @@ void iwlagn_rx_allocate(struct iwl_priv *priv, gfp_t priority)
>>>>>               }
>>>>>               spin_unlock_irqrestore(&rxq->lock, flags);
>>>>>
>>>>> -             if (rxq->free_count > RX_LOW_WATERMARK)
>>>>> +             if ((priority == GFP_ATOMIC) ||
>>>>> +                 (rxq->free_count > RX_LOW_WATERMARK / 4))
>>>>>                       gfp_mask |= __GFP_NOWARN;
>>>>>
>>>>>       
>>>>>           
>>> Here I set the allocation mask to not print _any_ warnings when
>>> allocation is atomic ...
>>>
>>>
>>>   
>>>       
>>>> [180257.090410] swapper: page allocation failure. order:1, mode:0x4020
>>>> [180257.090414] Pid: 0, comm: swapper Not tainted 2.6.34-pentoo-r2 #2
>>>> [180257.090416] Call Trace:
>>>>     
>>>>         
>>> ... clearly this is an allocation warning ...
>>>
>>>   
>>>       
>>>> [180257.090418]  <IRQ>  [<ffffffff810984c0>]
>>>> __alloc_pages_nodemask+0x571/0x5b9
>>>> [180257.090437]  [<ffffffffa05162f3>] iwlagn_rx_allocate+0x98/0x2e0 [iwlagn]
>>>> [180257.090445]  [<ffffffffa051668c>] iwlagn_rx_replenish_now+0x16/0x23
>>>> [iwlagn]
>>>>     
>>>>         
>>> ... but it is an atomic one, which after the patch should not be
>>> printing _any_ warning ...
>>>
>>>   
>>>       
>> I dunno, I really don't. but I did just verify the patch and it is 
>> correct and applied.
>>     
>
> Could you please verify that it is the patch below and not an earlier
> patch I sent? Apart from what I mention above there is another strange
> thing in the logs you provide. In your logs you have the message:
>
> iwlagn 0000:02:00.0: Failed to alloc_pages with
> GFP_ATOMIC. Only 40 free buffers remaining.
>
> while the code is:
>
> »-------»-------»-------if ((rxq->free_count <= RX_LOW_WATERMARK / 4) &&
> »-------»-------»-------    net_ratelimit())
> »-------»-------»-------»-------IWL_CRIT(priv, "Failed to alloc_pages with %s. Only %u free buffers remaining.\n",
> »-------»-------»-------»-------»------- priority == GFP_ATOMIC ?  "GFP_ATOMIC" : "GFP_KERNEL",
> »-------»-------»-------»-------»------- rxq->free_count);
>
> with :
> #define RX_LOW_WATERMARK 128
>
> The message in your log should thus not be there since it should only
> print the message if the free_count less than or equal to 32.
>
>   
I verified that I applied the correct patch (for the third time), sad 
part is, now it is different... I guess I messed up the first three 
times.  Anyway, no oops yet but:

[ 3091.463559] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 21 free buffers remaining.
[ 3091.534626] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 0 free buffers remaining.
[ 3593.179843] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 1 free buffers remaining.
[ 3593.307837] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 26 free buffers remaining.
[ 4091.542698] net_ratelimit: 34 callbacks suppressed
[ 4091.542702] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 25 free buffers remaining.
[ 4091.542724] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 3 free buffers remaining.
[ 4091.555285] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 26 free buffers remaining.
[ 4091.555305] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 0 free buffers remaining.
[ 4258.724351] net_ratelimit: 2073 callbacks suppressed
[ 4258.724372] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 0 free buffers remaining.
[ 4258.753286] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 31 free buffers remaining.
[ 4258.753309] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 2 free buffers remaining.
[ 4258.774133] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 28 free buffers remaining.
[ 5165.260524] net_ratelimit: 21 callbacks suppressed
[ 5166.400305] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 4 free buffers remaining.
[ 5167.126059] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 13 free buffers remaining.
[ 5454.561708] net_ratelimit: 4 callbacks suppressed
[ 5455.245019] iwlagn 0000:02:00.0: Failed to alloc_pages with 
GFP_ATOMIC. Only 1 free buffers remaining.


I'd certainly list it as improved as it hardly freezes and those aren't 
kernel oops.  However it should be noted that this test didn't seem to 
have nearly the same speed as the previous test (which may well be due 
to my internet connection or any number of things having nothing to do 
with this patch). Point is, I'd definately like to get a faster test it 
to see if it explodes.  Assuming it doesn't, how can I help you find out 
why it keeps running out of buffers? I'm guessing  this isn't expected 
behavior...

Thanks,
Rick Farina

> >From 65c459c35332c7039cc84a980e6e04118ba81c04 Mon Sep 17 00:00:00 2001
> From: Reinette Chatre <reinette.chatre@intel.com>
> Date: Thu, 24 Jun 2010 10:48:59 -0700
> Subject: [PATCH] increase low watermark
>
> ---
>  drivers/net/wireless/iwlwifi/iwl-agn-lib.c |    5 +++--
>  drivers/net/wireless/iwlwifi/iwl-fh.h      |    2 +-
>  2 files changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/net/wireless/iwlwifi/iwl-agn-lib.c b/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
> index 0f292a2..2815ee7 100644
> --- a/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
> +++ b/drivers/net/wireless/iwlwifi/iwl-agn-lib.c
> @@ -613,7 +613,8 @@ void iwlagn_rx_allocate(struct iwl_priv *priv, gfp_t priority)
>  		}
>  		spin_unlock_irqrestore(&rxq->lock, flags);
>  
> -		if (rxq->free_count > RX_LOW_WATERMARK)
> +		if ((priority == GFP_ATOMIC) ||
> +		    (rxq->free_count > RX_LOW_WATERMARK / 4))
>  			gfp_mask |= __GFP_NOWARN;
>  
>  		if (priv->hw_params.rx_page_order > 0)
> @@ -627,7 +628,7 @@ void iwlagn_rx_allocate(struct iwl_priv *priv, gfp_t priority)
>  					       "order: %d\n",
>  					       priv->hw_params.rx_page_order);
>  
> -			if ((rxq->free_count <= RX_LOW_WATERMARK) &&
> +			if ((rxq->free_count <= RX_LOW_WATERMARK / 4) &&
>  			    net_ratelimit())
>  				IWL_CRIT(priv, "Failed to alloc_pages with %s. Only %u free buffers remaining.\n",
>  					 priority == GFP_ATOMIC ?  "GFP_ATOMIC" : "GFP_KERNEL",
> diff --git a/drivers/net/wireless/iwlwifi/iwl-fh.h b/drivers/net/wireless/iwlwifi/iwl-fh.h
> index 113c366..431bc58 100644
> --- a/drivers/net/wireless/iwlwifi/iwl-fh.h
> +++ b/drivers/net/wireless/iwlwifi/iwl-fh.h
> @@ -426,7 +426,7 @@
>   * RX related structures and functions
>   */
>  #define RX_FREE_BUFFERS 64
> -#define RX_LOW_WATERMARK 8
> +#define RX_LOW_WATERMARK 128
>  
>  /* Size of one Rx buffer in host DRAM */
>  #define IWL_RX_BUF_SIZE_3K (3 * 1000) /* 3945 only */
>