在 JRuby 分析中花费大量时间在 Thread#initialize 和 Thread#join 中意味着啥？

Posted 2023-03-06

【中文标题】在 JRuby 分析中花费大量时间在 Thread#initialize 和 Thread#join 中意味着啥？

【英文标题】：What do large times spent in Thread#initialize and Thread#join mean in JRuby profiling?在 JRuby 分析中花费大量时间在 Thread#initialize 和 Thread#join 中意味着什么？

【发布时间】：2013-02-16 04:07:54

【问题描述】：

我正在尝试使用 JRuby 的内置分析器来分析应用程序。

大部分时间花在ClassIsOfInterest.method_that_is_of_interest，而大部分时间花在Thread#initialize和Thread#join

     total        self    children       calls  method
----------------------------------------------------------------
     31.36        0.02       31.35        4525  Array#each
     31.06        0.00       31.06           2  Test::Unit::RunCount.run_once
     31.06        0.00       31.06           1  Test::Unit::RunCount.run
     31.06        0.00       31.06           1  MiniTest::Unit#run
     31.06        0.00       31.05           1  MiniTest::Unit#_run
     31.01        0.00       31.01        2219  Kernel.send
     31.00        0.00       31.00           1  MiniTest::Unit#run_tests
     31.00        0.00       31.00           1  MiniTest::Unit#_run_anything
     30.99        0.00       30.99           1  Test::Unit::Runner#_run_suites
     30.99        0.00       30.99           5  MiniTest::Unit#_run_suite
     30.99        0.00       30.98       21629  Array#map
     30.98        0.00       30.98           1  Test::Unit::TestCase#run
     30.98        0.00       30.98           1  MiniTest::Unit::TestCase#run
     30.98        0.00       30.98         659  BasicObject#__send__
     30.98        0.00       30.98           1  MyTestClass#my_test_method
     30.80        0.00       30.80          18  Enumerable.each_with_index
     30.77        0.00       30.77          15  MyTestHelper.generate_call_parser_based_on_barcoded_sequence
     30.26        0.00       30.25        4943  Class#new_proxy
     26.13        0.00       26.13          15  MyProductionClass1#my_production_method1

<snip boring methods with zero self time>

     24.27        0.00       24.27          15  ClassIsOfInterest.method_that_is_of_interest
     13.71        0.01       13.71         541  Enumerable.map
     13.48        0.86       12.63          30  Range#each
     12.62        0.22       12.41         450  Thread.new
     12.41       12.41        0.00         450  Thread#initialize
     10.78       10.78        0.00         450  Thread#join
      4.03        0.12        3.91         539  Kernel.require
      3.34        0.00        3.34         248  Kernel.require
      2.49        0.00        2.49          15  MyTestFixture.create_fixture

<snip boring methods with small total times>

ClassIsOfInterest.method_that_is_of_interest 的每次调用都会创建 30 个线程，这可能有点过头了，但我认为它不会降低性能。当我每次调用只创建三个线程时，我得到了

 23.16        0.00       23.15          15  ClassIsOfInterest.method_that_is_of_interest
 22.73       22.73        0.00          45  Thread#join
  4.18        0.08        4.10         539  Kernel.require
  3.56        0.00        3.56         248  Kernel.require
  2.78        0.00        2.78          15  MyTestFixture.create_fixture

Thread#initialize（在第一个配置文件中）和Thread#join 的大时间值是否表明负责线程化的代码需要一段时间，或者仅仅是线程内执行的代码需要一段时间？

【参考方案1】：

您看到Thread#join 的原因是您的主线程正在花费大量时间等待其他线程完成。在method_that_is_of_interest 上花费的大部分时间都花在阻止Thread#join 上，因为它没有做任何其他工作。我不会太担心——配置文件只是说你的一个线程阻塞了其他线程正在做的事情。在这种情况下，更好的性能测量是总运行时间，使用不同数量的线程运行代码并查看最佳点在哪里。

Thread.new/Thread#initialize 出现的原因是线程是昂贵的创建对象。如果您经常调用此方法并且每次都会创建所有这些线程，我建议您查看 Java 的 Executors API。使用Executors 创建一个线程池一次（当您的应用程序启动时）并将所有任务提交到池中而不是创建新线程（您可以使用ExecutorCompletionService 等待所有任务完成，或者只调用#get在您提交任务时获得的FutureTask 实例上）。