timing.cc

Ubuntu packages of security software。 相当不错的源码

  gettimeofday(&now, NULL);
  time_diff = TIMEVAL_MSEC_SUBTRACT(now, lastcall);
  if (time_diff < (int) o.scan_delay) {  
    if (o.debugging > 1) {
      log_write(LOG_PLAIN, "Sleeping for %d milliseconds in %s()\n", o.scan_delay - time_diff, __func__);
    }
    usleep((o.scan_delay - time_diff) * 1000);
    gettimeofday(&lastcall, NULL);
  } else
    memcpy(&lastcall, &now, sizeof(struct timeval));
  if (tv) {
    memcpy(tv, &lastcall, sizeof(struct timeval));
  }

  return;    
}

ScanProgressMeter::ScanProgressMeter(char *stypestr) {
  scantypestr = strdup(stypestr);
  gettimeofday(&begin, NULL);
  last_print_test = begin;
  memset(&last_print, 0, sizeof(last_print));
  memset(&last_est, 0, sizeof(last_print));
  beginOrEndTask(&begin, NULL, true);
}

ScanProgressMeter::~ScanProgressMeter() {
  if (scantypestr) {
    free(scantypestr);
    scantypestr = NULL;
  }
}

/* Decides whether a timing report is likely to even be
   printed.  There are stringent limitations on how often they are
   printed, as well as the verbosity level that must exist.  So you
   might as well check this before spending much time computing
   progress info.  now can be NULL if caller doesn't have the current
   time handy.  Just because this function returns true does not mean
   that the next printStatsIfNeccessary will always print something.
   It depends on whether time estimates have changed, which this func
   doesn't even know about. */
bool ScanProgressMeter::mayBePrinted(const struct timeval *now) {
  struct timeval tv;

  if (!o.verbose)
    return false;

  if (!now) {
    gettimeofday(&tv, NULL);
    now = (const struct timeval *) &tv;
  }

  if (last_print.tv_sec == 0) {
    /* We've never printed before -- the rules are less stringent */
    if (TIMEVAL_MSEC_SUBTRACT(*now, begin) > 30000)
      return true;
    else return false;
  } 

  if (TIMEVAL_MSEC_SUBTRACT(*now, last_print_test) < 3000) 
    return false;  /* No point even checking too often */

  /* We'd never want to print more than once per 30 seconds */
  if (TIMEVAL_MSEC_SUBTRACT(*now, last_print) < 30000)
    return false;

  return true;
}

/* Prints an estimate of when this scan will complete.  It only does
   so if mayBePrinted() is true, and it seems reasonable to do so
   because the estimate has changed significantly.  Returns whether
   or not a line was printed.*/
bool ScanProgressMeter::printStatsIfNeccessary(double perc_done, 
					       const struct timeval *now) {
  struct timeval tvtmp;
  long time_used_ms;
  long time_needed_ms;
  long time_left_ms;
  long prev_est_time_left_ms; /* Time left as per prev. estimate */
  long change_abs_ms; /* absolute value of change */
  bool printit = false;

  if (!now) {
    gettimeofday(&tvtmp, NULL);
    now = (const struct timeval *) &tvtmp;
  }
  
  if (!mayBePrinted(now))
    return false;

  last_print_test = *now;

  if (perc_done <= 0.003)
    return false; /* Need more info first */

  assert(perc_done <= 1.0);

  /* OK, now lets estimate the time to finish */
  time_used_ms = TIMEVAL_MSEC_SUBTRACT(*now, begin);
  time_needed_ms = (int) ((double) time_used_ms / perc_done);
  time_left_ms = time_needed_ms - time_used_ms;

  if (time_left_ms < 30000)
    return false; /* No point in updating when it is virtually finished. */

  /* If we have not printed before, or if our previous ETC has elapsed, print
     a new one */
  if (last_print.tv_sec < 0)
    printit = true;
  else {
    /* If the estimate changed by more than X minutes, and if that
       change represents at least X% of the time remaining, print
       it.  */
    prev_est_time_left_ms = TIMEVAL_MSEC_SUBTRACT(last_est, *now);
    change_abs_ms = ABS(prev_est_time_left_ms - time_left_ms);
    if (prev_est_time_left_ms <= 0)
      printit = true;
    else if (o.debugging || (change_abs_ms > 180000 && change_abs_ms > .05 * MAX(time_left_ms, prev_est_time_left_ms)))
      printit = true;
  }

  if (printit) {
     return printStats(perc_done, now);
  } 
  return false;
}


/* Prints an estimate of when this scan will complete.  */
bool ScanProgressMeter::printStats(double perc_done, 
                                   const struct timeval *now) {
  struct timeval tvtmp;
  long time_used_ms;
  long time_needed_ms;
  long time_left_ms;
  long sec_left;
  time_t timet;
  struct tm *ltime;

  if (!now) {
    gettimeofday(&tvtmp, NULL);
    now = (const struct timeval *) &tvtmp;
  }
  
  /* OK, now lets estimate the time to finish */
  time_used_ms = TIMEVAL_MSEC_SUBTRACT(*now, begin);
  time_needed_ms = (int) ((double) time_used_ms / perc_done);
  time_left_ms = time_needed_ms - time_used_ms;

    /* Here we go! */
    last_print = *now;
    TIMEVAL_MSEC_ADD(last_est, *now, time_left_ms);
    timet = last_est.tv_sec;
    ltime = localtime(&timet);
    assert(ltime);

    sec_left = time_left_ms / 1000;

    // If we're less than 1% done we probably don't have enough
    // data for decent timing estimates. Also with perc_done == 0
    // these elements will be nonsensical.
    if (perc_done < 0.01) {
      log_write(LOG_STDOUT, "%s Timing: About %.2f%% done\n", 
                scantypestr, perc_done * 100);
      log_flush(LOG_STDOUT);
    } else {
      log_write(LOG_STDOUT, "%s Timing: About %.2f%% done; ETC: %02d:%02d (%li:%02li:%02li remaining)\n", 
                scantypestr, perc_done * 100, ltime->tm_hour, ltime->tm_min, sec_left / 3600, 
                (sec_left % 3600) / 60, sec_left % 60);
      log_write(LOG_XML, "<taskprogress task=\"%s\" time=\"%lu\" percent=\"%.2f\" remaining=\"%li\" etc=\"%lu\" />\n",
		scantypestr, (unsigned long) now->tv_sec,
		perc_done * 100, sec_left, (unsigned long) last_est.tv_sec);
      log_flush(LOG_STDOUT|LOG_XML);
    }
    return true;
}

/* Indicates that the task is beginning or ending, and that a message should
   be generated if appropriate.  Returns whether a message was printed.
   now may be NULL, if the caller doesn't have the current time handy.
   additional_info may be NULL if no additional information is necessary. */
bool ScanProgressMeter::beginOrEndTask(const struct timeval *now, const char *additional_info, bool beginning) {
  struct timeval tvtmp;
  struct tm *tm;
  time_t tv_sec;

  if (!o.verbose) {
    return false;
  }

  if (!now) {
    gettimeofday(&tvtmp, NULL);
    now = (const struct timeval *) &tvtmp;
  }

  tv_sec = now->tv_sec;
  tm = localtime(&tv_sec);
  if (beginning) {
    log_write(LOG_STDOUT, "Initiating %s at %02d:%02d", scantypestr, tm->tm_hour, tm->tm_min);
    log_write(LOG_XML, "<taskbegin task=\"%s\" time=\"%lu\"", scantypestr, (unsigned long) now->tv_sec);
    if (additional_info) {
      log_write(LOG_STDOUT, " (%s)", additional_info);
      log_write(LOG_XML, " extrainfo=\"%s\"", additional_info);
    }
    log_write(LOG_STDOUT, "\n");
    log_write(LOG_XML, " />\n");
  } else {
    log_write(LOG_STDOUT, "Completed %s at %02d:%02d, %.2fs elapsed", scantypestr, tm->tm_hour, tm->tm_min, TIMEVAL_MSEC_SUBTRACT(*now, begin) / 1000.0);
    log_write(LOG_XML, "<taskend task=\"%s\" time=\"%lu\"", scantypestr, (unsigned long) now->tv_sec);
    if (additional_info) {
      log_write(LOG_STDOUT, " (%s)", additional_info);
      log_write(LOG_XML, " extrainfo=\"%s\"", additional_info);
    }
    log_write(LOG_STDOUT, "\n");
    log_write(LOG_XML, " />\n");
  }
  log_flush(LOG_STDOUT|LOG_XML);
  return true;
}