Merge pull request #214 from trailofbits/readme_tweaks_and_log_level_change

Change name of `log_level` option, add libfuzzer/AFL to example in README

README.md

@@ -290,16 +290,72 @@ CRITICAL: /Users/alex/deepstate/examples/Runlen.cpp(60): ORIGINAL: '91c499', ENC
 ERROR: Failed: Runlength_EncodeDecode
 ```
 
+If you're using the DeepState docker, it's easy to also try libFuzzer
+and AFL on the Runlen example:
+
+```shell
+mkdir libfuzzer_runlen
+./Runlen_LF libfuzzer_runlen -max_total_time=30
+./Runlen --input_test_files_dir libfuzzer_runlen
+```
+
+And you'll see a number of failures, e.g.:
+```
+WARNING: No test specified, defaulting to last test defined (Runlength_EncodeDecode)
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: '4af4aa', ENCODED: '4AaAfA4AaA', ROUNDTRIP: '4af4a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//9e266f6cb627ce3bb7d717a6e569ade6b3633f23 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aaaaaa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//d8fc60ccdd8f555c1858b9f0820f263e3d2b58ec failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: '4aaa', ENCODED: '4AaA', ROUNDTRIP: '4a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//3177c75208f2d35399842196dc8093243d5a8243 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aaa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//9842926af7ca0a8cca12604f945414f07b01e13d failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aaa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//85e53271e14006f0265921d02d4d736cdc580b0b failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aaaaa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//241cbd6dfb6e53c43c73b62f9384359091dcbf56 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//05a79f06cf3f67f726dae68d18a2290f6c9a50c9 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: '25aaaa', ENCODED: '2A5AaA', ROUNDTRIP: '25a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//419c3b754bacd6fc14ff9a932c5e2089d6dfcab5 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: 'aaaa', ENCODED: 'aA', ROUNDTRIP: 'a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//bb589d0621e5472f470fa3425a234c74b1e202e8 failed
+CRITICAL: /home/user/deepstate/examples/Runlen.cpp(60): ORIGINAL: '97aa', ENCODED: '9A7AaA', ROUNDTRIP: '97a'
+ERROR: Failed: Runlength_EncodeDecode
+ERROR: Test case libfuzzer_runlen//ca61c43b0e3ff0a8eccf3136996c9f1d9bfd627c failed
+INFO: Ran 16 tests; 10 tests failed
+```
+
+Using AFL is similarly easy:
+
+```shell
+mkdir afl_seeds
+echo "ok" >& seeds/seed
+afl-fuzz -i seeds -o afl_runlen -- ./Runlen_AFL --input_test_file @@ --no_fork --abort_on_fail
+```
+
+You'll have to stop this with Ctrl-C.  The `afl_runlen/crashes`
+directory will contain crashing inputs AFL found.
+
 ## Log Levels
 
 By default, DeepState is not very verbose about testing activity,
-other than failing tests.  The `--log_level` argument lowers the
+other than failing tests.  The `--min_log_level` argument lowers the
 threshold for output, with 0 = `DEBUG`, 1 = `TRACE` (output from the
 tests, including from `printf`), 2 = INFO (DeepState messages, the default), 3 = `WARNING`,
 4 = `ERROR`, 5 = `EXTERNAL` (output from other programs such as
-libFuzzer), and 6 = `CRITICAL` messages.  Lowering the `log_level` can be very
+libFuzzer), and 6 = `CRITICAL` messages.  Lowering the `min_log_level` can be very
 useful for understanding what a DeepState harness is actually doing;
-often, setting `--log_level 1` in either fuzzing or symbolic
+often, setting `--min_log_level 1` in either fuzzing or symbolic
 execution will give sufficient information to debug your test harness.
 
 

bin/deepstate/common.py

@@ -144,8 +144,8 @@ class DeepState(object):
         help="Verbosity level for symbolic execution tool (default: 1, lower means less output).")
 
     parser.add_argument(
-        "--log_level", default=2, type=int,
-        help="DeepState log level (default: 2), 0-6 (debug, trace, info, warning, error, external, critical).")
+        "--min_log_level", default=2, type=int,
+        help="Minimum DeepState log level to print (default: 2), 0-6 (debug, trace, info, warning, error, external, critical).")
     
     parser.add_argument(
         "binary", type=str, help="Path to the test binary to run.")
@@ -273,7 +273,7 @@ class DeepState(object):
       LOG_LEVEL_ERROR: logging.ERROR,
       LOG_LEVEL_FATAL: logging.CRITICAL
     }
-    LOGGER.setLevel(logging_levels[args.log_level])
+    LOGGER.setLevel(logging_levels[args.min_log_level])
     
     if args.output_test_dir is not None:
       test_dir = os.path.join(args.output_test_dir,

src/include/deepstate/DeepState.h

@@ -74,7 +74,7 @@ DECLARE_bool(fuzz);
 DECLARE_bool(fuzz_save_passing);
 DECLARE_bool(fork);
 
-DECLARE_int(log_level);
+DECLARE_int(min_log_level);
 DECLARE_int(seed);
 DECLARE_int(timeout);
 
@@ -794,8 +794,8 @@ static int DeepState_RunSingleSavedTestDir(void) {
   int num_failed_tests = 0;
   struct DeepState_TestInfo *test = NULL;  
 
-  if (!HAS_FLAG_log_level) {
-    FLAGS_log_level = 2;
+  if (!HAS_FLAG_min_log_level) {
+    FLAGS_min_log_level = 2;
   }
     
   DeepState_Setup();
@@ -876,8 +876,8 @@ static int DeepState_RunSavedTestCases(void) {
   int num_failed_tests = 0;
   struct DeepState_TestInfo *test = NULL;
 
-  if (!HAS_FLAG_log_level) {
-    FLAGS_log_level = 2;
+  if (!HAS_FLAG_min_log_level) {
+    FLAGS_min_log_level = 2;
   }
     
   DeepState_Setup();

src/lib/DeepState.c

@@ -47,7 +47,7 @@ DEFINE_bool(fuzz, false, "Perform brute force unguided fuzzing.");
 DEFINE_bool(fuzz_save_passing, false, "Save passing tests during fuzzing.");
 DEFINE_bool(fork, true, "Fork when running a test.");
 
-DEFINE_int(log_level, 0, "Minimum level of logging to output.");
+DEFINE_int(min_log_level, 0, "Minimum level of logging to output (default 2, 0=debug, 1=trace, 2=info, ...).");
 DEFINE_int(seed, 0, "Seed for brute force fuzzing (uses time if not set).");
 DEFINE_int(timeout, 120, "Timeout for brute force fuzzing.");
 
@@ -739,8 +739,8 @@ bool DeepState_CatchAbandoned(void) {
 int DeepState_Fuzz(void){
   DeepState_LogFormat(DeepState_LogInfo, "Starting fuzzing");
 
-  if (!HAS_FLAG_log_level) {
-    FLAGS_log_level = 2;
+  if (!HAS_FLAG_min_log_level) {
+    FLAGS_min_log_level = 2;
   }
   
   if (HAS_FLAG_seed) {
@@ -853,7 +853,7 @@ extern int LLVMFuzzerTestOneInput(const uint8_t *Data, size_t Size) {
 
   const char* loud = getenv("LIBFUZZER_LOUD");
   if (loud != NULL) {
-    FLAGS_log_level = 0;
+    FLAGS_min_log_level = 0;
     DeepState_LibFuzzerLoud = 1;
   }
   

src/lib/Log.c

@@ -77,7 +77,7 @@ char DeepState_LogBuf[DeepState_LogBufSize + 1] = {};
 DEEPSTATE_NOINLINE
 void DeepState_Log(enum DeepState_LogLevel level, const char *str) {
   if ((DeepState_UsingLibFuzzer && !DeepState_LibFuzzerLoud && (level < DeepState_LogExternal)) ||
-      (level < FLAGS_log_level)) {
+      (level < FLAGS_min_log_level)) {
     return;
   }
   memset(DeepState_LogBuf, 0, DeepState_LogBufSize);

tests/logrun.py

@@ -10,7 +10,7 @@ def logrun(cmd, file, timeout):
   sys.stderr.flush()
   with open(file, 'w') as outf:
     # We need to set log_level so we see ALL messages, for testing
-    p = subprocess.Popen(cmd + ["--log_level", "0"], stdout=outf, stderr=outf)
+    p = subprocess.Popen(cmd + ["--min_log_level", "0"], stdout=outf, stderr=outf)
   start = time.time()
   oldContents = ""
   lastOutput = time.time()