[BUG] Profiler output shows inconsistent shuffleWriteTime results

[cindyyuanjiang]

Describe the bug
Profiler output shows inconsistent shuffle write write time results in profiler.log.

Under Stage Level All Metrics, the total is 93 ms.

+--------+-------+-------------+---------------------------------------------------+---------+---------+---------+----------+
|appIndex|stageId|accumulatorId|name                                               |min      |median   |max      |total     |
+--------+-------+-------------+---------------------------------------------------+---------+---------+---------+----------+
|1       |2      |201          |internal.metrics.shuffle.write.writeTime           |139875   |230038   |9747416  |93193331  |

Under Stage level aggregated task metrics, the total is 42ms.

+--------+-------+--------+--------+--------------------+------------+------------+------------+------------+-------------------+------------------------------+---------------------------+-------------------+-------------------+---------------------+-------------+----------------------+-----------------------+-------------------------+-----------------------+---------------------------+--------------+--------------------+-------------------------+---------------------+--------------------------+----------------------+----------------------------+---------------------+-------------------+---------------------+----------------+
|appIndex|stageId|numTasks|Duration|diskBytesSpilled_sum|duration_sum|duration_max|duration_min|duration_avg|executorCPUTime_sum|executorDeserializeCPUTime_sum|executorDeserializeTime_sum|executorRunTime_sum|input_bytesRead_sum|input_recordsRead_sum|jvmGCTime_sum|memoryBytesSpilled_sum|output_bytesWritten_sum|output_recordsWritten_sum|peakExecutionMemory_max|resultSerializationTime_sum|resultSize_max|sr_fetchWaitTime_sum|sr_localBlocksFetched_sum|sr_localBytesRead_sum|sr_remoteBlocksFetched_sum|sr_remoteBytesRead_sum|sr_remoteBytesReadToDisk_sum|sr_totalBytesRead_sum|sw_bytesWritten_sum|sw_recordsWritten_sum|sw_writeTime_sum|
+--------+-------+--------+--------+--------------------+------------+------------+------------+------------+-------------------+------------------------------+---------------------------+-------------------+-------------------+---------------------+-------------+----------------------+-----------------------+-------------------------+-----------------------+---------------------------+--------------+--------------------+-------------------------+---------------------+--------------------------+----------------------+----------------------------+---------------------+-------------------+---------------------+----------------+
|1       |2      |200     |688     |0                   |7705        |237         |10          |38.5        |1556               |940                           |1474                       |5337               |0                  |0                    |0            |0                     |0                      |0                        |0                      |0                          |7359          |0                   |2400                     |80264508             |0                         |0                     |0                           |80264508             |15400              |200                  |42              |

We suspect this is due to precision lost from converting nanoseconds to milliseconds. For Stage Level All Metrics, the results are in nanoseconds, and for Stage level aggregated task metrics, the results are in milliseconds. Most tasks in this stage has < 1,000,000 nanoseconds = 1 ms shuffle write time, which will rounds to 0 ms.

Steps/Code to reproduce bug
spark_rapids profiling -v -e <my_tools_repo>/core/src/test/resources/spark-events-profiling/rapids_join_eventlog.zstd

[cindyyuanjiang]

Found conversion from nanoseconds to ms in TaskModel construction:

spark-rapids-tools/core/src/main/scala/org/apache/spark/sql/rapids/tool/store/TaskModel.scala

Line 112 in 019ede2

TimeUnit.NANOSECONDS.toMillis(event.taskMetrics.shuffleWriteMetrics.writeTime),