public inbox for systemtap@sourceware.org
 help / color / mirror / Atom feed
* [Bug uprobes/11672] New: utrace_report_syscall_exit crash
@ 2010-06-08 11:07 mjw at redhat dot com
  2010-06-08 11:49 ` [Bug uprobes/11672] " fche at redhat dot com
                   ` (4 more replies)
  0 siblings, 5 replies; 11+ messages in thread
From: mjw at redhat dot com @ 2010-06-08 11:07 UTC (permalink / raw)
  To: systemtap

I get this oops sometimes. It involves utrace_report_syscall_exit going bad.
There is no simple reliable reproducer. It happens when I am stress testing
systemtap and have several scripts doing various uprobes.

BUG: unable to handle kernel paging request at ffffffffa0b10d00
IP: [<ffffffff810c7686>] utrace_report_syscall_exit+0x96/0xf0
PGD 1003067 PUD 1007063 PMD 104a7d067 PTE 0
Oops: 0000 [#1] SMP 
last sysfs file:
/sys/devices/pci0000:00/0000:00:1c.5/0000:01:00.0/net/eth0/statistics/tx_packets
CPU 4 
Modules linked in: uprobes(U) authenc(U) iptable_nat(U) nf_nat(U) ah6(U) ah4(U)
esp6(U) esp4(U) xfrm4_mode_beet(U) xfrm4_tunnel(U) xfrm4_mode_tunnel(U)
xfrm4_mode_transport(U) xfrm6_mode_transport(U) xfrm6_mode_ro(U)
xfrm6_mode_beet(U) xfrm6_mode_tunnel(U) ipcomp(U) ipcomp6(U) xfrm6_tunnel(U)
af_key(U) fuse(U) ip6table_filter(U) ip6_tables(U) ebtable_nat(U) ebtables(U)
netconsole(U) configfs(U) deflate(U) zlib_deflate(U) ctr(U) camellia(U) cast5(U)
rmd160(U) crypto_null(U) ccm(U) serpent(U) blowfish(U) twofish_x86_64(U)
twofish_common(U) ecb(U) xcbc(U) cbc(U) sha256_generic(U) sha512_generic(U)
des_generic(U) cryptd(U) aes_x86_64(U) aes_generic(U) tunnel4(U) xfrm_ipcomp(U)
tunnel6(U) nfsd(U) nfs_acl(U) auth_rpcgss(U) exportfs(U) autofs4(U) lockd(U)
sunrpc(U) cpufreq_ondemand(U) acpi_cpufreq(U) freq_table(U) bridge(U) stp(U)
llc(U) xt_physdev(U) be2iscsi(U) bnx2i(U) cnic(U) uio(U) cxgb3i(U) cxgb3(U)
mdio(U) ib_iser(U) rdma_cm(U) ib_cm(U) iw_cm(U) ib_sa(U) ib_mad(U) ib_core(U)
ib_addr(U) ipv6(U) iscsi_tcp(U) libiscsi_tcp(U) libiscsi(U)
scsi_transport_iscsi(U) ext3(U) jbd(U) dm_mirror(U) dm_region_hash(U) dm_log(U)
kvm_intel(U) kvm(U) uinput(U) snd_hda_codec_realtek(U) snd_hda_intel(U)
snd_hda_codec(U) snd_usb_audio(U) snd_seq(U) snd_pcm(U) snd_usb_lib(U)
snd_rawmidi(U) snd_timer(U) snd_seq_device(U) snd_hwdep(U) serio_raw(U) snd(U)
sg(U) tg3(U) i7core_edac(U) edac_core(U) soundcore(U) wmi(U) tpm_infineon(U)
snd_page_alloc(U) iTCO_wdt(U) iTCO_vendor_support(U) ext4(U) mbcache(U) jbd2(U)
raid456(U) async_raid6_recov(U) async_pq(U) raid6_pq(U) async_xor(U) xor(U)
async_memcpy(U) async_tx(U) sd_mod(U) crc_t10dif(U) firewire_ohci(U)
usb_storage(U) firewire_core(U) crc_itu_t(U) ahci(U) radeon(U) ttm(U)
drm_kms_helper(U) drm(U) i2c_algo_bit(U) i2c_core(U) dm_mod(U) [last unloaded:
stap_5a471983680cefbac658241d073264fb_77899]

Modules linked in: uprobes(U) authenc(U) iptable_nat(U) nf_nat(U) ah6(U) ah4(U)
esp6(U) esp4(U) xfrm4_mode_beet(U) xfrm4_tunnel(U) xfrm4_mode_tunnel(U)
xfrm4_mode_transport(U) xfrm6_mode_transport(U) xfrm6_mode_ro(U)
xfrm6_mode_beet(U) xfrm6_mode_tunnel(U) ipcomp(U) ipcomp6(U) xfrm6_tunnel(U)
af_key(U) fuse(U) ip6table_filter(U) ip6_tables(U) ebtable_nat(U) ebtables(U)
netconsole(U) configfs(U) deflate(U) zlib_deflate(U) ctr(U) camellia(U) cast5(U)
rmd160(U) crypto_null(U) ccm(U) serpent(U) blowfish(U) twofish_x86_64(U)
twofish_common(U) ecb(U) xcbc(U) cbc(U) sha256_generic(U) sha512_generic(U)
des_generic(U) cryptd(U) aes_x86_64(U) aes_generic(U) tunnel4(U) xfrm_ipcomp(U)
tunnel6(U) nfsd(U) nfs_acl(U) auth_rpcgss(U) exportfs(U) autofs4(U) lockd(U)
sunrpc(U) cpufreq_ondemand(U) acpi_cpufreq(U) freq_table(U) bridge(U) stp(U)
llc(U) xt_physdev(U) be2iscsi(U) bnx2i(U) cnic(U) uio(U) cxgb3i(U) cxgb3(U)
mdio(U) ib_iser(U) rdma_cm(U) ib_cm(U) iw_cm(U) ib_sa(U) ib_mad(U) ib_core(U)
ib_addr(U) ipv6(U) iscsi_tcp(U) libiscsi_tcp(U) libiscsi(U)
scsi_transport_iscsi(U) ext3(U) jbd(U) dm_mirror(U) dm_region_hash(U) dm_log(U)
kvm_intel(U) kvm(U) uinput(U) snd_hda_codec_realtek(U) snd_hda_intel(U)
snd_hda_codec(U) snd_usb_audio(U) snd_seq(U) snd_pcm(U) snd_usb_lib(U)
snd_rawmidi(U) snd_timer(U) snd_seq_device(U) snd_hwdep(U) serio_raw(U) snd(U)
sg(U) tg3(U) i7core_edac(U) edac_core(U) soundcore(U) wmi(U) tpm_infineon(U)
snd_page_alloc(U) iTCO_wdt(U) iTCO_vendor_support(U) ext4(U) mbcache(U) jbd2(U)
raid456(U) async_raid6_recov(U) async_pq(U) raid6_pq(U) async_xor(U) xor(U)
async_memcpy(U) async_tx(U) sd_mod(U) crc_t10dif(U) firewire_ohci(U)
usb_storage(U) firewire_core(U) crc_itu_t(U) ahci(U) radeon(U) ttm(U)
drm_kms_helper(U) drm(U) i2c_algo_bit(U) i2c_core(U) dm_mod(U) [last unloaded:
stap_5a471983680cefbac658241d073264fb_77899]
Pid: 11329, comm: run-mozilla.sh Tainted: G        W  2.6.32-33.el6.x86_64 #1 HP
Z400 Workstation
RIP: 0010:[<ffffffff810c7686>]  [<ffffffff810c7686>]
utrace_report_syscall_exit+0x96/0xf0
RSP: 0000:ffff88014fee7e00  EFLAGS: 00010282
RAX: ffffffffa0b10cd0 RBX: ffff880133d9fdb8 RCX: ffff8801161700c0
RDX: ffff88014fee7f58 RSI: ffff880133d9fdb8 RDI: 0000000000000005
RBP: ffff88014fee7e50 R08: 0000000000000080 R09: ffff8801161700c0
R10: ffff880193052950 R11: dead000000200200 R12: ffff88010a0eeca0
R13: ffff8801161700c0 R14: ffff88014fee7e10 R15: ffff88010a0eeca8
FS:  00007f5759dd2700(0000) GS:ffff880028280000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: ffffffffa0b10d00 CR3: 000000014fee8000 CR4: 00000000000026e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff4ff0 DR7: 0000000000000400
Process run-mozilla.sh (pid: 11329, threadinfo ffff88014fee6000, task
ffff8801161700c0)
Stack:
 0000000000000000 ffff88014fee7f58 0000000500000000 0000000100000005
<0> ffffffff8106e1b3 ffff88014fee7f58 ffff88014fee7f58 0000000000000001
<0> 0000000000000000 0000000000000000 ffff88014fee7f10 ffffffff8101eb2b
Call Trace:
 [<ffffffff8106e1b3>] ? wait_consider_task+0x7e3/0xb20
 [<ffffffff8101eb2b>] tracehook_report_syscall_exit+0xcb/0x120
 [<ffffffff8106e6e7>] ? do_wait+0x1f7/0x250
 [<ffffffff810d3449>] ? audit_syscall_exit+0x239/0x270
 [<ffffffff8101ebef>] syscall_trace_leave+0x6f/0xf0
 [<ffffffff8106cd50>] ? child_wait_callback+0x0/0x70
 [<ffffffff81013423>] int_check_syscall_exit_work+0x34/0x3d
Code: 00 00 00 00 00 41 b8 80 00 00 00 4c 89 e9 48 89 da 4c 89 f6 4c 89 e7 e8 29
e7 ff ff 48 85 c0 74 21 48 8b 55 b8 48 89 de 8b 7d c4 <ff> 50 30 48 89 d9 41 89
c0 4c 89 f2 4c 89 e6 4c 89 ef e8 c3 e5 
RIP  [<ffffffff810c7686>] utrace_report_syscall_exit+0x96/0xf0
 RSP <ffff88014fee7e00>
CR2: ffffffffa0b10d00
---[ end trace 407d787c552fbee3 ]---
Kernel panic - not syncing: Fatal exception
Pid: 11329, comm: run-mozilla.sh Tainted: G      D W  2.6.32-33.el6.x86_64 #1
Call Trace:
 [<ffffffff814d72ad>] panic+0x78/0x137
 [<ffffffff814db3e4>] oops_end+0xe4/0x100
 [<ffffffff8104545b>] no_context+0xfb/0x260
 [<ffffffff810456e5>] __bad_area_nosemaphore+0x125/0x1e0
 [<ffffffff810457b3>] bad_area_nosemaphore+0x13/0x20
 [<ffffffff814dcec8>] do_page_fault+0x2a8/0x3a0
 [<ffffffff814da735>] page_fault+0x25/0x30
 [<ffffffff810c7686>] ? utrace_report_syscall_exit+0x96/0xf0
 [<ffffffff8106e1b3>] ? wait_consider_task+0x7e3/0xb20
 [<ffffffff8101eb2b>] tracehook_report_syscall_exit+0xcb/0x120
 [<ffffffff8106e6e7>] ? do_wait+0x1f7/0x250
 [<ffffffff810d3449>] ? audit_syscall_exit+0x239/0x270
 [<ffffffff8101ebef>] syscall_trace_leave+0x6f/0xf0
 [<ffffffff8106cd50>] ? child_wait_callback+0x0/0x70
 [<ffffffff81013423>] int_check_syscall_exit_work+0x34/0x3d

-- 
           Summary: utrace_report_syscall_exit crash
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: uprobes
        AssignedTo: systemtap at sources dot redhat dot com
        ReportedBy: mjw at redhat dot com


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
@ 2010-06-08 11:49 ` fche at redhat dot com
  2010-06-08 15:51 ` mjw at redhat dot com
                   ` (3 subsequent siblings)
  4 siblings, 0 replies; 11+ messages in thread
From: fche at redhat dot com @ 2010-06-08 11:49 UTC (permalink / raw)
  To: systemtap


------- Additional Comments From fche at redhat dot com  2010-06-07 14:12 -------
Do you have slightly earlier kernel log data, to see whether that
address ffffffffa0b10d00 might have belonged to the recently
unloaded stap_5a471983680cefbac658241d073264fb_77899 module?

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
  2010-06-08 11:49 ` [Bug uprobes/11672] " fche at redhat dot com
@ 2010-06-08 15:51 ` mjw at redhat dot com
  2010-06-08 15:54 ` mjw at redhat dot com
                   ` (2 subsequent siblings)
  4 siblings, 0 replies; 11+ messages in thread
From: mjw at redhat dot com @ 2010-06-08 15:51 UTC (permalink / raw)
  To: systemtap


------- Additional Comments From mjw at redhat dot com  2010-06-07 14:57 -------
(In reply to comment #1)
> Do you have slightly earlier kernel log data, to see whether that
> address ffffffffa0b10d00 might have belonged to the recently
> unloaded stap_5a471983680cefbac658241d073264fb_77899 module?

The last two stap modules loaded where:

stap_ec5331d00f8db3443f0c883900fd96cb_77339: systemtap: 1.2/0.147, base: fffffff
fa0a84000, memory: 133data/42text/31ctx/13net/98alloc kb, probes: 140
stap_5a471983680cefbac658241d073264fb_77899: systemtap: 1.2/0.147, base: fffffff
fa0ab3000, memory: 133data/42text/31ctx/13net/98alloc kb, probes: 140


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
  2010-06-08 11:49 ` [Bug uprobes/11672] " fche at redhat dot com
  2010-06-08 15:51 ` mjw at redhat dot com
@ 2010-06-08 15:54 ` mjw at redhat dot com
  2010-06-09 22:26 ` mjw at redhat dot com
  2010-06-16 14:30 ` mjw at redhat dot com
  4 siblings, 0 replies; 11+ messages in thread
From: mjw at redhat dot com @ 2010-06-08 15:54 UTC (permalink / raw)
  To: systemtap


------- Additional Comments From mjw at redhat dot com  2010-06-07 15:08 -------
Wait, there are actually a couple more in the neighbourhood (was also running a
make installcheck at the same time):

stap_edbbec79eeb344df9dea92d2ffca2940_217463: systemtap: 1.2/0.147, base:
ffffffffa0b19000, memory: 64data/27text/29ctx/13net/2346alloc kb, probes: 564
stap_bc9111a9c6063bd1632422c9a94b8489_1197: systemtap: 1.2/0.147, base:
ffffffffa0b17000, memory: 46data/19text/9ctx/13net/76alloc kb, probes: 4
stap_0fee5aa333e805ca04a9c5a696b8d11d_9276: systemtap: 1.2/0.147, base:
ffffffffa0b12000, memory: 234data/41text/21ctx/13net/88alloc kb, probes: 12
stap_c9d2f79852a02794b01247cc585da70d_873: systemtap: 1.2/0.147, base:
ffffffffa0b12000, memory: 43data/18text/5ctx/13net/72alloc kb, probes: 1
stap_1f9d477af7c2d17d070d5d1f5b521751_3086: systemtap: 1.2/0.147, base:
ffffffffa0b14000, memory: 180data/26text/5ctx/13net/72alloc kb, probes: 3
stap_052558c882cf3dbba84c5322fd136dbc_9411: systemtap: 1.2/0.147, base:
ffffffffa0b1b000, memory: 234data/41text/21ctx/13net/88alloc kb, probes: 12
stap_e5cae574a0202ff31c280a21af00dbd6_614: systemtap: 1.2/0.147, base:
ffffffffa0b1b000, memory: 43data/18text/5ctx/13net/72alloc kb, probes: 1
stap_335ae717a25b53f625620eed0ae7bdad_1483: systemtap: 1.2/0.147, base:
ffffffffa0b1d000, memory: 60data/27text/5ctx/13net/72alloc kb, probes: 5


-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
                   ` (2 preceding siblings ...)
  2010-06-08 15:54 ` mjw at redhat dot com
@ 2010-06-09 22:26 ` mjw at redhat dot com
  2010-06-14 14:08   ` Roland McGrath
  2010-06-16 14:30 ` mjw at redhat dot com
  4 siblings, 1 reply; 11+ messages in thread
From: mjw at redhat dot com @ 2010-06-09 22:26 UTC (permalink / raw)
  To: systemtap


------- Additional Comments From mjw at redhat dot com  2010-06-09 14:39 -------
After reading the code I think we weren't handling utrace_control UTRACE_DETACH
returning -EINPROGRESS totally correctly. Which could theoretically lead to
unloading the module before the handlers were totally done (which could
theoretically lead to this crash). I tried to make the handling explicit in this
commit:

commit 9cb8092cf84d18e7435f03eef3963e01ea4e993f
Author: Mark Wielaard <mjw@redhat.com>
Date:   Wed Jun 9 11:50:48 2010 +0200

    Loop on utrace_barrier if utrace_control UTRACE_DETACH returns -EINPROGRESS.
    
    When utrace_control(tsk, eng, UTRACE_DETACH) returns -EINPROGRESS that
    means there are still handlers running. So loop on utrace_barrier(tsk, eng)
    in that case, till it no longer returns -ERESTARTSYS. That makes sure that
    no engine handler will be called afterwards, so we can safely unload the
    stap module. Not doing this might have caused PR11672
    (utrace_report_syscall_exit crash), although we don't yet have a simple
    reproducer for that issue.
    
    * runtime/itrace.c (remove_usr_itrace_info): Loop on utrace_barrier if
      utrace_control returned -EINPROGRESS.
    * runtime/task_finder.c (stap_utrace_detach): Likewise.
      (stap_utrace_detach_ops): Likewise. And warn if stap_utrace_detach
      didn't return successfully.
      (__stp_utrace_attach): Loop on -ERESTARTSYS after utrace_barrier.
      (__stp_utrace_task_finder_target_quiesce): Likewise.

I added a bit more error reporting in a followup commit, to catch anything going
wrong during detach:

commit 722a48dbe4ea51e798a137cb40663812126b2939
Author: Mark Wielaard <mjw@redhat.com>
Date:   Wed Jun 9 12:48:14 2010 +0200

    Add more error messages when something goes wrong during task_finder detach.
    
    * runtime/task_finder.c (stap_utrace_detach): Report when utrace_barrier
      fails.
      (stap_utrace_detach_ops): Report how stap_utrace_detach failed.

On irc roland said that newer utrace have a new enginer callback "release" that
is called when the engine (and its handlers) are totally done. We could use that
instead of trying to track things ourselves before unloading the module. But it
isn't available in older utrace implementations.

So far I haven't been able to reproduce the crash (with or without the above
patches). Still monitoring.

-- 


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-09 22:26 ` mjw at redhat dot com
@ 2010-06-14 14:08   ` Roland McGrath
  2010-06-14 14:49     ` Mark Wielaard
  2010-06-14 19:53     ` Frank Ch. Eigler
  0 siblings, 2 replies; 11+ messages in thread
From: Roland McGrath @ 2010-06-14 14:08 UTC (permalink / raw)
  To: Mark Wielaard; +Cc: systemtap

>       (__stp_utrace_attach): Loop on -ERESTARTSYS after utrace_barrier.
>       (__stp_utrace_task_finder_target_quiesce): Likewise.

That is a busy-wait loop, because -ERESTARTSYS means "signal is pending"
and that stays true without any blocking until you let it get back to user
mode (or almost, i.e. signal handling).  I don't really understand the
context of where these functions get called.  I'm guessing it is in some
control thread belonging to stapio or something like that.  In that case,
the signal pending is a SIGINT killing stapio or something like that I
suppose.  Is that the case?

This is a relatively "safe" busy-wait.  utrace_barrier will return 0 when
the tracee is all clear, not short-circuit because of signal_pending()
unless it actually has to block.  It's waiting for the tracee on the other
CPU to complete your callback, which should be pretty quick.  But it's
still a busy-wait that suddenly chews CPU in a spurt, and all quite fragile.

> On irc roland said that newer utrace have a new enginer callback
> "release" that is called when the engine (and its handlers) are totally
> done. We could use that instead of trying to track things ourselves
> before unloading the module. 

It's called on the last utrace_engine_put(), intended as what would release
whatever resources ->data points to.  Aside from your own refs, the "last"
engine ref is held by "attachedness", so it goes exactly when UTRACE_DETACH
(or implicit detach on reap) is complete--i.e., always after the very last
report_* callback that might ever be made to that engine.  So it makes
perfect sense as the place that "releases the hold" on stap module shutdown.

> But it isn't available in older utrace implementations.

I don't think anyone really cares about the intermediate utrace versions,
only the recent Fedora kernels (that have the current code), and RHEL5.  In
RHEL5 utrace, the API (and implementation) about this stuff is pretty
drastically different (no utrace_barrier).  I certainly don't really recall
all the racy corner details of that version, but I don't think it offers
any kind of synchronization option you can rely on short of quiescing the
thread before detach.

The only clearly safe alternative I see there is some giant synchronization
like stop_machine_run, off hand.  I'm trying to imagine a changed scenario
where you use module_get/module_put to prevent the module removal until the
detach is safely complete.  But I'm not sure how to do that without some
extra helper module that holds the callback routines so that they can use
module_put without undercutting their own code mapping.  And if you had
that, you probably wouldn't need to keep the script module refs at all in
the first place.  I think the forcible quiesce before detach is probably
the way to go.  RHEL5's utrace_detach has those signal-interruption side
effects anyway.  Then you just have to check for the sudden-death races
that utrace_detach's return value will alert you to.


Thanks,
Roland

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-14 14:08   ` Roland McGrath
@ 2010-06-14 14:49     ` Mark Wielaard
  2010-06-14 21:06       ` Roland McGrath
  2010-06-14 19:53     ` Frank Ch. Eigler
  1 sibling, 1 reply; 11+ messages in thread
From: Mark Wielaard @ 2010-06-14 14:49 UTC (permalink / raw)
  To: Roland McGrath; +Cc: systemtap

On Mon, 2010-06-14 at 01:40 -0700, Roland McGrath wrote:
> >       (__stp_utrace_attach): Loop on -ERESTARTSYS after utrace_barrier.
> >       (__stp_utrace_task_finder_target_quiesce): Likewise.
> 
> That is a busy-wait loop, because -ERESTARTSYS means "signal is pending"
> and that stays true without any blocking until you let it get back to user
> mode (or almost, i.e. signal handling).  I don't really understand the
> context of where these functions get called.  I'm guessing it is in some
> control thread belonging to stapio or something like that.  In that case,
> the signal pending is a SIGINT killing stapio or something like that I
> suppose.  Is that the case?

This is called from the task finder cleanup code and the utrace probe
exit code before the module tries to unload. There could be some signals
involved since we might unload the module by forking, executing and
waiting for a child, runstap -d, process to do it (this might happen
when the stap process gets a ^C). It also happens when a script calls
exit(), or someone explicitly calls rmmod on us. Precise description can
be found in runtime/transport/transport.txt (SHUTDOWN AND UNLOADING).

> This is a relatively "safe" busy-wait.  utrace_barrier will return 0 when
> the tracee is all clear, not short-circuit because of signal_pending()
> unless it actually has to block.  It's waiting for the tracee on the other
> CPU to complete your callback, which should be pretty quick.  But it's
> still a busy-wait that suddenly chews CPU in a spurt, and all quite fragile.

Busy-waiting is bad, so if there is an alternative that would be nice.
All we need is that if after a utrace_control UTRACE_DETACH we get an
-EINPROGRESS that we can wait till we are sure any pending handlers have
finished and that the detach fully succeeded.

Thanks,

Mark

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-14 14:08   ` Roland McGrath
  2010-06-14 14:49     ` Mark Wielaard
@ 2010-06-14 19:53     ` Frank Ch. Eigler
  1 sibling, 0 replies; 11+ messages in thread
From: Frank Ch. Eigler @ 2010-06-14 19:53 UTC (permalink / raw)
  To: Roland McGrath; +Cc: Mark Wielaard, systemtap


Roland McGrath <roland@redhat.com> writes:

> [...]  The only clearly safe alternative I see there is some giant
> synchronization like stop_machine_run, off hand.  [...]

Actually, why not.  One stop_machine_run per systemtap module shutdown
may well be tolerable.

- FChE

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-14 14:49     ` Mark Wielaard
@ 2010-06-14 21:06       ` Roland McGrath
  2010-06-14 21:32         ` Mark Wielaard
  0 siblings, 1 reply; 11+ messages in thread
From: Roland McGrath @ 2010-06-14 21:06 UTC (permalink / raw)
  To: Mark Wielaard; +Cc: systemtap

> This is called from the task finder cleanup code and the utrace probe
> exit code before the module tries to unload. 

From a quick glance I'm still not really clear on the important question:
what thread is current when calling into this code?

> Busy-waiting is bad, so if there is an alternative that would be nice.
> All we need is that if after a utrace_control UTRACE_DETACH we get an
> -EINPROGRESS that we can wait till we are sure any pending handlers have
> finished and that the detach fully succeeded.

As I said, utrace_barrier is that except that it's a busy-wait if
signal_pending().  The alternative requires changing your model such that
any waiting is via your own synchronization with your ops->release
function.


Thanks,
Roland

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-14 21:06       ` Roland McGrath
@ 2010-06-14 21:32         ` Mark Wielaard
  0 siblings, 0 replies; 11+ messages in thread
From: Mark Wielaard @ 2010-06-14 21:32 UTC (permalink / raw)
  To: Roland McGrath; +Cc: systemtap

On Mon, 2010-06-14 at 09:58 -0700, Roland McGrath wrote:
> > This is called from the task finder cleanup code and the utrace probe
> > exit code before the module tries to unload. 
> 
> From a quick glance I'm still not really clear on the important question:
> what thread is current when calling into this code?

I think it depends on which method of exiting/unloading is being used.
As far as I understand the code this is called from the proc transport
on response to an exit packet being writen to our .cmd file. Otherwise
it is done through DECLARE_DELAYED_WORK, but I am not completely sure
how that works. Maybe someone who hacked on the transport layer can
explain the precise interactions.

> > Busy-waiting is bad, so if there is an alternative that would be nice.
> > All we need is that if after a utrace_control UTRACE_DETACH we get an
> > -EINPROGRESS that we can wait till we are sure any pending handlers have
> > finished and that the detach fully succeeded.
> 
> As I said, utrace_barrier is that except that it's a busy-wait if
> signal_pending().  The alternative requires changing your model such that
> any waiting is via your own synchronization with your ops->release
> function.

OK, thanks. The current solution seems to make things more stable (I am
unable to trigger any crashes anymore). Lets not rewrite the whole
synchronization just for this small possibility of a busy wait. Unless
someone else wants to of course.

Cheers,

Mark

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug uprobes/11672] utrace_report_syscall_exit crash
  2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
                   ` (3 preceding siblings ...)
  2010-06-09 22:26 ` mjw at redhat dot com
@ 2010-06-16 14:30 ` mjw at redhat dot com
  4 siblings, 0 replies; 11+ messages in thread
From: mjw at redhat dot com @ 2010-06-16 14:30 UTC (permalink / raw)
  To: systemtap


------- Additional Comments From mjw at redhat dot com  2010-06-16 09:17 -------
Haven't been able to trigger anymore after patches from comment #4.

-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|                            |FIXED


http://sourceware.org/bugzilla/show_bug.cgi?id=11672

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2010-06-16  9:17 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2010-06-08 11:07 [Bug uprobes/11672] New: utrace_report_syscall_exit crash mjw at redhat dot com
2010-06-08 11:49 ` [Bug uprobes/11672] " fche at redhat dot com
2010-06-08 15:51 ` mjw at redhat dot com
2010-06-08 15:54 ` mjw at redhat dot com
2010-06-09 22:26 ` mjw at redhat dot com
2010-06-14 14:08   ` Roland McGrath
2010-06-14 14:49     ` Mark Wielaard
2010-06-14 21:06       ` Roland McGrath
2010-06-14 21:32         ` Mark Wielaard
2010-06-14 19:53     ` Frank Ch. Eigler
2010-06-16 14:30 ` mjw 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).