Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1332281 > unrolled thread
| Started by | Gerald Schaefer <gerald.schaefer@de.ibm.com> |
|---|---|
| First post | 2016-02-11 19:30 +0100 |
| Last post | 2016-02-15 17:50 +0100 |
| Articles | 10 on this page of 30 — 7 participants |
Back to article view | Back to linux.kernel
[BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-11 19:30 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-11 20:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill.shutemov@linux.intel.com> - 2016-02-11 20:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-12 13:30 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-11 21:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Aneesh Kumar K.V" <aneesh.kumar@linux.vnet.ibm.com> - 2016-02-12 05:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-12 13:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Aneesh Kumar K.V" <aneesh.kumar@linux.vnet.ibm.com> - 2016-02-12 17:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Will Deacon <will.deacon@arm.com> - 2016-02-12 11:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-12 11:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Will Deacon <will.deacon@arm.com> - 2016-02-12 17:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-12 16:50 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Christian Borntraeger <borntraeger@de.ibm.com> - 2016-02-12 17:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-12 18:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-13 00:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-13 13:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-15 16:50 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-15 17:40 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-15 19:40 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-16 00:30 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-16 11:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-16 17:30 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-17 16:30 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Christian Borntraeger <borntraeger@de.ibm.com> - 2016-02-16 19:50 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-17 20:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-18 08:00 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-18 16:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) "Kirill A. Shutemov" <kirill@shutemov.name> - 2016-02-18 18:10 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Sebastian Ott <sebott@linux.vnet.ibm.com> - 2016-02-19 15:20 +0100
Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) Gerald Schaefer <gerald.schaefer@de.ibm.com> - 2016-02-15 17:50 +0100
Page 2 of 2 — ← Prev page 1 [2]
| From | Sebastian Ott <sebott@linux.vnet.ibm.com> |
|---|---|
| Date | 2016-02-16 11:00 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r2KAi-685-7@gated-at.bofh.it> |
| In reply to | #1334877 |
On Mon, 15 Feb 2016, Kirill A. Shutemov wrote: > Just to make sure: commit 122afea9626a is fine, commit 61f5d698cc97 > crashes. Correct? Correct.
[toc] | [prev] | [next] | [standalone]
| From | Gerald Schaefer <gerald.schaefer@de.ibm.com> |
|---|---|
| Date | 2016-02-16 17:30 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r2QFI-1Px-7@gated-at.bofh.it> |
| In reply to | #1334877 |
On Mon, 15 Feb 2016 23:35:26 +0200
"Kirill A. Shutemov" <kirill@shutemov.name> wrote:
> On Mon, Feb 15, 2016 at 07:37:02PM +0100, Gerald Schaefer wrote:
> > On Mon, 15 Feb 2016 13:31:59 +0200
> > "Kirill A. Shutemov" <kirill@shutemov.name> wrote:
> >
> > > On Sat, Feb 13, 2016 at 12:58:31PM +0100, Sebastian Ott wrote:
> > > >
> > > > On Sat, 13 Feb 2016, Kirill A. Shutemov wrote:
> > > > > Could you check if revert of fecffad25458 helps?
> > > >
> > > > I reverted fecffad25458 on top of 721675fcf277cf - it oopsed with:
> > > >
> > > > ¢ 1851.721062! Unable to handle kernel pointer dereference in virtual kernel address space
> > > > ¢ 1851.721075! failing address: 0000000000000000 TEID: 0000000000000483
> > > > ¢ 1851.721078! Fault in home space mode while using kernel ASCE.
> > > > ¢ 1851.721085! AS:0000000000d5c007 R3:00000000ffff0007 S:00000000ffffa800 P:000000000000003d
> > > > ¢ 1851.721128! Oops: 0004 ilc:3 ¢#1! PREEMPT SMP DEBUG_PAGEALLOC
> > > > ¢ 1851.721135! Modules linked in: bridge stp llc btrfs mlx4_ib mlx4_en ib_sa ib_mad vxlan xor ip6_udp_tunnel ib_core udp_tunnel ptp pps_core ib_addr ghash_s390raid6_pq prng ecb aes_s390 mlx4_core des_s390 des_generic genwqe_card sha512_s390 sha256_s390 sha1_s390 sha_common crc_itu_t dm_mod scm_block vhost_net tun vhost eadm_sch macvtap macvlan kvm autofs4
> > > > ¢ 1851.721183! CPU: 7 PID: 256422 Comm: bash Not tainted 4.5.0-rc3-00058-g07923d7-dirty #178
> > > > ¢ 1851.721186! task: 000000007fbfd290 ti: 000000008c604000 task.ti: 000000008c604000
> > > > ¢ 1851.721189! Krnl PSW : 0704d00180000000 000000000045d3b8 (__rb_erase_color+0x280/0x308)
> > > > ¢ 1851.721200! R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 EA:3
> > > > Krnl GPRS: 0000000000000001 0000000000000020 0000000000000000 00000000bd07eff1
> > > > ¢ 1851.721205! 000000000027ca10 0000000000000000 0000000083e45898 0000000077b61198
> > > > ¢ 1851.721207! 000000007ce1a490 00000000bd07eff0 000000007ce1a548 000000000027ca10
> > > > ¢ 1851.721210! 00000000bd07c350 00000000bd07eff0 000000008c607aa8 000000008c607a68
> > > > ¢ 1851.721221! Krnl Code: 000000000045d3aa: e3c0d0080024 stg %%r12,8(%%r13)
> > > > 000000000045d3b0: b9040039 lgr %%r3,%%r9
> > > > #000000000045d3b4: a53b0001 oill %%r3,1
> > > > >000000000045d3b8: e33010000024 stg %%r3,0(%%r1)
> > > > 000000000045d3be: ec28000e007c cgij %%r2,0,8,45d3da
> > > > 000000000045d3c4: e34020000004 lg %%r4,0(%%r2)
> > > > 000000000045d3ca: b904001c lgr %%r1,%%r12
> > > > 000000000045d3ce: ec143f3f0056 rosbg %%r1,%%r4,63,63,0
> > > > ¢ 1851.721269! Call Trace:
> > > > ¢ 1851.721273! (¢<0000000083e45898>! 0x83e45898)
> > > > ¢ 1851.721279! ¢<000000000029342a>! unlink_anon_vmas+0x9a/0x1d8
> > > > ¢ 1851.721282! ¢<0000000000283f34>! free_pgtables+0xcc/0x148
> > > > ¢ 1851.721285! ¢<000000000028c376>! exit_mmap+0xd6/0x300
> > > > ¢ 1851.721289! ¢<0000000000134db8>! mmput+0x90/0x118
> > > > ¢ 1851.721294! ¢<00000000002d76bc>! flush_old_exec+0x5d4/0x700
> > > > ¢ 1851.721298! ¢<00000000003369f4>! load_elf_binary+0x2f4/0x13e8
> > > > ¢ 1851.721301! ¢<00000000002d6e4a>! search_binary_handler+0x9a/0x1f8
> > > > ¢ 1851.721304! ¢<00000000002d8970>! do_execveat_common.isra.32+0x668/0x9a0
> > > > ¢ 1851.721307! ¢<00000000002d8cec>! do_execve+0x44/0x58
> > > > ¢ 1851.721310! ¢<00000000002d8f92>! SyS_execve+0x3a/0x48
> > > > ¢ 1851.721315! ¢<00000000006fb096>! system_call+0xd6/0x258
> > > > ¢ 1851.721317! ¢<000003ff997436d6>! 0x3ff997436d6
> > > > ¢ 1851.721319! INFO: lockdep is turned off.
> > > > ¢ 1851.721321! Last Breaking-Event-Address:
> > > > ¢ 1851.721323! ¢<000000000045d31a>! __rb_erase_color+0x1e2/0x308
> > > > ¢ 1851.721327!
> > > > ¢ 1851.721329! ---¢ end trace 0d80041ac00cfae2 !---
> > > >
> > > >
> > > > >
> > > > > And could you share how crashes looks like? I haven't seen backtraces yet.
> > > > >
> > > >
> > > > Sure. I didn't because they really looked random to me. Most of the time
> > > > in rcu or list debugging but I thought these have just been the messenger
> > > > observing a corruption first. Anyhow, here is an older one that might look
> > > > interesting:
> > > >
> > > > [ 59.851421] list_del corruption. next->prev should be 000000006e1eb000, but was 0000000000000400
> > >
> > > This kinda interesting: 0x400 is TAIL_MAPPING.. Hm..
> > >
> > > Could you check if you see the problem on commit 1c290f642101 and its
> > > immediate parent?
> > >
> >
> > How should the page->mapping poison end up as next->prev in the list of
> > pre-allocated THP splitting page tables?
>
> May be pgtable was casted to struct page or something. I don't know.
>
> > Also, commit 1c290f642101 is before the THP rework, at least the
> > non-bisectable part, so we should expect not to see the problem there.
>
> Just to make sure: commit 122afea9626a is fine, commit 61f5d698cc97
> crashes. Correct?
>
> > 0x400 is also the value of an empty pte on s390, and the thp_deposit/withdraw
> > listheads are placed inside the pre-allocated pagetables instead of page->lru,
> > because we have 2K pagetables on s390 and cannot use struct page == pgtable_t.
>
> 0x400 from empty pte makes more sense than TAIL_MAPPING. But I guess it
> worth changing TAIL_MAPPING to some other value to make sure.
Right, but we cannot trigger this list corruption symptom reliably, in fact
I didn't hit it at all during the last runs, and previous crash logs also
showed list corruptions with other values than 0x400, which may hint towards
concurrent pagetable freeing and re-use, given that our THP splitting pagetable
listhead is located inside the pre-allocated pagetables.
>
> > So, for example, two concurrent withdraws could produce such a list
> > corruption, because the first withdraw will overwrite the listhead at the
> > beginning of the pagetable with 2 empty ptes.
> >
> > Has anything changed regarding the general THP deposit/withdraw logic?
>
> I don't see any changes in this area.
>
> To eliminate one more variable, I would propose to disable split pmd lock
> for testing and check if it makes difference.
Disabling ARCH_ENABLE_SPLIT_PMD_PTLOCK didn't make any difference, other
than maybe a little reduction in "randomness" of the crashes, but that
may be pure coincidence. Out of about 10 runs, I always ended up with either
ODEBUG "WARNING: at lib/debugobjects.c:263" and subsequent "kernel BUG at
mm/slub.c:3629", or "bad swap file / page map" with subsequent "kernel BUG
at kernel/cred.c:142", see below for the full traces.
>
> Is there any chance that I'll be able to trigger the bug using QEMU?
> Does anybody have an QEMU image I can use?
>
I have no image, but trying to reproduce this under virtualization may
help to trigger this also on other architectures. After ruling out IPI
vs. fast_gup I do not really see why this should be arch-specific, and
it wouldn't be the first time that we hit subtle races first on s390, due
to our virtualized environment (my test case is make -j20 with 10 CPUs and
4GB of memory, no swap).
Here are the full traces from the runs w/o split pmd lock:
1)
[ 2584.391880] cc1 (71885) used greatest stack depth: 10496 bytes left
[ 2951.268250] ld (147667) used greatest stack depth: 10472 bytes left
[ 2972.530753] swap_free: Bad swap file entry 1000000000000000
[ 2972.530763] BUG: Bad page map in process cc1 pte:00000420 pmd:6cfd3000
[ 2972.530766] addr:0000000080d00000 vm_flags:00000875 anon_vma: (null) mapping:000000005dc6ac70 index
:d00
[ 2972.530776] file:cc1 fault:ext4_filemap_fault mmap:ext4_file_mmap readpage:ext4_readpage
[ 2972.530781] CPU: 6 PID: 152043 Comm: cc1 Not tainted 4.5.0-rc4-00014-g1926e54-dirty #70
[ 2972.530784] 0000000071947a60 0000000071947af0 0000000000000002 0000000000000000
0000000071947b90 0000000071947b08 0000000071947b08 0000000000113d38
0000000000000000 0000000000b70df4 0000000000b4f348 000000000000000b
0000000071947b50 0000000071947af0 0000000000000000 0000000000000000
07000000c3763ae8 0000000000113d38 0000000071947af0 0000000071947b50
[ 2972.530811] Call Trace:
[ 2972.530818] ([<0000000000113c3c>] show_trace+0x12c/0x150)
[ 2972.530821] [<0000000000113cee>] show_stack+0x8e/0xf0
[ 2972.530826] [<000000000068b8ec>] dump_stack+0x9c/0xe0
[ 2972.530830] [<00000000002bbeda>] print_bad_pte+0x222/0x238
[ 2972.530833] [<00000000002beb92>] zap_pte_range+0x442/0x790
[ 2972.530835] [<00000000002bf2c6>] unmap_single_vma+0x3e6/0x400
[ 2972.530837] [<00000000002c0f46>] unmap_vmas+0x8e/0xc8
[ 2972.530840] [<00000000002c9a56>] exit_mmap+0xc6/0x300
[ 2972.530844] [<0000000000138b10>] mmput+0xa0/0x128
[ 2972.530847] [<000000000013fcb4>] do_exit+0x42c/0xd60
[ 2972.530849] [<00000000001406f0>] do_group_exit+0x98/0xe0
[ 2972.530851] [<0000000000140768>] __wake_up_parent+0x0/0x28
[ 2972.530855] [<0000000000910f2e>] system_call+0xd6/0x270
[ 2972.530883] [<000003ff89b43698>] 0x3ff89b43698
[ 2972.530886] 1 lock held by cc1/152043:
[ 2972.530887] #0: (&(ptlock_ptr(page))->rlock){+.+.-.}, at: [<00000000002be7f6>] zap_pte_range+0xa6/0x790
[ 2972.530897] Disabling lock debugging due to kernel taint
[ 2972.533069] BUG: Bad rss-counter state mm:00000000719d0e00 idx:2 val:-1
[ 5899.109157] ------------[ cut here ]------------
[ 5899.109166] kernel BUG at kernel/cred.c:142!
[ 5899.109211] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 5899.109217] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp iptable_filter ip_tables x_tables bridge stp llc mlx4_ib ib_sa ib_mad mlx4_en ib_core vxlan udp_tunnel ptp ib_addr pps_core ghash_s390 prng ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 sha_common mlx4_core eadm_sch nfsd vhost_net tun vhost macvtap auth_rpcgss macvlan kvm oid_registry nfs_acl lockd grace sunrpc dm_multipath dm_mod autofs4
[ 5899.109279] CPU: 1 PID: 12 Comm: ksoftirqd/1 Tainted: G B 4.5.0-rc4-00014-g1926e54-dirty #70
[ 5899.109283] task: 00000000d09e2a48 ti: 00000000d09f4000 task.ti: 00000000d09f4000
[ 5899.109286] Krnl PSW : 0704c00180000000 00000000001651aa (__put_cred+0x22/0x68)
[ 5899.109296] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3
Krnl GPRS: 0000000000000002 0000000000000020 000000007431f000 00000000c38e3400
[ 5899.109301] 000000000032aaf8 0000000000000002 0000000000000000 000000000000000a
[ 5899.109304] 0000000000000000 000000000032aac0 0000000000000008 00000000749ad000
[ 5899.109306] 00000000c38e3400 000000007431f000 000000000032ab2e 00000000d09f7bf0
[ 5899.109316] Krnl Code: 000000000016519c: 58102004 l %%r1,4(%%r2)
00000000001651a0: ec180005007e cij %%r1,0,8,1651aa
#00000000001651a6: a7f40001 brc 15,1651a8
>00000000001651aa: e3e020080024 stg %%r14,8(%%r2)
00000000001651b0: c01944656144 iilf %%r1,1147494724
00000000001651b6: 50102010 st %%r1,16(%%r2)
00000000001651ba: e31003100004 lg %%r1,784
00000000001651c0: e32018300020 cg %%r2,2096(%%r1)
[ 5899.109371] Call Trace:
[ 5899.109376] ([<000000000032aaf8>] file_free_rcu+0x38/0x88)
[ 5899.109381] [<00000000001c5ddc>] rcu_process_callbacks+0x5fc/0x9f0
[ 5899.109385] [<0000000000141794>] __do_softirq+0x25c/0x570
[ 5899.109387] [<0000000000141ae6>] run_ksoftirqd+0x3e/0xa0
[ 5899.109391] [<0000000000167bee>] smpboot_thread_fn+0x30e/0x360
[ 5899.109394] [<0000000000162f4a>] kthread+0x112/0x128
[ 5899.109398] [<00000000009110fa>] kernel_thread_starter+0x6/0xc
[ 5899.109401] [<00000000009110f4>] kernel_thread_starter+0x0/0xc
[ 5899.109403] INFO: lockdep is turned off.
[ 5899.109405] Last Breaking-Event-Address:
[ 5899.109407] [<00000000001651a6>] __put_cred+0x1e/0x68
[ 5899.109411]
[ 5899.109414] Kernel panic - not syncing: Fatal exception in interrupt
2)
[ 7790.934295] ODEBUG: active_state not available (active state 0) object type: rcu_head hint: (null)
[ 7790.934356] ------------[ cut here ]------------
[ 7790.934359] WARNING: at lib/debugobjects.c:263
[ 7790.934361] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack mlx4_ib ib_sa ipt_REJECT mlx4_en ib_mad nf_reject_ipv4 ib_core vxlan udp_tunnel ptp xt_tcpudp ib_addr pps_core iptable_filter ip_tables x_tables bridge stp llc ghash_s390 prng ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 mlx4_core sha1_s390 sha_common eadm_sch vhost_net nfsd tun vhost macvtap macvlan auth_rpcgss kvm oid_registry nfs_acl lockd grace sunrpc dm_multipath dm_mod autofs4
[ 7790.934417] CPU: 8 PID: 40 Comm: ksoftirqd/8 Not tainted 4.5.0-rc4-00014-g1926e54-dirty #149
[ 7790.934420] task: 00000000e2955490 ti: 00000000e2958000 task.ti: 00000000e2958000
[ 7790.934422] Krnl PSW : 0404c00180000000 000000000071c340 (debug_print_object+0xb0/0xd0)
[ 7790.934431] R:0 T:1 IO:0 EX:0 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3
Krnl GPRS: 0000000001e6e3c7 00000000e2955490 0000000000000060 00000000e2958000
[ 7790.934435] 000000000071c33c 0000000000000000 0000000000b975e8 0000000001f2b008
[ 7790.934437] 07000000001d7e24 0000000000000000 0000000001f2b010 0000000000bea6b8
[ 7790.934440] 0000000000e241f8 00000000e295bc38 000000000071c33c 00000000e295bb38
[ 7790.934449] Krnl Code: 000000000071c330: c41f00bf6a14 strl %%r1,1f09758
000000000071c336: c0e5ffdbd64d brasl %%r14,296fd0
#000000000071c33c: a7f40001 brc 15,71c33e
>000000000071c340: c41d0036e746 lrl %%r1,df91cc
000000000071c346: e340f0e80004 lg %%r4,232(%%r15)
000000000071c34c: a71a0001 ahi %%r1,1
000000000071c350: eb6ff0a80004 lmg %%r6,%%r15,168(%%r15)
000000000071c356: c41f0036e73b strl %%r1,df91cc
[ 7790.934493] Call Trace:
[ 7790.934495] ([<000000000071c33c>] debug_print_object+0xac/0xd0)
[ 7790.934498] [<000000000071d704>] debug_object_active_state+0x164/0x178
[ 7790.934504] [<00000000001d7da4>] rcu_process_callbacks+0x57c/0xa00
[ 7790.934508] [<00000000001487ec>] __do_softirq+0x26c/0x580
[ 7790.934510] [<0000000000148b50>] run_ksoftirqd+0x50/0xb0
[ 7790.934515] [<0000000000172b28>] smpboot_thread_fn+0x320/0x378
[ 7790.934517] [<000000000016d21c>] kthread+0x124/0x138
[ 7790.934521] [<00000000009a1d72>] kernel_thread_starter+0x6/0xc
[ 7790.934524] [<00000000009a1d6c>] kernel_thread_starter+0x0/0xc
[ 7790.934526] 1 lock held by ksoftirqd/8/40:
[ 7790.934528] #0: (&obj_hash[i].lock){-.-.-.}, at: [<000000000071d64c>] debug_object_active_state+0xac/0x178
[ 7790.934535] Last Breaking-Event-Address:
[ 7790.934537] [<000000000071c33c>] debug_print_object+0xac/0xd0
[ 7790.934539] ---[ end trace b583bfd967a78637 ]---
[ 7790.934543] ODEBUG: deactivate not available (active state 0) object type: rcu_head hint: (null)
[ 7790.934551] ------------[ cut here ]------------
[ 7790.934553] WARNING: at lib/debugobjects.c:263
[ 7790.934555] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack mlx4_ib ib_sa ipt_REJECT mlx4_en ib_mad nf_reject_ipv4 ib_core vxlan udp_tunnel ptp xt_tcpudp ib_addr pps_core iptable_filter ip_tables x_tables bridge stp llc ghash_s390 prng ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 mlx4_core sha1_s390 sha_common eadm_sch vhost_net nfsd tun vhost macvtap macvlan auth_rpcgss kvm oid_registry nfs_acl lockd grace sunrpc dm_multipath dm_mod autofs4
[ 7790.934599] CPU: 8 PID: 40 Comm: ksoftirqd/8 Tainted: G W 4.5.0-rc4-00014-g1926e54-dirty #149
[ 7790.934601] task: 00000000e2955490 ti: 00000000e2958000 task.ti: 00000000e2958000
[ 7790.934603] Krnl PSW : 0404c00180000000 000000000071c340 (debug_print_object+0xb0/0xd0)
[ 7790.934608] R:0 T:1 IO:0 EX:0 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3
Krnl GPRS: 0000000001e6e3c7 00000000e2955490 000000000000005e 00000000e2958000
[ 7790.934612] 000000000071c33c 0000000000000000 0000000000b975e8 000000000000000a
[ 7790.934614] 0000000004bcd020 0700000001f2b010 0000000001f2b010 0000000000ba5d0a
[ 7790.934617] 0000000000e241f8 00000000e295bc48 000000000071c33c 00000000e295bb48
[ 7790.934622] Krnl Code: 000000000071c330: c41f00bf6a14 strl %%r1,1f09758
000000000071c336: c0e5ffdbd64d brasl %%r14,296fd0
#000000000071c33c: a7f40001 brc 15,71c33e
>000000000071c340: c41d0036e746 lrl %%r1,df91cc
000000000071c346: e340f0e80004 lg %%r4,232(%%r15)
000000000071c34c: a71a0001 ahi %%r1,1
000000000071c350: eb6ff0a80004 lmg %%r6,%%r15,168(%%r15)
000000000071c356: c41f0036e73b strl %%r1,df91cc
[ 7790.934639] Call Trace:
[ 7790.934641] ([<000000000071c33c>] debug_print_object+0xac/0xd0)
[ 7790.934644] [<000000000071d0a8>] debug_object_deactivate+0x170/0x188
[ 7790.934646] [<00000000001d7db6>] rcu_process_callbacks+0x58e/0xa00
[ 7790.934648] [<00000000001487ec>] __do_softirq+0x26c/0x580
[ 7790.934651] [<0000000000148b50>] run_ksoftirqd+0x50/0xb0
[ 7790.934653] [<0000000000172b28>] smpboot_thread_fn+0x320/0x378
[ 7790.934655] [<000000000016d21c>] kthread+0x124/0x138
[ 7790.934657] [<00000000009a1d72>] kernel_thread_starter+0x6/0xc
[ 7790.934659] [<00000000009a1d6c>] kernel_thread_starter+0x0/0xc
[ 7790.934661] 1 lock held by ksoftirqd/8/40:
[ 7790.934663] #0: (&obj_hash[i].lock){-.-.-.}, at: [<000000000071cfdc>] debug_object_deactivate+0xa4/0x188
[ 7790.934669] Last Breaking-Event-Address:
[ 7790.934671] [<000000000071c33c>] debug_print_object+0xac/0xd0
[ 7790.934673] ---[ end trace b583bfd967a78638 ]---
[ 7790.934680] ------------[ cut here ]------------
[ 7790.934682] kernel BUG at mm/slub.c:3629!
[ 7790.934707] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 7790.934715] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack mlx4_ib ib_sa ipt_REJECT mlx4_en ib_mad nf_reject_ipv4 ib_core vxlan udp_tunnel ptp xt_tcpudp ib_addr pps_core iptable_filter ip_tables x_tables bridge stp llc ghash_s390 prng ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 mlx4_core sha1_s390 sha_common eadm_sch vhost_net nfsd tun vhost macvtap macvlan auth_rpcgss kvm oid_registry nfs_acl lockd grace sunrpc dm_multipath dm_mod autofs4
[ 7790.934789] CPU: 8 PID: 40 Comm: ksoftirqd/8 Tainted: G W 4.5.0-rc4-00014-g1926e54-dirty #149
[ 7790.934791] task: 00000000e2955490 ti: 00000000e2958000 task.ti: 00000000e2958000
[ 7790.934794] Krnl PSW : 0704c00180000000 000000000032295a (kfree+0x3f2/0x428)
[ 7790.934801] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3
Krnl GPRS: 0000000000000000 0000000000000100 0000000000000100 0000000000e24260
[ 7790.934806] 00000000001d1c82 0000000000000000 0000000000000000 000000000000000a
[ 7790.934809] 0000000000000001 00000000001d7e0a 0000000000000006 000003d10012f340
[ 7790.934812] 0000000004bcd000 0000000000f0433c 000000000032267a 00000000e295bbb0
[ 7790.934818] Krnl Code: 000000000032294c: c0e50033bef6 brasl %%r14,99a738
0000000000322952: a7f4feba brc 15,3226c6
#0000000000322956: a7f40001 brc 15,322958
>000000000032295a: e310b0060090 llgc %%r1,6(%%r11)
0000000000322960: a7110040 tmll %%r1,64
0000000000322964: a774fee9 brc 7,322736
0000000000322968: a7f4feeb brc 15,32273e
000000000032296c: c0e50033be32 brasl %%r14,99a5d0
[ 7790.934838] Call Trace:
[ 7790.934841] ([<000000000032267a>] kfree+0x112/0x428)
[ 7790.934844] [<00000000001d7e0a>] rcu_process_callbacks+0x5e2/0xa00
[ 7790.934847] [<00000000001487ec>] __do_softirq+0x26c/0x580
[ 7790.934850] [<0000000000148b50>] run_ksoftirqd+0x50/0xb0
[ 7790.934854] [<0000000000172b28>] smpboot_thread_fn+0x320/0x378
[ 7790.934856] [<000000000016d21c>] kthread+0x124/0x138
[ 7790.934859] [<00000000009a1d72>] kernel_thread_starter+0x6/0xc
[ 7790.934862] [<00000000009a1d6c>] kernel_thread_starter+0x0/0xc
[ 7790.934864] INFO: lockdep is turned off.
[ 7790.934866] Last Breaking-Event-Address:
[ 7790.934869] [<0000000000322956>] kfree+0x3ee/0x428
[ 7790.934873]
[ 7790.934876] Kernel panic - not syncing: Fatal exception in interrupt
[toc] | [prev] | [next] | [standalone]
| From | "Kirill A. Shutemov" <kirill@shutemov.name> |
|---|---|
| Date | 2016-02-17 16:30 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3cdc-8f1-15@gated-at.bofh.it> |
| In reply to | #1335611 |
On Tue, Feb 16, 2016 at 05:24:44PM +0100, Gerald Schaefer wrote: > On Mon, 15 Feb 2016 23:35:26 +0200 > "Kirill A. Shutemov" <kirill@shutemov.name> wrote: > > > Is there any chance that I'll be able to trigger the bug using QEMU? > > Does anybody have an QEMU image I can use? > > > > I have no image, but trying to reproduce this under virtualization may > help to trigger this also on other architectures. After ruling out IPI > vs. fast_gup I do not really see why this should be arch-specific, and > it wouldn't be the first time that we hit subtle races first on s390, due > to our virtualized environment (my test case is make -j20 with 10 CPUs and > 4GB of memory, no swap). Could you post your kernel config? It would be nice also to check if disabling split_huge_page() would make any difference: diff --git a/mm/huge_memory.c b/mm/huge_memory.c index a75081ca31cf..26d2b7b21021 100644 --- a/mm/huge_memory.c +++ b/mm/huge_memory.c @@ -3364,6 +3364,8 @@ int split_huge_page_to_list(struct page *page, struct list_head *list) bool mlocked; unsigned long flags; + return -EBUSY; + VM_BUG_ON_PAGE(is_huge_zero_page(page), page); VM_BUG_ON_PAGE(!PageAnon(page), page); VM_BUG_ON_PAGE(!PageLocked(page), page); -- Kirill A. Shutemov
[toc] | [prev] | [next] | [standalone]
| From | Christian Borntraeger <borntraeger@de.ibm.com> |
|---|---|
| Date | 2016-02-16 19:50 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r2SRc-3dV-11@gated-at.bofh.it> |
| In reply to | #1334877 |
On 02/15/2016 10:35 PM, Kirill A. Shutemov wrote: > > Is there any chance that I'll be able to trigger the bug using QEMU? > Does anybody have an QEMU image I can use? qemu/TCG on s390 does neither provide SMP nor large pages (only QEMU/KVM does) so this will probably not help you here. Christian
[toc] | [prev] | [next] | [standalone]
| From | Gerald Schaefer <gerald.schaefer@de.ibm.com> |
|---|---|
| Date | 2016-02-17 20:20 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3fNN-2nq-33@gated-at.bofh.it> |
| In reply to | #1333309 |
On Sat, 13 Feb 2016 12:58:31 +0100 (CET) Sebastian Ott <sebott@linux.vnet.ibm.com> wrote: > [ 59.875935] ------------[ cut here ]------------ > [ 59.875937] kernel BUG at mm/huge_memory.c:2884! > [ 59.875979] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC > [ 59.875986] Modules linked in: bridge stp llc btrfs xor mlx4_en vxlan ip6_udp_tunnel udp_tunnel mlx4_ib ptp pps_core ib_sa ib_mad ib_core ib_addr ghash_s390 prng raid6_pq ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 mlx4_core sha_common genwqe_card scm_block crc_itu_t vhost_net tun vhost dm_mod macvtap eadm_sch macvlan kvm autofs4 > [ 59.876033] CPU: 2 PID: 5402 Comm: git Tainted: G W 4.4.0-07794-ga4eff16-dirty #77 > [ 59.876036] task: 00000000d2312948 ti: 00000000cfecc000 task.ti: 00000000cfecc000 > [ 59.876039] Krnl PSW : 0704d00180000000 00000000002bf3aa (__split_huge_pmd_locked+0x562/0xa10) > [ 59.876045] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 EA:3 > Krnl GPRS: 0000000001a7a1cf 000003d10177c000 0000000000044068 000000005df00215 > [ 59.876051] 0000000000000001 0000000000000001 0000000000000000 00000000774e6900 > [ 59.876054] 000003ff52000000 000000006d403b10 000000006e1eb800 000003ff51f00000 > [ 59.876058] 000003d10177c000 0000000000715190 00000000002bf234 00000000cfecfb58 > [ 59.876068] Krnl Code: 00000000002bf39c: d507d010a000 clc 16(8,%%r13),0(%%r10) > 00000000002bf3a2: a7840004 brc 8,2bf3aa > #00000000002bf3a6: a7f40001 brc 15,2bf3a8 > >00000000002bf3aa: 91407440 tm 1088(%%r7),64 > 00000000002bf3ae: a7840208 brc 8,2bf7be > 00000000002bf3b2: a7f401e9 brc 15,2bf784 > 00000000002bf3b6: 9104a006 tm 6(%%r10),4 > 00000000002bf3ba: a7740004 brc 7,2bf3c2 > [ 59.876089] Call Trace: > [ 59.876092] ([<00000000002bf234>] __split_huge_pmd_locked+0x3ec/0xa10) > [ 59.876095] [<00000000002c4310>] __split_huge_pmd+0x118/0x218 > [ 59.876099] [<00000000002810e8>] unmap_single_vma+0x2d8/0xb40 > [ 59.876102] [<0000000000282d66>] zap_page_range+0x116/0x318 > [ 59.876105] [<000000000029b834>] SyS_madvise+0x23c/0x5e8 > [ 59.876108] [<00000000006f9f56>] system_call+0xd6/0x258 > [ 59.876111] [<000003ff9bbfd282>] 0x3ff9bbfd282 > [ 59.876113] INFO: lockdep is turned off. > [ 59.876115] Last Breaking-Event-Address: > [ 59.876118] [<00000000002bf3a6>] __split_huge_pmd_locked+0x55e/0xa10 The BUG at mm/huge_memory.c:2884 is interesting, it's the BUG_ON(!pte_none(*pte)) check in __split_huge_pmd_locked(). Obviously we expect the pre-allocated pagetables to be empty, but in collapse_huge_page() we deposit the original pagetable instead of allocating a new (empty) one. This saves an allocation, which is good, but doesn't that mean that if such a collapsed hugepage will ever be split, we will always run into the BUG_ON(!pte_none(*pte)), or one of the two other VM_BUG_ONs in mm/huge_memory.c that check the same? This behavior is not new, it was the same before the THP rework, so I do not assume that it is related to the current problems, maybe with the exception of this specific crash. I never saw the BUG at mm/huge_memory.c:2884 myself, and the other crashes probably cannot be explained with this. Maybe I am also missing something, but I do not see how collapse_huge_page() and the (non-empty) pgtable deposit there can work out with the BUG_ON(!pte_none(*pte)) checks. Any thoughts?
[toc] | [prev] | [next] | [standalone]
| From | "Kirill A. Shutemov" <kirill@shutemov.name> |
|---|---|
| Date | 2016-02-18 08:00 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3qJd-1Fp-13@gated-at.bofh.it> |
| In reply to | #1336682 |
On Wed, Feb 17, 2016 at 08:13:40PM +0100, Gerald Schaefer wrote: > On Sat, 13 Feb 2016 12:58:31 +0100 (CET) > Sebastian Ott <sebott@linux.vnet.ibm.com> wrote: > > > [ 59.875935] ------------[ cut here ]------------ > > [ 59.875937] kernel BUG at mm/huge_memory.c:2884! > > [ 59.875979] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC > > [ 59.875986] Modules linked in: bridge stp llc btrfs xor mlx4_en vxlan ip6_udp_tunnel udp_tunnel mlx4_ib ptp pps_core ib_sa ib_mad ib_core ib_addr ghash_s390 prng raid6_pq ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 mlx4_core sha_common genwqe_card scm_block crc_itu_t vhost_net tun vhost dm_mod macvtap eadm_sch macvlan kvm autofs4 > > [ 59.876033] CPU: 2 PID: 5402 Comm: git Tainted: G W 4.4.0-07794-ga4eff16-dirty #77 > > [ 59.876036] task: 00000000d2312948 ti: 00000000cfecc000 task.ti: 00000000cfecc000 > > [ 59.876039] Krnl PSW : 0704d00180000000 00000000002bf3aa (__split_huge_pmd_locked+0x562/0xa10) > > [ 59.876045] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 EA:3 > > Krnl GPRS: 0000000001a7a1cf 000003d10177c000 0000000000044068 000000005df00215 > > [ 59.876051] 0000000000000001 0000000000000001 0000000000000000 00000000774e6900 > > [ 59.876054] 000003ff52000000 000000006d403b10 000000006e1eb800 000003ff51f00000 > > [ 59.876058] 000003d10177c000 0000000000715190 00000000002bf234 00000000cfecfb58 > > [ 59.876068] Krnl Code: 00000000002bf39c: d507d010a000 clc 16(8,%%r13),0(%%r10) > > 00000000002bf3a2: a7840004 brc 8,2bf3aa > > #00000000002bf3a6: a7f40001 brc 15,2bf3a8 > > >00000000002bf3aa: 91407440 tm 1088(%%r7),64 > > 00000000002bf3ae: a7840208 brc 8,2bf7be > > 00000000002bf3b2: a7f401e9 brc 15,2bf784 > > 00000000002bf3b6: 9104a006 tm 6(%%r10),4 > > 00000000002bf3ba: a7740004 brc 7,2bf3c2 > > [ 59.876089] Call Trace: > > [ 59.876092] ([<00000000002bf234>] __split_huge_pmd_locked+0x3ec/0xa10) > > [ 59.876095] [<00000000002c4310>] __split_huge_pmd+0x118/0x218 > > [ 59.876099] [<00000000002810e8>] unmap_single_vma+0x2d8/0xb40 > > [ 59.876102] [<0000000000282d66>] zap_page_range+0x116/0x318 > > [ 59.876105] [<000000000029b834>] SyS_madvise+0x23c/0x5e8 > > [ 59.876108] [<00000000006f9f56>] system_call+0xd6/0x258 > > [ 59.876111] [<000003ff9bbfd282>] 0x3ff9bbfd282 > > [ 59.876113] INFO: lockdep is turned off. > > [ 59.876115] Last Breaking-Event-Address: > > [ 59.876118] [<00000000002bf3a6>] __split_huge_pmd_locked+0x55e/0xa10 > > The BUG at mm/huge_memory.c:2884 is interesting, it's the BUG_ON(!pte_none(*pte)) > check in __split_huge_pmd_locked(). Obviously we expect the pre-allocated > pagetables to be empty, but in collapse_huge_page() we deposit the original > pagetable instead of allocating a new (empty) one. This saves an allocation, > which is good, but doesn't that mean that if such a collapsed hugepage will > ever be split, we will always run into the BUG_ON(!pte_none(*pte)), or one > of the two other VM_BUG_ONs in mm/huge_memory.c that check the same? > > This behavior is not new, it was the same before the THP rework, so I do not > assume that it is related to the current problems, maybe with the exception > of this specific crash. I never saw the BUG at mm/huge_memory.c:2884 myself, > and the other crashes probably cannot be explained with this. Maybe I am > also missing something, but I do not see how collapse_huge_page() and the > (non-empty) pgtable deposit there can work out with the BUG_ON(!pte_none(*pte)) > checks. Any thoughts? I don't think there's a problem: ptes in the pgtable are cleared with pte_clear() in __collapse_huge_page_copy(). -- Kirill A. Shutemov
[toc] | [prev] | [next] | [standalone]
| From | Gerald Schaefer <gerald.schaefer@de.ibm.com> |
|---|---|
| Date | 2016-02-18 16:10 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3ynn-7re-5@gated-at.bofh.it> |
| In reply to | #1337093 |
On Thu, 18 Feb 2016 01:58:08 +0200
"Kirill A. Shutemov" <kirill@shutemov.name> wrote:
> On Wed, Feb 17, 2016 at 08:13:40PM +0100, Gerald Schaefer wrote:
> > On Sat, 13 Feb 2016 12:58:31 +0100 (CET)
> > Sebastian Ott <sebott@linux.vnet.ibm.com> wrote:
> >
> > > [ 59.875935] ------------[ cut here ]------------
> > > [ 59.875937] kernel BUG at mm/huge_memory.c:2884!
> > > [ 59.875979] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> > > [ 59.875986] Modules linked in: bridge stp llc btrfs xor mlx4_en vxlan ip6_udp_tunnel udp_tunnel mlx4_ib ptp pps_core ib_sa ib_mad ib_core ib_addr ghash_s390 prng raid6_pq ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 mlx4_core sha_common genwqe_card scm_block crc_itu_t vhost_net tun vhost dm_mod macvtap eadm_sch macvlan kvm autofs4
> > > [ 59.876033] CPU: 2 PID: 5402 Comm: git Tainted: G W 4.4.0-07794-ga4eff16-dirty #77
> > > [ 59.876036] task: 00000000d2312948 ti: 00000000cfecc000 task.ti: 00000000cfecc000
> > > [ 59.876039] Krnl PSW : 0704d00180000000 00000000002bf3aa (__split_huge_pmd_locked+0x562/0xa10)
> > > [ 59.876045] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 EA:3
> > > Krnl GPRS: 0000000001a7a1cf 000003d10177c000 0000000000044068 000000005df00215
> > > [ 59.876051] 0000000000000001 0000000000000001 0000000000000000 00000000774e6900
> > > [ 59.876054] 000003ff52000000 000000006d403b10 000000006e1eb800 000003ff51f00000
> > > [ 59.876058] 000003d10177c000 0000000000715190 00000000002bf234 00000000cfecfb58
> > > [ 59.876068] Krnl Code: 00000000002bf39c: d507d010a000 clc 16(8,%%r13),0(%%r10)
> > > 00000000002bf3a2: a7840004 brc 8,2bf3aa
> > > #00000000002bf3a6: a7f40001 brc 15,2bf3a8
> > > >00000000002bf3aa: 91407440 tm 1088(%%r7),64
> > > 00000000002bf3ae: a7840208 brc 8,2bf7be
> > > 00000000002bf3b2: a7f401e9 brc 15,2bf784
> > > 00000000002bf3b6: 9104a006 tm 6(%%r10),4
> > > 00000000002bf3ba: a7740004 brc 7,2bf3c2
> > > [ 59.876089] Call Trace:
> > > [ 59.876092] ([<00000000002bf234>] __split_huge_pmd_locked+0x3ec/0xa10)
> > > [ 59.876095] [<00000000002c4310>] __split_huge_pmd+0x118/0x218
> > > [ 59.876099] [<00000000002810e8>] unmap_single_vma+0x2d8/0xb40
> > > [ 59.876102] [<0000000000282d66>] zap_page_range+0x116/0x318
> > > [ 59.876105] [<000000000029b834>] SyS_madvise+0x23c/0x5e8
> > > [ 59.876108] [<00000000006f9f56>] system_call+0xd6/0x258
> > > [ 59.876111] [<000003ff9bbfd282>] 0x3ff9bbfd282
> > > [ 59.876113] INFO: lockdep is turned off.
> > > [ 59.876115] Last Breaking-Event-Address:
> > > [ 59.876118] [<00000000002bf3a6>] __split_huge_pmd_locked+0x55e/0xa10
> >
> > The BUG at mm/huge_memory.c:2884 is interesting, it's the BUG_ON(!pte_none(*pte))
> > check in __split_huge_pmd_locked(). Obviously we expect the pre-allocated
> > pagetables to be empty, but in collapse_huge_page() we deposit the original
> > pagetable instead of allocating a new (empty) one. This saves an allocation,
> > which is good, but doesn't that mean that if such a collapsed hugepage will
> > ever be split, we will always run into the BUG_ON(!pte_none(*pte)), or one
> > of the two other VM_BUG_ONs in mm/huge_memory.c that check the same?
> >
> > This behavior is not new, it was the same before the THP rework, so I do not
> > assume that it is related to the current problems, maybe with the exception
> > of this specific crash. I never saw the BUG at mm/huge_memory.c:2884 myself,
> > and the other crashes probably cannot be explained with this. Maybe I am
> > also missing something, but I do not see how collapse_huge_page() and the
> > (non-empty) pgtable deposit there can work out with the BUG_ON(!pte_none(*pte))
> > checks. Any thoughts?
>
> I don't think there's a problem: ptes in the pgtable are cleared with
> pte_clear() in __collapse_huge_page_copy().
>
Ah OK, I didn't see that. Still the BUG_ON() tells us that something went
wrong with the pre-allocated pagetable, or at least with the deposit/withdraw
list, or both. Given that on s390 we keep the listheads for the deposit/withdraw
list inside the pre-allocated pgtables, instead of the struct pages, it may
also explain why we see don't the problems on x86.
We already have the list corruption warning in exit_mmap -> zap_huge_pmd ->
withdraw, and from time to time I also hit the BUG_ON(page->pmd_huge_pte)
in exit_mmap -> free_pgtables -> free_pmd_range, which also indicates some
issues with the deposit/withdraw list, see below:
[ 2489.384069] page:000003d101aa6f00 count:1 mapcount:0 mapping: (null) index:0x0
[ 2489.384075] flags: 0x0()
[ 2489.384078] page dumped because: VM_BUG_ON_PAGE(page->pmd_huge_pte)
[ 2489.384086] ------------[ cut here ]------------
[ 2489.384088] kernel BUG at include/linux/mm.h:1700!
[ 2489.384131] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 2489.384137] Modules linked in: bridge stp llc mlx4_ib ib_sa ib_mad mlx4_en ib_core vxlan udp_tunnel ptp pps_core ib_addr ghash_s390 prng ecb mlx4_core aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 sha_common eadm_sch dm_mod vhost_net tun vhost macvtap macvlan kvm autofs4
[ 2489.384173] CPU: 5 PID: 173619 Comm: cc1 Tainted: G B W 4.5.0-rc3-00083-gc05235d #10
[ 2489.384176] task: 00000000c54d0000 ti: 0000000060504000 task.ti: 0000000060504000
[ 2489.384179] Krnl PSW : 0704c00180000000 0000000000283cf4 (free_pgd_range+0x334/0x460)
[ 2489.384184] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3
Krnl GPRS: 0000000001a161c7 0000000000000000 0000000000000037 0000000000000000
[ 2489.384189] 0000000000283cf0 0000000000000000 000003ff7d980000 0000000060507e18
[ 2489.384192] 000003ff00000000 0000000075e43ff0 000003ff7d97ffff 000003ff7d980000
[ 2489.384195] 000000006a9bc000 00000000006cc390 0000000000283cf0 0000000060507c68
[ 2489.384201] Krnl Code: 0000000000283ce4: c030002e14dd larl %%r3,84669e
0000000000283cea: c0e5ffffd217 brasl %%r14,27e118
#0000000000283cf0: a7f40001 brc 15,283cf2
>0000000000283cf4: c0e5fffffe5a brasl %%r14,2839a8
0000000000283cfa: b9040027 lgr %%r2,%%r7
0000000000283cfe: b904003c lgr %%r3,%%r12
0000000000283d02: c0e5fff509e3 brasl %%r14,1250c8
0000000000283d08: e31070000004 lg %%r1,0(%%r7)
[ 2489.384221] Call Trace:
[ 2489.384224] ([<0000000000283cf0>] free_pgd_range+0x330/0x460)
[ 2489.384227] [<0000000000283f38>] free_pgtables+0x118/0x148
[ 2489.384230] [<000000000028c32e>] exit_mmap+0xd6/0x300
[ 2489.384233] [<0000000000134d70>] mmput+0x90/0x118
[ 2489.384235] [<000000000013a55c>] do_exit+0x41c/0xd18
[ 2489.384238] [<000000000013c3c2>] do_group_exit+0x92/0xd8
[ 2489.384241] [<000000000013c432>] SyS_exit_group+0x2a/0x30
[ 2489.384244] [<00000000006b1a36>] system_call+0xd6/0x258
[ 2489.384246] [<000003ff7d343698>] 0x3ff7d343698
[ 2489.384248] INFO: lockdep is turned off.
[ 2489.384251] Last Breaking-Event-Address:
[ 2489.384253] [<0000000000283cf0>] free_pgd_range+0x330/0x460
[ 2489.384256]
[ 2489.384258] Kernel panic - not syncing: Fatal exception: panic_on_oops
I'll try to add a BUG_ON(pmd_huge(*pmd)) to free_pte_range() and see if that
catches anything, and I'll also check if debug_cow = 1 or use_zero_page = 0
makes any difference.
[toc] | [prev] | [next] | [standalone]
| From | "Kirill A. Shutemov" <kirill@shutemov.name> |
|---|---|
| Date | 2016-02-18 18:10 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3Afx-lQ-25@gated-at.bofh.it> |
| In reply to | #1337446 |
On Thu, Feb 18, 2016 at 04:00:37PM +0100, Gerald Schaefer wrote: > On Thu, 18 Feb 2016 01:58:08 +0200 > "Kirill A. Shutemov" <kirill@shutemov.name> wrote: > > > On Wed, Feb 17, 2016 at 08:13:40PM +0100, Gerald Schaefer wrote: > > > On Sat, 13 Feb 2016 12:58:31 +0100 (CET) > > > Sebastian Ott <sebott@linux.vnet.ibm.com> wrote: > > > > > > > [ 59.875935] ------------[ cut here ]------------ > > > > [ 59.875937] kernel BUG at mm/huge_memory.c:2884! > > > > [ 59.875979] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC > > > > [ 59.875986] Modules linked in: bridge stp llc btrfs xor mlx4_en vxlan ip6_udp_tunnel udp_tunnel mlx4_ib ptp pps_core ib_sa ib_mad ib_core ib_addr ghash_s390 prng raid6_pq ecb aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 mlx4_core sha_common genwqe_card scm_block crc_itu_t vhost_net tun vhost dm_mod macvtap eadm_sch macvlan kvm autofs4 > > > > [ 59.876033] CPU: 2 PID: 5402 Comm: git Tainted: G W 4.4.0-07794-ga4eff16-dirty #77 > > > > [ 59.876036] task: 00000000d2312948 ti: 00000000cfecc000 task.ti: 00000000cfecc000 > > > > [ 59.876039] Krnl PSW : 0704d00180000000 00000000002bf3aa (__split_huge_pmd_locked+0x562/0xa10) > > > > [ 59.876045] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 EA:3 > > > > Krnl GPRS: 0000000001a7a1cf 000003d10177c000 0000000000044068 000000005df00215 > > > > [ 59.876051] 0000000000000001 0000000000000001 0000000000000000 00000000774e6900 > > > > [ 59.876054] 000003ff52000000 000000006d403b10 000000006e1eb800 000003ff51f00000 > > > > [ 59.876058] 000003d10177c000 0000000000715190 00000000002bf234 00000000cfecfb58 > > > > [ 59.876068] Krnl Code: 00000000002bf39c: d507d010a000 clc 16(8,%%r13),0(%%r10) > > > > 00000000002bf3a2: a7840004 brc 8,2bf3aa > > > > #00000000002bf3a6: a7f40001 brc 15,2bf3a8 > > > > >00000000002bf3aa: 91407440 tm 1088(%%r7),64 > > > > 00000000002bf3ae: a7840208 brc 8,2bf7be > > > > 00000000002bf3b2: a7f401e9 brc 15,2bf784 > > > > 00000000002bf3b6: 9104a006 tm 6(%%r10),4 > > > > 00000000002bf3ba: a7740004 brc 7,2bf3c2 > > > > [ 59.876089] Call Trace: > > > > [ 59.876092] ([<00000000002bf234>] __split_huge_pmd_locked+0x3ec/0xa10) > > > > [ 59.876095] [<00000000002c4310>] __split_huge_pmd+0x118/0x218 > > > > [ 59.876099] [<00000000002810e8>] unmap_single_vma+0x2d8/0xb40 > > > > [ 59.876102] [<0000000000282d66>] zap_page_range+0x116/0x318 > > > > [ 59.876105] [<000000000029b834>] SyS_madvise+0x23c/0x5e8 > > > > [ 59.876108] [<00000000006f9f56>] system_call+0xd6/0x258 > > > > [ 59.876111] [<000003ff9bbfd282>] 0x3ff9bbfd282 > > > > [ 59.876113] INFO: lockdep is turned off. > > > > [ 59.876115] Last Breaking-Event-Address: > > > > [ 59.876118] [<00000000002bf3a6>] __split_huge_pmd_locked+0x55e/0xa10 > > > > > > The BUG at mm/huge_memory.c:2884 is interesting, it's the BUG_ON(!pte_none(*pte)) > > > check in __split_huge_pmd_locked(). Obviously we expect the pre-allocated > > > pagetables to be empty, but in collapse_huge_page() we deposit the original > > > pagetable instead of allocating a new (empty) one. This saves an allocation, > > > which is good, but doesn't that mean that if such a collapsed hugepage will > > > ever be split, we will always run into the BUG_ON(!pte_none(*pte)), or one > > > of the two other VM_BUG_ONs in mm/huge_memory.c that check the same? > > > > > > This behavior is not new, it was the same before the THP rework, so I do not > > > assume that it is related to the current problems, maybe with the exception > > > of this specific crash. I never saw the BUG at mm/huge_memory.c:2884 myself, > > > and the other crashes probably cannot be explained with this. Maybe I am > > > also missing something, but I do not see how collapse_huge_page() and the > > > (non-empty) pgtable deposit there can work out with the BUG_ON(!pte_none(*pte)) > > > checks. Any thoughts? > > > > I don't think there's a problem: ptes in the pgtable are cleared with > > pte_clear() in __collapse_huge_page_copy(). > > > > Ah OK, I didn't see that. Still the BUG_ON() tells us that something went > wrong with the pre-allocated pagetable, or at least with the deposit/withdraw > list, or both. Given that on s390 we keep the listheads for the deposit/withdraw > list inside the pre-allocated pgtables, instead of the struct pages, it may > also explain why we see don't the problems on x86. > > We already have the list corruption warning in exit_mmap -> zap_huge_pmd -> > withdraw, and from time to time I also hit the BUG_ON(page->pmd_huge_pte) > in exit_mmap -> free_pgtables -> free_pmd_range, which also indicates some > issues with the deposit/withdraw list, see below: > > [ 2489.384069] page:000003d101aa6f00 count:1 mapcount:0 mapping: (null) index:0x0 > [ 2489.384075] flags: 0x0() > [ 2489.384078] page dumped because: VM_BUG_ON_PAGE(page->pmd_huge_pte) > [ 2489.384086] ------------[ cut here ]------------ > [ 2489.384088] kernel BUG at include/linux/mm.h:1700! > [ 2489.384131] illegal operation: 0001 ilc:1 [#1] PREEMPT SMP DEBUG_PAGEALLOC > [ 2489.384137] Modules linked in: bridge stp llc mlx4_ib ib_sa ib_mad mlx4_en ib_core vxlan udp_tunnel ptp pps_core ib_addr ghash_s390 prng ecb mlx4_core aes_s390 des_s390 des_generic sha512_s390 sha256_s390 sha1_s390 sha_common eadm_sch dm_mod vhost_net tun vhost macvtap macvlan kvm autofs4 > [ 2489.384173] CPU: 5 PID: 173619 Comm: cc1 Tainted: G B W 4.5.0-rc3-00083-gc05235d #10 > [ 2489.384176] task: 00000000c54d0000 ti: 0000000060504000 task.ti: 0000000060504000 > [ 2489.384179] Krnl PSW : 0704c00180000000 0000000000283cf4 (free_pgd_range+0x334/0x460) > [ 2489.384184] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 EA:3 > Krnl GPRS: 0000000001a161c7 0000000000000000 0000000000000037 0000000000000000 > [ 2489.384189] 0000000000283cf0 0000000000000000 000003ff7d980000 0000000060507e18 > [ 2489.384192] 000003ff00000000 0000000075e43ff0 000003ff7d97ffff 000003ff7d980000 > [ 2489.384195] 000000006a9bc000 00000000006cc390 0000000000283cf0 0000000060507c68 > [ 2489.384201] Krnl Code: 0000000000283ce4: c030002e14dd larl %%r3,84669e > 0000000000283cea: c0e5ffffd217 brasl %%r14,27e118 > #0000000000283cf0: a7f40001 brc 15,283cf2 > >0000000000283cf4: c0e5fffffe5a brasl %%r14,2839a8 > 0000000000283cfa: b9040027 lgr %%r2,%%r7 > 0000000000283cfe: b904003c lgr %%r3,%%r12 > 0000000000283d02: c0e5fff509e3 brasl %%r14,1250c8 > 0000000000283d08: e31070000004 lg %%r1,0(%%r7) > [ 2489.384221] Call Trace: > [ 2489.384224] ([<0000000000283cf0>] free_pgd_range+0x330/0x460) > [ 2489.384227] [<0000000000283f38>] free_pgtables+0x118/0x148 > [ 2489.384230] [<000000000028c32e>] exit_mmap+0xd6/0x300 > [ 2489.384233] [<0000000000134d70>] mmput+0x90/0x118 > [ 2489.384235] [<000000000013a55c>] do_exit+0x41c/0xd18 > [ 2489.384238] [<000000000013c3c2>] do_group_exit+0x92/0xd8 > [ 2489.384241] [<000000000013c432>] SyS_exit_group+0x2a/0x30 > [ 2489.384244] [<00000000006b1a36>] system_call+0xd6/0x258 > [ 2489.384246] [<000003ff7d343698>] 0x3ff7d343698 > [ 2489.384248] INFO: lockdep is turned off. > [ 2489.384251] Last Breaking-Event-Address: > [ 2489.384253] [<0000000000283cf0>] free_pgd_range+0x330/0x460 > [ 2489.384256] > [ 2489.384258] Kernel panic - not syncing: Fatal exception: panic_on_oops > > I'll try to add a BUG_ON(pmd_huge(*pmd)) to free_pte_range() and see if that > catches anything, and I'll also check if debug_cow = 1 or use_zero_page = 0 > makes any difference. I worth minimizing kernel config on which you can see the bug. Things like CONFIG_DEBUG_PAGEALLOC used to interfere with THP before. You can also disable khugepaged, just in case. One more thing: try add smp_wmb() in pgtable_trans_huge_withdraw() just before return to make sure all CPUs sees _PAGE_INVALID. I don't think it would make a difference. Again, just in case. -- Kirill A. Shutemov
[toc] | [prev] | [next] | [standalone]
| From | Sebastian Ott <sebott@linux.vnet.ibm.com> |
|---|---|
| Date | 2016-02-19 15:20 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r3U4y-6g5-31@gated-at.bofh.it> |
| In reply to | #1337543 |
On Thu, 18 Feb 2016, Kirill A. Shutemov wrote: > I worth minimizing kernel config on which you can see the bug. Things like > CONFIG_DEBUG_PAGEALLOC used to interfere with THP before. I disabled all debugging options (using arch/s390/configs/performance_defconfig) - we still chrashed. Sebastian
[toc] | [prev] | [next] | [standalone]
| From | Gerald Schaefer <gerald.schaefer@de.ibm.com> |
|---|---|
| Date | 2016-02-15 17:50 +0100 |
| Subject | Re: [BUG] random kernel crashes after THP rework on s390 (maybe also on PowerPC and ARM) |
| Message-ID | <r2uvw-3zL-29@gated-at.bofh.it> |
| In reply to | #1333202 |
On Sat, 13 Feb 2016 01:15:10 +0200 "Kirill A. Shutemov" <kirill@shutemov.name> wrote: > > I'm trying to wrap my head around the issue and I don't think missing > serialization with gup_fast is the cause -- we just don't need it > anymore. > > Previously, __split_huge_page_splitting() required serialization against > gup_fast to make sure nobody can obtain new reference to the page after > __split_huge_page_splitting() returns. This was a way to stabilize page > references before starting to distribute them from head page to tail > pages. > > With new refcounting, we don't care about this. Splitting PMD is now > decoupled from splitting underlying compound page. It's okay to get new > pins after split_huge_pmd(). To stabilize page references during > split_huge_page() we rely on setting up migration entries once all > pmds are split into page table entries. > > The theory that serialization against gup_fast is not a root cause of the > crashes is consistent no crashes on arm64. Problem is somewhere else. Hmm, ok, I just relied on the commit message of commit fecffad25458, which talks about "pmdp_clear_flush() will do IPI as needed for fast_gup", as well as the comments in mm/gup.c, which also still talk about IPIs and THP splitting. If IPI serialization with fast_gup is not needed anymore for THP splitting, please fix at least the comments in mm/gup.c. > > > > (It also does some some other magic to the attach_count, which might hold off > > > finish_arch_post_lock_switch while some flushing is happening, but this should > > > be unrelated here) > > > > > > > > > > I'm also confused by pmd_none() is equal to !pmd_present() on s390. Hm? > > > > > > Don't know, Gerald or Martin? > > > > The implementation frequently changes depending on how many new bits Martin > > needs to squeeze out :-) > > One bit was freed up by the commit you've pointed to as a cause. > I wounder If it's possible that screw up something while removing it? I > don't see it, but who knows. > > Could you check if revert of fecffad25458 helps? I tried reverting fecffad25458, plus re-adding a call to pmdp_splitting_flush() in __split_huge_pmd_locked(), and I could still reproduce the crashes, so I guess it really isn't related to fast_gup vs. THP splitting. > > And could you share how crashes looks like? I haven't seen backtraces yet. > > > We don't have a _PAGE_PRESENT bit for pmds, so pmd_present() just checks if the > > entry is not empty. pmd_none() of course does the opposite, it checks if it is > > empty. >
[toc] | [prev] | [standalone]
Page 2 of 2 — ← Prev page 1 [2]
Back to top | Article view | linux.kernel
csiph-web