hadoop-yarn-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "zhihai xu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (YARN-2871) TestRMRestart#testRMRestartGetApplicationList sometime fails in trunk
Date Tue, 23 Jun 2015 08:57:02 GMT

    [ https://issues.apache.org/jira/browse/YARN-2871?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14597368#comment-14597368
] 

zhihai xu commented on YARN-2871:
---------------------------------

I can work on this issue, Based on the failure logs https://builds.apache.org/job/PreCommit-YARN-Build/8323/testReport/org.apache.hadoop.yarn.server.resourcemanager/TestRMRestart/testRMRestartGetApplicationList_1_/,
the root cause of this issue is a race condition in the test. {{logApplicationSummary}} is
called when RMAppManager handles APP_COMPLETED RMAppManagerEvent. RMAppImpl sends APP_COMPLETED
event to AsyncDispatcher thread. If AsyncDispatcher thread doesn't process APP_COMPLETED event
on time, then the test will fail. I think If we add some delay before the verification, it
will fix this issue.
The important logs from failed test:
{code}
2015-06-23 06:06:20,484 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572))
- Recovery started
2015-06-23 06:06:20,484 INFO  [Thread-693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178))
- recovering RMDelegationTokenSecretManager.
2015-06-23 06:06:20,484 INFO  [Thread-693] resourcemanager.RMAppManager (RMAppManager.java:recover(425))
- Recovering 3 applications
2015-06-23 06:06:20,485 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) -
Processing event for application_1435039562888_0001 of type RECOVER
2015-06-23 06:06:20,485 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) -
Recovering app: application_1435039562888_0001 with 1 attempts and final state = FINISHED
2015-06-23 06:06:20,485 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435039562888_0001_000001 with final state: FINISHED
2015-06-23 06:06:20,485 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435039562888_0001_000001 of type RECOVER
2015-06-23 06:06:20,486 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435039562888_0001_000001 State change from NEW to FINISHED
2015-06-23 06:06:20,486 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) -
application_1435039562888_0001 State change from NEW to FINISHED
2015-06-23 06:06:20,486 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) -
Processing event for application_1435039562888_0002 of type RECOVER
2015-06-23 06:06:20,486 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) -
Recovering app: application_1435039562888_0002 with 1 attempts and final state = FAILED
2015-06-23 06:06:20,487 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435039562888_0002_000001 with final state: FAILED
2015-06-23 06:06:20,487 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435039562888_0002_000001 of type RECOVER
2015-06-23 06:06:20,487 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435039562888_0002_000001 State change from NEW to FAILED
2015-06-23 06:06:20,487 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) -
application_1435039562888_0002 State change from NEW to FAILED
2015-06-23 06:06:20,488 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) -
Processing event for application_1435039562888_0003 of type RECOVER
2015-06-23 06:06:20,488 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) -
Recovering app: application_1435039562888_0003 with 1 attempts and final state = KILLED
2015-06-23 06:06:20,488 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435039562888_0003_000001 with final state: KILLED
2015-06-23 06:06:20,489 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435039562888_0003_000001 of type RECOVER
2015-06-23 06:06:20,489 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435039562888_0003_000001 State change from NEW to KILLED
2015-06-23 06:06:20,489 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) -
application_1435039562888_0003 State change from NEW to KILLED
2015-06-23 06:06:20,489 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579))
- Recovery ended
2015-06-23 06:06:20,489 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115))
- RMActiveServices: starting services, size=15
2015-06-23 06:06:20,489 INFO  [Thread-693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105))
- Rolling master-key for container-tokens
2015-06-23 06:06:20,489 INFO  [Thread-693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110))
- Going to activate master-key with key-id -644495556 in 900000ms
2015-06-23 06:06:20,489 INFO  [Thread-693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95))
- Rolling master-key for nm-tokens
2015-06-23 06:06:20,489 INFO  [Thread-693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100))
- Going to activate master-key with key-id 1471860283 in 900000ms
2015-06-23 06:06:20,490 INFO  [Thread-693] delegation.AbstractDelegationTokenSecretManager
(AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master
key for generating delegation tokens
2015-06-23 06:06:20,490 INFO  [Thread-693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87))
- storing master key with keyID 3
2015-06-23 06:06:20,490 DEBUG [Thread-693] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832))
- Processing event of type STORE_MASTERKEY
2015-06-23 06:06:20,490 INFO  [Thread-693] recovery.RMStateStore (RMStateStore.java:transition(365))
- Storing RMDTMasterKey.
2015-06-23 06:06:20,490 INFO  [Thread-693] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213))
- Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3
2015-06-23 06:06:20,490 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started
2015-06-23 06:06:20,490 INFO  [Thread[Thread-717,5,main]] delegation.AbstractDelegationTokenSecretManager
(AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover
thread, tokenRemoverScanInterval=60 min(s)
2015-06-23 06:06:20,491 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer
is started
2015-06-23 06:06:20,491 INFO  [Thread[Thread-717,5,main]] delegation.AbstractDelegationTokenSecretManager
(AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master
key for generating delegation tokens
2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] security.RMDelegationTokenSecretManager
(RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID
4
2015-06-23 06:06:20,492 DEBUG [Thread[Thread-717,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832))
- Processing event of type STORE_MASTERKEY
2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365))
- Storing RMDTMasterKey.
2015-06-23 06:06:20,492 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service AMLivelinessMonitor is started
2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213))
- Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service AMLivelinessMonitor is started
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services,
size=0
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is
started
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services,
size=0
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is
started
2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started
2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.AllocationFileLoaderService
is started
2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler is started
2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher
is started
2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service NMLivelinessMonitor is started
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher
is started
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service RMActiveServices is started
2015-06-23 06:06:20,495 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049))
- Transitioned to active state
2015-06-23 06:06:20,495 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115))
- ResourceManager: starting services, size=2
2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service Dispatcher is started
2015-06-23 06:06:20,496 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0
2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started
2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197))
- Service ResourceManager is started
2015-06-23 06:06:20,496 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-23 06:06:20,496 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003
owned by user
2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,497 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002
owned by user
2015-06-23 06:06:20,497 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0001
of type APP_COMPLETED
2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,498 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Succeeded
TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435039562888_0001
2015-06-23 06:06:20,498 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001
owned by user
2015-06-23 06:06:20,498 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,499 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0001,name=name,user=user,queue=default,state=FINISHED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0001/,appMasterHost=N/A,startTime=1435039562899,finishTime=1435039567908,finalStatus=SUCCEEDED,memorySeconds=3586,vcoreSeconds=3,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-23 06:06:20,499 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003
owned by user
2015-06-23 06:06:20,499 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-23 06:06:20,500 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0002
of type APP_COMPLETED
2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,500 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002
owned by user
2015-06-23 06:06:20,500 WARN  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logFailure(263)) - USER=user	OPERATION=Application Finished - Failed	TARGET=RMAppManager
RESULT=FAILURE	DESCRIPTION=App failed with state: FAILED	PERMISSIONS=Application application_1435039562888_0002
failed 1 times due to AM Container for appattempt_1435039562888_0002_000001 exited with  exitCode:
0
Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking
page: http://asf906.gq1.ygridcore.net:8088/cluster/app/application_1435039562888_0002 Then
click on links to logs of each attempt.
. Failing the application.	APPID=application_1435039562888_0002
2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,501 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
2015-06-23 06:06:20,501 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001
owned by user
2015-06-23 06:06:20,501 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0002,name=name,user=user,queue=default,state=FAILED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0002/,appMasterHost=N/A,startTime=1435039569909,finishTime=1435039573919,finalStatus=FAILED,memorySeconds=2564,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0003
of type APP_COMPLETED
2015-06-23 06:06:20,502 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Killed	TARGET=RMAppManager
RESULT=SUCCESS	APPID=application_1435039562888_0003
2015-06-23 06:06:20,503 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435039562888_0003_000001
2015-06-23 06:06:20,503 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0003,name=name,user=user,queue=default,state=KILLED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0003/,appMasterHost=N/A,startTime=1435039574916,finishTime=1435039578925,finalStatus=KILLED,memorySeconds=6,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-23 06:06:20,508 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: ResourceManager entered state STOPPED
{code}
>From above logs, you can see RMAppManager processing event for application_1435039562888_0003
of type APP_COMPLETED is after all Verifying access-type VIEW_APP which is called from {{rm2.getClientRMService().getApplications}}.

The corresponding logs from succeeded test:
{code}
2015-06-22 23:45:01,319 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572))
- Recovery started
2015-06-22 23:45:01,320 INFO  [Thread-1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178))
- recovering RMDelegationTokenSecretManager.
2015-06-22 23:45:01,348 INFO  [Thread-1] resourcemanager.RMAppManager (RMAppManager.java:recover(425))
- Recovering 3 applications
2015-06-22 23:45:01,349 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing
event for application_1435041883856_0001 of type RECOVER
2015-06-22 23:45:01,349 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering
app: application_1435041883856_0001 with 1 attempts and final state = FINISHED
2015-06-22 23:45:01,350 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435041883856_0001_000001 with final state: FINISHED
2015-06-22 23:45:01,351 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435041883856_0001_000001 of type RECOVER
2015-06-22 23:45:01,351 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435041883856_0001_000001 State change from NEW to FINISHED
2015-06-22 23:45:01,351 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0001
State change from NEW to FINISHED
2015-06-22 23:45:01,352 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing
event for application_1435041883856_0002 of type RECOVER
2015-06-22 23:45:01,352 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering
app: application_1435041883856_0002 with 1 attempts and final state = FAILED
2015-06-22 23:45:01,353 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435041883856_0002_000001 with final state: FAILED
2015-06-22 23:45:01,353 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435041883856_0002_000001 of type RECOVER
2015-06-22 23:45:01,354 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435041883856_0002_000001 State change from NEW to FAILED
2015-06-22 23:45:01,354 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0002
State change from NEW to FAILED
2015-06-22 23:45:01,354 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing
event for application_1435041883856_0003 of type RECOVER
2015-06-22 23:45:01,354 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering
app: application_1435041883856_0003 with 1 attempts and final state = KILLED
2015-06-22 23:45:01,355 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827))
- Recovering attempt: appattempt_1435041883856_0003_000001 with final state: KILLED
2015-06-22 23:45:01,356 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781))
- Processing event for appattempt_1435041883856_0003_000001 of type RECOVER
2015-06-22 23:45:01,356 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793))
- appattempt_1435041883856_0003_000001 State change from NEW to KILLED
2015-06-22 23:45:01,356 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0003
State change from NEW to KILLED
2015-06-22 23:45:01,356 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579))
- Recovery ended
2015-06-22 23:45:01,356 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115))
- RMActiveServices: starting services, size=15
2015-06-22 23:45:01,356 INFO  [Thread-1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105))
- Rolling master-key for container-tokens
2015-06-22 23:45:01,356 INFO  [Thread-1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110))
- Going to activate master-key with key-id 344850257 in 900000ms
2015-06-22 23:45:01,357 INFO  [Thread-1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95))
- Rolling master-key for nm-tokens
2015-06-22 23:45:01,357 INFO  [Thread-1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100))
- Going to activate master-key with key-id -867844649 in 900000ms
2015-06-22 23:45:01,357 INFO  [Thread-1] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336))
- Updating the current master key for generating delegation tokens
2015-06-22 23:45:01,357 INFO  [Thread-1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87))
- storing master key with keyID 3
2015-06-22 23:45:01,357 DEBUG [Thread-1] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832))
- Processing event of type STORE_MASTERKEY
2015-06-22 23:45:01,357 INFO  [Thread-1] recovery.RMStateStore (RMStateStore.java:transition(365))
- Storing RMDTMasterKey.
2015-06-22 23:45:01,357 INFO  [Thread-1] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213))
- Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3
2015-06-22 23:45:01,358 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started
2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] delegation.AbstractDelegationTokenSecretManager
(AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover
thread, tokenRemoverScanInterval=60 min(s)
2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] delegation.AbstractDelegationTokenSecretManager
(AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master
key for generating delegation tokens
2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] security.RMDelegationTokenSecretManager
(RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID
4
2015-06-22 23:45:01,358 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer
is started
2015-06-22 23:45:01,359 DEBUG [Thread[Thread-21,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832))
- Processing event of type STORE_MASTERKEY
2015-06-22 23:45:01,359 INFO  [Thread[Thread-21,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365))
- Storing RMDTMasterKey.
2015-06-22 23:45:01,359 INFO  [Thread[Thread-21,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213))
- Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4
2015-06-22 23:45:01,359 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service AMLivelinessMonitor is started
2015-06-22 23:45:01,359 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service AMLivelinessMonitor is started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services,
size=0
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is
started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services,
size=0
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is
started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler
is started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher
is started
2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service NMLivelinessMonitor is started
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher
is started
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service RMActiveServices is started
2015-06-22 23:45:01,361 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049))
- Transitioned to active state
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115))
- ResourceManager: starting services, size=2
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service Dispatcher is started
2015-06-22 23:45:01,361 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-22 23:45:01,361 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0
2015-06-22 23:45:01,362 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started
2015-06-22 23:45:01,362 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197))
- Service ResourceManager is started
2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0001
of type APP_COMPLETED
2015-06-22 23:45:01,363 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Succeeded
TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435041883856_0001
2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,364 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0001,name=name,user=user,queue=default,state=FINISHED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0001/,appMasterHost=N/A,startTime=1435041884030,finishTime=1435041888611,finalStatus=SUCCEEDED,memorySeconds=112,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0002
of type APP_COMPLETED
2015-06-22 23:45:01,365 WARN  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logFailure(263)) - USER=user	OPERATION=Application Finished - Failed	TARGET=RMAppManager
RESULT=FAILURE	DESCRIPTION=App failed with state: FAILED	PERMISSIONS=Application application_1435041883856_0002
failed 1 times due to AM Container for appattempt_1435041883856_0002_000001 exited with  exitCode:
0
Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking
page: http://zxu-mbp.local:8088/cluster/app/application_1435041883856_0002 Then click on links
to logs of each attempt.
. Failing the application.	APPID=application_1435041883856_0002
2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,366 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0002,name=name,user=user,queue=default,state=FAILED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0002/,appMasterHost=N/A,startTime=1435041890627,finishTime=1435041894642,finalStatus=FAILED,memorySeconds=2565,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167))
- Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType:
APP_COMPLETED
2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager
(RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0003
of type APP_COMPLETED
2015-06-22 23:45:01,367 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger
(RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Killed	TARGET=RMAppManager
RESULT=SUCCESS	APPID=application_1435041883856_0003
2015-06-22 23:45:01,367 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler
(AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown
attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,368 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary
(RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0003,name=name,user=user,queue=default,state=KILLED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0003/,appMasterHost=N/A,startTime=1435041895640,finishTime=1435041899657,finalStatus=KILLED,memorySeconds=18,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\,
vCores:0>,applicationType=myType
2015-06-22 23:45:01,368 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001
owned by user
2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,376 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002
owned by user
2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,378 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003
owned by user
2015-06-22 23:45:01,378 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,379 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,379 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,382 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001
owned by user
2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
2015-06-22 23:45:01,384 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002
owned by user
2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
2015-06-22 23:45:01,386 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102))
- Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003
owned by user
2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255))
- Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
2015-06-22 23:45:01,395 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: ResourceManager entered state STOPPED
{code}
>From above logs, you can see RMAppManager processing event for application_1435041883856_0003
of type APP_COMPLETED is before Verifying access-type VIEW_APP.

> TestRMRestart#testRMRestartGetApplicationList sometime fails in trunk
> ---------------------------------------------------------------------
>
>                 Key: YARN-2871
>                 URL: https://issues.apache.org/jira/browse/YARN-2871
>             Project: Hadoop YARN
>          Issue Type: Test
>            Reporter: Ted Yu
>            Assignee: zhihai xu
>            Priority: Minor
>
> From trunk build #746 (https://builds.apache.org/job/Hadoop-Yarn-trunk/746):
> {code}
> Failed tests:
>   TestRMRestart.testRMRestartGetApplicationList:957
> rMAppManager.logApplicationSummary(
>     isA(org.apache.hadoop.yarn.api.records.ApplicationId)
> );
> Wanted 3 times:
> -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:957)
> But was 2 times:
> -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66)
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message