3.10-rc5 + the two patches referenced in the RCU thread from earlier.
Dave
[ 2313.381283] WARNING: at kernel/trace/ftrace.c:1605 __ftrace_hash_rec_update.part.37+0x20a/0x240()
[ 2313.386619] Modules linked in: fuse bnep rfcomm hidp can_bcm nfnetlink scsi_transport_iscsi can_raw nfc ipt_ULOG pppoe pppox ppp_generic slhc rose can af_rxrpc netrom phonet bluetooth rds af_802154 caif_socket caif ipx atm rfkill p8023 af_key p8022 ax25 llc2 irda decnet crc_ccitt appletalk psnap x25 llc nfsv3 nfs_acl nfs lockd sunrpc fscache coretemp hwmon kvm_intel snd_hda_codec_realtek kvm crc32c_intel ghash_clmulni_intel snd_hda_codec_hdmi microcode pcspkr snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm e1000e usb_debug ptp snd_page_alloc pps_core snd_timer snd soundcore xfs libcrc32c
[ 2313.411063] CPU: 1 PID: 19448 Comm: trinity-child2 Not tainted 3.10.0-rc5+ #7
[ 2313.424699] ffffffff81a1739e ffff880234f23ab0 ffffffff816e395b ffff880234f23ae8
[ 2313.427336] ffffffff8104a1b1 0000000000000000 0000000000000001 ffff8801b6c64000
[ 2313.429532] 0000000000000000 ffff8801b6c745a0 ffff880234f23af8 ffffffff8104a28a
[ 2313.431805] Call Trace:
[ 2313.433308] [<ffffffff816e395b>] dump_stack+0x19/0x1b
[ 2313.435306] [<ffffffff8104a1b1>] warn_slowpath_common+0x61/0x80
[ 2313.437254] [<ffffffff8104a28a>] warn_slowpath_null+0x1a/0x20
[ 2313.439175] [<ffffffff8110de3a>] __ftrace_hash_rec_update.part.37+0x20a/0x240
[ 2313.441392] [<ffffffff8110fe48>] ftrace_shutdown+0xb8/0x170
[ 2313.443301] [<ffffffff811102e0>] unregister_ftrace_function+0x30/0x50
[ 2313.445449] [<ffffffff8112d9c7>] perf_ftrace_event_register+0x87/0x130
[ 2313.447466] [<ffffffff8112d82c>] perf_trace_destroy+0x2c/0x50
[ 2313.449389] [<ffffffff81135469>] tp_perf_event_destroy+0x9/0x10
[ 2313.451336] [<ffffffff81136bec>] free_event+0x6c/0x190
[ 2313.453186] [<ffffffff81136d74>] perf_event_release_kernel+0x64/0x90
[ 2313.455299] [<ffffffff81138010>] put_event+0x120/0x1b0
[ 2313.457152] [<ffffffff81137f20>] ? put_event+0x30/0x1b0
[ 2313.459020] [<ffffffff811380b0>] perf_release+0x10/0x20
[ 2313.460886] [<ffffffff811ae4a5>] __fput+0xf5/0x2d0
[ 2313.462705] [<ffffffff811ae73e>] ____fput+0xe/0x10
[ 2313.464697] [<ffffffff810745ec>] task_work_run+0xac/0xe0
[ 2313.466571] [<ffffffff8104f3b3>] do_exit+0x2b3/0xcd0
[ 2313.468400] [<ffffffff81063709>] ? get_signal_to_deliver+0x299/0x940
[ 2313.470402] [<ffffffff810511bc>] do_group_exit+0x4c/0xc0
[ 2313.472279] [<ffffffff81063751>] get_signal_to_deliver+0x2e1/0x940
[ 2313.474264] [<ffffffff81002418>] do_signal+0x48/0x5a0
[ 2313.476266] [<ffffffff8108cdad>] ? get_parent_ip+0xd/0x50
[ 2313.478153] [<ffffffff810029e8>] do_notify_resume+0x78/0x90
[ 2313.480059] [<ffffffff816f510a>] int_signal+0x12/0x17
[ 2313.514533] ---[ end trace 0677af9739c508fb ]---
On Mon, 2013-06-10 at 19:48 -0400, Dave Jones wrote:
> 3.10-rc5 + the two patches referenced in the RCU thread from earlier.
>
> Dave
>
> [ 2313.381283] WARNING: at kernel/trace/ftrace.c:1605 __ftrace_hash_rec_update.part.37+0x20a/0x240()
Grumble,
Somehow the list of functions that perf enabled got out of sync with
what ftrace had. When perf disabled its list of functions from ftrace,
perf thought it had a function enabled that wasn't and ftrace cried
about that.
What does 'trinity-child2' do? and is this reproducible? I'll go and
investigate how perf integrates with ftrace to see if I can find how
things got out of sync.
Thanks,
-- Steve
> [ 2313.386619] Modules linked in: fuse bnep rfcomm hidp can_bcm nfnetlink scsi_transport_iscsi can_raw nfc ipt_ULOG pppoe pppox ppp_generic slhc rose can af_rxrpc netrom phonet bluetooth rds af_802154 caif_socket caif ipx atm rfkill p8023 af_key p8022 ax25 llc2 irda decnet crc_ccitt appletalk psnap x25 llc nfsv3 nfs_acl nfs lockd sunrpc fscache coretemp hwmon kvm_intel snd_hda_codec_realtek kvm crc32c_intel ghash_clmulni_intel snd_hda_codec_hdmi microcode pcspkr snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm e1000e usb_debug ptp snd_page_alloc pps_core snd_timer snd soundcore xfs libcrc32c
> [ 2313.411063] CPU: 1 PID: 19448 Comm: trinity-child2 Not tainted 3.10.0-rc5+ #7
> [ 2313.424699] ffffffff81a1739e ffff880234f23ab0 ffffffff816e395b ffff880234f23ae8
> [ 2313.427336] ffffffff8104a1b1 0000000000000000 0000000000000001 ffff8801b6c64000
> [ 2313.429532] 0000000000000000 ffff8801b6c745a0 ffff880234f23af8 ffffffff8104a28a
> [ 2313.431805] Call Trace:
> [ 2313.433308] [<ffffffff816e395b>] dump_stack+0x19/0x1b
> [ 2313.435306] [<ffffffff8104a1b1>] warn_slowpath_common+0x61/0x80
> [ 2313.437254] [<ffffffff8104a28a>] warn_slowpath_null+0x1a/0x20
> [ 2313.439175] [<ffffffff8110de3a>] __ftrace_hash_rec_update.part.37+0x20a/0x240
> [ 2313.441392] [<ffffffff8110fe48>] ftrace_shutdown+0xb8/0x170
> [ 2313.443301] [<ffffffff811102e0>] unregister_ftrace_function+0x30/0x50
> [ 2313.445449] [<ffffffff8112d9c7>] perf_ftrace_event_register+0x87/0x130
> [ 2313.447466] [<ffffffff8112d82c>] perf_trace_destroy+0x2c/0x50
> [ 2313.449389] [<ffffffff81135469>] tp_perf_event_destroy+0x9/0x10
> [ 2313.451336] [<ffffffff81136bec>] free_event+0x6c/0x190
> [ 2313.453186] [<ffffffff81136d74>] perf_event_release_kernel+0x64/0x90
> [ 2313.455299] [<ffffffff81138010>] put_event+0x120/0x1b0
> [ 2313.457152] [<ffffffff81137f20>] ? put_event+0x30/0x1b0
> [ 2313.459020] [<ffffffff811380b0>] perf_release+0x10/0x20
> [ 2313.460886] [<ffffffff811ae4a5>] __fput+0xf5/0x2d0
> [ 2313.462705] [<ffffffff811ae73e>] ____fput+0xe/0x10
> [ 2313.464697] [<ffffffff810745ec>] task_work_run+0xac/0xe0
> [ 2313.466571] [<ffffffff8104f3b3>] do_exit+0x2b3/0xcd0
> [ 2313.468400] [<ffffffff81063709>] ? get_signal_to_deliver+0x299/0x940
> [ 2313.470402] [<ffffffff810511bc>] do_group_exit+0x4c/0xc0
> [ 2313.472279] [<ffffffff81063751>] get_signal_to_deliver+0x2e1/0x940
> [ 2313.474264] [<ffffffff81002418>] do_signal+0x48/0x5a0
> [ 2313.476266] [<ffffffff8108cdad>] ? get_parent_ip+0xd/0x50
> [ 2313.478153] [<ffffffff810029e8>] do_notify_resume+0x78/0x90
> [ 2313.480059] [<ffffffff816f510a>] int_signal+0x12/0x17
> [ 2313.514533] ---[ end trace 0677af9739c508fb ]---
On Mon, Jun 10, 2013 at 08:33:14PM -0400, Steven Rostedt wrote:
> On Mon, 2013-06-10 at 19:48 -0400, Dave Jones wrote:
> > 3.10-rc5 + the two patches referenced in the RCU thread from earlier.
> >
> > Dave
> >
> > [ 2313.381283] WARNING: at kernel/trace/ftrace.c:1605 __ftrace_hash_rec_update.part.37+0x20a/0x240()
>
> Grumble,
>
> Somehow the list of functions that perf enabled got out of sync with
> what ftrace had. When perf disabled its list of functions from ftrace,
> perf thought it had a function enabled that wasn't and ftrace cried
> about that.
>
> What does 'trinity-child2' do?
Same as all the other child processes. Random syscalls, semi-intelligent args.
> and is this reproducible?
I'm sure I'll hit it again eventually. The This one looks tricky because
the trace isn't a syscall that I can go hammer on, it's happening
at process exit time.
Dave
On Mon, Jun 10, 2013 at 08:33:14PM -0400, Steven Rostedt wrote:
> On Mon, 2013-06-10 at 19:48 -0400, Dave Jones wrote:
> > 3.10-rc5 + the two patches referenced in the RCU thread from earlier.
> >
> > Dave
> >
> > [ 2313.381283] WARNING: at kernel/trace/ftrace.c:1605 __ftrace_hash_rec_update.part.37+0x20a/0x240()
>
> Grumble,
>
> Somehow the list of functions that perf enabled got out of sync with
> what ftrace had. When perf disabled its list of functions from ftrace,
> perf thought it had a function enabled that wasn't and ftrace cried
> about that.
>
> What does 'trinity-child2' do? and is this reproducible? I'll go and
> investigate how perf integrates with ftrace to see if I can find how
> things got out of sync.
Just hit this again on rc7. So 'reproducable' means "twice a month" apparently ;)
Though now that I have a fix for the lockups I was seeing, maybe I'll start
seeing this more frequently.
Dave
[ 393.396441] WARNING: at kernel/trace/ftrace.c:1605 __ftrace_hash_rec_update.part.37+0x20a/0x240()
[ 393.400825] Modules linked in: fuse tun bnep rfcomm ipt_ULOG nfnetlink can_bcm scsi_transport_iscsi can_raw appletalk netrom bluetooth irda af_802154 phonet af_rxrpc nfc rfkill can af_key rose atm ipx p8023 psnap p8022 caif_socket caif crc_ccitt rds llc2 llc ax25 x25 pppoe pppox ppp_generic slhc snd_hda_codec_realtek coretemp hwmon kvm_intel kvm snd_hda_codec_hdmi crc32c_intel ghash_clmulni_intel microcode snd_hda_intel snd_hda_codec pcspkr snd_hwdep usb_debug snd_seq snd_seq_device snd_pcm e1000e snd_page_alloc ptp snd_timer snd pps_core soundcore xfs libcrc32c
[ 393.484160] CPU: 2 PID: 19336 Comm: trinity-child0 Not tainted 3.10.0-rc7+ #37
[ 393.502497] ffffffff81a17636 ffff8801e49cdc68 ffffffff816e4662 ffff8801e49cdca0
[ 393.507648] ffffffff8104a0c1 0000000000000000 0000000000000001 ffff8801e3667000
[ 393.512670] 0000000000000000 ffff8801f1f4cb40 ffff8801e49cdcb0 ffffffff8104a19a
[ 393.520041] Call Trace:
[ 393.521408] [<ffffffff816e4662>] dump_stack+0x19/0x1b
[ 393.525699] [<ffffffff8104a0c1>] warn_slowpath_common+0x61/0x80
[ 393.529232] [<ffffffff8104a19a>] warn_slowpath_null+0x1a/0x20
[ 393.532732] [<ffffffff8110e3aa>] __ftrace_hash_rec_update.part.37+0x20a/0x240
[ 393.538897] [<ffffffff811103b8>] ftrace_shutdown+0xb8/0x170
[ 393.542390] [<ffffffff81110850>] unregister_ftrace_function+0x30/0x50
[ 393.547601] [<ffffffff8112e247>] perf_ftrace_event_register+0x87/0x130
[ 393.551518] [<ffffffff8112e0ac>] perf_trace_destroy+0x2c/0x50
[ 393.556096] [<ffffffff81135e09>] tp_perf_event_destroy+0x9/0x10
[ 393.559632] [<ffffffff81137481>] free_event+0xa1/0x1c0
[ 393.562751] [<ffffffff81137604>] perf_event_release_kernel+0x64/0x90
[ 393.568341] [<ffffffff811388a0>] put_event+0x120/0x1b0
[ 393.571456] [<ffffffff811387b0>] ? put_event+0x30/0x1b0
[ 393.574813] [<ffffffff81138940>] perf_release+0x10/0x20
[ 393.577944] [<ffffffff811af115>] __fput+0xf5/0x2d0
[ 393.580749] [<ffffffff811af3ae>] ____fput+0xe/0x10
[ 393.585035] [<ffffffff8107464c>] task_work_run+0xac/0xe0
[ 393.588187] [<ffffffff8104f35b>] do_exit+0x2bb/0xcd0
[ 393.592297] [<ffffffff816f5780>] ? ftrace_call+0x5/0x2f
[ 393.598091] [<ffffffff8105115c>] do_group_exit+0x4c/0xc0
[ 393.602355] [<ffffffff810511e4>] SyS_exit_group+0x14/0x20
[ 393.608055] [<ffffffff816f5d54>] tracesys+0xdd/0xe2
[ 393.620867] ---[ end trace 113d10486f2930c4 ]---