* [lttng-dev] deadlock in ust baddr 2.4.0-rc1
[not found] <553056004.74731.1385279999530.JavaMail.zimbra@efficios.com>
@ 2013-11-24 8:13 ` Mathieu Desnoyers
2013-11-25 11:30 ` Woegerer, Paul
2013-11-25 12:05 ` [lttng-dev] [PATCH] Allow suppressing of base-address-state tracing Paul Woegerer
0 siblings, 2 replies; 6+ messages in thread
From: Mathieu Desnoyers @ 2013-11-24 8:13 UTC (permalink / raw)
Hi Paul,
We are facing a deadlock with the UST baddr feature in 2.4.0-rc1. Here is how to
reproduce:
Build UST ae5f44dbf46c87c1318fde8ab5b5a68048e5af08 by following doc/java-util-logging.txt
Build tools 077df0b372f77833c1de2dd9f534dec9e75696de
Install into system + run lttng-sessiond as user (there is an issue David is working
on that prevents non-root applications to register to the root session daemon, so
make sure sessiond is not run as root for now).
run doc/examples/java-jul ./run file (in UST)
example output (all is OK, since no tracing is active):
24-Nov-2013 3:05:37 AM Hello main
INFO: Hello World, the answer is 42
Firing hello delay in 10 seconds...
24-Nov-2013 3:05:47 AM Hello main
INFO: Hello World delayed...
Cleaning Hello
Then start JUL tracing with:
lttng create
lttng enable-event -j -a
lttng start
./run
libust[3438/3439]: Error: Timed out waiting for lttng-sessiond (in lttng_ust_init() at lttng-ust-comm.c:1397)
even worse if:
LTTNG_UST_REGISTER_TIMEOUT=-1 ./run
The application deadlocks like this (on thread 2 in gdb):
(gdb) bt full
#0 __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
No locals.
#1 0x00007f78ce4c2354 in _L_lock_997 () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#2 0x00007f78ce4c21b7 in __pthread_mutex_lock (mutex=0x7f78ceb0c948) at pthread_mutex_lock.c:82
ignore1 = <optimized out>
ignore2 = <optimized out>
ignore3 = <optimized out>
__PRETTY_FUNCTION__ = "__pthread_mutex_lock"
type = 3467692360
#3 0x00007f78ce8fdadb in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#4 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
args = 0x7f78c5903520
#5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#6 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78c5903520) at dlerror.c:164
result = 0x1568b30
#7 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
args = {file = 0x7f78c69a7eb9 "liblttng-ust-baddr.so.0", mode = 258, new = 0x101010101010101, caller = 0x7f78c696d8a9}
#8 0x00007f78c696d8a9 in lttng_ust_baddr_handle () at lttng-ust-comm.c:249
__func__ = "lttng_ust_baddr_handle"
#9 0x00007f78c696d999 in lttng_ust_baddr_statedump (session=0x159ded0) at lttng-ust-comm.c:264
baddr_handle = 0xc69a7dd7
lttng_ust_baddr_init_fn = 0
__func__ = "lttng_ust_baddr_statedump"
#10 0x00007f78c6971317 in ust_listener_thread (arg=0x7f78c6bbd000) at lttng-ust-comm.c:1254
session = 0x159ded0
len = 612
lum = {handle = 1, cmd = 128, padding = '\000' <repeats 31 times>, u = {channel = {len = 0, type = LTTNG_UST_CHAN_PER_CPU,
padding = '\000' <repeats 287 times>, data = 0x7f78c5903d54 ""}, stream = {len = 0, stream_nr = 0,
padding = '\000' <repeats 287 times>}, event = {instrumentation = LTTNG_UST_TRACEPOINT,
name = '\000' <repeats 255 times>, loglevel_type = LTTNG_UST_LOGLEVEL_ALL, loglevel = 0,
padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}}, context = {
ctx = LTTNG_UST_CONTEXT_VTID, padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}},
version = {major = 0, minor = 0, patchlevel = 0}, tracepoint = {name = '\000' <repeats 255 times>, loglevel = 0,
padding = '\000' <repeats 15 times>}, filter = {data_size = 0, reloc_offset = 0, seqnum = 0}, exclusion = {
count = 0}, padding = '\000' <repeats 31 times>}}
sock_info = 0x7f78c6bbd000
sock = 15
ret = 0
prev_connect_failed = 0
has_waited = 0
timeout = -1
__func__ = "ust_listener_thread"
__PRETTY_FUNCTION__ = "ust_listener_thread"
#11 0x00007f78ce4bfb50 in start_thread (arg=<optimized out>) at pthread_create.c:304
__res = <optimized out>
pd = 0x7f78c5904700
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140156687369984, -4360901099104425548, 140156840281200, 140156687370688,
140156840493120, 3, 4434775346229094836, 4434756016842287540}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0,
0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call = <optimized out>
freesize = <optimized out>
__PRETTY_FUNCTION__ = "start_thread"
#12 0x00007f78cde01a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
It is deadlocked on the constructor awaiting for semaphore completion. The
mutex is probably the internal libc dynamic linker mutex held across
constructor execution:
#0 sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:86
No locals.
#1 0x00007f78c6971eb6 in lttng_ust_init () at lttng-ust-comm.c:1404
constructor_timeout = {tv_sec = 140736647255400, tv_nsec = 5}
sig_all_blocked = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
orig_parent_mask = {__val = {4, 140156702215847, 1, 140156702215909, 140153372803072, 140156840282096, 0, 140156594940184,
140156840281472, 140156840281496, 3467478208, 140156840282096, 140156709124528, 140156707014326, 140156833869240,
140156840308736}}
thread_attr = {
__size = "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\020", '\000' <repeats 37 times>,
__align = 0}
timeout_mode = -1
ret = 0
__PRETTY_FUNCTION__ = "lttng_ust_init"
__func__ = "lttng_ust_init"
#2 0x00007f78ce8f9f80 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#3 0x00007f78ce8fa077 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#4 0x00007f78ce8fe363 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#6 0x00007f78ce8fdb4a in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#7 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
args = 0x7f78cead8b20
#8 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
No symbol table info available.
#9 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78cead8b20) at dlerror.c:164
result = 0x14e2630
#10 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
args = {file = 0x7f78c00eb5f0 "/home/compudj/git/lttng-ust/liblttng-ust-jul/.libs/liblttng-ust-jul-jni.so.0.0.0", mode = 1,
new = 0x14ea800, caller = 0x7f78cd7abf9f}
#11 0x00007f78cd7abf9f in os::dll_load(char const*, char*, int) ()
from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
No symbol table info available.
#12 0x00007f78cd648f3f in JVM_LoadLibrary () from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
No symbol table info available.
#13 0x00007f78cc3799f7 in Java_java_lang_ClassLoader_00024NativeLibrary_load ()
from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/libjava.so
No symbol table info available.
#14 0x00007f78c8939d68 in ?? ()
No symbol table info available.
#15 0x00007f78cead95d0 in ?? ()
No symbol table info available.
#16 0x00007f78c892e85a in ?? ()
No symbol table info available.
#17 0x00007f78cead9580 in ?? ()
No symbol table info available.
#18 0x0000000000000000 in ?? ()
No symbol table info available.
So it looks like calling dlopen() from within lttng-ust is tricky, because it
introduces deadlocks with the dynamic linker.
Thoughts ?
Thanks,
Mathieu
--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
^ permalink raw reply [flat|nested] 6+ messages in thread
* [lttng-dev] deadlock in ust baddr 2.4.0-rc1
2013-11-24 8:13 ` [lttng-dev] deadlock in ust baddr 2.4.0-rc1 Mathieu Desnoyers
@ 2013-11-25 11:30 ` Woegerer, Paul
2013-11-25 12:22 ` Woegerer, Paul
2013-11-25 12:05 ` [lttng-dev] [PATCH] Allow suppressing of base-address-state tracing Paul Woegerer
1 sibling, 1 reply; 6+ messages in thread
From: Woegerer, Paul @ 2013-11-25 11:30 UTC (permalink / raw)
Hi Mathieu,
Hi David,
thanks for putting this together.
I'm now able to reproduce the problem and I'm investigating options to
circumvent the deadlock.
I will keep you informed on any progress made.
For the time being I will send a patch to prevent
lttng_ust_baddr_statedump if environment-variable
LTTNG_UST_WITHOUT_BADDR_STATEDUMP is set. This was already requested in
another context anyway. See:
http://lists.lttng.org/pipermail/lttng-dev/2013-November/021861.html
--
Thanks,
Paul
On 11/24/2013 09:13 AM, Mathieu Desnoyers wrote:
> Hi Paul,
>
> We are facing a deadlock with the UST baddr feature in 2.4.0-rc1. Here is how to
> reproduce:
>
> Build UST ae5f44dbf46c87c1318fde8ab5b5a68048e5af08 by following doc/java-util-logging.txt
> Build tools 077df0b372f77833c1de2dd9f534dec9e75696de
>
> Install into system + run lttng-sessiond as user (there is an issue David is working
> on that prevents non-root applications to register to the root session daemon, so
> make sure sessiond is not run as root for now).
>
> run doc/examples/java-jul ./run file (in UST)
>
> example output (all is OK, since no tracing is active):
>
> 24-Nov-2013 3:05:37 AM Hello main
> INFO: Hello World, the answer is 42
> Firing hello delay in 10 seconds...
> 24-Nov-2013 3:05:47 AM Hello main
> INFO: Hello World delayed...
> Cleaning Hello
>
> Then start JUL tracing with:
>
> lttng create
> lttng enable-event -j -a
> lttng start
>
> ./run
>
>
> libust[3438/3439]: Error: Timed out waiting for lttng-sessiond (in lttng_ust_init() at lttng-ust-comm.c:1397)
>
> even worse if:
>
> LTTNG_UST_REGISTER_TIMEOUT=-1 ./run
>
> The application deadlocks like this (on thread 2 in gdb):
>
>
> (gdb) bt full
> #0 __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
> No locals.
> #1 0x00007f78ce4c2354 in _L_lock_997 () from /lib/x86_64-linux-gnu/libpthread.so.0
> No symbol table info available.
> #2 0x00007f78ce4c21b7 in __pthread_mutex_lock (mutex=0x7f78ceb0c948) at pthread_mutex_lock.c:82
> ignore1 = <optimized out>
> ignore2 = <optimized out>
> ignore3 = <optimized out>
> __PRETTY_FUNCTION__ = "__pthread_mutex_lock"
> type = 3467692360
> #3 0x00007f78ce8fdadb in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #4 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
> args = 0x7f78c5903520
> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #6 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78c5903520) at dlerror.c:164
> result = 0x1568b30
> #7 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
> args = {file = 0x7f78c69a7eb9 "liblttng-ust-baddr.so.0", mode = 258, new = 0x101010101010101, caller = 0x7f78c696d8a9}
> #8 0x00007f78c696d8a9 in lttng_ust_baddr_handle () at lttng-ust-comm.c:249
> __func__ = "lttng_ust_baddr_handle"
> #9 0x00007f78c696d999 in lttng_ust_baddr_statedump (session=0x159ded0) at lttng-ust-comm.c:264
> baddr_handle = 0xc69a7dd7
> lttng_ust_baddr_init_fn = 0
> __func__ = "lttng_ust_baddr_statedump"
> #10 0x00007f78c6971317 in ust_listener_thread (arg=0x7f78c6bbd000) at lttng-ust-comm.c:1254
> session = 0x159ded0
> len = 612
> lum = {handle = 1, cmd = 128, padding = '\000' <repeats 31 times>, u = {channel = {len = 0, type = LTTNG_UST_CHAN_PER_CPU,
> padding = '\000' <repeats 287 times>, data = 0x7f78c5903d54 ""}, stream = {len = 0, stream_nr = 0,
> padding = '\000' <repeats 287 times>}, event = {instrumentation = LTTNG_UST_TRACEPOINT,
> name = '\000' <repeats 255 times>, loglevel_type = LTTNG_UST_LOGLEVEL_ALL, loglevel = 0,
> padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}}, context = {
> ctx = LTTNG_UST_CONTEXT_VTID, padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}},
> version = {major = 0, minor = 0, patchlevel = 0}, tracepoint = {name = '\000' <repeats 255 times>, loglevel = 0,
> padding = '\000' <repeats 15 times>}, filter = {data_size = 0, reloc_offset = 0, seqnum = 0}, exclusion = {
> count = 0}, padding = '\000' <repeats 31 times>}}
> sock_info = 0x7f78c6bbd000
> sock = 15
> ret = 0
> prev_connect_failed = 0
> has_waited = 0
> timeout = -1
> __func__ = "ust_listener_thread"
> __PRETTY_FUNCTION__ = "ust_listener_thread"
> #11 0x00007f78ce4bfb50 in start_thread (arg=<optimized out>) at pthread_create.c:304
> __res = <optimized out>
> pd = 0x7f78c5904700
> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140156687369984, -4360901099104425548, 140156840281200, 140156687370688,
> 140156840493120, 3, 4434775346229094836, 4434756016842287540}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0,
> 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
> not_first_call = <optimized out>
> freesize = <optimized out>
> __PRETTY_FUNCTION__ = "start_thread"
> #12 0x00007f78cde01a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
>
>
> It is deadlocked on the constructor awaiting for semaphore completion. The
> mutex is probably the internal libc dynamic linker mutex held across
> constructor execution:
>
>
> #0 sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:86
> No locals.
> #1 0x00007f78c6971eb6 in lttng_ust_init () at lttng-ust-comm.c:1404
> constructor_timeout = {tv_sec = 140736647255400, tv_nsec = 5}
> sig_all_blocked = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
> orig_parent_mask = {__val = {4, 140156702215847, 1, 140156702215909, 140153372803072, 140156840282096, 0, 140156594940184,
> 140156840281472, 140156840281496, 3467478208, 140156840282096, 140156709124528, 140156707014326, 140156833869240,
> 140156840308736}}
> thread_attr = {
> __size = "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\020", '\000' <repeats 37 times>,
> __align = 0}
> timeout_mode = -1
> ret = 0
> __PRETTY_FUNCTION__ = "lttng_ust_init"
> __func__ = "lttng_ust_init"
> #2 0x00007f78ce8f9f80 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #3 0x00007f78ce8fa077 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #4 0x00007f78ce8fe363 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #6 0x00007f78ce8fdb4a in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #7 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
> args = 0x7f78cead8b20
> #8 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> No symbol table info available.
> #9 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78cead8b20) at dlerror.c:164
> result = 0x14e2630
> #10 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
> args = {file = 0x7f78c00eb5f0 "/home/compudj/git/lttng-ust/liblttng-ust-jul/.libs/liblttng-ust-jul-jni.so.0.0.0", mode = 1,
> new = 0x14ea800, caller = 0x7f78cd7abf9f}
> #11 0x00007f78cd7abf9f in os::dll_load(char const*, char*, int) ()
> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
> No symbol table info available.
> #12 0x00007f78cd648f3f in JVM_LoadLibrary () from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
> No symbol table info available.
> #13 0x00007f78cc3799f7 in Java_java_lang_ClassLoader_00024NativeLibrary_load ()
> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/libjava.so
> No symbol table info available.
> #14 0x00007f78c8939d68 in ?? ()
> No symbol table info available.
> #15 0x00007f78cead95d0 in ?? ()
> No symbol table info available.
> #16 0x00007f78c892e85a in ?? ()
> No symbol table info available.
> #17 0x00007f78cead9580 in ?? ()
> No symbol table info available.
> #18 0x0000000000000000 in ?? ()
> No symbol table info available.
>
> So it looks like calling dlopen() from within lttng-ust is tricky, because it
> introduces deadlocks with the dynamic linker.
>
> Thoughts ?
>
> Thanks,
>
> Mathieu
>
--
Paul Woegerer, SW Development Engineer
Sourcery Analyzer <http://go.mentor.com/sourceryanalyzer>
Mentor Graphics, Embedded Software Division
^ permalink raw reply [flat|nested] 6+ messages in thread
* [lttng-dev] [PATCH] Allow suppressing of base-address-state tracing
2013-11-24 8:13 ` [lttng-dev] deadlock in ust baddr 2.4.0-rc1 Mathieu Desnoyers
2013-11-25 11:30 ` Woegerer, Paul
@ 2013-11-25 12:05 ` Paul Woegerer
1 sibling, 0 replies; 6+ messages in thread
From: Paul Woegerer @ 2013-11-25 12:05 UTC (permalink / raw)
If environment variable LTTNG_UST_WITHOUT_BADDR_STATEDUMP is set prior
to tracing base-address-state tracing on session-enable gets suppressed.
Signed-off-by: Paul Woegerer <paul_woegerer at mentor.com>
---
liblttng-ust/lttng-ust-comm.c | 3 +++
1 file changed, 3 insertions(+)
diff --git a/liblttng-ust/lttng-ust-comm.c b/liblttng-ust/lttng-ust-comm.c
index 77d8e3f..0b9c17d 100644
--- a/liblttng-ust/lttng-ust-comm.c
+++ b/liblttng-ust/lttng-ust-comm.c
@@ -260,6 +260,9 @@ int lttng_ust_baddr_statedump(struct lttng_session *session)
static
int (*lttng_ust_baddr_init_fn)(struct lttng_session *);
+ if (getenv("LTTNG_UST_WITHOUT_BADDR_STATEDUMP"))
+ return 0;
+
if (!lttng_ust_baddr_init_fn) {
void *baddr_handle = lttng_ust_baddr_handle();
if (baddr_handle) {
--
1.8.4
^ permalink raw reply [flat|nested] 6+ messages in thread
* [lttng-dev] deadlock in ust baddr 2.4.0-rc1
2013-11-25 11:30 ` Woegerer, Paul
@ 2013-11-25 12:22 ` Woegerer, Paul
2013-11-25 13:44 ` Mathieu Desnoyers
0 siblings, 1 reply; 6+ messages in thread
From: Woegerer, Paul @ 2013-11-25 12:22 UTC (permalink / raw)
I found a very simple way to prevent the deadlock situation.
Here again the jul sample that reproduces the issue:
pwoegere at atv-pwoegere-l3:~/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul>
./run
libust[2876/2877]: Error: Timed out waiting for lttng-sessiond (in
lttng_ust_init() at lttng-ust-comm.c:1400)
Nov 25, 2013 1:07:36 PM Hello main
INFO: Hello World, the answer is 42
Firing hello delay in 10 seconds...
Nov 25, 2013 1:07:46 PM Hello main
INFO: Hello World delayed...
Cleaning Hello
/home/pwoegere/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul
By using *LD_PRELOAD* we are able to make sure that the critical dlopen
turns into a null operation (thus the locking gets prevented):
pwoegere at atv-pwoegere-l3:~/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul>
*LD_PRELOAD=liblttng-ust-baddr.so.0 ./run*
Nov 25, 2013 1:08:42 PM Hello main
INFO: Hello World, the answer is 42
Firing hello delay in 10 seconds...
Nov 25, 2013 1:08:52 PM Hello main
INFO: Hello World delayed...
Cleaning Hello
/home/pwoegere/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul
Do you want me to restructure the base-address-state tracing code to
make the *LD_PRELOAD=liblttng-ust-baddr.so.0* approach the one and only
way to use it ?
Best,
Paul
On 11/25/2013 12:30 PM, Woegerer, Paul wrote:
> Hi Mathieu,
> Hi David,
>
> thanks for putting this together.
> I'm now able to reproduce the problem and I'm investigating options to
> circumvent the deadlock.
>
> I will keep you informed on any progress made.
>
> For the time being I will send a patch to prevent
> lttng_ust_baddr_statedump if environment-variable
> LTTNG_UST_WITHOUT_BADDR_STATEDUMP is set. This was already requested in
> another context anyway. See:
> http://lists.lttng.org/pipermail/lttng-dev/2013-November/021861.html
>
> --
> Thanks,
> Paul
>
>
> On 11/24/2013 09:13 AM, Mathieu Desnoyers wrote:
>> Hi Paul,
>>
>> We are facing a deadlock with the UST baddr feature in 2.4.0-rc1. Here is how to
>> reproduce:
>>
>> Build UST ae5f44dbf46c87c1318fde8ab5b5a68048e5af08 by following doc/java-util-logging.txt
>> Build tools 077df0b372f77833c1de2dd9f534dec9e75696de
>>
>> Install into system + run lttng-sessiond as user (there is an issue David is working
>> on that prevents non-root applications to register to the root session daemon, so
>> make sure sessiond is not run as root for now).
>>
>> run doc/examples/java-jul ./run file (in UST)
>>
>> example output (all is OK, since no tracing is active):
>>
>> 24-Nov-2013 3:05:37 AM Hello main
>> INFO: Hello World, the answer is 42
>> Firing hello delay in 10 seconds...
>> 24-Nov-2013 3:05:47 AM Hello main
>> INFO: Hello World delayed...
>> Cleaning Hello
>>
>> Then start JUL tracing with:
>>
>> lttng create
>> lttng enable-event -j -a
>> lttng start
>>
>> ./run
>>
>>
>> libust[3438/3439]: Error: Timed out waiting for lttng-sessiond (in lttng_ust_init() at lttng-ust-comm.c:1397)
>>
>> even worse if:
>>
>> LTTNG_UST_REGISTER_TIMEOUT=-1 ./run
>>
>> The application deadlocks like this (on thread 2 in gdb):
>>
>>
>> (gdb) bt full
>> #0 __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
>> No locals.
>> #1 0x00007f78ce4c2354 in _L_lock_997 () from /lib/x86_64-linux-gnu/libpthread.so.0
>> No symbol table info available.
>> #2 0x00007f78ce4c21b7 in __pthread_mutex_lock (mutex=0x7f78ceb0c948) at pthread_mutex_lock.c:82
>> ignore1 = <optimized out>
>> ignore2 = <optimized out>
>> ignore3 = <optimized out>
>> __PRETTY_FUNCTION__ = "__pthread_mutex_lock"
>> type = 3467692360
>> #3 0x00007f78ce8fdadb in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #4 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
>> args = 0x7f78c5903520
>> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #6 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78c5903520) at dlerror.c:164
>> result = 0x1568b30
>> #7 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
>> args = {file = 0x7f78c69a7eb9 "liblttng-ust-baddr.so.0", mode = 258, new = 0x101010101010101, caller = 0x7f78c696d8a9}
>> #8 0x00007f78c696d8a9 in lttng_ust_baddr_handle () at lttng-ust-comm.c:249
>> __func__ = "lttng_ust_baddr_handle"
>> #9 0x00007f78c696d999 in lttng_ust_baddr_statedump (session=0x159ded0) at lttng-ust-comm.c:264
>> baddr_handle = 0xc69a7dd7
>> lttng_ust_baddr_init_fn = 0
>> __func__ = "lttng_ust_baddr_statedump"
>> #10 0x00007f78c6971317 in ust_listener_thread (arg=0x7f78c6bbd000) at lttng-ust-comm.c:1254
>> session = 0x159ded0
>> len = 612
>> lum = {handle = 1, cmd = 128, padding = '\000' <repeats 31 times>, u = {channel = {len = 0, type = LTTNG_UST_CHAN_PER_CPU,
>> padding = '\000' <repeats 287 times>, data = 0x7f78c5903d54 ""}, stream = {len = 0, stream_nr = 0,
>> padding = '\000' <repeats 287 times>}, event = {instrumentation = LTTNG_UST_TRACEPOINT,
>> name = '\000' <repeats 255 times>, loglevel_type = LTTNG_UST_LOGLEVEL_ALL, loglevel = 0,
>> padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}}, context = {
>> ctx = LTTNG_UST_CONTEXT_VTID, padding = '\000' <repeats 15 times>, u = {padding = '\000' <repeats 287 times>}},
>> version = {major = 0, minor = 0, patchlevel = 0}, tracepoint = {name = '\000' <repeats 255 times>, loglevel = 0,
>> padding = '\000' <repeats 15 times>}, filter = {data_size = 0, reloc_offset = 0, seqnum = 0}, exclusion = {
>> count = 0}, padding = '\000' <repeats 31 times>}}
>> sock_info = 0x7f78c6bbd000
>> sock = 15
>> ret = 0
>> prev_connect_failed = 0
>> has_waited = 0
>> timeout = -1
>> __func__ = "ust_listener_thread"
>> __PRETTY_FUNCTION__ = "ust_listener_thread"
>> #11 0x00007f78ce4bfb50 in start_thread (arg=<optimized out>) at pthread_create.c:304
>> __res = <optimized out>
>> pd = 0x7f78c5904700
>> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140156687369984, -4360901099104425548, 140156840281200, 140156687370688,
>> 140156840493120, 3, 4434775346229094836, 4434756016842287540}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0,
>> 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>> not_first_call = <optimized out>
>> freesize = <optimized out>
>> __PRETTY_FUNCTION__ = "start_thread"
>> #12 0x00007f78cde01a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
>>
>>
>> It is deadlocked on the constructor awaiting for semaphore completion. The
>> mutex is probably the internal libc dynamic linker mutex held across
>> constructor execution:
>>
>>
>> #0 sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:86
>> No locals.
>> #1 0x00007f78c6971eb6 in lttng_ust_init () at lttng-ust-comm.c:1404
>> constructor_timeout = {tv_sec = 140736647255400, tv_nsec = 5}
>> sig_all_blocked = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
>> orig_parent_mask = {__val = {4, 140156702215847, 1, 140156702215909, 140153372803072, 140156840282096, 0, 140156594940184,
>> 140156840281472, 140156840281496, 3467478208, 140156840282096, 140156709124528, 140156707014326, 140156833869240,
>> 140156840308736}}
>> thread_attr = {
>> __size = "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\020", '\000' <repeats 37 times>,
>> __align = 0}
>> timeout_mode = -1
>> ret = 0
>> __PRETTY_FUNCTION__ = "lttng_ust_init"
>> __func__ = "lttng_ust_init"
>> #2 0x00007f78ce8f9f80 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #3 0x00007f78ce8fa077 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #4 0x00007f78ce8fe363 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #6 0x00007f78ce8fdb4a in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #7 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
>> args = 0x7f78cead8b20
>> #8 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
>> No symbol table info available.
>> #9 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00 <dlopen_doit>, args=0x7f78cead8b20) at dlerror.c:164
>> result = 0x14e2630
>> #10 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:88
>> args = {file = 0x7f78c00eb5f0 "/home/compudj/git/lttng-ust/liblttng-ust-jul/.libs/liblttng-ust-jul-jni.so.0.0.0", mode = 1,
>> new = 0x14ea800, caller = 0x7f78cd7abf9f}
>> #11 0x00007f78cd7abf9f in os::dll_load(char const*, char*, int) ()
>> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
>> No symbol table info available.
>> #12 0x00007f78cd648f3f in JVM_LoadLibrary () from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
>> No symbol table info available.
>> #13 0x00007f78cc3799f7 in Java_java_lang_ClassLoader_00024NativeLibrary_load ()
>> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/libjava.so
>> No symbol table info available.
>> #14 0x00007f78c8939d68 in ?? ()
>> No symbol table info available.
>> #15 0x00007f78cead95d0 in ?? ()
>> No symbol table info available.
>> #16 0x00007f78c892e85a in ?? ()
>> No symbol table info available.
>> #17 0x00007f78cead9580 in ?? ()
>> No symbol table info available.
>> #18 0x0000000000000000 in ?? ()
>> No symbol table info available.
>>
>> So it looks like calling dlopen() from within lttng-ust is tricky, because it
>> introduces deadlocks with the dynamic linker.
>>
>> Thoughts ?
>>
>> Thanks,
>>
>> Mathieu
>>
>
--
Paul Woegerer, SW Development Engineer
Sourcery Analyzer <http://go.mentor.com/sourceryanalyzer>
Mentor Graphics, Embedded Software Division
^ permalink raw reply [flat|nested] 6+ messages in thread
* [lttng-dev] deadlock in ust baddr 2.4.0-rc1
2013-11-25 12:22 ` Woegerer, Paul
@ 2013-11-25 13:44 ` Mathieu Desnoyers
2013-11-26 16:21 ` [lttng-dev] [PATCH] Make base-address-state tracing use LD_PRELOAD Paul Woegerer
0 siblings, 1 reply; 6+ messages in thread
From: Mathieu Desnoyers @ 2013-11-25 13:44 UTC (permalink / raw)
----- Original Message -----
> From: "Paul Woegerer" <Paul_Woegerer@mentor.com>
> To: "Mathieu Desnoyers" <mathieu.desnoyers at efficios.com>
> Cc: "lttng-dev" <lttng-dev at lists.lttng.org>
> Sent: Monday, November 25, 2013 7:22:41 AM
> Subject: Re: [lttng-dev] deadlock in ust baddr 2.4.0-rc1
>
> I found a very simple way to prevent the deadlock situation.
>
> Here again the jul sample that reproduces the issue:
>
> pwoegere at atv-pwoegere-l3:~/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul>
> ./run
> libust[2876/2877]: Error: Timed out waiting for lttng-sessiond (in
> lttng_ust_init() at lttng-ust-comm.c:1400)
> Nov 25, 2013 1:07:36 PM Hello main
> INFO: Hello World, the answer is 42
> Firing hello delay in 10 seconds...
> Nov 25, 2013 1:07:46 PM Hello main
> INFO: Hello World delayed...
> Cleaning Hello
> /home/pwoegere/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul
>
> By using *LD_PRELOAD* we are able to make sure that the critical dlopen
> turns into a null operation (thus the locking gets prevented):
>
> pwoegere at atv-pwoegere-l3:~/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul>
> *LD_PRELOAD=liblttng-ust-baddr.so.0 ./run*
> Nov 25, 2013 1:08:42 PM Hello main
> INFO: Hello World, the answer is 42
> Firing hello delay in 10 seconds...
> Nov 25, 2013 1:08:52 PM Hello main
> INFO: Hello World delayed...
> Cleaning Hello
> /home/pwoegere/MGC/lttng2_stack_latest/lttng-ust/doc/examples/java-jul
>
> Do you want me to restructure the base-address-state tracing code to
> make the *LD_PRELOAD=liblttng-ust-baddr.so.0* approach the one and only
> way to use it ?
Yes, that sounds like the proper way to fix this issue.
Thanks,
Matheiu
>
> Best,
> Paul
>
>
> On 11/25/2013 12:30 PM, Woegerer, Paul wrote:
> > Hi Mathieu,
> > Hi David,
> >
> > thanks for putting this together.
> > I'm now able to reproduce the problem and I'm investigating options to
> > circumvent the deadlock.
> >
> > I will keep you informed on any progress made.
> >
> > For the time being I will send a patch to prevent
> > lttng_ust_baddr_statedump if environment-variable
> > LTTNG_UST_WITHOUT_BADDR_STATEDUMP is set. This was already requested in
> > another context anyway. See:
> > http://lists.lttng.org/pipermail/lttng-dev/2013-November/021861.html
> >
> > --
> > Thanks,
> > Paul
> >
> >
> > On 11/24/2013 09:13 AM, Mathieu Desnoyers wrote:
> >> Hi Paul,
> >>
> >> We are facing a deadlock with the UST baddr feature in 2.4.0-rc1. Here is
> >> how to
> >> reproduce:
> >>
> >> Build UST ae5f44dbf46c87c1318fde8ab5b5a68048e5af08 by following
> >> doc/java-util-logging.txt
> >> Build tools 077df0b372f77833c1de2dd9f534dec9e75696de
> >>
> >> Install into system + run lttng-sessiond as user (there is an issue David
> >> is working
> >> on that prevents non-root applications to register to the root session
> >> daemon, so
> >> make sure sessiond is not run as root for now).
> >>
> >> run doc/examples/java-jul ./run file (in UST)
> >>
> >> example output (all is OK, since no tracing is active):
> >>
> >> 24-Nov-2013 3:05:37 AM Hello main
> >> INFO: Hello World, the answer is 42
> >> Firing hello delay in 10 seconds...
> >> 24-Nov-2013 3:05:47 AM Hello main
> >> INFO: Hello World delayed...
> >> Cleaning Hello
> >>
> >> Then start JUL tracing with:
> >>
> >> lttng create
> >> lttng enable-event -j -a
> >> lttng start
> >>
> >> ./run
> >>
> >>
> >> libust[3438/3439]: Error: Timed out waiting for lttng-sessiond (in
> >> lttng_ust_init() at lttng-ust-comm.c:1397)
> >>
> >> even worse if:
> >>
> >> LTTNG_UST_REGISTER_TIMEOUT=-1 ./run
> >>
> >> The application deadlocks like this (on thread 2 in gdb):
> >>
> >>
> >> (gdb) bt full
> >> #0 __lll_lock_wait () at
> >> ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:136
> >> No locals.
> >> #1 0x00007f78ce4c2354 in _L_lock_997 () from
> >> /lib/x86_64-linux-gnu/libpthread.so.0
> >> No symbol table info available.
> >> #2 0x00007f78ce4c21b7 in __pthread_mutex_lock (mutex=0x7f78ceb0c948) at
> >> pthread_mutex_lock.c:82
> >> ignore1 = <optimized out>
> >> ignore2 = <optimized out>
> >> ignore3 = <optimized out>
> >> __PRETTY_FUNCTION__ = "__pthread_mutex_lock"
> >> type = 3467692360
> >> #3 0x00007f78ce8fdadb in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #4 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
> >> args = 0x7f78c5903520
> >> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #6 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00
> >> <dlopen_doit>, args=0x7f78c5903520) at dlerror.c:164
> >> result = 0x1568b30
> >> #7 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized
> >> out>) at dlopen.c:88
> >> args = {file = 0x7f78c69a7eb9 "liblttng-ust-baddr.so.0", mode =
> >> 258, new = 0x101010101010101, caller = 0x7f78c696d8a9}
> >> #8 0x00007f78c696d8a9 in lttng_ust_baddr_handle () at
> >> lttng-ust-comm.c:249
> >> __func__ = "lttng_ust_baddr_handle"
> >> #9 0x00007f78c696d999 in lttng_ust_baddr_statedump (session=0x159ded0) at
> >> lttng-ust-comm.c:264
> >> baddr_handle = 0xc69a7dd7
> >> lttng_ust_baddr_init_fn = 0
> >> __func__ = "lttng_ust_baddr_statedump"
> >> #10 0x00007f78c6971317 in ust_listener_thread (arg=0x7f78c6bbd000) at
> >> lttng-ust-comm.c:1254
> >> session = 0x159ded0
> >> len = 612
> >> lum = {handle = 1, cmd = 128, padding = '\000' <repeats 31 times>,
> >> u = {channel = {len = 0, type = LTTNG_UST_CHAN_PER_CPU,
> >> padding = '\000' <repeats 287 times>, data = 0x7f78c5903d54
> >> ""}, stream = {len = 0, stream_nr = 0,
> >> padding = '\000' <repeats 287 times>}, event =
> >> {instrumentation = LTTNG_UST_TRACEPOINT,
> >> name = '\000' <repeats 255 times>, loglevel_type =
> >> LTTNG_UST_LOGLEVEL_ALL, loglevel = 0,
> >> padding = '\000' <repeats 15 times>, u = {padding = '\000'
> >> <repeats 287 times>}}, context = {
> >> ctx = LTTNG_UST_CONTEXT_VTID, padding = '\000' <repeats 15
> >> times>, u = {padding = '\000' <repeats 287 times>}},
> >> version = {major = 0, minor = 0, patchlevel = 0}, tracepoint =
> >> {name = '\000' <repeats 255 times>, loglevel = 0,
> >> padding = '\000' <repeats 15 times>}, filter = {data_size =
> >> 0, reloc_offset = 0, seqnum = 0}, exclusion = {
> >> count = 0}, padding = '\000' <repeats 31 times>}}
> >> sock_info = 0x7f78c6bbd000
> >> sock = 15
> >> ret = 0
> >> prev_connect_failed = 0
> >> has_waited = 0
> >> timeout = -1
> >> __func__ = "ust_listener_thread"
> >> __PRETTY_FUNCTION__ = "ust_listener_thread"
> >> #11 0x00007f78ce4bfb50 in start_thread (arg=<optimized out>) at
> >> pthread_create.c:304
> >> __res = <optimized out>
> >> pd = 0x7f78c5904700
> >> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140156687369984,
> >> -4360901099104425548, 140156840281200, 140156687370688,
> >> 140156840493120, 3, 4434775346229094836,
> >> 4434756016842287540}, mask_was_saved = 0}}, priv = {pad =
> >> {0x0, 0x0, 0x0,
> >> 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
> >> not_first_call = <optimized out>
> >> freesize = <optimized out>
> >> __PRETTY_FUNCTION__ = "start_thread"
> >> #12 0x00007f78cde01a7d in clone () at
> >> ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
> >>
> >>
> >> It is deadlocked on the constructor awaiting for semaphore completion. The
> >> mutex is probably the internal libc dynamic linker mutex held across
> >> constructor execution:
> >>
> >>
> >> #0 sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:86
> >> No locals.
> >> #1 0x00007f78c6971eb6 in lttng_ust_init () at lttng-ust-comm.c:1404
> >> constructor_timeout = {tv_sec = 140736647255400, tv_nsec = 5}
> >> sig_all_blocked = {__val = {18446744067267100671,
> >> 18446744073709551615 <repeats 15 times>}}
> >> orig_parent_mask = {__val = {4, 140156702215847, 1,
> >> 140156702215909, 140153372803072, 140156840282096, 0,
> >> 140156594940184,
> >> 140156840281472, 140156840281496, 3467478208, 140156840282096,
> >> 140156709124528, 140156707014326, 140156833869240,
> >> 140156840308736}}
> >> thread_attr = {
> >> __size =
> >> "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\020",
> >> '\000' <repeats 37 times>,
> >> __align = 0}
> >> timeout_mode = -1
> >> ret = 0
> >> __PRETTY_FUNCTION__ = "lttng_ust_init"
> >> __func__ = "lttng_ust_init"
> >> #2 0x00007f78ce8f9f80 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #3 0x00007f78ce8fa077 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #4 0x00007f78ce8fe363 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #5 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #6 0x00007f78ce8fdb4a in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #7 0x00007f78ce0b1f66 in dlopen_doit (a=<optimized out>) at dlopen.c:67
> >> args = 0x7f78cead8b20
> >> #8 0x00007f78ce8f9bd6 in ?? () from /lib64/ld-linux-x86-64.so.2
> >> No symbol table info available.
> >> #9 0x00007f78ce0b22ec in _dlerror_run (operate=0x7f78ce0b1f00
> >> <dlopen_doit>, args=0x7f78cead8b20) at dlerror.c:164
> >> result = 0x14e2630
> >> #10 0x00007f78ce0b1ee1 in __dlopen (file=<optimized out>, mode=<optimized
> >> out>) at dlopen.c:88
> >> args = {file = 0x7f78c00eb5f0
> >> "/home/compudj/git/lttng-ust/liblttng-ust-jul/.libs/liblttng-ust-jul-jni.so.0.0.0",
> >> mode = 1,
> >> new = 0x14ea800, caller = 0x7f78cd7abf9f}
> >> #11 0x00007f78cd7abf9f in os::dll_load(char const*, char*, int) ()
> >> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
> >> No symbol table info available.
> >> #12 0x00007f78cd648f3f in JVM_LoadLibrary () from
> >> /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server/libjvm.so
> >> No symbol table info available.
> >> #13 0x00007f78cc3799f7 in
> >> Java_java_lang_ClassLoader_00024NativeLibrary_load ()
> >> from /usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/libjava.so
> >> No symbol table info available.
> >> #14 0x00007f78c8939d68 in ?? ()
> >> No symbol table info available.
> >> #15 0x00007f78cead95d0 in ?? ()
> >> No symbol table info available.
> >> #16 0x00007f78c892e85a in ?? ()
> >> No symbol table info available.
> >> #17 0x00007f78cead9580 in ?? ()
> >> No symbol table info available.
> >> #18 0x0000000000000000 in ?? ()
> >> No symbol table info available.
> >>
> >> So it looks like calling dlopen() from within lttng-ust is tricky, because
> >> it
> >> introduces deadlocks with the dynamic linker.
> >>
> >> Thoughts ?
> >>
> >> Thanks,
> >>
> >> Mathieu
> >>
> >
>
>
> --
> Paul Woegerer, SW Development Engineer
> Sourcery Analyzer <http://go.mentor.com/sourceryanalyzer>
> Mentor Graphics, Embedded Software Division
>
>
--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
^ permalink raw reply [flat|nested] 6+ messages in thread
* [lttng-dev] [PATCH] Make base-address-state tracing use LD_PRELOAD
2013-11-25 13:44 ` Mathieu Desnoyers
@ 2013-11-26 16:21 ` Paul Woegerer
0 siblings, 0 replies; 6+ messages in thread
From: Paul Woegerer @ 2013-11-26 16:21 UTC (permalink / raw)
Signed-off-by: Paul Woegerer <paul_woegerer at mentor.com>
---
liblttng-ust-baddr/Makefile.am | 2 -
liblttng-ust-baddr/lttng-ust-baddr.c | 45 ++++---------
liblttng-ust-baddr/lttng-ust-baddr.h | 22 +++++++
liblttng-ust-dl/Makefile.am | 5 +-
.../ust_baddr.c | 0
.../ust_baddr.h | 0
liblttng-ust-dl/ustdl.c | 76 ++++++----------------
liblttng-ust/lttng-ust-comm.c | 43 +-----------
8 files changed, 62 insertions(+), 131 deletions(-)
create mode 100644 liblttng-ust-baddr/lttng-ust-baddr.h
rename {liblttng-ust-baddr => liblttng-ust-dl}/ust_baddr.c (100%)
rename {liblttng-ust-baddr => liblttng-ust-dl}/ust_baddr.h (100%)
diff --git a/liblttng-ust-baddr/Makefile.am b/liblttng-ust-baddr/Makefile.am
index 0d3cf28..23e4ce2 100644
--- a/liblttng-ust-baddr/Makefile.am
+++ b/liblttng-ust-baddr/Makefile.am
@@ -4,8 +4,6 @@ AM_CFLAGS = -fno-strict-aliasing
lib_LTLIBRARIES = liblttng-ust-baddr.la
liblttng_ust_baddr_la_SOURCES = \
lttng-ust-baddr.c \
- ust_baddr.c \
- ust_baddr.h \
ust_baddr_statedump.c \
ust_baddr_statedump.h
liblttng_ust_baddr_la_LIBADD = \
diff --git a/liblttng-ust-baddr/lttng-ust-baddr.c b/liblttng-ust-baddr/lttng-ust-baddr.c
index a856965..bc3c1ed 100644
--- a/liblttng-ust-baddr/lttng-ust-baddr.c
+++ b/liblttng-ust-baddr/lttng-ust-baddr.c
@@ -32,38 +32,11 @@
#include <stdio.h>
#include "usterr.h"
+#include "lttng-ust-baddr.h"
+
#define TRACEPOINT_DEFINE
-#include "ust_baddr.h"
#include "ust_baddr_statedump.h"
-int
-lttng_ust_push_baddr(void *so_base, const char *so_name)
-{
- char resolved_path[PATH_MAX];
- struct stat sostat;
-
- if (!realpath(so_name, resolved_path)) {
- ERR("could not resolve path '%s'", so_name);
- return 0;
- }
-
- if (stat(resolved_path, &sostat)) {
- ERR("could not access file status for %s", resolved_path);
- return 0;
- }
-
- tracepoint(ust_baddr, push,
- so_base, resolved_path, sostat.st_size, sostat.st_mtime);
- return 0;
-}
-
-int
-lttng_ust_pop_baddr(void *so_base)
-{
- tracepoint(ust_baddr, pop, so_base);
- return 0;
-}
-
static int
extract_soinfo_events(struct dl_phdr_info *info, size_t size, void *data)
{
@@ -129,8 +102,18 @@ lttng_ust_baddr_statedump(struct lttng_session *session)
{
/*
* Iterate through the list of currently loaded shared objects and
- * generate events for loadable segments using extract_soinfo_events
+ * generate events for loadable segments using extract_soinfo_events.
+ *
+ * The use of dlopen is required to make sure tracepoint registration
+ * happens before using the tracepoint in extract_soinfo_events().
*/
- dl_iterate_phdr(extract_soinfo_events, session);
+ void *dlref = dlopen("liblttng-ust-baddr.so.0", RTLD_NOW | RTLD_GLOBAL);
+ if (dlref) {
+ dl_iterate_phdr(extract_soinfo_events, session);
+ dlclose(dlref);
+ } else {
+ fprintf(stderr, "%s\n", dlerror());
+ return -1;
+ }
return 0;
}
diff --git a/liblttng-ust-baddr/lttng-ust-baddr.h b/liblttng-ust-baddr/lttng-ust-baddr.h
new file mode 100644
index 0000000..2229150
--- /dev/null
+++ b/liblttng-ust-baddr/lttng-ust-baddr.h
@@ -0,0 +1,22 @@
+/*
+ * Copyright (C) 2013 Paul Woegerer <paul_woegerer at mentor.com>
+ *
+ * This library is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; either
+ * version 2.1 of the License, or (at your option) any later version.
+ *
+ * This library is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public
+ * License along with this library; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
+ */
+
+#include <lttng/ust-events.h>
+
+int __attribute__((weak))
+lttng_ust_baddr_statedump(struct lttng_session *session);
diff --git a/liblttng-ust-dl/Makefile.am b/liblttng-ust-dl/Makefile.am
index c408fdd..352f145 100644
--- a/liblttng-ust-dl/Makefile.am
+++ b/liblttng-ust-dl/Makefile.am
@@ -2,7 +2,10 @@ AM_CPPFLAGS = -I$(top_srcdir)/include
AM_CFLAGS = -fno-strict-aliasing
lib_LTLIBRARIES = liblttng-ust-dl.la
-liblttng_ust_dl_la_SOURCES = ustdl.c
+liblttng_ust_dl_la_SOURCES = \
+ ustdl.c \
+ ust_baddr.c \
+ ust_baddr.h
liblttng_ust_dl_la_LIBADD = \
$(top_builddir)/liblttng-ust/liblttng-ust.la
diff --git a/liblttng-ust-baddr/ust_baddr.c b/liblttng-ust-dl/ust_baddr.c
similarity index 100%
rename from liblttng-ust-baddr/ust_baddr.c
rename to liblttng-ust-dl/ust_baddr.c
diff --git a/liblttng-ust-baddr/ust_baddr.h b/liblttng-ust-dl/ust_baddr.h
similarity index 100%
rename from liblttng-ust-baddr/ust_baddr.h
rename to liblttng-ust-dl/ust_baddr.h
diff --git a/liblttng-ust-dl/ustdl.c b/liblttng-ust-dl/ustdl.c
index 8baf9ee..dbde8b7 100644
--- a/liblttng-ust-dl/ustdl.c
+++ b/liblttng-ust-dl/ustdl.c
@@ -22,6 +22,9 @@
#include <link.h>
#include <unistd.h>
#include <stdio.h>
+#include <limits.h>
+#include <sys/types.h>
+#include <sys/stat.h>
#include <signal.h>
#include <sched.h>
#include <stdarg.h>
@@ -30,9 +33,11 @@
#include <lttng/ust-compiler.h>
#include <lttng/ust.h>
+#define TRACEPOINT_DEFINE
+#include "ust_baddr.h"
+
static void *(*__lttng_ust_plibc_dlopen)(const char *filename, int flag);
static int (*__lttng_ust_plibc_dlclose)(void *handle);
-static void *__lttng_ust_baddr_handle;
static
void *_lttng_ust_dl_libc_dlopen(const char *filename, int flag)
@@ -61,53 +66,24 @@ int _lttng_ust_dl_libc_dlclose(void *handle)
}
static
-void *lttng_ust_baddr_handle(void)
+void lttng_ust_baddr_push(void *so_base, const char *so_name)
{
- if (!__lttng_ust_baddr_handle) {
- __lttng_ust_baddr_handle = _lttng_ust_dl_libc_dlopen(
- "liblttng-ust-baddr.so.0", RTLD_NOW | RTLD_GLOBAL);
- if (__lttng_ust_baddr_handle == NULL)
- fprintf(stderr, "%s\n", dlerror());
- }
- return __lttng_ust_baddr_handle;
-}
+ char resolved_path[PATH_MAX];
+ struct stat sostat;
-static
-int lttng_ust_baddr_push(void *so_base, const char *so_name)
-{
- static int
- (*lttng_ust_baddr_push_fn)(void *so_base, const char *so_name);
- if (!lttng_ust_baddr_push_fn) {
- void *baddr_handle = lttng_ust_baddr_handle();
- if (baddr_handle) {
- lttng_ust_baddr_push_fn = dlsym(baddr_handle,
- "lttng_ust_push_baddr");
- if (lttng_ust_baddr_push_fn == NULL)
- fprintf(stderr, "%s\n", dlerror());
- }
- if (!lttng_ust_baddr_push_fn)
- return -1;
+ if (!realpath(so_name, resolved_path)) {
+ ERR("could not resolve path '%s'", so_name);
+ return;
}
- return lttng_ust_baddr_push_fn(so_base, so_name);
-}
-static
-int lttng_ust_baddr_pop(void *so_base)
-{
- static int
- (*lttng_ust_baddr_pop_fn)(void *so_base);
- if (!lttng_ust_baddr_pop_fn) {
- void *baddr_handle = lttng_ust_baddr_handle();
- if (baddr_handle) {
- lttng_ust_baddr_pop_fn = dlsym(baddr_handle,
- "lttng_ust_pop_baddr");
- if (lttng_ust_baddr_pop_fn == NULL)
- fprintf(stderr, "%s\n", dlerror());
- }
- if (!lttng_ust_baddr_pop_fn)
- return -1;
+ if (stat(resolved_path, &sostat)) {
+ ERR("could not access file status for %s", resolved_path);
+ return;
}
- return lttng_ust_baddr_pop_fn(so_base);
+
+ tracepoint(ust_baddr, push,
+ so_base, resolved_path, sostat.st_size, sostat.st_mtime);
+ return;
}
void *dlopen(const char *filename, int flag)
@@ -128,19 +104,7 @@ int dlclose(void *handle)
struct link_map *p = NULL;
if (dlinfo(handle, RTLD_DI_LINKMAP, &p) != -1 && p != NULL
&& p->l_addr != 0)
- lttng_ust_baddr_pop((void *) p->l_addr);
+ tracepoint(ust_baddr, pop, (void *) p->l_addr);
}
return _lttng_ust_dl_libc_dlclose(handle);
}
-
-static void __attribute__((destructor))
-lttng_ust_baddr_handle_fini(void);
-static void
-lttng_ust_baddr_handle_fini(void)
-{
- if (__lttng_ust_baddr_handle) {
- int ret = _lttng_ust_dl_libc_dlclose(__lttng_ust_baddr_handle);
- if (ret)
- fprintf(stderr, "%s\n", dlerror());
- }
-}
diff --git a/liblttng-ust/lttng-ust-comm.c b/liblttng-ust/lttng-ust-comm.c
index 77d8e3f..912521b 100644
--- a/liblttng-ust/lttng-ust-comm.c
+++ b/liblttng-ust/lttng-ust-comm.c
@@ -52,6 +52,7 @@
#include "lttng-tracer-core.h"
#include "compat.h"
#include "../libringbuffer/tlsfixup.h"
+#include "../liblttng-ust-baddr/lttng-ust-baddr.h"
/*
* Has lttng ust comm constructor been called ?
@@ -183,7 +184,6 @@ static const char *cmd_name_mapping[] = {
static const char *str_timeout;
static int got_timeout_env;
-static void *ust_baddr_handle;
extern void lttng_ring_buffer_client_overwrite_init(void);
extern void lttng_ring_buffer_client_overwrite_rt_init(void);
@@ -243,39 +243,6 @@ void print_cmd(int cmd, int handle)
}
static
-void *lttng_ust_baddr_handle(void)
-{
- if (!ust_baddr_handle) {
- ust_baddr_handle = dlopen(
- "liblttng-ust-baddr.so.0", RTLD_NOW | RTLD_GLOBAL);
- if (ust_baddr_handle == NULL)
- ERR("%s", dlerror());
- }
- return ust_baddr_handle;
-}
-
-static
-int lttng_ust_baddr_statedump(struct lttng_session *session)
-{
- static
- int (*lttng_ust_baddr_init_fn)(struct lttng_session *);
-
- if (!lttng_ust_baddr_init_fn) {
- void *baddr_handle = lttng_ust_baddr_handle();
- if (baddr_handle) {
- lttng_ust_baddr_init_fn = dlsym(baddr_handle,
- "lttng_ust_baddr_statedump");
- if (lttng_ust_baddr_init_fn == NULL)
- ERR("%s", dlerror());
- }
- if (!lttng_ust_baddr_init_fn)
- return -1;
- }
-
- return lttng_ust_baddr_init_fn(session);
-}
-
-static
int setup_local_apps(void)
{
const char *home_dir;
@@ -1249,7 +1216,7 @@ restart:
} else {
struct lttng_session *session =
sock_info->session_enabled;
- if (session) {
+ if (session && lttng_ust_baddr_statedump) {
sock_info->session_enabled = NULL;
lttng_ust_baddr_statedump(session);
}
@@ -1489,12 +1456,6 @@ void __attribute__((destructor)) lttng_ust_exit(void)
* cleanup the threads if there are stalled in a syscall.
*/
lttng_ust_cleanup(1);
-
- if (ust_baddr_handle) {
- int ret = dlclose(ust_baddr_handle);
- if (ret)
- ERR("%s", dlerror());
- }
}
/*
--
1.8.4
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2013-11-26 16:21 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <553056004.74731.1385279999530.JavaMail.zimbra@efficios.com>
2013-11-24 8:13 ` [lttng-dev] deadlock in ust baddr 2.4.0-rc1 Mathieu Desnoyers
2013-11-25 11:30 ` Woegerer, Paul
2013-11-25 12:22 ` Woegerer, Paul
2013-11-25 13:44 ` Mathieu Desnoyers
2013-11-26 16:21 ` [lttng-dev] [PATCH] Make base-address-state tracing use LD_PRELOAD Paul Woegerer
2013-11-25 12:05 ` [lttng-dev] [PATCH] Allow suppressing of base-address-state tracing Paul Woegerer
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox