Wie ich im Beitrag Speicherlecksuche mit Heaptrack erwähnt habe, zeigt heaptrack nicht die Codezeilen für Programme und Bibliotheken an, deren Debugsymbole in getrennten Dateien liegen. Dies ist üblich, da die Debugsymbole meist sehr groß sind und nur auf Wunsch installiert werden. Bei Debian sind die Debugsymbole in Paketen, deren Namen mit dbgsym endet, und liegen in Dateien im Verzeichnis /usr/lib/debug.

Um die passenden Debugsymbole zu finden, ist in den Programmdateien eine BuildID enthalten, anhand derer man die Datei mit den dazugehörigen Debugsymbolen finden kann:

% file /bin/uname /usr/lib/debug/.build-id/da/72a2b255582607738147efc1bb99b639d5c6c9.debug
/bin/uname: ELF 64-bit LSB shared object, x86-64, version 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2, BuildID[sha1]=da72a2b255582607738147efc1bb99b639d5c6c9, for GNU/Linux 3.2.0, stripped
/usr/lib/debug/.build-id/da/72a2b255582607738147efc1bb99b639d5c6c9.debug: ELF 64-bit LSB shared object, x86-64, version 1 (SYSV), dynamically linked, interpreter *empty*, BuildID[sha1]=da72a2b255582607738147efc1bb99b639d5c6c9, for GNU/Linux 3.2.0, with debug_info, not stripped

Das Programm heaptrack ist ein reines Shellskript, das zum einen das Programm heaptrack_interpret startet, welches dann die Rohdaten auswertet, und zum anderen das zu untersuchende Programm und ihm mit LD_PRELOAD präparierte Versionen von malloc und free unterschiebt. Um nun meinerseits herauszufinden, was bei der Suche der Debugsymbole schief geht, starte ich heaptrack_interpret mit strace.

% mkfifo /tmp/pipe

% strace -o /tmp/ht.st /usr/lib/heaptrack/libexec/heaptrack_interpret < /tmp/pipe >/tmp/ht.out &

% LD_PRELOAD=/usr/lib/heaptrack/libheaptrack_preload.so DUMP_HEAPTRACK_OUTPUT=/tmp/pipe /bin/uname -r
5.7.0-1-amd64

Es zeigt sich, dass heaptrack_interpret nach den abgetrennten Debugsymbolen sucht, aber leider an der falschen Stelle:

% grep 72a2b255582607738147efc1bb99b639d5c6c9 /tmp/ht.st
openat(AT_FDCWD, "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/bin/.debug/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/debug//usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/bin/.debug/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/debug//usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

Für strace hatte ich entdeckt, dass man mit -P nach Pfaden filtern kann. Dieses in Kombination mit -k könnte die verantwortlichen Codestellen liefern, aber strace scheint am gleichen Problem zu leiden, wie heaptrack.

(gdb) start < /tmp/pipe >/tmp/ht.out
(gdb) b open
Breakpoint 2 at 0x7ffff7a64710: open. (38 locations)
(gdb) c

Breakpoint 2, __libc_open64 (file=file@entry=0x5555555afef0 "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", oflag=oflag@entry=524288)
    at ../sysdeps/unix/sysv/linux/open64.c:37
37      in ../sysdeps/unix/sysv/linux/open64.c
(gdb) bt
#0  __libc_open64 (file=file@entry=0x5555555afef0 "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", oflag=oflag@entry=524288)
    at ../sysdeps/unix/sysv/linux/open64.c:37
#1  0x0000555555568c84 in open (__oflag=524288, __path=0x5555555afef0 "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug")
    at /usr/include/x86_64-linux-gnu/bits/fcntl2.h:53
#2  backtrace_open (filename=filename@entry=0x5555555afef0 "/usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug", 
    error_callback=error_callback@entry=0x55555555c0d0 <(anonymous namespace)::AccumulatedTraceData::<lambda(void*, char const*, int)>::_FUN(void *, const char *, int)>, data=data@entry=0x7fffffffdfd8, does_not_exist=does_not_exist@entry=0x7fffffffda14) at ./3rdparty/libbacktrace/posix.c:67
#3  0x0000555555560ef6 in elf_try_debugfile (state=state@entry=0x5555555afdd0, prefix=prefix@entry=0x5555555afda8 "/usr/bin/uname", 
    prefix_len=prefix_len@entry=9, prefix2=prefix2@entry=0x55555556a37a "", prefix2_len=prefix2_len@entry=0, 
    debuglink_name=debuglink_name@entry=0x7ffff7fc926c "72a2b255582607738147efc1bb99b639d5c6c9.debug", 
    error_callback=0x55555555c0d0 <(anonymous namespace)::AccumulatedTraceData::<lambda(void*, char const*, int)>::_FUN(void *, const char *, int)>, 
    data=0x7fffffffdfd8) at ./3rdparty/libbacktrace/elf.c:865
#4  0x0000555555563340 in elf_find_debugfile_by_debuglink (data=<optimized out>, error_callback=<optimized out>, debuglink_name=<optimized out>, 
    filename=<optimized out>, state=<optimized out>) at ./3rdparty/libbacktrace/elf.c:954
#5  elf_open_debugfile_by_debuglink (data=<optimized out>, error_callback=<optimized out>, debuglink_crc=<optimized out>, debuglink_name=<optimized out>, 
    filename=<optimized out>, state=<optimized out>) at ./3rdparty/libbacktrace/elf.c:1002
#6  elf_add (state=<optimized out>, filename=<optimized out>, descriptor=<optimized out>, base_address=93911885459456, error_callback=<optimized out>, 
    data=<optimized out>, fileline_fn=0x5555555afde8, found_sym=0x7fffffffdfb0, found_dwarf=0x7fffffffdfe0, exe=0, debuginfo=0)
    at ./3rdparty/libbacktrace/elf.c:2885
#7  0x000055555555adac in (anonymous namespace)::AccumulatedTraceData::findBacktraceState (addressStart=<optimized out>, 
    fileName=0x5555555afda8 "/usr/bin/uname", this=0x7fffffffe080) at ./src/interpret/heaptrack_interpret.cpp:361
#8  main () at ./src/interpret/heaptrack_interpret.cpp:449

Wie sich herausstellte, verwendet heaptrack eine Kopie von libbacktrace, in der sich der Aufruf von elf_try_debugfile für /usr/lib/debug befindet.

Debian-Code-Search

Vor kurzem hatte ich die Codesuche von Debian entdeckt, womit ich jetzt alle Pakete nach der Funktion elf_find_debugfile_by_debuglink durchsuchen konnte. Wie sich herausstellte, verwendet nicht nur heaptrack seine eigene Version, sondern auch andere Programme wie rustc und Firefox, aber in keiner Variante ist der Pfad an die Verzeichnisstruktur von Debian angepasst.

bpftrace

Als Umgehung des Problems würde sich ja anbieten, einfach Symlinks an den gesuchten Stellen anzulegen. Und damit kam die schon lange gesuchte Anwendung für bpftrace. Von dem Programm hatte ich schon oft gelesen, nur hatte sich für mich noch kein richtiger Anwendungsfall ergeben, sodass ich es ausprobieren könnte. Aber hierfür passte es super.

Damit ich nicht auf solch umständliche Weise mit strace die Pfade ermitteln muss, wollte ich einfach im Kernel bei openat den Abhörpunkt nutzen und dort die Information abgreifen. Den Einstieg hatte ich aus mit dem 3. Beispiel aus bpftrace-Lehrbuch.

Nach einigem Basteln habe ich dann folgendes Programm erstellt, das am Beginn von openat den Dateinamen zwischenspeichert, sollte heaptrack_inter eine Datei unter /usr/lib/debug suchen. Beim Verlassen der Funktion prüfe ich dann, ob der Rückgabewert für nicht gefunden steht und gebe die entsprechenden Information aus. Die Fehlercodes für die Rückgabewerte kann man mit dem Programm errno aus dem Paket moreutils ermitteln. In der Ausgabe von strace ist der Fehlercode zu sehen.

// Aufruf: BPFTRACE_STRLEN=92 bpftrace list-failed-dbgsym.bt > missing-files

tracepoint:syscalls:sys_enter_openat
{
    if (strncmp(comm, "heaptrack_inter", 15) == 0 &&
      strncmp(str(args->filename), "/usr/lib/debug/", 15) == 0) {
        @fname[tid] = args->filename;
    }
}

tracepoint:syscalls:sys_exit_openat
/@fname[tid]/
{
    // if (args->ret == -2) {
        printf("%-6d %-16s %s %d\n", pid, comm, str(@fname[tid]), args->ret);
    // }
    delete(@fname[tid]);
}

Da bpftrace die Zeichenfolgen mit str() auf 64 Bytes einkürzt, muss beim Aufruf die Umgebungsvariable BPFTRACE_STRLEN=92 entsprechend angepasst werden.

Die Lösung

Die Symlinks für die Dateien zu erstellen, ist wieder eine klassische Aufgabe für die Shell, weshalb ich dies auch mit ein wenig Zsh-Magie gelöst habe:

# head -n 5 /tmp/missing-files
491026 heaptrack_inter  /usr/lib/debug//usr/bin/72a2b255582607738147efc1bb99b639d5c6c9.debug -2
491026 heaptrack_inter  /usr/lib/debug//usr/lib/heaptrack/7bf6129b2bfeb03c562382e5c83a3b88c9c9e3.debug -2
491026 heaptrack_inter  /usr/lib/debug//lib/x86_64-linux-gnu/ca8289e3166be84222b2904268e7cb81a32bc4.debug -2
491026 heaptrack_inter  /usr/lib/debug//lib/x86_64-linux-gnu/c7de0acd47d86cf3580641f055295268d64c8a.debug -2
491026 heaptrack_inter  /usr/lib/debug//lib/x86_64-linux-gnu/506543854e9457d432033f640c0497e6fd472d.debug -2

# for f in $(sed -n '/ -2$/ { s///; s,.* ,,; p; }' /tmp/missing-files |sort -u); do
  tgt=( /usr/lib/debug/.build-id/*/$f:t(N) )
  [[ ! -e $f && $#tgt > 0 ]] && { mkdir -p $f:h && ln -svi $tgt[1] $f }
done

Und siehe da, plötzlich sieht man auch, welche Funktionen in Python wie viel Speicher nutzen: