Re: INFO: rcu detected stall in vprintk_func

2018-04-01 Thread Sergey Senozhatsky
On (04/02/18 10:54), Sergey Senozhatsky wrote:
> > > If you forward the report, please keep this part and the footer.
> > >
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU

[..]

> diff --git a/net/nfc/llcp_core.c b/net/nfc/llcp_core.c
> index ef4026a23e80..a309a27581da 100644
> --- a/net/nfc/llcp_core.c
> +++ b/net/nfc/llcp_core.c
> @@ -1386,7 +1386,7 @@ static void nfc_llcp_recv_agf(struct nfc_llcp_local 
> *local, struct sk_buff *skb)
>  
>   new_skb = nfc_alloc_recv_skb(pdu_len, GFP_KERNEL);
>   if (new_skb == NULL) {
> - pr_err("Could not allocate PDU\n");
> + pr_err_ratelimited("Could not allocate PDU\n");
>   return;
>   }

And of course I ended up patching the wrong function...
What I actually meant was:

---

diff --git a/net/nfc/llcp_commands.c b/net/nfc/llcp_commands.c
index 2ceefa183cee..2f3becb709b8 100644
--- a/net/nfc/llcp_commands.c
+++ b/net/nfc/llcp_commands.c
@@ -755,7 +755,7 @@ int nfc_llcp_send_ui_frame(struct nfc_llcp_sock *sock, u8 
ssap, u8 dsap,
pdu = nfc_alloc_send_skb(sock->dev, >sk, MSG_DONTWAIT,
 frag_len + LLCP_HEADER_SIZE, );
if (pdu == NULL) {
-   pr_err("Could not allocate PDU\n");
+   pr_err_ratelimited("Could not allocate PDU\n");
continue;
}
 


Re: INFO: rcu detected stall in vprintk_default

2018-04-01 Thread Sergey Senozhatsky
On (04/01/18 12:52), Dmitry Vyukov wrote:
> 
> Seems to be the same as:
> 
> #syz dup: INFO: rcu detected stall in vprintk_func
> 
> +nfc maintainers

Yes, seems to be the same issue.

-ss


Re: INFO: rcu detected stall in vprintk_func

2018-04-01 Thread Sergey Senozhatsky
On (04/01/18 12:51), Dmitry Vyukov wrote:
[..]
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+3f28bd18291266ec8...@syzkaller.appspotmail.com
> > It will help syzbot understand when the bug is fixed. See footer for
> > details.
> > If you forward the report, please keep this part and the footer.
> >
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU

Yes, this thing

do {
remote_miu = sock->remote_miu > LLCP_MAX_MIU ?
local->remote_miu : sock->remote_miu;

frag_len = min_t(size_t, remote_miu, remaining_len);

pr_debug("Fragment %zd bytes remaining %zd",
 frag_len, remaining_len);

pdu = nfc_alloc_send_skb(sock->dev, >sk, MSG_DONTWAIT,
 frag_len + LLCP_HEADER_SIZE, );
if (pdu == NULL) {
pr_err("Could not allocate PDU\n");
continue;

}

is basically

do {
pr_err("Could not allocate PDU\n");
} while (1)

Can cause problems sometimes. But this loop is a bit worrisome
even without the printk() call.

>From printk() side, we only can do rate limiting here. Would be
great if nfc maintainers could take a look and tweak the loop
maybe.

---

diff --git a/net/nfc/llcp_core.c b/net/nfc/llcp_core.c
index ef4026a23e80..a309a27581da 100644
--- a/net/nfc/llcp_core.c
+++ b/net/nfc/llcp_core.c
@@ -1386,7 +1386,7 @@ static void nfc_llcp_recv_agf(struct nfc_llcp_local 
*local, struct sk_buff *skb)
 
new_skb = nfc_alloc_recv_skb(pdu_len, GFP_KERNEL);
if (new_skb == NULL) {
-   pr_err("Could not allocate PDU\n");
+   pr_err_ratelimited("Could not allocate PDU\n");
return;
}
 


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-14 Thread Sergey Senozhatsky
On (10/13/16 14:49), Andy Lutomirski wrote:
[..]
> > >  FAIL: 412cba02 > c900802cba02 || 1 -> (412cba02
> > > >> 39) == 130
> >
> > Yeah, we already know that in this function the aad variable is on the
> > stack, it explicitly is.
> >
> > The question, though, is why precisely that fails in the crypto code.
> > Can you send the Oops report itself?
> >
> 
> It's failing before that.  With CONFIG_VMAP_STACK=y, the stack may not
> be physically contiguous and can't be used for DMA, so putting it in a
> scatterlist is bogus in general, and the crypto code mostly wants a
> scatterlist.
> 
> There are a couple (faster!) APIs for crypto that don't use
> scatterlists, but I don't think AEAD works with them.

given that we have a known issue shouldn't VMAP_STACK be
disabled for now, or would you rather prefer to mark MAC80211
as incompatible: "depends on CFG80211 && !VMAP_STACK"?

-ss


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-13 Thread Sergey Senozhatsky
On (10/14/16 00:00), Sergey Senozhatsky wrote:
> kernel:  [] ieee80211_crypto_ccmp_decrypt+0x204/0x298
> kernel:  [] ieee80211_rx_handlers+0x7df/0x1c1d
> kernel:  [] ieee80211_prepare_and_rx_handle+0xdc2/0xe79
> kernel:  [] ? ieee80211_rx_napi+0x168/0x7b6
> kernel:  [] ieee80211_rx_napi+0x48b/0x7b6
> kernel:  [] ? debug_smp_processor_id+0x17/0x19
> kernel:  [] iwl_mvm_rx_rx_mpdu+0x6e6/0x751 [iwlmvm]
> kernel:  [] iwl_mvm_rx+0x7e/0x98 [iwlmvm]
> kernel:  [] iwl_pcie_rx_handle+0x523/0x698 [iwlwifi]
> kernel:  [] iwl_pcie_irq_handler+0x46f/0x65f [iwlwifi]
> kernel:  [] ? irq_finalize_oneshot+0xd4/0xd4
> kernel:  [] irq_thread_fn+0x1d/0x34
> kernel:  [] irq_thread+0xe6/0x1bb
> kernel:  [] ? wake_threads_waitq+0x2c/0x2c
> kernel:  [] ? irq_thread_dtor+0x95/0x95
> kernel:  [] kthread+0xfc/0x104
> kernel:  [] ? put_lock_stats.isra.9+0xe/0x20
> kernel:  [] ? kthread_create_on_node+0x3f/0x3f
> kernel:  [] ret_from_fork+0x22/0x30
> kernel: Code: 01 ca 49 89 d1 48 89 d1 48 c1 ea 23 48 8b 14 d5 80 23 63 82 49 
> c1 e9 0c 48 c1 e9 1b 48 85 d2 74 0a 0f b6 c9 48 c1 e1 04 48 01 ca <48> 8b 12 
> 49 c1 e1 06 b9 00 00 00 80 89 7d 80 89 75 84 48 8b 3d 
> kernel: RIP  [] ieee80211_aes_ccm_decrypt+0x107/0x27f

8146d1ed :
8146d1ed:   e8 9e 67 04 00  callq  814b3990 
<__fentry__>
8146d1f2:   55  push   %rbp
8146d1f3:   48 89 e5mov%rsp,%rbp
8146d1f6:   41 57   push   %r15
8146d1f8:   41 56   push   %r14
8146d1fa:   49 89 cemov%rcx,%r14
8146d1fd:   41 55   push   %r13
8146d1ff:   41 54   push   %r12
8146d201:   53  push   %rbx
8146d202:   48 83 c4 80 add$0xff80,%rsp
8146d206:   8b 47 04mov0x4(%rdi),%eax
8146d209:   48 8d 48 50 lea0x50(%rax),%rcx
8146d20d:   48 83 c0 5e add$0x5e,%rax
8146d211:   48 c1 e8 03 shr$0x3,%rax
8146d215:   48 c1 e0 03 shl$0x3,%rax
8146d219:   48 29 c4sub%rax,%rsp
8146d21c:   4c 8d 7c 24 07  lea0x7(%rsp),%r15
8146d221:   49 c1 ef 03 shr$0x3,%r15
8146d225:   4d 85 c0test   %r8,%r8
8146d228:   4a 8d 04 fd 00 00 00lea0x0(,%r15,8),%rax
8146d22f:   00 
8146d230:   48 89 85 70 ff ff ffmov%rax,-0x90(%rbp)
8146d237:   75 0a   jne8146d243 
<ieee80211_aes_ccm_decrypt+0x56>
8146d239:   b8 ea ff ff ff  mov$0xffea,%eax
8146d23e:   e9 1a 02 00 00  jmpq   8146d45d 
<ieee80211_aes_ccm_decrypt+0x270>
8146d243:   31 c0   xor%eax,%eax
8146d245:   49 89 fcmov%rdi,%r12
8146d248:   49 89 f5mov%rsi,%r13
8146d24b:   4c 89 85 58 ff ff ffmov%r8,-0xa8(%rbp)
8146d252:   4a 8d 3c fd 00 00 00lea0x0(,%r15,8),%rdi
8146d259:   00 
8146d25a:   be 03 00 00 00  mov$0x3,%esi
8146d25f:   4c 89 cbmov%r9,%rbx
8146d262:   48 89 95 60 ff ff ffmov%rdx,-0xa0(%rbp)
8146d269:   f3 aa   rep stos %al,%es:(%rdi)
8146d26b:   48 8d 85 78 ff ff fflea-0x88(%rbp),%rax
8146d272:   48 89 c7mov%rax,%rdi
8146d275:   48 89 85 68 ff ff ffmov%rax,-0x98(%rbp)
8146d27c:   e8 46 06 dc ff  callq  8122d8c7 

8146d281:   48 8b 95 60 ff ff ffmov-0xa0(%rbp),%rdx
8146d288:   41 b9 00 00 00 80   mov$0x8000,%r9d
8146d28e:   48 8b 0d 7b cd 39 00mov0x39cd7b(%rip),%rcx  
  # 8180a010 
8146d295:   48 8b 85 68 ff ff ffmov-0x98(%rbp),%rax
8146d29c:   4c 8b 85 58 ff ff ffmov-0xa8(%rbp),%r8
8146d2a3:   0f b7 32movzwl (%rdx),%esi
8146d2a6:   48 83 c2 02 add$0x2,%rdx
8146d2aa:   89 d7   mov%edx,%edi
8146d2ac:   81 e7 ff 0f 00 00   and$0xfff,%edi
8146d2b2:   66 c1 c6 08 rol$0x8,%si
8146d2b6:   4c 01 caadd%r9,%rdx
8146d2b9:   0f b7 f6movzwl %si,%esi
8146d2bc:   72 0a   jb 8146d2c8 
<ieee80211_aes_ccm_decrypt+0xdb>
8146d2be:   48 b9 00 00 00 80 ffmovabs $0x77ff8000,%rcx

Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-13 Thread Sergey Senozhatsky
On (10/13/16 15:45), Johannes Berg wrote:
> On Thu, 2016-10-13 at 22:42 +0900, Sergey Senozhatsky wrote:
> > 
> > > > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commi
> > > > t/?h=x86/vmap_stack=0a39cfa6fbb5d5635c85253cc7d6b44b54822afd
> > > > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commi
> > > > t/?h=x86/vmap_stack=bf8cfa200b5a01383ea39fc8ce2f32909767baa8
> > > 
> > > That truly sounds like something we'd rather avoid in the TX/RX
> > > paths though, which should perform well.
> > 
> > didn't fix.
> 
> It couldn't, since the new helpers weren't used in mac80211 in those
> patches yet.

indeed. I thought they were.

> >  FAIL: 412cba02 > c900802cba02 || 1 -> (412cba02
> > >> 39) == 130
> 
> The question, though, is why precisely that fails in the crypto code.
> Can you send the Oops report itself?

kernel: BUG: unable to handle kernel NULL pointer dereference at   
(null)
kernel: IP: [] ieee80211_aes_ccm_decrypt+0x107/0x27f
kernel: PGD 0 
kernel: 
kernel: Oops:  [#1] PREEMPT SMP
kernel: Modules linked in: nls_iso8859_1 nls_cp437 vfat fat mousedev psmouse 
serio_raw atkbd libps2 i915 coretemp i2c_algo_bit hwmon crc32c_intel mxm_wmi 
drm_kms_helper cfbfillrect syscopyarea cfbimgblt sysfillrect iwlmvm sysimgblt 
fb_sys_fops i2c_i801 cfbcopyarea ie31200_edac drm iwlwifi i2c
kernel: CPU: 3 PID: 245 Comm: irq/28-iwlwifi Not tainted 
4.8.0-next-20161013-dbg-2-ge789862-dirty #112
kernel: task: 88041bf01800 task.stack: c92d
kernel: RIP: 0010:[]  [] 
ieee80211_aes_ccm_decrypt+0x107/0x27f
kernel: RSP: 0018:c92d3770  EFLAGS: 00010246
kernel: RAX: c92d3930 RBX: 8804133cf606 RCX: 00082000
kernel: RDX:  RSI: 0018 RDI: 0a02
kernel: RBP: c92d39b8 R08: 05e4 R09: 000412d3
kernel: R10: 001c R11: 8803e66d2d20 R12: 8804191c2780
kernel: R13: c92d39f0 R14: 8804133cf022 R15: 1925a6ee
kernel: FS:  () GS:88041ea0() 
knlGS:
kernel: CS:  0010 DS:  ES:  CR0: 80050033
kernel: CR2:  CR3: 01805000 CR4: 001406e0
kernel: Stack:
kernel:     
kernel:     
kernel:     
kernel: Call Trace:
kernel:  [] ieee80211_crypto_ccmp_decrypt+0x204/0x298
kernel:  [] ieee80211_rx_handlers+0x7df/0x1c1d
kernel:  [] ieee80211_prepare_and_rx_handle+0xdc2/0xe79
kernel:  [] ? ieee80211_rx_napi+0x168/0x7b6
kernel:  [] ieee80211_rx_napi+0x48b/0x7b6
kernel:  [] ? debug_smp_processor_id+0x17/0x19
kernel:  [] iwl_mvm_rx_rx_mpdu+0x6e6/0x751 [iwlmvm]
kernel:  [] iwl_mvm_rx+0x7e/0x98 [iwlmvm]
kernel:  [] iwl_pcie_rx_handle+0x523/0x698 [iwlwifi]
kernel:  [] iwl_pcie_irq_handler+0x46f/0x65f [iwlwifi]
kernel:  [] ? irq_finalize_oneshot+0xd4/0xd4
kernel:  [] irq_thread_fn+0x1d/0x34
kernel:  [] irq_thread+0xe6/0x1bb
kernel:  [] ? wake_threads_waitq+0x2c/0x2c
kernel:  [] ? irq_thread_dtor+0x95/0x95
kernel:  [] kthread+0xfc/0x104
kernel:  [] ? put_lock_stats.isra.9+0xe/0x20
kernel:  [] ? kthread_create_on_node+0x3f/0x3f
kernel:  [] ret_from_fork+0x22/0x30
kernel: Code: 01 ca 49 89 d1 48 89 d1 48 c1 ea 23 48 8b 14 d5 80 23 63 82 49 c1 
e9 0c 48 c1 e9 1b 48 85 d2 74 0a 0f b6 c9 48 c1 e1 04 48 01 ca <48> 8b 12 49 c1 
e1 06 b9 00 00 00 80 89 7d 80 89 75 84 48 8b 3d 
kernel: RIP  [] ieee80211_aes_ccm_decrypt+0x107/0x27f
kernel:  RSP 
kernel: CR2: 
kernel: ---[ end trace 3cd1fcd496516f72 ]---

-ss


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-13 Thread Sergey Senozhatsky
On (10/13/16 22:42), Sergey Senozhatsky wrote:
> 
> On (10/13/16 08:02), Johannes Berg wrote:
> > On Wed, 2016-10-12 at 22:39 -0700, Andy Lutomirski wrote:
> > 
> > > In a pinch, I have these patches sitting around:
> > > 
> > > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commit/?h=x86/vmap_stack=0a39cfa6fbb5d5635c85253cc7d6b44b54822afd
> > > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commit/?h=x86/vmap_stack=bf8cfa200b5a01383ea39fc8ce2f32909767baa8
> > 
> > That truly sounds like something we'd rather avoid in the TX/RX paths
> > though, which should perform well.
> 
> didn't fix.
> 
> so I finally had some time to do a better bug-reporter job.
> 
> I added a bunch of printk-s and several virt_addr_valid()-s
> to ieee80211_aes_ccm_encrypt().
> 
> and right befoe the Oops I see the following report from
> virt_addr_valid()
> 
> 
>  FAIL: 412cba02 > c900802cba02 || 1 -> (412cba02 >> 39) 
> == 130

that  `(412cba02 >> 39) == 130'   part is

phys_addr_valid()
{
(addr >> boot_cpu_data.x86_phys_bits)
}

-ss


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-13 Thread Sergey Senozhatsky
On (10/13/16 08:02), Johannes Berg wrote:
> On Wed, 2016-10-12 at 22:39 -0700, Andy Lutomirski wrote:
> 
> > In a pinch, I have these patches sitting around:
> > 
> > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commit/?h=x86/vmap_stack=0a39cfa6fbb5d5635c85253cc7d6b44b54822afd
> > https://git.kernel.org/cgit/linux/kernel/git/luto/linux.git/commit/?h=x86/vmap_stack=bf8cfa200b5a01383ea39fc8ce2f32909767baa8
> 
> That truly sounds like something we'd rather avoid in the TX/RX paths
> though, which should perform well.

didn't fix.

so I finally had some time to do a better bug-reporter job.

I added a bunch of printk-s and several virt_addr_valid()-s
to ieee80211_aes_ccm_encrypt().

and right befoe the Oops I see the following report from
virt_addr_valid()


 FAIL: 412cba02 > c900802cba02 || 1 -> (412cba02 >> 39) == 
130


which is basically failed '!phys_addr_valid(x)' in __virt_addr_valid()

/* carry flag will be set if starting x was >= PAGE_OFFSET */
if ((x > y) || !phys_addr_valid(x))
return false;

backtrace

 [ cut here ]
 WARNING: CPU: 7 PID: 246 at arch/x86/mm/physaddr.c:68 
__virt_addr_valid+0xab/0xed
  c92cb6f0 8122168c  
  c92cb730 810428d8 00440198 88041bd21022
  c92cba02 192596ed 88041932d1e0 c92cba00
 Call Trace:
  [] dump_stack+0x4f/0x65
  [] __warn+0xc2/0xdd
  [] warn_slowpath_null+0x1d/0x1f
  [] __virt_addr_valid+0xab/0xed
  [] ieee80211_aes_ccm_decrypt+0x8f/0x2da
  [] ? debug_smp_processor_id+0x17/0x19
  [] ? __put_page+0x3c/0x3f
  [] ? ccmp_special_blocks.isra.1+0x51/0x12d
  [] ieee80211_crypto_ccmp_decrypt+0x204/0x298
  [] ieee80211_rx_handlers+0x7df/0x1c1d
  [] ieee80211_prepare_and_rx_handle+0xdc2/0xe79
  [] ? ieee80211_rx_napi+0x154/0x7a5
  [] ieee80211_rx_napi+0x474/0x7a5
  [] iwl_mvm_rx_rx_mpdu+0x6e6/0x751 [iwlmvm]
  [] iwl_mvm_rx+0x7e/0x98 [iwlmvm]
  [] iwl_pcie_rx_handle+0x523/0x698 [iwlwifi]
  [] iwl_pcie_irq_handler+0x45d/0x64d [iwlwifi]
  [] ? irq_finalize_oneshot+0xd4/0xd4
  [] irq_thread_fn+0x1d/0x34
  [] irq_thread+0xe6/0x1bb
  [] ? wake_threads_waitq+0x2c/0x2c
  [] ? irq_thread_dtor+0x95/0x95
  [] kthread+0xfc/0x104
  [] ? put_lock_stats.isra.9+0xe/0x20
  [] ? kthread_create_on_node+0x3f/0x3f
  [] ? kthread_create_on_node+0x3f/0x3f
  [] ? kthread_create_on_node+0x3f/0x3f
  [] ret_from_fork+0x22/0x30

-ss


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-12 Thread Sergey Senozhatsky
Hello,

On (10/12/16 11:05), Johannes Berg wrote:
> Sorry - I meant to look into this yesterday but forgot.
> 
> > Andy, can this be related to CONFIG_VMAP_STACK?
> 
> I think it is.

yeah, the system works fine with !CONFIG_VMAP_STACK.

> > > current -git kills my system.
> 
> Can you elaborate on how exactly it kills your system?

the last time I saw it it was a NULL deref at ieee80211_aes_ccm_decrypt.

-ss


Re: [mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-10 Thread Sergey Senozhatsky
Cc Andy

Andy, can this be related to CONFIG_VMAP_STACK?

On (10/11/16 00:03), Sergey Senozhatsky wrote:
> Hello,
> 
> current -git kills my system. adding
> 
>   if (!virt_addr_valid([2])) {
>   WARN_ON(1);
>   return -EINVAL;
>   }
> 
> to ieee80211_aes_ccm_decrypt() given the following backtrace
> 
>  WARNING: CPU: 5 PID: 252 at net/mac80211/aes_ccm.c:77 
> ieee80211_aes_ccm_decrypt+0xc8/0x197
>  CPU: 5 PID: 252 Comm: irq/29-iwlwifi Tainted: GW   
> 4.8.0-next-20161010-dbg-7-g79797e9-dirty #88
>   c9413638 811ff0e3  
>   c9413678 8103fe91 004d01c8 192826d3
>   88040fc526d8 0008 c9413978 c941397a
>  Call Trace:
>   [] dump_stack+0x4f/0x65
>   [] __warn+0xc2/0xdd
>   [] warn_slowpath_null+0x1d/0x1f
>   [] ieee80211_aes_ccm_decrypt+0xc8/0x197
>   [] ? __put_page+0x3c/0x3f
>   [] ? put_page+0x4a/0x62
>   [] ? __pskb_pull_tail+0x1e8/0x279
>   [] ? ccmp_special_blocks.isra.5+0x51/0x12d
>   [] ieee80211_crypto_ccmp_decrypt+0x1ba/0x221
>   [] ieee80211_rx_handlers+0x52a/0x19c2
>   [] ? start_dl_timer+0xa8/0xb4
>   [] ? put_lock_stats.isra.24+0xe/0x20
>   [] ? del_timer+0x57/0x61
>   [] ieee80211_prepare_and_rx_handle+0xcd6/0xd2a
>   [] ? local_clock+0x10/0x12
>   [] ? __lock_acquire.isra.31+0x202/0x57e
>   [] ? rcu_read_unlock+0x23/0x23
>   [] ? sched_clock_cpu+0x17/0xc6
>   [] ieee80211_rx_napi+0x5af/0x698
>   [] ? get_lock_stats+0x19/0x50
>   [] ? put_lock_stats.isra.24+0xe/0x20
>   [] iwl_mvm_rx_rx_mpdu+0x5ab/0x60c [iwlmvm]
>   [] ? get_lock_stats+0x19/0x50
>   [] iwl_mvm_rx+0x45/0x69 [iwlmvm]
>   [] iwl_pcie_rx_handle+0x478/0x584 [iwlwifi]
>   [] iwl_pcie_irq_handler+0x39c/0x52d [iwlwifi]
>   [] ? irq_finalize_oneshot+0xa7/0xa7
>   [] irq_thread_fn+0x1d/0x34
>   [] irq_thread+0xe6/0x1bb
>   [] ? wake_threads_waitq+0x2c/0x2c
>   [] ? irq_thread_dtor+0x95/0x95
>   [] kthread+0xc6/0xce
>   [] ? put_lock_stats.isra.24+0xe/0x20
>   [] ? __list_del_entry+0x22/0x22
>   [] ret_from_fork+0x22/0x30
>  ---[ end trace 94da6d4698b938b2 ]---

-ss


[mac80211] BUG_ON with current -git (4.8.0-11417-g24532f7)

2016-10-10 Thread Sergey Senozhatsky
Hello,

current -git kills my system. adding

if (!virt_addr_valid([2])) {
WARN_ON(1);
return -EINVAL;
}

to ieee80211_aes_ccm_decrypt() given the following backtrace

 WARNING: CPU: 5 PID: 252 at net/mac80211/aes_ccm.c:77 
ieee80211_aes_ccm_decrypt+0xc8/0x197
 CPU: 5 PID: 252 Comm: irq/29-iwlwifi Tainted: GW   
4.8.0-next-20161010-dbg-7-g79797e9-dirty #88
  c9413638 811ff0e3  
  c9413678 8103fe91 004d01c8 192826d3
  88040fc526d8 0008 c9413978 c941397a
 Call Trace:
  [] dump_stack+0x4f/0x65
  [] __warn+0xc2/0xdd
  [] warn_slowpath_null+0x1d/0x1f
  [] ieee80211_aes_ccm_decrypt+0xc8/0x197
  [] ? __put_page+0x3c/0x3f
  [] ? put_page+0x4a/0x62
  [] ? __pskb_pull_tail+0x1e8/0x279
  [] ? ccmp_special_blocks.isra.5+0x51/0x12d
  [] ieee80211_crypto_ccmp_decrypt+0x1ba/0x221
  [] ieee80211_rx_handlers+0x52a/0x19c2
  [] ? start_dl_timer+0xa8/0xb4
  [] ? put_lock_stats.isra.24+0xe/0x20
  [] ? del_timer+0x57/0x61
  [] ieee80211_prepare_and_rx_handle+0xcd6/0xd2a
  [] ? local_clock+0x10/0x12
  [] ? __lock_acquire.isra.31+0x202/0x57e
  [] ? rcu_read_unlock+0x23/0x23
  [] ? sched_clock_cpu+0x17/0xc6
  [] ieee80211_rx_napi+0x5af/0x698
  [] ? get_lock_stats+0x19/0x50
  [] ? put_lock_stats.isra.24+0xe/0x20
  [] iwl_mvm_rx_rx_mpdu+0x5ab/0x60c [iwlmvm]
  [] ? get_lock_stats+0x19/0x50
  [] iwl_mvm_rx+0x45/0x69 [iwlmvm]
  [] iwl_pcie_rx_handle+0x478/0x584 [iwlwifi]
  [] iwl_pcie_irq_handler+0x39c/0x52d [iwlwifi]
  [] ? irq_finalize_oneshot+0xa7/0xa7
  [] irq_thread_fn+0x1d/0x34
  [] irq_thread+0xe6/0x1bb
  [] ? wake_threads_waitq+0x2c/0x2c
  [] ? irq_thread_dtor+0x95/0x95
  [] kthread+0xc6/0xce
  [] ? put_lock_stats.isra.24+0xe/0x20
  [] ? __list_del_entry+0x22/0x22
  [] ret_from_fork+0x22/0x30
 ---[ end trace 94da6d4698b938b2 ]---

-ss


Re: [linux-next: May 13] intel/iwlwifi/mvm/mvm.h:1069 suspicious rcu_dereference_protected() usage

2016-05-14 Thread Sergey Senozhatsky
On (05/15/16 01:31), Sergey Senozhatsky wrote:
> [11455.550649] ===
> [11455.550652] [ INFO: suspicious RCU usage. ]
> [11455.550657] 4.6.0-rc7-next-20160513-dbg-4-g8de8b92-dirty #655 Not 
> tainted
> [11455.550660] ---
> [11455.550664] drivers/net/wireless/intel/iwlwifi/mvm/mvm.h:1069 suspicious 
> rcu_dereference_protected() usage!
> [11455.550667] 
>other info that might help us debug this:
> 
> [11455.550671] 
>rcu_scheduler_active = 1, debug_locks = 0
> [11455.550675] 5 locks held by irq/29-iwlwifi/247:
> [11455.550677]  #0:  (sync_cmd_lockdep_map){..}, at: [] 
> iwl_pcie_irq_handler+0x0/0x635 [iwlwifi]
> [11455.550705]  #1:  (&(>lock)->rlock){+.+...}, at: [] 
> iwl_pcie_rx_handle+0x38/0x5d5 [iwlwifi]
> [11455.550725]  #2:  (rcu_read_lock){..}, at: [] 
> ieee80211_rx_napi+0x152/0x8e2 [mac80211]
> [11455.550768]  #3:  (&(>rx_path_lock)->rlock){+.-...}, at: 
> [] ieee80211_rx_handlers+0x2e/0x1fe1 [mac80211]
> [11455.550804]  #4:  (rcu_read_lock){..}, at: [] 
> iwl_mvm_update_tkip_key+0x0/0x162 [iwlmvm]
> [11455.550833] 


[ 5406.034379] iwlwifi :02:00.0: Queue 16 stuck for 1 ms.
[ 5406.034385] iwlwifi :02:00.0: Current SW read_ptr 98 write_ptr 125
[ 5406.034431] iwl data: : 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00  
[ 5406.034454] iwlwifi :02:00.0: FH TRBs(0) = 0x8000300f
[ 5406.034475] iwlwifi :02:00.0: FH TRBs(1) = 0xc0110071
[ 5406.034491] iwlwifi :02:00.0: FH TRBs(2) = 0x
[ 5406.034505] iwlwifi :02:00.0: FH TRBs(3) = 0x8030001e
[ 5406.034520] iwlwifi :02:00.0: FH TRBs(4) = 0x
[ 5406.034536] iwlwifi :02:00.0: FH TRBs(5) = 0x
[ 5406.034551] iwlwifi :02:00.0: FH TRBs(6) = 0x
[ 5406.034566] iwlwifi :02:00.0: FH TRBs(7) = 0x00709087
[ 5406.034625] iwlwifi :02:00.0: Q 0 is active and mapped to fifo 3 ra_tid 
0x [31,31]
[ 5406.034690] iwlwifi :02:00.0: Q 1 is active and mapped to fifo 2 ra_tid 
0x [0,0]
[ 5406.034756] iwlwifi :02:00.0: Q 2 is active and mapped to fifo 1 ra_tid 
0x [17,17]
[ 5406.034821] iwlwifi :02:00.0: Q 3 is active and mapped to fifo 0 ra_tid 
0x [16,16]
[ 5406.034886] iwlwifi :02:00.0: Q 4 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.034944] iwlwifi :02:00.0: Q 5 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035010] iwlwifi :02:00.0: Q 6 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035068] iwlwifi :02:00.0: Q 7 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035133] iwlwifi :02:00.0: Q 8 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035192] iwlwifi :02:00.0: Q 9 is active and mapped to fifo 7 ra_tid 
0x [136,136]
[ 5406.035257] iwlwifi :02:00.0: Q 10 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035323] iwlwifi :02:00.0: Q 11 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035388] iwlwifi :02:00.0: Q 12 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035446] iwlwifi :02:00.0: Q 13 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035505] iwlwifi :02:00.0: Q 14 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035563] iwlwifi :02:00.0: Q 15 is active and mapped to fifo 5 ra_tid 
0x [0,0]
[ 5406.035622] iwlwifi :02:00.0: Q 16 is active and mapped to fifo 1 ra_tid 
0x [98,125]
[ 5406.035687] iwlwifi :02:00.0: Q 17 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035752] iwlwifi :02:00.0: Q 18 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035817] iwlwifi :02:00.0: Q 19 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.035883] iwlwifi :02:00.0: Q 20 is inactive and mapped to fifo 0 
ra_tid 0xfffc [0,0]
[ 5406.035940] iwlwifi :02:00.0: Q 21 is inactive and mapped to fifo 0 
ra_tid 0x0003 [0,0]
[ 5406.035999] iwlwifi :02:00.0: Q 22 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036064] iwlwifi :02:00.0: Q 23 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036122] iwlwifi :02:00.0: Q 24 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036188] iwlwifi :02:00.0: Q 25 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036246] iwlwifi :02:00.0: Q 26 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036305] iwlwifi :02:00.0: Q 27 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036370] iwlwifi :02:00.0: Q 28 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036428] iwlwifi :02:00.0: Q 29 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036487] iwlwifi :02:00.0: Q 30 is inactive and mapped to fifo 0 
ra_tid 0x [0,0]
[ 5406.036555] iwlwifi :02:00.0: Microcode SW error dete

[linux-next: May 13] intel/iwlwifi/mvm/mvm.h:1069 suspicious rcu_dereference_protected() usage

2016-05-14 Thread Sergey Senozhatsky
Hello,

[11455.550649] ===
[11455.550652] [ INFO: suspicious RCU usage. ]
[11455.550657] 4.6.0-rc7-next-20160513-dbg-4-g8de8b92-dirty #655 Not tainted
[11455.550660] ---
[11455.550664] drivers/net/wireless/intel/iwlwifi/mvm/mvm.h:1069 suspicious 
rcu_dereference_protected() usage!
[11455.550667] 
   other info that might help us debug this:

[11455.550671] 
   rcu_scheduler_active = 1, debug_locks = 0
[11455.550675] 5 locks held by irq/29-iwlwifi/247:
[11455.550677]  #0:  (sync_cmd_lockdep_map){..}, at: [] 
iwl_pcie_irq_handler+0x0/0x635 [iwlwifi]
[11455.550705]  #1:  (&(>lock)->rlock){+.+...}, at: [] 
iwl_pcie_rx_handle+0x38/0x5d5 [iwlwifi]
[11455.550725]  #2:  (rcu_read_lock){..}, at: [] 
ieee80211_rx_napi+0x152/0x8e2 [mac80211]
[11455.550768]  #3:  (&(>rx_path_lock)->rlock){+.-...}, at: 
[] ieee80211_rx_handlers+0x2e/0x1fe1 [mac80211]
[11455.550804]  #4:  (rcu_read_lock){..}, at: [] 
iwl_mvm_update_tkip_key+0x0/0x162 [iwlmvm]
[11455.550833] 
   stack backtrace:
[11455.550840] CPU: 4 PID: 247 Comm: irq/29-iwlwifi Not tainted 
4.6.0-rc7-next-20160513-dbg-4-g8de8b92-dirty #655
[11455.550844]   880037ff78e8 81187f9c 
88041b7ea980
[11455.550854]  0001 880037ff7918 8106b836 
88041bc0e028
[11455.550863]   88041d247878 88041bc0e028 
880037ff7938
[11455.550872] Call Trace:
[11455.550883]  [] dump_stack+0x68/0x92
[11455.550890]  [] lockdep_rcu_suspicious+0xf7/0x100
[11455.550911]  [] iwl_mvm_get_key_sta.part.0+0x5d/0x80 
[iwlmvm]
[11455.550930]  [] iwl_mvm_update_tkip_key+0xd3/0x162 [iwlmvm]
[11455.550945]  [] iwl_mvm_mac_update_tkip_key+0x17/0x19 
[iwlmvm]
[11455.550973]  [] ieee80211_tkip_decrypt_data+0x22c/0x24b 
[mac80211]
[11455.550996]  [] ieee80211_crypto_tkip_decrypt+0xc5/0x110 
[mac80211]
[11455.551026]  [] ieee80211_rx_handlers+0x9bb/0x1fe1 
[mac80211]
[11455.551035]  [] ? __lock_is_held+0x3c/0x57
[11455.551063]  [] 
ieee80211_prepare_and_rx_handle+0xe89/0xf33 [mac80211]
[11455.551071]  [] ? debug_smp_processor_id+0x17/0x19
[11455.551098]  [] ieee80211_rx_napi+0x4bf/0x8e2 [mac80211]
[11455.551119]  [] iwl_mvm_rx_rx_mpdu+0x6af/0x754 [iwlmvm]
[11455.551134]  [] iwl_mvm_rx+0x44/0x6d [iwlmvm]
[11455.551147]  [] iwl_pcie_rx_handle+0x461/0x5d5 [iwlwifi]
[11455.551160]  [] iwl_pcie_irq_handler+0x452/0x635 [iwlwifi]
[11455.551167]  [] ? irq_finalize_oneshot+0xc9/0xc9
[11455.551172]  [] irq_thread_fn+0x18/0x2f
[11455.551176]  [] irq_thread+0x108/0x1b0
[11455.551183]  [] ? __schedule+0x48d/0x58f
[11455.551188]  [] ? wake_threads_waitq+0x28/0x28
[11455.551193]  [] ? irq_thread_dtor+0x93/0x93
[11455.551198]  [] kthread+0xf3/0xfb
[11455.551205]  [] ? _raw_spin_unlock_irq+0x27/0x45
[11455.551212]  [] ret_from_fork+0x1f/0x40
[11455.551217]  [] ? kthread_create_on_node+0x1ca/0x1ca

-ss
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [linux-next] iwl_mvm_get_key_sta_id() suspicious RCU usage

2015-12-11 Thread Sergey Senozhatsky
On (12/12/15 09:05), Sergey Senozhatsky wrote:
> On (12/11/15 14:49), Johannes Berg wrote:
> > On Fri, 2015-12-11 at 22:44 +0900, Sergey Senozhatsky wrote:
> > 
> > > [ 6385.246300] drivers/net/wireless/intel/iwlwifi/mvm/sta.c:1226
> > > suspicious rcu_dereference_protected() usage!
> > > 
> > 
> > Funny, Laura Abbott also reported this bug earlier today :)
> > 
> > I've sent out a fix, you can see it here:
> > https://patchwork.ozlabs.org/patch/87/
> > 
> 

had to replace 'drivers/net/wireless/iwlwifi/mvm/sta.c' with
drivers/net/wireless/intel/iwlwifi/mvm/sta.c'

I'll report back if any problems show up.

-ss
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [linux-next] iwl_mvm_get_key_sta_id() suspicious RCU usage

2015-12-11 Thread Sergey Senozhatsky
On (12/11/15 14:49), Johannes Berg wrote:
> On Fri, 2015-12-11 at 22:44 +0900, Sergey Senozhatsky wrote:
> 
> > [ 6385.246300] drivers/net/wireless/intel/iwlwifi/mvm/sta.c:1226
> > suspicious rcu_dereference_protected() usage!
> > 
> 
> Funny, Laura Abbott also reported this bug earlier today :)
> 
> I've sent out a fix, you can see it here:
> https://patchwork.ozlabs.org/patch/87/
> 

Great, thanks!

-ss
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[linux-next] iwl_mvm_get_key_sta_id() suspicious RCU usage

2015-12-11 Thread Sergey Senozhatsky
Hi,

linux-next 20151211

[ 6385.246285] ===
[ 6385.246288] [ INFO: suspicious RCU usage. ]
[ 6385.246294] 4.4.0-rc4-next-20151211-dbg-00015-g7b65ef3-dirty #302 Not tainted
[ 6385.246296] ---
[ 6385.246300] drivers/net/wireless/intel/iwlwifi/mvm/sta.c:1226 suspicious 
rcu_dereference_protected() usage!
[ 6385.246303] 
   other info that might help us debug this:

[ 6385.246308] 
   rcu_scheduler_active = 1, debug_locks = 0
[ 6385.246313] 4 locks held by irq/30-iwlwifi/246:
[ 6385.246316]  #0:  (sync_cmd_lockdep_map){..}, at: [] 
iwl_pcie_irq_handler+0x5/0xaf4 [iwlwifi]
[ 6385.246341]  #1:  (&(>lock)->rlock){+.+...}, at: [] 
iwl_pcie_irq_handler+0x427/0xaf4 [iwlwifi]
[ 6385.246356]  #2:  (rcu_read_lock){..}, at: [] 
ieee80211_rx_napi+0x139/0x8f2 [mac80211]
[ 6385.246408]  #3:  (&(>rx_path_lock)->rlock){+.-...}, at: 
[] ieee80211_rx_handlers+0x33/0x21c3 [mac80211]
[ 6385.246448] 
   stack backtrace:
[ 6385.246455] CPU: 0 PID: 246 Comm: irq/30-iwlwifi Not tainted 
4.4.0-rc4-next-20151211-dbg-00015-g7b65ef3-dirty #302
[ 6385.246459]   8800c65678e0 811e7d72 
88041af55100
[ 6385.246467]  8800c6567910 8107dabe  
88041c6d2048
[ 6385.246474]  880416a30a08 88041c6d2048 8800c6567930 
a04f5106
[ 6385.246480] Call Trace:
[ 6385.246490]  [] dump_stack+0x4b/0x63
[ 6385.246497]  [] lockdep_rcu_suspicious+0xf7/0x100
[ 6385.246517]  [] iwl_mvm_get_key_sta_id.part.0+0x60/0x7f 
[iwlmvm]
[ 6385.246533]  [] iwl_mvm_update_tkip_key+0x43/0x22d [iwlmvm]
[ 6385.246544]  [] iwl_mvm_mac_update_tkip_key+0x1c/0x1e 
[iwlmvm]
[ 6385.246578]  [] ieee80211_tkip_decrypt_data+0x22f/0x44e 
[mac80211]
[ 6385.246584]  [] ? lock_acquire+0x101/0x188
[ 6385.246611]  [] ieee80211_crypto_tkip_decrypt+0xc8/0x113 
[mac80211]
[ 6385.246645]  [] ieee80211_rx_handlers+0xa68/0x21c3 
[mac80211]
[ 6385.246677]  [] 
ieee80211_prepare_and_rx_handle+0x81f/0x86f [mac80211]
[ 6385.246706]  [] ? ieee80211_rx_napi+0x139/0x8f2 [mac80211]
[ 6385.246711]  [] ? __lock_is_held+0x3c/0x57
[ 6385.246748]  [] ieee80211_rx_napi+0x640/0x8f2 [mac80211]
[ 6385.246767]  [] iwl_mvm_rx_rx_mpdu+0x651/0x660 [iwlmvm]
[ 6385.246781]  [] iwl_mvm_rx+0x58/0x1e6 [iwlmvm]
[ 6385.246793]  [] iwl_pcie_irq_handler+0x960/0xaf4 [iwlwifi]
[ 6385.246800]  [] ? __schedule+0x716/0xaf9
[ 6385.246806]  [] ? irq_finalize_oneshot+0xd0/0xd0
[ 6385.246812]  [] irq_thread_fn+0x1d/0x34
[ 6385.246817]  [] irq_thread+0x10d/0x1b5
[ 6385.246823]  [] ? wake_threads_waitq+0x2d/0x2d
[ 6385.246828]  [] ? irq_thread_dtor+0x98/0x98
[ 6385.246833]  [] kthread+0xf8/0x100
[ 6385.246840]  [] ? kthread_create_on_node+0x1c7/0x1c7
[ 6385.246847]  [] ret_from_fork+0x3f/0x70
[ 6385.246852]  [] ? kthread_create_on_node+0x1c7/0x1c7

-ss
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[-next] WARNING at iwl_mvm_time_event_send_add+0x72/0x1b6

2015-10-26 Thread Sergey Senozhatsky
Hi,

linux-next 20151022


wlp2s0: aborting authentication with 00:04:96:61:cd:e0 by local choice (Reason: 
3=DEAUTH_LEAVING)
[ cut here ]
WARNING: CPU: 0 PID: 1006 at drivers/net/wireless/iwlwifi/mvm/time-event.c:513 
iwl_mvm_time_event_send_add+0x72/0x1b6 [iwlmvm]()
Modules linked in: mousedev arc4 nls_iso8859_1 nls_cp437 vfat fat serio_raw 
psmouse atkbd coretemp hwmon i915 libps2 iwlmvm i2c_algo_bit mac80211 
drm_kms_helper cfbfillrect intel_powerclamp syscopyarea cfbimgblt sysfillrect 
sysimgblt crc32c_intel fb_sys_fops cfbcopyarea iwlwifi drm r8
CPU: 0 PID: 1006 Comm: iwconfig Not tainted 
4.3.0-rc6-next-20151022-dbg-2-g4041783-dirty #260
  8800c69479c8 811dd4ad 
 8800c6947a00 8103db4e a04fd261 88041c7cdfc8
 88041cc87a20 88041c7ceb28 8800c6947aac 8800c6947a10
Call Trace:
 [] dump_stack+0x4b/0x63
 [] warn_slowpath_common+0x99/0xb2
 [] ? iwl_mvm_time_event_send_add+0x72/0x1b6 [iwlmvm]
 [] warn_slowpath_null+0x1a/0x1c
 [] iwl_mvm_time_event_send_add+0x72/0x1b6 [iwlmvm]
 [] ? __lock_is_held+0x3c/0x57
 [] iwl_mvm_protect_session+0x150/0x219 [iwlmvm]
 [] ? iwl_mvm_protect_session+0x150/0x219 [iwlmvm]
 [] ? iwl_mvm_ref_sync+0x37/0x10c [iwlmvm]
 [] iwl_mvm_mac_mgd_prepare_tx+0xa4/0xc2 [iwlmvm]
 [] ? iwl_mvm_mac_mgd_prepare_tx+0xa4/0xc2 [iwlmvm]
 [] ieee80211_mgd_deauth+0x14f/0x3b0 [mac80211]
 [] ? __lock_is_held+0x3c/0x57
 [] ieee80211_deauth+0x18/0x1a [mac80211]
 [] cfg80211_mlme_deauth+0x13c/0x28e [cfg80211]
 [] cfg80211_disconnect+0xb5/0x2f7 [cfg80211]
 [] cfg80211_mgd_wext_siwfreq+0xed/0x160 [cfg80211]
 [] ? cfg80211_wext_freq+0x5f/0x5f [cfg80211]
 [] cfg80211_wext_siwfreq+0x76/0xf6 [cfg80211]
 [] ioctl_standard_call+0x66/0x376
 [] wext_handle_ioctl+0x102/0x16d
 [] dev_ioctl+0x6bb/0x6de
 [] ? handle_mm_fault+0xefc/0x13f9
 [] sock_ioctl+0x230/0x23c
 [] ? sock_ioctl+0x230/0x23c
 [] do_vfs_ioctl+0x458/0x4dc
 [] ? retint_user+0x18/0x20
 [] ? __fget_light+0x4d/0x71
 [] SyS_ioctl+0x43/0x61
 [] entry_SYSCALL_64_fastpath+0x12/0x6f
---[ end trace 6a44e7f1588bdae7 ]---


-ss
--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: [linuxwifi] [-next] WARNING at iwl_mvm_time_event_send_add+0x72/0x1b6

2015-10-26 Thread Sergey Senozhatsky
On (10/26/15 07:51), Grumbach, Emmanuel wrote:
> > On 10/26/2015 08:41 AM, Sergey Senozhatsky wrote:
> >> Hi,
> >>
> >> linux-next 20151022
> >>
> >>
> > 
> > Can be reproduced reliably?
> > Seems like a bad race between the end of session protection for the
> > authentication and the start of the session protection for the deauth.
> > I think I found the hole in the locks in there, but it is going to be
> > tricky to solve.
> 
> Not sure if I found the race. Can you please send the complete log?
> If you have timestamps, it'd greatly helps...
> dmesg output should do.
> 

Hi,

not really sure if I can reproduce this one easily. seen once.

---

Oct 26 15:20:51  dhclient[399]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 7
Oct 26 15:20:58  dhclient[399]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 17
Oct 26 15:21:09  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 7
Oct 26 15:21:09  kernel: wlp2s0: authenticate with 00:04:96:69:0d:80
Oct 26 15:21:09  kernel: wlp2s0: send auth to 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:09  kernel: wlp2s0: authenticated
Oct 26 15:21:09  kernel: wlp2s0: associate with 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:09  kernel: wlp2s0: RX AssocResp from 00:04:96:69:0d:80 
(capab=0x11 status=0 aid=24)
Oct 26 15:21:09  kernel: wlp2s0: associated
Oct 26 15:21:09  kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp2s0: link becomes 
ready
Oct 26 15:21:09  kernel: wlp2s0: deauthenticating from 00:04:96:69:0d:80 by 
local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:21:12  kernel: wlp2s0: authenticate with 00:04:96:61:e9:f0
Oct 26 15:21:12  kernel: wlp2s0: send auth to 00:04:96:61:e9:f0 (try 1/3)
Oct 26 15:21:12  kernel: wlp2s0: authenticated
Oct 26 15:21:12  kernel: wlp2s0: associate with 00:04:96:61:e9:f0 (try 1/3)
Oct 26 15:21:12  kernel: wlp2s0: RX AssocResp from 00:04:96:61:e9:f0 
(capab=0x11 status=0 aid=16)
Oct 26 15:21:12  kernel: wlp2s0: associated
Oct 26 15:21:12  kernel: wlp2s0: deauthenticating from 00:04:96:61:e9:f0 by 
local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:21:16  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 10
Oct 26 15:21:22  kernel: wlp2s0: authenticate with 00:04:96:69:0d:80
Oct 26 15:21:22  kernel: wlp2s0: send auth to 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:22  kernel: wlp2s0: authenticated
Oct 26 15:21:22  kernel: wlp2s0: associate with 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:22  kernel: wlp2s0: RX AssocResp from 00:04:96:69:0d:80 
(capab=0x11 status=0 aid=25)
Oct 26 15:21:22  kernel: wlp2s0: associated
Oct 26 15:21:22  kernel: wlp2s0: deauthenticating from 00:04:96:69:0d:80 by 
local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:21:26  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 9
Oct 26 15:21:35  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 12
Oct 26 15:21:47  kernel: wlp2s0: authenticate with 00:04:96:69:0d:80
Oct 26 15:21:47  kernel: wlp2s0: send auth to 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:47  kernel: wlp2s0: authenticated
Oct 26 15:21:47  kernel: wlp2s0: associate with 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:21:47  kernel: wlp2s0: RX AssocResp from 00:04:96:69:0d:80 
(capab=0x11 status=0 aid=25)
Oct 26 15:21:47  kernel: wlp2s0: associated
Oct 26 15:21:47  kernel: wlp2s0: deauthenticating from 00:04:96:69:0d:80 by 
local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:21:47  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 18
Oct 26 15:22:05  dhclient[539]: DHCPDISCOVER on wlp2s0 to 255.255.255.255 port 
67 interval 5
Oct 26 15:22:10  dhclient[539]: No DHCPOFFERS received.
Oct 26 15:22:10  dhclient[539]: No working leases in persistent database - 
sleeping.
Oct 26 15:22:34  kernel: wlp2s0: authenticate with 00:04:96:69:0d:80
Oct 26 15:22:34  kernel: wlp2s0: send auth to 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:22:34  kernel: wlp2s0: authenticated
Oct 26 15:22:34  kernel: wlp2s0: associate with 00:04:96:69:0d:80 (try 1/3)
Oct 26 15:22:34  kernel: wlp2s0: RX AssocResp from 00:04:96:69:0d:80 
(capab=0x11 status=0 aid=29)
Oct 26 15:22:34  kernel: wlp2s0: associated
Oct 26 15:22:34  kernel: wlp2s0: deauthenticating from 00:04:96:69:0d:80 by 
local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:22:34  kernel: wlp2s0: authenticate with 00:04:96:61:cd:e0
Oct 26 15:22:34  kernel: wlp2s0: send auth to 00:04:96:61:cd:e0 (try 1/3)
Oct 26 15:22:34  kernel: wlp2s0: aborting authentication with 00:04:96:61:cd:e0 
by local choice (Reason: 3=DEAUTH_LEAVING)
Oct 26 15:22:34  kernel: [ cut here ]
Oct 26 15:22:34  kernel: WARNING: CPU: 0 PID: 1006 at 
drivers/net/wireless/iwlwifi/mvm/time-event.c:513 
iwl_mvm_time_event_send_add+0x72/0x1b6 [iwlmvm]()
Oct 26 15:22:34  kernel: Modules linked in: mousedev arc4 nls_iso8859_1 
nls_cp437 vfat fat serio_raw psmouse atkbd coretemp hwmon i915 l