[SPARK-36070][CORE] Log time cost info for writing rows out and committing the task

[yaooqinn]

What changes were proposed in this pull request?

We have a job that has a stage that contains about 8k tasks. Most tasks take about 1~10min to finish but 3 of them tasks run extremely slow with similar data sizes. They take about 1 hour each to finish and also do their speculations.

The root cause is most likely the delay of the storage system. But it's not straightforward enough to find where the performance issue occurs, in the phase of shuffle read, task execution, output, commitment e.t.c..

2021-07-09 03:05:17 CST SparkHadoopMapRedUtil INFO - attempt_20210709022249_0003_m_007050_37351: Committed
2021-07-09 03:05:17 CST Executor INFO - Finished task 7050.0 in stage 3.0 (TID 37351). 3311 bytes result sent to driver
2021-07-09 04:06:10 CST ShuffleBlockFetcherIterator INFO - Getting 9 non-empty blocks including 0 local blocks and 9 remote blocks
2021-07-09 04:06:10 CST TransportClientFactory INFO - Found inactive connection to

Why are the changes needed?

On the spark side, we can record the time cost in logs for better bug hunting or performance tuning.

Does this PR introduce any user-facing change?

no

How was this patch tested?

passing GA

[yaooqinn]

cc @cloud-fan @maropu @dongjoon-hyun, thanks

[SparkQA]

Kubernetes integration test starting
URL: https://amplab.cs.berkeley.edu/jenkins/job/SparkPullRequestBuilder-K8s/45355/

[SparkQA]

Kubernetes integration test unable to build dist.

exiting with code: 1
URL: https://amplab.cs.berkeley.edu/jenkins/job/SparkPullRequestBuilder-K8s/45358/

[SparkQA]

Kubernetes integration test status success
URL: https://amplab.cs.berkeley.edu/jenkins/job/SparkPullRequestBuilder-K8s/45355/

[SparkQA]

Test build #140844 has finished for PR 33279 at commit 7950524.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[SparkQA]

Test build #140847 has finished for PR 33279 at commit fb3af2a.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[yaooqinn]

thanks, merged to master

[cloud-fan]

After some more thought, I think it's better to use SQL metrics for it. It's very hard to know max/min/avg by reading the logs.

@AngersZhuuuu I think you tried it before. Can you restore the work?

[AngersZhuuuu]

After some more thought, I think it's better to use SQL metrics for it. It's very hard to know max/min/avg by reading the logs.

@AngersZhuuuu I think you tried it before. Can you restore the work?

Yea, working on this