use usecs instead of msecs as the basic unit of time

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 =

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

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;

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);
 }
 

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;

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;

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) {

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);

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);

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

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,