Bug 471807 - Add support for lazy reading and downloading of DWARF debuginfo
Summary: Add support for lazy reading and downloading of DWARF debuginfo
Status: RESOLVED FIXED
Alias: None
Product: valgrind
Classification: Developer tools
Component: general (other bugs)
Version First Reported In: unspecified
Platform: Other Linux
: NOR normal
Target Milestone: ---
Assignee: Julian Seward
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-06-30 23:59 UTC by Aaron Merey
Modified: 2023-09-25 21:03 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments
patch (46.20 KB, patch)
2023-06-30 23:59 UTC, Aaron Merey
Details
patch-v2 (50.60 KB, patch)
2023-07-12 21:14 UTC, Aaron Merey
Details
patch v3 (50.93 KB, patch)
2023-07-19 03:19 UTC, Aaron Merey
Details
patch v4 (44.91 KB, patch)
2023-07-31 05:02 UTC, Aaron Merey
Details
patch v5 (36.00 KB, patch)
2023-08-09 01:39 UTC, Aaron Merey
Details
patch v6 (35.86 KB, patch)
2023-08-16 04:50 UTC, Aaron Merey
Details
ppc fix (1.52 KB, patch)
2023-08-30 19:11 UTC, Aaron Merey
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Aaron Merey 2023-06-30 23:59:16 UTC
Created attachment 160009 [details]
patch

Currently valgrind attempts to read DWARF .debug_* sections as well as separate debuginfo files for ELF shared library binaries as soon as each shared library is loaded.  This might also result in the downloading of separate debuginfo files via debuginfod.

This is inefficient when some of this debuginfo never ends up being used by valgrind.

I've attached a patch that adds support for lazy reading and downloading of DWARF debuginfo to help address this inefficiency. Currently only AMD64 Linux is supported.

For the handful of client processes I've tested this with, I've seen ~25% reduction in the total amount of debuginfo data valgrind downloads. When all debuginfo for these processes is pre-downloaded, I've seen a ~10% average reduction in the time it takes for these processes to run and exit under valgrind. When valgrind must download all debuginfo, I've seen a ~20% average reduction in the time it takes for the processes to run and exit under valgrind.
Comment 1 Mark Wielaard 2023-07-07 17:14:42 UTC
(In reply to Aaron Merey from comment #0)
> Currently only AMD64 Linux is supported.

Why is that? The patch looks generic for ELF platforms. Is there something specific for amd64? Or is it just not tested on anything else?
Comment 2 Aaron Merey 2023-07-07 18:26:47 UTC
(In reply to Mark Wielaard from comment #1)
> (In reply to Aaron Merey from comment #0)
> > Currently only AMD64 Linux is supported.
> 
> Why is that? The patch looks generic for ELF platforms. Is there something
> specific for amd64? Or is it just not tested on anything else?

Sorry that should have said amd64 ELF platforms. Currently only the amd64 get_StackTrace_wrk contains calls to addr_load_di, which performs the lazy reading.  I'm working on v2 of this patch which adds support for ELF platforms that are non-amd64.
Comment 3 Aaron Merey 2023-07-12 21:14:55 UTC
Created attachment 160259 [details]
patch-v2

I've updated the patch with lazy debuginfo support for all ELF platforms. I regression tested this on Fedora 38 x86_64, aarch64, s390x and ppc64le.
Comment 4 Mark Wielaard 2023-07-18 13:52:08 UTC
(In reply to Aaron Merey from comment #3)
> Created attachment 160259 [details]
> patch-v2
> 
> I've updated the patch with lazy debuginfo support for all ELF platforms. I
> regression tested this on Fedora 38 x86_64, aarch64, s390x and ppc64le.

make check && make regtest
does show a couple of new stderr failures under helgrind/tests which all contain:

valgrind: m_deduppoolalloc.c:377 (vgPlain_indexEltNumber): Assertion '(UChar*)dedup_elt >= ddpa->curpool && (UChar*)dedup_elt < ddpa->curpool_free' failed.

Also ...checking makefile consistency
memcheck/tests/linux/Makefile.am:1: error: debuginfod-check-deferred.stderr.exp is missing in EXTRA_DIST
Comment 5 Aaron Merey 2023-07-19 03:19:43 UTC
Created attachment 160375 [details]
patch v3

(In reply to Mark Wielaard from comment #4)
> make check && make regtest
> does show a couple of new stderr failures under helgrind/tests which all
> contain:
> 
> valgrind: m_deduppoolalloc.c:377 (vgPlain_indexEltNumber): Assertion
> '(UChar*)dedup_elt >= ddpa->curpool && (UChar*)dedup_elt <
> ddpa->curpool_free' failed.

Interesting, these tests pass if valgrind and the test executables are built with '-O0', which is what I used during testing. But I can reproduce the failures by using -Og or by leaving the optimization level unspecified.

I've attached v3 of the patch that fixes this assert failure.
Comment 6 Mark Wielaard 2023-07-22 16:45:31 UTC
Do we need a --enable-lazy-debuginfo=[yes|no] flag?
Is there any advantage to the user to set it to no?
Less variants in the code seems good.
Comment 7 Mark Wielaard 2023-07-22 21:13:04 UTC
v3 does work. But I admit to not fully understand why/how.
The addr_load_di calls in coregrind/m_stacktrace..c seems unnecessary (you can comment them out and things still work fine).
This is because there is a addr_load_di call in describe_IP and find_DiCfSI.
Which makes sense since those methods are called when the debuginfo for an executable address are consulted.

I do wonder if addr_load_di can be made a bit cheaper. Currently it does a search for the DebugInfo by calling find_DebugInfo which goes over the debugInfo_list. find_DiCfSI does something similar. And describe_IP is called with a InlIPCursor which already is associated with a particular DebugInfo. I couldn't immediately find a way to "load" those DebugInfos instead of calling addr_load_di, so maybe the "double" search is necessary.
Comment 8 Aaron Merey 2023-07-31 05:02:12 UTC
Created attachment 160636 [details]
patch v4

(In reply to Mark Wielaard from comment #6)
> Do we need a --enable-lazy-debuginfo=[yes|no] flag?
> Is there any advantage to the user to set it to no?
> Less variants in the code seems good.

Maybe there are some cases where it is preferable for valgrind to
minimize pausing execution of the client process? Downloading
debuginfo as soon as the shared library is linked might be better
here.

(In reply to Mark Wielaard from comment #7)
> v3 does work. But I admit to not fully understand why/how.
> The addr_load_di calls in coregrind/m_stacktrace..c seems unnecessary (you
> can comment them out and things still work fine).
> This is because there is a addr_load_di call in describe_IP and find_DiCfSI.
> Which makes sense since those methods are called when the debuginfo for an
> executable address are consulted.

Nice catch.

> I do wonder if addr_load_di can be made a bit cheaper. Currently it does a
> search for the DebugInfo by calling find_DebugInfo which goes over the
> debugInfo_list. find_DiCfSI does something similar. And describe_IP is
> called with a InlIPCursor which already is associated with a particular
> DebugInfo. I couldn't immediately find a way to "load" those DebugInfos
> instead of calling addr_load_di, so maybe the "double" search is necessary.

In patch v4, I added a load_di function that takes a debuginfo and ip
and loads the debuginfo if the ip is in the appropriate text segment.
This removes an unnecessary iteration over the debuginfo_list in
find_DiCfSI.  As for describe_IP, I think we still want to use addr_load_di
in case the InlIPCursor is NULL.
Comment 9 Mark Wielaard 2023-08-02 14:15:15 UTC
(In reply to Aaron Merey from comment #8)
> (In reply to Mark Wielaard from comment #6)
> > Do we need a --enable-lazy-debuginfo=[yes|no] flag?
> > Is there any advantage to the user to set it to no?
> > Less variants in the code seems good.
> 
> Maybe there are some cases where it is preferable for valgrind to
> minimize pausing execution of the client process? Downloading
> debuginfo as soon as the shared library is linked might be better
> here.

In that case it might be simpler to simply disable all debuginfo downloading.
If you think it really is an option people would use then ok.
But I do like to keep the number of (unused) options and code paths to a minimum when possible.

> > I do wonder if addr_load_di can be made a bit cheaper. Currently it does a
> > search for the DebugInfo by calling find_DebugInfo which goes over the
> > debugInfo_list. find_DiCfSI does something similar. And describe_IP is
> > called with a InlIPCursor which already is associated with a particular
> > DebugInfo. I couldn't immediately find a way to "load" those DebugInfos
> > instead of calling addr_load_di, so maybe the "double" search is necessary.
> 
> In patch v4, I added a load_di function that takes a debuginfo and ip
> and loads the debuginfo if the ip is in the appropriate text segment.
> This removes an unnecessary iteration over the debuginfo_list in
> find_DiCfSI.  As for describe_IP, I think we still want to use addr_load_di
> in case the InlIPCursor is NULL.

Nice. Patch4 looks a lot more streamlined.

Can we do something like:

   if (iipc && iipc->di)
      VG_(load_di) (iipc->di, eip);
   else
      VG_(addr_load_di) (eip);

To reduce the extra search? And is the else part really necessary?
Comment 10 Aaron Merey 2023-08-09 01:39:59 UTC
Created attachment 160848 [details]
patch v5

(In reply to Mark Wielaard from comment #9)
> (In reply to Aaron Merey from comment #8)
> > Maybe there are some cases where it is preferable for valgrind to
> > minimize pausing execution of the client process? Downloading
> > debuginfo as soon as the shared library is linked might be better
> > here.
> 
> In that case it might be simpler to simply disable all debuginfo downloading.
> If you think it really is an option people would use then ok.
> But I do like to keep the number of (unused) options and code paths to a
> minimum when possible.

Fair enough, we can always add the option later if there is a desire for it.
Patch v5 attachment has the option removed.
 
> Can we do something like:
> 
>    if (iipc && iipc->di)
>       VG_(load_di) (iipc->di, eip);
>    else
>       VG_(addr_load_di) (eip);
> 
> To reduce the extra search? And is the else part really necessary?

Patch v5 has this added to describe_IP. The else part is necessary since
removing it caused testsuite regressions.
Comment 11 Mark Wielaard 2023-08-15 16:46:52 UTC
Thanks for those changes, they look good. Some minor comments/thoughts:

The move_DebugInfo_one_step_forward in VG_(load_di) and VG_(addr_load_di) seem unnecessary, but mostly harmless.
Those are optimizations for VG_(find_DebugInfo) and find_DiCfSI, should probably only be done there.

ML_(canonicaliseTables) looks correct, you don't want to freeze if deferred, there could be a separate .symtab show up.

I don't fully understand the ML_(finish_CFSI_arrays) early return. Does that ever happen? Is .eh_frame not always read early because it is always in the main ELF image? Or do we also handle .debug_frame? Ah, we do. OK then we don't want to free cfsi_rd just yet.

This looks good. I think we should remove those two move_DebugInfo_one_step_forward calls. I like to commit this with that small change so we can test it a bit more widely.
Comment 12 Aaron Merey 2023-08-16 04:50:20 UTC
Created attachment 160996 [details]
patch v6

(In reply to Mark Wielaard from comment #11)
> The move_DebugInfo_one_step_forward in VG_(load_di) and VG_(addr_load_di)
> seem unnecessary, but mostly harmless.
> Those are optimizations for VG_(find_DebugInfo) and find_DiCfSI, should
> probably only be done there.
> [...] 
> This looks good. I think we should remove those two
> move_DebugInfo_one_step_forward calls. I like to commit this with that small
> change so we can test it a bit more widely.

Thanks for all of these reviews. I've attached patch v6 with the move_DebugInfo_one_step_forward calls removed.
Comment 13 Mark Wielaard 2023-08-16 12:17:41 UTC
commit 60f7e89ba32b54d73b9e36d49e28d0f559ade0b9
Author: Aaron Merey <amerey@redhat.com>
Date:   Fri Jun 30 18:31:42 2023 -0400

    Support lazy reading and downloading of DWARF debuginfo
    
    Currently valgrind attempts to read DWARF .debug_* sections as well
    as separate debuginfo files for ELF binaries as soon as a shared library
    is loaded.  This might also result in the downloading of separate debuginfo
    files via debuginfod.
    
    This is inefficient when some of this debuginfo never ends up being used
    by valgrind while running the client process.
    
    This patch adds support for lazy reading and downloading of DWARF
    debuginfo.  When an ELF shared library is loaded, the reading of .debug_*
    sections as well as separate or alternate debuginfo is deferred until
    valgrind handles an instruction pointer corresponding to a text segment
    of the shared library.  At this point the deferred sections and separate
    debug files are loaded.
    
    This feature is only supported on ELF platforms.
    
    https://bugs.kde.org/show_bug.cgi?id=471807
    
    ChangeLog
            * debuginfo.c (di_notify_ACHIEVE_ACCEPT_STATE): Replace
            read_elf_debug_info with read_elf_object.
            (addr_load_di): New function.  Attempts to load deferred debuginfo
            associated with a given address.
            (load_di): New function.  Attempts to load a given deferred
            debuginfo associated with a given address.
            (describe_IP): Add calls to load_di and addr_load_di.
            (find_DiCfSI): Add call to load_di.
    
            * priv_readelf.h (read_elf_object): New declaration.
            (read_elf_debug): Ditto.
    
            * priv_storage.h (struct _DebugInfo): New field 'bool deferred'.
    
            * readelf.c (read_elf_debug_info): Split into read_elf_object and
            read_elf_debug.
            (read_elf_object): Read non .debug_* section from an ELF binary.
            (read_elf_debug): Read .debug_* sections from an ELF binary as
            as well any separate/alternate debuginfo files.
    
            * storage.c (canonicaliseSymtab): Remove assert in order to support
            canonicalization of deferred _DebugInfo.
            (finish_CFSI_arrays): Add early return if _DebugInfo is
            deferred in order to avoid freeing memory that will be needed
            when reading debuginfo at a later time.
            (canonicaliseTables): Ditto.
    
            * pub_core_debuginfo.h (addr_load_di): New declaration.
            (load_di): New declaration.
Comment 14 Mark Wielaard 2023-08-17 11:21:47 UTC
I have seen no regressions from this patch. At least not in the nightly tests.
There was one issue on s390x. drd/tests/getaddrinfo would randomly fail (one in ~5 times).
But this can also be replicated when reverting this patch.
Comment 15 Mark Wielaard 2023-08-21 12:37:02 UTC
Note there was one cleanup followup for an error case:

commit a0d555a0dfe078ef04ea49d991a8090ab14bd4a5
Author: Paul Floyd <pjfloyd@wanadoo.fr>
Date:   Sat Aug 19 21:37:33 2023 +0200

    Always cleanup on exit from ML_(read_elf_object)
Comment 16 Mark Wielaard 2023-08-27 15:28:37 UTC
This did create some regressions on linux-ppc64le:

memcheck/tests/inlinfo                   (stderr)
memcheck/tests/inlinfosupp               (stderr)
memcheck/tests/inlinfosuppobj            (stderr)
memcheck/tests/inltemplate               (stderr)
memcheck/tests/leak_cpp_interior         (stderr)
memcheck/tests/overlap                   (stderr)
memcheck/tests/suppsrc_sanlineno         (stderr)
memcheck/tests/varinfo2                  (stderr)
memcheck/tests/varinfo3                  (stderr)
memcheck/tests/varinfo4                  (stderr)
memcheck/tests/varinforestrict           (stderr)
helgrind/tests/hg03_inherit              (stderr)
helgrind/tests/hg04_race                 (stderr)
helgrind/tests/hg04_race_h9              (stderr)
helgrind/tests/hg05_race2                (stderr)
helgrind/tests/rwlock_race               (stderr)
helgrind/tests/tc01_simple_race          (stderr)
helgrind/tests/tc05_simple_race          (stderr)
helgrind/tests/tc06_two_races            (stderr)
helgrind/tests/tc06_two_races_xml        (stderr)
helgrind/tests/tc16_byterace             (stderr)
helgrind/tests/tc20_verifywrap           (stderr)
helgrind/tests/tc21_pthonce              (stderr)
drd/tests/annotate_ignore_rw             (stderr)
drd/tests/annotate_ignore_rw2            (stderr)
drd/tests/annotate_ignore_write          (stderr)
drd/tests/annotate_ignore_write2         (stderr)
drd/tests/atomic_var                     (stderr)
drd/tests/fp_race                        (stderr)
drd/tests/fp_race_xml                    (stderr)
drd/tests/hg03_inherit                   (stderr)
drd/tests/hg04_race                      (stderr)
drd/tests/hg05_race2                     (stderr)
drd/tests/pth_detached3                  (stderr)
drd/tests/rwlock_race                    (stderr)
drd/tests/sem_as_mutex                   (stderr)
drd/tests/sem_as_mutex3                  (stderr)
drd/tests/sem_open                       (stderr)
drd/tests/sem_open3                      (stderr)
drd/tests/tc01_simple_race               (stderr)
drd/tests/tc16_byterace                  (stderr)

The patch depends on a call to find_DiCfSI triggering a full debuginfo load.
find_DiCfSI is (indirectly called) when ML_(get_CFA) is called.
It looks like ppc64le doesn't call ML_(get_CFA) because we have the following in
coregrind/m_debuginfo/d3basics.c

#if defined(VGP_ppc32_linux) || defined(VGP_ppc64be_linux) \
    || defined(VGP_ppc64le_linux)
            /* Valgrind on ppc32/ppc64 currently doesn't use unwind info. */
            uw1 = ML_(read_Addr)((UChar*)regs->sp);
#else
            uw1 = ML_(get_CFA)(regs->ip, regs->sp, regs->fp, 0, ~(UWord) 0);
#endif
Comment 17 Carl Love 2023-08-29 23:25:05 UTC
I have been poking around a little on the issue on Power 10 to see what the cause is of the failures this patch seems to be causing.  

I tried one of the failing tests memcheck/tests/doublefree.

valgrind --tool=memcheck  -q ./doublefree 
==427300== Invalid free() / delete / delete[] / realloc()
==427300==    at 0x40A8DD8: free (vg_replace_malloc.c:974)
==427300==    by 0x10000793: main (doublefree.c:10)
==427300==  Address 0x4350040 is 0 bytes inside a block of size 177 free'd
==427300==    at 0x40A8DD8: free (vg_replace_malloc.c:974)
==427300==    by 0x10000793: main (doublefree.c:10)
==427300==  Block was alloc'd at
==427300==    at 0x40A53F8: malloc (vg_replace_malloc.c:431)
==427300==    by 0x1000076F: main (doublefree.c:8)
==427300== 

At the moment, it looks like the issue is with freeing memory.   There may also be an issue with the debug info stuff but I don't seem to be hitting that yet.
Comment 18 Aaron Merey 2023-08-30 19:11:36 UTC
Created attachment 161290 [details]
ppc fix

I've attached a patch that should fix the ppc regressions. I posted it to the valgrind-developers list and I'm also posting it here for completeness.
Comment 19 Carl Love 2023-08-30 22:51:04 UTC
The ppc patch was tested on a variety of Power Platforms.   Here is what I am seeing before the commit to add the lazy loading, 
with the current Valgrind mainline (includes the lazy commit) and with the patch to fix the lazy load on Power:

machine         pre-lazy-load           current mainline        with ppc debuginfo fix
Power 8 LE      707 tests,              708 tests,              708 tests
                4 stderr failures,      280 stderr failures,    247 stderr failures, 
                0 stdout failures,      54 stdout failures,     54 stdout failures,
                13 stderrB failures,    16 stderrB failures,    16 stderrB failures,
                0 stdoutB failures,     11 stdoutB failures,    12 stdoutB failures
                9 post failures         13 post failures        9 post failures

Power 8 BE      742 tests,              743 tests,              743 tests,      
                2 stderr failures,      671 stderr failures,    671 stderr failures,
                0 stdout failures,      152 stdout failures,    152 stdout failures,
                0 stderrB failures,     14 stderrB failures,    14 stderrB failures,
                2 stdoutB failures,     20 stdoutB failures,    20 stdoutB failures,
                9 post failures         43 post failures        43 post failures

Power 9 LE      711 tests,              712 tests,              712 tests,
                4 stderr failures,      280 stderr failures,    247 stderr failures,
                0 stdout failures,      54 stdout failures,     54 stdout failures,
                13 stderrB failures,    16 stderrB failures,    16 stderrB failures,
                0 stdoutB failures,     12 stdoutB failures,    12 stdoutB failures
                9 post failures         13 post failures        9 post failures

Power 10 LE     719 tests               720 tests,              720 tests,
                2 stderr failures,      42 stderr failures,     2 stderr failures,
                0 stdout failures,      0 stdout failures,      0 stdout failures,
                2 stderrB failures,     2 stderrB failures,     2 stderrB failures,
                10 stdoutB failures,    10 stdoutB failures,    10 stdoutB failures,
                0 post failures         3 post failures         0 post failures
Comment 20 Carl Love 2023-09-25 21:02:04 UTC
Aaron created a patch to fix the BE failures.  It was sent out on Monday Sept 18, subject Re: [Valgrind-developers] ppc64le results

From 626b205bb9fbe209353b708ace7b22644ca0607a Mon Sep 17 00:00:00 2001
From: Aaron Merey <amerey@redhat.com>
Date: Mon, 18 Sep 2023 17:42:42 -0400
Subject: [PATCH] Try to find section .opd in read_elf_object

read_elf_debug skips checking for .opd ELF section, causing
assert failures on PPC BE.

This patch adds the missing check for .opd.
---
 coregrind/m_debuginfo/readelf.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/coregrind/m_debuginfo/readelf.c b/coregrind/m_debuginfo/readelf.c
index 13efc46b8..56a9ce6b2 100644
--- a/coregrind/m_debuginfo/readelf.c
+++ b/coregrind/m_debuginfo/readelf.c
@@ -2883,6 +2883,7 @@ Bool ML_(read_elf_object) ( struct _DebugInfo* di )
 #        if defined(VGO_solaris)
          FIND_MIMG(   ".SUNW_ldynsym",      ldynsym_escn)
 #        endif
+         FIND_MIMG(   ".opd",               opd_escn)
 
          FINDX_MIMG(  ".eh_frame",          ehframe_escn[ehframe_mix],
                do { ehframe_mix++; vg_assert(ehframe_mix <= N_EHFRAME_SECTS);
-- 
2.41.0
Comment 21 Carl Love 2023-09-25 21:03:33 UTC
I tested the patch on PowerPC BE.  Test results:


Power 8 BE  Ubuntu 20.04.5 LTS (Focal Fossa)
pre-lazy-load           with Explicitly-load-           initialize opd_escn
                        (as of 8/31/2023)               (9/18/2023)

742 tests,              743 tests,                      743 tests
2 stderr failures,      671 stderr failures,            2 stderr failures
0 stdout failures,      152 stdout failures,            0 stdout failures
0 stderrB failures,     14 stderrB failures,            0 stderrB failures
2 stdoutB failures,     20 stdoutB failures,            2 stdoutB failures      
9 post failures         43 post failures                9 post failures

Patch fixes the PowerPC BE issues.