Re: IPv6 issue in next-20171102 - lockdep and BUG handling RA packet.

[Ido Schimmel <idosch@idosch.org>]

On Mon, Nov 06, 2017 at 03:56:54PM -0500, valdis.kletnieks@vt.edu wrote:
> I've hit this 6 times now, across 3 boots:
> 
> Nov  3 11:04:54 turing-police kernel: [  547.814748] BUG: sleeping function called from invalid context at mm/slab.h:422
> 
> Nov  3 20:24:11 turing-police kernel: [   60.093793] BUG: sleeping function called from invalid context at mm/slab.h:422
> Nov  4 20:20:54 turing-police kernel: [86264.366955] BUG: sleeping function called from invalid context at mm/slab.h:422
> Nov  5 19:17:40 turing-police kernel: [172469.769179] BUG: sleeping function called from invalid context at mm/slab.h:422
> Nov  6 06:07:37 turing-police kernel: [211467.239460] BUG: sleeping function called from invalid context at mm/slab.h:422
> 
> Nov  6 14:12:43 turing-police kernel: [   54.891848] BUG: sleeping function called from invalid context at mm/slab.h:422
> 
> Something seems to be going astray while handling a RA packet.
> 
> Kernel dirty due to hand-patching https://patchwork.kernel.org/patch/10003555/
> (signed int:1 bitfield in sched.h causing tons of warnings)
> 
> Unfortunately, the previous next- kernel I built was -20170927 (which worked OK).
> 
> Googling for things in the traceback in the last month comes up empty, and only
> thing in the git log for net/ipv6 that looks vaguely related:
> 
> commit f3d9832e56c48e4ca50bab0457e21bcaade4536d
> Author: David Ahern <dsahern@gmail.com>
> Date:   Wed Oct 18 09:56:52 2017 -0700
> 
>     ipv6: addrconf: cleanup locking in ipv6_add_addr

Probably right...

[...]

> [   54.891848] BUG: sleeping function called from invalid context at mm/slab.h:422
> [   54.891855] in_atomic(): 1, irqs_disabled(): 0, pid: 0, name: swapper/0
> [   54.891859] INFO: lockdep is turned off.
> [   54.891867] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W  OE    4.14.0-rc7-next-20171102-dirty #537
> [   54.891872] Hardware name: Dell Inc. Latitude E6530/07Y85M, BIOS A20 05/08/2017
> [   54.891877] Call Trace:
> [   54.891882]  <IRQ>
> [   54.891894]  dump_stack+0x7b/0xe4
> [   54.891907]  ___might_sleep+0x1b0/0x300
> [   54.891921]  kmem_cache_alloc_trace+0x2c7/0x500
> [   54.891931]  ? cyc2ns_read_end+0x1e/0x30
> [   54.891944]  ipv6_add_addr+0x15a/0xc30
> [   54.891977]  ? ipv6_create_tempaddr+0x2ea/0x5d0
> [   54.891986]  ipv6_create_tempaddr+0x2ea/0x5d0

This function is called from softirq so we should call ipv6_add_addr()
with 'can_block' set to 'false'.

DavidA, it's already late here so you can probably fix this before I
take a closer look tomorrow morning. :)

Thanks

> [   54.892007]  ? manage_tempaddrs+0x195/0x220
> [   54.892023]  ? addrconf_prefix_rcv_add_addr+0x1c0/0x4f0
> [   54.892032]  addrconf_prefix_rcv_add_addr+0x1c0/0x4f0
> [   54.892052]  addrconf_prefix_rcv+0x2e5/0x9b0
> [   54.892068]  ? neigh_update+0x446/0xb90
> [   54.892098]  ? ndisc_router_discovery+0x5ab/0xf00
> [   54.892107]  ndisc_router_discovery+0x5ab/0xf00
> [   54.892120]  ? retint_kernel+0x2d/0x2d
> [   54.892152]  ndisc_rcv+0x1b6/0x270
> [   54.892167]  icmpv6_rcv+0x6aa/0x9f0
> [   54.892175]  ? ipv6_chk_mcast_addr+0x176/0x530
> [   54.892183]  ? do_csum+0x17b/0x260
> [   54.892197]  ip6_input_finish+0x194/0xb20
> [   54.892216]  ip6_input+0x5b/0x2c0
> [   54.892228]  ? ip6_rcv_finish+0x320/0x320
> [   54.892244]  ip6_mc_input+0x15a/0x250
> [   54.892252]  ipv6_rcv+0x772/0x1050
> [   54.892261]  ? consume_skb+0xbe/0x2d0
> [   54.892275]  ? ip6_make_skb+0x2a0/0x2a0
> [   54.892283]  ? ip6_input+0x2c0/0x2c0
> [   54.892298]  __netif_receive_skb_core+0xa0f/0x1600
> [   54.892316]  ? process_backlog+0xac/0x400
> [   54.892323]  process_backlog+0xfa/0x400
> [   54.892334]  ? net_rx_action+0x145/0x1130
> [   54.892348]  net_rx_action+0x310/0x1130
> [   54.892407]  ? RTUSBBulkReceive+0x11d/0x190 [mt7610u_sta]
> [   54.892430]  __do_softirq+0x140/0xaba
> [   54.892455]  irq_exit+0x10b/0x160
> [   54.892464]  do_IRQ+0xbb/0x1b0
> [   54.892476]  common_interrupt+0x93/0x93
> [   54.892481]  </IRQ>
> [   54.892490] RIP: 0010:cpuidle_enter_state+0xe6/0x5f0
> [   54.892496] RSP: 0018:ffffffff9ca03e60 EFLAGS: 00000282 ORIG_RAX: ffffffffffffffda
> [   54.892508] RAX: 000000000011b081 RBX: ffffc01bff617430 RCX: 0000000000000000
> [   54.892515] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff9ca2e580
> [   54.892521] RBP: 0000000cbf23c844 R08: 0000000000000b84 R09: 0000000000000000
> [   54.892528] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000005
> [   54.892534] R13: 0000000cbf23c844 R14: 0000000000000000 R15: 0000000cbf0f0e82
> [   54.892574]  do_idle+0x191/0x3a0
> [   54.892587]  cpu_startup_entry+0x7b/0x90
> [   54.892599]  start_kernel+0x80b/0x841
> [   54.892613]  secondary_startup_64+0xa5/0xb0