[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <CAKt3ReJYWKRhnYdt3TpZa0+CqTgp+gL2Xkf-zoBLVmj1vk6s7w@mail.gmail.com>
Date: Tue, 19 Dec 2017 10:50:42 +0200
From: Darius Ski <darius.ski@...il.com>
To: Steffen Klassert <steffen.klassert@...unet.com>
Cc: netdev@...r.kernel.org
Subject: Re: BUG: 4.14.6 unable to handle kernel NULL pointer dereference at xfrm_output_resume
Hi,
thanks a lot for the patch. I have applied it to 4.14.7 and crossed
fingers, hopefully no more problems.
I will let community know if there are any more crashes.
Thanks!
Darius.
On Mon, Dec 18, 2017 at 2:22 PM, Steffen Klassert
<steffen.klassert@...unet.com> wrote:
> On Mon, Dec 18, 2017 at 01:50:10PM +0200, Darius Ski wrote:
>> Hi,
>>
>> running 4.14.6 with 3 IPSec tunnels via Racoon/setkey and today woke up to this:
>>
>> [Mon Dec 18 07:26:15 2017] ------------[ cut here ]------------
>> [Mon Dec 18 07:26:15 2017] WARNING: CPU: 0 PID: 10555 at
>> ./include/net/dst.h:256 xfrm_resolve_and_create_bundle+0x97e/0x9b0
>> [Mon Dec 18 07:26:15 2017] Modules linked in: smartpqi
>> [Mon Dec 18 07:26:15 2017] CPU: 0 PID: 10555 Comm: java Not tainted 4.14.6 #1
>> [Mon Dec 18 07:26:15 2017] Hardware name: HPE ProLiant DL380
>> Gen10/ProLiant DL380 Gen10, BIOS U30 11/14/2017
>> [Mon Dec 18 07:26:15 2017] task: ffff8852b33aca40 task.stack: ffffc9000fe88000
>> [Mon Dec 18 07:26:15 2017] RIP: 0010:xfrm_resolve_and_create_bundle+0x97e/0x9b0
>> [Mon Dec 18 07:26:15 2017] RSP: 0018:ffffc9000fe8ba40 EFLAGS: 00010246
>> [Mon Dec 18 07:26:15 2017] RAX: 0000000000000000 RBX: ffff882a136b9540
>> RCX: 00000000000005dc
>> [Mon Dec 18 07:26:15 2017] RDX: ffffffff818bece0 RSI: 0000000000000000
>> RDI: ffff882f73c3cd00
>> [Mon Dec 18 07:26:15 2017] RBP: ffffc9000fe8bb40 R08: 00000000000000ff
>> R09: 0000000000000002
>> [Mon Dec 18 07:26:15 2017] R10: ffff885f741a0990 R11: ffff885f741a09a8
>> R12: 0000000000000001
>> [Mon Dec 18 07:26:15 2017] R13: 0000000000000006 R14: ffff882a136b9540
>> R15: ffff882f73c3cd00
>> [Mon Dec 18 07:26:15 2017] FS: 00007f86c239b700(0000)
>> GS:ffff882f7f800000(0000) knlGS:0000000000000000
>> [Mon Dec 18 07:26:15 2017] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [Mon Dec 18 07:26:15 2017] CR2: 00007f6b241d2000 CR3: 00000052c6274002
>> CR4: 00000000001606f0
>> [Mon Dec 18 07:26:15 2017] DR0: 0000000000000000 DR1: 0000000000000000
>> DR2: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] DR3: 0000000000000000 DR6: 00000000fffe0ff0
>> DR7: 0000000000000400
>> [Mon Dec 18 07:26:15 2017] Call Trace:
>> [Mon Dec 18 07:26:15 2017] ? __dev_queue_xmit+0x229/0x560
>> [Mon Dec 18 07:26:15 2017] ? esp_output_tail+0x24f/0x570
>> [Mon Dec 18 07:26:15 2017] ? xfrm_policy_lookup_bytype.constprop.50+0x539/0x710
>> [Mon Dec 18 07:26:15 2017] ? xfrm_lookup+0x289/0x760
>> [Mon Dec 18 07:26:15 2017] xfrm_lookup+0x289/0x760
>> [Mon Dec 18 07:26:15 2017] ? ip_route_output_key_hash+0x5c/0x80
>> [Mon Dec 18 07:26:15 2017] xfrm_lookup_route+0x16/0x60
>> [Mon Dec 18 07:26:15 2017] ip_queue_xmit+0x335/0x3a0
>> [Mon Dec 18 07:26:15 2017] ? kmem_cache_alloc_node_trace+0x137/0x580
>> [Mon Dec 18 07:26:15 2017] ? __kmalloc_reserve.isra.41+0x2e/0x80
>> [Mon Dec 18 07:26:15 2017] tcp_transmit_skb+0x4c1/0x900
>> [Mon Dec 18 07:26:15 2017] tcp_write_xmit+0x1c3/0xfa0
>> [Mon Dec 18 07:26:15 2017] ? _copy_from_iter_full+0x93/0x230
>> [Mon Dec 18 07:26:15 2017] __tcp_push_pending_frames+0x2d/0xd0
>> [Mon Dec 18 07:26:15 2017] tcp_sendmsg_locked+0x663/0xe30
>> [Mon Dec 18 07:26:15 2017] ? tcp_poll+0x27c/0x290
>> [Mon Dec 18 07:26:15 2017] tcp_sendmsg+0x27/0x40
>> [Mon Dec 18 07:26:15 2017] sock_write_iter+0x95/0x110
>> [Mon Dec 18 07:26:15 2017] __vfs_write+0xf8/0x160
>> [Mon Dec 18 07:26:15 2017] vfs_write+0xb0/0x190
>> [Mon Dec 18 07:26:15 2017] SyS_write+0x52/0xc0
>> [Mon Dec 18 07:26:15 2017] ? SyS_epoll_wait+0x9c/0xe0
>> [Mon Dec 18 07:26:15 2017] entry_SYSCALL_64_fastpath+0x13/0x94
>> [Mon Dec 18 07:26:15 2017] RIP: 0033:0x7f877661f1ad
>> [Mon Dec 18 07:26:15 2017] RSP: 002b:00007f86c239a730 EFLAGS: 00000293
>> ORIG_RAX: 0000000000000001
>> [Mon Dec 18 07:26:15 2017] RAX: ffffffffffffffda RBX: 00000000e8e42860
>> RCX: 00007f877661f1ad
>> [Mon Dec 18 07:26:15 2017] RDX: 0000000000000007 RSI: 00007f86bc440f50
>> RDI: 0000000000000ea9
>> [Mon Dec 18 07:26:15 2017] RBP: 000000002000b3ad R08: 0000000000000007
>> R09: 00000000e982ff48
>> [Mon Dec 18 07:26:15 2017] R10: 0000000000004f34 R11: 0000000000000293
>> R12: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] R13: 00000000fb287ba8 R14: 00000000c8ccca00
>> R15: 00007f86bc43f800
>> [Mon Dec 18 07:26:15 2017] Code: c7 c5 ed ff ff ff 4c 89 eb e9 d2 fb
>> ff ff e8 4e 26 00 00 e8 95 2b a3 ff 85 c0 74 0f 8d 48 01 f0 0f b1 0a
>> 0f 84 ba fe ff ff eb ed <0f> ff 44 8b a5 70 ff ff ff e9 b1 fe ff ff 48
>> 63 db 49 89 dd e9
>> [Mon Dec 18 07:26:15 2017] ---[ end trace 55978b2661bba1e7 ]---
>> [Mon Dec 18 07:26:15 2017] BUG: unable to handle kernel NULL pointer
>> dereference at 0000000000000018
>> [Mon Dec 18 07:26:15 2017] IP: xfrm_output_resume+0x1bd/0x350
>> [Mon Dec 18 07:26:15 2017] PGD 52c6372067 P4D 52c6372067 PUD 52f3453067 PMD 0
>> [Mon Dec 18 07:26:15 2017] Oops: 0000 [#1] SMP
>> [Mon Dec 18 07:26:15 2017] Modules linked in: smartpqi
>> [Mon Dec 18 07:26:15 2017] CPU: 0 PID: 10555 Comm: java Tainted: G
>> W 4.14.6 #1
>> [Mon Dec 18 07:26:15 2017] Hardware name: HPE ProLiant DL380
>> Gen10/ProLiant DL380 Gen10, BIOS U30 11/14/2017
>> [Mon Dec 18 07:26:15 2017] task: ffff8852b33aca40 task.stack: ffffc9000fe88000
>> [Mon Dec 18 07:26:15 2017] RIP: 0010:xfrm_output_resume+0x1bd/0x350
>> [Mon Dec 18 07:26:15 2017] RSP: 0018:ffffc9000fe8bc10 EFLAGS: 00010246
>> [Mon Dec 18 07:26:15 2017] RAX: 0000000000000000 RBX: 0000000000000000
>> RCX: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] RDX: 000000000000002f RSI: 0000000000000000
>> RDI: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] RBP: ffff882f7729c990 R08: 000000000000000c
>> R09: ffffc9000fe8ba18
>> [Mon Dec 18 07:26:15 2017] R10: 000000000000000c R11: 00000000000008b8
>> R12: ffffffff81cd6600
>> [Mon Dec 18 07:26:15 2017] R13: ffff882c6d90e000 R14: ffff882c6d90e03c
>> R15: 0000000000007180
>> [Mon Dec 18 07:26:15 2017] FS: 00007f86c239b700(0000)
>> GS:ffff882f7f800000(0000) knlGS:0000000000000000
>> [Mon Dec 18 07:26:15 2017] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [Mon Dec 18 07:26:15 2017] CR2: 0000000000000018 CR3: 00000052c6274002
>> CR4: 00000000001606f0
>> [Mon Dec 18 07:26:15 2017] DR0: 0000000000000000 DR1: 0000000000000000
>> DR2: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] DR3: 0000000000000000 DR6: 00000000fffe0ff0
>> DR7: 0000000000000400
>> [Mon Dec 18 07:26:15 2017] Call Trace:
>> [Mon Dec 18 07:26:15 2017] tcp_transmit_skb+0x4c1/0x900
>> [Mon Dec 18 07:26:15 2017] tcp_write_xmit+0x1c3/0xfa0
>> [Mon Dec 18 07:26:15 2017] ? _copy_from_iter_full+0x93/0x230
>> [Mon Dec 18 07:26:15 2017] __tcp_push_pending_frames+0x2d/0xd0
>> [Mon Dec 18 07:26:15 2017] tcp_sendmsg_locked+0x663/0xe30
>> [Mon Dec 18 07:26:15 2017] ? tcp_poll+0x27c/0x290
>> [Mon Dec 18 07:26:15 2017] tcp_sendmsg+0x27/0x40
>> [Mon Dec 18 07:26:15 2017] sock_write_iter+0x95/0x110
>> [Mon Dec 18 07:26:15 2017] __vfs_write+0xf8/0x160
>> [Mon Dec 18 07:26:15 2017] vfs_write+0xb0/0x190
>> [Mon Dec 18 07:26:15 2017] SyS_write+0x52/0xc0
>> [Mon Dec 18 07:26:15 2017] ? SyS_epoll_wait+0x9c/0xe0
>> [Mon Dec 18 07:26:15 2017] entry_SYSCALL_64_fastpath+0x13/0x94
>> [Mon Dec 18 07:26:15 2017] RIP: 0033:0x7f877661f1ad
>> [Mon Dec 18 07:26:15 2017] RSP: 002b:00007f86c239a730 EFLAGS: 00000293
>> ORIG_RAX: 0000000000000001
>> [Mon Dec 18 07:26:15 2017] RAX: ffffffffffffffda RBX: 00000000e8e42860
>> RCX: 00007f877661f1ad
>> [Mon Dec 18 07:26:15 2017] RDX: 0000000000000007 RSI: 00007f86bc440f50
>> RDI: 0000000000000ea9
>> [Mon Dec 18 07:26:15 2017] RBP: 000000002000b3ad R08: 0000000000000007
>> R09: 00000000e982ff48
>> [Mon Dec 18 07:26:15 2017] R10: 0000000000004f34 R11: 0000000000000293
>> R12: 0000000000000000
>> [Mon Dec 18 07:26:15 2017] R13: 00000000fb287ba8 R14: 00000000c8ccca00
>> R15: 00007f86bc43f800
>> [Mon Dec 18 07:26:15 2017] Code: f6 0f 8f ed fe ff ff 31 f6 85 d2 0f
>> 8f e3 fe ff ff e9 f1 fe ff ff 85 f6 89 f3 0f 85 12 ff ff ff 48 8b 7d
>> 58 48 89 f8 48 83 e0 fe <48> 8b 58 18 48 85 db 0f 84 e4 00 00 00 8b 83
>> 80 00 00 00 85 c0
>> [Mon Dec 18 07:26:15 2017] RIP: xfrm_output_resume+0x1bd/0x350 RSP:
>> ffffc9000fe8bc10
>> [Mon Dec 18 07:26:15 2017] CR2: 0000000000000018
>> [Mon Dec 18 07:26:15 2017] ---[ end trace 55978b2661bba1e8 ]---
>>
>>
>> Anyone got ideas what is going on? Java process 10555 is communicating
>> via those IPSec tunnels and it used to run for year+ on 3.14 kernel
>> and crashed within 2 days of moving to new server with 4.14.6.
>
> Looks like a race in the new xfrm percpu dst cache. The old flow cache
> ran the reslover routines with bottom halves disabled, the new percpu
> cache does not and I think this is missing.
>
> Can you please try this patch:
>
> diff --git a/net/xfrm/xfrm_policy.c b/net/xfrm/xfrm_policy.c
> index 6eb228a70131..b08c6c7991b5 100644
> --- a/net/xfrm/xfrm_policy.c
> +++ b/net/xfrm/xfrm_policy.c
> @@ -2048,8 +2048,11 @@ xfrm_bundle_lookup(struct net *net, const struct flowi *fl, u16 family, u8 dir,
> if (num_xfrms <= 0)
> goto make_dummy_bundle;
>
> + local_bh_disable();
> xdst = xfrm_resolve_and_create_bundle(pols, num_pols, fl, family,
> xflo->dst_orig);
> + local_bh_enable();
> +
> if (IS_ERR(xdst)) {
> err = PTR_ERR(xdst);
> if (err != -EAGAIN)
> @@ -2136,9 +2139,12 @@ struct dst_entry *xfrm_lookup(struct net *net, struct dst_entry *dst_orig,
> goto no_transform;
> }
>
> + local_bh_disable();
> xdst = xfrm_resolve_and_create_bundle(
> pols, num_pols, fl,
> family, dst_orig);
> + local_bh_enable();
> +
> if (IS_ERR(xdst)) {
> xfrm_pols_put(pols, num_pols);
> err = PTR_ERR(xdst);
Powered by blists - more mailing lists