Hi,
It's not a problem at all. Anything I can do to help.
I've attached the log file for the relevant time period. This is hadoop
2.7.2 - you have a good memory :)
Cheers,
On 30/06/16 22:56, Darin Johnson wrote:
> Hey Steven,
>
> Looks like this might be slightly different than what I was originally
> expecting. Sorry to keep asking for more info but it will help me recreate
> the issue. Could you possibly get me more of the ResourceManager logs? In
> particular, I'm trying to figure out where upgradeNodeCapacity is getting
> called from and any transitions of slave2. Also, what version of hadoop
> are you running, I think I recall it being 2.72 but should verify.
>
> Thanks for taken the time to work with me on this.
>
> Darin
>
> On Thu, Jun 30, 2016 at 5:10 PM, Stephen Gran <stephen.g...@piksel.com>
> wrote:
>
>> Hi,
>>
>> Yes - the imaginatively named slave2 was a zero-sized nm at that point -
>> I am looking at how small a pool of reserved resource I can get away
>> with, and use FGS for burst activity.
>>
>>
>> Here are all the logs related to that host:port combination around that
>> time:
>>
>> 2016-06-30 19:47:43,756 INFO
>> org.apache.hadoop.yarn.util.AbstractLivelinessMonitor:
>> Expired:slave2:24679 Timed out after 2 secs
>> 2016-06-30 19:47:43,771 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl:
>> Deactivating Node slave2:24679 as it is now LOST
>> 2016-06-30 19:47:43,771 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl:
>> slave2:24679 Node Transitioned from RUNNING to LOST
>> 2016-06-30 19:47:43,909 INFO
>> org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task
>> yarn_Container: [ContainerId: container_1467314892573_0009_01_000005,
>> NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource:
>> <memory:2048, vCores:1>, Priority: 20, Token: Token { kind:
>> ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0
>> cpu and 1 mem.
>> 2016-06-30 19:47:43,909 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode:
>> Released container container_1467314892573_0009_01_000005 of capacity
>> <memory:2048, vCores:1> on host slave2:24679, which currently has 1
>> containers, <memory:2048, vCores:1> used and <memory:2048, vCores:1>
>> available, release resources=true
>> 2016-06-30 19:47:43,909 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler:
>> Application attempt appattempt_1467314892573_0009_000001 released
>> container container_1467314892573_0009_01_000005 on node: host:
>> slave2:24679 #containers=1 available=<memory:2048, vCores:1>
>> used=<memory:2048, vCores:1> with event: KILL
>> 2016-06-30 19:47:43,909 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService:
>> Node not found resyncing slave2:24679
>> 2016-06-30 19:47:43,952 INFO
>> org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task
>> yarn_Container: [ContainerId: container_1467314892573_0009_01_000006,
>> NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource:
>> <memory:2048, vCores:1>, Priority: 20, Token: Token { kind:
>> ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0
>> cpu and 1 mem.
>> 2016-06-30 19:47:43,952 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode:
>> Released container container_1467314892573_0009_01_000006 of capacity
>> <memory:2048, vCores:1> on host slave2:24679, which currently has 0
>> containers, <memory:0, vCores:0> used and <memory:4096, vCores:2>
>> available, release resources=true
>> 2016-06-30 19:47:43,952 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler:
>> Application attempt appattempt_1467314892573_0009_000001 released
>> container container_1467314892573_0009_01_000006 on node: host:
>> slave2:24679 #containers=0 available=<memory:4096, vCores:2>
>> used=<memory:0, vCores:0> with event: KILL
>> 2016-06-30 19:47:43,952 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler:
>> Removed node slave2:24679 cluster capacity: <memory:4096, vCores:4>
>> 2016-06-30 19:47:47,573 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl:
>> slave2:24679 Node Transitioned from NEW to RUNNING
>> 2016-06-30 19:47:47,936 INFO
>> org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService:
>> NodeManager from node slave2(cmPort: 24679 httpPort: 23177) registered
>> with capability: <memory:0, vCores:0>, assigned nodeId slave2:24679
>>
>>
>> Looks like it did go into LOST for a bit.
>>
>> Cheers,
>>
>> On 30/06/16 21:36, Darin Johnson wrote:
>>> Steven, thanks. I thought I had fixed that but perhaps a regression was
>>> made in another merge. I'll look into it, can you answer a few
>> questions?
>>> Was the node (slave2) a zero sided nodemanager (for fgs)? In the node
>>> manager logs had it recently become unhealthy? I'm pretty concerned
>> about
>>> this and will try to get a patch soon.
>>>
>>> Thanks,
>>>
>>> Darin
>>> On Jun 30, 2016 3:53 PM, "Stephen Gran" <stephen.g...@piksel.com> wrote:
>>>
>>>> Hi,
>>>>
>>>> Just playing with the 0.2.0 release (congratulations, by the way!)
>>>>
>>>> I have seen this twice now, although it is by no means consistent - I
>>>> will have a dozen successful runs, and then one of these. This exits
>>>> the RM, which makes it rather noticable.
>>>>
>>>> 2016-06-30 19:47:43,952 INFO
>>>>
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler:
>>>> Removed node slave2:24679 cluster capacity: <memory:4096, vCore
>>>> s:4>
>>>> 2016-06-30 19:47:43,953 FATAL
>>>> org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Error in
>>>> handling event type NODE_RESOURCE_UPDATE to the scheduler
>>>> java.lang.NullPointerException
>>>> at
>>>>
>>>>
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler.updateNodeResource(AbstractYarnScheduler.java:563)
>>>> at
>>>>
>>>>
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler.updateNodeResource(FairScheduler.java:1652)
>>>> at
>>>>
>>>>
>> org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler.handle(FairScheduler.java:1222)
>>>> at
>>>>
>>>>
>> org.apache.myriad.scheduler.yarn.MyriadFairScheduler.handle(MyriadFairScheduler.java:102)
>>>> at
>>>>
>>>>
>> org.apache.myriad.scheduler.yarn.MyriadFairScheduler.handle(MyriadFairScheduler.java:42)
>>>> at
>>>>
>>>>
>> org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher$EventProcessor.run(ResourceManager.java:671)
>>>> at java.lang.Thread.run(Thread.java:745)
>>>> 2016-06-30 19:47:43,972 INFO
>>>> org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Exiting,
>>>> bbye..
>>>>
>>>> --
>>>> Stephen Gran
>>>> Senior Technical Architect
>>>>
>>>> picture the possibilities | piksel.com
>>>> This message is private and confidential. If you have received this
>>>> message in error, please notify the sender or serviced...@piksel.com
>> and
>>>> remove it from your system.
>>>>
>>>> Piksel Inc is a company registered in the United States New York City,
>>>> 1250 Broadway, Suite 1902, New York, NY 10001. F No. = 2931986
>>>>
>>>
>>
>> --
>> Stephen Gran
>> Senior Technical Architect
>>
>> picture the possibilities | piksel.com
>>
>
--
Stephen Gran
Senior Technical Architect
picture the possibilities | piksel.com
2016-06-30 19:46:10,122 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:10,306 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Null container completed...
2016-06-30 19:46:11,011 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:11,011 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:11,011 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:11,012 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:12,126 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:16,128 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:17,021 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:17,022 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:17,022 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:17,023 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:18,136 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:22,142 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:23,031 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:23,031 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:23,032 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:23,032 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:23,144 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:28,150 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 2
2016-06-30 19:46:29,044 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:29,045 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:29,045 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:29,045 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:31,724 INFO org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Allocated new applicationId: 8
2016-06-30 19:46:32,655 INFO org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Application with id 8 submitted by user root
2016-06-30 19:46:32,655 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root IP=10.0.5.3 OPERATION=Submit Application Request TARGET=ClientRMService RESULT=SUCCESS APPID=application_1467314892573_0008
2016-06-30 19:46:32,655 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Storing application with id application_1467314892573_0008
2016-06-30 19:46:32,655 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0008 State change from NEW to NEW_SAVING
2016-06-30 19:46:32,655 INFO org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: Storing info for app: application_1467314892573_0008
2016-06-30 19:46:32,656 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0008 State change from NEW_SAVING to SUBMITTED
2016-06-30 19:46:32,656 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Accepted application application_1467314892573_0008 from user: root, in queue: default, currently num of applications: 1
2016-06-30 19:46:32,657 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0008 State change from SUBMITTED to ACCEPTED
2016-06-30 19:46:32,657 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Registering app attempt : appattempt_1467314892573_0008_000001
2016-06-30 19:46:32,657 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from NEW to SUBMITTED
2016-06-30 19:46:32,657 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Added Application Attempt appattempt_1467314892573_0008_000001 to scheduler from user: root
2016-06-30 19:46:32,658 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from SUBMITTED to SCHEDULED
2016-06-30 19:46:33,064 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_01_000001 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:46:33,064 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0008 CONTAINERID=container_1467314892573_0008_01_000001
2016-06-30 19:46:33,064 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0008_01_000001 of capacity <memory:0, vCores:0> on host slave2:24679, which has 1 containers, <memory:0, vCores:0> used and <memory:0, vCores:0> available after allocation
2016-06-30 19:46:33,065 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Sending NMToken for nodeId : slave2:24679 for container : container_1467314892573_0008_01_000001
2016-06-30 19:46:33,067 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_01_000001 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:46:33,067 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Clear node set for appattempt_1467314892573_0008_000001
2016-06-30 19:46:33,067 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: Storing attempt: AppId: application_1467314892573_0008 AttemptId: appattempt_1467314892573_0008_000001 MasterContainer: Container: [ContainerId: container_1467314892573_0008_01_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ]
2016-06-30 19:46:33,067 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from SCHEDULED to ALLOCATED_SAVING
2016-06-30 19:46:33,067 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from ALLOCATED_SAVING to ALLOCATED
2016-06-30 19:46:33,068 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Launching masterappattempt_1467314892573_0008_000001
2016-06-30 19:46:33,070 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Setting up container Container: [ContainerId: container_1467314892573_0008_01_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] for AM appattempt_1467314892573_0008_000001
2016-06-30 19:46:33,071 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Command to launch container container_1467314892573_0008_01_000001 : $JAVA_HOME/bin/java -Djava.io.tmpdir=$PWD/tmp -Dlog4j.configuration=container-log4j.properties -Dyarn.app.container.log.dir=<LOG_DIR> -Dyarn.app.container.log.filesize=0 -Dhadoop.root.logger=INFO,CLA -Dhadoop.root.logfile=syslog -Xmx1024m org.apache.hadoop.mapreduce.v2.app.MRAppMaster 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr
2016-06-30 19:46:33,071 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Create AMRMToken for ApplicationAttempt: appattempt_1467314892573_0008_000001
2016-06-30 19:46:33,071 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Creating password for appattempt_1467314892573_0008_000001
2016-06-30 19:46:33,093 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Done launching container Container: [ContainerId: container_1467314892573_0008_01_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] for AM appattempt_1467314892573_0008_000001
2016-06-30 19:46:33,098 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_01_000001 not found, status: TASK_RUNNING
2016-06-30 19:46:33,098 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from ALLOCATED to LAUNCHED
2016-06-30 19:46:33,160 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:34,107 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_01_000001 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:46:34,161 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:35,108 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:35,109 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:35,109 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:35,111 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:38,166 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:40,170 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:40,214 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:40,215 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:40,216 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:40,216 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:43,174 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:46,159 INFO org.apache.hadoop.yarn.util.AbstractLivelinessMonitor: Expired:appattempt_1467314892573_0008_000001 Timed out after 10 secs
2016-06-30 19:46:46,159 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: Updating application attempt appattempt_1467314892573_0008_000001 with final state: FAILED, and exit status: -1000
2016-06-30 19:46:46,159 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from LAUNCHED to FINAL_SAVING
2016-06-30 19:46:46,159 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Unregistering app attempt : appattempt_1467314892573_0008_000001
2016-06-30 19:46:46,160 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Application finished, removing password for appattempt_1467314892573_0008_000001
2016-06-30 19:46:46,160 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000001 State change from FINAL_SAVING to FAILED
2016-06-30 19:46:46,160 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: The number of failed attempts is 1. The max attempts is 2
2016-06-30 19:46:46,160 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application appattempt_1467314892573_0008_000001 is done. finalState=FAILED
2016-06-30 19:46:46,160 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: container_1467314892573_0008_01_000001 completed with exit status KILL, killing cooresponding mesos task.
2016-06-30 19:46:46,160 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0008_01_000001"
killed with status: DRIVER_RUNNING
2016-06-30 19:46:46,160 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task yarn_Container: [ContainerId: container_1467314892573_0008_01_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0 cpu and 0 mem.
2016-06-30 19:46:46,160 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_01_000001 Container Transitioned from RUNNING to KILLED
2016-06-30 19:46:46,161 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Completed container: container_1467314892573_0008_01_000001 in state: KILLED event:KILL
2016-06-30 19:46:46,161 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Released Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0008 CONTAINERID=container_1467314892573_0008_01_000001
2016-06-30 19:46:46,161 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Released container container_1467314892573_0008_01_000001 of capacity <memory:0, vCores:0> on host slave2:24679, which currently has 0 containers, <memory:0, vCores:0> used and <memory:0, vCores:0> available, release resources=true
2016-06-30 19:46:46,161 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application attempt appattempt_1467314892573_0008_000001 released container container_1467314892573_0008_01_000001 on node: host: slave2:24679 #containers=0 available=<memory:0, vCores:0> used=<memory:0, vCores:0> with event: KILL
2016-06-30 19:46:46,161 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AppSchedulingInfo: Application application_1467314892573_0008 requests cleared
2016-06-30 19:46:46,162 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Registering app attempt : appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,162 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from NEW to SUBMITTED
2016-06-30 19:46:46,162 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Added Application Attempt appattempt_1467314892573_0008_000002 to scheduler from user: root
2016-06-30 19:46:46,162 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_01_000001 not found, status: TASK_LOST
2016-06-30 19:46:46,164 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Cleaning master appattempt_1467314892573_0008_000001
2016-06-30 19:46:46,164 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from SUBMITTED to SCHEDULED
2016-06-30 19:46:46,177 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:46,417 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:46,417 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:46,418 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_02_000001 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:46:46,418 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0008 CONTAINERID=container_1467314892573_0008_02_000001
2016-06-30 19:46:46,418 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0008_02_000001 of capacity <memory:0, vCores:0> on host slave2:24679, which has 1 containers, <memory:0, vCores:0> used and <memory:4637, vCores:6> available after allocation
2016-06-30 19:46:46,419 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:46,420 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Sending NMToken for nodeId : slave2:24679 for container : container_1467314892573_0008_02_000001
2016-06-30 19:46:46,424 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_02_000001 not found, status: TASK_ERROR
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_02_000001 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Clear node set for appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: Storing attempt: AppId: application_1467314892573_0008 AttemptId: appattempt_1467314892573_0008_000002 MasterContainer: Container: [ContainerId: container_1467314892573_0008_02_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ]
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from SCHEDULED to ALLOCATED_SAVING
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:46,425 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from ALLOCATED_SAVING to ALLOCATED
2016-06-30 19:46:46,426 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Launching masterappattempt_1467314892573_0008_000002
2016-06-30 19:46:46,428 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Setting up container Container: [ContainerId: container_1467314892573_0008_02_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] for AM appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,428 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Command to launch container container_1467314892573_0008_02_000001 : $JAVA_HOME/bin/java -Djava.io.tmpdir=$PWD/tmp -Dlog4j.configuration=container-log4j.properties -Dyarn.app.container.log.dir=<LOG_DIR> -Dyarn.app.container.log.filesize=0 -Dhadoop.root.logger=INFO,CLA -Dhadoop.root.logfile=syslog -Xmx1024m org.apache.hadoop.mapreduce.v2.app.MRAppMaster 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr
2016-06-30 19:46:46,428 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Create AMRMToken for ApplicationAttempt: appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,428 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Creating password for appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,914 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Done launching container Container: [ContainerId: container_1467314892573_0008_02_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] for AM appattempt_1467314892573_0008_000002
2016-06-30 19:46:46,914 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from ALLOCATED to LAUNCHED
2016-06-30 19:46:47,120 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_02_000001 not found, status: TASK_RUNNING
2016-06-30 19:46:47,214 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_01_000001 not found, status: TASK_FINISHED
2016-06-30 19:46:47,420 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_02_000001 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:46:47,421 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Null container completed...
2016-06-30 19:46:48,182 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:52,185 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:52,617 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:52,617 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:52,618 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:52,618 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:53,187 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:46:58,197 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 2
2016-06-30 19:46:58,207 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:46:58,207 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:46:58,208 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:46:58,208 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:46:59,492 INFO org.apache.hadoop.yarn.util.AbstractLivelinessMonitor: Expired:appattempt_1467314892573_0008_000002 Timed out after 10 secs
2016-06-30 19:46:59,492 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: Updating application attempt appattempt_1467314892573_0008_000002 with final state: FAILED, and exit status: -1000
2016-06-30 19:46:59,492 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from LAUNCHED to FINAL_SAVING
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Unregistering app attempt : appattempt_1467314892573_0008_000002
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Application finished, removing password for appattempt_1467314892573_0008_000002
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0008_000002 State change from FINAL_SAVING to FAILED
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: The number of failed attempts is 2. The max attempts is 2
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Updating application application_1467314892573_0008 with final state: FAILED
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0008 State change from ACCEPTED to FINAL_SAVING
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application appattempt_1467314892573_0008_000002 is done. finalState=FAILED
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: Updating info for app: application_1467314892573_0008
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Application application_1467314892573_0008 failed 2 times due to ApplicationMaster for attempt appattempt_1467314892573_0008_000002 timed out. Failing the application.
2016-06-30 19:46:59,493 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: container_1467314892573_0008_02_000001 completed with exit status KILL, killing cooresponding mesos task.
2016-06-30 19:46:59,493 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0008 State change from FINAL_SAVING to FAILED
2016-06-30 19:46:59,493 WARN org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=Application Finished - Failed TARGET=RMAppManager RESULT=FAILURE DESCRIPTION=App failed with state: FAILED PERMISSIONS=Application application_1467314892573_0008 failed 2 times due to ApplicationMaster for attempt appattempt_1467314892573_0008_000002 timed out. Failing the application. APPID=application_1467314892573_0008
2016-06-30 19:46:59,494 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0008_02_000001"
killed with status: DRIVER_RUNNING
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAppManager$ApplicationSummary: appId=application_1467314892573_0008,name=QuasiMonteCarlo,user=root,queue=root.root,state=FAILED,trackingUrl=http://master.testing.local:8088/cluster/app/application_1467314892573_0008,appMasterHost=N/A,startTime=1467315992655,finishTime=1467316019493,finalStatus=FAILED,memorySeconds=0,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=MAPREDUCE
2016-06-30 19:46:59,494 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task yarn_Container: [ContainerId: container_1467314892573_0008_02_000001, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0 cpu and 0 mem.
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0008_02_000001 Container Transitioned from RUNNING to KILLED
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Completed container: container_1467314892573_0008_02_000001 in state: KILLED event:KILL
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Released Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0008 CONTAINERID=container_1467314892573_0008_02_000001
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Released container container_1467314892573_0008_02_000001 of capacity <memory:0, vCores:0> on host slave2:24679, which currently has 0 containers, <memory:0, vCores:0> used and <memory:0, vCores:0> available, release resources=true
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application attempt appattempt_1467314892573_0008_000002 released container container_1467314892573_0008_02_000001 on node: host: slave2:24679 #containers=0 available=<memory:0, vCores:0> used=<memory:0, vCores:0> with event: KILL
2016-06-30 19:46:59,494 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AppSchedulingInfo: Application application_1467314892573_0008 requests cleared
2016-06-30 19:46:59,497 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Cleaning master appattempt_1467314892573_0008_000002
2016-06-30 19:46:59,498 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_02_000001 not found, status: TASK_LOST
2016-06-30 19:47:01,514 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0008_02_000001 not found, status: TASK_FINISHED
2016-06-30 19:47:01,522 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Null container completed...
2016-06-30 19:47:01,523 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Null container completed...
2016-06-30 19:47:04,202 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 2
2016-06-30 19:47:04,528 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:04,528 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:47:04,528 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:47:04,528 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:47:09,213 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:10,213 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:10,562 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:10,564 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:47:10,598 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:47:10,602 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:47:11,963 INFO org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Allocated new applicationId: 9
2016-06-30 19:47:13,081 INFO org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Application with id 9 submitted by user root
2016-06-30 19:47:13,081 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root IP=10.0.5.3 OPERATION=Submit Application Request TARGET=ClientRMService RESULT=SUCCESS APPID=application_1467314892573_0009
2016-06-30 19:47:13,081 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Storing application with id application_1467314892573_0009
2016-06-30 19:47:13,081 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0009 State change from NEW to NEW_SAVING
2016-06-30 19:47:13,082 INFO org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: Storing info for app: application_1467314892573_0009
2016-06-30 19:47:13,082 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0009 State change from NEW_SAVING to SUBMITTED
2016-06-30 19:47:13,082 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Accepted application application_1467314892573_0009 from user: root, in queue: default, currently num of applications: 1
2016-06-30 19:47:13,084 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0009 State change from SUBMITTED to ACCEPTED
2016-06-30 19:47:13,084 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: Registering app attempt : appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,084 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from NEW to SUBMITTED
2016-06-30 19:47:13,084 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Added Application Attempt appattempt_1467314892573_0009_000001 to scheduler from user: root
2016-06-30 19:47:13,087 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from SUBMITTED to SCHEDULED
2016-06-30 19:47:13,501 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000001 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:47:13,501 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000001
2016-06-30 19:47:13,501 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0009_01_000001 of capacity <memory:0, vCores:0> on host slave1:27152, which has 1 containers, <memory:0, vCores:0> used and <memory:4096, vCores:4> available after allocation
2016-06-30 19:47:13,502 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Sending NMToken for nodeId : slave1:27152 for container : container_1467314892573_0009_01_000001
2016-06-30 19:47:13,503 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000001 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:47:13,503 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Clear node set for appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,503 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: Storing attempt: AppId: application_1467314892573_0009 AttemptId: appattempt_1467314892573_0009_000001 MasterContainer: Container: [ContainerId: container_1467314892573_0009_01_000001, NodeId: slave1:27152, NodeHttpAddress: slave1:29830, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.4:27152 }, ]
2016-06-30 19:47:13,503 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from SCHEDULED to ALLOCATED_SAVING
2016-06-30 19:47:13,503 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from ALLOCATED_SAVING to ALLOCATED
2016-06-30 19:47:13,504 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Launching masterappattempt_1467314892573_0009_000001
2016-06-30 19:47:13,506 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Setting up container Container: [ContainerId: container_1467314892573_0009_01_000001, NodeId: slave1:27152, NodeHttpAddress: slave1:29830, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.4:27152 }, ] for AM appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,506 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Command to launch container container_1467314892573_0009_01_000001 : $JAVA_HOME/bin/java -Djava.io.tmpdir=$PWD/tmp -Dlog4j.configuration=container-log4j.properties -Dyarn.app.container.log.dir=<LOG_DIR> -Dyarn.app.container.log.filesize=0 -Dhadoop.root.logger=INFO,CLA -Dhadoop.root.logfile=syslog -Xmx1024m org.apache.hadoop.mapreduce.v2.app.MRAppMaster 1><LOG_DIR>/stdout 2><LOG_DIR>/stderr
2016-06-30 19:47:13,507 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Create AMRMToken for ApplicationAttempt: appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,507 INFO org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: Creating password for appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,544 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000001 not found, status: TASK_RUNNING
2016-06-30 19:47:13,551 INFO org.apache.hadoop.yarn.server.resourcemanager.amlauncher.AMLauncher: Done launching container Container: [ContainerId: container_1467314892573_0009_01_000001, NodeId: slave1:27152, NodeHttpAddress: slave1:29830, Resource: <memory:0, vCores:0>, Priority: 0, Token: Token { kind: ContainerToken, service: 10.0.5.4:27152 }, ] for AM appattempt_1467314892573_0009_000001
2016-06-30 19:47:13,552 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from ALLOCATED to LAUNCHED
2016-06-30 19:47:14,223 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:14,508 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000001 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:47:16,227 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:16,650 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:16,651 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:47:16,651 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:47:16,651 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:47:19,327 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:22,332 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:22,495 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for appattempt_1467314892573_0009_000001 (auth:SIMPLE)
2016-06-30 19:47:22,527 INFO org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: AM registration appattempt_1467314892573_0009_000001
2016-06-30 19:47:22,534 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root IP=10.0.5.4 OPERATION=Register App Master TARGET=ApplicationMasterService RESULT=SUCCESS APPID=application_1467314892573_0009 APPATTEMPTID=appattempt_1467314892573_0009_000001
2016-06-30 19:47:22,539 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: appattempt_1467314892573_0009_000001 State change from LAUNCHED to RUNNING
2016-06-30 19:47:22,539 INFO org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: application_1467314892573_0009 State change from ACCEPTED to RUNNING
2016-06-30 19:47:22,671 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:22,672 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:47:22,672 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:47:22,673 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:0, vCores:0>
2016-06-30 19:47:24,334 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:24,552 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000002 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:47:24,552 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000002
2016-06-30 19:47:24,552 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0009_01_000002 of capacity <memory:2048, vCores:1> on host slave1:27152, which has 2 containers, <memory:2048, vCores:1> used and <memory:2048, vCores:3> available after allocation
2016-06-30 19:47:24,671 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Sending NMToken for nodeId : slave1:27152 for container : container_1467314892573_0009_01_000002
2016-06-30 19:47:24,672 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000002 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:47:24,922 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000002 not found, status: TASK_RUNNING
2016-06-30 19:47:25,566 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000002 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:47:25,567 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000003 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:47:25,567 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000003
2016-06-30 19:47:25,567 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0009_01_000003 of capacity <memory:2048, vCores:1> on host slave1:27152, which has 3 containers, <memory:4096, vCores:2> used and <memory:0, vCores:2> available after allocation
2016-06-30 19:47:25,811 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000003 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:47:25,955 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000003 not found, status: TASK_RUNNING
2016-06-30 19:47:26,589 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000003 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:47:26,603 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Making reservation: node=slave1 app_id=application_1467314892573_0009
2016-06-30 19:47:26,604 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000004 Container Transitioned from NEW to RESERVED
2016-06-30 19:47:26,604 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSSchedulerNode: Reserved container container_1467314892573_0009_01_000004 on node host: slave1:27152 #containers=3 available=<memory:0, vCores:2> used=<memory:4096, vCores:2> for application org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt@82f920c
2016-06-30 19:47:28,340 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:28,719 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:28,719 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:0, vCores:0>, to: <memory:4637, vCores:6>
2016-06-30 19:47:28,727 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000005 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:47:28,727 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000005
2016-06-30 19:47:28,727 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0009_01_000005 of capacity <memory:2048, vCores:1> on host slave2:24679, which has 1 containers, <memory:2048, vCores:1> used and <memory:2589, vCores:5> available after allocation
2016-06-30 19:47:28,727 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:2048, vCores:1>
2016-06-30 19:47:28,735 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:2048, vCores:1>
2016-06-30 19:47:28,772 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000005 not found, status: TASK_RUNNING
2016-06-30 19:47:28,869 INFO org.apache.hadoop.yarn.server.resourcemanager.security.NMTokenSecretManagerInRM: Sending NMToken for nodeId : slave2:24679 for container : container_1467314892573_0009_01_000005
2016-06-30 19:47:28,887 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000005 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:47:29,180 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000005 not found, status: TASK_RUNNING
2016-06-30 19:47:29,348 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:29,745 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000005 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:47:29,745 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Making reservation: node=slave2 app_id=application_1467314892573_0009
2016-06-30 19:47:29,745 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000006 Container Transitioned from NEW to RESERVED
2016-06-30 19:47:29,745 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSSchedulerNode: Reserved container container_1467314892573_0009_01_000006 on node host: slave2:24679 #containers=1 available=<memory:0, vCores:0> used=<memory:2048, vCores:1> for application org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt@82f920c
2016-06-30 19:47:34,352 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:34,826 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:34,826 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:2048, vCores:1>, to: <memory:4637, vCores:6>
2016-06-30 19:47:34,831 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000006 Container Transitioned from NEW to ALLOCATED
2016-06-30 19:47:34,832 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Allocated Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000006
2016-06-30 19:47:34,832 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Application application_1467314892573_0009 unreserved on node host: slave2:24679 #containers=1 available=<memory:2589, vCores:5> used=<memory:2048, vCores:1>, currently has 1 at priority 20; currentReservation <memory:2048, vCores:1>
2016-06-30 19:47:34,832 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Assigned container container_1467314892573_0009_01_000006 of capacity <memory:2048, vCores:1> on host slave2:24679, which has 2 containers, <memory:4096, vCores:2> used and <memory:541, vCores:4> available after allocation
2016-06-30 19:47:34,832 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4096, vCores:2>
2016-06-30 19:47:34,834 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:4096, vCores:2>
2016-06-30 19:47:34,898 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000006 not found, status: TASK_RUNNING
2016-06-30 19:47:35,303 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000006 Container Transitioned from ALLOCATED to ACQUIRED
2016-06-30 19:47:35,764 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Releasing reservation that cannot be satisfied for application appattempt_1467314892573_0009_000001 on node host: slave1:27152 #containers=3 available=<memory:0, vCores:2> used=<memory:4096, vCores:2>
2016-06-30 19:47:35,764 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Application application_1467314892573_0009 unreserved on node host: slave1:27152 #containers=3 available=<memory:0, vCores:2> used=<memory:4096, vCores:2>, currently has 0 at priority 20; currentReservation <memory:0, vCores:0>
2016-06-30 19:47:36,236 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000006 Container Transitioned from ACQUIRED to RUNNING
2016-06-30 19:47:36,271 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000006 not found, status: TASK_RUNNING
2016-06-30 19:47:36,380 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:36,410 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AppSchedulingInfo: checking for deactivate of application :application_1467314892573_0009
2016-06-30 19:47:39,510 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000002 not found, status: TASK_FINISHED
2016-06-30 19:47:40,337 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000002 Container Transitioned from RUNNING to COMPLETED
2016-06-30 19:47:40,337 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Completed container: container_1467314892573_0009_01_000002 in state: COMPLETED event:FINISHED
2016-06-30 19:47:40,337 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Released Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000002
2016-06-30 19:47:40,337 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Released container container_1467314892573_0009_01_000002 of capacity <memory:2048, vCores:1> on host slave1:27152, which currently has 2 containers, <memory:2048, vCores:1> used and <memory:2048, vCores:3> available, release resources=true
2016-06-30 19:47:40,337 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application attempt appattempt_1467314892573_0009_000001 released container container_1467314892573_0009_01_000002 on node: host: slave1:27152 #containers=2 available=<memory:2048, vCores:3> used=<memory:2048, vCores:1> with event: FINISHED
2016-06-30 19:47:40,356 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:41,276 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4637, vCores:6>
2016-06-30 19:47:41,278 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4096, vCores:2>, to: <memory:4637, vCores:6>
2016-06-30 19:47:41,278 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:4096, vCores:2>
2016-06-30 19:47:41,279 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler: Update resource on node: slave2 from: <memory:4637, vCores:6>, to: <memory:4096, vCores:2>
2016-06-30 19:47:42,744 INFO org.apache.myriad.scheduler.event.handlers.ResourceOffersEventHandler: Received offers 1
2016-06-30 19:47:43,702 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Making reservation: node=slave1 app_id=application_1467314892573_0009
2016-06-30 19:47:43,702 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000007 Container Transitioned from NEW to RESERVED
2016-06-30 19:47:43,702 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSSchedulerNode: Reserved container container_1467314892573_0009_01_000007 on node host: slave1:27152 #containers=2 available=<memory:2048, vCores:3> used=<memory:2048, vCores:1> for application org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt@82f920c
2016-06-30 19:47:43,756 INFO org.apache.hadoop.yarn.util.AbstractLivelinessMonitor: Expired:slave2:24679 Timed out after 2 secs
2016-06-30 19:47:43,771 INFO org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: Deactivating Node slave2:24679 as it is now LOST
2016-06-30 19:47:43,771 INFO org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: slave2:24679 Node Transitioned from RUNNING to LOST
2016-06-30 19:47:43,773 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: container_1467314892573_0009_01_000005 completed with exit status KILL, killing cooresponding mesos task.
2016-06-30 19:47:43,773 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0009_01_000005"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:43,773 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:2048, vCores:1>
2016-06-30 19:47:43,909 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task yarn_Container: [ContainerId: container_1467314892573_0009_01_000005, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:2048, vCores:1>, Priority: 20, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0 cpu and 1 mem.
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000005 Container Transitioned from RUNNING to KILLED
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Completed container: container_1467314892573_0009_01_000005 in state: KILLED event:KILL
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Released Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000005
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Released container container_1467314892573_0009_01_000005 of capacity <memory:2048, vCores:1> on host slave2:24679, which currently has 1 containers, <memory:2048, vCores:1> used and <memory:2048, vCores:1> available, release resources=true
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application attempt appattempt_1467314892573_0009_000001 released container container_1467314892573_0009_01_000005 on node: host: slave2:24679 #containers=1 available=<memory:2048, vCores:1> used=<memory:2048, vCores:1> with event: KILL
2016-06-30 19:47:43,909 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: Node not found resyncing slave2:24679
2016-06-30 19:47:43,909 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: container_1467314892573_0009_01_000006 completed with exit status KILL, killing cooresponding mesos task.
2016-06-30 19:47:43,909 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0009_01_000006"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:43,909 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Setting capacity for node slave2 to <memory:0, vCores:0>
2016-06-30 19:47:43,952 INFO org.apache.myriad.scheduler.fgs.YarnNodeCapacityManager: Removed task yarn_Container: [ContainerId: container_1467314892573_0009_01_000006, NodeId: slave2:24679, NodeHttpAddress: slave2:23177, Resource: <memory:2048, vCores:1>, Priority: 20, Token: Token { kind: ContainerToken, service: 10.0.5.5:24679 }, ] with exit status freeing 0 cpu and 1 mem.
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.RMContainerImpl: container_1467314892573_0009_01_000006 Container Transitioned from RUNNING to KILLED
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FSAppAttempt: Completed container: container_1467314892573_0009_01_000006 in state: KILLED event:KILL
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=root OPERATION=AM Released Container TARGET=SchedulerApp RESULT=SUCCESS APPID=application_1467314892573_0009 CONTAINERID=container_1467314892573_0009_01_000006
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.SchedulerNode: Released container container_1467314892573_0009_01_000006 of capacity <memory:2048, vCores:1> on host slave2:24679, which currently has 0 containers, <memory:0, vCores:0> used and <memory:4096, vCores:2> available, release resources=true
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Application attempt appattempt_1467314892573_0009_000001 released container container_1467314892573_0009_01_000006 on node: host: slave2:24679 #containers=0 available=<memory:4096, vCores:2> used=<memory:0, vCores:0> with event: KILL
2016-06-30 19:47:43,952 INFO org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler: Removed node slave2:24679 cluster capacity: <memory:4096, vCores:4>
2016-06-30 19:47:43,953 FATAL org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Error in handling event type NODE_RESOURCE_UPDATE to the scheduler
java.lang.NullPointerException
at org.apache.hadoop.yarn.server.resourcemanager.scheduler.AbstractYarnScheduler.updateNodeResource(AbstractYarnScheduler.java:563)
at org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler.updateNodeResource(FairScheduler.java:1652)
at org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler.handle(FairScheduler.java:1222)
at org.apache.myriad.scheduler.yarn.MyriadFairScheduler.handle(MyriadFairScheduler.java:102)
at org.apache.myriad.scheduler.yarn.MyriadFairScheduler.handle(MyriadFairScheduler.java:42)
at org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher$EventProcessor.run(ResourceManager.java:671)
at java.lang.Thread.run(Thread.java:745)
2016-06-30 19:47:43,972 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Exiting, bbye..
2016-06-30 19:47:44,560 ERROR org.apache.hadoop.security.token.delegation.AbstractDelegationTokenSecretManager: ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
2016-06-30 19:47:47,494 INFO org.apache.hadoop.yarn.util.AbstractLivelinessMonitor: Expired:slave1:27152 Timed out after 2 secs
2016-06-30 19:47:47,547 INFO org.apache.myriad.scheduler.MyriadDriverManager: Killing task value: "yarn_container_1467314892573_0009_01_000006"
2016-06-30 19:47:47,547 INFO org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: Deactivating Node slave1:27152 as it is now LOST
2016-06-30 19:47:47,547 INFO org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: slave1:27152 Node Transitioned from RUNNING to LOST
2016-06-30 19:47:47,547 INFO org.apache.hadoop.yarn.util.RackResolver: Resolved slave2 to /default-rack
2016-06-30 19:47:47,547 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0009_01_000006"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:47,547 INFO org.apache.myriad.scheduler.MyriadDriverManager: Task value: "yarn_container_1467314892573_0009_01_000006"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:47,547 WARN org.apache.myriad.scheduler.TaskTerminator: NodeTask with taskId: value: "yarn_container_1467314892573_0009_01_000006"
does not exist
2016-06-30 19:47:47,547 INFO org.apache.myriad.scheduler.MyriadDriverManager: Killing task value: "yarn_container_1467314892573_0009_01_000005"
2016-06-30 19:47:47,548 INFO org.apache.myriad.scheduler.MyriadDriver: Task value: "yarn_container_1467314892573_0009_01_000005"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:47,548 INFO org.apache.myriad.scheduler.MyriadDriverManager: Task value: "yarn_container_1467314892573_0009_01_000005"
killed with status: DRIVER_RUNNING
2016-06-30 19:47:47,548 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000005 not found, status: TASK_KILLED
2016-06-30 19:47:47,548 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000006 not found, status: TASK_KILLED
2016-06-30 19:47:47,548 WARN org.apache.myriad.scheduler.TaskTerminator: NodeTask with taskId: value: "yarn_container_1467314892573_0009_01_000005"
does not exist
2016-06-30 19:47:47,551 INFO org.mortbay.log: Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@master.testing.local:8088
2016-06-30 19:47:47,573 INFO org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: slave2:24679 Node Transitioned from NEW to RUNNING
2016-06-30 19:47:47,573 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000006 not found, status: TASK_LOST
2016-06-30 19:47:47,574 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000005 not found, status: TASK_LOST
2016-06-30 19:47:47,578 INFO org.apache.hadoop.ipc.Server: Stopping server on 8032
2016-06-30 19:47:47,657 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 8032
2016-06-30 19:47:47,658 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2016-06-30 19:47:47,924 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: Node not found resyncing slave1:27152
2016-06-30 19:47:47,936 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: received container statuses on node manager register :[container_id { app_attempt_id { application_id { id: 9 cluster_timestamp: 1467314892573 } attemptId: 1 } id: 5 } container_state: C_RUNNING resource { memory: 2048 virtual_cores: 1 } priority { priority: 20 } diagnostics: "" container_exit_status: -1000 creation_time: 1467316048727, container_id { app_attempt_id { application_id { id: 9 cluster_timestamp: 1467314892573 } attemptId: 1 } id: 6 } container_state: C_RUNNING resource { memory: 2048 virtual_cores: 1 } priority { priority: 20 } diagnostics: "" container_exit_status: -1000 creation_time: 1467316054831]
2016-06-30 19:47:47,936 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: NodeManager from node slave2(cmPort: 24679 httpPort: 23177) registered with capability: <memory:0, vCores:0>, assigned nodeId slave2:24679
2016-06-30 19:47:47,967 INFO org.apache.hadoop.ipc.Server: Stopping server on 8033
2016-06-30 19:47:48,101 WARN org.apache.myriad.scheduler.event.handlers.StatusUpdateEventHandler: Task: yarn_container_1467314892573_0009_01_000003 not found, status: TASK_FINISHED
2016-06-30 19:47:48,105 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 8033
2016-06-30 19:47:48,105 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2016-06-30 19:47:48,124 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Transitioning to standby state
2016-06-30 19:47:48,128 WARN org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher: org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher$LauncherThread interrupted. Returning.
2016-06-30 19:47:48,145 INFO org.apache.hadoop.ipc.Server: Stopping server on 8030
2016-06-30 19:47:48,197 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 8030
2016-06-30 19:47:48,198 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2016-06-30 19:47:48,236 INFO org.apache.hadoop.ipc.Server: Stopping server on 8031
2016-06-30 19:47:48,268 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server listener on 8031
2016-06-30 19:47:48,268 INFO org.apache.hadoop.ipc.Server: Stopping IPC Server Responder
2016-06-30 19:47:48,269 INFO org.apache.hadoop.yarn.util.AbstractLivelinessMonitor: NMLivelinessMonitor thread interrupted
