如何准确计算一段 Javascript 代码的执行时间? console.time/timeEnd 和 console.log(new Date().getTime())计算出来的时间正确吗? Performance 对象读取出来的时间呢? - V2EX
V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
tmxklzp
V2EX 问与答

如何准确计算一段 Javascript 代码的执行时间? console.time/timeEnd 和 console.log(new Date().getTime())计算出来的时间正确吗? Performance 对象读取出来的时间呢?

  •  
  •   tmxklzp 2018-08-07 20:58:38 +08:00 3940 次点击
    这是一个创建于 2631 天前的主题,其中的信息可能已经有所发展或是发生改变。

    我想获取浏览器(Chrome)环境下一整段 Javascript 代码中每一小段代码精确的执行时间,使用了三种计算方式:

    1.console.time、console.timeEnd 配合使用 2.console.log(new Date().getTime()) 3.console.log(performance.now()) 

    但是这两种方式计算出来的时间都和我“观察感觉到的时间”有所差异,实际使用断点进行 debug 时也有同样的感觉。

    debug 时感觉每小段代码的耗时和感觉一致:代码循环和递归多的地方耗时长,一两行的地方耗时短,使用上述三种计算方式时会出现:本应该耗时长的代码段算出来的时间短、本应该耗时很短的地方显示的时间很长的情况,甚至出现了两个连在一起的 console 计算出来的时间差了 500ms,例如:

    // 前面的代码,省略 ...... // 中间某段代码 console.log("calcBefore", performance.now()) // 一个有很多循环和递归计算的代码 calculate() console.log("calcAfter1", performance.now()) console.log("calcAfter2", performance.now()) console.log("calcAfter3", performance.now()) console.log("calcAfter4", performance.now()) // 后面的代码,省略 ...... // 打印结果 calcBefore 573.499999998603 calcAfter1 633.2000000038533 calcAfter2 1221.1999999999534 calcAfter3 1222.6000000009662 calcAfter4 1223.5000000000582 

    搜了一下,没有发现很多相关资料,只有知乎的一篇文章:https://zhuanlan.zhihu.com/p/28978126 描述了类似的事情。

    恳请前端大佬解惑!!!

    第 1 条附言    2018-08-08 09:59:16 +08:00

    更正:“这两种方式”应该为“这三种方式”,之前写的时候没有使用Performance API,但是结果是同样的不准确。

    这个问题可以稳定复现,今天早上重启项目之后依然在这里有同样的时间消耗,如下图:

    console.log("calcBefore", performance.now()) calculate() console.log("calcAfter1", performance.now()) console.log("calcAfter2", performance.now()) // console calcBefore 1134.9999999947613 calcAfter1 1214.80000000156 calcAfter2 1878.7000000011176 console.log("calcBefore", performance.now()) //calculate() console.log("calcAfter1", performance.now()) console.log("calcAfter2", performance.now()) // console calcBefore 669.3999999988591 calcAfter1 671.6000000014901 calcAfter2 672.5000000005821 
    6 条回复    2018-08-08 14:36:55 +08:00
    noe132
        1
    noe132  
       2018-08-07 21:35:16 +08:00
    有一种可能,v8 会对比较热门(popular)的代码做优化编译(Crankshaft),会将用的多的 JS 代码块进行优化,编译出效率更高的二进制代码执行。这是一个 runtime 执行的功能,有可能会影响接下来一部分代码的执行性能。
    http://jayconrod.com/posts/54/a-tour-of-v8--crankshaft--the-optimizing-compiler

    建议做性能基准测试时,先让代码多跑几个循环,让代码被优化后,再进行基准测试,以减小误差,jsPref 用的 benchmark.js 是这样做的。
    https://stackoverflow.com/questions/4986245/how-does-jsperf-work
    noe132
        2
    noe132  
       2018-08-07 21:37:37 +08:00
    gc 也有可能影响下一步操作的时间,因为 gc 也是需要暂停 js 的主线程的,尤其是在做全量 gc 的时候。能影响的因素还是比较多。
    xiaody
        3
    xiaody  
       2018-08-07 21:38:13 +08:00
    能稳定复现吗?代码内存使用情况怎么样,会不会是遇到 GC 了?
    tmxklzp
        4
    tmxklzp  
    OP
       2018-08-08 10:09:19 +08:00
    @noe132 谢谢科普!对 v8 引擎和 GC 这方面的知识我了解得不够深入,后续会去深入研究。另外能否对上述这一个问题提出一下的想法:两个连在一起的 console 即 calcAfter1 和 calcAfter2,为何稳定出现相差 500~600ms 的情况?如果是 GC 的话每次到这一步都会进行吗?
    @xiaody 我对于何时会出现 GC 不太清楚,已知的就是 calculate() 这一行内部会有一个大循环和很多次递归,去掉这一行之后 console 时间正常,有可能会是因为在这里计算时占用了大量内存,然后在 calcAfter1 时显示正确的 calculate()调用时间,却在下一行 calcAfter2 时进行了 GC,导致了 600ms 左右的性能损耗吗?
    tmxklzp
        5
    tmxklzp  
    OP
       2018-08-08 10:17:09 +08:00
    另外就是 debug 的话,会明显感觉到这个 600ms 的时间消耗是在 calculate()这一行产生的,后面的 console 并不会有 debug 时的卡顿感。这也是我在问题描述里表达的“ console 计算出来的时间和我打断点&感觉出来的时间不一致”
    tmxklzp
        6
    tmxklzp  
    OP
       2018-08-08 14:36:55 +08:00
    问 jjc 大佬得到的回复:“凡是带有 gc 和 jit 的 runtime,统计都会不准确”
    关于     帮助文档     自助推广系统     博客     API     FAQ     Solana     929 人在线   最高记录 6679       Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 24ms UTC 21:25 PVG 05:25 LAX 14:25 JFK 17:25
    Do have faith in what you're doing.
    ubao msn snddm index pchome yahoo rakuten mypaper meadowduck bidyahoo youbao zxmzxm asda bnvcg cvbfg dfscv mmhjk xxddc yybgb zznbn ccubao uaitu acv GXCV ET GDG YH FG BCVB FJFH CBRE CBC GDG ET54 WRWR RWER WREW WRWER RWER SDG EW SF DSFSF fbbs ubao fhd dfg ewr dg df ewwr ewwr et ruyut utut dfg fgd gdfgt etg dfgt dfgd ert4 gd fgg wr 235 wer3 we vsdf sdf gdf ert xcv sdf rwer hfd dfg cvb rwf afb dfh jgh bmn lgh rty gfds cxv xcv xcs vdas fdf fgd cv sdf tert sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf sdf shasha9178 shasha9178 shasha9178 shasha9178 shasha9178 liflif2 liflif2 liflif2 liflif2 liflif2 liblib3 liblib3 liblib3 liblib3 liblib3 zhazha444 zhazha444 zhazha444 zhazha444 zhazha444 dende5 dende denden denden2 denden21 fenfen9 fenf619 fen619 fenfe9 fe619 sdf sdf sdf sdf sdf zhazh90 zhazh0 zhaa50 zha90 zh590 zho zhoz zhozh zhozho zhozho2 lislis lls95 lili95 lils5 liss9 sdf0ty987 sdft876 sdft9876 sdf09876 sd0t9876 sdf0ty98 sdf0976 sdf0ty986 sdf0ty96 sdf0t76 sdf0876 df0ty98 sf0t876 sd0ty76 sdy76 sdf76 sdf0t76 sdf0ty9 sdf0ty98 sdf0ty987 sdf0ty98 sdf6676 sdf876 sd876 sd876 sdf6 sdf6 sdf9876 sdf0t sdf06 sdf0ty9776 sdf0ty9776 sdf0ty76 sdf8876 sdf0t sd6 sdf06 s688876 sd688 sdf86