AFL Internals
Stats, Counters and the UI
AFL Internals - Stats, Counters and the UI
Introduction
In a previous article, AFL stages are explained in detail. This time, I’ll try to go over the elements that make up the user interface. There are plenty of stats generated by a fuzzing session. For instance, you can track the overall progress by counters such as cycles done, total paths, unique crashes and unique hangs. Join to learn more.
The User Interface
The above is similar to what one might observe when AFL is run. The user interface is divided into eight sections. There is also a CPU meter at the bottom of the screen to the right. Let’s start by describing the particulars.
- Process Timing: Includes the metrics related to the processes,
- run time: The time passed since this fuzzer is started,
- last new path: The time passed since a new path is found,
- last unique crash: The time passed since a unique crash has been observed,
- last unique hang: The time passed since a unique hang has been observed,
- Overall Results: Section provides overall information about findings,
- cycles done: Number of cycles where a cycle is a run of all stages,
- total paths: The number of paths in the fuzzer queue,
- unique crashes: The number of unique crashes this fuzzer has observed,
- unique hangs: The number of unique hangs this fuzzer has observed,
- Cycle Progress: Displays the progress of the current cycle,
- now processing: The queue item that the fuzzer is processing,
- paths timed out: The number of paths timed out in this cycle,
- Map Coverage: Displays information about the intrumentation and
trace_bits,- map density: The percentage of edges observed in this cycle,
- count coverage: The ratio of bits per bytes in the bitmap, entropy,
- Stage Progress: Displays information about stages and their progress,
- now trying: The current stage the fuzzer is running,
- stage executions: Progress of the current stage,
- total executions: The total number of executions,
- execution speed: The target execution speed (execs per sec),
- Findings in Depth: Displays information about the findings,
- favored paths: The number of paths favoured by this fuzzer,
- new edges on: The number of new edges found,
- total crashes: The number of total crashes and unique crashes,
- total timeouts: The number of timeouts and unique timeout,
- Fuzzing Strategy Yields: Display information about yields,
- bit flips: The number of paths discovered by 1-,2-,4- bitflips,
- byte flip: The number of paths discovered by 1,2,4 byteflips,
- arithmetics: The number of paths discovered by 8,16,32 bit arithmetics,
- known interesting: The number of paths discovered by 8,16,32 bit interesting constants,
- dictionary: The number of paths discovered by 8,16,32 bit dictionary constants,
- havoc: The number of paths discovered by probabilistic havoc and splice stages,
- trim: Trimming success percentage, total number of trimming attempts, Effector selected bytes percentage,
- Path Geometry: Displays information about path geometry,
- levels: The depth of the queue item,
- pending: Pending items in the queue,
- pending favorites: Pending items favored by this fuzzer,
- own findings: The paths discovered by this fuzzer,
- imported findings: The number of items imported by this fuzzer (see multicore fuzzing),
- stability: The stability of the target binary, depending on the number of variable bytes.
Calibration
Before delving into the metrics, let’s look into the calibration stage that is called in various places. Calibration stage basically collects important information about the current queue item and the target.
/* Calibrate a new test case. This is done when processing the input directory
to warn about flaky or otherwise problematic test cases early on; and when
new paths are discovered to detect variable behavior and so on. */
static u8 calibrate_case(char** argv, struct queue_entry* q, u8* use_mem,
u32 handicap, u8 from_queue) {
static u8 first_trace[MAP_SIZE];
u8 fault = 0, new_bits = 0, var_detected = 0, hnb = 0,
first_run = (q->exec_cksum == 0);
u64 start_us, stop_us;
s32 old_sc = stage_cur, old_sm = stage_max;
u32 use_tmout = exec_tmout;
u8* old_sn = stage_name;
/* Be a bit more generous about timeouts when resuming sessions, or when
trying to calibrate already-added finds. This helps avoid trouble due
to intermittent latency. */
if (!from_queue || resuming_fuzz)
use_tmout = MAX(exec_tmout + CAL_TMOUT_ADD,
exec_tmout * CAL_TMOUT_PERC / 100);
First, calibration picks a longer timeout value. CAL_TMOUT_ADD is
defined to be 50ms and CAL_TMOUT_PERC is defined to be 125 in
config.h.
q->cal_failed++;
stage_name = "calibration";
stage_max = fast_cal ? 3 : CAL_CYCLES;
The number of calibration cycles is CAL_CYCLES by default. In
config.h, it is defined to be 8.
/* Make sure the forkserver is up before we do anything, and let's not
count its spin-up time toward binary calibration. */
if (dumb_mode != 1 && !no_forkserver && !forksrv_pid)
init_forkserver(argv);
Let’s run the forkserver.
if (q->exec_cksum) {
memcpy(first_trace, trace_bits, MAP_SIZE);
hnb = has_new_bits(virgin_bits);
if (hnb > new_bits) new_bits = hnb;
}
Detect if the queue item has already been fuzzed. Copy the trace_bits into first_trace. MAP_SIZE is still 64KiB.
start_us = get_cur_time_us();
Mark the moment and proceed into the rounds.
for (stage_cur = 0; stage_cur < stage_max; stage_cur++) {
u32 cksum;
if (!first_run && !(stage_cur % stats_update_freq)) show_stats();
write_to_testcase(use_mem, q->len);
fault = run_target(argv, use_tmout);
/* stop_soon is set by the handler for Ctrl+C. When it's pressed,
we want to bail out quickly. */
if (stop_soon || fault != crash_mode) goto abort_calibration;
if (!dumb_mode && !stage_cur && !count_bytes(trace_bits)) {
fault = FAULT_NOINST;
goto abort_calibration;
}
The above code runs the target and checks for failures, nothing interesting so far.
cksum = hash32(trace_bits, MAP_SIZE, HASH_CONST);
if (q->exec_cksum != cksum) {
Calculate the checksum and see if we get any new edges.
hnb = has_new_bits(virgin_bits);
if (hnb > new_bits) new_bits = hnb;
Merge new bits into virgin_bits. Virgins bits is the map that holds untouched bits so far. Let’s see the definition of has_new_bits():
static inline u8 has_new_bits(u8* virgin_map) {
#ifdef WORD_SIZE_64
.. skipd for brevity ..
#else
u32* current = (u32*)trace_bits;
u32* virgin = (u32*)virgin_map;
u32 i = (MAP_SIZE >> 2);
#endif /* ^WORD_SIZE_64 */
u8 ret = 0;
while (i--) {
if (unlikely(*current) && unlikely(*current & *virgin)) {
if (likely(ret < 2)) {
u8* cur = (u8*)current;
u8* vir = (u8*)virgin;
#ifdef WORD_SIZE_64
.. skipd for brevity ..
#else
if ((cur[0] && vir[0] == 0xff) || (cur[1] && vir[1] == 0xff) ||
(cur[2] && vir[2] == 0xff) || (cur[3] && vir[3] == 0xff)) ret = 2;
else ret = 1;
#endif /* ^WORD_SIZE_64 */
}
*virgin &= ~*current;
}
current++;
virgin++;
}
if (ret && virgin_map == virgin_bits) bitmap_changed = 1;
return ret;
}
Note that, virgin_bits is set to all ones at the beginning and
virgin &= ~*current clears the relevant bits. This function returns
1 if only hitcounts are changed, 2 if we see new edges, 0
otherwise. Let’s continue with calibration.
if (q->exec_cksum) {
u32 i;
for (i = 0; i < MAP_SIZE; i++) {
if (!var_bytes[i] && first_trace[i] != trace_bits[i]) {
var_bytes[i] = 1;
stage_max = CAL_CYCLES_LONG;
}
}
var_detected = 1;
If it is the first run, mark in var_bytes[] and increase the number
of stages to CAL_CYCLES_LONG which is defined to be 40 in
config.h.
} else {
q->exec_cksum = cksum;
memcpy(first_trace, trace_bits, MAP_SIZE);
}
}
}
Else, update first_trace and checksum.
stop_us = get_cur_time_us();
total_cal_us += stop_us - start_us;
total_cal_cycles += stage_max;
Mark the moment, calculate the calibration time in microseconds, and save number of calibration cycles.
q->exec_us = (stop_us - start_us) / stage_max;
q->bitmap_size = count_bytes(trace_bits);
q->handicap = handicap;
q->cal_failed = 0;
Save metrics into the queue item. count_bytes() basically counts the
number of bytes different from zero in trace_bits.
total_bitmap_size += q->bitmap_size;
total_bitmap_entries++;
update_bitmap_score(q);
Save the total bitmap size and increase the number of entries. Let’s
look into the update_bitmap_score(). The purpose of this function is
basically favor some of the items in the queue according to a
metric. That particular metric is called fav_factor and calculated
by execution time multiplied by the input length.
static struct queue_entry*
top_rated[MAP_SIZE]; /* Top entries for bitmap bytes */
A global variable top_rated[] holds the favorable items. It will be
used in cull_queue() to pick favorable items in the main fuzzer loop.
/* When we bump into a new path, we call this to see if the path appears
more "favorable" than any of the existing ones. The purpose of the
"favorables" is to have a minimal set of paths that trigger all the bits
seen in the bitmap so far, and focus on fuzzing them at the expense of
the rest.
The first step of the process is to maintain a list of top_rated[] entries
for every byte in the bitmap. We win that slot if there is no previous
contender, or if the contender has a more favorable speed x size factor. */
static void update_bitmap_score(struct queue_entry* q) {
u32 i;
u64 fav_factor = q->exec_us * q->len;
Calculate the metric.
/* For every byte set in trace_bits[], see if there is a previous winner,
and how it compares to us. */
for (i = 0; i < MAP_SIZE; i++)
if (trace_bits[i]) {
if (top_rated[i]) {
/* Faster-executing or smaller test cases are favored. */
if (fav_factor > top_rated[i]->exec_us * top_rated[i]->len) continue;
Skip if what we have is better.
/* Looks like we're going to win. Decrease ref count for the
previous winner, discard its trace_bits[] if necessary. */
if (!--top_rated[i]->tc_ref) {
ck_free(top_rated[i]->trace_mini);
top_rated[i]->trace_mini = 0;
}
}
Release the current one since we have a better one.
/* Insert ourselves as the new winner. */
top_rated[i] = q;
q->tc_ref++;
if (!q->trace_mini) {
q->trace_mini = ck_alloc(MAP_SIZE >> 3);
minimize_bits(q->trace_mini, trace_bits);
}
score_changed = 1;
}
}
Save the new one in top_rated[], increase the reference count, save
trace_bits in the item and minimize. Minimization basically drops
counts.
/* If this case didn't result in new output from the instrumentation, tell
parent. This is a non-critical problem, but something to warn the user
about. */
if (!dumb_mode && first_run && !fault && !new_bits) fault = FAULT_NOBITS;
abort_calibration:
if (new_bits == 2 && !q->has_new_cov) {
q->has_new_cov = 1;
queued_with_cov++;
}
Inform that we have a new edge.
/* Mark variable paths. */
if (var_detected) {
var_byte_count = count_bytes(var_bytes);
if (!q->var_behavior) {
mark_as_variable(q);
queued_variable++;
}
}
If first run and variable bytes detected, mark the item as
variable. mark_as_variable() basically creates a file named in
output/queue/.state/variable_behavior/ so that next time the fuzzer
loads, the information is preserved.
stage_name = old_sn;
stage_cur = old_sc;
stage_max = old_sm;
if (!first_run) show_stats();
return fault;
}
Restore globals and if not the first run, show counters.
Decision Making and cull_queue()
Let’s revisit cull_queue() to see how top_rated[] items are
favored.
/* The second part of the mechanism discussed above is a routine that
goes over top_rated[] entries, and then sequentially grabs winners for
previously-unseen bytes (temp_v) and marks them as favored, at least
until the next run. The favored entries are given more air time during
all fuzzing steps. */
static void cull_queue(void) {
struct queue_entry* q;
static u8 temp_v[MAP_SIZE >> 3];
u32 i;
if (dumb_mode || !score_changed) return;
score_changed = 0;
memset(temp_v, 255, MAP_SIZE >> 3);
queued_favored = 0;
pending_favored = 0;
q = queue;
while (q) {
q->favored = 0;
q = q->next;
}
Set temp_v to all ones, reset all locals, reset all favorites.
/* Let's see if anything in the bitmap isn't captured in temp_v.
If yes, and if it has a top_rated[] contender, let's use it. */
for (i = 0; i < MAP_SIZE; i++)
if (top_rated[i] && (temp_v[i >> 3] & (1 << (i & 7)))) {
Recall top_rated[i] is a queue_entry, we see that there is winner
for this bit.
u32 j = MAP_SIZE >> 3;
/* Remove all bits belonging to the current entry from temp_v. */
while (j--)
if (top_rated[i]->trace_mini[j])
temp_v[j] &= ~top_rated[i]->trace_mini[j];
Aggregate all bits of the current item into temp_v[].
top_rated[i]->favored = 1;
queued_favored++;
if (!top_rated[i]->was_fuzzed) pending_favored++;
}
Favor the item, increment the counter, if not fuzzed already, order to do so.
q = queue;
while (q) {
mark_as_redundant(q, !q->favored);
q = q->next;
}
}
The above basically saves the information into the
filesystem. mark_as_redundant() will create a file in
output/queue/.state/redundant_edges/ directory for the queue item
and the next load will notice the file and restore.
Let’s revisit the main fuzzing loop in main().
while (1) {
u8 skipped_fuzz;
cull_queue();
if (!queue_cur) {
Current queue item is empty when we start. queue denotes the loaded
test cases.
queue_cycle++;
current_entry = 0;
cur_skipped_paths = 0;
queue_cur = queue;
while (seek_to) {
current_entry++;
seek_to--;
queue_cur = queue_cur->next;
}
show_stats();
if (not_on_tty) {
ACTF("Entering queue cycle %llu.", queue_cycle);
fflush(stdout);
}
/* If we had a full queue cycle with no new finds, try
recombination strategies next. */
if (queued_paths == prev_queued) {
if (use_splicing) cycles_wo_finds++; else use_splicing = 1;
} else cycles_wo_finds = 0;
This enables splicing since we have a cycle without findings.
prev_queued = queued_paths;
if (sync_id && queue_cycle == 1 && getenv("AFL_IMPORT_FIRST"))
sync_fuzzers(use_argv);
}
Multi-core related, I will visit this in particular section later.
skipped_fuzz = fuzz_one(use_argv); // fuzz one
Execute the fuzzer and set the current item to the next one in the queue.
if (!stop_soon && sync_id && !skipped_fuzz) {
if (!(sync_interval_cnt++ % SYNC_INTERVAL))
sync_fuzzers(use_argv);
}
if (!stop_soon && exit_1) stop_soon = 2;
if (stop_soon) break;
queue_cur = queue_cur->next;
current_entry++;
}
Let’s see the prologue of fuzz_one() and see how skipping works.
static u8 fuzz_one(char** argv) {
s32 len, fd, temp_len, i, j;
u8 *in_buf, *out_buf, *orig_in, *ex_tmp, *eff_map = 0;
u64 havoc_queued, orig_hit_cnt, new_hit_cnt;
u32 splice_cycle = 0, perf_score = 100, orig_perf, prev_cksum, eff_cnt = 1;
u8 ret_val = 1, doing_det = 0;
u8 a_collect[MAX_AUTO_EXTRA];
u32 a_len = 0;
#ifdef IGNORE_FINDS
.. skipd for brevity ..
#else
if (pending_favored) {
if ((queue_cur->was_fuzzed || !queue_cur->favored) &&
UR(100) < SKIP_TO_NEW_PROB) return 1;
If we have a favored item pending, skip if we already fuzzed or if it
is not favored probabilistly. Recall UR(100) picks a random number
between 0 and 99 inclusively. Interesting enough, SKIP_TO_NEW_PROB
is defined to be 99 in config.h, so this is true only 99 percent of
the time.
} else if (!dumb_mode && !queue_cur->favored && queued_paths > 10) {
if (queue_cycle > 1 && !queue_cur->was_fuzzed) {
if (UR(100) < SKIP_NFAV_NEW_PROB) return 1;
} else {
if (UR(100) < SKIP_NFAV_OLD_PROB) return 1;
}
}
#endif /* ^IGNORE_FINDS */
The above also skips non-favored items probablistly. If we are not in
the first cycle, we skip according to SKIP_NFAV_NEW_PROB, otherwise,
we skip according to SKIP_NFAV_OLD_PROB. The constants are defined in
config.h as follows:
#define SKIP_NFAV_OLD_PROB 95 /* ...no new favs, cur entry already fuzzed */
#define SKIP_NFAV_NEW_PROB 75 /* ...no new favs, cur entry not fuzzed yet */
It can be observed that old items are skipped 95 percent and new items are skipped only 75 percent. The rest of the function is discussed in the Stages section.
Trimming
After calibration is done, there is a also a trimming stage. Let’s see how it works.
/************
* TRIMMING *
************/
if (!dumb_mode && !queue_cur->trim_done) {
u8 res = trim_case(argv, queue_cur, in_buf);
if (res == FAULT_ERROR)
FATAL("Unable to execute target application");
if (stop_soon) {
cur_skipped_paths++;
goto abandon_entry;
}
/* Don't retry trimming, even if it failed. */
queue_cur->trim_done = 1;
if (len != queue_cur->len) len = queue_cur->len;
}
This is the call site in fuzz_one(). It invokes trimming on the
current queue item. Let’s see the definition.
/* Trim all new test cases to save cycles when doing deterministic checks. The
trimmer uses power-of-two increments somewhere between 1/16 and 1/1024 of
file size, to keep the stage short and sweet. */
static u8 trim_case(char** argv, struct queue_entry* q, u8* in_buf) {
static u8 tmp[64];
static u8 clean_trace[MAP_SIZE];
u8 needs_write = 0, fault = 0;
u32 trim_exec = 0;
u32 remove_len;
u32 len_p2;
/* Although the trimmer will be less useful when variable behavior is
detected, it will still work to some extent, so we don't check for
this. */
if (q->len < 5) return 0;
Skip if length is less than 5 bytes.
stage_name = tmp;
Seems like tmp is not initialized :(
bytes_trim_in += q->len;
/* Select initial chunk len, starting with large steps. */
len_p2 = next_p2(q->len);
First power of two larger than q->len.
remove_len = MAX(len_p2 / TRIM_START_STEPS, TRIM_MIN_BYTES);
So these constants are defined in config.h as follows:
#define TRIM_MIN_BYTES 4
#define TRIM_START_STEPS 16
#define TRIM_END_STEPS 1024
Let’s do an example. Say q->len is 127. Then, p2 is
128=2^7. remove_len will be MAX(128/16, 4) which
is 8. Similarly,
MAX(len_p2/TRIM_END_STEPS,TRIM_MIN_BYTES)=MAX(128/1024, 4)=4. stage_max will be 127/8=8.
/* Continue until the number of steps gets too high or the stepover
gets too small. */
while (remove_len >= MAX(len_p2 / TRIM_END_STEPS, TRIM_MIN_BYTES)) {
u32 remove_pos = remove_len;
sprintf(tmp, "trim %s/%s", DI(remove_len), DI(remove_len));
stage_cur = 0;
stage_max = q->len / remove_len;
while (remove_pos < q->len) {
u32 trim_avail = MIN(remove_len, q->len - remove_pos);
trim_avail will be MIN(8, 127-8)=8.
u32 cksum;
write_with_gap(in_buf, q->len, remove_pos, trim_avail);
The above function has the following prototype:
static void write_with_gap(void* mem, u32 len, u32 skip_at, u32 skip_len);
write_with_gap() omits the data between skip_at and
skip_at+skip_len in the buffer pointed by mem. So the loop
basically modifies the buffer by skipping trim_avail bytes at
position remove_pos.
fault = run_target(argv, exec_tmout);
trim_execs++;
if (stop_soon || fault == FAULT_ERROR) goto abort_trimming;
/* Note that we don't keep track of crashes or hangs here; maybe TODO? */
cksum = hash32(trace_bits, MAP_SIZE, HASH_CONST);
/* If the deletion had no impact on the trace, make it permanent. This
isn't perfect for variable-path inputs, but we're just making a
best-effort pass, so it's not a big deal if we end up with false
negatives every now and then. */
if (cksum == q->exec_cksum) {
Run the target and check whether the checksum is modified. If it is
not then, modify the input buffer to reflect that change and flag
needs_write.
u32 move_tail = q->len - remove_pos - trim_avail;
q->len -= trim_avail;
len_p2 = next_p2(q->len);
memmove(in_buf + remove_pos, in_buf + remove_pos + trim_avail,
move_tail);
/* Let's save a clean trace, which will be needed by
update_bitmap_score once we're done with the trimming stuff. */
if (!needs_write) {
needs_write = 1;
memcpy(clean_trace, trace_bits, MAP_SIZE);
}
} else remove_pos += remove_len;
/* Since this can be slow, update the screen every now and then. */
if (!(trim_exec++ % stats_update_freq)) show_stats();
stage_cur++;
}
remove_len will be 4 in the next loop.
remove_len >>= 1;
}
/* If we have made changes to in_buf, we also need to update the on-disk
version of the test case. */
if (needs_write) {
s32 fd;
unlink(q->fname); /* ignore errors */
fd = open(q->fname, O_WRONLY | O_CREAT | O_EXCL, 0600);
if (fd < 0) PFATAL("Unable to create '%s'", q->fname);
ck_write(fd, in_buf, q->len, q->fname);
close(fd);
memcpy(trace_bits, clean_trace, MAP_SIZE);
update_bitmap_score(q);
}
abort_trimming:
bytes_trim_out += q->len;
return fault;
}
Finally, the new buffer will be written to a file while the old one is unlinked.
Initial Values and show_init_stats()
It is time for the user inerfaces. This function is called in main()
and it initializes common parameters like timeout,
havoc_div. Let’s see the details.
/* Display quick statistics at the end of processing the input directory,
plus a bunch of warnings. Some calibration stuff also ended up here,
along with several hardcoded constants. Maybe clean up eventually. */
static void show_init_stats(void) {
struct queue_entry* q = queue;
u32 min_bits = 0, max_bits = 0;
u64 min_us = 0, max_us = 0;
u64 avg_us = 0;
u32 max_len = 0;
if (total_cal_cycles) avg_us = total_cal_us / total_cal_cycles;
Set the average execution time based on the calibration stage.
while (q) {
if (!min_us || q->exec_us < min_us) min_us = q->exec_us;
if (q->exec_us > max_us) max_us = q->exec_us;
if (!min_bits || q->bitmap_size < min_bits) min_bits = q->bitmap_size;
if (q->bitmap_size > max_bits) max_bits = q->bitmap_size;
if (q->len > max_len) max_len = q->len;
q = q->next;
}
SAYF("\n");
Set minimum, maximum execution times. Set minimum and maximum bitmap sizes. Set maximum input length in the queue.
if (avg_us > (qemu_mode ? 50000 : 10000))
WARNF(cLRD "The target binary is pretty slow! See %s/perf_tips.txt.",
doc_path);
Warn if average execution time is over 10ms.
/* Let's keep things moving with slow binaries. */
if (avg_us > 50000) havoc_div = 10; /* 0-19 execs/sec */
else if (avg_us > 20000) havoc_div = 5; /* 20-49 execs/sec */
else if (avg_us > 10000) havoc_div = 2; /* 50-100 execs/sec */
Adjust havoc_div according to the average execution time.
if (!resuming_fuzz) {
if (max_len > 50 * 1024)
WARNF(cLRD "Some test cases are huge (%s) - see %s/perf_tips.txt!",
DMS(max_len), doc_path);
else if (max_len > 10 * 1024)
WARNF("Some test cases are big (%s) - see %s/perf_tips.txt.",
DMS(max_len), doc_path);
if (useless_at_start && !in_bitmap)
WARNF(cLRD "Some test cases look useless. Consider using a smaller set.");
if (queued_paths > 100)
WARNF(cLRD "You probably have far too many input files! Consider trimming down.");
else if (queued_paths > 20)
WARNF("You have lots of input files; try starting small.");
}
These let us know if we are walking over the limits. Basically, it suggests that, 50KiB test cases are huge and it is better to keep them under 10KiB. Besides, if there are more than 100 initial items, it is better to run minimization (ie. afl-cmin, afl-tmin) over the input directory. Finally, it is also advised to start with less than 20 test cases, otherwise we get a warning.
OKF("Here are some useful stats:\n\n"
cGRA " Test case count:" cRST "%u favored, %u variable, %u total\n"
cGRA " Bitmap range:" cRST "%u to %u bits (average: %0.02f bits)\n"
cGRA " Exec timing:" cRST "%s to %s us (average: %s us)\n",
queued_favored, queued_variable, queued_paths, min_bits, max_bits,
((double)total_bitmap_size) /
(total_bitmap_entries ? total_bitmap_entries : 1),
DI(min_us), DI(max_us), DI(avg_us));
Let’s describe these variables:
queued_favored: Number of items favored in the queuequeued_variable: Number of items with variable bytes in the queuequeued_paths: The total number of paths in the queuemin_bits: Minimum number of trace bits in the queuemax_bits: Maximum number of trace bits in the queuetotal_bitmap_size: Total number of non-zero bits seentotal_bitmap_entries: Total number of items that contributes to the bitmapmin_us: Minimum execution time in microsecondsmax_us: Maximum eexcution time in microsecondsavg_us: Average execution time in microseconds
if (!timeout_given) {
/* Figure out the appropriate timeout. The basic idea is: 5x average or
1x max, rounded up to EXEC_TM_ROUND ms and capped at 1 second.
If the program is slow, the multiplier is lowered to 2x or 3x, because
random scheduler jitter is less likely to have any impact, and because
our patience is wearing thin =) */
if (avg_us > 50000) exec_tmout = avg_us * 2 / 1000;
else if (avg_us > 10000) exec_tmout = avg_us * 3 / 1000;
else exec_tmout = avg_us * 5 / 1000;
exec_tmout = MAX(exec_tmout, max_us / 1000);
exec_tmout = (exec_tmout + EXEC_TM_ROUND) / EXEC_TM_ROUND * EXEC_TM_ROUND;
if (exec_tmout > EXEC_TIMEOUT) exec_tmout = EXEC_TIMEOUT;
ACTF("No -t option specified, so I'll use exec timeout of %u ms.",
exec_tmout);
timeout_given = 1;
} else if (timeout_given == 3) {
ACTF("Applying timeout settings from resumed session (%u ms).",
exec_tmout);
}
The above code tries to figure out a sane timeout value. This value is
in milliseconds and upper bounded by EXEC_TIMEOUT defined in config.h
as 1000ms.
/* In dumb mode, re-running every timing out test case with a generous time
limit is very expensive, so let's select a more conservative default. */
if (dumb_mode && !getenv("AFL_HANG_TMOUT"))
hang_tmout = MIN(EXEC_TIMEOUT, exec_tmout * 2 + 100);
OKF("All set and ready to roll!");
}
Timeout value also can be provided by an environment variable called
AFL_HANG_TMOUT.
show_stats()
This is the last function covered in this article. It is called in
various places to update the UI and adjust several
parameters. Frequency depends on stats_update_freq.
static void show_stats(void) {
static u64 last_stats_ms, last_plot_ms, last_ms, last_execs;
static double avg_exec;
double t_byte_ratio, stab_ratio;
u64 cur_ms;
u32 t_bytes, t_bits;
u32 banner_len, banner_pad;
u8 tmp[256];
cur_ms = get_cur_time();
Mark the moment.
/* If not enough time has passed since last UI update, bail out. */
if (cur_ms - last_ms < 1000 / UI_TARGET_HZ) return;
UI_TARGET_HZ is defined to be 5 in config.h so 1000/UI_TARGET_HZ
is 0.2 seconds.
/* Check if we're past the 10 minute mark. */
if (cur_ms - start_time > 10 * 60 * 1000) run_over10m = 1;
Mark if we are running over 10 minutes. This is used in havoc/splice stages.
/* Calculate smoothed exec speed stats. */
if (!last_execs) {
avg_exec = ((double)total_execs) * 1000 / (cur_ms - start_time);
} else {
double cur_avg = ((double)(total_execs - last_execs)) * 1000 /
(cur_ms - last_ms);
/* If there is a dramatic (5x+) jump in speed, reset the indicator
more quickly. */
if (cur_avg * 5 < avg_exec || cur_avg / 5 > avg_exec)
avg_exec = cur_avg;
avg_exec = avg_exec * (1.0 - 1.0 / AVG_SMOOTHING) +
cur_avg * (1.0 / AVG_SMOOTHING);
}
Calculate average execution time.
last_ms = cur_ms;
last_execs = total_execs;
Save state for later use.
/* Tell the callers when to contact us (as measured in execs). */
stats_update_freq = avg_exec / (UI_TARGET_HZ * 10);
if (!stats_update_freq) stats_update_freq = 1;
Calculate call frequency, avg_exec/50.
/* Do some bitmap stats. */
t_bytes = count_non_255_bytes(virgin_bits);
t_byte_ratio = ((double)t_bytes * 100) / MAP_SIZE;
if (t_bytes)
stab_ratio = 100 - ((double)var_byte_count) * 100 / t_bytes;
else
stab_ratio = 100;
Calculate t_bytes by counting !=255 bytes. stab_ratio is the
stability ratio. This variable depends on the number of variable
bytes, more variable bytes more instability.
/* Roughly every minute, update fuzzer stats and save auto tokens. */
if (cur_ms - last_stats_ms > STATS_UPDATE_SEC * 1000) {
last_stats_ms = cur_ms;
write_stats_file(t_byte_ratio, stab_ratio, avg_exec);
save_auto();
write_bitmap();
}
Save stats in stats file, save auto collected token, save
bitmap. Period is determined by STATS_UPDATE_SEC and it is defined
in config.h as 60.
/* Every now and then, write plot data. */
if (cur_ms - last_plot_ms > PLOT_UPDATE_SEC * 1000) {
last_plot_ms = cur_ms;
maybe_update_plot_file(t_byte_ratio, avg_exec);
}
Update the plot file. The period is determined by PLOT_UPDATE_SEC
defined in config.h as 5.
/* Honor AFL_EXIT_WHEN_DONE and AFL_BENCH_UNTIL_CRASH. */
if (!dumb_mode && cycles_wo_finds > 100 && !pending_not_fuzzed &&
getenv("AFL_EXIT_WHEN_DONE")) stop_soon = 2;
This is interesting. It allows the fuzzer to quit if 100 cycles passed
without any finds and enabled by environment variabled called
AFL_EXIT_WHEN_DONE.
if (total_crashes && getenv("AFL_BENCH_UNTIL_CRASH")) stop_soon = 2;
This allows the fuzzer quit if AFL_BENCH_UNTIL_CRASH is defined and
target crashes.
/* If we're not on TTY, bail out. */
if (not_on_tty) return;
/* Compute some mildly useful bitmap stats. */
t_bits = (MAP_SIZE << 3) - count_bits(virgin_bits);
Save the bitcount in t_bits. count_bits() is a nice popcount
implementation.
/* Now, for the visuals... */
if (clear_screen) {
SAYF(TERM_CLEAR CURSOR_HIDE);
clear_screen = 0;
check_term_size();
}
SAYF(TERM_HOME);
if (term_too_small) {
SAYF(cBRI "Your terminal is too small to display the UI.\n"
"Please resize terminal window to at least 80x25.\n" cRST);
return;
}
/* Let's start by drawing a centered banner. */
banner_len = (crash_mode ? 24 : 22) + strlen(VERSION) + strlen(use_banner);
banner_pad = (80 - banner_len) / 2;
memset(tmp, ' ', banner_pad);
sprintf(tmp + banner_pad, "%s " cLCY VERSION cLGN
" (%s)", crash_mode ? cPIN "peruvian were-rabbit" :
cYEL "american fuzzy lop", use_banner);
SAYF("\n%s\n\n", tmp);
/* "Handy" shortcuts for drawing boxes... */
#define bSTG bSTART cGRA
#define bH2 bH bH
#define bH5 bH2 bH2 bH
#define bH10 bH5 bH5
#define bH20 bH10 bH10
#define bH30 bH20 bH10
#define SP5 " "
#define SP10 SP5 SP5
#define SP20 SP10 SP10
Clear the terminal, check the terminal size, complain if too small, show the banner.
/* Lord, forgive me this. */
SAYF(SET_G1 bSTG bLT bH bSTOP cCYA " process timing " bSTG bH30 bH5 bH2 bHB
bH bSTOP cCYA " overall results " bSTG bH5 bRT "\n");
if (dumb_mode) {
strcpy(tmp, cRST);
} else {
u64 min_wo_finds = (cur_ms - last_path_time) / 1000 / 60;
/* First queue cycle: don't stop now! */
if (queue_cycle == 1 || min_wo_finds < 15) strcpy(tmp, cMGN); else
/* Subsequent cycles, but we're still making finds. */
if (cycles_wo_finds < 25 || min_wo_finds < 30) strcpy(tmp, cYEL); else
/* No finds for a long time and no test cases to try. */
if (cycles_wo_finds > 100 && !pending_not_fuzzed && min_wo_finds > 120)
strcpy(tmp, cLGN);
/* Default: cautiously OK to stop? */
else strcpy(tmp, cLBL);
}
min_wo_finds is the time passed since the last path discovery. The
rest is for coloring cycles_done. It is magenta if we are in the
first cycle or we have found a path in the last 15 hours. It is
yellow, if we have not found a new path for 25 cycles or in the last
30 hours. Finally it is light green if we haven’t found for 100
cycles, no new items in the queue and no new paths for 120 hours. This
indicates the fuzzer is failing to discover new paths.
SAYF(bV bSTOP " run time : " cRST "%-34s " bSTG bV bSTOP
" cycles done : %s%-5s " bSTG bV "\n",
DTD(cur_ms, start_time), tmp, DI(queue_cycle - 1));
Show the runtime. DTD() is short for describe time delta and DI() is
short for describe integer.
/* We want to warn people about not seeing new paths after a full cycle,
except when resuming fuzzing or running in non-instrumented mode. */
if (!dumb_mode && (last_path_time || resuming_fuzz || queue_cycle == 1 ||
in_bitmap || crash_mode)) {
SAYF(bV bSTOP " last new path : " cRST "%-34s ",
DTD(cur_ms, last_path_time));
} else {
if (dumb_mode)
SAYF(bV bSTOP " last new path : " cPIN "n/a" cRST
" (non-instrumented mode) ");
else
SAYF(bV bSTOP " last new path : " cRST "none yet " cLRD
"(odd, check syntax!) ");
}
SAYF(bSTG bV bSTOP " total paths : " cRST "%-5s " bSTG bV "\n",
DI(queued_paths));
Now show the last_path_time and queued_paths.
/* Highlight crashes in red if found, denote going over the KEEP_UNIQUE_CRASH
limit with a '+' appended to the count. */
sprintf(tmp, "%s%s", DI(unique_crashes),
(unique_crashes >= KEEP_UNIQUE_CRASH) ? "+" : "");
SAYF(bV bSTOP " last uniq crash : " cRST "%-34s " bSTG bV bSTOP
" uniq crashes : %s%-6s " bSTG bV "\n",
DTD(cur_ms, last_crash_time), unique_crashes ? cLRD : cRST,
tmp);
Show last_crash_time and the number of unique crashes. It becomes
light red if the fuzzer discovered a crash already.
sprintf(tmp, "%s%s", DI(unique_hangs),
(unique_hangs >= KEEP_UNIQUE_HANG) ? "+" : "");
SAYF(bV bSTOP " last uniq hang : " cRST "%-34s " bSTG bV bSTOP
" uniq hangs : " cRST "%-6s " bSTG bV "\n",
DTD(cur_ms, last_hang_time), tmp);
Show last_hang_time and the number of unique timeouts.
SAYF(bVR bH bSTOP cCYA " cycle progress " bSTG bH20 bHB bH bSTOP cCYA
" map coverage " bSTG bH bHT bH20 bH2 bH bVL "\n");
Header for cycle progress and coverage.
/* This gets funny because we want to print several variable-length variables
together, but then cram them into a fixed-width field - so we need to
put them in a temporary buffer first. */
sprintf(tmp, "%s%s (%0.02f%%)", DI(current_entry),
queue_cur->favored ? "" : "*",
((double)current_entry * 100) / queued_paths);
SAYF(bV bSTOP " now processing : " cRST "%-17s " bSTG bV bSTOP, tmp);
sprintf(tmp, "%0.02f%% / %0.02f%%", ((double)queue_cur->bitmap_size) *
100 / MAP_SIZE, t_byte_ratio);
SAYF(" map density : %s%-21s " bSTG bV "\n", t_byte_ratio > 70 ? cLRD :
((t_bytes < 200 && !dumb_mode) ? cPIN : cRST), tmp);
Now, show cycle progress. current_entry is the unique ID of the item
in the queue. queued_paths is the total number of items in the
queue. Next, show map density. Recall, queue_cur->bitmap_size is the
number of bits in that particular item. t_byte_ratio is t_bytes
(ie. count_non_255_bytes()) as percentage over the total
MAP_SIZE >> 3.
sprintf(tmp, "%s (%0.02f%%)", DI(cur_skipped_paths),
((double)cur_skipped_paths * 100) / queued_paths);
SAYF(bV bSTOP " paths timed out : " cRST "%-17s " bSTG bV, tmp);
sprintf(tmp, "%0.02f bits/tuple",
t_bytes ? (((double)t_bits) / t_bytes) : 0);
SAYF(bSTOP " count coverage : " cRST "%-21s " bSTG bV "\n", tmp);
cur_skipped_paths is the number of skipped paths. This counter is
incremented in common_fuzz_stuff() if it encounters a
timeout. Moreover, users can skip an item in the queue by sending
SIGUSR1 signal during fuzzing. Show this number and its percentage
over the total. counter coverage is the ratio of total bits over total
bytes. This measures the entropy of the target.
SAYF(bVR bH bSTOP cCYA " stage progress " bSTG bH20 bX bH bSTOP cCYA
" findings in depth " bSTG bH20 bVL "\n");
Headers for stage progress and findings.
sprintf(tmp, "%s (%0.02f%%)", DI(queued_favored),
((double)queued_favored) * 100 / queued_paths);
SAYF(bV bSTOP " now trying : " cRST "%-21s " bSTG bV bSTOP
" favored paths : " cRST "%-22s " bSTG bV "\n", stage_name, tmp);
Show the stage name and favored paths and its ratio.
if (!stage_max) {
sprintf(tmp, "%s/-", DI(stage_cur));
} else {
sprintf(tmp, "%s/%s (%0.02f%%)", DI(stage_cur), DI(stage_max),
((double)stage_cur) * 100 / stage_max);
}
SAYF(bV bSTOP " stage execs : " cRST "%-21s " bSTG bV bSTOP, tmp);
Tell the user about the current stage and its total stages.
sprintf(tmp, "%s (%0.02f%%)", DI(queued_with_cov),
((double)queued_with_cov) * 100 / queued_paths);
SAYF(" new edges on : " cRST "%-22s " bSTG bV "\n", tmp);
Show the number of items with coverage and its ratio over the total.
sprintf(tmp, "%s (%s%s unique)", DI(total_crashes), DI(unique_crashes),
(unique_crashes >= KEEP_UNIQUE_CRASH) ? "+" : "");
if (crash_mode) {
SAYF(bV bSTOP " total execs : " cRST "%-21s " bSTG bV bSTOP
" new crashes : %s%-22s " bSTG bV "\n", DI(total_execs),
unique_crashes ? cLRD : cRST, tmp);
} else {
SAYF(bV bSTOP " total execs : " cRST "%-21s " bSTG bV bSTOP
" total crashes : %s%-22s " bSTG bV "\n", DI(total_execs),
unique_crashes ? cLRD : cRST, tmp);
}
Show the total number of crashes and number of unique crashes that
lead to distinct bitmaps. If unique_crashes > 0 then it is displayed
in light red.
/* Show a warning about slow execution. */
if (avg_exec < 100) {
sprintf(tmp, "%s/sec (%s)", DF(avg_exec), avg_exec < 20 ?
"zzzz..." : "slow!");
SAYF(bV bSTOP " exec speed : " cLRD "%-21s ", tmp);
} else {
sprintf(tmp, "%s/sec", DF(avg_exec));
SAYF(bV bSTOP " exec speed : " cRST "%-21s ", tmp);
}
Tell the user about the execution speed. DF is for describe
float. Execution speed is very slow (ie. “zzz”) if it is less than 20
execs/sec. It is slow if it is less than 100 execs/sec.
sprintf(tmp, "%s (%s%s unique)", DI(total_tmouts), DI(unique_tmouts),
(unique_hangs >= KEEP_UNIQUE_HANG) ? "+" : "");
SAYF (bSTG bV bSTOP " total tmouts : " cRST "%-22s " bSTG bV "\n", tmp);
Show the total number of timeouts. Put a little plus sign if we have
more than KEEP_UNIQUE_HANG which is defined to be 500 in config.h.
/* Aaaalmost there... hold on! */
SAYF(bVR bH cCYA bSTOP " fuzzing strategy yields " bSTG bH10 bH bHT bH10
bH5 bHB bH bSTOP cCYA " path geometry " bSTG bH5 bH2 bH bVL "\n");
Headers for strategy yields and path geometry.
if (skip_deterministic) {
strcpy(tmp, "n/a, n/a, n/a");
} else {
sprintf(tmp, "%s/%s, %s/%s, %s/%s",
DI(stage_finds[STAGE_FLIP1]), DI(stage_cycles[STAGE_FLIP1]),
DI(stage_finds[STAGE_FLIP2]), DI(stage_cycles[STAGE_FLIP2]),
DI(stage_finds[STAGE_FLIP4]), DI(stage_cycles[STAGE_FLIP4]));
}
SAYF(bV bSTOP " bit flips : " cRST "%-37s " bSTG bV bSTOP " levels : "
cRST "%-10s " bSTG bV "\n", tmp, DI(max_depth));
Show bitflip stage yields. Show the maximum depth in the queue. Recall that, depth counter is an increment of the depth of the parent queue item and it is monotonic.
if (!skip_deterministic)
sprintf(tmp, "%s/%s, %s/%s, %s/%s",
DI(stage_finds[STAGE_FLIP8]), DI(stage_cycles[STAGE_FLIP8]),
DI(stage_finds[STAGE_FLIP16]), DI(stage_cycles[STAGE_FLIP16]),
DI(stage_finds[STAGE_FLIP32]), DI(stage_cycles[STAGE_FLIP32]));
SAYF(bV bSTOP " byte flips : " cRST "%-37s " bSTG bV bSTOP " pending : "
cRST "%-10s " bSTG bV "\n", tmp, DI(pending_not_fuzzed));
Show bitflip stage yields. Tell the number of pending items in the queue.
if (!skip_deterministic)
sprintf(tmp, "%s/%s, %s/%s, %s/%s",
DI(stage_finds[STAGE_ARITH8]), DI(stage_cycles[STAGE_ARITH8]),
DI(stage_finds[STAGE_ARITH16]), DI(stage_cycles[STAGE_ARITH16]),
DI(stage_finds[STAGE_ARITH32]), DI(stage_cycles[STAGE_ARITH32]));
SAYF(bV bSTOP " arithmetics : " cRST "%-37s " bSTG bV bSTOP " pend fav : "
cRST "%-10s " bSTG bV "\n", tmp, DI(pending_favored));
Show arithmetic stage yields. Tell about favored items in the queue.
if (!skip_deterministic)
sprintf(tmp, "%s/%s, %s/%s, %s/%s",
DI(stage_finds[STAGE_INTEREST8]), DI(stage_cycles[STAGE_INTEREST8]),
DI(stage_finds[STAGE_INTEREST16]), DI(stage_cycles[STAGE_INTEREST16]),
DI(stage_finds[STAGE_INTEREST32]), DI(stage_cycles[STAGE_INTEREST32]));
SAYF(bV bSTOP " known ints : " cRST "%-37s " bSTG bV bSTOP " own finds : "
cRST "%-10s " bSTG bV "\n", tmp, DI(queued_discovered));
Show interesting stage yields. Tell about newly discovered items in the queue by this particular fuzzer.
if (!skip_deterministic)
sprintf(tmp, "%s/%s, %s/%s, %s/%s",
DI(stage_finds[STAGE_EXTRAS_UO]), DI(stage_cycles[STAGE_EXTRAS_UO]),
DI(stage_finds[STAGE_EXTRAS_UI]), DI(stage_cycles[STAGE_EXTRAS_UI]),
DI(stage_finds[STAGE_EXTRAS_AO]), DI(stage_cycles[STAGE_EXTRAS_AO]));
SAYF(bV bSTOP " dictionary : " cRST "%-37s " bSTG bV bSTOP
" imported : " cRST "%-10s " bSTG bV "\n", tmp,
sync_id ? DI(queued_imported) : (u8*)"n/a");
Show the extras stage yields. Tell about the imported items in the queue. These are the items found by other fuzzer instances. We will discuss how this works in multi-core fuzzing.
sprintf(tmp, "%s/%s, %s/%s",
DI(stage_finds[STAGE_HAVOC]), DI(stage_cycles[STAGE_HAVOC]),
DI(stage_finds[STAGE_SPLICE]), DI(stage_cycles[STAGE_SPLICE]));
SAYF(bV bSTOP " havoc : " cRST "%-37s " bSTG bV bSTOP, tmp);
Show the havoc/splice stage yields.
if (t_bytes) sprintf(tmp, "%0.02f%%", stab_ratio);
else strcpy(tmp, "n/a");
SAYF(" stability : %s%-10s " bSTG bV "\n",
(stab_ratio < 85 && var_byte_count > 40)
? cLRD : ((queued_variable && (!persistent_mode || var_byte_count > 20))
? cMGN : cRST), tmp);
Tell about the stability. Recall, stability is ratio of variable bytes
(var_byte_count) over the total bytes (t_bytes).
if (!bytes_trim_out) {
sprintf(tmp, "n/a, ");
} else {
sprintf(tmp, "%0.02f%%/%s, ",
((double)(bytes_trim_in - bytes_trim_out)) * 100 / bytes_trim_in,
DI(trim_execs));
}
So here bytes_trim_in is the sum of inputs and bytes_trim_out is the
sum after the trimming is done by trim_case(). trim_execs is the count
of runs of trim_case().
if (!blocks_eff_total) {
u8 tmp2[128];
sprintf(tmp2, "n/a");
strcat(tmp, tmp2);
} else {
u8 tmp2[128];
sprintf(tmp2, "%0.02f%%",
((double)(blocks_eff_total - blocks_eff_select)) * 100 /
blocks_eff_total);
strcat(tmp, tmp2);
}
SAYF(bV bSTOP " trim : " cRST "%-37s " bSTG bVR bH20 bH2 bH2 bRB "\n"
bLB bH30 bH20 bH2 bH bRB bSTOP cRST RESET_G1, tmp);
The above code tells the user about Effector
progress. blocks_eff_total is the total bytes handled by the
Effector and blocks_eff_select is the total number of bytes selected
by it so that consequent stages skip fuzzing.
/* Provide some CPU utilization stats. */
if (cpu_core_count) {
double cur_runnable = get_runnable_processes();
u32 cur_utilization = cur_runnable * 100 / cpu_core_count;
u8* cpu_color = cCYA;
/* If we could still run one or more processes, use green. */
if (cpu_core_count > 1 && cur_runnable + 1 <= cpu_core_count)
cpu_color = cLGN;
/* If we're clearly oversubscribed, use red. */
if (!no_cpu_meter_red && cur_utilization >= 150) cpu_color = cLRD;
#ifdef HAVE_AFFINITY
if (cpu_aff >= 0) {
SAYF(SP10 cGRA "[cpu%03u:%s%3u%%" cGRA "]\r" cRST,
MIN(cpu_aff, 999), cpu_color,
MIN(cur_utilization, 999));
} else {
SAYF(SP10 cGRA " [cpu:%s%3u%%" cGRA "]\r" cRST,
cpu_color, MIN(cur_utilization, 999));
}
#else
SAYF(SP10 cGRA " [cpu:%s%3u%%" cGRA "]\r" cRST,
cpu_color, MIN(cur_utilization, 999));
#endif /* ^HAVE_AFFINITY */
} else SAYF("\r");
/* Hallelujah! */
fflush(0);
}
Finally, tell the user about the current CPU utilization.
Conclusion
In this section, we have covered the decision making process that defines the progress of the fuzzer. Moreover, we have seen counters, metrics regarding the execution. The user inferface tells about the progress and it is updated regularly.
Hope you enjoyed it. Until next time!