Kernel crash in free_pipe_info()

[Cong Wang]

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!