hadoop-common-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Vasilis Liaskovitis <vlias...@gmail.com>
Subject duplicate START_TIME, FINISH_TIME timestamps in history log
Date Thu, 10 Sep 2009 17:09:36 GMT
Hi,

I am getting different values for START_TIME, FINISH_TIME regarding
the exact same task when looking at the history log of a sorter job.
 E.g greping for a particular reduce task in the history log:

masternode:/home/hadoop-git # grep -r
"task_200909031613_0002_r_000002"
/home/vliaskov/hadoop-git/logs/history/doomhead.amd.com_1252012387435_job_200909031613_0002_root_sorter

Task TASKID="task_200909031613_0002_r_000002" TASK_TYPE="REDUCE"
START_TIME="1252014285633" SPLITS="" .
ReduceAttempt TASK_TYPE="REDUCE"
TASKID="task_200909031613_0002_r_000002"
TASK_ATTEMPT_ID="attempt_200909031613_0002_r_000002_0"
START_TIME="1252012959359"
TRACKER_NAME="tracker_compute-5\.doomcluster\.amd\.com:localhost/127\.0\.0\.1:37388"
HTTP_PORT="50060" .
ReduceAttempt TASK_TYPE="REDUCE"
TASKID="task_200909031613_0002_r_000002"
TASK_ATTEMPT_ID="attempt_200909031613_0002_r_000002_0"
TASK_STATUS="SUCCESS" SHUFFLE_FINISHED="1252014856244"
SORT_FINISHED="1252014856723" FINISH_TIME="1252015219858"
Task TASKID="task_200909031613_0002_r_000002" TASK_TYPE="REDUCE"
TASK_STATUS="SUCCESS" FINISH_TIME="1252016563501" ...

>From the above you can see that e.g. START_TIME is reported twice and
is different.
START_TIME= 1252014285633
START_TIME= 1252012959359

Same goes for FINISH_TIME and possibly other timestamped events. Does
the history log gather messages from several tasktrackers and from the
jobtracker regarding one particular task? That might explain the log.

Could this be a problem because the cluster nodes are not synchronized
to a master node using e.g. NTP?
On that note, do people use ntpd and ntpq/ntpc to synchronize their
slave/tasktracker nodes' clocks to their master/jobtracker node clock?

thanks for any help,

- Vasilis

Mime
View raw message