Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

A small problem about calibrate_case #159

Open
MortalAndTry opened this issue Mar 19, 2019 · 3 comments
Open

A small problem about calibrate_case #159

MortalAndTry opened this issue Mar 19, 2019 · 3 comments

Comments

@MortalAndTry
Copy link
Contributor

MortalAndTry commented Mar 19, 2019

when i debug afl-fuzz.c with test.exe, I find that i can't trim input file successfully , Because the cksum(come from hash32 function) is always different with q->exec_cksum。q->exec_cksum is set in function calibrate_case 。 My input file is “abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789”。Note that there is not a character 't' in the input file, so no matter how i trim it , the execution path and the cksum should be the same as q->exec_cksum. But the truth is not what I thought it would be.

In order to find the reason , i record some data in my log.txt. And in order to determine if trace_bits is all the same , I wirite a trace_bit_sum() function like this:

int trace_bit_sum() {
	int i = 0;
	int result = 0;
	for (i; i < MAP_SIZE; i++) {
		if(trace_bits[i] > 0)
			result++;
	}
	return result;
}

here's my log.txt: (trace_sum is the return value of trace_bit_sum() )

perform_dry_run start
calibrate_case start 
sample:	abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
cksum: 3897125560   trace_sum: 17
calibrate_case  end
perform_dry_run end 

trim_case start
sample:	abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
one trim length
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 3897125560  trace_sum: 17
cksum: 3897125560  trace_sum: 17
cksum: 3897125560  trace_sum: 17
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
one trim length
write after trim:
abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz456789
ok , i trim it 
trim_case end

look :
perform_dry_run function start, calibrate_case function start,
the cksum I get in function calibrate_case has alwys been 3897125560 , and the trace_sum is 17。so the q->exec_cksum is 3897125560 .
But when I trim the input file, most of the cksum are 675120926 , which caused that i can't successfully cut the input file.

I've made a lot of attempts to solve this problem. Eventually, I found out that i need to add a delay between run_target() and hash32() in calibrate_case() function. like this:

    fault = run_target(argv, use_tmout);
    Sleep(50);

    /* 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;
    }

    cksum = hash32(trace_bits, MAP_SIZE, HASH_CONST);

my new log.txt like this:

perform_dry_run start
calibrate_case start 
sample:	abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
cksum: 675120926   trace_sum: 18
calibrate_case  end
perform_dry_run end 
trim_case start
sample:	abcdefghijklmnopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
once trim len
cksum: 675120926  trace_sum: 18
once trim len
write after trim:
abcd
ok , i trim it 
trim_case end

look , I trim the input fiel successfully.
So do you know what caused this?

@ifratric
Copy link
Collaborator

Interesting, thanks for the analysis! Let's try to figure out the root cause, and some more help with this would be greatly appreciated. It looks like in some cases an extra basic block is encountered and it might be useful to know which one it is. Could you add some extra logging to figure out what its offset in trace_bits is?

I'm not sure why trace_bits would change once the iteration is already over. One possible explanation would be that another thread is hitting a basic block in the coverage module. If this is the case, the problem should vanish when the coverage is collected only from a single thread. Could you test again with -thread_coverage added to the instrumentation flags and see if the problem persists?

@MortalAndTry
Copy link
Contributor Author

MortalAndTry commented Mar 21, 2019

I don't think that " in some cases an extra basic block is encountered ", becausee I did the following try:

for (stage_cur = 0; stage_cur < stage_max; stage_cur++) {
    u32 cksum = 0;
    int trace_sum = 0;

    if (!first_run && !(stage_cur % stats_update_freq)) show_stats();
    write_to_testcase(use_mem, q->len);

    fault = run_target(argv, use_tmout);

    trace_sum = trace_bit_sum();
    cksum = hash32(trace_bits, MAP_SIZE, HASH_CONST);
    fprintf_s(testlog, "before sleep, cksum: %u   trace_sum: %d\n", cksum, trace_sum);
    trace_sum = 0;
    cksum = 0;

    Sleep(50);

    if (stop_soon || fault != crash_mode) goto abort_calibration;

    if (!dumb_mode && !stage_cur && !count_bytes(trace_bits)) {
      fault = FAULT_NOINST;
      goto abort_calibration;
    }

    trace_sum = trace_bit_sum();
    cksum = hash32(trace_bits, MAP_SIZE, HASH_CONST);
    fprintf_s(testlog, "after sleep, cksum: %u   trace_sum: %d\n", cksum, trace_sum);

After run_target() function, I get two times cksum, once before sleep(50), once after sleep(50) , the log is following:

perform_dry_run start
calibrate_case start 
sample:	abcdefghijklmntestopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
before sleep, cksum: 3897125560   trace_sum: 17
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
before sleep, cksum: 675120926   trace_sum: 18
after sleep, cksum: 675120926   trace_sum: 18
calibrate_case  end
perform_dry_run end 
trim_case start
sample:	abcdefghijklmntestopqrsuvwxyz123456789123456789abcdefghijklmnopqrsuvwxyz123456789123456789
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
cksum: 675120926  trace_sum: 18
once trim len
cksum: 675120926  trace_sum: 18
once trim len
write after trim:
abcd
ok , i trim it 
trim_case end

so i think the key is "time"

@ifratric
Copy link
Collaborator

Yes, but the question is, why is trace_sum 17 before and 18 after sleep in some cases, and my thinking is that something must have written to trace_bits in the meantime, which only happens in winafl.dll when an instrumented basic block is hit. Either that or afl-fuzz is reading stale data from the cpu cache, which would be odd IMHO.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants