[MAPREDUCE-7272] TaskAttemptListenerImpl excessive log messages

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 3.3.0, 3.1.4, 3.2.2, 2.10.1, 3.4.0
• Fix Version/s: 2.8.6, 3.3.0, 2.9.3, 3.1.4, 3.2.2, 2.10.1, 3.4.0
• Component/s: test
• Target Version/s: 3.3.0, 3.1.4, 3.2.2, 2.10.1, 3.4.0
• Hadoop Flags: Reviewed
• Assignee: Ahmed Hussein
• Reporter: Ahmed Hussein
• Created: 09/Apr/20 15:15
• Updated: 11/Feb/24 11:05
• Resolved: 13/Apr/20 20:08

Description

TaskAttemptListenerImpl.statusUpdate() causes a bloating in log files. One every call, the listener uses LOG.info() to printout the progress of the TaskAttempt.

taskAttemptStatus.progress = taskStatus.getProgress();
    LOG.info("Progress of TaskAttempt " + taskAttemptID + " is : "
        + taskStatus.getProgress());

 

2020-04-07 10:20:50,708 INFO [IPC Server handler 17 on 43926] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1586003420099_716645_m_007783_0 is : 0.40713295
2020-04-07 10:20:50,717 INFO [IPC Server handler 7 on 43926] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1586003420099_716645_m_020681_0 is : 0.55573714
2020-04-07 10:20:50,717 INFO [IPC Server handler 26 on 43926] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1586003420099_716645_m_024371_0 is : 0.54190344
2020-04-07 10:20:50,738 INFO [IPC Server handler 15 on 43926] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1586003420099_716645_m_033182_0 is : 0.50264555
2020-04-07 10:20:50,748 INFO [IPC Server handler 3 on 43926] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1586003420099_716645_m_022375_0 is : 0.5495565

After discussing this issue with nroberts, ebadger, and epayne, we thought that while it is helpful to have a log print of task progress, it is still excessive to log the progress in every update.
This Jira is to suppress the excessive logging from TaskAttemptListener without affecting the frequency of progress updates. 
There are two flags:

• -Dmapreduce.task.log.progress.delta.threshold=0.10: means that the task progress will be logged every 10% of delta progress. Default is 5%.
• -Dmapreduce.task.log.progress.wait.interval-seconds=120: means that if the listener will log the progress every 2 minutes. This is helpful for long running tasks that take long time to achieve the delta threshold. Default is 1 minute.

The listener will long whichever of delta.threshold and wait.interval-seconds is reached first.
  Enabling LOG.DEBUG for  TaskAttemptListenerImpl will override those two flags and log the task progress on every update.