Process our logs after tracing to work out how much time is spent where
542895
function processLogs() {
  var calcs = 0;
  for (var i in stats) {
    stats[i].average = stats[i].totalTime / stats[i].count;
    calcs += stats[i].calcs;
  }
  var time1 = meaningfulTime();
  var time2 = meaningfulTime();
  console.error("TRACER TOTAL OVERHEAD", (calcs*timeDiff(time2, time1)).toFixed(2)+'ms');

  while (Object.keys(stats).length > 0) {
    var biggest = 0;
    var biggestPath = Object.keys(stats)[0];
    for (var path in stats) {
      if (stats[path].average >= biggest) {
        biggestPath = path;
        biggest = stats[path].average;
      }
    }
    console.error("TRACER TOTAL",
                  stats[biggestPath].min.toFixed(2)+'ms',
                  stats[biggestPath].average.toFixed(2)+'ms',
                  stats[biggestPath].max.toFixed(2)+'ms',
                  stats[biggestPath].count,
                  biggestPath);
    delete stats[biggestPath];
  }
}
858212
function startTracer() {
  if (!moduleRef) {
    for (var i in window) {
      if ([ 'top', 'document', 'window', 'worker', 'parent', 'frames', 'self', 'performance', 'navigator' ].indexOf(i) === -1) {
        processModules({ exports: window[i], filename: i });
      }
    }
  } else {
    processModules(parentModule);
  }
  active = true;
  measureTracerOverhead();
}
1192928
def log_end(path, log_file, sum_time):
    
    with open(path + log_file, "a") as log:
        log.seek(2)
        log.write("#" * 79 + "\n\n")
        log.write("Time : " + time.strftime("%H:%M:%S") + "\n")
        log.write("Total build time : {0}\n".format(sum_time))
        log.write(" " * 38 + "E N D\n\n")
        log.write("#" * 79 + "\n\n")
        log.close()
502843
def constructTotalCounts(self, logger):
        '''
        
        '''
        self.totalSize = self.bwt.shape[0]
        
        abtFN = self.dirName+'/totalCounts.p'
        if os.path.exists(abtFN):
            fp = open(abtFN, 'r')
            self.totalCounts = pickle.load(fp)
            fp.close()
        else:
            chunkSize = 2**20
            if logger != None:
                logger.info('First time calculation of \'%s\'' % abtFN)
            
            #figure out the counts using the standard counting techniques, one chunk at a time
            self.totalCounts = [0]*self.vcLen
            i = 0
            while i*chunkSize < self.bwt.shape[0]:
                self.totalCounts = np.add(self.totalCounts, np.bincount(self.bwt[i*chunkSize:(i+1)*chunkSize], minlength=self.vcLen))
                i += 1
            
            #save the total count to '<DIR>/totalCounts.p'
            fp = open(abtFN, 'w+')
            pickle.dump(self.totalCounts, fp)
            fp.close()
923805
def logtrace(logger, msg, *args, **kwargs):
    '''
    
    '''
    if esgfpid.defaults.LOG_TRACE_TO_DEBUG:
        logdebug(logger, '[trace] %s' % msg, *args, **kwargs)
    else:
        pass
1089959
def _perform_system_check(self):
        
        if Global.CONFIG_MANAGER.tracing_mode:
            Global.LOGGER.debug("performing a system check")

        now = datetime.datetime.now()
        sent = Global.MESSAGE_DISPATCHER.dispatched
        received = self.fetched
        queue_length = sent - received
        message_sleep_interval = Global.CONFIG_MANAGER.message_fetcher_sleep_interval

        if Global.CONFIG_MANAGER.show_stats:
            if (now - self.last_stats_check_date).total_seconds() > Global.CONFIG_MANAGER.stats_timeout:
                self.last_stats_check_date = now
                stats_string = f"showing stats\n--- [STATS] ---\nMessage Sent: {sent}\nMessage Received: {received}\nMessage Sleep Interval = {message_sleep_interval}\nQueue length = {queue_length}\n--- [ END ] ---"
                Global.LOGGER.info(stats_string)

        # if we are accumulating messages, or we have processed at least 5000 messages
        # since last check, we need to speed up the process
        messages_limit_reached = sent - self.last_queue_check_count > Global.CONFIG_MANAGER.messages_dispatched_for_system_check
        queue_limit_reached = queue_length > Global.CONFIG_MANAGER.queue_length_for_system_check
        time_limit_since_last_check_is_over = (now - self.last_queue_check_date).total_seconds() > Global.CONFIG_MANAGER.seconds_between_queue_check

        if not Global.CONFIG_MANAGER.fixed_message_fetcher_interval:
            if (messages_limit_reached) or (queue_limit_reached and time_limit_since_last_check_is_over):
                cause = "messages limit reached" if messages_limit_reached else "queue limit reached"
                Global.LOGGER.debug(f"triggering the throttle function due to {cause}")
                self._adapt_sleep_interval(sent, received, queue_length, now)
292256
def CallLoggedAndAccounted(f):
  """"""

  @functools.wraps(f)
  def Decorator(*args, **kwargs):
    try:
      start_time = time.time()
      result = f(*args, **kwargs)
      latency = time.time() - start_time

      stats_collector_instance.Get().RecordEvent(
          "db_request_latency", latency, fields=[f.__name__])
      logging.debug("DB request %s SUCCESS (%.3fs)", f.__name__, latency)

      return result
    except db.Error as e:
      stats_collector_instance.Get().IncrementCounter(
          "db_request_errors", fields=[f.__name__, "grr"])
      logging.debug("DB request %s GRR ERROR: %s", f.__name__,
                    utils.SmartUnicode(e))
      raise
    except Exception as e:
      stats_collector_instance.Get().IncrementCounter(
          "db_request_errors", fields=[f.__name__, "db"])
      logging.debug("DB request %s INTERNAL DB ERROR : %s", f.__name__,
                    utils.SmartUnicode(e))
      raise

  return Decorator
66739
def trace_memory_usage(self, frame, event, arg):
        """"""
        if (event in ('call', 'line', 'return')
                and frame.f_code in self.code_map):
            if event != 'call':
                # "call" event just saves the lineno but not the memory
                mem = _get_memory(-1, include_children=self.include_children)
                # if there is already a measurement for that line get the max
                old_mem = self.code_map[frame.f_code].get(self.prevline, 0)
                self.code_map[frame.f_code][self.prevline] = max(mem, old_mem)
            self.prevline = frame.f_lineno

        if self._original_trace_function is not None:
            (self._original_trace_function)(frame, event, arg)

        return self.trace_memory_usage
747216
def analyze_reach_log(log_fname=None, log_str=None):
    """"""
    assert bool(log_fname) ^ bool(log_str), 'Must specify log_fname OR log_str'
    started_patt = re.compile('Starting ([\d]+)')
    # TODO: it might be interesting to get the time it took to read
    # each paper here
    finished_patt = re.compile('Finished ([\d]+)')

    def get_content_nums(txt):
        pat = 'Retrieved content for ([\d]+) / ([\d]+) papers to be read'
        res = re.match(pat, txt)
        has_content, total = res.groups() if res else None, None
        return has_content, total

    if log_fname:
        with open(log_fname, 'r') as fh:
            log_str = fh.read()
    # has_content, total = get_content_nums(log_str)  # unused
    pmids = {}
    pmids['started'] = started_patt.findall(log_str)
    pmids['finished'] = finished_patt.findall(log_str)
    pmids['not_done'] = set(pmids['started']) - set(pmids['finished'])
    return pmids
688224
def get_activitylog(self, after=None, severity=None, start=None, end=None):
        
        if after:
            log_raw = self._router.get_instance_activitylog(org_id=self.organizationId,
                                                            instance_id=self.instanceId,
                                                            params={"after": after}).json()
        else:
            log_raw = self._router.get_instance_activitylog(org_id=self.organizationId,
                                                            instance_id=self.instanceId).json()

        return ActivityLog(log_raw, severity=severity, start=start, end=end)
363945
def log_trace(self, tag, original, loc, tokens=None, extra=None):
        """"""
        if self.tracing:
            tag, original, loc = displayable(tag), displayable(original), int(loc)
            if "{" not in tag:
                out = ["[" + tag + "]"]
                add_line_col = True
                if tokens is not None:
                    if isinstance(tokens, Exception):
                        msg = displayable(str(tokens))
                        if "{" in msg:
                            head, middle = msg.split("{", 1)
                            middle, tail = middle.rsplit("}", 1)
                            msg = head + "{...}" + tail
                        out.append(msg)
                        add_line_col = False
                    elif len(tokens) == 1 and isinstance(tokens[0], str):
                        out.append(ascii(tokens[0]))
                    else:
                        out.append(ascii(tokens))
                if add_line_col:
                    out.append("(line:" + str(lineno(loc, original)) + ", col:" + str(col(loc, original)) + ")")
                if extra is not None:
                    out.append("from " + ascii(extra))
                printerr(*out)
1241586
def log(begin_time, running_num_tks, running_mlm_loss, running_nsp_loss, step_num,
        mlm_metric, nsp_metric, trainer, log_interval):
    """"""
    end_time = time.time()
    duration = end_time - begin_time
    throughput = running_num_tks / duration / 1000.0
    running_mlm_loss = running_mlm_loss / log_interval
    running_nsp_loss = running_nsp_loss / log_interval
    lr = trainer.learning_rate if trainer else 0
    # pylint: disable=line-too-long
    logging.info('[step {}]\tmlm_loss={:.5f}\tmlm_acc={:.5f}\tnsp_loss={:.5f}\tnsp_acc={:.3f}\tthroughput={:.1f}K tks/s\tlr={:.7f} time={:.2f}, latency={:.1f} ms/batch'
                 .format(step_num, running_mlm_loss.asscalar(), mlm_metric.get()[1] * 100, running_nsp_loss.asscalar(),
                         nsp_metric.get()[1] * 100, throughput.asscalar(), lr, duration, duration*1000/log_interval))
1086574
def _find_logs(self, compile_workunit):
    """"""
    for idx, workunit in enumerate(compile_workunit.children):
      for output_name, outpath in workunit.output_paths().items():
        if output_name in ('stdout', 'stderr'):
          yield idx, workunit.name, output_name, outpath
1089064
def _finalize_step(self):
        
        t = time.time()
        if self._callback is not None:
            self._callback(self.age)
        t2 = time.time()
        self._step_processing_time += t2 - t
        self._log(logging.INFO, "Step {} run in: {:.3f}s ({:.3f}s of "
                  "actual processing time used)"
                  .format(self.age, self._step_processing_time,
                          t2 - self._step_start_time))
        self._processing_time += self._step_processing_time
770218
def trace(message = nil, ex = nil, data = nil, &block)
      log(TRACE, message, ex, data, block)
    end
615740
public static void logPerIteration(long startTimeMs, int times, String msg, int workerId) {
    long takenTimeMs = System.currentTimeMillis() - startTimeMs;
    double result = 1000.0 * sFileBytes / takenTimeMs / 1024 / 1024;
    LOG.info(times + msg + workerId + " : " + result + " Mb/sec. Took " + takenTimeMs + " ms. ");
  }
1135419
def log_stop(self, start):
        """"""
        if not logger.isEnabledFor(logging.INFO): return

        stop = time.time()
        get_elapsed = lambda start, stop, multiplier, rnd: round(abs(stop - start) * float(multiplier), rnd)
        elapsed = get_elapsed(start, stop, 1000.00, 1)
        total = "%0.1f ms" % (elapsed)
        logger.info("RESPONSE {} {} in {}".format(self.response.code, self.response.status, total))