llvm dev - Feb 2016 - [cfe-dev] Buildling with/without AddressSanitizer causes divergent execution behaviour

Hi Kostya & Yury,

Thanks for the advice.

On 9 February 2016 at 22:48, Kostya Serebryany <kcc at google.com>
wrote:
> Hi Dan,
>
> On Tue, Feb 9, 2016 at 10:57 AM, Dan Liew <dan at su-root.co.uk>
wrote:
>>
>> Hi,
>>
>> # TL;DR
>>
>> I've been building an application with and without the address
>> sanitizer (with gcc 5.3 and clang 3.7.1) and I've observed that the
>> application's behaviour changes (assertion hit/ not hit). I'm
>> wondering if this could be a bug in address sanitizer or if the
>> application I'm running is just buggy (e.g. doing bad things like
>> relying on memory layout, etc.). I'm also observing ASan reporting
a
>> heap-use-after-free which Valgrind is not reporting, which makes me
>> wonder if it is a false positive.
>
>
> Let us start from this heap-use-after-free report. The one in
> https://github.com/Z3Prover/z3/issues/436 looks legitimate.
> Unless the application does something extremely weird and tricky,
> heap-use-after-free reports are usually true positives.
The developers tell me they are doing some unusual things and they
believe that this might the cause of the report.
> Can you somehow verify that this heap-use-after-free is happening?
> E.g. print all the pointer values coming from memory::allocate, coming into
> memory::deallocate, and coming into sat::clause::operator[]
>
> If curious, check what size of quarantine is required to catch this bug
> (ASAN_OPTIONS=quarantine_size_mb=N, default=256)
> Valgrind may have smaller default quarantine and thus misses this bug.
I was lazy and just told valgrind to execute the program (built by gcc
without ASan) with the largest quarantine it supported.

```
LD_LIBRARY_PATH=`pwd` valgrind --freelist-vol=10000000000 ./c_example
```

It didn't report any problems. This fills me with some confidence that
when the application is compiled without ASan that it probably doesn't
have a heap-use-after-free.

> Does the application have threads? (If yes, did you run with TSan?)
Not yet but I've stumbled across an issue that looks interesting. See below
> Did you try msan?
I just have and it immediately reported a problem. I took a closer
look and it looks like a false positive to me.

Here are the steps to reproduce

```
git clone https://github.com/Z3Prover/z3.git
cd z3
git checkout 9ed7dadc0251db992b44984edfa6c586aab20ecb
CC=clang CXX=clang++ CXXFLAGS="-fsanitize=memory -fPIE -pie
-fno-omit-frame-pointer -fsanitize-memory-track-origins"
LDFLAGS="-fsanitize=memory" python scripts/mk_make.py --build
build_msan_clang --noomp --debug
cd build_msan_clang
make
make c_example
LD_LIBRARY_PATH=`pwd` ./c_example
==26936==WARNING: MemorySanitizer: use-of-uninitialized-value
    #0 0x7fa7d906f3b0 in Z3_open_log
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../src/api/api_log.cpp:33:13
    #1 0x55c0c03107f5 in main
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../examples/c/test_capi.c:2794:5
    #2 0x7fa7d78f960f in __libc_start_main (/usr/lib/libc.so.6+0x2060f)
    #3 0x55c0c024d838 in _start
(/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/c_example+0x1c838)

  Uninitialized value was created by a heap allocation
    #0 0x55c0c0253ea0 in __interceptor_malloc
(/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/c_example+0x22ea0)
    #1 0x7fa7e2a6c120 in memory::allocate(unsigned long)
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../src/util/memory_manager.cpp:276:16
    #2 0x7fa7d906f125 in Z3_open_log
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../src/api/api_log.cpp:31:20
    #3 0x55c0c03107f5 in main
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../examples/c/test_capi.c:2794:5
    #4 0x7fa7d78f960f in __libc_start_main (/usr/lib/libc.so.6+0x2060f)

SUMMARY: MemorySanitizer: use-of-uninitialized-value
/home/dsl11/dev/klee/z3/z3_upstream/build_msan_clang/../src/api/api_log.cpp:33:13
in Z3_open_log
Exiting
```

Side note using ``MSAN_OPTIONS="halt_on_error=0`` doesn't seem to do
anything, the application always exits when it hits the reported bug.
I'd like a way to catch this in gdb but I'm not sure how to do it.

I took a look. MSan is complaining about this code

```
std::ostream * g_z3_log = 0;

...

    Z3_bool Z3_API Z3_open_log(Z3_string filename) {
        if (g_z3_log != 0)
            Z3_close_log();
        g_z3_log = alloc(std::ofstream, filename);
        g_z3_log_enabled = true;
        if (g_z3_log->bad() || g_z3_log->fail()) {
            dealloc(g_z3_log);
            g_z3_log = 0;
            return Z3_FALSE;
        }
        return Z3_TRUE;
    }
```

It seems to be complaining that ``g_z3_log`` is uninitialised when
doing ``g_z3_log->bad() || g_z3_log->fail()``. This seems incorrect
because ``alloc()`` appears to be this macro (see
``src/util/memory_manager.h``).

```
#define alloc(T,...) new (memory::allocate(sizeof(T))) T(__VA_ARGS__)
```
With the macro expanded it looks like this

```
g_z3_log = new (memory::allocate(sizeof(std::ofstream)))
std::ofstream(filename);
```

I think this is calling the "placement" version of ``operator new``
and so constructs a new object (in this case ``std::ofstream``)  using
the constructor but uses the memory allocated by
``memory::allocate(sizeof(T))``.

Therefore the memory in the pointer ``g_z3_log`` is initialised and
the "use-of-uninitialized-value" report is a false positive. Would you
agree with this assessment?

Thanks,
Dan.

On Thu, Feb 11, 2016 at 5:53 AM, Dan Liew via cfe-dev <
cfe-dev at lists.llvm.org> wrote:
>
> > Can you somehow verify that this heap-use-after-free is happening?
> > E.g. print all the pointer values coming from memory::allocate, coming
> into
> > memory::deallocate, and coming into sat::clause::operator[]
> >
> > If curious, check what size of quarantine is required to catch this
bug
> > (ASAN_OPTIONS=quarantine_size_mb=N, default=256)
> > Valgrind may have smaller default quarantine and thus misses this bug.
>
> I was lazy and just told valgrind to execute the program (built by gcc
> without ASan) with the largest quarantine it supported.
>
There are some differences between Clang and GCC, such as left-to-right vs
right-to-left argument evaluation. This usually bites people who are moving
unique_ptr or vector and accessing it in the same expression. Given the
stack traces, I suspect that different orderings of refcount operations is
what's happening here. I would suggest building Z3 with Clang without ASan
and running valgrind on that.

> > Did you try msan?
>
> I just have and it immediately reported a problem. I took a closer
> look and it looks like a false positive to me.
>
...

This is because your STL was not compiled with MSan. The std::ofstream
constructor is provided by libstdc++, the writes are not instrumented, and
MSan never sees the initialization. Unfortunately, MSan is not very useful
unless you recompile your *entire* application minus glibc with msan. =/

It is possible to build an MSan-ified libc++ and use it if you want to keep
trying, but it's involved.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.llvm.org/pipermail/llvm-dev/attachments/20160211/a3628a27/attachment.html>

On Thu, Feb 11, 2016 at 9:08 AM, Reid Kleckner <rnk at google.com> wrote:
> On Thu, Feb 11, 2016 at 5:53 AM, Dan Liew via cfe-dev <
> cfe-dev at lists.llvm.org> wrote:
>>
>> > Can you somehow verify that this heap-use-after-free is happening?
>> > E.g. print all the pointer values coming from memory::allocate,
coming
>> into
>> > memory::deallocate, and coming into sat::clause::operator[]
>> >
>> > If curious, check what size of quarantine is required to catch
this bug
>> > (ASAN_OPTIONS=quarantine_size_mb=N, default=256)
>> > Valgrind may have smaller default quarantine and thus misses this
bug.
>>
>> I was lazy and just told valgrind to execute the program (built by gcc
>> without ASan) with the largest quarantine it supported.
>>
>
> There are some differences between Clang and GCC, such as left-to-right vs
> right-to-left argument evaluation. This usually bites people who are moving
> unique_ptr or vector and accessing it in the same expression. Given the
> stack traces, I suspect that different orderings of refcount operations is
> what's happening here. I would suggest building Z3 with Clang without
ASan
> and running valgrind on that.
>
>
>> > Did you try msan?
>>
>> I just have and it immediately reported a problem. I took a closer
>> look and it looks like a false positive to me.
>>
> ...
>
> This is because your STL was not compiled with MSan. The std::ofstream
> constructor is provided by libstdc++, the writes are not instrumented, and
> MSan never sees the initialization. Unfortunately, MSan is not very useful
> unless you recompile your *entire* application minus glibc with msan. =/
>
> It is possible to build an MSan-ified libc++ and use it if you want to
> keep trying, but it's involved.
>
Exact steps:
https://github.com/google/sanitizers/wiki/MemorySanitizerLibcxxHowTo
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.llvm.org/pipermail/llvm-dev/attachments/20160211/c6313506/attachment.html>

On 11 February 2016 at 17:08, Reid Kleckner <rnk at google.com>
wrote:
> On Thu, Feb 11, 2016 at 5:53 AM, Dan Liew via cfe-dev
> <cfe-dev at lists.llvm.org> wrote:
>>
>> > Can you somehow verify that this heap-use-after-free is happening?
>> > E.g. print all the pointer values coming from memory::allocate,
coming
>> > into
>> > memory::deallocate, and coming into sat::clause::operator[]
>> >
>> > If curious, check what size of quarantine is required to catch
this bug
>> > (ASAN_OPTIONS=quarantine_size_mb=N, default=256)
>> > Valgrind may have smaller default quarantine and thus misses this
bug.
>>
>> I was lazy and just told valgrind to execute the program (built by gcc
>> without ASan) with the largest quarantine it supported.
>
>
> There are some differences between Clang and GCC, such as left-to-right vs
> right-to-left argument evaluation. This usually bites people who are moving
> unique_ptr or vector and accessing it in the same expression. Given the
> stack traces, I suspect that different orderings of refcount operations is
> what's happening here. I would suggest building Z3 with Clang without
ASan
> and running valgrind on that.
Yeah I tried building Z3 with Clang without ASan and running Valgrind.
It didn't report any problems.

I don't think this is a GCC vs Clang problem. When I build Z3 with GCC
or Clang with ASan enabled both of them report
the same heap-use-after-free issue.

The original problem I reported (the divergent behaviour when building
with and without ASan, i.e. the assert being hit/not hit respectively)
should be disregarded.
I was struggling to reproduce the issue just now and I gave up and
then I accidently hit it again. Then when I tried to run valgrind on a
binary (that wasn't supposed to be built
with ASan) built by Z3's build system it complained about ASan. I
think there's something with wrong with Z3's build system and reusing
the same binary directory for non-asan / asan
build is broken in some way. Lesson learnt, always use a fresh binary
build directory!

The heap-use-after-free issue is reproducible though. I'll report out
what I found to the Z3 devs and leave it for now.
>>
>> > Did you try msan?
>>
>> I just have and it immediately reported a problem. I took a closer
>> look and it looks like a false positive to me.
>
> ...
>
> This is because your STL was not compiled with MSan. The std::ofstream
> constructor is provided by libstdc++, the writes are not instrumented, and
> MSan never sees the initialization. Unfortunately, MSan is not very useful
> unless you recompile your *entire* application minus glibc with msan. =/
>
> It is possible to build an MSan-ified libc++ and use it if you want to keep
> trying, but it's involved.
Thanks for pointing out. Out of interest how is MSan able to work with
a non MSan-ified glibc?

Thanks,
Dan.