[HDFS-9521] TransferFsImage.receiveFile should account and log separate times for image download and fsync to disk

• Type: Improvement
• Status: Resolved
• Priority: Minor
• Resolution: Fixed
• Fix Version/s: 2.9.0, 3.0.0-alpha1
• Hadoop Flags: Reviewed
• Assignee: Wellington Chevreuil
• Reporter: Wellington Chevreuil
• Created: 08/Dec/15 17:30
• Updated: 30/Aug/16 01:22
• Resolved: 07/Mar/16 11:54

Description

Currently, TransferFsImage.receiveFile is logging total transfer time as below:

double xferSec = Math.max(
       ((float)(Time.monotonicNow() - startTime)) / 1000.0, 0.001);    
long xferKb = received / 1024;
LOG.info(String.format("Transfer took %.2fs at %.2f KB/s",xferSec, xferKb / xferSec))

This is really useful, but it just measures the total method execution time, which includes time taken to download the image and do an fsync to all the namenode metadata directories.

Sometime when troubleshooting these imager transfer problems, it's interesting to know which part of the process is being the bottleneck (whether network or disk write).

This patch accounts time for image download and fsync to each disk separately, logging how much time did it take on each operation.