[BUG] Investigate long execution time of eventlogs

[amahussein]

Describe the bug

After we addressed memory configuration in #1382, we need to narrow down to find where does the core-tool spend most of the time analyzing the eventlogs

Analysis result for an eventlog that takes up to 28 minutes:

jvm Args:

-Xms32G -Xmx64G -XX:+UseG1GC

total CPU: 1,695,427ms
total time: 11,919,747 ms
total allocation: 6.14 TB

Methods with highest resource utilizations ProfileMain_2024_12_13_162335.zip:

• getAggRawMetrics: 1,396,931 ms | 82% of all | 5.78 TB (94 % of all)
  • aggregateSparkMetricsByJob: 498,101 ms (29% parent, 36% total) | 2.06 TB (36 parent, 34% all).
  • aggregateSparkMetricsBySql: 448,030 ms (32% of parent, 27% of all) | 1.86 TB (32% parent, 30%).
    • It seems we call the method twice by mistake. We should fix that to get 27% CPU time back. So, in total this method takes 898,580 ms -> 53% of all | 1.86 TB (32% parent, 30%)
    • in addition, just one line inside the function takes 492,010 ms (29% of all).

      val cachedResBySQL = stageLevelSparkMetrics(index).filterKeys(stagesInSQL.contains).value
      

Tasks

Preview Give feedback

1. Deduplicate calls to aggregateSparkMetricsBySql #1464
   bug core_tools +2
   
2. Optimize implementation of getAggregateRawMetrics in core-tools #1468
   core_tools +1
   
3. Improve implementation of finding median in StatisticsMetrics #1474
   core_tools +1
   

[cindyyuanjiang]

Thanks @amahussein for investigating into this!

QQ: aggregateSparkMetricsBySql takes 448,030 ms and line
val cachedResBySQL = stageLevelSparkMetrics(index).filterKeys(stagesInSQL.contains).value
in this function takes 492,010 ms, which takes more time than the function call?

[amahussein]

Thanks @amahussein for investigating into this!

QQ: aggregateSparkMetricsBySql takes 448,030 ms and line val cachedResBySQL = stageLevelSparkMetrics(index).filterKeys(stagesInSQL.contains).value in this function takes 492,010 ms, which takes more time than the function call?

Good question!
It is due to that this is the total cost of that line because we were calling the method twice.
It implies that this line 50% of the cost of the method.