diff --git a/cmdline.c b/cmdline.c index cbc5df566..64532a69e 100644 --- a/cmdline.c +++ b/cmdline.c @@ -342,7 +342,7 @@ bool cmdlineParse(int argc, char* argv[], honggfuzz_t* hfuzz) { .runEndTime = 0, .tmOut = 1, .lastCovUpdate = time(NULL), - .timeOfLongestUnitInMilliseconds = 0, + .timeOfLongestUnitUSecs = 0, .tmoutVTALRM = false, }, .mutate = @@ -357,7 +357,7 @@ bool cmdlineParse(int argc, char* argv[], honggfuzz_t* hfuzz) { .display = { .useScreen = true, - .lastDisplayMillis = util_timeNowMillis(), + .lastDisplayUSecs = util_timeNowUSecs(), .cmdline_txt[0] = '\0', }, .cfg = diff --git a/display.c b/display.c index 4f41e7985..81baf3bf4 100644 --- a/display.c +++ b/display.c @@ -171,9 +171,9 @@ void display_display(honggfuzz_t* hfuzz) { const time_t curr_sec = time(NULL); const time_t elapsed_sec = curr_sec - hfuzz->timing.timeStart; - const int64_t curr_time_millis = util_timeNowMillis(); - const int64_t elapsed_millis = curr_time_millis - hfuzz->display.lastDisplayMillis; - hfuzz->display.lastDisplayMillis = curr_time_millis; + const int64_t curr_time_usecs = util_timeNowUSecs(); + const int64_t elapsed_usecs = curr_time_usecs - hfuzz->display.lastDisplayUSecs; + hfuzz->display.lastDisplayUSecs = curr_time_usecs; char lastCovStr[64]; getDuration(curr_sec - ATOMIC_GET(hfuzz->timing.lastCovUpdate), lastCovStr, sizeof(lastCovStr)); @@ -200,8 +200,8 @@ void display_display(honggfuzz_t* hfuzz) { } static size_t prev_exec_cnt = 0UL; - size_t exec_per_millis = - elapsed_millis ? ((curr_exec_cnt - prev_exec_cnt) * 1000) / elapsed_millis : 0; + size_t exec_per_usecs = + elapsed_usecs ? ((curr_exec_cnt - prev_exec_cnt) * 1000000) / elapsed_usecs : 0; prev_exec_cnt = curr_exec_cnt; display_start(); @@ -257,7 +257,7 @@ void display_display(honggfuzz_t* hfuzz) { size_t tot_exec_per_sec = elapsed_sec ? (curr_exec_cnt / elapsed_sec) : 0; display_put(" Speed : " ESC_BOLD "%" _HF_NONMON_SEP "zu" ESC_RESET "/sec [avg: " ESC_BOLD "%" _HF_NONMON_SEP "zu" ESC_RESET "]\n", - exec_per_millis, tot_exec_per_sec); + exec_per_usecs, tot_exec_per_sec); uint64_t crashesCnt = ATOMIC_GET(hfuzz->cnts.crashesCnt); /* colored the crash count as red when exist crash */ diff --git a/fuzz.c b/fuzz.c index 997316fe3..c505de3e6 100644 --- a/fuzz.c +++ b/fuzz.c @@ -132,7 +132,7 @@ static void fuzz_setDynamicMainState(run_t* run) { .cov = {}, .idx = 0, .fd = -1, - .timeExecMillis = 1, + .timeExecUSecs = 1, .path = "[DYNAMIC-0-SIZE]", .data = (uint8_t*)"", }; @@ -219,10 +219,10 @@ static void fuzz_perfFeedback(run_t* run) { run->global->linux.hwCnts.softCntEdge += softCntEdge; run->global->linux.hwCnts.softCntCmp += softCntCmp; - LOG_I("Size:%zu Time:%" PRIu64 "ms (i/b/h/e/p/c): %" PRIu64 "/%" PRIu64 "/%" PRIu64 + LOG_I("Size:%zu Time:%" PRIu64 "us (i/b/h/e/p/c): %" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64 ", Tot:%" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64 "/%" PRIu64, - run->dynfile->size, util_timeNowMillis() - run->timeStartedMillis, + run->dynfile->size, util_timeNowUSecs() - run->timeStartedUSecs, run->linux.hwCnts.cpuInstrCnt, run->linux.hwCnts.cpuBranchCnt, run->linux.hwCnts.newBBCnt, softCntEdge, softCntPc, softCntCmp, run->global->linux.hwCnts.cpuInstrCnt, run->global->linux.hwCnts.cpuBranchCnt, @@ -260,7 +260,7 @@ static bool fuzz_runVerifier(run_t* run) { for (int i = 0; i < _HF_VERIFIER_ITER; i++) { LOG_I("Launching verifier for HASH: %" PRIx64 " (iteration: %d out of %d)", run->backtrace, i + 1, _HF_VERIFIER_ITER); - run->timeStartedMillis = util_timeNowMillis(); + run->timeStartedUSecs = util_timeNowUSecs(); run->backtrace = 0; run->access = 0; run->exception = 0; @@ -375,7 +375,7 @@ static bool fuzz_fetchInput(run_t* run) { } static void fuzz_fuzzLoop(run_t* run) { - run->timeStartedMillis = util_timeNowMillis(); + run->timeStartedUSecs = util_timeNowUSecs(); run->crashFileName[0] = '\0'; run->pc = 0; run->backtrace = 0; @@ -412,7 +412,7 @@ static void fuzz_fuzzLoop(run_t* run) { } static void fuzz_fuzzLoopSocket(run_t* run) { - run->timeStartedMillis = util_timeNowMillis(); + run->timeStartedUSecs = util_timeNowUSecs(); run->crashFileName[0] = '\0'; run->pc = 0; run->backtrace = 0; diff --git a/honggfuzz.c b/honggfuzz.c index 519722cf1..2b294b7c0 100644 --- a/honggfuzz.c +++ b/honggfuzz.c @@ -211,7 +211,7 @@ static void printSummary(honggfuzz_t* hfuzz) { "peak_rss_mb:%lu", hfuzz->cnts.mutationsCnt, elapsed_sec, exec_per_sec, hfuzz->cnts.crashesCnt, hfuzz->cnts.timeoutedCnt, hfuzz->io.newUnitsAdded, - hfuzz->timing.timeOfLongestUnitInMilliseconds, hfuzz->feedback.covFeedbackMap->guardNb, + hfuzz->timing.timeOfLongestUnitUSecs / 1000U, hfuzz->feedback.covFeedbackMap->guardNb, branch_percent_cov, usage.ru_maxrss); } diff --git a/honggfuzz.h b/honggfuzz.h index 0011f3b27..692d1f446 100644 --- a/honggfuzz.h +++ b/honggfuzz.h @@ -143,7 +143,7 @@ struct _dynfile_t { uint64_t cov[4]; size_t idx; int fd; - uint64_t timeExecMillis; + uint64_t timeExecUSecs; char path[PATH_MAX]; struct _dynfile_t* src; uint32_t refs; @@ -232,7 +232,7 @@ typedef struct { time_t runEndTime; time_t tmOut; time_t lastCovUpdate; - int64_t timeOfLongestUnitInMilliseconds; + int64_t timeOfLongestUnitUSecs; bool tmoutVTALRM; } timing; struct { @@ -249,7 +249,7 @@ typedef struct { struct { bool useScreen; char cmdline_txt[65]; - int64_t lastDisplayMillis; + int64_t lastDisplayUSecs; } display; struct { bool useVerifier; @@ -332,7 +332,7 @@ typedef enum { typedef struct { honggfuzz_t* global; pid_t pid; - int64_t timeStartedMillis; + int64_t timeStartedUSecs; char crashFileName[PATH_MAX]; uint64_t pc; uint64_t backtrace; diff --git a/input.c b/input.c index f6768b3ab..8b4744638 100644 --- a/input.c +++ b/input.c @@ -378,7 +378,7 @@ void input_addDynamicInput(run_t* run) { dynfile_t* dynfile = (dynfile_t*)util_Calloc(sizeof(dynfile_t)); dynfile->size = run->dynfile->size; memcpy(dynfile->cov, run->dynfile->cov, sizeof(dynfile->cov)); - dynfile->timeExecMillis = util_timeNowMillis() - run->timeStartedMillis; + dynfile->timeExecUSecs = util_timeNowUSecs() - run->timeStartedUSecs; dynfile->data = (uint8_t*)util_AllocCopy(run->dynfile->data, run->dynfile->size); dynfile->src = run->dynfile->src; if (run->dynfile->src) { @@ -440,24 +440,29 @@ bool input_inDynamicCorpus(run_t* run, const char* fname) { return false; } -static inline unsigned input_slowFactor(run_t* run, dynfile_t* dynfile) { +static inline int input_speedFactor(run_t* run, dynfile_t* dynfile) { /* Slower the input, lower the chance of it being tested */ - uint64_t msec_per_run = ((uint64_t)(time(NULL) - run->global->timing.timeStart) * 1000); - msec_per_run /= ATOMIC_GET(run->global->cnts.mutationsCnt); - msec_per_run /= run->global->threads.threadsMax; - /* Cap this to 1-10 ms */ - msec_per_run = HF_CAP(msec_per_run, 1, 10); - - unsigned slow_factor = (unsigned)(dynfile->timeExecMillis / msec_per_run); - return HF_MIN(slow_factor, 20); + uint64_t usecs_per_run = ((uint64_t)(time(NULL) - run->global->timing.timeStart) * 1000000); + usecs_per_run /= ATOMIC_GET(run->global->cnts.mutationsCnt); + usecs_per_run /= run->global->threads.threadsMax; + + /* Cap both vals to 1us-1s */ + usecs_per_run = HF_CAP(usecs_per_run, 1U, 1000000U); + uint64_t sample_exec_usec = HF_CAP(dynfile->timeExecUSecs, 1U, 1000000U); + + if (sample_exec_usec >= usecs_per_run) { + return (int)(sample_exec_usec / usecs_per_run); + } else { + return -(int)(usecs_per_run / sample_exec_usec); + } } -static inline unsigned input_skipFactor(run_t* run, dynfile_t* dynfile, unsigned* slow_factor) { +static inline unsigned input_skipFactor(run_t* run, dynfile_t* dynfile, int* speed_factor) { int penalty = 1; { - *slow_factor = input_slowFactor(run, dynfile); - penalty += HF_CAP(((int)*slow_factor - 3), -15, 30); + *speed_factor = input_speedFactor(run, dynfile); + penalty += HF_CAP(*speed_factor, -30, 30); } { @@ -503,7 +508,7 @@ bool input_prepareDynamicInput(run_t* run, bool needs_mangle) { LOG_F("The dynamic file corpus is empty. This shouldn't happen"); } - unsigned slow_factor = 0; + int speed_factor = 0; for (;;) { MX_SCOPED_RWLOCK_WRITE(&run->global->io.dynfileq_mutex); @@ -514,7 +519,7 @@ bool input_prepareDynamicInput(run_t* run, bool needs_mangle) { current = run->global->io.dynfileqCurrent; run->global->io.dynfileqCurrent = TAILQ_NEXT(run->global->io.dynfileqCurrent, pointers); - unsigned skip_factor = input_skipFactor(run, current, &slow_factor); + unsigned skip_factor = input_skipFactor(run, current, &speed_factor); if ((util_rnd64() % skip_factor) == 0) { break; } @@ -523,14 +528,14 @@ bool input_prepareDynamicInput(run_t* run, bool needs_mangle) { input_setSize(run, current->size); memcpy(run->dynfile->cov, current->cov, sizeof(run->dynfile->cov)); run->dynfile->idx = current->idx; - run->dynfile->timeExecMillis = current->timeExecMillis; + run->dynfile->timeExecUSecs = current->timeExecUSecs; snprintf(run->dynfile->path, sizeof(run->dynfile->path), "%s", current->path); run->dynfile->src = current; run->dynfile->refs = 0; memcpy(run->dynfile->data, current->data, current->size); if (needs_mangle) { - mangle_mangleContent(run, slow_factor); + mangle_mangleContent(run, speed_factor); } return true; diff --git a/libhfcommon/util.c b/libhfcommon/util.c index ac344ac47..8733b1f9c 100644 --- a/libhfcommon/util.c +++ b/libhfcommon/util.c @@ -243,13 +243,13 @@ uint64_t util_hash(const char* buf, size_t len) { return ret; } -int64_t util_timeNowMillis(void) { +int64_t util_timeNowUSecs(void) { struct timeval tv; if (gettimeofday(&tv, NULL) == -1) { PLOG_F("gettimeofday()"); } - return (((int64_t)tv.tv_sec * 1000LL) + ((int64_t)tv.tv_usec / 1000LL)); + return (((int64_t)tv.tv_sec * 1000000) + (int64_t)tv.tv_usec); } void util_sleepForMSec(uint64_t msec) { diff --git a/libhfcommon/util.h b/libhfcommon/util.h index f1a7a869c..6002a1cfd 100644 --- a/libhfcommon/util.h +++ b/libhfcommon/util.h @@ -133,7 +133,7 @@ extern bool util_64bitValInBinary(uint32_t v); extern uint64_t util_hash(const char* buf, size_t len); extern int64_t fastArray64Search(uint64_t* array, size_t arraySz, uint64_t key); -extern int64_t util_timeNowMillis(void); +extern int64_t util_timeNowUSecs(void); extern void util_sleepForMSec(uint64_t msec); extern uint64_t util_getUINT32(const uint8_t* buf); diff --git a/mangle.c b/mangle.c index bcea4bae5..ed1551030 100644 --- a/mangle.c +++ b/mangle.c @@ -825,7 +825,7 @@ static void mangle_Resize(run_t* run, bool printable) { } } -void mangle_mangleContent(run_t* run, unsigned slow_factor) { +void mangle_mangleContent(run_t* run, int speed_factor) { static void (*const mangleFuncs[])(run_t * run, bool printable) = { /* Every *Insert or Expand expands file, so add more Shrink's */ mangle_Shrink, @@ -868,18 +868,18 @@ void mangle_mangleContent(run_t* run, unsigned slow_factor) { } uint64_t changesCnt = run->global->mutate.mutationsPerRun; - switch (slow_factor) { - case 0 ... 3: - changesCnt = util_rndGet(1, run->global->mutate.mutationsPerRun); - break; - default: - /* Give it a good shake-up, if it's a slow input */ - changesCnt = HF_MIN(slow_factor, 20); - changesCnt = HF_MAX(changesCnt, run->global->mutate.mutationsPerRun); - break; + + if (speed_factor <= 1) { + changesCnt = util_rndGet(1, run->global->mutate.mutationsPerRun); + } else if (speed_factor <= 3) { + changesCnt = run->global->mutate.mutationsPerRun; + } else { + changesCnt = HF_MIN(speed_factor, 20); + changesCnt = HF_MAX(changesCnt, run->global->mutate.mutationsPerRun); } - if ((util_timeNowMillis() - ATOMIC_GET(run->global->timing.lastCovUpdate)) > 5000) { + /* If last coverage acquisition was mroe than 5 secs ago, use splicing more frequently */ + if ((util_timeNowUSecs() - ATOMIC_GET(run->global->timing.lastCovUpdate)) > 5000000) { switch (util_rnd64() % 4) { case 0: mangle_SpliceOverwrite(run, run->global->cfg.only_printable); diff --git a/mangle.h b/mangle.h index 0fccfcac0..f8f3988cb 100644 --- a/mangle.h +++ b/mangle.h @@ -26,6 +26,6 @@ #include "honggfuzz.h" -extern void mangle_mangleContent(run_t* run, unsigned slow_factor); +extern void mangle_mangleContent(run_t* run, int speed_factor); #endif diff --git a/subproc.c b/subproc.c index f903b4566..7e2163fd2 100644 --- a/subproc.c +++ b/subproc.c @@ -429,13 +429,13 @@ bool subproc_Run(run_t* run) { arch_prepareParent(run); arch_reapChild(run); - int64_t diffMillis = util_timeNowMillis() - run->timeStartedMillis; + int64_t diffUSecs = util_timeNowUSecs() - run->timeStartedUSecs; { static pthread_mutex_t local_mutex = PTHREAD_MUTEX_INITIALIZER; MX_SCOPED_LOCK(&local_mutex); - if (diffMillis >= ATOMIC_GET(run->global->timing.timeOfLongestUnitInMilliseconds)) { - ATOMIC_SET(run->global->timing.timeOfLongestUnitInMilliseconds, diffMillis); + if (diffUSecs >= ATOMIC_GET(run->global->timing.timeOfLongestUnitUSecs)) { + ATOMIC_SET(run->global->timing.timeOfLongestUnitUSecs, diffUSecs); } } @@ -506,17 +506,17 @@ void subproc_checkTimeLimit(run_t* run) { return; } - int64_t curMillis = util_timeNowMillis(); - int64_t diffMillis = curMillis - run->timeStartedMillis; + int64_t curUSecs = util_timeNowUSecs(); + int64_t diffUSecs = curUSecs - run->timeStartedUSecs; - if (run->tmOutSignaled && (diffMillis > ((run->global->timing.tmOut + 1) * 1000))) { + if (run->tmOutSignaled && (diffUSecs > ((run->global->timing.tmOut + 1) * 1000000))) { /* Has this instance been already signaled due to timeout? Just, SIGKILL it */ LOG_W("pid=%d has already been signaled due to timeout. Killing it with SIGKILL", run->pid); kill(run->pid, SIGKILL); return; } - if ((diffMillis > (run->global->timing.tmOut * 1000)) && !run->tmOutSignaled) { + if ((diffUSecs > (run->global->timing.tmOut * 1000000)) && !run->tmOutSignaled) { run->tmOutSignaled = true; LOG_W("pid=%d took too much time (limit %ld s). Killing it with %s", (int)run->pid, (long)run->global->timing.tmOut,