[lttng-dev] Function Tracing Fails

Mon Jul 30 08:55:14 EDT 2018

----- On Jul 29, 2018, at 9:29 PM, paramesh p <params16jan at gmail.com> wrote: 

> Hi,
> I am trying to use Function Tracing for my application running in 32-bit ARM
> Platform. I have added below lines in my makefile for enabling Trace Data for
> function tracing

> AM_CFLAGS += -g -O0 -finstrument-functions
> AM_CXXFLAGS += -g -O0 -finstrument-functions

> **(My App have both C && CPP files, So I added CFLAGS & CXXFLAGS).

> I am running below commands,
> $lttng create session1
> $lttng enable-event -u -a --loglevel-only TRACE_DEBUG_FUNCTION
> $lttng start
> $LD_PRELOAD=liblttng-ust-cyg-profile.so.0.0.0 my_test_app
> $lttng start
> $babeltrace /home/root/lttng-traces/session1

> Its showing nothing.

> I tried with below event-enable command also. There is no data
> $lttng enable-event -u -a --loglevel TRACE_DEBUG_FUNCTION

> But If I use the command, "lttng enable-event -u -a" for enabling the event, I
> am getting below output from babeltrace,

> [22:25:30.812389281] (+?.?????????) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0xAD1A9000, sopath = "/usr/lib/liblttng-ust-cyg-profile.so.0.0.0",
> size = 10004, mtime = 1532324280 }
> [22:25:30.812496469] (+0.000107188) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DFF0000, sopath = "/usr/lib/xxx.so", size = 19540, mtime =
> 1532369202 }
> [22:25:30.812604177] (+0.000107708) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4E120000, sopath = "/usr/lib/libcutils.so.0.0.0", size = 48624,
> mtime = 1532323462 }
> [22:25:30.812655219] (+0.000051042) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DC80000, sopath = "/lib/ [ http://libpthread-2.22.so/ |
> libpthread-2.22.so ] ", size = 94976, mtime = 1532322845 }
> [22:25:30.812701677] (+0.000046458) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DB20000, sopath = "/lib/ [ http://libc-2.22.so/ | libc-2.22.so
> ] ", size = 1304484, mtime = 1532322845 }
> [22:25:30.812757927] (+0.000056250) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0xAD15B000, sopath = "/usr/lib/liblttng-ust.so.0.0.0", size =
> 315248, mtime = 1532324280 }
> [22:25:30.812814229] (+0.000056302) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0xAD149000, sopath = "/usr/lib/liblttng-ust-tracepoint.so.0.0.0",
> size = 35624, mtime = 1532324280 }
> [22:25:30.812860635] (+0.000046406) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DEC0000, sopath = "/lib/ [ http://librt-2.22.so/ |
> librt-2.22.so ] ", size = 28380, mtime = 1532322845 }
> [22:25:30.812904438] (+0.000043803) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DCB0000, sopath = "/lib/ [ http://libdl-2.22.so/ |
> libdl-2.22.so ] ", size = 11236, mtime = 1532322845 }
> [22:25:30.812959125] (+0.000054687) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DE10000, sopath = "/usr/lib/liburcu-bp.so.2.0.0", size = 29052,
> mtime = 1532323584 }
> [22:25:30.813013969] (+0.000054844) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DE00000, sopath = "/usr/lib/liburcu-cds.so.2.0.0", size =
> 26152, mtime = 1532323584 }
> [22:25:30.813485479] (+0.000471510) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DD60000, sopath = "/usr/lib/liburcu-common.so.2.0.0", size =
> 13084, mtime = 1532323584 }
> [22:25:30.813600792] (+0.000115313) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DAE0000, sopath = "/lib/ [ http://ld-2.22.so/ | ld-2.22.so ] ",
> size = 139632, mtime = 1532322845 }
> [22:25:30.813663656] (+0.000062864) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DFC0000, sopath = "/usr/lib/xxx.so.1.0.0", size = 19456, mtime
> = 1532323510 }
> [22:25:30.813720635] (+0.000056979) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4E030000, sopath = "/usr/lib/xxx.so.1.6.0", size = 142164, mtime
> = 1532323441 }
> [22:25:30.813776990] (+0.000056355) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4E060000, sopath = "/usr/lib/xxx.so.0.0.0", size = 265304, mtime
> = 1532324468 }
> [22:25:30.813843917] (+0.000066927) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DEA0000, sopath = "/usr/lib/xxx.so.0.0.0", size = 84016, mtime
> = 1532324363 }
> [22:25:30.813884385] (+0.000040468) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DFE0000, sopath = "/usr/lib/xxx.so", size = 34204, mtime =
> 1532324426 }
> [22:25:30.813940479] (+0.000056094) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DFD0000, sopath = "/usr/lib/xxx.so", size = 7388, mtime =
> 1532324388 }
> [22:25:30.813993604] (+0.000053125) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4E000000, sopath = "/usr/lib/xxx.so", size = 33152, mtime =
> 1532323414 }
> [22:25:30.814049333] (+0.000055729) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DEE0000, sopath = "/usr/lib/libstdc++.so.6.0.20", size =
> 869236, mtime = 1532323320 }
> [22:25:30.814094177] (+0.000044844) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DCD0000, sopath = "/lib/ [ http://libm-2.22.so/ | libm-2.22.so
> ] ", size = 441372, mtime = 1532322845 }
> [22:25:30.814234177] (+0.000140000) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DE80000, sopath = "/lib/libgcc_s.so.1", size = 118608, mtime =
> 1532323098 }
> [22:25:30.814427615] (+0.000193438) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x8000, sopath = " /usr/bin/my_test_app ", size = 54540, mtime =
> 1532369202 }
> [22:25:30.828436677] (+0.014009062) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0xAEC57000, sopath = "/usr/lib/liblttng-ust-cyg-profile.so.0.0.0",
> size = 10004, mtime = 1532324280 }
> [22:25:30.828634958] (+0.000198281) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 1
> }, { baddr = 0x4DCD0000, sopath = "/lib/ [ http://libm-2.22.so/ | libm-2.22.so
> ] ", size = 441372, mtime = 1532322845 }
> [22:25:30.829786104] (+0.001151146) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DB20000, sopath = "/lib/ [ http://libc-2.22.so/ | libc-2.22.so
> ] ", size = 1304484, mtime = 1532322845 }
> [22:25:30.829910219] (+0.000124115) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0xAEC09000, sopath = "/usr/lib/liblttng-ust.so.0.0.0", size =
> 315248, mtime = 1532324280 }
> [22:25:30.829996000] (+0.000085781) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0xAEBF7000, sopath = "/usr/lib/liblttng-ust-tracepoint.so.0.0.0",
> size = 35624, mtime = 1532324280 }
> [22:25:30.830067510] (+0.000071510) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DEC0000, sopath = "/lib/ [ http://librt-2.22.so/ |
> librt-2.22.so ] ", size = 28380, mtime = 1532322845 }
> [22:25:30.830118031] (+0.000050521) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DCB0000, sopath = "/lib/ [ http://libdl-2.22.so/ |
> libdl-2.22.so ] ", size = 11236, mtime = 1532322845 }
> [22:25:30.830175010] (+0.000056979) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DE10000, sopath = "/usr/lib/liburcu-bp.so.2.0.0", size = 29052,
> mtime = 1532323584 }
> [22:25:30.830245271] (+0.000070261) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DE00000, sopath = "/usr/lib/liburcu-cds.so.2.0.0", size =
> 26152, mtime = 1532323584 }
> [22:25:30.830316521] (+0.000071250) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 0
> }, { baddr = 0x4DD60000, sopath = "/usr/lib/liburcu-common.so.2.0.0", size =
> 13084, mtime = 1532323584 }
> [22:25:34.384458499] (+3.554141978) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0xAF584000, sopath = "/usr/lib/liblttng-ust-cyg-profile.so.0.0.0",
> size = 10004, mtime = 1532324280 }
> [22:25:34.385048967] (+0.000590468) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DCD0000, sopath = "/lib/ [ http://libm-2.22.so/ | libm-2.22.so
> ] ", size = 441372, mtime = 1532322845 }
> [22:25:34.385146415] (+0.000097448) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DB20000, sopath = "/lib/ [ http://libc-2.22.so/ | libc-2.22.so
> ] ", size = 1304484, mtime = 1532322845 }
> [22:25:34.385251832] (+0.000105417) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0xAF536000, sopath = "/usr/lib/liblttng-ust.so.0.0.0", size =
> 315248, mtime = 1532324280 }
> [22:25:34.385354228] (+0.000102396) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0xAF524000, sopath = "/usr/lib/liblttng-ust-tracepoint.so.0.0.0",
> size = 35624, mtime = 1532324280 }
> [22:25:34.385444384] (+0.000090156) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DEC0000, sopath = "/lib/ [ http://librt-2.22.so/ |
> librt-2.22.so ] ", size = 28380, mtime = 1532322845 }
> [22:25:34.385530165] (+0.000085781) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DCB0000, sopath = "/lib/ [ http://libdl-2.22.so/ |
> libdl-2.22.so ] ", size = 11236, mtime = 1532322845 }
> [22:25:34.385607613] (+0.000077448) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DE10000, sopath = "/usr/lib/liburcu-bp.so.2.0.0", size = 29052,
> mtime = 1532323584 }
> [22:25:34.385677978] (+0.000070365) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DE00000, sopath = "/usr/lib/liburcu-cds.so.2.0.0", size =
> 26152, mtime = 1532323584 }
> [22:25:34.385773655] (+0.000095677) ZZZ ust_baddr_statedump:soinfo: { cpu_id = 2
> }, { baddr = 0x4DD60000, sopath = "/usr/lib/liburcu-common.so.2.0.0", size =
> 13084, mtime = 1532323584 }

> Note: I have changed the Target Name as 'ZZZ' and some of the library name as
> 'xxx' in the above log for some confidential issues.

> Please guide me where I am making mistake and Please give your input on how to
> check the application compiled with function instrument information for
> tracing. I verified that application compiled with debugging information, by
> running gdb command. Below is the output of gdb command,

> /usr/bin # gdb my_test_app
> GNU gdb (GDB) 7.9.1
> Copyright (C) 2015 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later < [ http://gnu.org/licenses/gpl.html
> | http://gnu.org/licenses/gpl.html ] >
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law. Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "arm-oe-linux-gnueabi".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> < [ http://www.gnu.org/software/gdb/bugs/ |
> http://www.gnu.org/software/gdb/bugs/ ] >.
> Find the GDB manual and other documentation resources online at:
> < [ http://www.gnu.org/software/gdb/documentation/ |
> http://www.gnu.org/software/gdb/documentation/ ] >.
> For help, type "help".
> Type "apropos word" to search for commands related to "word"...
> Reading symbols from my_test_app ...done.
> (gdb)
> (gdb) exit
> I am not sure whether it is compiled with finstrumentation information.

We would need the output of 

make clean 
make V=1 

when you compile your project, so we can effectively see how the compiler is invoked. 

Thanks, 

Mathieu 

> Thanks in Advance,
> Paramesh

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

-- 
Mathieu Desnoyers 
EfficiOS Inc. 
http://www.efficios.com 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.lttng.org/pipermail/lttng-dev/attachments/20180730/7fc94c29/attachment-0001.html>