* [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel
@ 2014-09-15 12:34 mcermak at redhat dot com
2014-09-15 13:37 ` [Bug runtime/17393] " mcermak at redhat dot com
` (4 more replies)
0 siblings, 5 replies; 6+ messages in thread
From: mcermak at redhat dot com @ 2014-09-15 12:34 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
Bug ID: 17393
Summary: java.exp: ERROR: Cannot attach to module control
channel
Product: systemtap
Version: unspecified
Status: NEW
Severity: normal
Priority: P2
Component: runtime
Assignee: systemtap at sourceware dot org
Reporter: mcermak at redhat dot com
Running java.exp's singleparam.stp repeatedly on f20 shows that from time to
time (~ 50% of runs in my case) the testcase fails. In that case the testcase
produces an error and a zombie systemtap module is left in the kernel. This
never happens when stap is run in the verbose mode (-v). In verbose mode the
testcase seems to always pass:
=======
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
ERROR: Cannot attach to module stap_eb60c788b3b733806a89b60e3c953452_14967
control channel; not running?
ERROR: 'stap_eb60c788b3b733806a89b60e3c953452_14967' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
# lsmod | grep stap
stap_eb60c788b3b733806a89b60e3c953452_14967 178071 0
# lsmod | grep stap | awk '{print $1}' | xargs rmmod
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
ERROR: Cannot attach to module stap_eb60c788b3b733806a89b60e3c953452_16114
control channel; not running?
ERROR: 'stap_eb60c788b3b733806a89b60e3c953452_16114' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
# lsmod | grep stap
stap_eb60c788b3b733806a89b60e3c953452_16114 178071 0
# lsmod | grep stap | awk '{print $1}' | xargs rmmod
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
ERROR: Cannot attach to module stap_eb60c788b3b733806a89b60e3c953452_17261
control channel; not running?
ERROR: 'stap_eb60c788b3b733806a89b60e3c953452_17261' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
# lsmod | grep stap
stap_eb60c788b3b733806a89b60e3c953452_17261 178071 0
# lsmod | grep stap | awk '{print $1}' | xargs rmmod
# lsmod | grep stap
# stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
java("singleparam").class("singleparam").method("printMessage(int)") 42
java("singleparam").class("singleparam").method("printMessage(long)") 254775806
java("singleparam").class("singleparam").method("printMessage(double)") 3
java("singleparam").class("singleparam").method("printMessage(float)") 2345987
java("singleparam").class("singleparam").method("printMessage(byte)") 10
java("singleparam").class("singleparam").method("printMessage(boolean)") 1
java("singleparam").class("singleparam").method("printMessage(char)") 97
java("singleparam").class("singleparam").method("printMessage(short)") 14
ERROR: Cannot attach to module stap_eb60c788b3b733806a89b60e3c953452_17838
control channel; not running?
ERROR: 'stap_eb60c788b3b733806a89b60e3c953452_17838' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
#
=======
Versions used:
# uname -r; rpm -q systemtap java-1.7.0-openjdk
3.16.2-200.fc20.x86_64
systemtap-2.7-1.mcermak.b8056bd.fc20.x86_64
java-1.7.0-openjdk-1.7.0.65-2.5.2.5.fc20.x86_64
#
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
* [Bug runtime/17393] java.exp: ERROR: Cannot attach to module control channel
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
@ 2014-09-15 13:37 ` mcermak at redhat dot com
2014-09-15 13:41 ` mcermak at redhat dot com
` (3 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: mcermak at redhat dot com @ 2014-09-15 13:37 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
--- Comment #1 from Martin Cermak <mcermak at redhat dot com> ---
On RHEL7 similar behaviour can be observed except two things:
- the 'zombie module' issue happens even in the verbose mode and
- no probes are being hit (which isn't true in the previous post)
Details:
=======
7.0 S x86_64 # uname -r; rpm -q systemtap java-1.7.0-openjdk
3.10.0-131.el7.x86_64
systemtap-2.7-1.mcermak.5705063.el7.x86_64
java-1.7.0-openjdk-1.7.0.65-2.5.1.2.el7_0.x86_64
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
ERROR: Cannot attach to module stap_9cdab9fbf6e7162080002b330c28908a_13844
control channel; not running?
ERROR: 'stap_9cdab9fbf6e7162080002b330c28908a_13844' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
ERROR: Cannot attach to module stap_9cdab9fbf6e7162080002b330c28908a_13961
control channel; not running?
ERROR: 'stap_9cdab9fbf6e7162080002b330c28908a_13961' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
7.0 S x86_64 # lsmod | grep stap | awk '{print $1}' | xargs rmmod
7.0 S x86_64 # lsmod | grep stap
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
7.0 S x86_64 # java singleparam
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
ERROR: Cannot attach to module stap_9cdab9fbf6e7162080002b330c28908a_14456
control channel; not running?
ERROR: 'stap_9cdab9fbf6e7162080002b330c28908a_14456' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
7.0 S x86_64 # lsmod | grep stap
stap_9cdab9fbf6e7162080002b330c28908a_14456 239073 0
7.0 S x86_64 # lsmod | grep stap | awk '{print $1}' | xargs rmmod
7.0 S x86_64 # stap systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
ERROR: Cannot attach to module stap_9cdab9fbf6e7162080002b330c28908a_14581
control channel; not running?
ERROR: 'stap_9cdab9fbf6e7162080002b330c28908a_14581' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
7.0 S x86_64 # # NOW THE VERBOSE MODE
7.0 S x86_64 # stap -v systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
Pass 1: parsed user script and 114 library script(s) using
218196virt/35532res/3012shr/33084data kb, in 210usr/20sys/222real ms.
Pass 2: analyzed script: 32 probe(s), 5 function(s), 4 embed(s), 0 global(s)
using 219972virt/38464res/4068shr/34860data kb, in 30usr/70sys/97real ms.
Pass 3: using cached
/root/.systemtap/cache/9c/stap_9cdab9fbf6e7162080002b330c28908a_11075.c
Pass 4: using cached
/root/.systemtap/cache/9c/stap_9cdab9fbf6e7162080002b330c28908a_11075.ko
Pass 5: starting run.
Pass 5: run completed in 80usr/90sys/30418real ms.
7.0 S x86_64 # stap -v systemtap.apps/singleparam.stp -c "java singleparam
>/dev/null 2>&1"
Pass 1: parsed user script and 114 library script(s) using
218188virt/35532res/3012shr/33076data kb, in 200usr/10sys/220real ms.
Pass 2: analyzed script: 32 probe(s), 5 function(s), 4 embed(s), 0 global(s)
using 219964virt/38516res/4068shr/34852data kb, in 30usr/70sys/100real ms.
Pass 3: using cached
/root/.systemtap/cache/9c/stap_9cdab9fbf6e7162080002b330c28908a_11075.c
Pass 4: using cached
/root/.systemtap/cache/9c/stap_9cdab9fbf6e7162080002b330c28908a_11075.ko
Pass 5: starting run.
ERROR: Cannot attach to module stap_9cdab9fbf6e7162080002b330c28908a_14816
control channel; not running?
ERROR: 'stap_9cdab9fbf6e7162080002b330c28908a_14816' is not a zombie systemtap
module.
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run completed in 80usr/100sys/30422real ms.
Pass 5: run failed. [man error::pass5]
7.0 S x86_64 #
=======
I can provide more testing details or an access to testing box on demand.
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
* [Bug runtime/17393] java.exp: ERROR: Cannot attach to module control channel
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
2014-09-15 13:37 ` [Bug runtime/17393] " mcermak at redhat dot com
@ 2014-09-15 13:41 ` mcermak at redhat dot com
2016-03-08 15:52 ` dsmith at redhat dot com
` (2 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: mcermak at redhat dot com @ 2014-09-15 13:41 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
--- Comment #2 from Martin Cermak <mcermak at redhat dot com> ---
How to reproduce manually:
Either:
cd /usr/share/systemtap/testsuite
make RUNTESTFLAGS='java.exp' installcheck
Or:
cd /usr/share/systemtap/testsuite
javac -d ./ systemtap.apps/singleparam.java
stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
* [Bug runtime/17393] java.exp: ERROR: Cannot attach to module control channel
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
2014-09-15 13:37 ` [Bug runtime/17393] " mcermak at redhat dot com
2014-09-15 13:41 ` mcermak at redhat dot com
@ 2016-03-08 15:52 ` dsmith at redhat dot com
2016-03-08 22:36 ` dsmith at redhat dot com
2016-03-21 22:13 ` dsmith at redhat dot com
4 siblings, 0 replies; 6+ messages in thread
From: dsmith at redhat dot com @ 2016-03-08 15:52 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
David Smith <dsmith at redhat dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |dsmith at redhat dot com
--- Comment #3 from David Smith <dsmith at redhat dot com> ---
(In reply to Martin Cermak from comment #2)
> How to reproduce manually:
>
> Either:
> cd /usr/share/systemtap/testsuite
> make RUNTESTFLAGS='java.exp' installcheck
>
> Or:
> cd /usr/share/systemtap/testsuite
> javac -d ./ systemtap.apps/singleparam.java
> stap systemtap.apps/singleparam.stp -c "java singleparam >/dev/null 2>&1"
On f23 I'm still seeing this. It happens pretty regularly when running the test
case, but not as often when run by hand.
Here's the interesting part of the output when "-vvv" is added to the command
line. First, here's the output of a successful run:
====
stapio:stp_main_loop:782 got STP_EXIT
stapio:cleanup_and_exit:474 detach=0
stapio:close_relayfs:440 closing
stapio:close_relayfs:462 done
stapio:cleanup_and_exit:491 closing control channel
stapio:close_ctl_channel:112 Closed ctl fd 4
stapio:cleanup_and_exit:499
Renamed module to: stap_d6d5dc4cdf58d2cfe354504512002cb9_19483
stapio:cleanup_and_exit:506 removing
stap_d6d5dc4cdf58d2cfe354504512002cb9_19483
staprun:parse_modpath:458
modpath="/lib/modules/4.4.3-300.fc23.x86_64/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_19483.ko"
staprun:main:431
modpath="/lib/modules/4.4.3-300.fc23.x86_64/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_19483.ko",
modname="stap_d6d5dc4cdf58d2cfe354504512002cb9_19483"
staprun:init_staprun:337 init_staprun
staprun:remove_module:246 stap_d6d5dc4cdf58d2cfe354504512002cb9_19483
staprun:init_ctl_channel:72 Opened
/sys/kernel/debug/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_19483/.cmd
(4)
staprun:close_ctl_channel:112 Closed ctl fd 4
staprun:remove_module:271 removing module
stap_d6d5dc4cdf58d2cfe354504512002cb9_19483
staprun:remove_module:283 Module stap_d6d5dc4cdf58d2cfe354504512002cb9_19483
removed.
Spawn waitpid result (0x0): 0
====
Here's the output of a failure run:
====
stapio:stp_main_loop:782 got STP_EXIT
stapio:cleanup_and_exit:474 detach=0
stapio:close_relayfs:440 closing
stapio:close_relayfs:462 done
stapio:cleanup_and_exit:491 closing control channel
stapio:close_ctl_channel:112 Closed ctl fd 4
stapio:cleanup_and_exit:499
Renamed module to: stap_d6d5dc4cdf58d2cfe354504512002cb9_18888
stapio:cleanup_and_exit:506 removing
stap_d6d5dc4cdf58d2cfe354504512002cb9_18888
staprun:parse_modpath:458
modpath="/lib/modules/4.4.3-300.fc23.x86_64/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_18888.ko"
staprun:main:431
modpath="/lib/modules/4.4.3-300.fc23.x86_64/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_18888.ko",
modname="stap_d6d5dc4cdf58d2cfe354504512002cb9_18888"
staprun:init_staprun:337 init_staprun
staprun:remove_module:246 stap_d6d5dc4cdf58d2cfe354504512002cb9_18888
staprun:init_ctl_channel:72 Opened
/sys/kernel/debug/systemtap/stap_d6d5dc4cdf58d2cfe354504512002cb9_18888/.cmd
(-1)
ERROR: Cannot attach to module stap_d6d5dc4cdf58d2cfe354504512002cb9_18888
control channel; not running?
ERROR: 'stap_d6d5dc4cdf58d2cfe354504512002cb9_18888' is not a zombie systemtap
module.
Spawn waitpid result (0x100): 1
====
In the failure case, for some odd reason we get back into init_staprun() at
exit.
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
* [Bug runtime/17393] java.exp: ERROR: Cannot attach to module control channel
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
` (2 preceding siblings ...)
2016-03-08 15:52 ` dsmith at redhat dot com
@ 2016-03-08 22:36 ` dsmith at redhat dot com
2016-03-21 22:13 ` dsmith at redhat dot com
4 siblings, 0 replies; 6+ messages in thread
From: dsmith at redhat dot com @ 2016-03-08 22:36 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
--- Comment #4 from David Smith <dsmith at redhat dot com> ---
Created attachment 9075
--> https://sourceware.org/bugzilla/attachment.cgi?id=9075&action=edit
potential patch
After some debugging, I found that the open() of the control channel was
failing with EBUSY. So, I put the open in a loop to retry (for up to 10
seconds) if we get an EBUSY.
Note that I don't know why the module is busy then. Also note that this patch
doesn't fix the actual test case failures.
However, this patch does keep the module from being left behind.
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
* [Bug runtime/17393] java.exp: ERROR: Cannot attach to module control channel
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
` (3 preceding siblings ...)
2016-03-08 22:36 ` dsmith at redhat dot com
@ 2016-03-21 22:13 ` dsmith at redhat dot com
4 siblings, 0 replies; 6+ messages in thread
From: dsmith at redhat dot com @ 2016-03-21 22:13 UTC (permalink / raw)
To: systemtap
https://sourceware.org/bugzilla/show_bug.cgi?id=17393
David Smith <dsmith at redhat dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution|--- |FIXED
--- Comment #5 from David Smith <dsmith at redhat dot com> ---
It looks like what is going on here is that the java support code adds
synthetic begin and end probes that install and delete the java probes. When
the end probe happens, the system() function is run to delete the java probes.
Unfortunately, the control channel and relayfs file descriptors are passed down
to the child process, and if it is still running when the module tries to exit,
removing the module will fail. If the control channel is still open, you'll get
EAGAIN. If the relayfs file descriptors are still open, you'll get EBUSY.
Fixed in commit 9010bbb by making sure all file descriptors are closed when
needed and marked close-on-exec.
--
You are receiving this mail because:
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2016-03-21 22:13 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-09-15 12:34 [Bug runtime/17393] New: java.exp: ERROR: Cannot attach to module control channel mcermak at redhat dot com
2014-09-15 13:37 ` [Bug runtime/17393] " mcermak at redhat dot com
2014-09-15 13:41 ` mcermak at redhat dot com
2016-03-08 15:52 ` dsmith at redhat dot com
2016-03-08 22:36 ` dsmith at redhat dot com
2016-03-21 22:13 ` 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).