write queue statistics

docs/Changelog.md

@@ -9,6 +9,9 @@
       send fuzz data to the target as you need, e.g. via IPC.
     - cmplog mode now has -l R option for random colorization, thanks
       to guyf2010 for the PR!
+    - queue statistics are written every 30 minutes to
+      out/NAME/queue_data - likely this will be moved to a debug flag
+      in the future.
   - afl-showmap/afl-cmin
     - -t none now translates to -t 120000 (120 seconds)
   - unicorn_mode updated

include/afl-fuzz.h

@@ -169,12 +169,18 @@ struct queue_entry {
 
   u32 bitmap_size,                      /* Number of bits set in bitmap     */
       fuzz_level,                       /* Number of fuzzing iterations     */
-      n_fuzz_entry;                     /* offset in n_fuzz                 */
+      n_fuzz_entry,                     /* offset in n_fuzz                 */
+      stats_selected,                   /* stats: how often selected        */
+      stats_skipped,                    /* stats: how often skipped         */
+      stats_finds,                      /* stats: # of saved finds          */
+      stats_crashes,                    /* stats: # of saved crashes        */
+      stats_tmouts;                     /* stats: # of saved timeouts       */
 
   u64 exec_us,                          /* Execution time (us)              */
       handicap,                         /* Number of queue cycles behind    */
       depth,                            /* Path depth                       */
-      exec_cksum;                       /* Checksum of the execution trace  */
+      exec_cksum,                       /* Checksum of the execution trace  */
+      stats_mutated;                    /* stats: # of mutations performed  */
 
   u8 *trace_mini;                       /* Trace bytes, if kept             */
   u32 tc_ref;                           /* Trace bytes ref count            */
@@ -686,7 +692,8 @@ typedef struct afl_state {
   u32 plot_prev_qp, plot_prev_pf, plot_prev_pnf, plot_prev_ce, plot_prev_md;
   u64 plot_prev_qc, plot_prev_uc, plot_prev_uh, plot_prev_ed;
 
-  u64 stats_last_stats_ms, stats_last_plot_ms, stats_last_ms, stats_last_execs;
+  u64 stats_last_stats_ms, stats_last_plot_ms, stats_last_queue_ms,
+      stats_last_ms, stats_last_execs;
 
   /* StatsD */
   u64                statsd_last_send_ms;
@@ -1101,6 +1108,7 @@ void load_stats_file(afl_state_t *);
 void write_setup_file(afl_state_t *, u32, char **);
 void write_stats_file(afl_state_t *, u32, double, double, double);
 void maybe_update_plot_file(afl_state_t *, u32, double, double);
+void write_queue_stats(afl_state_t *);
 void show_stats(afl_state_t *);
 void show_stats_normal(afl_state_t *);
 void show_stats_pizza(afl_state_t *);

include/config.h

@@ -290,10 +290,11 @@
 
 #define UI_TARGET_HZ 5
 
-/* Fuzzer stats file and plot update intervals (sec): */
+/* Fuzzer stats file, queue stats and plot update intervals (sec): */
 
 #define STATS_UPDATE_SEC 60
 #define PLOT_UPDATE_SEC 5
+#define QUEUE_UPDATE_SEC 1800
 
 /* Smoothing divisor for CPU load and exec speed stats (1 - no smoothing). */
 

src/afl-fuzz-init.c

@@ -1848,6 +1848,10 @@ static void handle_existing_out_dir(afl_state_t *afl) {
 
   }
 
+  fn = alloc_printf("%s/queue_data", afl->out_dir);
+  if (unlink(fn) && errno != ENOENT) { goto dir_cleanup_failed; }
+  ck_free(fn);
+
   fn = alloc_printf("%s/cmdline", afl->out_dir);
   if (unlink(fn) && errno != ENOENT) { goto dir_cleanup_failed; }
   ck_free(fn);

src/afl-fuzz-one.c

@@ -743,6 +743,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP1] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP1] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Two walking bits. */
 
@@ -775,6 +776,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP2] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP2] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Four walking bits. */
 
@@ -811,6 +813,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP4] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP4] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Effector map setup. These macros calculate:
 
@@ -919,6 +922,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Two walking bytes. */
 
@@ -962,6 +966,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   if (len < 4) { goto skip_bitflip; }
 
@@ -1005,6 +1010,7 @@ u8 fuzz_one_original(afl_state_t *afl) {
 
   afl->stage_finds[STAGE_FLIP32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_bitflip:
 
@@ -1097,6 +1103,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* 16-bit arithmetics, both endians. */
 
@@ -1227,6 +1234,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* 32-bit arithmetics, both endians. */
 
@@ -1356,6 +1364,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_arith:
 
@@ -1422,6 +1431,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Setting 16-bit integers, both endians. */
 
@@ -1510,6 +1520,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   if (len < 4) { goto skip_interest; }
 
@@ -1599,6 +1610,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_interest:
 
@@ -1672,6 +1684,7 @@ skip_interest:
 
   afl->stage_finds[STAGE_EXTRAS_UO] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_UO] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Insertion of user-supplied extras. */
 
@@ -1728,6 +1741,7 @@ skip_interest:
 
   afl->stage_finds[STAGE_EXTRAS_UI] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_UI] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_user_extras:
 
@@ -1786,6 +1800,7 @@ skip_user_extras:
 
   afl->stage_finds[STAGE_EXTRAS_AO] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_AO] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Insertion of auto extras. */
 
@@ -1842,6 +1857,7 @@ skip_user_extras:
 
   afl->stage_finds[STAGE_EXTRAS_AI] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_AI] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_extras:
 
@@ -1988,6 +2004,7 @@ custom_mutator_stage:
 
   afl->stage_finds[STAGE_CUSTOM_MUTATOR] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_CUSTOM_MUTATOR] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   if (likely(afl->custom_only)) {
 
@@ -2925,11 +2942,13 @@ havoc_stage:
 
     afl->stage_finds[STAGE_HAVOC] += new_hit_cnt - orig_hit_cnt;
     afl->stage_cycles[STAGE_HAVOC] += afl->stage_max;
+    afl->queue_cur->stats_mutated += afl->stage_max;
 
   } else {
 
     afl->stage_finds[STAGE_SPLICE] += new_hit_cnt - orig_hit_cnt;
     afl->stage_cycles[STAGE_SPLICE] += afl->stage_max;
+    afl->queue_cur->stats_mutated += afl->stage_max;
 
   }
 
@@ -3411,6 +3430,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP1] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP1] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Two walking bits. */
 
@@ -3442,6 +3462,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP2] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP2] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Four walking bits. */
 
@@ -3477,6 +3498,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP4] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP4] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Effector map setup. These macros calculate:
 
@@ -3584,6 +3606,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Two walking bytes. */
 
@@ -3626,6 +3649,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   if (len < 4) { goto skip_bitflip; }
 
@@ -3668,6 +3692,7 @@ static u8 mopt_common_fuzzing(afl_state_t *afl, MOpt_globals_t MOpt_globals) {
 
   afl->stage_finds[STAGE_FLIP32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_FLIP32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_bitflip:
 
@@ -3758,6 +3783,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* 16-bit arithmetics, both endians. */
 
@@ -3884,6 +3910,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* 32-bit arithmetics, both endians. */
 
@@ -4009,6 +4036,7 @@ skip_bitflip:
 
   afl->stage_finds[STAGE_ARITH32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_ARITH32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_arith:
 
@@ -4074,6 +4102,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST8] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST8] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Setting 16-bit integers, both endians. */
 
@@ -4160,6 +4189,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST16] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST16] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   if (len < 4) { goto skip_interest; }
 
@@ -4247,6 +4277,7 @@ skip_arith:
 
   afl->stage_finds[STAGE_INTEREST32] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_INTEREST32] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_interest:
 
@@ -4320,6 +4351,7 @@ skip_interest:
 
   afl->stage_finds[STAGE_EXTRAS_UO] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_UO] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Insertion of user-supplied extras. */
 
@@ -4376,6 +4408,7 @@ skip_interest:
 
   afl->stage_finds[STAGE_EXTRAS_UI] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_UI] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_user_extras:
 
@@ -4435,6 +4468,7 @@ skip_user_extras:
 
   afl->stage_finds[STAGE_EXTRAS_AO] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_AO] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
   /* Insertion of auto extras. */
 
@@ -4491,6 +4525,7 @@ skip_user_extras:
 
   afl->stage_finds[STAGE_EXTRAS_AI] += new_hit_cnt - orig_hit_cnt;
   afl->stage_cycles[STAGE_EXTRAS_AI] += afl->stage_max;
+  afl->queue_cur->stats_mutated += afl->stage_max;
 
 skip_extras:
 
@@ -5316,11 +5351,13 @@ pacemaker_fuzzing:
 
           afl->stage_finds[STAGE_HAVOC] += new_hit_cnt - orig_hit_cnt;
           afl->stage_cycles[STAGE_HAVOC] += afl->stage_max;
+          afl->queue_cur->stats_mutated += afl->stage_max;
 
         } else {
 
           afl->stage_finds[STAGE_SPLICE] += new_hit_cnt - orig_hit_cnt;
           afl->stage_cycles[STAGE_SPLICE] += afl->stage_max;
+          afl->queue_cur->stats_mutated += afl->stage_max;
 
         }
 

src/afl-fuzz-stats.c

@@ -365,6 +365,36 @@ void write_stats_file(afl_state_t *afl, u32 t_bytes, double bitmap_cvg,
 
 }
 
+void write_queue_stats(afl_state_t *afl) {
+
+  FILE *f;
+  u8   *fn = alloc_printf("%s/queue_data", afl->out_dir);
+  if ((f = fopen(fn, "w")) != NULL) {
+
+    u32 id;
+    fprintf(f,
+            "# filename, length, exec_us, selected, skipped, mutations, finds, "
+            "crashes, timeouts, bitmap_size, perf_score, weight, colorized, "
+            "favored, disabled\n");
+    for (id = 0; id < afl->queued_items; ++id) {
+
+      struct queue_entry *q = afl->queue_buf[id];
+      fprintf(f, "\"%s\",%u,%llu,%u,%u,%llu,%u,%u,%u,%u,%.3f,%.3f,%u,%u,%u\n",
+              q->fname, q->len, q->exec_us, q->stats_selected, q->stats_skipped,
+              q->stats_mutated, q->stats_finds, q->stats_crashes,
+              q->stats_tmouts, q->bitmap_size, q->perf_score, q->weight,
+              q->colorized, q->favored, q->disabled);
+
+    }
+
+    fclose(f);
+
+  }
+
+  ck_free(fn);
+
+}
+
 /* Update the plot file if there is a reason to. */
 
 void maybe_update_plot_file(afl_state_t *afl, u32 t_bytes, double bitmap_cvg,
@@ -613,6 +643,16 @@ void show_stats_normal(afl_state_t *afl) {
 
   }
 
+  /* Every now and then, write queue data. */
+
+  if (unlikely(afl->force_ui_update ||
+               cur_ms - afl->stats_last_queue_ms > QUEUE_UPDATE_SEC * 1000)) {
+
+    afl->stats_last_queue_ms = cur_ms;
+    write_queue_stats(afl);
+
+  }
+
   /* Honor AFL_EXIT_WHEN_DONE and AFL_BENCH_UNTIL_CRASH. */
 
   if (unlikely(!afl->non_instrumented_mode && afl->cycles_wo_finds > 100 &&
@@ -1399,6 +1439,16 @@ void show_stats_pizza(afl_state_t *afl) {
 
   }
 
+  /* Every now and then, write queue data. */
+
+  if (unlikely(afl->force_ui_update ||
+               cur_ms - afl->stats_last_queue_ms > QUEUE_UPDATE_SEC * 1000)) {
+
+    afl->stats_last_queue_ms = cur_ms;
+    write_queue_stats(afl);
+
+  }
+
   /* Honor AFL_EXIT_WHEN_DONE and AFL_BENCH_UNTIL_CRASH. */
 
   if (unlikely(!afl->non_instrumented_mode && afl->cycles_wo_finds > 100 &&

src/afl-fuzz.c

@@ -2278,7 +2278,7 @@ int main(int argc, char **argv_orig, char **envp) {
   afl->start_time = get_cur_time();
 
   u32 runs_in_current_cycle = (u32)-1;
-  u32 prev_queued_items = 0;
+  u32 prev_queued_items = 0, prev_saved_crashes = 0, prev_saved_tmouts = 0;
   u8  skipped_fuzz;
 
   #ifdef INTROSPECTION
@@ -2529,21 +2529,55 @@ int main(int argc, char **argv_orig, char **envp) {
       }
 
       skipped_fuzz = fuzz_one(afl);
+      ++afl->queue_cur->stats_selected;
+      if (unlikely(skipped_fuzz)) {
+
+        ++afl->queue_cur->stats_skipped;
+
+      } else {
+
+        if (unlikely(afl->queued_items > prev_queued_items)) {
+
+          afl->queue_cur->stats_finds += afl->queued_items - prev_queued_items;
+          prev_queued_items = afl->queued_items;
+
+        }
+
+        if (unlikely(afl->saved_crashes > prev_saved_crashes)) {
+
+          afl->queue_cur->stats_crashes +=
+              afl->saved_crashes - prev_saved_crashes;
+          prev_saved_crashes = afl->saved_crashes;
+
+        }
+
+        if (unlikely(afl->saved_tmouts > prev_saved_tmouts)) {
+
+          afl->queue_cur->stats_tmouts += afl->saved_tmouts - prev_saved_tmouts;
+          prev_saved_tmouts = afl->saved_tmouts;
+
+        }
+
+      }
 
       if (unlikely(!afl->stop_soon && exit_1)) { afl->stop_soon = 2; }
 
       if (unlikely(afl->old_seed_selection)) {
 
         while (++afl->current_entry < afl->queued_items &&
-               afl->queue_buf[afl->current_entry]->disabled)
+               afl->queue_buf[afl->current_entry]->disabled) {};
-          ;
         if (unlikely(afl->current_entry >= afl->queued_items ||
                      afl->queue_buf[afl->current_entry] == NULL ||
-                     afl->queue_buf[afl->current_entry]->disabled))
+                     afl->queue_buf[afl->current_entry]->disabled)) {
+
           afl->queue_cur = NULL;
-        else
+
+        } else {
+
           afl->queue_cur = afl->queue_buf[afl->current_entry];
 
+        }
+
       }
 
     } while (skipped_fuzz && afl->queue_cur && !afl->stop_soon);