Re: divide error: 0000 [#1] SMP in task_numa_migrate - handle_mm_fault vanilla 4.4.6

[Stefan Priebe]

Am 19.03.2016 um 23:26 schrieb Vlastimil Babka:
> On 03/17/2016 07:45 PM, Greg KH wrote:
> > On Thu, Mar 17, 2016 at 07:38:03PM +0100, Stefan Priebe wrote:
> > > Hi,
> > >
> > > while running qemu 2.5 on a host running 4.4.6 the host system has
> > > crashed
> > > (load > 200) 3 times in the last 3 days.
> > >
> > > Always with this stack trace: (copy left here:
> > > http://pastebin.com/raw/bCWTLKyt)
> > >
> > > [69068.874268] divide error: 0000 [#1] SMP
> > > [69068.875242] Modules linked in: ebtable_filter ebtables ip6t_REJECT
> > > nf_reject_ipv6 nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter
> > > ip6_tables
> > > ipt_REJECT nf_reject_ipv4 xt_physdev xt_comment nf_conntrack_ipv4
> > > nf_defrag_ipv4 xt_tcpudp xt_mark xt_set xt_addrtype xt_conntrack
> > > nf_conntrack ip_set_hash_net ip_set vhost_net tun vhost macvtap macvlan
> > > kvm_intel nfnetlink_log kvm nfnetlink irqbypass netconsole dlm
> > > xt_multiport
> > > iptable_filter ip_tables x_tables iscsi_tcp libiscsi_tcp libiscsi
> > > scsi_transport_iscsi nfsd auth_rpcgss oid_registry bonding coretemp
> > > 8021q
> > > garp fuse i2c_i801 i7core_edac edac_core i5500_temp button btrfs xor
> > > raid6_pq dm_mod raid1 md_mod usb_storage ohci_hcd bcache sg usbhid
> > > sd_mod
> > > ata_generic uhci_hcd ehci_pci ehci_hcd usbcore ata_piix usb_common igb
> > > i2c_algo_bit mpt3sas raid_class ixgbe scsi_transport_sas i2c_core
> > > mdio ptp
> > > pps_core
> > > [69068.895604] CPU: 14 PID: 6673 Comm: ceph-osd Not tainted
> > > 4.4.6+7-ph #1
> > > [69068.897052] Hardware name: Supermicro X8DT3/X8DT3, BIOS 2.1
> > > 03/17/2012
> > > [69068.898578] task: ffff880fc7f28000 ti: ffff880fda2c4000 task.ti:
> > > ffff880fda2c4000
> > > [69068.900377] RIP: 0010:[<ffffffff860b372c>]  [<ffffffff860b372c>]
> > > task_h_load+0xcc/0x100
>
> decodecode says:
>
>    27:   48 83 c1 01             add    $0x1,%rcx
>    2b:*  48 f7 f1                div    %rcx             <-- trapping
> instruction
>
> This suggests the CONFIG_FAIR_GROUP_SCHED version of task_h_load:
>
>          update_cfs_rq_h_load(cfs_rq);
>          return div64_ul(p->se.avg.load_avg * cfs_rq->h_load,
>                          cfs_rq_load_avg(cfs_rq) + 1);
>
> So the load avg is -1, thus after adding 1 we get division by 0, huh?

Yes CONFIG_FAIR_GROUP_SCHED is set. I cherry picked now all those 
commits up to 4.5 for fair.c:
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/log/kernel/sched/fair.c?h=v4.5

It didn't happen again with v4.4.6 + 4.5 patches for fair.c

Greets,
Stefan

> > > [69068.961763] RSP: 0000:ffff880fda2c7b50  EFLAGS: 00010257
> > > [69069.023910] RAX: 0000000000000000 RBX: ffff880fda2c7c10 RCX:
> > > 0000000000000000
> > > [69069.085953] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
> > > ffff880fc7f28000
> > > [69069.151731] RBP: ffff880fda2c7bc8 R08: 00000001041955df R09:
> > > ffff880fffd153f8
> > > [69069.213757] R10: 0000000000000009 R11: 0000000000000193 R12:
> > > ffff881f6832c780
> > > [69069.274271] R13: ffff88203fc35380 R14: 0000000000000007 R15:
> > > 00000000000000b6
> > > [69069.334727] FS:  00007f578a3fb700(0000) GS:ffff880fffd00000(0000)
> > > knlGS:0000000000000000
> > > [69069.396435] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [69069.458522] CR2: 00007f5784f18468 CR3: 0000001fe9738000 CR4:
> > > 00000000000026e0
> > > [69069.520799] Stack:
> > > [69069.581430]  ffffffff860b6855 ffff880fda2c7b78 0000000000000000
> > > 0000000000000005
> > > [69069.642629]  ffff880fffd00000 0000000000000015 fffffffffffffe7d
> > > 0000000000000015
> > > [69069.702815]  0000000000015380 ffff880fda2c7bc8 ffff880fc7f28000
> > > 00000000000001e9
> > > [69069.761881] Call Trace:
> > > [69069.819883]  [<ffffffff860b6855>] ? task_numa_find_cpu+0x225/0x670
> > > [69069.878368]  [<ffffffff860b79f0>] task_numa_migrate+0x550/0x950
> > > [69069.936059]  [<ffffffff863d9138>] ? find_next_bit+0x18/0x20
> > > [69069.993262]  [<ffffffff860b7e6d>] numa_migrate_preferred+0x7d/0x90
> > > [69070.050528]  [<ffffffff860b89a5>] task_numa_fault+0x7c5/0xaa0
> > > [69070.106544]  [<ffffffff861a2c0b>] ? mpol_misplaced+0x16b/0x1b0
> > > [69070.163705]  [<ffffffff8618104e>] __handle_mm_fault+0x9ae/0x11f0
> > > [69070.220013]  [<ffffffff865e4c52>] ? inet_recvmsg+0x72/0x90
> > > [69070.276558]  [<ffffffff8655240b>] ? SYSC_recvfrom+0x12b/0x170
> > > [69070.332283]  [<ffffffff8618196f>] handle_mm_fault+0xdf/0x180
> > > [69070.388515]  [<ffffffff8604f324>] __do_page_fault+0x164/0x380
> > > [69070.443897]  [<ffffffff860b25c3>] ? account_user_time+0x73/0x80
> > > [69070.498534]  [<ffffffff860b2b3e>] ? vtime_account_user+0x4e/0x70
> > > [69070.552598]  [<ffffffff8604f5a7>] do_page_fault+0x37/0x90
> > > [69070.605960]  [<ffffffff86002a23>] ? syscall_return_slowpath+0x83/0xf0
> > > [69070.660705]  [<ffffffff866b32f8>] page_fault+0x28/0x30
> > > [69070.715707] Code: 86 b8 00 00 00 48 89 86 b0 00 00 00 48 85 c9 75
> > > ca 49
> > > 8b 81 b0 00 00 00 49 8b 49 78 31 d2 48 0f af 87 d8 01 00 00 5d 48 83
> > > c1 01
> > > <48> f7 f1 c3 4c 89 ce 48 8b 8e c0 00 00 00 48 8b 46 78 4c 89 86
> > > [69070.835144] RIP  [<ffffffff860b372c>] task_h_load+0xcc/0x100
> > > [69070.894095]  RSP <ffff880fda2c7b50>
> > > [69070.953213] ---[ end trace 8d6f449a03dacfd4 ]---
> > >
> > > Would be nice if we can fix this in 4.4?
> >
> > Does this also happen in 4.5?  Did this work on 4.4.5?  Some previous
> > release?  If you can find the offending patch using 'git bisect', that
> > would be great.
> >
> > thanks,
> >
> > greg k-h
> >
> > --
> > To unsubscribe, send a message with 'unsubscribe linux-mm' in
> > the body to majordomo@xxxxxxxxxx  For more info on Linux MM,
> > see: http://www.linux-mm.org/ .
> > Don't email: <a href=mailto:"dont@xxxxxxxxx";> email@xxxxxxxxx </a>