Skip to content

Commit

Permalink
Improve log parsing to fix performance analyzer for Go targets (#860).
Browse files Browse the repository at this point in the history
  • Loading branch information
@Dor1s
Dor1s committed Oct 29, 2019
1 parent 773c968 commit 6688f9e
Show file tree
Hide file tree
Showing 3 changed files with 59 additions and 3 deletions.
14 changes: 11 additions & 3 deletions src/python/bot/fuzzers/libFuzzer/stats.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,16 +41,19 @@
LIBFUZZER_CRASH_TYPE_REGEX.format(type='timeout'))

# Regular expressions to detect different sections of logs.
LIBFUZZER_EXTRA_COUNTERS_REGEX = re.compile(r'^INFO:\s+\d+\s+Extra\s+Counters')
LIBFUZZER_FUZZING_STRATEGIES = re.compile(r'cf::fuzzing_strategies:\s*(.*)')
LIBFUZZER_LOG_COVERAGE_REGEX = re.compile(r'#\d+.*cov:\s+(\d+)\s+ft:\s+(\d+).*')
LIBFUZZER_LOG_DICTIONARY_REGEX = re.compile(r'Dictionary: \d+ entries')
LIBFUZZER_LOG_END_REGEX = re.compile(r'Done \d+ runs.*')
LIBFUZZER_LOG_END_REGEX = re.compile(r'Done\s+\d+\s+runs.*')
LIBFUZZER_LOG_IGNORE_REGEX = re.compile(r'.*WARNING:.*Sanitizer')
LIBFUZZER_LOG_LINE_REGEX = re.compile(r'^#\d+.*(READ|cov:)')
LIBFUZZER_LOG_LINE_REGEX = re.compile(r'^#\d+.*(READ|NEW|pulse|REDUCE|ft:)')
LIBFUZZER_LOG_SEED_CORPUS_INFO_REGEX = re.compile(
r'INFO:\s+seed corpus:\s+files:\s+(\d+).*rss:\s+(\d+)Mb.*')
LIBFUZZER_LOG_START_INITED_REGEX = re.compile(
r'#\d+\s+INITED\s+cov:\s+(\d+)\s+ft:\s+(\d+).*')
LIBFUZZER_LOG_START_INITED_NO_COVERAGE_REGEX = re.compile(
r'#\d+\s+INITED\s+ft:\s+(\d+).*')
LIBFUZZER_MERGE_LOG_EDGE_COVERAGE_REGEX = re.compile(r'#\d+.*cov:\s+(\d+).*')
LIBFUZZER_MODULES_LOADED_REGEX = re.compile(
r'^INFO:\s+Loaded\s+\d+\s+(modules|PC tables)\s+\((\d+)\s+.*\).*')
Expand All @@ -74,7 +77,8 @@ def calculate_log_lines(log_lines):
for line in log_lines:
if not libfuzzer_inited:
# Skip to start of libFuzzer log output.
if LIBFUZZER_LOG_START_INITED_REGEX.match(line):
if (LIBFUZZER_LOG_START_INITED_REGEX.match(line) or
LIBFUZZER_LOG_START_INITED_NO_COVERAGE_REGEX.match(line)):
libfuzzer_inited = True
else:
ignored_lines_count += 1
Expand Down Expand Up @@ -262,6 +266,10 @@ def parse_performance_features(log_lines,
stats['startup_crash_count'] = 0
stats['edges_total'] = int(match.group(2))

match = LIBFUZZER_EXTRA_COUNTERS_REGEX.match(line)
if match:
stats['startup_crash_count'] = 0

match = LIBFUZZER_LOG_START_INITED_REGEX.match(line)
if match:
stats['initial_edge_coverage'] = stats['edge_coverage'] = int(
Expand Down
10 changes: 10 additions & 0 deletions src/python/tests/core/bot/fuzzers/libFuzzer/libfuzzer_stats_test.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,16 @@ def test_parse_log_and_stats_crash(self):
self.assertEqual(0, parsed_stats['corpus_crash_count'])
self.assertEqual(0, parsed_stats['startup_crash_count'])

def test_parse_log_and_stats_go_fuzz(self):
"""Test stats parsing and additional performance features extraction
without applying of stat_overrides."""
log_lines = self._read_test_data('go_fuzz_log.txt')
parsed_stats = stats.parse_performance_features(log_lines, [],
['-max_len=1337'])
self.assertEqual(0, parsed_stats['crash_count'])
self.assertEqual(0, parsed_stats['corpus_crash_count'])
self.assertEqual(0, parsed_stats['startup_crash_count'])

def test_parse_log_and_stats_startup_crash(self):
"""Test stats parsing and additional performance features extraction
without applying of stat_overrides."""
Expand Down
38 changes: 38 additions & 0 deletions src/python/tests/core/bot/fuzzers/libFuzzer/libfuzzer_test_data/go_fuzz_log.txt
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
Command: /mnt/scratch0/clusterfuzz/resources/platform/linux/minijail0 -f /tmp/tmpMg_9Md -U -m '0 1337 1' -T static -c 0 -n -v -p -l -I -k proc,/proc,proc,1 -P /mnt/scratch0/clusterfuzz/bot/inputs/fuzzer-testcases-disk/temp-387/tmpot31jp -b /mnt/scratch0/clusterfuzz/bot/inputs/fuzzer-testcases-disk/temp-387/tmpd5Appy,/tmp,1 -b /lib,/lib,0 -b /lib32,/lib32,0 -b /lib64,/lib64,0 -b /usr/lib,/usr/lib,0 -b /usr/lib32,/usr/lib32,0 -b /mnt/scratch0/clusterfuzz/bot/builds/clusterfuzz-builds_go-attestation_6af98b8fbc8e1eba35c78858068206247723399f/revisions,/mnt/scratch0/clusterfuzz/bot/builds/clusterfuzz-builds_go-attestation_6af98b8fbc8e1eba35c78858068206247723399f/revisions,0 -b /mnt/scratch0/clusterfuzz/bot/builds/clusterfuzz-builds_go-attestation_6af98b8fbc8e1eba35c78858068206247723399f/revisions,/out,0 -b /mnt/scratch0/clusterfuzz/bot/inputs/fuzzer-testcases-disk/temp-387/new,/new,1 -b /mnt/scratch0/clusterfuzz/bot/inputs/data-bundles/global/go-attestation_parse_event_log_fuzzer,/go-attestation_parse_event_log_fuzzer,1 -b /mnt/scratch0/clusterfuzz/bot/inputs/fuzzer-testcases,/fuzzer-testcases,1 /mnt/scratch0/clusterfuzz/bot/builds/clusterfuzz-builds_go-attestation_6af98b8fbc8e1eba35c78858068206247723399f/revisions/parse_event_log_fuzzer -timeout=25 -rss_limit_mb=2048 -dict=/mnt/scratch0/clusterfuzz/bot/builds/clusterfuzz-builds_go-attestation_6af98b8fbc8e1eba35c78858068206247723399f/revisions/parse_event_log_fuzzer.dict.merged -artifact_prefix=/fuzzer-testcases/ -max_total_time=6250 -print_final_stats=1 /new /go-attestation_parse_event_log_fuzzer
Bot: oss-fuzz-linux-zone3-worker-go-attestation-8nv6
Time ran: 6251.10500097

Dictionary: 6 entries
INFO: Seed: 3372372460
INFO: 65536 Extra Counters
INFO: 0 files found in /new
INFO: 654 files found in /go-attestation_parse_event_log_fuzzer
INFO: -max_len is not provided; libFuzzer will not generate inputs larger than 251192 bytes
INFO: seed corpus: files: 654 min: 1b max: 251192b total: 994633b rss: 29Mb
#655 INITED ft: 1256 corp: 90/114Kb exec/s: 0 rss: 46Mb
#32434 NEW ft: 1257 corp: 91/114Kb lim: 8152 exec/s: 16217 rss: 136Mb L: 184/7840 MS: 4 ChangeASCIIInt-EraseBytes-ChangeByte-ShuffleBytes-
#32768 pulse ft: 1257 corp: 91/114Kb lim: 8152 exec/s: 16384 rss: 136Mb
#65536 pulse ft: 1257 corp: 91/114Kb lim: 8473 exec/s: 13107 rss: 136Mb
#131072 pulse ft: 1257 corp: 91/114Kb lim: 9123 exec/s: 13107 rss: 136Mb
#262144 pulse ft: 1257 corp: 91/114Kb lim: 10436 exec/s: 13107 rss: 141Mb
#524288 pulse ft: 1257 corp: 91/114Kb lim: 13049 exec/s: 12787 rss: 149Mb
#1048576 pulse ft: 1257 corp: 91/114Kb lim: 18266 exec/s: 12633 rss: 166Mb
#2097152 pulse ft: 1257 corp: 91/114Kb lim: 28710 exec/s: 12409 rss: 191Mb
#2784915 REDUCE ft: 1257 corp: 91/114Kb lim: 35575 exec/s: 12377 rss: 198Mb L: 110/7840 MS: 1 EraseBytes-
#4194304 pulse ft: 1257 corp: 91/114Kb lim: 49615 exec/s: 12228 rss: 229Mb
#8064536 REDUCE ft: 1257 corp: 91/114Kb lim: 88185 exec/s: 12018 rss: 241Mb L: 86/7840 MS: 1 EraseBytes-
#8388608 pulse ft: 1257 corp: 91/114Kb lim: 91401 exec/s: 12000 rss: 241Mb
#9421732 REDUCE ft: 1257 corp: 91/114Kb lim: 101705 exec/s: 11971 rss: 265Mb L: 57/7840 MS: 1 EraseBytes-
#11047358 REDUCE ft: 1257 corp: 91/114Kb lim: 117897 exec/s: 11866 rss: 269Mb L: 36/7840 MS: 1 EraseBytes-
#15412369 REDUCE ft: 1257 corp: 91/114Kb lim: 161409 exec/s: 11120 rss: 286Mb L: 35/7840 MS: 1 EraseBytes-
#15602250 REDUCE ft: 1257 corp: 91/114Kb lim: 163296 exec/s: 11081 rss: 286Mb L: 32/7840 MS: 1 EraseBytes-
#16777216 pulse ft: 1257 corp: 91/114Kb lim: 175009 exec/s: 10880 rss: 286Mb
#33554432 pulse ft: 1257 corp: 91/114Kb lim: 251192 exec/s: 9054 rss: 286Mb
#50928490 DONE ft: 1257 corp: 91/114Kb lim: 251192 exec/s: 8147 rss: 286Mb
Done 50928490 runs in 6251 second(s)
stat::number_of_executed_units: 50928490
stat::average_exec_per_sec: 8147
stat::new_units_added: 7
stat::slowest_unit_time_sec: 0
stat::peak_rss_mb: 286
cf::fuzzing_strategies: recommended_dict:1

0 comments on commit 6688f9e

Please sign in to comment.