Low input stability

[Kurt Roeckx]

Hi,

I've just upgraded to 2.21b and was looking at the new input
stability value. I'm getting a value of 71.51%. I'm using
afl-clang-fast.

I'm looking at the openssl "ct" fuzzer currently.

I have always assumed that the reason for some of the behaviour I
see is related to this input stability and is caused by global
variables that get initliazed in certain cases. For instance, on
the first error it's loading the error strings, the first time it
needs digests it loads them, and so on.

So I tried to add a call to OPENSSL_init_crypto() that is outside
the __AFL_LOOP(). This seems to have made things worse. Using it
I get:
71.36% OPENSSL_INIT_LOAD_CRYPTO_STRINGS
66.92% OPENSSL_INIT_ADD_ALL_DIGESTS
59.20% OPENSSL_INIT_ADD_ALL_CIPHERS
57.65% all 3

Using the negative values that prevent the auto initialization on
the other hand turns it into 92.24%

So it clearly seems to have an effect on it, but I don't
understand why I'm seeing a negative effect when I try to
initialize things early.

Is there some way I can debug this and know what is different?


Kurt

[Michal Zalewski]

> I have always assumed that the reason for some of the behaviour I
> see is related to this input stability and is caused by global
> variables that get initliazed in certain cases.

There's a bunch of possible explanations (see status_screen.txt). In
persistent mode, the intrinsic source of instability is the fact that
the loop eventually exits every 1000 iterations (or whatever you pass
to __AFL_LOOP as a parameter), so the loop exit conditional branch
takes a different turn. But that should be a very small difference,
unless there's a lot of code executed after the loop - explicitly or
implicitly through constructs such as atexit().

Another source of instability may be the fact that the loop may not
clean up the state perfectly, and yup, that the subsequent iterations
work differently or not work at all. Only the latter should result in
the "stability" metric taking a major dip.

More substantial exec path variability can be a product of concurrent
threads (although this should be mitigated in llvm_mode) or the use of
actual randomness (e.g., as IVs or keys), system time, or other
changing variables in computations.

> Is there some way I can debug this and know what is different?

AFL doesn't generate human-readable coverage data, but you can try to
see if execution paths differ in any way when using afl-showmap with
the inputs flagged as variable in the .state dir. If yes, then using
other coverage / profiling tools will probably give you some insight.
Seeing if it also happens in non-persistent mode can help narrow it
down (to approximate non-persistent mode, just use __AFL_LOOP(1)).

/mz

[Kurt Roeckx]

On Fri, Jul 29, 2016 at 12:31:58PM -0700, Michal Zalewski wrote:
> > I have always assumed that the reason for some of the behaviour I
> > see is related to this input stability and is caused by global
> > variables that get initliazed in certain cases.
>
> There's a bunch of possible explanations (see status_screen.txt).

I already looked at that before sending the mail.

> In persistent mode, the intrinsic source of instability is the fact that
> the loop eventually exits every 1000 iterations (or whatever you pass
> to __AFL_LOOP as a parameter), so the loop exit conditional branch
> takes a different turn. But that should be a very small difference,
> unless there's a lot of code executed after the loop - explicitly or
> implicitly through constructs such as atexit().

You recommended me to put a large value in there before, it takes
hours to days before it exits.

> Another source of instability may be the fact that the loop may not
> clean up the state perfectly, and yup, that the subsequent iterations
> work differently or not work at all. Only the latter should result in
> the "stability" metric taking a major dip.

I expect it to just work, but if things fails in a way that I
don't know about, I guess it could explain something.

> More substantial exec path variability can be a product of concurrent
> threads (although this should be mitigated in llvm_mode) or the use of
> actual randomness (e.g., as IVs or keys), system time, or other
> changing variables in computations.

It's not using threads, there shouldn't be anything random in it.

We also have a fuzzer that actually uses randomness, it's really
unproducible what it's doing, which is why I stopped running that
one. I should find some time to make it reproducible.

> > Is there some way I can debug this and know what is different?
>
> AFL doesn't generate human-readable coverage data, but you can try to
> see if execution paths differ in any way when using afl-showmap with
> the inputs flagged as variable in the .state dir. If yes, then using
> other coverage / profiling tools will probably give you some insight.
> Seeing if it also happens in non-persistent mode can help narrow it
> down (to approximate non-persistent mode, just use __AFL_LOOP(1)).

Just running afl-showmap twice on the same input generates the
same output. I've actually tried this before mailing.

I guess I need to make something that reads that file 1 time and
something that reads that file 2 times.

I've used __AFL_LOOP(1) before when I previously looked at things
and using it now changes things to 100%.


Kurt

[Kurt Roeckx]

On Fri, Jul 29, 2016 at 10:01:12PM +0200, Kurt Roeckx wrote:
>
> Just running afl-showmap twice on the same input generates the
> same output. I've actually tried this before mailing.
>
> I guess I need to make something that reads that file 1 time and
> something that reads that file 2 times.

So I made something that did what is inside the __AFL_LOOP() 1 or
2 times depending on an argument to the program, so that afl still
uses the same numbers.

I've started by profiling that program. I expected one of the
RUN_ONCEs to cause this. They should be used for all the
initialization of global variables, and are clearly a point where
comming a second time you'll take the different branch. In the "ct"
program there only seems to be one of them: do_ex_data_init

So I made sure that that is called before the __AFL_LOOP(). This
changed the stability from 71.49% to 71.10%, and I really can't
explain why it makes it worse.

So I used gcc's -finstrument-functions to trace all the calls.
Before my change it clearly shows that do_ex_data_init() is called
during the first time the function is executed, but not anymore
during the second time. With calling do_ex_data_init() early
it shows them the 2 calls are now calling the same functions.

So gcc's -finstrument-functions shows that at least all the same
functions are called in the same order now, but that of course
doesn't mean anything about the same branches being taken.

I'm not sure how to convince gcov how to start collecting data
from a certain point, so that I can see either the first or
the second call.

Using afl-showmap calling the function 1 or 2 times originally had
2 different branches, after the early do_ex_data_init() call it
only shows 1. But the counters seems to react strangly. I expect
that all branches should be taken twice as often, except a few
expection that should be the same. But that's clearly not the case,
there are way more the same amount than I expect (49), there are
also that are less often which makes no sense at all, some
that are only 1 more which also makes little sense. And I guess
looking at those numbers in the showmap file, I can understand
that it's saying it's not stable.

I'm clearly not any closer to understanding why I'm getting that
and external tools currently don't seem to be providing much
inside at the moment.

Does someone have any ideas?


Kurt

[Michal Zalewski]

> Using afl-showmap calling the function 1 or 2 times originally had
> 2 different branches, after the early do_ex_data_init() call it
> only shows 1. But the counters seems to react strangly. I expect
> that all branches should be taken twice as often, except a few
> expection that should be the same.

Note that AFL quantizes counts into buckets. In particular, if
something executed 32 times and is now executing 64 times, it will
still fall into the same bucket. Not sure if that's the explanation,
though.

You mentioned that __AFL_LOOP(1) makes the problem go away; do you see
it come back with __AFL_LOOP(2), or only with much higher values, like
__AFL_LOOP(1000)? If it happens only with high values, the most likely
culprit would be a memory / fd leak or something like that,
manifesting itself only after a longer while. If it happens with 2,
then it must be something else...

One potential source of differences between (1) and (2) would be any
I/O buffering, stat() calls done on the input stream before the loop,
or any fds opened by OpenSSL to read files, etc...

Cheers,
/mz

[ku...@roeckx.be]

I tried to send this a few times, but it seems to get lost.

On Sat, Jul 30, 2016 at 03:02:45PM -0700, Michal Zalewski wrote:
> > Using afl-showmap calling the function 1 or 2 times originally had
> > 2 different branches, after the early do_ex_data_init() call it
> > only shows 1.  But the counters seems to react strangly.  I expect
> > that all branches should be taken twice as often, except a few
> > expection that should be the same.
>
> Note that AFL quantizes counts into buckets. In particular, if
> something executed 32 times and is now executing 64 times, it will
> still fall into the same bucket. Not sure if that's the explanation,
> though.

I forgot about that.  That would explain at least something, but
not why it would get lower.

> You mentioned that __AFL_LOOP(1) makes the problem go away; do you see
> it come back with __AFL_LOOP(2), or only with much higher values, like
> __AFL_LOOP(1000)? If it happens only with high values, the most likely
> culprit would be a memory / fd leak or something like that,
> manifesting itself only after a longer while. If it happens with 2,
> then it must be something else...

__AFL_LOOP(1) gives 100%, __AFL_LOOP(2) gives around 65%, but see
below.

It seems that when it starts a new process it changes the value
from somewhere around 71% to somewhere around 65%.  (It sometimes
finds new files, at which time the exact percentages change, but
one is around 71, the other around 65.)

If I use __AFL_LOOP(2) I also get this for all files:
[!] WARNING: Instrumentation output varies across runs.

(I also get that message with some of the other test programs I
looked at, but they're at 86%, and they have a much higher
__AFL_LOOP().  So I started to look at ct because it's the lowest
I saw so far.)

The higher I have the __AFL_LOOP(), the less files show that
warning.

I have removed the atexit() call and now it stays at the 71%, it
doesn't change anything for the rest.

> One potential source of differences between (1) and (2) would be any
> I/O buffering, stat() calls done on the input stream before the loop,
> or any fds opened by OpenSSL to read files, etc...

The loop looks like this:
    while (__AFL_LOOP(10000)) {
        uint8_t *buf = malloc(BUF_SIZE);
        size_t size = read(0, buf, BUF_SIZE);

        FuzzerTestOneInput(buf, size);
        free(buf);
    }

strace only shows this single call to read().  The whole strace is
58 lines long, and ends like this:

set_tid_address(0x7fbc43a519d0)         = 21106
set_robust_list(0x7fbc43a519e0, 24)     = 0
rt_sigaction(SIGRTMIN, {0x7fbc4344fba0, [], SA_RESTORER|SA_SIGINFO, 0x7fbc4345aed0}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x7fbc4344fc30, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fbc4345aed0}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
write(199, "\0\0\0\0", 4)               = -1 EBADF (Bad file descriptor)
brk(NULL)                               = 0x2045000
brk(0x2066000)                          = 0x2066000
futex(0x94e898, FUTEX_WAKE_PRIVATE, 2147483647) = 0
read(0, "$\200\200\201\201\0\201\0\00200\0\0030\2\2\0\00200\0\00200\0\0030\2\2\0\0020"..., 65536) = 143
exit_group(0)                           = ?
+++ exited with 0 +++

I assume that everything other than the read() call is done by the crt or afl.


Kurt

[Michal Zalewski]

Wait... I think I know what's causing your problem, sorry! The issue
that when you move more and more of the init code outside the loop, it
doesn't actually end up helping...

The problem is that the init code executes only on the first
iteration, and AFL then resets the SHM region; on the subsequent
iterations, a significant chunk of the code that executed previously
disappears, resulting in a fairly high dip in the stability score.

This doesn't affect other users to the same extent because the
initialization before __AFL_LOOP() is usually trivial, but in your
case, it's apparently some 30% of the all code executed.

If my theory is right, I think I have a simple fix. Please edit
llvm_mode/afl-llvm-rt.o.c and find __afl_persistent_loop. The function
opens with this conditional:

if (first_pass) {

cycle_cnt = max_cnt;
first_pass = 0;
return 1;

}

...put a call to memset(__afl_area_ptr, 0, MAP_SIZE) before the return
statement, then recompile llvm_mode and completely rebuild OpenSSL.
Let me know if it makes a difference!

[ku...@roeckx.be]

[It seems that Google is throwing away my e-mails for some reason.]

On Sun, Jul 31, 2016 at 09:48:39AM -0700, Michal Zalewski wrote:
> If my theory is right, I think I have a simple fix. Please edit
> llvm_mode/afl-llvm-rt.o.c and find __afl_persistent_loop. The function
> opens with this conditional:
>
>   if (first_pass) {
>
>     cycle_cnt  = max_cnt;
>     first_pass = 0;
>     return 1;
>
>   }
>
> ...put a call to memset(__afl_area_ptr, 0, MAP_SIZE) before the return
> statement, then recompile llvm_mode and completely rebuild OpenSSL.
> Let me know if it makes a difference!

So I used the following patch:
--- afl-2.21b.orig/llvm_mode/afl-llvm-rt.o.c
+++ afl-2.21b/llvm_mode/afl-llvm-rt.o.c
@@ -171,6 +171,7 @@ int __afl_persistent_loop(unsigned int m

     cycle_cnt  = max_cnt;
     first_pass = 0;

+    memset(__afl_area_ptr, 0, MAP_SIZE);
     return 1;

   }

This changed it from 71.58% without the moved init code to 71.83%
with it moved, which is at least in the right direction.

For the "asn1" fuzzer, it moves it from 91.37% to 99.43% when
moving the init code. That might be some init code that only
used in a few cases that still needs to move.  Yet it has this
warning for almost all the files:

WARNING: Instrumentation output varies across runs.

It also seems that the asn1 fuzzer suddenly finds a lot of new paths like this.

Kurt

[Michal Zalewski]

> This changed it from 71.58% without the moved init code to 71.83%
> with it moved, which is at least in the right direction.

Ugh. I'm officially out of ideas then. The memset() should take all
the pre-__AFL_LOOP() code out of the equation, so it's just what
happens within the loop. Or after it, but that we can fix, too... in
fact, I just released 2.23b, which may get your asn1 fuzzer to 100%
(although fraction of a percent is just a cosmetic defect, not a real
issue).

There must be something else going substantially different or failing
during the second iteration in your 71% case, but if it's not evident
using tools such as gcov (after converting __AFL_LOOP to a regular
loop), then I am stumped...

/mz

[ku...@roeckx.be]

On Sun, Jul 31, 2016 at 11:48:04AM -0700, Michal Zalewski wrote:
> > This changed it from 71.58% without the moved init code to 71.83%
> > with it moved, which is at least in the right direction.
>
> Ugh. I'm officially out of ideas then. The memset() should take all
> the pre-__AFL_LOOP() code out of the equation, so it's just what
> happens within the loop. Or after it, but that we can fix, too... in
> fact, I just released 2.23b, which may get your asn1 fuzzer to 100%
> (although fraction of a percent is just a cosmetic defect, not a real
> issue).

The asn1 fuzzer stays at 99.43%, and also still has that warning.
I will try to look if I missed anything.

> There must be something else going substantially different or failing
> during the second iteration in your 71% case, but if it's not evident
> using tools such as gcov (after converting __AFL_LOOP to a regular
> loop), then I am stumped...

Is there some way I can make it output addresses for each point it
reaches?  I can probably use that to find out what is going on.


Kurt

[Peter Gutmann]

ku...@roeckx.be <ku...@roeckx.be> writes:

>It also seems that the asn1 fuzzer suddenly finds a lot of new paths like this.

What's the ASN.1 fuzzer? Is it some specific tool, or are you just fuzzing code that processes ASN.1?

Peter.

[Kurt Roeckx]

We have a few fuzzers in openssl that try and parse things and then
tries to convert it back and print it. The "asn1" can be seen
here:
https://github.com/openssl/openssl/blob/master/fuzz/asn1.c

It uses as much as possible known structures for the same input.
For some structures it actually finds many different paths and for
others only a few, and a lot of them actually say the same input
files are the interesting ones.

We actually found a few bugs using this.

There is also the "asn1parse" one, that finds a lot less inputs.

For the x509 and and crl fuzzers the coverage really seems to
depend on input files I've providing it, it's not that good in
finding things on it's own, but the asn1 and asn1parse ones seems
to be able to find things on their own. I assume this is related
to OIDs and afl it's good in finding things where we do a binary
search over a table.

I should probably write some others like x509 and crl.

(It's been a while since I updated the corpora in git,
some of them have seen a large increase.)


Kurt

[Michal Zalewski]

Good news: I think I found the problem =) New version coming soon.

> --
> You received this message because you are subscribed to the Google Groups
> "afl-users" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to afl-users+...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.

[Michal Zalewski]

OK, I might have spoken to soon. Made some adjustments in 2.30b,
though. The most important of which is that the percentages are not
shown in red if running in persistent mode and if the overall bitmap
size is small, since the flukes here are related to how the compiler
unrolls / rerolls the __AFL_LOOP() stuff itself.

Anything that still shows in red after these changes is probably worth
a closer look, but I'm not sure I'd have particularly insightful
troubleshooting tips without diving into the target program itself :-(