From mboxrd@z Thu Jan 1 00:00:00 1970 From: Paul_Woegerer@mentor.com (Woegerer, Paul) Date: Wed, 13 Nov 2013 11:00:24 +0100 Subject: [lttng-dev] [PATCH lttng-ust 0/2] Shared object base address tracing In-Reply-To: <52828889.6030403@voxpopuli.im> References: <1384183688-19038-1-git-send-email-paul_woegerer@mentor.com> <52828889.6030403@voxpopuli.im> Message-ID: <52834DB8.5030004@mentor.com> On 11/12/2013 08:59 PM, Alexandre Montplaisir wrote: > Hi Paul, > > I tried your patches. It seems to work quite well! Glad to hear that :) > - The events are called "ust_baddr:push" and "ust_baddr:pop". To be > consistent with the other wrapper libraries in UST, perhaps they should > be called "ust_dl:dlopen" and "ust_dl:dlclose" or similar? I leave this up to Mathieu. I don't mind changing the names to whatever makes most sense for LTTng. > - Why does the "statedump" event seem to give many more libs than the > "push" events? Could we be missing some dlopen's? For example, I traced > glxgears by preloading liblttng-ust-dl.so: http://pastebin.com/HKVa9a4T Since ust_baddr:push/pop is based on LD_PRELOAD'ing dlopen/dlclose it can only tell you what shared libraries were opened/closed during the time you are actually tracing the application. Whatever is dlopen'ed/dlclose'ed before the tracing infrastructure that is part of the userspace application (lttng-ust) is becoming fully functional therefore cannot be captured as ust_baddr:push/pop events. For that reason we have the statedump mechanism (*) that complements shared object tracing by telling us what was happening (in respect to shared library loading) *before* we started (or before we were able) to trace calls to dlopen/dlclose. Only the two complementary approaches combined together give you the full picture of shared library loading. (*) The statedump mechanism iterates the currently open shared objects with dl_iterate_phdr (see: http://linux.die.net/man/3/dl_iterate_phdr). BTW, I get a slight different result when I trace glxgears (see attached glxgears_baddr.txt). I wonder what the reason is. > - As Matthew suggested, we could also hijack dlsym(), and with its > parameters we could match a symbol name to an address. This becomes > immensely useful when coupled with the ust-cyg-profile instrumentation, > so we can get information about about function names directly in the > trace! (but ironically, only for the dlopened libraries, and not the > main binary). What do you think of this approach? IMHO, hijacking dlsym() is not helping. The only thing you would know is that somewhere in your code for some reason the address for some symbol was requested via dlsym(). This will not help you to get symbol resolution for ust-cyg-profile instrumentation. In fact, the solution I present already contains all the information needed to provide full symbol resolution for any address during the whole lifetime of the traced application. To prove that I have attached a dump of our trace viewer that shows all the symbols resolved for a small forking web server example (traced with ust-cyg-profile and custom tracepoints + ip context enabled) . See attached server_sample.csv and server_sample_resolved.csv. > In any case, it's quite interesting! Thanks! -- Paul > > Cheers, > Alexandre > > > > On 13-11-11 10:28 AM, Paul Woegerer wrote: >> The following two patches implement https://bugs.lttng.org/issues/474 >> >> The first patch provides tracing of dlopen/dlclose calls with the use of an >> LD_PRELOAD library (liblttng-ust-dl.so) using the following events: >> >> ust_baddr:push(void *baddr, const char*sopath, int64_t size, int64_t mtime) >> ust_baddr:pop(void *baddr) >> >> The second patch adds support for tracing the whole state of currently loaded >> shared objects at session-enable time. The corresponding events are only >> emitted into the session that got enabled. The following event is used: >> >> ust_baddr_statedump (same args as ust_baddr:push) >> >> >> Paul Woegerer (2): >> Base-address tracing for dlopen and dlclose >> Implement base-address-state tracing >> >> Makefile.am | 2 + >> configure.ac | 2 + >> include/Makefile.am | 1 + >> include/lttng/tracepoint.h | 12 +-- >> include/lttng/ust-dl.h | 54 ++++++++++++ >> include/lttng/ust-tracepoint-event.h | 14 +++ >> liblttng-ust-baddr/Makefile.am | 20 +++++ >> liblttng-ust-baddr/lttng-ust-baddr.c | 111 ++++++++++++++++++++++++ >> liblttng-ust-baddr/ust_baddr.c | 20 +++++ >> liblttng-ust-baddr/ust_baddr.h | 66 ++++++++++++++ >> liblttng-ust-baddr/ust_baddr_statedump.c | 21 +++++ >> liblttng-ust-baddr/ust_baddr_statedump.h | 60 +++++++++++++ >> liblttng-ust-dl/Makefile.am | 17 ++++ >> liblttng-ust-dl/ustdl.c | 144 +++++++++++++++++++++++++++++++ >> liblttng-ust/lttng-events.c | 10 +++ >> liblttng-ust/lttng-tracer-core.h | 2 + >> liblttng-ust/lttng-ust-comm.c | 52 +++++++++++ >> 17 files changed, 603 insertions(+), 5 deletions(-) >> create mode 100644 include/lttng/ust-dl.h >> create mode 100644 liblttng-ust-baddr/Makefile.am >> create mode 100644 liblttng-ust-baddr/lttng-ust-baddr.c >> create mode 100644 liblttng-ust-baddr/ust_baddr.c >> create mode 100644 liblttng-ust-baddr/ust_baddr.h >> create mode 100644 liblttng-ust-baddr/ust_baddr_statedump.c >> create mode 100644 liblttng-ust-baddr/ust_baddr_statedump.h >> create mode 100644 liblttng-ust-dl/Makefile.am >> create mode 100644 liblttng-ust-dl/ustdl.c >> -- Paul Woegerer, SW Development Engineer Sourcery Analyzer Mentor Graphics, Embedded Software Division -------------- next part -------------- pwoegere at atv-pwoegere-l3:~> lttng create Session auto-20131113-092537 created. Traces will be written in /home/pwoegere/lttng-traces/auto-20131113-092537 pwoegere at atv-pwoegere-l3:~> lttng enable-event -u -a All UST events are enabled in channel channel0 pwoegere at atv-pwoegere-l3:~> lttng start Tracing started for session auto-20131113-092537 pwoegere at atv-pwoegere-l3:~> LD_PRELOAD=liblttng-ust-dl.so /usr/bin/glxgears Running synchronized to the vertical refresh. The framerate should be approximately the same as the monitor refresh rate. 301 frames in 5.0 seconds = 60.060 FPS XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" after 1515 requests (1515 known processed) with 0 events remaining. pwoegere at atv-pwoegere-l3:~> lttng stop Waiting for data availability. Tracing stopped for session auto-20131113-092537 pwoegere at atv-pwoegere-l3:~> lttng view Trace directory: /home/pwoegere/lttng-traces/auto-20131113-092537 [warning] Skipping directory 'index' found in trace [09:27:04.774912693] (+?.?????????) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x400000, sopath = "/usr/lib64/mesa-demos/xdemos/glxgears", size = 23360, mtime = 1381596745 } [09:27:04.774922939] (+0.000010246) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7FFF8A1DD000, sopath = "[linux-vdso.so.1]", size = 0, mtime = -1 } [09:27:04.774930406] (+0.000007467) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2AA4E000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liblttng-ust-dl.so.0.0.0", size = 21500, mtime = 1384181281 } [09:27:04.774936424] (+0.000006018) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2A7F0000, sopath = "/usr/lib64/libGL.so.1.2.0", size = 380976, mtime = 1382866191 } [09:27:04.774940192] (+0.000003768) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2A4F2000, sopath = "/lib64/libm-2.17.so", size = 1109606, mtime = 1379513990 } [09:27:04.774945488] (+0.000005296) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2A1B6000, sopath = "/usr/lib64/libX11.so.6.3.0", size = 1294064, mtime = 1380577077 } [09:27:04.774948793] (+0.000003305) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E29E08000, sopath = "/lib64/libc-2.17.so", size = 1996294, mtime = 1379513989 } [09:27:04.774955069] (+0.000006276) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E29BBF000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liblttng-ust.so.0.0.0", size = 1611934, mtime = 1384181281 } [09:27:04.774961151] (+0.000006082) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E299A5000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liblttng-ust-tracepoint.so.0.0.0", size = 138864, mtime = 1384181280 } [09:27:04.774964667] (+0.000003516) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2979D000, sopath = "/lib64/librt-2.17.so", size = 42706, mtime = 1379513990 } [09:27:04.774967809] (+0.000003142) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E29599000, sopath = "/lib64/libdl-2.17.so", size = 19016, mtime = 1379513990 } [09:27:04.774973714] (+0.000005905) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E29392000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liburcu-bp.so.2.0.0", size = 108574, mtime = 1381992197 } [09:27:04.774979504] (+0.000005790) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2918A000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liburcu-cds.so.2.0.0", size = 162940, mtime = 1381992197 } [09:27:04.774985314] (+0.000005810) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28F86000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liburcu-common.so.2.0.0", size = 86456, mtime = 1381992197 } [09:27:04.774988677] (+0.000003363) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28D6A000, sopath = "/lib64/libpthread-2.17.so", size = 131133, mtime = 1379513990 } [09:27:04.774992806] (+0.000004129) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28B44000, sopath = "/usr/lib64/libglapi.so.0.0.0", size = 150016, mtime = 1382866195 } [09:27:04.774996621] (+0.000003815) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28932000, sopath = "/usr/lib64/libXext.so.6.4.0", size = 73864, mtime = 1380578949 } [09:27:04.775000324] (+0.000003703) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2872F000, sopath = "/usr/lib64/libXdamage.so.1.1.0", size = 10424, mtime = 1380582326 } [09:27:04.775004059] (+0.000003735) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28529000, sopath = "/usr/lib64/libXfixes.so.3.1.0", size = 22736, mtime = 1380579302 } [09:27:04.775008109] (+0.000004050) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E28327000, sopath = "/usr/lib64/libX11-xcb.so.1.0.0", size = 6160, mtime = 1380577076 } [09:27:04.775013524] (+0.000005415) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2810F000, sopath = "/usr/lib64/libxcb-glx.so.0.0.0", size = 96464, mtime = 1382344054 } [09:27:04.775017240] (+0.000003716) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E27F0A000, sopath = "/usr/lib64/libxcb-dri2.so.0.0.0", size = 18656, mtime = 1382344054 } [09:27:04.775022385] (+0.000005145) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E27CEA000, sopath = "/usr/lib64/libxcb.so.1.1.0", size = 129920, mtime = 1382344056 } [09:27:04.775026302] (+0.000003917) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E27AE4000, sopath = "/usr/lib64/libXxf86vm.so.1.0.0", size = 22912, mtime = 1380582136 } [09:27:04.775030152] (+0.000003850) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E278D8000, sopath = "/usr/lib64/libdrm.so.2.4.0", size = 47696, mtime = 1382865247 } [09:27:04.775033421] (+0.000003269) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E2AC51000, sopath = "/lib64/ld-2.17.so", size = 163493, mtime = 1379513989 } [09:27:04.775037205] (+0.000003784) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E276D4000, sopath = "/usr/lib64/libXau.so.6.0.0", size = 14640, mtime = 1380536554 } [09:27:04.775042540] (+0.000005335) atv-pwoegere-l3.atv.mentorg.com ust_baddr_statedump:soinfo: { cpu_id = 5 }, { baddr = 0x7F8E26100000, sopath = "/home/pwoegere/MGC/lttng2_stack_latest_install/lib64/liblttng-ust-baddr.so.0.0.0", size = 77469, mtime = 1384181281 } [09:27:04.776345452] (+0.001302912) atv-pwoegere-l3.atv.mentorg.com ust_baddr:push: { cpu_id = 4 }, { baddr = 0x7F8E2A7F0000, sopath = "/usr/lib64/libGL.so.1.2.0", size = 380976, mtime = 1382866191 } [09:27:04.795393509] (+0.019048057) atv-pwoegere-l3.atv.mentorg.com ust_baddr:push: { cpu_id = 4 }, { baddr = 0x7F8E256DD000, sopath = "/usr/lib64/dri/r600_dri.so", size = 6560344, mtime = 1382866182 } [09:27:04.795397917] (+0.000004408) atv-pwoegere-l3.atv.mentorg.com ust_baddr:pop: { cpu_id = 4 }, { baddr = 0x7F8E2A7F0000 } pwoegere at atv-pwoegere-l3:~> lttng destroy Session auto-20131113-092537 destroyed -------------- next part -------------- A non-text attachment was scrubbed... Name: server_sample.csv Type: text/csv Size: 34540 bytes Desc: not available URL: -------------- next part -------------- A non-text attachment was scrubbed... Name: server_sample_resolved.csv Type: text/csv Size: 35382 bytes Desc: not available URL: