On Mon, Feb 21 2022, Taylor Blau wrote:

On Mon, Feb 21, 2022 at 04:58:35PM +0100, Ævar Arnfjörð Bjarmason wrote:

quoted

Add "fast_unwind_on_malloc=0" to LSAN_OPTIONS to get more meaningful
stack traces from LSAN. This isn't required under ASAN which will emit
traces such as this one for a leak in "t/t0006-date.sh":

    $ ASAN_OPTIONS=detect_leaks=1 ./t0006-date.sh -vixd
    [...]
    Direct leak of 3 byte(s) in 1 object(s) allocated from:
        #0 0x488b94 in strdup (t/helper/test-tool+0x488b94)
        #1 0x9444a4 in xstrdup wrapper.c:29:14
        #2 0x5995fa in parse_date_format date.c:991:24
        #3 0x4d2056 in show_dates t/helper/test-date.c:39:2
        #4 0x4d174a in cmd__date t/helper/test-date.c:116:3
        #5 0x4cce89 in cmd_main t/helper/test-tool.c:127:11
        #6 0x4cd1e3 in main common-main.c:52:11
        #7 0x7fef3c695e49 in __libc_start_main csu/../csu/libc-start.c:314:16
        #8 0x422b09 in _start (t/helper/test-tool+0x422b09)

    SUMMARY: AddressSanitizer: 3 byte(s) leaked in 1 allocation(s).
    Aborted

Whereas LSAN would emit this instead:

    $ ./t0006-date.sh -vixd
    [...]
    Direct leak of 3 byte(s) in 1 object(s) allocated from:
        #0 0x4323b8 in malloc (t/helper/test-tool+0x4323b8)
        #1 0x7f2be1d614aa in strdup string/strdup.c:42:15

    SUMMARY: LeakSanitizer: 3 byte(s) leaked in 1 allocation(s).
    Aborted

Now we'll instead git this sensible stack trace under
LSAN. I.e. almost the same one (but starting with "malloc", as is
usual for LSAN) as under ASAN:

    Direct leak of 3 byte(s) in 1 object(s) allocated from:
        #0 0x4323b8 in malloc (t/helper/test-tool+0x4323b8)
        #1 0x7f012af5c4aa in strdup string/strdup.c:42:15
        #2 0x5cb164 in xstrdup wrapper.c:29:14
        #3 0x495ee9 in parse_date_format date.c:991:24
        #4 0x453aac in show_dates t/helper/test-date.c:39:2
        #5 0x453782 in cmd__date t/helper/test-date.c:116:3
        #6 0x451d95 in cmd_main t/helper/test-tool.c:127:11
        #7 0x451f1e in main common-main.c:52:11
        #8 0x7f012aef5e49 in __libc_start_main csu/../csu/libc-start.c:314:16
        #9 0x42e0a9 in _start (t/helper/test-tool+0x42e0a9)

    SUMMARY: LeakSanitizer: 3 byte(s) leaked in 1 allocation(s).
    Aborted

This is great, by the way. I have often hit that bug in LSan and been
incredibly frustrated by it. I'm happy to see it getting fixed here,
thank you.

Cheers!

quoted

As the option name suggests this does make things slower, e.g. for
t0001-init.sh we're around 10% slower:

    $ hyperfine -L v 0,1 'LSAN_OPTIONS=fast_unwind_on_malloc={v} make T=t0001-init.sh' -r 3
    Benchmark 1: LSAN_OPTIONS=fast_unwind_on_malloc=0 make T=t0001-init.sh
      Time (mean ± σ):      2.135 s ±  0.015 s    [User: 1.951 s, System: 0.554 s]
      Range (min … max):    2.122 s …  2.152 s    3 runs

    Benchmark 2: LSAN_OPTIONS=fast_unwind_on_malloc=1 make T=t0001-init.sh
      Time (mean ± σ):      1.981 s ±  0.055 s    [User: 1.769 s, System: 0.488 s]
      Range (min … max):    1.941 s …  2.044 s    3 runs

    Summary
      'LSAN_OPTIONS=fast_unwind_on_malloc=1 make T=t0001-init.sh' ran
        1.08 ± 0.03 times faster than 'LSAN_OPTIONS=fast_unwind_on_malloc=0 make T=t0001-init.sh'

I think that's more than worth it to get the more meaningful stack
traces, we can always provide LSAN_OPTIONS=fast_unwind_on_malloc=0 for
one-off "fast" runs.

I completely agree. I am almost always run ASan / LSan tests a single
script at a time (often focusing on just one script that I know
demonstrates some bug).

At GitHub, we use both a sanitized and un-sanitized build when running
CI. So we'll probably feel the effects a little more during the "run
make test under a sanitized build" CI job, but we could easily set
fast_unwind_on_malloc=0 if it becomes too big of a problem for us
(though I suspect it won't matter in practice).

I suspect you mean SANITIZE=address not SANITIZE=leak, i.e. ASAN not
LSAN. Note that the performance of the two is often quite different
(with ASAN starting out much slower).

I almost never use ASAN, but I've been using LSAN a lot.

I also haven't been able to have ASAN spew out these worse stack traces,
as noted in the commit message. But in some brief testing now if I were
setting fast_unwind_on_malloc=0 it would be around 15% slower:
    
    $ hyperfine -L v 0,1 'ASAN_OPTIONS=fast_unwind_on_malloc={v} make T=t0001-init.sh' -r 5
    Benchmark 1: ASAN_OPTIONS=fast_unwind_on_malloc=0 make T=t0001-init.sh
      Time (mean ± σ):      3.264 s ±  0.014 s    [User: 2.456 s, System: 0.927 s]
      Range (min … max):    3.249 s …  3.282 s    5 runs
     
    Benchmark 2: ASAN_OPTIONS=fast_unwind_on_malloc=1 make T=t0001-init.sh
      Time (mean ± σ):      2.826 s ±  0.023 s    [User: 2.008 s, System: 0.936 s]
      Range (min … max):    2.814 s …  2.866 s    5 runs
     
    Summary
      'ASAN_OPTIONS=fast_unwind_on_malloc=1 make T=t0001-init.sh' ran
        1.15 ± 0.01 times faster than 'ASAN_OPTIONS=fast_unwind_on_malloc=0 make T=t0001-init.sh'

But I don't know in the ASAN case what, if anything, you're getting for
that reduction in performance.