* [Bug runtime/14463] New: "scheduling while atomic" bug on rawhide
@ 2012-08-13 16:35 dsmith at redhat dot com
2012-08-13 19:45 ` [Bug runtime/14463] " dsmith at redhat dot com
2012-08-13 19:54 ` dsmith at redhat dot com
0 siblings, 2 replies; 3+ messages in thread
From: dsmith at redhat dot com @ 2012-08-13 16:35 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14463
Bug #: 14463
Summary: "scheduling while atomic" bug on rawhide
Product: systemtap
Version: unspecified
Status: NEW
Severity: normal
Priority: P2
Component: runtime
AssignedTo: systemtap@sourceware.org
ReportedBy: dsmith@redhat.com
Classification: Unclassified
On rawhide (3.6.0-0.rc1.git2.1.fc18.i686.PAE), I'm seeing the occasional
scheduling while atomic bug while running the utrace_p5.exp testcase.
Unfortunately, this bug doesn't happen reliably. I suspect this is related to
the new task_work changes.
====
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.072070] BUG: scheduling while
atomic: stapio/18575/0x00000002
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092802] INFO: lockdep is turned
off.
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092805] Modules linked in:
stap_5bf878fef954c812443ccb479a24218_18575(U) nfs3 nfs_acl nfs dns_resolver
fscache lockd sunrpc bnep bluetooth rfkill ip6table_filter ip6_tables
ebtable_nat ebtables be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4
cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad
ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi tpm_bios
snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm
snd_page_alloc snd_timer snd virtio_net virtio_balloon soundcore i2c_piix4
uinput virtio_blk cirrus drm_kms_helper ttm drm i2c_core [last unloaded:
stap_0e17f6a7ecf0e4370a154d9317d048e_18554]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092861] Pid: 18575, comm:
stapio Tainted: G S W 3.6.0-0.rc1.git2.1.fc18.i686.PAE #1
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092863] Call Trace:
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092873] [<c0a125f0>]
__schedule_bug+0x69/0x79
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092879] [<c0a1b822>]
__schedule+0x8c2/0x9a0
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092885] [<c06e75ff>] ?
debug_object_activate+0x5f/0x170
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092888] [<c06e7692>] ?
debug_object_activate+0xf2/0x170
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092893] [<c04b728b>] ?
trace_hardirqs_off+0xb/0x10
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092897] [<c0a1d2e5>] ?
_raw_spin_unlock_irqrestore+0x65/0x70
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092900] [<c06e7692>] ?
debug_object_activate+0xf2/0x170
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092904] [<c0a1946c>] ?
schedule_timeout+0x10c/0x2a0
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092907] [<c0a1bba3>]
schedule+0x23/0x60
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092910] [<c0a19471>]
schedule_timeout+0x111/0x2a0
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092915] [<c0464e30>] ?
__internal_add_timer+0xc0/0xc0
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092924] [<f85eb6d5>] ?
utrace_barrier+0x55/0x80 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092928] [<c0a1965a>]
schedule_timeout_interruptible+0x1a/0x20
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092933] [<f85eb6df>]
utrace_barrier+0x5f/0x80 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092939] [<f85edd51>]
__stp_utrace_attach+0x131/0x1f0 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092945] [<f85f0881>] ?
_stp_ctl_write_cmd+0xbe1/0xeb0 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092953] [<f85f0908>]
_stp_ctl_write_cmd+0xc68/0xeb0 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092958] [<f85f0800>] ?
_stp_ctl_write_cmd+0xb60/0xeb0 [stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092967] [<f85efca0>] ?
_stp_build_id_check.constprop.63+0xf0/0xf0
[stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092973] [<c058968c>]
vfs_write+0x8c/0x160
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092978] [<f85efca0>] ?
_stp_build_id_check.constprop.63+0xf0/0xf0
[stap_5bf878fef954c812443ccb479a24218_18575]
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092984] [<c058996d>]
sys_write+0x3d/0x70
Aug 13 11:29:41 kvm-rawhide-32-1 kernel: [10430.092989] [<c0a24a9f>]
sysenter_do_call+0x12/0x38
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.251082] BUG: scheduling while
atomic: stapio/20296/0x00000002
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272046] INFO: lockdep is turned
off.
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272050] Modules linked in:
stap_0e17f6a7ecf0e4370a154d9317d048e_20296(U) nfs3 nfs_acl nfs dns_resolver
fscache lockd sunrpc bnep bluetooth rfkill ip6table_filter ip6_tables
ebtable_nat ebtables be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4
cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad
ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi tpm_bios
snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm
snd_page_alloc snd_timer snd virtio_net virtio_balloon soundcore i2c_piix4
uinput virtio_blk cirrus drm_kms_helper ttm drm i2c_core [last unloaded:
stap_f02064cb371081465dfe69106058bb8_20273]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272115] Pid: 20296, comm:
stapio Tainted: G S W 3.6.0-0.rc1.git2.1.fc18.i686.PAE #1
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272117] Call Trace:
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272128] [<c0a125f0>]
__schedule_bug+0x69/0x79
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272134] [<c0a1b822>]
__schedule+0x8c2/0x9a0
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272140] [<c06e75ff>] ?
debug_object_activate+0x5f/0x170
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272143] [<c06e7692>] ?
debug_object_activate+0xf2/0x170
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272148] [<c04b728b>] ?
trace_hardirqs_off+0xb/0x10
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272152] [<c0a1d2e5>] ?
_raw_spin_unlock_irqrestore+0x65/0x70
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272155] [<c06e7692>] ?
debug_object_activate+0xf2/0x170
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272159] [<c0a1946c>] ?
schedule_timeout+0x10c/0x2a0
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272162] [<c0a1bba3>]
schedule+0x23/0x60
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272166] [<c0a19471>]
schedule_timeout+0x111/0x2a0
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272171] [<c0464e30>] ?
__internal_add_timer+0xc0/0xc0
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272180] [<f860df65>] ?
utrace_barrier+0x55/0x80 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272184] [<c0a1965a>]
schedule_timeout_interruptible+0x1a/0x20
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272190] [<f860df6f>]
utrace_barrier+0x5f/0x80 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272196] [<f8610ae1>]
__stp_utrace_attach+0x131/0x1f0 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272202] [<f8613af4>] ?
_stp_ctl_write_cmd+0xce4/0xfc0 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272208] [<f8613c0c>]
_stp_ctl_write_cmd+0xdfc/0xfc0 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272216] [<f8613a77>] ?
_stp_ctl_write_cmd+0xc67/0xfc0 [stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272227] [<f8612e10>] ?
_stp_build_id_check.constprop.86+0xf0/0xf0
[stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272232] [<c058968c>]
vfs_write+0x8c/0x160
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272237] [<f8612e10>] ?
_stp_build_id_check.constprop.86+0xf0/0xf0
[stap_0e17f6a7ecf0e4370a154d9317d048e_20296]
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272243] [<c058996d>]
sys_write+0x3d/0x70
Aug 13 11:30:59 kvm-rawhide-32-1 kernel: [10508.272247] [<c0a24a9f>]
sysenter_do_call+0x12/0x38
====
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 3+ messages in thread
* [Bug runtime/14463] "scheduling while atomic" bug on rawhide
2012-08-13 16:35 [Bug runtime/14463] New: "scheduling while atomic" bug on rawhide dsmith at redhat dot com
@ 2012-08-13 19:45 ` dsmith at redhat dot com
2012-08-13 19:54 ` dsmith at redhat dot com
1 sibling, 0 replies; 3+ messages in thread
From: dsmith at redhat dot com @ 2012-08-13 19:45 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14463
--- Comment #1 from David Smith <dsmith at redhat dot com> 2012-08-13 19:45:20 UTC ---
I believe I know what's going on here. When we find a new task, we call
__stp_utrace_attach() to attach to the child. __stp_utrace_attach() calls
utrace_set_events() to set the right events to look for. However, if
utrace_set_events() returns -EINPROGRESS we call utrace_barrier() to wait until
a current callback is finished.
__stp_utrace_attach() isn't safe enough be called from a tracepoint handler
since we're in atomic context there. We'll need to use the task_work feature
in a few more places to make it safe to call sleepy functions.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 3+ messages in thread
* [Bug runtime/14463] "scheduling while atomic" bug on rawhide
2012-08-13 16:35 [Bug runtime/14463] New: "scheduling while atomic" bug on rawhide dsmith at redhat dot com
2012-08-13 19:45 ` [Bug runtime/14463] " dsmith at redhat dot com
@ 2012-08-13 19:54 ` dsmith at redhat dot com
1 sibling, 0 replies; 3+ messages in thread
From: dsmith at redhat dot com @ 2012-08-13 19:54 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14463
David Smith <dsmith at redhat dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |ASSIGNED
AssignedTo|systemtap at sourceware dot |dsmith at redhat dot com
|org |
--- Comment #2 from David Smith <dsmith at redhat dot com> 2012-08-13 19:54:24 UTC ---
Note that this problem only happens when the target task we're attaching to
isn't 'current' (since utrace_barrier() always succeeds when target ==
current). I believe this only happens during task_finder2's clone event, when
we're trying to attach to the child (the parent task is current). We're ok
during the exec event, since the target is 'current'.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2012-08-13 19:54 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-08-13 16:35 [Bug runtime/14463] New: "scheduling while atomic" bug on rawhide dsmith at redhat dot com
2012-08-13 19:45 ` [Bug runtime/14463] " dsmith at redhat dot com
2012-08-13 19:54 ` dsmith at redhat dot com
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 read-only IMAP folder(s) and NNTP newsgroup(s).