* Kernel crash in free_pipe_info()
@ 2017-10-30 20:58 Cong Wang
2017-10-30 22:14 ` Linus Torvalds
0 siblings, 1 reply; 14+ messages in thread
From: Cong Wang @ 2017-10-30 20:58 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
Hi, Linus
We got more than a dozen of kernel crashes at free_pipe_info() on our
4.1 kernel, they are all very similar to this one (with slightly
different faulty addresses):
[433948.755473] BUG: unable to handle kernel paging request at 000000010000000d
[433948.762570] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
[433948.768493] PGD 0
[433948.770537] Oops: 0000 [#1] SMP
[433948.773768] Modules linked in: sch_htb cls_basic act_mirred
cls_u32 veth sch_ingress fuse cpufreq_ondemand intel_rapl iosf_mbi
x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt
iTCO_vendor_support dcdbas microcode sb_edac wmi edac_core i2c_i801
hed lpc_ich mfd_core ioatdma shpchp lp parport tcp_diag inet_diag
ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs
libcrc32c crc32c_intel igb ptp pps_core i2c_algo_bit dca i2c_core ipv6
[433948.813421] CPU: 10 PID: 50667 Comm: rsync Not tainted 4.1.41.el7.x86_64 #1
[433948.821498] Hardware name: Dell Inc. PowerEdge C6220/03C9JJ, BIOS
2.2.3 11/07/2013
[433948.829247] task: ffff880f47fde240 ti: ffff880d282d8000 task.ti:
ffff880d282d8000
[433948.836770] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>]
free_pipe_info+0x54/0x85
[433948.845088] RSP: 0018:ffff880d282dbd98 EFLAGS: 00010202
[433948.850473] RAX: 00000000fffffffd RBX: ffff8817e7692240 RCX:
00000000000002c5
[433948.857603] RDX: 00000000000002c6 RSI: ffff8817c30be540 RDI:
ffff8817e7692240
[433948.864881] RBP: ffff880d282dbda8 R08: 0000000000000000 R09:
0000000000000000
[433948.871988] R10: ffff880c474a0c60 R11: ffff8812c3c44310 R12:
0000000000000008
[433948.879224] R13: ffff88182d8a9100 R14: ffff880c47b981a0 R15:
ffff88182d8a9100
[433948.886514] FS: 0000000000000000(0000) GS:ffff88184ee80000(0000)
knlGS:0000000000000000
[433948.894678] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[433948.900609] CR2: 000000010000000d CR3: 0000000001a0b000 CR4:
00000000000406e0
[433948.907840] Stack:
[433948.909876] ffff88182d8a9100 ffff8817e7692240 ffff880d282dbdc8
ffffffff8117668e
[433948.917331] ffff8817e7692240 ffff8812c3c44300 ffff880d282dbdf8
ffffffff8117672a
[433948.924799] 0000000000000000 ffff8812c3c44300 0000000000000010
ffff88182d8a9100
[433948.932234] Call Trace:
[433948.934780] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
[433948.940320] [<ffffffff8117672a>] pipe_release+0x97/0xa1
[433948.945734] [<ffffffff811707ff>] __fput+0xf9/0x1b8
[433948.950747] [<ffffffff811708f6>] ____fput+0xe/0x10
[433948.955665] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
[433948.961121] [<ffffffff8106acb6>] do_exit+0x400/0x8ba
[433948.966224] [<ffffffff8116f057>] ? fdput_pos.isra.10+0x29/0x30
[433948.972306] [<ffffffff8106b1eb>] do_group_exit+0x44/0x98
[433948.977847] [<ffffffff8106b253>] SyS_exit_group+0x14/0x14
[433948.983423] [<ffffffff81527757>] system_call_fastpath+0x12/0x6a
[433948.989477] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73
22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74
06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6
e8 be
[433949.008413] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
[433949.014335] RSP <ffff880d282dbd98>
[433949.017850] CR2: 000000010000000d
[433949.021820] ---[ end trace 95f92776b6f34085 ]---
For this one, the IP maps to fs/pipe.c:651
642 void free_pipe_info(struct pipe_inode_info *pipe)
643 {
644 int i;
645
646 account_pipe_buffers(pipe, pipe->buffers, 0);
647 free_uid(pipe->user);
648 for (i = 0; i < pipe->buffers; i++) {
649 struct pipe_buffer *buf = pipe->bufs + i;
650 if (buf->ops)
651 buf->ops->release(pipe, buf);
652 }
653 if (pipe->tmp_page)
654 __free_page(pipe->tmp_page);
655 kfree(pipe->bufs);
656 kfree(pipe);
657 }
And the faulty instruction is:
All code
========
0: 8b bb 88 00 00 00 mov 0x88(%rbx),%edi
6: e8 73 a5 ef ff callq 0xffffffffffefa57e
b: 44 3b 63 48 cmp 0x48(%rbx),%r12d
f: 73 22 jae 0x33
11: 49 63 f4 movslq %r12d,%rsi
14: 48 6b f6 28 imul $0x28,%rsi,%rsi
18: 48 03 b3 80 00 00 00 add 0x80(%rbx),%rsi
1f: 48 8b 46 10 mov 0x10(%rsi),%rax
23: 48 85 c0 test %rax,%rax
26: 74 06 je 0x2e
28: 48 89 df mov %rbx,%rdi
2b:* ff 50 10 callq *0x10(%rax) <--
trapping instruction
2e: 41 ff c4 inc %r12d
31: eb d8 jmp 0xb
33: 48 8b 7b 68 mov 0x68(%rbx),%rdi
37: 48 85 ff test %rdi,%rdi
3a: 74 07 je 0x43
3c: 31 f6 xor %esi,%esi
It looks like pipe->bufs was already freed for some reason. The code
is pretty solid, I can't find out any bug, as there should be only one
thread could invoke free_pipe_info().
Kdump is not properly setup on this host, so unfortunately I can't
inspect further on struct pipe_inode_info in memory.
Although it is too early to blame your commit b0d8d2292160 ("vfs: fix
subtle use-after-free of pipe_inode_info"), it is probably related.
Please let me know if I could provide any other information.
BTW, there is a similar (if not same) bug report on a much newer kernel:
https://www.spinics.net/lists/kernel/msg2616441.html
Thanks!
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-30 20:58 Kernel crash in free_pipe_info() Cong Wang
@ 2017-10-30 22:14 ` Linus Torvalds
2017-10-30 22:26 ` Linus Torvalds
2017-10-31 1:28 ` Cong Wang
0 siblings, 2 replies; 14+ messages in thread
From: Linus Torvalds @ 2017-10-30 22:14 UTC (permalink / raw)
To: Cong Wang; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 1:58 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>
> We got more than a dozen of kernel crashes at free_pipe_info() on our
> 4.1 kernel, they are all very similar to this one (with slightly
> different faulty addresses):
Were it not for the pointer to the much more recent powerpc version at
https://www.spinics.net/lists/kernel/msg2616441.html
that you referenced, I'd be inclined to ignore this as much too old.
Al fixed a number of issues with splice() some time ago.
And honestly, splice() is pretty much the only thing that I can think
of that can trigger issues wrt the pipe_inode_info structure.
But as you say, we've had subtle races just due to the named pipes:
> Although it is too early to blame your commit b0d8d2292160 ("vfs: fix
> subtle use-after-free of pipe_inode_info"), it is probably related.
I do hate the games we play with the stupid pipe_inode_info. The way
we have locking in the inode, instead of in the pipe_inode_info
itself.
There are hysterical raisins for that, and due to names piped we have
to keep the reference to the pipe_inode_info in the inode, but it's
still very very annoying.
Al, do you see anything?
Cong, do you have any way to trigger these? Is there any pattern to
when they happen or what is going on when they do?
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-30 22:14 ` Linus Torvalds
@ 2017-10-30 22:26 ` Linus Torvalds
2017-10-31 1:19 ` Cong Wang
2017-10-31 1:28 ` Cong Wang
1 sibling, 1 reply; 14+ messages in thread
From: Linus Torvalds @ 2017-10-30 22:26 UTC (permalink / raw)
To: Cong Wang; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 3:14 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Mon, Oct 30, 2017 at 1:58 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>>
>> We got more than a dozen of kernel crashes at free_pipe_info() on our
>> 4.1 kernel, they are all very similar to this one (with slightly
>> different faulty addresses):
>
> Were it not for the pointer to the much more recent powerpc version at
>
> https://www.spinics.net/lists/kernel/msg2616441.html
>
> that you referenced, I'd be inclined to ignore this as much too old.
> Al fixed a number of issues with splice() some time ago.
Hmm. So I tried to google for this oops, and the only oops I find is
hat ppc one you reference.
Was that how you found it too?
The fact that google doesn't report any other oopses would seem to
indicate that this is not a widespread issue. Where are the "more than
a dozen" ones you refer to being reported? I'd like to see them all if
at all possible, to see if there's some pattern to them..
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-30 22:26 ` Linus Torvalds
@ 2017-10-31 1:19 ` Cong Wang
2017-10-31 2:08 ` Linus Torvalds
0 siblings, 1 reply; 14+ messages in thread
From: Cong Wang @ 2017-10-31 1:19 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
[-- Attachment #1: Type: text/plain, Size: 1611 bytes --]
On Mon, Oct 30, 2017 at 3:26 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Mon, Oct 30, 2017 at 3:14 PM, Linus Torvalds
> <torvalds@linux-foundation.org> wrote:
>> On Mon, Oct 30, 2017 at 1:58 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>>>
>>> We got more than a dozen of kernel crashes at free_pipe_info() on our
>>> 4.1 kernel, they are all very similar to this one (with slightly
>>> different faulty addresses):
>>
>> Were it not for the pointer to the much more recent powerpc version at
>>
>> https://www.spinics.net/lists/kernel/msg2616441.html
>>
>> that you referenced, I'd be inclined to ignore this as much too old.
>> Al fixed a number of issues with splice() some time ago.
>
> Hmm. So I tried to google for this oops, and the only oops I find is
> hat ppc one you reference.
>
> Was that how you found it too?
Yes.
>
> The fact that google doesn't report any other oopses would seem to
> indicate that this is not a widespread issue. Where are the "more than
> a dozen" ones you refer to being reported? I'd like to see them all if
> at all possible, to see if there's some pattern to them..
>
We have thousands of machines running 4.1, so even with a dozen
crashes it is still a very small percentage. :)
I am attaching these stack traces that I copy-n-paste from the ABRT
email reports.
There are two patterns I can observe:
1. The faulty addresses are all near 0000000100000000, with one exception
of null (which is the most recent one)
2. R12 register, which should map to the local vairable 'i', is always 0x8
at the time of crash.
Hope it helps.
Thanks!
[-- Attachment #2: free_pipe_info.txt --]
[-- Type: text/plain, Size: 34816 bytes --]
:[840243.314457] BUG: unable to handle kernel NULL pointer dereference at (null)
:[840243.322420] IP: [< (null)>] (null)
:[840243.327582] PGD 18782067 PUD 24d42067 PMD 0
:[840243.331989] Oops: 0010 [#1] SMP
:[840243.335346] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand x86_pkg_temp_thermal coretemp kvm_intel kvm microcode lp parport iTCO_wdt tcp_diag iTCO_vendor_support inet_diag sb_edac edac_core lpc_ich i2c_i801 i2c_core mfd_core ioatdma dca hed wmi shpchp ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs libcrc32c mlx4_en vxlan ip6_udp_tunnel udp_tunnel ptp pps_core crc32c_intel serio_raw mlx4_core isci libsas scsi_transport_sas ipv6
:[840243.379972] CPU: 5 PID: 9355 Comm: java Not tainted 4.1.41.el7.x86_64 #1
:[840243.387803] Hardware name: SYNNEX HYVE-ZEUS/X9DRD-iF, BIOS 3.0.4 12/06/2013
:[840243.394855] task: ffff880866ba0000 ti: ffff880360940000 task.ti: ffff880360940000
:[840243.402426] RIP: 0010:[<0000000000000000>] [< (null)>] (null)
:[840243.410005] RSP: 0018:ffff880360943e30 EFLAGS: 00010206
:[840243.415400] RAX: 00000000fffffffa RBX: ffff8804697c4f00 RCX: 000000000000001a
:[840243.422617] RDX: 000000000000001b RSI: ffff8807cdc1b940 RDI: ffff8804697c4f00
:[840243.429835] RBP: ffff880360943e48 R08: 0000000000000000 R09: 0000000000000000
:[840243.437059] R10: 000000000000b708 R11: ffff88049f34b010 R12: 0000000000000008
:[840243.444275] R13: ffff880866500aa0 R14: ffff8808689681a0 R15: ffff880866500aa0
:[840243.451492] FS: 00007f01c40ba700(0000) GS:ffff88046fca0000(0000) knlGS:0000000000000000
:[840243.459672] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[840243.465509] CR2: 0000000000000000 CR3: 0000000078b43000 CR4: 00000000001406e0
:[840243.472734] Stack:
:[840243.474841] ffffffff8117660f ffff880866500aa0 ffff8804697c4f00 ffff880360943e68
:[840243.482386] ffffffff8117668e ffff8804697c4f00 ffff88049f34b000 ffff880360943e98
:[840243.489933] ffffffff8117672a 0000000000000000 ffff88049f34b000 0000000000000010
:[840243.497479] Call Trace:
:[840243.500019] [<ffffffff8117660f>] ? free_pipe_info+0x57/0x85
:[840243.505768] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[840243.511254] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[840243.516659] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[840243.521628] [<ffffffff811708f6>] ____fput+0xe/0x10
:[840243.526601] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[840243.532089] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[840243.537842] [<ffffffff81527902>] int_signal+0x12/0x17
:[840243.543068] Code: Bad RIP value.
:[840243.546519] RIP [< (null)>] (null)
:[840243.551757] RSP <ffff880360943e30>
:[840243.555332] CR2: 0000000000000000
:[840243.559179] ---[ end trace b725063bc2e1920b ]---
:[319591.443093] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.448958] PGD 0
:[319591.450964] Oops: 0000 [#1] SMP
:[319591.454327] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand xfs libcrc32c intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support dcdbas microcode sb_edac lpc_ich ioatdma mfd_core shpchp i2c_i801 edac_core acpi_pad wmi hed lp parport tcp_diag inet_diag ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel crc32c_intel igb ptp pps_core i2c_algo_bit i2c_core dca ipv6
:[319591.494830] CPU: 4 PID: 1221 Comm: sshd Not tainted 4.1.41.el7.x86_64 #1
:[319591.502659] Hardware name: Dell Inc. PowerEdge C6220/03C9JJ, BIOS 2.2.3 11/07/2013
:[319591.510310] task: ffff8810498d1890 ti: ffff881049074000 task.ti: ffff881049074000
:[319591.517837] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.526241] RSP: 0018:ffff881049077e38 EFLAGS: 00010202
:[319591.531652] RAX: 00000000fffffffd RBX: ffff88006ec2b680 RCX: 00000000000002c0
:[319591.538820] RDX: 00000000000002c1 RSI: ffff880f12a08940 RDI: ffff88006ec2b680
:[319591.545993] RBP: ffff881049077e48 R08: 0000000000000000 R09: 0000000000000000
:[319591.553311] R10: 0000000000000000 R11: ffff880d9b5a8410 R12: 0000000000000008
:[319591.560469] R13: ffff8806b1d24c80 R14: ffff88085aa681a0 R15: ffff8806b1d24c80
:[319591.567660] FS: 00007f1a624338c0(0000) GS:ffff88085f680000(0000) knlGS:0000000000000000
:[319591.575953] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[319591.581801] CR2: 000000010000000d CR3: 00000008599b9000 CR4: 00000000000406e0
:[319591.588999] Stack:
:[319591.591054] ffff8806b1d24c80 ffff88006ec2b680 ffff881049077e68 ffffffff8117668e
:[319591.598444] ffff88006ec2b680 ffff880d9b5a8400 ffff881049077e98 ffffffff8117672a
:[319591.605960] 0000000000000000 ffff880d9b5a8400 0000000000000010 ffff8806b1d24c80
:[319591.613464] Call Trace:
:[319591.615987] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[319591.621503] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[319591.626857] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[319591.631872] [<ffffffff811708f6>] ____fput+0xe/0x10
:[319591.636728] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[319591.642165] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[319591.647975] [<ffffffff81527902>] int_signal+0x12/0x17
:[319591.653293] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[319591.672186] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.678047] RSP <ffff881049077e38>
:[319591.681541] CR2: 000000010000000d
:[319591.685696] ---[ end trace 5f879abbafe81e2e ]---
:[52816.774838] BUG: unable to handle kernel paging request at 0000000100000001
:[52816.781852] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[52816.787628] PGD 1055c12067 PUD 0
:[52816.791004] Oops: 0000 [#1] SMP
:[52816.794281] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand xfs libcrc32c x86_pkg_temp_thermal coretemp kvm_intel kvm lp iTCO_wdt parport iTCO_vendor_support tcp_diag inet_diag microcode sb_edac ioatdma edac_core i2c_i801 i2c_core lpc_ich mfd_core hed dca shpchp wmi ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel mlx4_en vxlan ip6_udp_tunnel udp_tunnel ptp pps_core crc32c_intel serio_raw mlx4_core isci libsas scsi_transport_sas ipv6
:[52816.838840] CPU: 12 PID: 2608 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[52816.847104] Hardware name: SYNNEX HYVE-ZEUS/X9DRD-iF, BIOS 3.0.4 12/06/2013
:[52816.854068] task: ffff881054ce49b0 ti: ffff881056bf8000 task.ti: ffff881056bf8000
:[52816.861551] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[52816.869749] RSP: 0018:ffff881056bfbe38 EFLAGS: 00010202
:[52816.875066] RAX: 00000000fffffff1 RBX: ffff88070b3c7740 RCX: 0000000000000264
:[52816.882202] RDX: 0000000000000265 RSI: ffff8810564b7d40 RDI: ffff88070b3c7740
:[52816.889332] RBP: ffff881056bfbe48 R08: 0000000000000000 R09: 0000000000000000
:[52816.896462] R10: 0000000002a47a68 R11: ffff88085a61b410 R12: 0000000000000008
:[52816.903601] R13: ffff881054849ba0 R14: ffff88085bb5c1a0 R15: ffff881054849ba0
:[52816.910740] FS: 00007ff97951d740(0000) GS:ffff88085fcc0000(0000) knlGS:0000000000000000
:[52816.918830] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[52816.924571] CR2: 0000000100000001 CR3: 0000001055c15000 CR4: 00000000001406e0
:[52816.931703] Stack:
:[52816.933723] ffff881054849ba0 ffff88070b3c7740 ffff881056bfbe68 ffffffff8117668e
:[52816.941182] ffff88070b3c7740 ffff88085a61b400 ffff881056bfbe98 ffffffff8117672a
:[52816.948639] 0000000000000000 ffff88085a61b400 0000000000000010 ffff881054849ba0
:[52816.956100] Call Trace:
:[52816.958554] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[52816.963952] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[52816.969267] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[52816.974151] [<ffffffff811708f6>] ____fput+0xe/0x10
:[52816.979036] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[52816.984438] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[52816.990101] [<ffffffff81527902>] int_signal+0x12/0x17
:[52816.995242] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[52817.015210] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[52817.021064] RSP <ffff881056bfbe38>
:[52817.024549] CR2: 0000000100000001
:[52817.028246] ---[ end trace c1158171fca5c9ce ]---
:[232742.868283] BUG: unable to handle kernel paging request at 0000000100000007
:[232742.875340] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[232742.881216] PGD 0
:[232742.883240] Oops: 0000 [#1] SMP
:[232742.886561] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm microcode dcdbas i2c_i801 iTCO_wdt iTCO_vendor_support sb_edac edac_core hed wmi acpi_pad lpc_ich mfd_core shpchp ioatdma lp parport tcp_diag inet_diag ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel igb ptp pps_core i2c_algo_bit dca i2c_core ipv6
:[232742.927066] CPU: 19 PID: 53748 Comm: mesos-slave Not tainted 4.1.41.el7.x86_64 #1
:[232742.935598] Hardware name: Dell Inc. PowerEdge C6220/03C9JJ, BIOS 2.2.3 11/07/2013
:[232742.943286] task: ffff8807f8dfe240 ti: ffff880036a8c000 task.ti: ffff880036a8c000
:[232742.950813] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[232742.959167] RSP: 0018:ffff880036a8fe38 EFLAGS: 00010202
:[232742.964475] RAX: 00000000fffffff7 RBX: ffff880f8c8db380 RCX: 00000000000002e5
:[232742.971705] RDX: 00000000000002e6 RSI: ffff880f8f4ce140 RDI: ffff880f8c8db380
:[232742.979033] RBP: ffff880036a8fe48 R08: 0000000000000000 R09: 0000000000000000
:[232742.986226] R10: 00007f219f004ca0 R11: ffff880fb6523f10 R12: 0000000000000008
:[232742.993433] R13: ffff881027afdb60 R14: ffff88085beacc20 R15: ffff881027afdb60
:[232743.000618] FS: 00007f2195838700(0000) GS:ffff88105eee0000(0000) knlGS:0000000000000000
:[232743.008793] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[232743.014626] CR2: 0000000100000007 CR3: 00000007ffe0c000 CR4: 00000000000406e0
:[232743.021879] Stack:
:[232743.023925] ffff881027afdb60 ffff880f8c8db380 ffff880036a8fe68 ffffffff8117668e
:[232743.031440] ffff880f8c8db380 ffff880fb6523f00 ffff880036a8fe98 ffffffff8117672a
:[232743.038830] 0000000000000000 ffff880fb6523f00 0000000000000010 ffff881027afdb60
:[232743.046357] Call Trace:
:[232743.048880] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[232743.054375] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[232743.059785] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[232743.064761] [<ffffffff811708f6>] ____fput+0xe/0x10
:[232743.069650] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[232743.075182] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[232743.080902] [<ffffffff81527902>] int_signal+0x12/0x17
:[232743.086072] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[232743.105237] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[232743.111122] RSP <ffff880036a8fe38>
:[232743.114764] CR2: 0000000100000007
:[232743.118809] ---[ end trace 1f8c48ab7dd43c58 ]---
:[519559.707216] BUG: unable to handle kernel paging request at 0000000100000004
:[519559.707476] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[519559.707686] PGD 5c1b4c067 PUD 0
:[519559.707810] Oops: 0000 [#1] SMP
:[519559.707932] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse coretemp kvm i2c_i801 i7core_edac edac_core lp parport iTCO_wdt hed iTCO_vendor_support tcp_diag inet_diag lpc_ich ioatdma dcdbas ipmi_si ipmi_devintf shpchp ipmi_msghandler microcode mfd_core dell_rbu sch_fq_codel xfs libcrc32c crc32c_intel igb ptp pps_core i2c_algo_bit dca i2c_core ipv6
:[519559.709237] CPU: 12 PID: 11761 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[519559.709514] Hardware name: Dell C6100 /0D61XP, BIOS 1.66 12/23/2011
:[519559.709774] task: ffff8810f0a2b120 ti: ffff8810f5b6c000 task.ti: ffff8810f5b6c000
:[519559.710028] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[519559.710304] RSP: 0018:ffff8810f5b6fe38 EFLAGS: 00010202
:[519559.710480] RAX: 00000000fffffff4 RBX: ffff88108852a240 RCX: 000000000000023e
:[519559.710713] RDX: 000000000000023f RSI: ffff880fa3a66d40 RDI: ffff88108852a240
:[519559.710951] RBP: ffff8810f5b6fe48 R08: 0000000000000000 R09: 0000000000000000
:[519559.711191] R10: 000000000000006a R11: ffff8805332a6010 R12: 0000000000000008
:[519559.711430] R13: ffff8811f3897960 R14: ffff88091571cc20 R15: ffff8811f3897960
:[519559.711666] FS: 00007f6c72ffd700(0000) GS:ffff88123fc80000(0000) knlGS:0000000000000000
:[519559.711929] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[519559.712125] CR2: 0000000100000004 CR3: 0000000532f9a000 CR4: 00000000000006e0
:[519559.712360] Stack:
:[519559.712435] ffff8811f3897960 ffff88108852a240 ffff8810f5b6fe68 ffffffff8117668e
:[519559.712700] ffff88108852a240 ffff8805332a6000 ffff8810f5b6fe98 ffffffff8117672a
:[519559.712969] 0000000000000000 ffff8805332a6000 0000000000000010 ffff8811f3897960
:[519559.713247] Call Trace:
:[519559.713341] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[519559.713529] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[519559.713708] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[519559.713874] [<ffffffff811708f6>] ____fput+0xe/0x10
:[519559.714040] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[519559.714227] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[519559.714437] [<ffffffff81527902>] int_signal+0x12/0x17
:[519559.714611] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[519559.715644] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[519559.715855] RSP <ffff8810f5b6fe38>
:[519559.715977] CR2: 0000000100000004
:[519559.716509] ---[ end trace 38d88592bbbeb5f8 ]---
:[551268.106787] BUG: unable to handle kernel paging request at 000000010000000a
:[551268.107036] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[551268.107240] PGD 91309b067 PUD 0
:[551268.107364] Oops: 0000 [#1] SMP
:[551268.107489] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse coretemp i7core_edac kvm iTCO_wdt iTCO_vendor_support lpc_ich ioatdma i2c_i801 hed edac_core mfd_core microcode dcdbas shpchp lp parport tcp_diag inet_diag ipmi_si ipmi_devintf ipmi_msghandler dell_rbu sch_fq_codel xfs libcrc32c crc32c_intel igb ptp pps_core i2c_algo_bit dca i2c_core ipv6
:[551268.108806] CPU: 4 PID: 13860 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[551268.109077] Hardware name: Dell C6100 /0D61XP, BIOS 1.66 12/23/2011
:[551268.109331] task: ffff88120f2ab120 ti: ffff8811f6290000 task.ti: ffff8811f6290000
:[551268.109578] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[551268.109854] RSP: 0018:ffff8811f6293e38 EFLAGS: 00010206
:[551268.110031] RAX: 00000000fffffffa RBX: ffff8811d880af00 RCX: 0000000000000211
:[551268.110266] RDX: 0000000000000212 RSI: ffff880a67882540 RDI: ffff8811d880af00
:[551268.110501] RBP: ffff8811f6293e48 R08: 0000000000000000 R09: 0000000000000000
:[551268.110736] R10: 0000000002192080 R11: ffff88117ae9c810 R12: 0000000000000008
:[551268.110971] R13: ffff8808fb6430e0 R14: ffff881211274c20 R15: ffff8808fb6430e0
:[551268.111206] FS: 00007f6394615700(0000) GS:ffff88123fc00000(0000) knlGS:0000000000000000
:[551268.111472] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[551268.111663] CR2: 000000010000000a CR3: 00000008fe344000 CR4: 00000000000006e0
:[551268.111898] Stack:
:[551268.111971] ffff8808fb6430e0 ffff8811d880af00 ffff8811f6293e68 ffffffff8117668e
:[551268.112237] ffff8811d880af00 ffff88117ae9c800 ffff8811f6293e98 ffffffff8117672a
:[551268.112504] 0000000000000000 ffff88117ae9c800 0000000000000010 ffff8808fb6430e0
:[551268.112771] Call Trace:
:[551268.112861] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[551268.113042] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[551268.113223] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[551268.113391] [<ffffffff811708f6>] ____fput+0xe/0x10
:[551268.113559] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[551268.113741] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[551268.113931] [<ffffffff81527902>] int_signal+0x12/0x17
:[551268.114103] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[551268.115086] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[551268.115287] RSP <ffff8811f6293e38>
:[551268.115408] CR2: 000000010000000a
:[551268.115934] ---[ end trace 924ce3279cfe8f43 ]---
:[542609.029919] BUG: unable to handle kernel paging request at 000000010000000d
:[542609.036999] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[542609.042849] PGD 200ada1067 PUD 0
:[542609.046281] Oops: 0000 [#1] SMP
:[542609.049628] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support microcode sb_edac edac_core lpc_ich mfd_core i2c_i801 i2c_core ioatdma shpchp wmi hed lp parport tcp_diag inet_diag acpi_pad ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel ixgbe mdio ptp pps_core dca ipv6
:[542609.089748] CPU: 25 PID: 19536 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[542609.098168] Hardware name: SYNNEX F2HY-M/X10DRD-LTP-TW008, BIOS 1.0a.C8 12/09/2015
:[542609.105812] task: ffff88200f6f8000 ti: ffff882009cc0000 task.ti: ffff882009cc0000
:[542609.113369] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[542609.121638] RSP: 0018:ffff882009cc3e38 EFLAGS: 00010202
:[542609.127029] RAX: 00000000fffffffd RBX: ffff8805a688a600 RCX: 0000000000000331
:[542609.134239] RDX: 0000000000000332 RSI: ffff88200f74e940 RDI: ffff8805a688a600
:[542609.141450] RBP: ffff882009cc3e48 R08: 0000000000000000 R09: 0000000000000000
:[542609.148660] R10: 00000000027a8e80 R11: ffff881037c53410 R12: 0000000000000008
:[542609.155872] R13: ffff880d8def7b80 R14: ffff881037ca81a0 R15: ffff880d8def7b80
:[542609.163082] FS: 00007f902ef32700(0000) GS:ffff88203f360000(0000) knlGS:0000000000000000
:[542609.171246] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[542609.177071] CR2: 000000010000000d CR3: 000000202f214000 CR4: 00000000001406e0
:[542609.184281] Stack:
:[542609.186378] ffff880d8def7b80 ffff8805a688a600 ffff882009cc3e68 ffffffff8117668e
:[542609.193919] ffff8805a688a600 ffff881037c53400 ffff882009cc3e98 ffffffff8117672a
:[542609.201456] 0000000000000000 ffff881037c53400 0000000000000010 ffff880d8def7b80
:[542609.209006] Call Trace:
:[542609.211542] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[542609.217023] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[542609.222415] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[542609.227372] [<ffffffff811708f6>] ____fput+0xe/0x10
:[542609.232335] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[542609.237819] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[542609.243566] [<ffffffff81527902>] int_signal+0x12/0x17
:[542609.248787] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[542609.268831] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[542609.274761] RSP <ffff882009cc3e38>
:[542609.278342] CR2: 000000010000000d
:[542609.282367] ---[ end trace f2a3d19f1219472b ]---
:[319591.436009] BUG: unable to handle kernel paging request at 000000010000000d
:[319591.443093] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.448958] PGD 0
:[319591.450964] Oops: 0000 [#1] SMP
:[319591.454327] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand xfs libcrc32c intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support dcdbas microcode sb_edac lpc_ich ioatdma mfd_core shpchp i2c_i801 edac_core acpi_pad wmi hed lp parport tcp_diag inet_diag ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel crc32c_intel igb ptp pps_core i2c_algo_bit i2c_core dca ipv6
:[319591.494830] CPU: 4 PID: 1221 Comm: sshd Not tainted 4.1.41.el7.x86_64 #1
:[319591.502659] Hardware name: Dell Inc. PowerEdge C6220/03C9JJ, BIOS 2.2.3 11/07/2013
:[319591.510310] task: ffff8810498d1890 ti: ffff881049074000 task.ti: ffff881049074000
:[319591.517837] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.526241] RSP: 0018:ffff881049077e38 EFLAGS: 00010202
:[319591.531652] RAX: 00000000fffffffd RBX: ffff88006ec2b680 RCX: 00000000000002c0
:[319591.538820] RDX: 00000000000002c1 RSI: ffff880f12a08940 RDI: ffff88006ec2b680
:[319591.545993] RBP: ffff881049077e48 R08: 0000000000000000 R09: 0000000000000000
:[319591.553311] R10: 0000000000000000 R11: ffff880d9b5a8410 R12: 0000000000000008
:[319591.560469] R13: ffff8806b1d24c80 R14: ffff88085aa681a0 R15: ffff8806b1d24c80
:[319591.567660] FS: 00007f1a624338c0(0000) GS:ffff88085f680000(0000) knlGS:0000000000000000
:[319591.575953] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[319591.581801] CR2: 000000010000000d CR3: 00000008599b9000 CR4: 00000000000406e0
:[319591.588999] Stack:
:[319591.591054] ffff8806b1d24c80 ffff88006ec2b680 ffff881049077e68 ffffffff8117668e
:[319591.598444] ffff88006ec2b680 ffff880d9b5a8400 ffff881049077e98 ffffffff8117672a
:[319591.605960] 0000000000000000 ffff880d9b5a8400 0000000000000010 ffff8806b1d24c80
:[319591.613464] Call Trace:
:[319591.615987] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[319591.621503] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[319591.626857] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[319591.631872] [<ffffffff811708f6>] ____fput+0xe/0x10
:[319591.636728] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[319591.642165] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[319591.647975] [<ffffffff81527902>] int_signal+0x12/0x17
:[319591.653293] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[319591.672186] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[319591.678047] RSP <ffff881049077e38>
:[319591.681541] CR2: 000000010000000d
:[319591.685696] ---[ end trace 5f879abbafe81e2e ]---
:[251630.918372] BUG: unable to handle kernel paging request at 000000010000000a
:[251630.925501] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[251630.931184] PGD 103e170067 PUD 0
:[251630.934547] Oops: 0000 [#1] SMP
:[251630.937905] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand xfs libcrc32c intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt microcode iTCO_vendor_support dcdbas sb_edac wmi hed edac_core i2c_i801 ioatdma lpc_ich acpi_pad shpchp mfd_core lp parport tcp_diag inet_diag ipmi_si ipmi_devintf sch_fq_codel ipmi_msghandler acpi_cpufreq crc32c_intel igb ptp pps_core i2c_algo_bit i2c_core dca ipv6
:[251630.978334] CPU: 10 PID: 10737 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[251630.986888] Hardware name: Dell Inc. PowerEdge C6220/03C9JJ, BIOS 2.2.3 11/07/2013
:[251630.994461] task: ffff880be9deb120 ti: ffff880a388b4000 task.ti: ffff880a388b4000
:[251631.002040] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[251631.010250] RSP: 0018:ffff880a388b7e38 EFLAGS: 00010206
:[251631.015652] RAX: 00000000fffffffa RBX: ffff880b8c167800 RCX: 0000000000000284
:[251631.022882] RDX: 0000000000000285 RSI: ffff88101ae19140 RDI: ffff880b8c167800
:[251631.030043] RBP: ffff880a388b7e48 R08: 0000000000000000 R09: 0000000000000000
:[251631.037287] R10: 00000000017d0610 R11: ffff880ef7dcfa10 R12: 0000000000000008
:[251631.044540] R13: ffff8807bf1bd0c0 R14: ffff88085beacc20 R15: ffff8807bf1bd0c0
:[251631.051841] FS: 00007f7258bd9700(0000) GS:ffff88105ee80000(0000) knlGS:0000000000000000
:[251631.060060] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[251631.065997] CR2: 000000010000000a CR3: 0000001048a1d000 CR4: 00000000000406e0
:[251631.073258] Stack:
:[251631.075285] ffff8807bf1bd0c0 ffff880b8c167800 ffff880a388b7e68 ffffffff8117668e
:[251631.082762] ffff880b8c167800 ffff880ef7dcfa00 ffff880a388b7e98 ffffffff8117672a
:[251631.090410] 0000000000000000 ffff880ef7dcfa00 0000000000000010 ffff8807bf1bd0c0
:[251631.097896] Call Trace:
:[251631.100412] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[251631.105815] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[251631.111228] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[251631.116127] [<ffffffff811708f6>] ____fput+0xe/0x10
:[251631.121235] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[251631.126641] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[251631.132382] [<ffffffff81527902>] int_signal+0x12/0x17
:[251631.137614] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[251631.156558] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[251631.162432] RSP <ffff880a388b7e38>
:[251631.165980] CR2: 000000010000000a
:[251631.170187] ---[ end trace b83bbad5e99dfe42 ]---
:[305135.798506] BUG: unable to handle kernel paging request at 00000000fffffff8
:[305135.798753] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[305135.798954] PGD 1206675067 PUD 0
:[305135.799081] Oops: 0000 [#1] SMP
:[305135.799203] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse coretemp kvm lp parport iTCO_wdt i2c_i801 iTCO_vendor_support microcode ioatdma i7core_edac edac_core lpc_ich mfd_core shpchp tcp_diag inet_diag dcdbas hed ipmi_si ipmi_devintf ipmi_msghandler dell_rbu sch_fq_codel xfs libcrc32c crc32c_intel igb ptp pps_core i2c_algo_bit dca i2c_core ipv6
:[305135.800516] CPU: 2 PID: 5685 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[305135.800784] Hardware name: Dell Inc. C6100 /0D61XP, BIOS 1.69 06/22/2012
:[305135.801035] task: ffff8808f4801890 ti: ffff8812094b4000 task.ti: ffff8812094b4000
:[305135.801280] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[305135.801555] RSP: 0018:ffff8812094b7e38 EFLAGS: 00010206
:[305135.801732] RAX: 00000000ffffffe8 RBX: ffff8811d20a9380 RCX: 000000000000021b
:[305135.801966] RDX: 000000000000021c RSI: ffff88120f144d40 RDI: ffff8811d20a9380
:[305135.802199] RBP: ffff8812094b7e48 R08: 0000000000000000 R09: 0000000000000000
:[305135.802433] R10: 0000000000000000 R11: ffff881206653910 R12: 0000000000000008
:[305135.802668] R13: ffff880d1dba8440 R14: ffff88091571cc20 R15: ffff880d1dba8440
:[305135.802902] FS: 00007fccb1f73700(0000) GS:ffff88091bc40000(0000) knlGS:0000000000000000
:[305135.803167] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[305135.803357] CR2: 00000000fffffff8 CR3: 000000120ff7d000 CR4: 00000000000006e0
:[305135.803591] Stack:
:[305135.803664] ffff880d1dba8440 ffff8811d20a9380 ffff8812094b7e68 ffffffff8117668e
:[305135.803929] ffff8811d20a9380 ffff881206653900 ffff8812094b7e98 ffffffff8117672a
:[305135.804194] 0000000000000000 ffff881206653900 0000000000000010 ffff880d1dba8440
:[305135.804459] Call Trace:
:[305135.804549] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[305135.804730] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[305135.804907] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[305135.805070] [<ffffffff811708f6>] ____fput+0xe/0x10
:[305135.805236] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[305135.805417] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[305135.805606] [<ffffffff81527902>] int_signal+0x12/0x17
:[305135.805777] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[305135.806759] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[305135.806959] RSP <ffff8812094b7e38>
:[305135.807078] CR2: 00000000fffffff8
:[305135.807692] ---[ end trace 4dd3a06ef6834d64 ]---
:[239058.390411] BUG: unable to handle kernel paging request at 0000000100000001
:[239058.397490] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[239058.403343] PGD 1036c62067 PUD 0
:[239058.406777] Oops: 0000 [#1] SMP
:[239058.410127] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand intel_rapl iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support microcode sb_edac i2c_i801 lpc_ich edac_core mfd_core i2c_core shpchp wmi hed lp parport tcp_diag inet_diag acpi_pad ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs libcrc32c ixgbe mdio crc32c_intel ptp pps_core dca ipv6
:[239058.449541] CPU: 51 PID: 52058 Comm: python2.7 Tainted: G W 4.1.41.el7.x86_64 #1
:[239058.459186] Hardware name: SYNNEX F3HY-X/X10DRD-LTP-B-TW008, BIOS 2.0 10/14/2016
:[239058.466670] task: ffff88184476e240 ti: ffff88049a844000 task.ti: ffff88049a844000
:[239058.474233] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[239058.482515] RSP: 0018:ffff88049a847e38 EFLAGS: 00010202
:[239058.487910] RAX: 00000000fffffff1 RBX: ffff881016cff140 RCX: 00000000000003ab
:[239058.495127] RDX: 00000000000003ac RSI: ffff882022b83940 RDI: ffff881016cff140
:[239058.502343] RBP: ffff88049a847e48 R08: 0000000000000000 R09: 0000000000000000
:[239058.509558] R10: 000000000187d500 R11: ffff881013ba7610 R12: 0000000000000008
:[239058.516774] R13: ffff880e8bc6d500 R14: ffff88202f9941a0 R15: ffff880e8bc6d500
:[239058.524001] FS: 00007f6593518700(0000) GS:ffff88203f460000(0000) knlGS:0000000000000000
:[239058.532169] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[239058.537997] CR2: 0000000100000001 CR3: 00000010321dd000 CR4: 00000000003406e0
:[239058.545217] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
:[239058.552439] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
:[239058.559657] Stack:
:[239058.561756] ffff880e8bc6d500 ffff881016cff140 ffff88049a847e68 ffffffff8117668e
:[239058.569302] ffff881016cff140 ffff881013ba7600 ffff88049a847e98 ffffffff8117672a
:[239058.576845] 0000000000000000 ffff881013ba7600 0000000000000010 ffff880e8bc6d500
:[239058.584395] Call Trace:
:[239058.586944] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[239058.592426] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[239058.597820] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[239058.602782] [<ffffffff811708f6>] ____fput+0xe/0x10
:[239058.607746] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[239058.613233] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[239058.618978] [<ffffffff81527902>] int_signal+0x12/0x17
:[239058.624205] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[239058.644256] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[239058.650199] RSP <ffff88049a847e38>
:[239058.653771] CR2: 0000000100000001
:[239058.657655] ---[ end trace 6c59e5f8f35e4e1c ]---
:[187988.817094] BUG: unable to handle kernel paging request at 0000000100000007
:[187988.824189] IP: [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[187988.830055] PGD 85a6a5067 PUD 0
:[187988.833410] Oops: 0000 [#1] SMP
:[187988.836766] Modules linked in: sch_htb cls_basic act_mirred cls_u32 veth sch_ingress fuse cpufreq_ondemand x86_pkg_temp_thermal coretemp kvm_intel kvm lp parport tcp_diag inet_diag iTCO_wdt iTCO_vendor_support microcode sb_edac edac_core i2c_i801 lpc_ich mfd_core hed wmi shpchp i2c_core ioatdma dca ipmi_si ipmi_devintf ipmi_msghandler acpi_cpufreq sch_fq_codel xfs libcrc32c mlx4_en vxlan ip6_udp_tunnel udp_tunnel ptp pps_core crc32c_intel serio_raw mlx4_core isci libsas scsi_transport_sas ipv6
:[187988.881411] CPU: 8 PID: 16016 Comm: python2.7 Not tainted 4.1.41.el7.x86_64 #1
:[187988.889762] Hardware name: SYNNEX HYVE-ZEUS/X9DRD-iF, BIOS 3.0.4 12/06/2013
:[187988.896812] task: ffff88085a110000 ti: ffff88085ac74000 task.ti: ffff88085ac74000
:[187988.904384] RIP: 0010:[<ffffffff8117660c>] [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[187988.912668] RSP: 0018:ffff88085ac77e38 EFLAGS: 00010202
:[187988.918071] RAX: 00000000fffffff7 RBX: ffff8802e3802540 RCX: 0000000000000258
:[187988.925288] RDX: 0000000000000259 RSI: ffff88085b09ad40 RDI: ffff8802e3802540
:[187988.932514] RBP: ffff88085ac77e48 R08: 0000000000000000 R09: 0000000000000000
:[187988.939737] R10: 0000000002c9b5c0 R11: ffff880443e34e10 R12: 0000000000000008
:[187988.946955] R13: ffff880513271760 R14: ffff88085ba681a0 R15: ffff880513271760
:[187988.954179] FS: 00007f0460256740(0000) GS:ffff88107fc40000(0000) knlGS:0000000000000000
:[187988.962359] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:[187988.968196] CR2: 0000000100000007 CR3: 0000000812bfd000 CR4: 00000000001406e0
:[187988.975419] Stack:
:[187988.977520] ffff880513271760 ffff8802e3802540 ffff88085ac77e68 ffffffff8117668e
:[187988.985074] ffff8802e3802540 ffff880443e34e00 ffff88085ac77e98 ffffffff8117672a
:[187988.992619] 0000000000000000 ffff880443e34e00 0000000000000010 ffff880513271760
:[187989.000166] Call Trace:
:[187989.002716] [<ffffffff8117668e>] put_pipe_info+0x51/0x56
:[187989.008208] [<ffffffff8117672a>] pipe_release+0x97/0xa1
:[187989.013612] [<ffffffff811707ff>] __fput+0xf9/0x1b8
:[187989.018582] [<ffffffff811708f6>] ____fput+0xe/0x10
:[187989.023557] [<ffffffff8107f118>] task_work_run+0x8a/0xa1
:[187989.029042] [<ffffffff81002780>] do_notify_resume+0x56/0x65
:[187989.034796] [<ffffffff81527902>] int_signal+0x12/0x17
:[187989.040021] Code: 8b bb 88 00 00 00 e8 73 a5 ef ff 44 3b 63 48 73 22 49 63 f4 48 6b f6 28 48 03 b3 80 00 00 00 48 8b 46 10 48 85 c0 74 06 48 89 df <ff> 50 10 41 ff c4 eb d8 48 8b 7b 68 48 85 ff 74 07 31 f6 e8 be
:[187989.060099] RIP [<ffffffff8117660c>] free_pipe_info+0x54/0x85
:[187989.066042] RSP <ffff88085ac77e38>
:[187989.069624] CR2: 0000000100000007
:[187989.073570] ---[ end trace 2adab1b0d0c8bd8a ]---
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-30 22:14 ` Linus Torvalds
2017-10-30 22:26 ` Linus Torvalds
@ 2017-10-31 1:28 ` Cong Wang
1 sibling, 0 replies; 14+ messages in thread
From: Cong Wang @ 2017-10-31 1:28 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 3:14 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Mon, Oct 30, 2017 at 1:58 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>>
>> We got more than a dozen of kernel crashes at free_pipe_info() on our
>> 4.1 kernel, they are all very similar to this one (with slightly
>> different faulty addresses):
>
> Were it not for the pointer to the much more recent powerpc version at
>
> https://www.spinics.net/lists/kernel/msg2616441.html
>
> that you referenced, I'd be inclined to ignore this as much too old.
> Al fixed a number of issues with splice() some time ago.
>
> And honestly, splice() is pretty much the only thing that I can think
> of that can trigger issues wrt the pipe_inode_info structure.
>
> But as you say, we've had subtle races just due to the named pipes:
It is unlikely that we use splice() or named pipes, I highly suspect it
is caused by the pipe(), although stack traces can't tell.
>
>> Although it is too early to blame your commit b0d8d2292160 ("vfs: fix
>> subtle use-after-free of pipe_inode_info"), it is probably related.
>
> I do hate the games we play with the stupid pipe_inode_info. The way
> we have locking in the inode, instead of in the pipe_inode_info
> itself.
>
> There are hysterical raisins for that, and due to names piped we have
> to keep the reference to the pipe_inode_info in the inode, but it's
> still very very annoying.
>
> Al, do you see anything?
>
> Cong, do you have any way to trigger these? Is there any pattern to
> when they happen or what is going on when they do?
>
I have no idea how this was triggered, all of the stack traces are reported
by ABRT service on each host.
Note, since kdump is not properly config'ed, there could be even more
machines crashed silently in a corner without even an ABRT report.
I will try to gather more information.
Thanks!
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 1:19 ` Cong Wang
@ 2017-10-31 2:08 ` Linus Torvalds
2017-10-31 3:06 ` Linus Torvalds
` (2 more replies)
0 siblings, 3 replies; 14+ messages in thread
From: Linus Torvalds @ 2017-10-31 2:08 UTC (permalink / raw)
To: Cong Wang; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 6:19 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>
> 1. The faulty addresses are all near 0000000100000000, with one exception
> of null (which is the most recent one)
Well, they're at 8(%rax), except for that last case.
And in every case (_including_ that last case), %rax has a very
interesting pattern.. That's the (bad) buf->ops pointer that was
loaded from the somehow corrupted "buf".
The values in all cases are
00000000fffffffa
00000000fffffffd
00000000fffffff1
00000000fffffff7
00000000fffffff4
00000000fffffffa
00000000fffffffd
00000000fffffffd
00000000fffffffa
00000000ffffffe8
00000000fffffff1
00000000fffffff7
which kind of looks like a 32-bit error value. So we have (n, val, (errno)):
1 -24 (EMFILE)
2 -15 (ENOTBLK)
1 -12 (ENOMEM)
2 -9 (EBADF)
3 -6 (ENXIO)
3 -3 (ESRCH)
none of which makes any sense to me, but it's an interesting pattern
nonetheless.
> 2. R12 register, which should map to the local vairable 'i', is always 0x8
> at the time of crash.
So _if_ this is some kind of use-after-free thing, and the allocation
got re-used for something else, that might just be related to whatever
ends up being the offset that is filled in with the (int) error
number.
Except the offset is that %r12*0x28+0x10, so we're talking a byte
offset of 330 bytes into the allocation, and apparently the eight
previous (0-7) iterations were fine.
Which is really odd.
I'm not seeing anything that makes sense. I'll have to think about this.
I'm assuming you don't have slub debugging enabled, and no way to
enable it and try to catch this?
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 2:08 ` Linus Torvalds
@ 2017-10-31 3:06 ` Linus Torvalds
2017-10-31 5:00 ` Al Viro
2017-10-31 4:44 ` Al Viro
2017-11-01 3:19 ` Cong Wang
2 siblings, 1 reply; 14+ messages in thread
From: Linus Torvalds @ 2017-10-31 3:06 UTC (permalink / raw)
To: Cong Wang; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 7:08 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
>
> I'm not seeing anything that makes sense. I'll have to think about this.
Al, would you mind taking a look at the error handling in create_pipe_files().
In particular, look here:
- we start out allocating the inode with "get_pipe_inode().
That sets up a inode->i_pipe, with pipe->files initialized to 2.
Fine. We're going to have two file descriptors.
- we then create the dummy path:
path.dentry = d_alloc_pseudo(pipe_mnt->mnt_sb, &empty_name);
fine fine. Again, this looks all good for the success cases.
But the *error* cases are a bit dodgy, aren't they?
We have three different error cases:
- we couldn't even allocate a dentry. We do
free_pipe_info(inode->i_pipe);
iput(inode);
- we couldn't allocate any file at all:
free_pipe_info(inode->i_pipe);
path_put(&path);
- we allocated the first file, but not the second:
put_filp(f);
free_pipe_info(inode->i_pipe);
path_put(&path);
and it worries me a bit that in all those error cases, we end up doing
that "free_pipe_info()", but we basically do this half-arsed job of
freeing things.
For example, we use "put_filp()" to free the file pointer, not "fput()".
We do that "free_pipe_info(inode->i_pipe);", but we never actually
clear inode->i_pipe, so now we have an inode that looks like a pipe
inode, and has a stale pointer to a pipe_inode_info.
It all looks technically correct. It's fine to use put_filp(), because
the file pointer has never really been used. And the inode should
never get re-used anyway without going through the whole reinit in
inode_init_always().
So I don't see anything *wrong*, but I see a lot that is just unusual,
and seems to depend on half-initialized state being fine. Can you look
at this?
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 2:08 ` Linus Torvalds
2017-10-31 3:06 ` Linus Torvalds
@ 2017-10-31 4:44 ` Al Viro
2017-10-31 19:00 ` Linus Torvalds
2017-11-01 3:19 ` Cong Wang
2 siblings, 1 reply; 14+ messages in thread
From: Al Viro @ 2017-10-31 4:44 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Cong Wang, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 07:08:46PM -0700, Linus Torvalds wrote:
> On Mon, Oct 30, 2017 at 6:19 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
> >
> > 1. The faulty addresses are all near 0000000100000000, with one exception
> > of null (which is the most recent one)
>
> Well, they're at 8(%rax), except for that last case.
0x10(%rax)?
> And in every case (_including_ that last case), %rax has a very
> interesting pattern.. That's the (bad) buf->ops pointer that was
> loaded from the somehow corrupted "buf".
> So _if_ this is some kind of use-after-free thing, and the allocation
> got re-used for something else, that might just be related to whatever
> ends up being the offset that is filled in with the (int) error
> number.
>
> Except the offset is that %r12*0x28+0x10, so we're talking a byte
> offset of 330 bytes into the allocation, and apparently the eight
> previous (0-7) iterations were fine.
>
> Which is really odd.
I wonder what pipe->buffers is equal to here...
> I'm not seeing anything that makes sense. I'll have to think about this.
>
> I'm assuming you don't have slub debugging enabled, and no way to
> enable it and try to catch this?
FWIW, I would try to slap
if (buf->ops && (unsigned long)buf->ops <= 0xffffffff)
dump the living hell out of that thing
and see what it catches...
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 3:06 ` Linus Torvalds
@ 2017-10-31 5:00 ` Al Viro
0 siblings, 0 replies; 14+ messages in thread
From: Al Viro @ 2017-10-31 5:00 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Cong Wang, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 08:06:23PM -0700, Linus Torvalds wrote:
> We do that "free_pipe_info(inode->i_pipe);", but we never actually
> clear inode->i_pipe, so now we have an inode that looks like a pipe
> inode, and has a stale pointer to a pipe_inode_info.
>
> It all looks technically correct. It's fine to use put_filp(), because
> the file pointer has never really been used. And the inode should
> never get re-used anyway without going through the whole reinit in
> inode_init_always().
>
> So I don't see anything *wrong*, but I see a lot that is just unusual,
FWIW, it's really brittle - consider
if ((mode & (FMODE_READ | FMODE_WRITE)) == FMODE_READ)
i_readcount_inc(path->dentry->d_inode);
in alloc_file(). It's not the source of trouble in this case, but only
because it's the second call that gets FMODE_READ; reorder them in
create_pipe_files() and you've got a bug.
I considered using fput() there, but that would've required manually
decrementing pipe->files first, which made it rather unappealing...
I don't see anything relevant there, but that's not saying much - flu
and debugging do not mix well, and lack of sleep also doesn't help ;-/
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 4:44 ` Al Viro
@ 2017-10-31 19:00 ` Linus Torvalds
0 siblings, 0 replies; 14+ messages in thread
From: Linus Torvalds @ 2017-10-31 19:00 UTC (permalink / raw)
To: Al Viro; +Cc: Cong Wang, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 9:44 PM, Al Viro <viro@zeniv.linux.org.uk> wrote:
> On Mon, Oct 30, 2017 at 07:08:46PM -0700, Linus Torvalds wrote:
>>
>> Well, they're at 8(%rax), except for that last case.
>
> 0x10(%rax)?
Duh, yes.
>> Except the offset is that %r12*0x28+0x10, so we're talking a byte
>> offset of 330 bytes into the allocation, and apparently the eight
>> previous (0-7) iterations were fine.
>>
>> Which is really odd.
>
> I wonder what pipe->buffers is equal to here...
Sadly, we never even bother loading it so it doesn't show up in the
register state, we just iterate over the whole table.
The (one) ppc oops that looks like it might be the same issue has a
totally different pattern. Instead of having that "error number"
looking thing as the invalid pointer base, it has the magic number
from a spinlock. And rather than being about "pipe->bufs[]" array,
it's the pipe pointer itself that seems corrupted, and thus the oops
happens in the account_pipe_buffers() code instead of in the loop over
the buffers.
Of course, both are consistent with that "pipe_inode_info" simply
having been overwritten by something else (possibly, but not
necessarily, due to a use-after-free).
> FWIW, I would try to slap
> if (buf->ops && (unsigned long)buf->ops <= 0xffffffff)
> dump the living hell out of that thing
> and see what it catches...
Actually, I'm looking at *another* error path - the one in named pipes.
Named pipes are why we do that nasty "inode->i_pipe" thing - if it was
for just the regular pipes, we'd be able to just do
file->f_private_data and be done with it. But named pipes have to have
the pipe data associated with a particular inode.
And that code actually does look wrong.
Look at fifo_open(): it increments the pipe->files as it sets
filp->private_data to point to the pipe_inode_info. Good so far.
But look at the error case. It does that put_pipe_info() to release it
again, but filp->private_data still contains the pipe_inode_info
pointer.
So what happens on a failed open of a named pipe? The *normal* code
all is very careful to _not_ use "fput()", but instead use
"put_filp(f)", which will just free the file pointer.
But what if somebody does "vfs_open()" on one of those things, and
then does "fput()" in the failure case?
In "do_last()" we have that FILE_OPENED protection:
if (unlikely(error) && (*opened & FILE_OPENED))
fput(file);
and path_openat() is again very careful to then use put_filp(file); if
FILE_OPENED was never set. And do_o_path() does the same.
I'm not seeing anybody who does the wrong thing, but there's a number
of ways to get this entirely wrong, and I worry some path does.
I would be a *lot* happier if we didn't have that very subtle
fput()-vs-put_filp() issue going on.
Again, I cannot see anything wrong, but this feels very very fragile to me.
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-10-31 2:08 ` Linus Torvalds
2017-10-31 3:06 ` Linus Torvalds
2017-10-31 4:44 ` Al Viro
@ 2017-11-01 3:19 ` Cong Wang
2017-11-10 6:07 ` Simon Brewer
2 siblings, 1 reply; 14+ messages in thread
From: Cong Wang @ 2017-11-01 3:19 UTC (permalink / raw)
To: Linus Torvalds; +Cc: Al Viro, Andrew Morton, linux-fsdevel, LKML
On Mon, Oct 30, 2017 at 7:08 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Mon, Oct 30, 2017 at 6:19 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>>
>> 1. The faulty addresses are all near 0000000100000000, with one exception
>> of null (which is the most recent one)
>
> Well, they're at 8(%rax), except for that last case.
>
> And in every case (_including_ that last case), %rax has a very
> interesting pattern.. That's the (bad) buf->ops pointer that was
> loaded from the somehow corrupted "buf".
>
> The values in all cases are
>
> 00000000fffffffa
> 00000000fffffffd
> 00000000fffffff1
> 00000000fffffff7
> 00000000fffffff4
> 00000000fffffffa
> 00000000fffffffd
> 00000000fffffffd
> 00000000fffffffa
> 00000000ffffffe8
> 00000000fffffff1
> 00000000fffffff7
>
> which kind of looks like a 32-bit error value. So we have (n, val, (errno)):
>
> 1 -24 (EMFILE)
> 2 -15 (ENOTBLK)
> 1 -12 (ENOMEM)
> 2 -9 (EBADF)
> 3 -6 (ENXIO)
> 3 -3 (ESRCH)
>
> none of which makes any sense to me, but it's an interesting pattern
> nonetheless.
Yeah, good find!
>
>> 2. R12 register, which should map to the local vairable 'i', is always 0x8
>> at the time of crash.
>
> So _if_ this is some kind of use-after-free thing, and the allocation
> got re-used for something else, that might just be related to whatever
> ends up being the offset that is filled in with the (int) error
> number.
>
> Except the offset is that %r12*0x28+0x10, so we're talking a byte
> offset of 330 bytes into the allocation, and apparently the eight
> previous (0-7) iterations were fine.
>
> Which is really odd.
>
> I'm not seeing anything that makes sense. I'll have to think about this.
>
> I'm assuming you don't have slub debugging enabled, and no way to
> enable it and try to catch this?
We enable it at compile-time but not at run-time:
CONFIG_SLUB_DEBUG=y
CONFIG_SLUB=y
CONFIG_SLUB_CPU_PARTIAL=y
# CONFIG_SLUB_DEBUG_ON is not set
# CONFIG_SLUB_STATS is not set
I can try to manually add slub_debug in boot parameters, but still
have no idea how and when can trigger this bug again.
Thanks!
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-11-01 3:19 ` Cong Wang
@ 2017-11-10 6:07 ` Simon Brewer
2017-11-10 19:16 ` Cong Wang
2017-11-10 19:47 ` Linus Torvalds
0 siblings, 2 replies; 14+ messages in thread
From: Simon Brewer @ 2017-11-10 6:07 UTC (permalink / raw)
To: Cong Wang; +Cc: Linus Torvalds, Al Viro, Andrew Morton, linux-fsdevel, LKML
On 1 November 2017 at 14:19, Cong Wang <xiyou.wangcong@gmail.com> wrote:
> On Mon, Oct 30, 2017 at 7:08 PM, Linus Torvalds
> <torvalds@linux-foundation.org> wrote:
>> On Mon, Oct 30, 2017 at 6:19 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>>>
>>> 1. The faulty addresses are all near 0000000100000000, with one exception
>>> of null (which is the most recent one)
>>
>> Well, they're at 8(%rax), except for that last case.
>>
>> And in every case (_including_ that last case), %rax has a very
>> interesting pattern.. That's the (bad) buf->ops pointer that was
>> loaded from the somehow corrupted "buf".
>>
>> The values in all cases are
>>
>> 00000000fffffffa
>> 00000000fffffffd
>> 00000000fffffff1
>> 00000000fffffff7
>> 00000000fffffff4
>> 00000000fffffffa
>> 00000000fffffffd
>> 00000000fffffffd
>> 00000000fffffffa
>> 00000000ffffffe8
>> 00000000fffffff1
>> 00000000fffffff7
>>
>> which kind of looks like a 32-bit error value. So we have (n, val, (errno)):
>>
>> 1 -24 (EMFILE)
>> 2 -15 (ENOTBLK)
>> 1 -12 (ENOMEM)
>> 2 -9 (EBADF)
>> 3 -6 (ENXIO)
>> 3 -3 (ESRCH)
>>
>> none of which makes any sense to me, but it's an interesting pattern
>> nonetheless.
>
>
> Yeah, good find!
>
>
>>
>>> 2. R12 register, which should map to the local vairable 'i', is always 0x8
>>> at the time of crash.
>>
>> So _if_ this is some kind of use-after-free thing, and the allocation
>> got re-used for something else, that might just be related to whatever
>> ends up being the offset that is filled in with the (int) error
>> number.
>>
>> Except the offset is that %r12*0x28+0x10, so we're talking a byte
>> offset of 330 bytes into the allocation, and apparently the eight
>> previous (0-7) iterations were fine.
>>
>> Which is really odd.
>>
>> I'm not seeing anything that makes sense. I'll have to think about this.
>>
>> I'm assuming you don't have slub debugging enabled, and no way to
>> enable it and try to catch this?
>
> We enable it at compile-time but not at run-time:
>
> CONFIG_SLUB_DEBUG=y
> CONFIG_SLUB=y
> CONFIG_SLUB_CPU_PARTIAL=y
> # CONFIG_SLUB_DEBUG_ON is not set
> # CONFIG_SLUB_STATS is not set
>
> I can try to manually add slub_debug in boot parameters, but still
> have no idea how and when can trigger this bug again.
>
>
> Thanks!
This looks familiar...
https://github.com/moby/moby/issues/34472
>From the bug report:
"In particular, it looks like either docker-containerd or
docker-containerd-shim (the log is cut off) has a pipe open that is
causing a kernel BUG when attempting to kill the process. Fun times."
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-11-10 6:07 ` Simon Brewer
@ 2017-11-10 19:16 ` Cong Wang
2017-11-10 19:47 ` Linus Torvalds
1 sibling, 0 replies; 14+ messages in thread
From: Cong Wang @ 2017-11-10 19:16 UTC (permalink / raw)
To: Simon Brewer; +Cc: Linus Torvalds, Al Viro, Andrew Morton, linux-fsdevel, LKML
Hi, Simon
On Thu, Nov 9, 2017 at 10:07 PM, Simon Brewer <sbrunau@gmail.com> wrote:
> This looks familiar...
>
> https://github.com/moby/moby/issues/34472
>
> From the bug report:
> "In particular, it looks like either docker-containerd or
> docker-containerd-shim (the log is cut off) has a pipe open that is
> causing a kernel BUG when attempting to kill the process. Fun times."
Yeah, looks nearly the same.
If you know how to reproduce it reliably, that would help a lot.
Also, as suggested by Linus, turning on slub debug would also help.
Or enable kdump to get a core dump.
Thanks!
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Kernel crash in free_pipe_info()
2017-11-10 6:07 ` Simon Brewer
2017-11-10 19:16 ` Cong Wang
@ 2017-11-10 19:47 ` Linus Torvalds
1 sibling, 0 replies; 14+ messages in thread
From: Linus Torvalds @ 2017-11-10 19:47 UTC (permalink / raw)
To: Simon Brewer; +Cc: Cong Wang, Al Viro, Andrew Morton, linux-fsdevel, LKML
On Thu, Nov 9, 2017 at 10:07 PM, Simon Brewer <sbrunau@gmail.com> wrote:
>
> This looks familiar...
>
> https://github.com/moby/moby/issues/34472
>
> From the bug report:
> "In particular, it looks like either docker-containerd or
> docker-containerd-shim (the log is cut off) has a pipe open that is
> causing a kernel BUG when attempting to kill the process. Fun times."
Interestingly, some of the "reproducers" show a totally different problem, with
kernel BUG at /build/linux-5EyXrQ/linux-4.4.0/mm/slub.c:1495!
which is this BUG():
1493 if (unlikely(flags & GFP_SLAB_BUG_MASK)) {
1494 pr_emerg("gfp: %u\n", flags & GFP_SLAB_BUG_MASK);
1495 BUG();
1496 }
which implies a completely invalid gfp mask.
The stack trace shows it's unix_stream_sendmsg -> sock_alloc_send_pskb
allocation, which uses "sk->sk_allocation".
Odd. af_unix just does
sk->sk_allocation = GFP_KERNEL_ACCOUNT;
That is new since v4.4, though - but before that it should have been
set by sock_init_data to just GFP_KERNEL.
So there it looks like a socket is entirely corrupted.
So that other backtrace looks entirely bogus too. More "that looks
like corrupted kernel data structures".
Enabling SLUB debugging would be really good here too.
But that is still quite an old kernel. I wish somebody could reproduce
this with something newer.
I added those wishes to the github thing.
Linus
^ permalink raw reply [flat|nested] 14+ messages in thread
end of thread, other threads:[~2017-11-10 19:47 UTC | newest]
Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-10-30 20:58 Kernel crash in free_pipe_info() Cong Wang
2017-10-30 22:14 ` Linus Torvalds
2017-10-30 22:26 ` Linus Torvalds
2017-10-31 1:19 ` Cong Wang
2017-10-31 2:08 ` Linus Torvalds
2017-10-31 3:06 ` Linus Torvalds
2017-10-31 5:00 ` Al Viro
2017-10-31 4:44 ` Al Viro
2017-10-31 19:00 ` Linus Torvalds
2017-11-01 3:19 ` Cong Wang
2017-11-10 6:07 ` Simon Brewer
2017-11-10 19:16 ` Cong Wang
2017-11-10 19:47 ` Linus Torvalds
2017-10-31 1:28 ` Cong Wang
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).