You are viewing a plain text version of this content. The canonical link for it is here.
Posted to mapreduce-issues@hadoop.apache.org by "chillon_m (JIRA)" <ji...@apache.org> on 2014/01/13 02:50:50 UTC
[jira] [Updated] (MAPREDUCE-5721) RM occur exception while
unregistering
[ https://issues.apache.org/jira/browse/MAPREDUCE-5721?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
chillon_m updated MAPREDUCE-5721:
---------------------------------
Description:
when i run WORDCOUNT EXAMPLES,it occur.
Hadoop:
2014-01-10 16:21:45,987 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001.summary because destination exists
2014-01-10 16:21:45,988 INFO BlockStateChange: BLOCK* addStoredBlock: blockMap updated: 192.168.0.135:50010 is added to blk_1073742140_1320 size 76810
2014-01-10 16:21:46,000 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml because destination exists
2014-01-10 16:21:46,005 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist because destination exists
2014-01-10 16:21:46,005 INFO org.apache.hadoop.hdfs.server.namenode.EditLogFileOutputStream: Nothing to flush
2014-01-10 16:21:46,152 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742126_1306 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742127_1307 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742128_1308 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742129_1309 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742131_1311 192.168.0.134:50010 192.168.0.135:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742130_1310 192.168.0.134:50010 192.168.0.135:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742137_1317 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742136_1316 192.168.0.135:50010 192.168.0.134:50010
2014-01-10 16:21:48,901 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* InvalidateBlocks: ask 192.168.0.134:50010 to delete [blk_1073742128_1308, blk_1073742129_1309, blk_1073742130_1310, blk_1073742131_1311, blk_1073742136_1316, blk_1073742137_1317, blk_1073742126_1306, blk_1073742127_1307]
2014-01-10 16:21:51,904 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* InvalidateBlocks: ask 192.168.0.135:50010 to delete [blk_1073742128_1308, blk_1073742129_1309, blk_1073742130_1310, blk_1073742131_1311, blk_1073742136_1316, blk_1073742137_1317, blk_1073742126_1306, blk_1073742127_1307]
RM:
2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: Application appattempt_1389341658181_0001_000002 released container container_1389341658181_0001_02_000001 on node: host: datanode1.hadoop:56467 #containers=0 available=8192 used=0 with event: FINISHED
2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Unregistering app attempt : appattempt_1389341658181_0001_000002
2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1389341658181_0001_000002 State change from RUNNING to FAILED
2014-01-10 16:21:47,007 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Application application_1389341658181_0001 failed 2 times due to AM Container for appattempt_1389341658181_0001_000002 exited with exitCode: 1 due to: Exception from container-launch:
org.apache.hadoop.util.Shell$ExitCodeException:
at org.apache.hadoop.util.Shell.runCommand(Shell.java:464)
at org.apache.hadoop.util.Shell.run(Shell.java:380)
at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:590)
at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:195)
at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:283)
at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:79)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:139)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)
at java.lang.Thread.run(Thread.java:662)
.Failing this attempt.. Failing the application.
2014-01-10 16:21:47,010 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1389341658181_0001 State change from RUNNING to FAILED
2014-01-10 16:21:47,012 INFO org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: Removing info for app: application_1389341658181_0001
2014-01-10 16:21:47,016 WARN org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=hadoop OPERATION=Application Finished - Failed TARGET=RMAppManager RESULT=FAILURE DESCRIPTION=App failed with state: FAILED PERMISSIONS=Application application_1389341658181_0001 failed 2 times due to AM Container for appattempt_1389341658181_0001_000002 exited with exitCode: 1 due to: Exception from container-launch:
org.apache.hadoop.util.Shell$ExitCodeException:
at org.apache.hadoop.util.Shell.runCommand(Shell.java:464)
at org.apache.hadoop.util.Shell.run(Shell.java:380)
at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:590)
at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:195)
at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:283)
at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:79)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:139)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)
at java.lang.Thread.run(Thread.java:662)
.Failing this attempt.. Failing the application. APPID=application_1389341658181_0001
2014-01-10 16:21:47,019 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAppManager$ApplicationSummary: appId=application_1389341658181_0001,name=word count,user=hadoop,queue=default,state=FAILED,trackingUrl=namenode0:8088/cluster/app/application_1389341658181_0001,appMasterHost=,startTime=1389341979049,finishTime=1389342107008,finalStatus=FAILED
2014-01-10 16:21:47,021 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Cleaning master appattempt_1389341658181_0001_000002
2014-01-10 16:21:47,012 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: Application appattempt_1389341658181_0001_000002 is done. finalState=FAILED
2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AppSchedulingInfo: Application application_1389341658181_0001 requests cleared
2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: Application removed - appId: application_1389341658181_0001 user: hadoop queue: default #user-pending-applications: 0 #user-active-applications: 0 #queue-pending-applications: 0 #queue-active-applications: 0
2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.ParentQueue: Application removed - appId: application_1389341658181_0001 user: hadoop leaf-queue of parent: root #applications: 0
datanode0-syslog:
2014-01-10 16:21:09,369 INFO [Socket Reader #1 for port 39047] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1389341658181_0001 (auth:SIMPLE)
2014-01-10 16:21:09,405 INFO [IPC Server handler 11 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1389341658181_0001_r_000004 asked for a task
2014-01-10 16:21:09,405 INFO [IPC Server handler 11 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1389341658181_0001_r_000004 given task: attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:10,012 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1389341658181_0001_01_000002
2014-01-10 16:21:10,012 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:0 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
2014-01-10 16:21:10,012 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1389341658181_0001_m_000000_0: Container killed by the ApplicationMaster.
Container killed on request. Exit code is 143
2014-01-10 16:21:10,578 INFO [IPC Server handler 12 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1389341658181_0001_r_000000_0. startIndex 0 maxEvents 10000
2014-01-10 16:21:11,593 INFO [IPC Server handler 13 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1389341658181_0001_r_000000_0. startIndex 2 maxEvents 10000
2014-01-10 16:21:12,003 INFO [IPC Server handler 14 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,003 INFO [IPC Server handler 14 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 0.0
2014-01-10 16:21:12,077 INFO [IPC Server handler 15 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,077 INFO [IPC Server handler 15 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 0.0
2014-01-10 16:21:12,698 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit-pending state update from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,699 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from RUNNING to COMMIT_PENDING
2014-01-10 16:21:12,700 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: attempt_1389341658181_0001_r_000000_0 given a go for committing the task output.
2014-01-10 16:21:12,702 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit go/no-go request from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,703 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Result of canCommit for attempt_1389341658181_0001_r_000000_0:true
2014-01-10 16:21:12,776 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,777 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 1.0
2014-01-10 16:21:12,779 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,780 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_CONTAINER_CLEANUP
2014-01-10 16:21:12,785 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1389341658181_0001_01_000004 taskAttempt attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,785 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1389341658181_0001_r_000000_0
2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1389341658181_0001_r_000000 Task Transitioned from RUNNING to SUCCEEDED
2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 3
2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1389341658181_0001Job Transitioned from RUNNING to COMMITTING
2014-01-10 16:21:12,870 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_COMMIT
2014-01-10 16:21:12,974 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Calling handler for JobFinishedEvent
2014-01-10 16:21:12,976 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1389341658181_0001Job Transitioned from COMMITTING to SUCCEEDED
2014-01-10 16:21:12,978 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
2014-01-10 16:21:12,978 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
2014-01-10 16:21:12,983 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 1
2014-01-10 16:21:13,021 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:1 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
2014-01-10 16:21:13,094 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
2014-01-10 16:21:13,140 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
2014-01-10 16:21:13,143 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1_conf.xml to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
2014-01-10 16:21:13,210 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
2014-01-10 16:21:13,214 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary
2014-01-10 16:21:13,215 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml
2014-01-10 16:21:13,216 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist
2014-01-10 16:21:13,219 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2014-01-10 16:21:13,226 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to
2014-01-10 16:21:13,229 ERROR [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Exception while unregistering
java.lang.NullPointerException
at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithoutScheme(MRWebAppUtil.java:133)
at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithScheme(MRWebAppUtil.java:148)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.doUnregistration(RMCommunicator.java:207)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.unregister(RMCommunicator.java:177)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.serviceStop(RMCommunicator.java:250)
at org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator.serviceStop(RMContainerAllocator.java:255)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter.serviceStop(MRAppMaster.java:817)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
at org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80)
at org.apache.hadoop.service.CompositeService.stop(CompositeService.java:159)
at org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:132)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.shutDownJob(MRAppMaster.java:548)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler$1.run(MRAppMaster.java:599)
2014-01-10 16:21:13,234 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:1 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
2014-01-10 16:21:13,234 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Skipping cleaning up the staging dir. assuming AM will be retried.
2014-01-10 16:21:13,235 INFO [Thread-69] org.apache.hadoop.ipc.Server: Stopping server on 39047
2014-01-10 16:21:13,241 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2014-01-10 16:21:13,242 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted
2014-01-10 16:21:13,243 INFO [IPC Server listener on 39047] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 39047
2014-01-10 16:21:18,243 INFO [Thread-69] org.apache.hadoop.ipc.Server: Stopping server on 41351
2014-01-10 16:21:18,272 INFO [Thread-69] org.mortbay.log: Stopped SelectChannelConnector@0.0.0.0:0
2014-01-10 16:21:18,274 INFO [IPC Server listener on 41351] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 41351
2014-01-10 16:21:18,275 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2014-01-10 16:21:18,378 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Exiting MR AppMaster..GoodBye!
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster received a signal. Signaling RMCommunicator and JobHistoryEventHandler.
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that iSignalled is: true
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: false
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: false
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: false
2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is false
datanode1-syslog：
014-01-10 16:21:39,815 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Will not try to recover. recoveryEnabled: true recoverySupportedByCommitter: false numReduceTasks: 1 shuffleKeyValidForRecovery: true ApplicationAttemptID: 2
2014-01-10 16:21:39,871 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Previous history file is at hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist
2014-01-10 16:21:41,503 INFO [Main Thread] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler
2014-01-10 16:21:41,752 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
2014-01-10 16:21:42,641 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
2014-01-10 16:21:42,641 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
2014-01-10 16:21:42,896 INFO [Main Thread] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at namenode0/192.168.0.133:8030
2014-01-10 16:21:43,123 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: maxContainerCapability: 8192
2014-01-10 16:21:43,183 INFO [Main Thread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryCopyService: History file is at hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist
2014-01-10 16:21:43,413 ERROR [Main Thread] org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:hadoop (auth:SIMPLE) cause:java.io.IOException: Was asked to shut down.
2014-01-10 16:21:43,414 FATAL [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Error starting MRAppMaster
java.io.IOException: Was asked to shut down.
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$1.run(MRAppMaster.java:1447)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1491)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.initAndStartAppMaster(MRAppMaster.java:1452)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.main(MRAppMaster.java:1374)
2014-01-10 16:21:43,454 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster received a signal. Signaling RMCommunicator and JobHistoryEventHandler.
2014-01-10 16:21:43,455 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that iSignalled is: true
2014-01-10 16:21:43,456 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
2014-01-10 16:21:43,470 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 17
2014-01-10 16:21:43,543 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1389341658181_0001, File: hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2.jhist
2014-01-10 16:21:43,657 INFO [eventHandlingThread] org.apache.hadoop.conf.Configuration.deprecation: user.name is deprecated. Instead, use mapreduce.job.user.name
2014-01-10 16:21:44,698 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event AM_STARTED
2014-01-10 16:21:44,700 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_SUBMITTED
2014-01-10 16:21:44,705 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_INITED
2014-01-10 16:21:44,707 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_INFO_CHANGED
2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_STARTED
2014-01-10 16:21:44,710 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_STARTED
2014-01-10 16:21:44,710 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_FINISHED
2014-01-10 16:21:44,763 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
2014-01-10 16:21:44,767 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event REDUCE_ATTEMPT_STARTED
2014-01-10 16:21:44,767 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_FINISHED
2014-01-10 16:21:44,769 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
2014-01-10 16:21:44,771 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event REDUCE_ATTEMPT_FINISHED
2014-01-10 16:21:44,775 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
2014-01-10 16:21:44,777 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_FINISHED
2014-01-10 16:21:44,886 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2.jhist to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
2014-01-10 16:21:45,005 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
2014-01-10 16:21:45,008 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2_conf.xml to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
2014-01-10 16:21:45,079 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
2014-01-10 16:21:45,103 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary
2014-01-10 16:21:45,108 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml
2014-01-10 16:21:45,110 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist
2014-01-10 16:21:45,110 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
2014-01-10 16:21:45,122 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to We crashed after successfully committing. Recovering.
2014-01-10 16:21:45,198 ERROR [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Exception while unregistering
java.lang.NullPointerException
at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithoutScheme(MRWebAppUtil.java:133)
at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithScheme(MRWebAppUtil.java:148)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.doUnregistration(RMCommunicator.java:207)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.unregister(RMCommunicator.java:177)
at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.serviceStop(RMCommunicator.java:250)
at org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator.serviceStop(RMContainerAllocator.java:255)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter.serviceStop(MRAppMaster.java:817)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
at org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80)
at org.apache.hadoop.service.CompositeService.stop(CompositeService.java:159)
at org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:132)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$MRAppMasterShutdownHook.run(MRAppMaster.java:1399)
at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54)
2014-01-10 16:21:45,199 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:0 ContRel:0 HostLocal:0 RackLocal:0
2014-01-10 16:21:45,203 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://namenode0:9000 /tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001
> RM occur exception while unregistering
> --------------------------------------
>
> Key: MAPREDUCE-5721
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-5721
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: resourcemanager
> Affects Versions: 2.2.0
> Environment: rhel 5.8_x86 ;jrockit 1.6.0_31-R28.2.3-4.1.0;hadoop 2.2.0
> Reporter: chillon_m
>
> when i run WORDCOUNT EXAMPLES,it occur.
> Hadoop:
> 2014-01-10 16:21:45,987 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001.summary because destination exists
> 2014-01-10 16:21:45,988 INFO BlockStateChange: BLOCK* addStoredBlock: blockMap updated: 192.168.0.135:50010 is added to blk_1073742140_1320 size 76810
> 2014-01-10 16:21:46,000 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml because destination exists
> 2014-01-10 16:21:46,005 WARN org.apache.hadoop.hdfs.StateChange: DIR* FSDirectory.unprotectedRenameTo: failed to rename /mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to /mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist because destination exists
> 2014-01-10 16:21:46,005 INFO org.apache.hadoop.hdfs.server.namenode.EditLogFileOutputStream: Nothing to flush
> 2014-01-10 16:21:46,152 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742126_1306 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742127_1307 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742128_1308 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742129_1309 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742131_1311 192.168.0.134:50010 192.168.0.135:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742130_1310 192.168.0.134:50010 192.168.0.135:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742137_1317 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:46,153 INFO BlockStateChange: BLOCK* addToInvalidates: blk_1073742136_1316 192.168.0.135:50010 192.168.0.134:50010
> 2014-01-10 16:21:48,901 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* InvalidateBlocks: ask 192.168.0.134:50010 to delete [blk_1073742128_1308, blk_1073742129_1309, blk_1073742130_1310, blk_1073742131_1311, blk_1073742136_1316, blk_1073742137_1317, blk_1073742126_1306, blk_1073742127_1307]
> 2014-01-10 16:21:51,904 INFO org.apache.hadoop.hdfs.StateChange: BLOCK* InvalidateBlocks: ask 192.168.0.135:50010 to delete [blk_1073742128_1308, blk_1073742129_1309, blk_1073742130_1310, blk_1073742131_1311, blk_1073742136_1316, blk_1073742137_1317, blk_1073742126_1306, blk_1073742127_1307]
> RM:
> 2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: Application appattempt_1389341658181_0001_000002 released container container_1389341658181_0001_02_000001 on node: host: datanode1.hadoop:56467 #containers=0 available=8192 used=0 with event: FINISHED
> 2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Unregistering app attempt : appattempt_1389341658181_0001_000002
> 2014-01-10 16:21:47,006 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1389341658181_0001_000002 State change from RUNNING to FAILED
> 2014-01-10 16:21:47,007 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Application application_1389341658181_0001 failed 2 times due to AM Container for appattempt_1389341658181_0001_000002 exited with exitCode: 1 due to: Exception from container-launch:
> org.apache.hadoop.util.Shell$ExitCodeException:
> at org.apache.hadoop.util.Shell.runCommand(Shell.java:464)
> at org.apache.hadoop.util.Shell.run(Shell.java:380)
> at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:590)
> at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:195)
> at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:283)
> at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:79)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:139)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)
> at java.lang.Thread.run(Thread.java:662)
> .Failing this attempt.. Failing the application.
> 2014-01-10 16:21:47,010 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1389341658181_0001 State change from RUNNING to FAILED
> 2014-01-10 16:21:47,012 INFO org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: Removing info for app: application_1389341658181_0001
> 2014-01-10 16:21:47,016 WARN org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=hadoop OPERATION=Application Finished - Failed TARGET=RMAppManager RESULT=FAILURE DESCRIPTION=App failed with state: FAILED PERMISSIONS=Application application_1389341658181_0001 failed 2 times due to AM Container for appattempt_1389341658181_0001_000002 exited with exitCode: 1 due to: Exception from container-launch:
> org.apache.hadoop.util.Shell$ExitCodeException:
> at org.apache.hadoop.util.Shell.runCommand(Shell.java:464)
> at org.apache.hadoop.util.Shell.run(Shell.java:380)
> at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:590)
> at org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor.launchContainer(DefaultContainerExecutor.java:195)
> at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:283)
> at org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch.call(ContainerLaunch.java:79)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:139)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)
> at java.lang.Thread.run(Thread.java:662)
> .Failing this attempt.. Failing the application. APPID=application_1389341658181_0001
> 2014-01-10 16:21:47,019 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAppManager$ApplicationSummary: appId=application_1389341658181_0001,name=word count,user=hadoop,queue=default,state=FAILED,trackingUrl=namenode0:8088/cluster/app/application_1389341658181_0001,appMasterHost=,startTime=1389341979049,finishTime=1389342107008,finalStatus=FAILED
> 2014-01-10 16:21:47,021 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Cleaning master appattempt_1389341658181_0001_000002
> 2014-01-10 16:21:47,012 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: Application appattempt_1389341658181_0001_000002 is done. finalState=FAILED
> 2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AppSchedulingInfo: Application application_1389341658181_0001 requests cleared
> 2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: Application removed - appId: application_1389341658181_0001 user: hadoop queue: default #user-pending-applications: 0 #user-active-applications: 0 #queue-pending-applications: 0 #queue-active-applications: 0
> 2014-01-10 16:21:47,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.ParentQueue: Application removed - appId: application_1389341658181_0001 user: hadoop leaf-queue of parent: root #applications: 0
> datanode0-syslog:
> 2014-01-10 16:21:09,369 INFO [Socket Reader #1 for port 39047] SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for job_1389341658181_0001 (auth:SIMPLE)
> 2014-01-10 16:21:09,405 INFO [IPC Server handler 11 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID : jvm_1389341658181_0001_r_000004 asked for a task
> 2014-01-10 16:21:09,405 INFO [IPC Server handler 11 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: JVM with ID: jvm_1389341658181_0001_r_000004 given task: attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:10,012 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Received completed container container_1389341658181_0001_01_000002
> 2014-01-10 16:21:10,012 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:0 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
> 2014-01-10 16:21:10,012 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1389341658181_0001_m_000000_0: Container killed by the ApplicationMaster.
> Container killed on request. Exit code is 143
> 2014-01-10 16:21:10,578 INFO [IPC Server handler 12 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1389341658181_0001_r_000000_0. startIndex 0 maxEvents 10000
> 2014-01-10 16:21:11,593 INFO [IPC Server handler 13 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: MapCompletionEvents request from attempt_1389341658181_0001_r_000000_0. startIndex 2 maxEvents 10000
> 2014-01-10 16:21:12,003 INFO [IPC Server handler 14 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,003 INFO [IPC Server handler 14 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 0.0
> 2014-01-10 16:21:12,077 INFO [IPC Server handler 15 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,077 INFO [IPC Server handler 15 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 0.0
> 2014-01-10 16:21:12,698 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit-pending state update from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,699 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from RUNNING to COMMIT_PENDING
> 2014-01-10 16:21:12,700 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: attempt_1389341658181_0001_r_000000_0 given a go for committing the task output.
> 2014-01-10 16:21:12,702 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Commit go/no-go request from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,703 INFO [IPC Server handler 16 on 39047] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Result of canCommit for attempt_1389341658181_0001_r_000000_0:true
> 2014-01-10 16:21:12,776 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Status update from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,777 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Progress of TaskAttempt attempt_1389341658181_0001_r_000000_0 is : 1.0
> 2014-01-10 16:21:12,779 INFO [IPC Server handler 18 on 39047] org.apache.hadoop.mapred.TaskAttemptListenerImpl: Done acknowledgement from attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,780 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_CONTAINER_CLEANUP
> 2014-01-10 16:21:12,785 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1389341658181_0001_01_000004 taskAttempt attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,785 INFO [ContainerLauncher #5] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1389341658181_0001_r_000000_0 TaskAttempt Transitioned from SUCCESS_CONTAINER_CLEANUP to SUCCEEDED
> 2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: Task succeeded with attempt attempt_1389341658181_0001_r_000000_0
> 2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1389341658181_0001_r_000000 Task Transitioned from RUNNING to SUCCEEDED
> 2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Num completed Tasks: 3
> 2014-01-10 16:21:12,867 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1389341658181_0001Job Transitioned from RUNNING to COMMITTING
> 2014-01-10 16:21:12,870 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: JOB_COMMIT
> 2014-01-10 16:21:12,974 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: Calling handler for JobFinishedEvent
> 2014-01-10 16:21:12,976 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl: job_1389341658181_0001Job Transitioned from COMMITTING to SUCCEEDED
> 2014-01-10 16:21:12,978 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: We are finishing cleanly so this is the last retry
> 2014-01-10 16:21:12,978 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
> 2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
> 2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
> 2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
> 2014-01-10 16:21:12,979 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Calling stop for all the services
> 2014-01-10 16:21:12,983 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 1
> 2014-01-10 16:21:13,021 INFO [RMCommunicator Allocator] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Before Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:1 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
> 2014-01-10 16:21:13,094 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
> 2014-01-10 16:21:13,140 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
> 2014-01-10 16:21:13,143 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1_conf.xml to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
> 2014-01-10 16:21:13,210 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
> 2014-01-10 16:21:13,214 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary
> 2014-01-10 16:21:13,215 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml
> 2014-01-10 16:21:13,216 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist
> 2014-01-10 16:21:13,219 INFO [Thread-69] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
> 2014-01-10 16:21:13,226 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to
> 2014-01-10 16:21:13,229 ERROR [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Exception while unregistering
> java.lang.NullPointerException
> at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithoutScheme(MRWebAppUtil.java:133)
> at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithScheme(MRWebAppUtil.java:148)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.doUnregistration(RMCommunicator.java:207)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.unregister(RMCommunicator.java:177)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.serviceStop(RMCommunicator.java:250)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator.serviceStop(RMContainerAllocator.java:255)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter.serviceStop(MRAppMaster.java:817)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
> at org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80)
> at org.apache.hadoop.service.CompositeService.stop(CompositeService.java:159)
> at org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:132)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.shutDownJob(MRAppMaster.java:548)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler$1.run(MRAppMaster.java:599)
> 2014-01-10 16:21:13,234 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:1 CompletedMaps:2 CompletedReds:1 ContAlloc:3 ContRel:0 HostLocal:2 RackLocal:0
> 2014-01-10 16:21:13,234 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Skipping cleaning up the staging dir. assuming AM will be retried.
> 2014-01-10 16:21:13,235 INFO [Thread-69] org.apache.hadoop.ipc.Server: Stopping server on 39047
> 2014-01-10 16:21:13,241 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
> 2014-01-10 16:21:13,242 INFO [TaskHeartbeatHandler PingChecker] org.apache.hadoop.mapreduce.v2.app.TaskHeartbeatHandler: TaskHeartbeatHandler thread interrupted
> 2014-01-10 16:21:13,243 INFO [IPC Server listener on 39047] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 39047
> 2014-01-10 16:21:18,243 INFO [Thread-69] org.apache.hadoop.ipc.Server: Stopping server on 41351
> 2014-01-10 16:21:18,272 INFO [Thread-69] org.mortbay.log: Stopped SelectChannelConnector@0.0.0.0:0
> 2014-01-10 16:21:18,274 INFO [IPC Server listener on 41351] org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 41351
> 2014-01-10 16:21:18,275 INFO [IPC Server Responder] org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
> 2014-01-10 16:21:18,378 INFO [Thread-69] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Exiting MR AppMaster..GoodBye!
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster received a signal. Signaling RMCommunicator and JobHistoryEventHandler.
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that iSignalled is: true
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: false
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: false
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: false
> 2014-01-10 16:21:18,390 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is false
> datanode1-syslog：
> 014-01-10 16:21:39,815 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Will not try to recover. recoveryEnabled: true recoverySupportedByCommitter: false numReduceTasks: 1 shuffleKeyValidForRecovery: true ApplicationAttemptID: 2
> 2014-01-10 16:21:39,871 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Previous history file is at hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist
> 2014-01-10 16:21:41,503 INFO [Main Thread] org.apache.hadoop.yarn.event.AsyncDispatcher: Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobFinishEventHandler
> 2014-01-10 16:21:41,752 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsConfig: loaded properties from hadoop-metrics2.properties
> 2014-01-10 16:21:42,641 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Scheduled snapshot period at 10 second(s).
> 2014-01-10 16:21:42,641 INFO [Main Thread] org.apache.hadoop.metrics2.impl.MetricsSystemImpl: MRAppMaster metrics system started
> 2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: nodeBlacklistingEnabled:true
> 2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: maxTaskFailuresPerNode is 3
> 2014-01-10 16:21:42,777 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: blacklistDisablePercent is 33
> 2014-01-10 16:21:42,896 INFO [Main Thread] org.apache.hadoop.yarn.client.RMProxy: Connecting to ResourceManager at namenode0/192.168.0.133:8030
> 2014-01-10 16:21:43,123 INFO [Main Thread] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: maxContainerCapability: 8192
> 2014-01-10 16:21:43,183 INFO [Main Thread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryCopyService: History file is at hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_1.jhist
> 2014-01-10 16:21:43,413 ERROR [Main Thread] org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:hadoop (auth:SIMPLE) cause:java.io.IOException: Was asked to shut down.
> 2014-01-10 16:21:43,414 FATAL [Main Thread] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Error starting MRAppMaster
> java.io.IOException: Was asked to shut down.
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$1.run(MRAppMaster.java:1447)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1491)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.initAndStartAppMaster(MRAppMaster.java:1452)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.main(MRAppMaster.java:1374)
> 2014-01-10 16:21:43,454 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: MRAppMaster received a signal. Signaling RMCommunicator and JobHistoryEventHandler.
> 2014-01-10 16:21:43,455 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that iSignalled is: true
> 2014-01-10 16:21:43,456 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify RMCommunicator isAMLastRetry: true
> 2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: RMCommunicator notified that shouldUnregistered is: true
> 2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Notify JHEH isAMLastRetry: true
> 2014-01-10 16:21:43,457 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: JobHistoryEventHandler notified that forceJobCompletion is true
> 2014-01-10 16:21:43,470 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopping JobHistoryEventHandler. Size of the outstanding queue size is 17
> 2014-01-10 16:21:43,543 INFO [eventHandlingThread] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Event Writer setup for JobId: job_1389341658181_0001, File: hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2.jhist
> 2014-01-10 16:21:43,657 INFO [eventHandlingThread] org.apache.hadoop.conf.Configuration.deprecation: user.name is deprecated. Instead, use mapreduce.job.user.name
> 2014-01-10 16:21:44,698 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event AM_STARTED
> 2014-01-10 16:21:44,700 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_SUBMITTED
> 2014-01-10 16:21:44,705 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_INITED
> 2014-01-10 16:21:44,707 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_INFO_CHANGED
> 2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
> 2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
> 2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_STARTED
> 2014-01-10 16:21:44,708 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_STARTED
> 2014-01-10 16:21:44,710 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_STARTED
> 2014-01-10 16:21:44,710 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_FINISHED
> 2014-01-10 16:21:44,763 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
> 2014-01-10 16:21:44,767 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event REDUCE_ATTEMPT_STARTED
> 2014-01-10 16:21:44,767 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event MAP_ATTEMPT_FINISHED
> 2014-01-10 16:21:44,769 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
> 2014-01-10 16:21:44,771 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event REDUCE_ATTEMPT_FINISHED
> 2014-01-10 16:21:44,775 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event TASK_FINISHED
> 2014-01-10 16:21:44,777 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: In stop, writing event JOB_FINISHED
> 2014-01-10 16:21:44,886 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2.jhist to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
> 2014-01-10 16:21:45,005 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp
> 2014-01-10 16:21:45,008 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copying hdfs://namenode0:9000/tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001/job_1389341658181_0001_2_conf.xml to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
> 2014-01-10 16:21:45,079 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Copied to done location: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp
> 2014-01-10 16:21:45,103 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001.summary
> 2014-01-10 16:21:45,108 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001_conf.xml
> 2014-01-10 16:21:45,110 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Moved tmp to done: hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist_tmp to hdfs://namenode0:9000/mr-history/tmp/hadoop/job_1389341658181_0001-1389341978991-hadoop-word+count-1389342072969-2-1-SUCCEEDED-default.jhist
> 2014-01-10 16:21:45,110 INFO [Thread-1] org.apache.hadoop.mapreduce.jobhistory.JobHistoryEventHandler: Stopped JobHistoryEventHandler. super.stop()
> 2014-01-10 16:21:45,122 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Setting job diagnostics to We crashed after successfully committing. Recovering.
> 2014-01-10 16:21:45,198 ERROR [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Exception while unregistering
> java.lang.NullPointerException
> at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithoutScheme(MRWebAppUtil.java:133)
> at org.apache.hadoop.mapreduce.v2.util.MRWebAppUtil.getApplicationWebURLOnJHSWithScheme(MRWebAppUtil.java:148)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.doUnregistration(RMCommunicator.java:207)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.unregister(RMCommunicator.java:177)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMCommunicator.serviceStop(RMCommunicator.java:250)
> at org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator.serviceStop(RMContainerAllocator.java:255)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$ContainerAllocatorRouter.serviceStop(MRAppMaster.java:817)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
> at org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80)
> at org.apache.hadoop.service.CompositeService.stop(CompositeService.java:159)
> at org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:132)
> at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
> at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$MRAppMasterShutdownHook.run(MRAppMaster.java:1399)
> at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54)
> 2014-01-10 16:21:45,199 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerAllocator: Final Stats: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:0 CompletedReds:0 ContAlloc:0 ContRel:0 HostLocal:0 RackLocal:0
> 2014-01-10 16:21:45,203 INFO [Thread-1] org.apache.hadoop.mapreduce.v2.app.MRAppMaster: Deleting staging directory hdfs://namenode0:9000 /tmp/hadoop-yarn/staging/hadoop/.staging/job_1389341658181_0001
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)