[
https://issues.apache.org/jira/browse/MAPREDUCE-5064?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13601015#comment-13601015
]
Steve Loughran commented on MAPREDUCE-5064:
-------------------------------------------
network messages not relevant; they don't surface on all runs. Rumen appears to
not be parsing the logs as expected -replicably.
{code}
2013-03-13 10:35:30,863 INFO mapred.UserLogCleaner
(UserLogCleaner.java:markJobLogsForDeletion(199)) - Adding
job_20130313103515487_0001 for user-log deletion with
retainTimeStamp:1363257330862
JOB_SUBMITTED
JOB_PRIORITY_CHANGED
JOB_STATUS_CHANGED
JOB_INITED
JOB_INFO_CHANGED
TASK_STARTED
SETUP_ATTEMPT_STARTED
SETUP_ATTEMPT_FINISHED
MAP_ATTEMPT_FINISHED
TASK_UPDATED
TASK_FINISHED
JOB_STATUS_CHANGED
TASK_STARTED
MAP_ATTEMPT_STARTED
MAP_ATTEMPT_FINISHED
MAP_ATTEMPT_FINISHED
TASK_UPDATED
TASK_FINISHED
TASK_STARTED
REDUCE_ATTEMPT_STARTED
REDUCE_ATTEMPT_FINISHED
REDUCE_ATTEMPT_FINISHED
TASK_UPDATED
TASK_FINISHED
TASK_STARTED
CLEANUP_ATTEMPT_STARTED
CLEANUP_ATTEMPT_FINISHED
MAP_ATTEMPT_FINISHED
TASK_UPDATED
TASK_FINISHED
JOB_STATUS_CHANGED
JOB_FINISHED
2013-03-13 10:35:33,138 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedJobAPI(236)) - Validating
ParsedJob.obtainXXX api... for job_20130313103515487_0001
2013-03-13 10:35:33,138 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAPI(290)) - Validating
ParsedTask.obtainXXX api... for task_20130313103515487_0001_m_000000
2013-03-13 10:35:33,138 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAttemptAPI(323)) - Validating
ParsedTaskAttempt.obtainXXX api... for attempt_20130313103515487_0001_m_000000_0
2013-03-13 10:35:33,138 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAPI(290)) - Validating
ParsedTask.obtainXXX api... for task_20130313103515487_0001_r_000000
2013-03-13 10:35:33,139 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAttemptAPI(323)) - Validating
ParsedTaskAttempt.obtainXXX api... for attempt_20130313103515487_0001_r_000000_0
2013-03-13 10:35:33,139 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAPI(290)) - Validating
ParsedTask.obtainXXX api... for task_20130313103515487_0001_m_000002
2013-03-13 10:35:33,139 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAttemptAPI(323)) - Validating
ParsedTaskAttempt.obtainXXX api... for attempt_20130313103515487_0001_m_000002_0
2013-03-13 10:35:33,139 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAPI(290)) - Validating
ParsedTask.obtainXXX api... for task_20130313103515487_0001_m_000001
2013-03-13 10:35:33,139 INFO rumen.TestRumenJobTraces
(TestRumenJobTraces.java:validateParsedTaskAttemptAPI(323)) - Validating
ParsedTaskAttempt.obtainXXX api... for attempt_20130313103515487_0001_m_000001_0
2013-03-13 10:35:33,141 INFO mapred.TaskTracker (TaskTracker.java:run(1080)) -
Shutting down: Map-events fetcher for all reduce tasks on
tracker_host0.foo.com:localhost/127.0.0.1:57815
2013-03-13 10:35:33,141 INFO ipc.Server (Server.java:stop(1594)) - Stopping
server on 57815
2013-03-13 10:35:33,142 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 0 on 57815: exiting
2013-03-13 10:35:33,142 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 1 on 57815: exiting
2013-03-13 10:35:33,142 INFO metrics.RpcInstrumentation
(RpcInstrumentation.java:shutdown(154)) - shut down
2013-03-13 10:35:33,142 INFO ipc.Server (Server.java:run(467)) - Stopping IPC
Server listener on 57815
2013-03-13 10:35:33,142 INFO mapred.TaskTracker
(TaskTracker.java:shutdown(1438)) - Shutting down StatusHttpServer
2013-03-13 10:35:33,142 INFO ipc.Server (Server.java:run(664)) - Stopping IPC
Server Responder
2013-03-13 10:35:33,142 INFO filecache.TrackerDistributedCacheManager
(TrackerDistributedCacheManager.java:run(1025)) - Cleanup...
java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method)
at
org.apache.hadoop.filecache.TrackerDistributedCacheManager$CleanupThread.run(TrackerDistributedCacheManager.java:1020)
2013-03-13 10:35:33,143 INFO mortbay.log (Slf4jLog.java:info(67)) - Stopped
[email protected]:0
2013-03-13 10:35:33,247 INFO mapred.TaskTracker
(TaskTracker.java:offerService(1905)) - Interrupted. Closing down.
2013-03-13 10:35:33,248 INFO mapred.JobTracker (JobTracker.java:close(2188)) -
Stopping infoServer
2013-03-13 10:35:33,249 INFO mortbay.log (Slf4jLog.java:info(67)) - Stopped
SelectChannelConnector@localhost:0
2013-03-13 10:35:33,351 INFO mapred.JobTracker (JobTracker.java:close(2196)) -
Stopping interTrackerServer
2013-03-13 10:35:33,351 INFO ipc.Server (Server.java:stop(1594)) - Stopping
server on 57813
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 0 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 3 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 7 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 1 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(467)) - Stopping IPC
Server listener on 57813
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 4 on 57813: exiting
2013-03-13 10:35:33,352 INFO metrics.RpcInstrumentation
(RpcInstrumentation.java:shutdown(154)) - shut down
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 2 on 57813: exiting
2013-03-13 10:35:33,353 INFO mapred.JobTracker
(JobTracker.java:offerService(2172)) - Stopped interTrackerServer
2013-03-13 10:35:33,353 INFO mapred.JobTracker (JobTracker.java:close(2200)) -
Stopping expireTrackers
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 6 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 9 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 8 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(1433)) - IPC Server
handler 5 on 57813: exiting
2013-03-13 10:35:33,352 INFO ipc.Server (Server.java:run(664)) - Stopping IPC
Server Responder
2013-03-13 10:35:33,353 INFO mapred.JobTracker (JobTracker.java:close(2209)) -
Stopping retirer
2013-03-13 10:35:33,354 INFO mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:terminate(107)) - Stopping Job Init
Manager thread
2013-03-13 10:35:33,354 INFO mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:run(61)) - JobInitManagerThread
interrupted.
2013-03-13 10:35:33,354 INFO mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:run(65)) - Shutting down thread pool
2013-03-13 10:35:33,355 INFO mapred.JobTracker (JobTracker.java:close(2221)) -
Stopping expireLaunchingTasks
2013-03-13 10:35:33,355 INFO mapred.JobTracker (JobTracker.java:close(2240)) -
Stopping job history server
2013-03-13 10:35:33,355 INFO mapred.JobTracker (JobTracker.java:close(2248)) -
stopped all jobtracker services
testCurrentJHParser validating using gold std
2013-03-13 10:35:33,390 WARN rumen.ZombieJob
(ZombieJob.java:sanitizeValue(244)) - NumberMaps not defined for null
2013-03-13 10:35:33,390 WARN rumen.ZombieJob
(ZombieJob.java:sanitizeValue(244)) - NumberReduces not defined for null
2013-03-13 10:35:33,407 INFO compress.CodecPool
(CodecPool.java:getDecompressor(128)) - Got brand-new decompressor
------------- ---------------- ---------------
------------- Standard Error -----------------
In LoggedJob, we saw the unknown attribute numberMaps.
In LoggedJob, we saw the unknown attribute numberReduces.
------------- ---------------- ---------------
Testcase: testSmallTrace took 0.965 sec
Testcase: testTruncatedTask took 0.15 sec
Testcase: testRumenViaDispatch took 0.56 sec
Testcase: testBracketedCounters took 0.109 sec
Testcase: testHadoop20JHParser took 0 sec
Testcase: testJobHistoryFilenameParsing took 0.015 sec
Testcase: testProcessInputArgument took 0.045 sec
Testcase: testCurrentJHParser took 17.892 sec
FAILED
Content mismatch expected:<[MA]P_ATTEMPT_STARTED> but
was:<[SETU]P_ATTEMPT_STARTED>
junit.framework.AssertionFailedError: Content mismatch
expected:<[MA]P_ATTEMPT_STARTED> but was:<[SETU]P_ATTEMPT_STARTED>
at
org.apache.hadoop.tools.rumen.TestRumenJobTraces.testCurrentJHParser(TestRumenJobTraces.java:779)
Testcase: testJobConfigurationParsing took 0.031 sec
{code}
> TestRumenJobTraces failing on 1.3.x
> -----------------------------------
>
> Key: MAPREDUCE-5064
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-5064
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Affects Versions: 1.3.0
> Environment: OS/X, java 1.6.0_41, GMT, home network (no DNS)
> Reporter: Steve Loughran
> Priority: Minor
>
> {{TestRumenJobTraces.testCurrentJHParser()}} is failing locally, both in a
> bulk test and standalone
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
