Repository navigation
Recording source location - #45
Merged
Merged
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Recording the source location works in three phases. At runtime, each call only remembers an address. At finalize, a table of those addresses is written into the trace. Only at analysis time does addr2line turn them into file, line and function.
Capture in the prologue. Every wrapper goes through RECORDER_INTERCEPTOR_PROLOGUE_CORE, which contains (recorder.h:57):
record->call_site = callsite_intern(__builtin_return_address(0));
__builtin_return_address(0) returns the address the wrapper will return to: the instruction just after the call in the caller. Recorder subtracts 1 so the address points at the call instruction itself, not at the next source line.
Special case: MPI wrappers. For MPI functions, the prologue sits in an inner imp_*() function behind a forwarder, so the return address points into librecorder itself. recorder-callsite.c:139 uses is_self() to check whether the address lies inside librecorder's own address range. Only then does unwind_out_of_self() (line 96) run: it uses libunwind to walk up the stack to the first frame outside librecorder. This is the only reason libunwind is needed.
Turning the address into (module, offset). An absolute address is useless once the program exits, because ASLR loads libraries at a different place on every run. So dladdr1(..., RTLD_DL_LINKMAP) (line 155) looks up two things:
the module containing the address, e.g. /path/to/ior or libmpi.so.12.1.1, normalized with realpath;
the offset relative to the load slide link_map->l_addr (line 173).
It deliberately does not use dli_fbase. For a non-PIE executable dli_fbase is 0x400000 while the slide is 0, and addr2line expects the offset against the slide.
Interning to an ID. dladdr1 and realpath are expensive, so there is a hash table mapping address → {id, module_id, offset}. The first time an address shows up it is resolved and gets the next free ID. Every later call from the same site is just a hash lookup. The Record stores only this uint32_t ID. A mutex protects the table across threads, and the in_intern flag prevents recursion in case realpath itself hits an intercepted function.
In recorder-cst-cfg.c, call_site is added to the CST key, the unique signature of a call. Two write(fd, buf, 262144) calls from different places in the code therefore become different signatures. The key layout changed because of this, so format_version was bumped to 2.
In callsite_save_local() (line 182), each rank writes .callsites: a header, the module paths (NUL-separated), then one {module_id, offset} entry per ID, ordered by ID.
IDs are assigned per rank, so each rank needs its own table.
While assembling recorder.dat, rank 0 appends each file as its own RECORDER_SECTION_CALLSITES section (type 7) tagged with the rank (recorder-logger.c:529), then deletes the per-rank files.
In reader-callsite.c, callsite_table_load() reads the section for a given rank. It then runs addr2line once per module, passing up to 128 offsets at a time:
addr2line -a -i -f -C -e /path/to/ior 0x1234 0x5678 ...
-f gives the function name, and -C demangles C++ names.
-i also gives the inline chain. That is where ... in MPIIO_Open <- ... in MPIIO_Create comes from: from one address, the debug info reconstructs which functions the code was inlined into. It is not a real backtrace.
If addr2line finds nothing, for example because libmpi has no debug info, the output stays as libmpi.so.12.1.1+0xce7fe9. You can resolve that yourself later.
recorder2text then looks up the ID for each record and appends @ .
Example:
0.0321134 0.0426196 H5open 0 3 ( ) @ /g/g90/x/repos/ior/src/aiori-HDF5.c:467 in HDF5_Xfer
0.0427623 0.0429573 H5Dwrite 0 3 ( 360287970189639680 216172782113783829 288230376151711747 288230376151711749 792633534417207321 %p ) @ /g/g90/x/repos/ior/src/aiori-HDF5.c:467 in HDF5_Xfer
0.0429792 0.0432973 close 1 0 ( /etc/romio-hints )
0.0439211 0.0544273 close 1 0 ( /g/g90/x/testFile )
0.0545700 0.0547650 MPI_File_write_at 1 1 ( 0-1 2048 %p 262144 MPI_BYTE [0_0] ) @ /root/.spack/stage/sly1/spack-stage-hdf5-1.14.0-usbfmqntytiqburdanwwd2wzmkkdsmqs/spack-src/src/H5FDmpio.c:1685 in H5FD__mpio_write
0.0547690 0.0549521 lseek 2 0 ( /g/g90/x/testFile 2048 0 ) @ libmpi.so.12.1.1+0xce81a6
0.0550899 0.0550899 fcntl 2 0 ( /g/g90/x/testFile 7 1 ) @ libmpi.so.12.1.1+0xd1620b
0.0552710 0.0552720 write 2 0 ( /g/g90/x/testFile %p 262144 ) @ libmpi.so.12.1.1+0xce81d1
0.0568688 0.0568698 fcntl 2 0 ( /g/g90/x/testFile 6 2 ) @ libmpi.so.12.1.1+0xd1620b
Requirements and limitations
Build switch: everything is compiled in only with -DRECORDER_ENABLE_FULL_TRACING=ON (or -DFULL_TRACING=ON). Without it there is no overhead and the trace format stays at version 1. You can turn it off at runtime with RECORDER_STORE_CALL_SITE=0.
The binaries must still be there: resolution happens offline. The program and libraries must be unchanged and at the same paths when you analyze the trace. For file and line they need debug info (-g).
One frame only: you see the direct call site plus any inlined functions, not the full call chain.
Missing @: if no call site could be determined, the ID is 0xFFFFFFFF (CALLSITE_UNKNOWN). callsite_table_get() then returns nothing and the line has no @. That is what happens with your close calls. I haven't looked into why yet.