[lttng-dev] some troubles having lttgng-ust actually log something on a shared library

[Mathieu Desnoyers]

* Sébastien Barthélémy (barthelemy at crans.org) wrote:
> 2011/12/20 Sébastien Barthélémy <barthelemy at crans.org>:
> > 011/12/19 Mathieu Desnoyers <compudj at krystal.dyndns.org>:
> >>
> >> Please try to reproduce this problem in a simple application that uses
> >> dlopen to load libs.
> >
> > I omitted to mention it, but I tried that yesterday. Without success: tracing
> > worked. I'll keep trying.
> 
> There is still a question that bugs me though: the tracing only works if I link
> the executable (the one which dlopens the traced .so) against lttng-ust.
> 
> So, while the attached example works out of the box, it won't with the following
> patch applied:
> 
> diff --git a/Makefile b/Makefile
> index 4674579..6e25f08 100644
> --- a/Makefile
> +++ b/Makefile
> @@ -3,7 +3,7 @@
>  all: run_motion libmotion.so.1.0.0
> 
>  run_motion:run_motion.cpp
> -       ${CC} -o run_motion -lstdc++ -ldl -llttng-ust run_motion.cpp
> +       ${CC} -o run_motion -lstdc++ -ldl run_motion.cpp
>  libmotion.so.1.0.0:motion.o ust_motion.o
>         ${CC} -shared -Wl,-soname,libmotion.so.1 -o libmotion.so.1.0.0
> -ldl -llttng-ust -lstdc++ motion.o ust_motion.o

you could also try linking libmotion.so on liblttng-ust, I think it
should work too.

you can also just LD_PRELOAD libmotion if you don't want to always link
your executable to libmotion (and thus liblttng-ust). The "demo" program
in the lttng-ust source tree does that with a small shell script.

> 
> The program hangs, waiting for ltt-sessiond :
> 
> libust[4114/4114]: just registered a tracepoints section from
> 0x7fab35640aa8 and having 1 tracepoints (in tracepoint_register_lib()
> at tracepoint.c:575)
> libust[4114/4114]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_metadata_client_init() at
> ltt-ring-buffer-metadata-client.h:318)
> libust[4114/4114]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_client_overwrite_init() at ltt-ring-buffer-client.h:557)
> libust[4114/4114]: LTT : ltt ring buffer client init
>  (in ltt_ring_buffer_client_discard_init() at ltt-ring-buffer-client.h:557)
> libust[4114/4116]: Info: sessiond not accepting connections to global
> apps socket (in ust_listener_thread() at lttng-ust-comm.c:633)
> libust[4114/4116]: Waiting for global apps sessiond (in
> wait_for_sessiond() at lttng-ust-comm.c:556)
> libust[4114/4116]: Linux kernels 2.6.33 to 3.0 (with the exception of
> stable versions) do not support FUTEX_WAKE on read-only memory
> mappings correctly. Please upgrade your kernel (fix is commit
> 9ea71503a8ed9184d2d0b8ccc4d269d05f7940ae in Linux kernel mainline).
> LTTng-UST will use polling mode fallback. (in wait_for_sessiond() at
> lttng-ust-comm.c:569)
> libust[4114/4116]: Error: futex: Bad address (in wait_for_sessiond()
> at lttng-ust-comm.c:571)
> libust[4114/4116]: Info: sessiond not accepting connections to global
> apps socket (in ust_listener_thread() at lttng-ust-comm.c:633)
> libust[4114/4115]: message received
>  (in ust_listener_thread() at lttng-ust-comm.c:700)
> libust[4114/4114]: Error: Timed out waiting for ltt-sessiond (in
> lttng_ust_init() at lttng-ust-comm.c:818)
> 
> Any idea why this is so?

The constructor of liblttng-ust always try to register to:

1) the per-user sessiond
2) the system-wide sessiond

So you can see that the program cannot register to one of the sessiond,
but it does not mean registration to the other has failed.

Also, note that you should upgrade your Linux kernel. There is a bug in
the futex implementation that lttng-ust needs to work-around by polling
for a sessiond every 5 seconds.

> 
> > 2011/12/19 Mathieu Desnoyers <compudj at krystal.dyndns.org>:
> >> Sébastien Barthélémy (barthelemy at crans.org) wrote:
> >>> A better understanding of the way probes are enabled would probably
> >>> help me debug it.
> >>> Is it documented somewhere? Or could you point me to the right source file?
> >>
> >> liblttng-ust/tracepoint.c
> >> liblttng-ust/ltt-probe.c
> >> include/lttng/tracepoint.h include/lttng/ust-tracepoint-event.h
> >>
> >> would be a good start,
> 
> Ok, I eventually understood why I haven't got any linking error on Friday, while
> having omitted an object file.
> And why the tracepoints were getting registered while I got no output:
> the constructor from
> include/lttng/ust-tracepoint-event.h was never called.
> 
> I have another question though:
> in include/lttng/ust-tracepoint-event.h there are the two following declarations
> 
> extern struct tracepoint * const __start___tracepoints_ptrs[]
> 	__attribute__((weak, visibility("hidden")));
> extern struct tracepoint * const __stop___tracepoints_ptrs[]
> 	__attribute__((weak, visibility("hidden")));
> 
> I eventually understood that they are defined in liblttng-ust.so
> 
> $ nm /usr/local/lib/liblttng-ust.so | grep ___tracepoints_ptrs
> 0000000000232aa8 a __start___tracepoints_ptrs
> 0000000000232ab0 a __stop___tracepoints_ptrs
> 
> And that they match the boundaries of the tracepoints_ptrs section
> 
> $ objdump -h /usr/local/lib/liblttng-ust.so |grep __tracepoints_ptrs
>  26 __tracepoints_ptrs 00000008  0000000000232aa8  0000000000232aa8
> 00032aa8  2**3
> 
> But how do you get these symbols defined? Greping through the lttng-ust source
> code did not help me much.

Those are defined in your instrumented application _and_ in
liblttng-ust.so (this is why they have a "hidden" visibility -- their
scope is either the application or the shared-object they are defined
in; there can be more than one of these symbols per process, thanks to
the hidden visibility).

For information about these special symbols, I have to cite Ian Lance
Taylor's blog about this feature almost undocumented
(source: http://www.airs.com/blog/archives/56):

"__start and __stop Symbols

A quick note about another GNU linker extension. If the linker sees a
section in the output file which can be part of a C variable name–the
name contains only alphanumeric characters or underscore–the linker will
automatically define symbols marking the start and stop of the section.
Note that this is not true of most section names, as by convention most
section names start with a period. But the name of a section can be any
string; it doesn’t have to start with a period. And when that happens
for section NAME, the GNU linker will define the symbols __start_NAME
and __stop_NAME to the address of the beginning and the end of section,
respectively.

This is convenient for collecting some information in several different
object files, and then referring to it in the code. For example, the GNU
C library uses this to keep a list of functions which may be called to
free memory. The __start and __stop symbols are used to walk through the
list.

In C code, these symbols should be declared as something like extern
char __start_NAME[]. For an extern array the value of the symbol and the
value of the variable are the same."

Best regards,

Mathieu


> 
> Cheers
> -- Sebastian


> _______________________________________________
> lttng-dev mailing list
> lttng-dev at lists.lttng.org
> http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev


-- 
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com