为啥从另一个调用的函数不会显示在节点应用程序的配置文件输出中？

Posted 2023-03-06

【中文标题】为啥从另一个调用的函数不会显示在节点应用程序的配置文件输出中？

【英文标题】：Why would a function called from another not show in the profile output of a node app?为什么从另一个调用的函数不会显示在节点应用程序的配置文件输出中？

【发布时间】：2021-08-12 13:34:48

【问题描述】：

我有一个 NodeJS 程序。这是一个更大程序的精简版本，具有很多复杂性，与这个问题无关。它通过列表寻找匹配的对象：

/**
 * Checks that the given attributes are defined in the given dictionaries
 * and have the same value
 */
function areDefinedAndEqual(a, b, keys) 
  return (
    a &&
    b &&
    keys
      .map(function (k) 
        return a[k] && b[k] && a[k] === b[k]
      )
      .reduce(function (a, b) 
        return a && b
      , true)
  )


function calculateOrder() 
  const matchingRules = [
    
      desc: 'stuff, more stuff and different stuff',
      find: (po, dp) => areDefinedAndEqual(po, dp, ['stuff', 'more_stuff', 'different_stuff'])
    ,
    
      desc: 'stuff and different stuff',
      find: (po, dp) => areDefinedAndEqual(po, dp, ['stuff', 'different_stuff'])
    ,
    
      desc: 'just stuff',
      find: (po, dp) => areDefinedAndEqual(po, dp, ['stuff'])
    
  ]
  let listOfStuff = []
  listOfStuff[999] =  stuff: 'Hello' 
  listOfStuff[9999] =  stuff: 'World' 
  listOfStuff[99999] =  stuff: 'Hello World' 
  // Run through lots of objects running through different rules to
  // find things that look similar to what we're searching for
  for (let i = 0; i < 100000000; i++) 
    for (let j = 0; j < matchingRules.length; j++) 
      if (matchingRules[j].find( stuff: 'Hello World' , listOfStuff[i])) 
        console.log(`Found match at position $i on $matchingRules[j].desc`)
      
    
  


calculateOrder()

现在，calculateOrder 所做的只是重复调用 matchRules 下列出的函数，然后再调用 areDefinedAndEqual 进行一些实际检查。

现在，如果我按如下方式运行：

richard@sophia:~/cc/sheetbuilder (main) $ node --prof fred.js 
Found match at position 99999 on just stuff
richard@sophia:~/cc/sheetbuilder (main) $ 

我得到了我所期望的。到现在为止还挺好。 然后我可以通过 prof-process 运行配置文件输出以获得更具可读性的内容。

node --prof-process isolate-0x57087f0-56563-v8.log

但是，如果我查看输出，我会看到：

 [javascript]:
   ticks  total  nonlib   name
   4197   46.0%   89.0%  LazyCompile: *calculateOrder /home/richard/cogcred/eng-data_pipeline_misc/sheetbuilder/fred.js:19:24

所有的时间都花在了calculateOrder上。我希望看到大部分时间花在各种“查找”函数和 areDefinedAndEqual 中，但我没有。根本没有提到它们中的任何一个。为什么？它们是否可能以某种方式被优化/内联？如果是这样，我该如何开始调试呢？还是对某些未在输出中显示的功能有一些限制？在这种情况下，这些限制在哪里定义？任何指针将不胜感激。

我正在运行 Node v16.5.0

【参考方案1】：

在为它们收集蜱样本后，函数会显示在配置文件中。由于基于样本的分析是一项统计事务，因此可能会发生一个运行时间很短的函数没有被采样的情况。

在目前的情况下，内联是更可能的答案。使用--trace-turbo-inlining 运行节点会吐出一堆关于内联决策的信息。

如果我运行您发布的示例，我看到areDefinedEqual 被内联到find，因此find（和calculateOrder）在配置文件中的位置很高。仔细观察，在我分析的特定运行中，areDefinedEqual 被单个分析器标记捕获 - 在它被内联之前。

【讨论】：

这就是答案，它很好地为我指出了另一个选项 --no-turbo-inlining 如果我使用它，我得到的东西更接近我的预期并且更容易排除故障。谢谢。

当然，禁用内联通常也会改变性能特征，所以要小心不要误导你:-)