JavaScript中 Console.log 函数到底有多慢

Posted by Yinode on Sunday, July 12, 2020

TOC

最近在写JS的时候碰到一个很奇怪的现象,起初是碰到一个树遍历的问题,我封装了一个迭代器用于遍历,并希望能够实际的统计一下性能,使用了console.timeconsole.timeEnd 这组方法,希望分析一下算法的各个部分实际的执行时间。

// 调用
let highestResponser = findHighestResponser(rootVue)
// 实际方法体
const findHighestResponser = root => {
  console.time('PT1')
  const containFilter = item => document.contains(item.$el)
  const responserFilter = item => typeof item[responseName] === 'function'
  const iterator = new VueExtensions.ComponentIterator(
    root,
    containFilter,
    responserFilter
  )
  console.timeEnd('PT1')

  console.time('PT2')
  let responserList = []

  // eslint-disable-next-line no-unused-vars
  let cur
  // eslint-disable-next-line no-cond-assign
  while ((cur = iterator.next())) {
    responserList.push(cur.element)
  }

  // 按照树中的深度进行排序 深度越深优先级越高 可以在data里面实现该属性从而改变响应优先级
  responserList.sort((a, b) => {
    let ah = a.info.h + (a._heightOffset || 0)
    let bh = b.info.h + (b._heightOffset || 0)
    return ah - bh
  })

  console.timeEnd('PT2')
  return responserList[responserList.length - 1]
}

在这里我把函数拆分成两个部分,那么正常来说, t(PT1) + t(PT2) = t(Total) 对吧,很显然函数内部只有两个主要部分,那么外部调用时间就应该大概等于里面两个部分消耗时间之和。

但是实际的执行结果可能会让你大跌眼镜

PT1: 0.675048828125ms
PT2: 0.011962890625ms
total: 1.007568359375ms

可以看到最终时间很奇怪的多了大概0.3ms,那么问题来了,这个时间到底干嘛了,我本来猜测可能是我不小心造成一次内存GC?

经过仔细的测试之后,我发现问题出现在console.time/end 函数上,一旦我删除这个计时函数,就能基本符合上面的等式。

我们再创建一个测试例子

  function hasConsole() {
    let res = 1
    console.log("1");
    return res
  }

  function noneConsole() {
    let res = 1
    return res
  }

  function b() {
    console.time('has console')
    let res1 = hasConsole()
    console.timeEnd('has console')

    console.time('none console')
    let res2 = noneConsole()
    console.timeEnd('none console')
  }

  b()
has console: 0.7080078125ms
none console: 0.030029296875ms

看来不仅仅是console.timeEnd的问题,所有的打印都有类似的问题,他们的成本高的几乎让人不可置信,比不使用的情况下慢了整整 23 倍.

接下来我尝试关闭开发者工具

has console: 0.07421875ms
none console: 0.01904296875ms

依然有大概7倍的差距。

所以我们的问题原因非常明显了,本质是因为console.timeEnd打印消耗的时间过多,并且其本身不计入PT1 和 PT2 内,造成了一定的偏差。

总结

Console系列控制台输出函数的执行成本非常高,一定要避免在生产环境中过于频繁的调用。 在使用Console.timeEnd函数进行性能分析的时候,要注意其本身消耗的时间,可以考虑劫持原本的函数,延迟最终性能成绩的输出,避免测试情况不符合实际情况,或者使用Chrome Dev tools 提供的 Performance 面板。