hadoop-yarn-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Bibin A Chundatt (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (YARN-5240) TestSystemMetricsPublisher.testPublishApplicationMetrics fails in trunk
Date Thu, 16 Jun 2016 15:29:05 GMT

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

Bibin A Chundatt commented on YARN-5240:
----------------------------------------

Entity entry details are as below . The test code is not waiting for YARN_APPLICATION_ACLS_UPDATED
to be completed even after having check based on entity size.
{noformat}
	Line 1540: 2016-06-16 02:27:12,027 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher entered
state INITED
	Line 1544: 2016-06-16 02:27:12,041 INFO  [main] event.AsyncDispatcher (AsyncDispatcher.java:register(209))
- Registering class org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsEventType
for class org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$ForwardingEventHandler
	Line 1545: 2016-06-16 02:27:12,041 INFO  [main] event.AsyncDispatcher (AsyncDispatcher.java:register(209))
- Registering class org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsEventType
for class org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$ForwardingEventHandler
	Line 1546: 2016-06-16 02:27:12,042 DEBUG [main] service.CompositeService (CompositeService.java:addService(73))
- Adding service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
	Line 1547: 2016-06-16 02:27:12,042 INFO  [main] metrics.SystemMetricsPublisher (SystemMetricsPublisher.java:serviceInit(96))
- YARN system metrics publishing service is enabled
	Line 1548: 2016-06-16 02:27:12,042 DEBUG [main] service.CompositeService (CompositeService.java:serviceInit(104))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: initing services,
size=2
	Line 1552: 2016-06-16 02:27:12,298 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
entered state INITED
	Line 1553: 2016-06-16 02:27:12,299 DEBUG [main] service.CompositeService (CompositeService.java:serviceInit(104))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher:
initing services, size=2
	Line 1556: 2016-06-16 02:27:12,299 DEBUG [main] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services,
size=2
	Line 1558: 2016-06-16 02:27:12,300 DEBUG [main] service.CompositeService (CompositeService.java:serviceStart(115))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher:
starting services, size=2
	Line 1561: 2016-06-16 02:27:12,301 DEBUG [main] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
is started
	Line 1562: 2016-06-16 02:27:12,301 DEBUG [main] service.AbstractService (AbstractService.java:start(197))
- Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is
started
	Line 1565: 2016-06-16 02:27:12,942 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0001, JSON-style
content: {"events":[{"timestamp":1466024232305,"eventtype":"YARN_APPLICATION_STATE_UPDATED","eventinfo":{"YARN_APPLICATION_STATE":"RUNNING"}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0001","relatedentities":{},"primaryfilters":{},"otherinfo":{}}
	Line 1567: 2016-06-16 02:27:12,945 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0001, JSON-style
content: {"events":[{"timestamp":2147483649,"eventtype":"YARN_APPLICATION_CREATED","eventinfo":{}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0001","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_CALLER_CONTEXT":"context","YARN_APPLICATION_SUBMITTED_TIME":2147483648,"YARN_APPLICATION_NAME":"test
app","YARN_AM_NODE_LABEL_EXPRESSION":"high-mem","YARN_APPLICATION_USER":"test user","YARN_APPLICATION_QUEUE":"test
queue","YARN_APPLICATION_TYPE":"test app type","YARN_APPLICATION_UNMANAGED_APPLICATION":false,"YARN_APPLICATION_PRIORITY":10,"YARN_APP_NODE_LABEL_EXPRESSION":"high-cpu","YARN_APPLICATION_TAGS":["test","tags"]}}
	Line 1769: 2016-06-16 02:27:13,709 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 1771: 2016-06-16 02:27:13,709 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0001, JSON-style
content: {"events":[{"timestamp":4,"eventtype":"YARN_APPLICATION_UPDATED","eventinfo":{"YARN_APPLICATION_QUEUE":"new
test queue","YARN_APPLICATION_PRIORITY":1}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0001","relatedentities":{},"primaryfilters":{},"otherinfo":{}}
	Line 1774: 2016-06-16 02:27:13,711 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 1873: 2016-06-16 02:27:13,836 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 1875: 2016-06-16 02:27:13,837 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0001, JSON-style
content: {"events":[{"timestamp":2147483650,"eventtype":"YARN_APPLICATION_FINISHED","eventinfo":{"YARN_APPLICATION_DIAGNOSTICS_INFO":"test
diagnostics info","YARN_APPLICATION_FINAL_STATUS":"UNDEFINED","YARN_APPLICATION_LATEST_APP_ATTEMPT":"appattempt_0_0001_000001","YARN_APPLICATION_STATE":"FINISHED"}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0001","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_CPU_METRIC":9223372036854775807,"YARN_APPLICATION_MEM_METRIC":2147483647}}
	Line 1976: 2016-06-16 02:27:13,950 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 1978: 2016-06-16 02:27:13,951 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0001, JSON-style
content: {"events":[{"timestamp":4,"eventtype":"YARN_APPLICATION_ACLS_UPDATED","eventinfo":{}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0001","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_VIEW_ACLS":"uers1,user2"}}
	Line 2078: 2016-06-16 02:27:14,077 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 2083: 2016-06-16 02:27:14,088 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0002, JSON-style
content: {"events":[{"timestamp":2147483649,"eventtype":"YARN_APPLICATION_CREATED","eventinfo":{}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0002","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_CALLER_CONTEXT":"context","YARN_APPLICATION_SUBMITTED_TIME":2147483648,"YARN_APPLICATION_NAME":"test
app","YARN_AM_NODE_LABEL_EXPRESSION":"high-mem","YARN_APPLICATION_USER":"test user","YARN_APPLICATION_QUEUE":"test
queue","YARN_APPLICATION_TYPE":"test app type","YARN_APPLICATION_UNMANAGED_APPLICATION":false,"YARN_APPLICATION_PRIORITY":10,"YARN_APP_NODE_LABEL_EXPRESSION":"high-cpu","YARN_APPLICATION_TAGS":["test","tags"]}}
	Line 2084: 2016-06-16 02:27:14,088 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0002, JSON-style
content: {"events":[{"timestamp":1466024232305,"eventtype":"YARN_APPLICATION_STATE_UPDATED","eventinfo":{"YARN_APPLICATION_STATE":"RUNNING"}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0002","relatedentities":{},"primaryfilters":{},"otherinfo":{}}
	Line 2268: 2016-06-16 02:27:14,293 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 2270: 2016-06-16 02:27:14,294 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0002, JSON-style
content: {"events":[{"timestamp":4,"eventtype":"YARN_APPLICATION_UPDATED","eventinfo":{"YARN_APPLICATION_QUEUE":"test
queue","YARN_APPLICATION_PRIORITY":10}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0002","relatedentities":{},"primaryfilters":{},"otherinfo":{}}
	Line 2328: 2016-06-16 02:27:14,377 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 2412: 2016-06-16 02:27:14,452 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 2414: 2016-06-16 02:27:14,453 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0002, JSON-style
content: {"events":[{"timestamp":2147483650,"eventtype":"YARN_APPLICATION_FINISHED","eventinfo":{"YARN_APPLICATION_DIAGNOSTICS_INFO":"test
diagnostics info","YARN_APPLICATION_FINAL_STATUS":"UNDEFINED","YARN_APPLICATION_LATEST_APP_ATTEMPT":"appattempt_0_0002_000001","YARN_APPLICATION_STATE":"FINISHED"}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0002","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_CPU_METRIC":9223372036854775807,"YARN_APPLICATION_MEM_METRIC":2147483647}}
	Line 2514: 2016-06-16 02:27:14,548 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
	Line 2516: 2016-06-16 02:27:14,548 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(542)) - Publishing the entity application_0_0002, JSON-style
content: {"events":[{"timestamp":4,"eventtype":"YARN_APPLICATION_ACLS_UPDATED","eventinfo":{}}],"entitytype":"YARN_APPLICATION","entity":"application_0_0002","relatedentities":{},"primaryfilters":{},"otherinfo":{"YARN_APPLICATION_VIEW_ACLS":""}}
	Line 2537: 2016-06-16 02:27:14,558 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher entered
state STOPPED
	Line 2538: 2016-06-16 02:27:14,558 DEBUG [main] service.CompositeService (CompositeService.java:serviceStop(129))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: stopping services,
size=2
	Line 2539: 2016-06-16 02:27:14,558 DEBUG [main] service.CompositeService (CompositeService.java:stop(151))
- Stopping service #1: Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
in state org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher:
STARTED
	Line 2539: 2016-06-16 02:27:14,558 DEBUG [main] service.CompositeService (CompositeService.java:stop(151))
- Stopping service #1: Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
in state org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher:
STARTED
	Line 2540: 2016-06-16 02:27:14,559 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452))
- Service: org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher
entered state STOPPED
	Line 2541: 2016-06-16 02:27:14,559 DEBUG [main] service.CompositeService (CompositeService.java:serviceStop(129))
- org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher$MultiThreadedDispatcher:
stopping services, size=2
	Line 2627: 2016-06-16 02:27:14,637 DEBUG [AsyncDispatcher event handler] metrics.SystemMetricsPublisher
(SystemMetricsPublisher.java:putEntity(548)) - Timeline entities are successfully put
{noformat}
Checked the entity put operation for application 2 

{noformat}
	Line 2185: 2016-06-16 06:43:19,687 DEBUG [40412161@qtp-613784740-3 - /ws/v1/timeline/] security.TimelineACLsManager
(TimelineACLsManager.java:checkAccess(106)) - Verifying the access of root on the timeline
entity { id: application_0_0002, type: YARN_APPLICATION }
	Line 2293: 2016-06-16 06:43:19,876 DEBUG [40412161@qtp-613784740-3 - /ws/v1/timeline/] security.TimelineACLsManager
(TimelineACLsManager.java:checkAccess(106)) - Verifying the access of root on the timeline
entity { id: application_0_0002, type: YARN_APPLICATION }
	Line 2326: 2016-06-16 06:43:19,894 DEBUG [1672353434@qtp-613784740-5 - /ws/v1/timeline/]
security.TimelineACLsManager (TimelineACLsManager.java:checkAccess(106)) - Verifying the access
of root on the timeline entity { id: application_0_0002, type: YARN_APPLICATION }
	Line 2430: 2016-06-16 06:43:20,047 DEBUG [40412161@qtp-613784740-3 - /ws/v1/timeline/] security.TimelineACLsManager
(TimelineACLsManager.java:checkAccess(106)) - Verifying the access of root on the timeline
entity { id: application_0_0002, type: YARN_APPLICATION }
	Line 2534: 2016-06-16 06:43:20,161 DEBUG [1672353434@qtp-613784740-5 - /ws/v1/timeline/]
security.TimelineACLsManager (TimelineACLsManager.java:checkAccess(106)) - Verifying the access
of root on the timeline entity { id: application_0_0002, type: YARN_APPLICATION }
	Line 2646: 2016-06-16 06:43:20,246 DEBUG [40412161@qtp-613784740-3 - /ws/v1/timeline/] security.TimelineACLsManager
(TimelineACLsManager.java:checkAccess(106)) - Verifying the access of root on the timeline
entity { id: application_0_0002, type: YARN_APPLICATION }
{noformat}

Tries to insert 6 entities even if we are publishing 5 events and its happens randomly and
last YARN_APPLICATION_ACLS_UPDATED is not finished.

{noformat}
2016-06-16 11:16:41,983 DEBUG [1272965700@qtp-613784740-2 - /ws/v1/timeline/] security.TimelineACLsManager
(TimelineACLsManager.java:checkAccess(106)) - Verifying the access of root on the timeline
entity { id: application_0_0002, type: YARN_APPLICATION }
2016-06-16 11:16:41,984 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(416)) - { id: application_0_0002, type: YARN_APPLICATION
}  Entity Put in needsPut 1466056001984
2016-06-16 11:16:41,984 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_STATE_UPDATED
Event Info-->{YARN_APPLICATION_STATE=RUNNING}Values: [RUNNING] Timestamp :1466055999733
2016-06-16 11:16:41,984 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_STATE_UPDATED
Event Info-->{YARN_APPLICATION_STATE=RUNNING}Values: [RUNNING] Timestamp :1466055999733
2016-06-16 11:16:41,984 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_ACLS_UPDATED
Event Info-->{}Values: [] Timestamp :2147483654
2016-06-16 11:16:41,984 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_UPDATED Event
Info-->{YARN_APPLICATION_QUEUE=test queue, YARN_APPLICATION_PRIORITY=10}Values: [test queue,
10] Timestamp :2147483653
2016-06-16 11:16:41,985 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_FINISHED Event
Info-->{YARN_APPLICATION_DIAGNOSTICS_INFO=test diagnostics info, YARN_APPLICATION_FINAL_STATUS=UNDEFINED,
YARN_APPLICATION_LATEST_APP_ATTEMPT=appattempt_0_0002_000001, YARN_APPLICATION_STATE=FINISHED}Values:
[test diagnostics info, UNDEFINED, appattempt_0_0002_000001, FINISHED] Timestamp :2147483650
2016-06-16 11:16:41,985 INFO  [1272965700@qtp-613784740-2 - /ws/v1/timeline/] timeline.KeyValueBasedTimelineStore
(KeyValueBasedTimelineStore.java:put(420)) - Events Output TypeYARN_APPLICATION_CREATED Event
Info-->{}Values: [] Timestamp :2147483649
{noformat}

YARN_APPLICATION_STATE_UPDATED Event Info-->{YARN_APPLICATION_STATE=RUNNING}Values: [RUNNING]
Timestamp :1466055999733 is added 2 times


> TestSystemMetricsPublisher.testPublishApplicationMetrics fails in trunk
> -----------------------------------------------------------------------
>
>                 Key: YARN-5240
>                 URL: https://issues.apache.org/jira/browse/YARN-5240
>             Project: Hadoop YARN
>          Issue Type: Test
>          Components: test
>            Reporter: Rohith Sharma K S
>              Labels: test
>
> In the build [link|https://builds.apache.org/job/PreCommit-YARN-Build/11975/artifact/patchprocess/patch-unit-hadoop-yarn-project_hadoop-yarn_hadoop-yarn-server_hadoop-yarn-server-resourcemanager.txt]
test case failed. 
> {noformat}
> Tests run: 5, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 6.554 sec <<<
FAILURE! - in org.apache.hadoop.yarn.server.resourcemanager.metrics.TestSystemMetricsPublisher
> testPublishApplicationMetrics(org.apache.hadoop.yarn.server.resourcemanager.metrics.TestSystemMetricsPublisher)
 Time elapsed: 2.206 sec  <<< FAILURE!
> java.lang.AssertionError: expected:<> but was:<null>
> 	at org.junit.Assert.fail(Assert.java:88)
> 	at org.junit.Assert.failNotEquals(Assert.java:743)
> 	at org.junit.Assert.assertEquals(Assert.java:118)
> 	at org.junit.Assert.assertEquals(Assert.java:144)
> 	at org.apache.hadoop.yarn.server.resourcemanager.metrics.TestSystemMetricsPublisher.testPublishApplicationMetrics(TestSystemMetricsPublisher.java:201)
> {noformat}



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

---------------------------------------------------------------------
To unsubscribe, e-mail: yarn-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: yarn-issues-help@hadoop.apache.org


Mime
View raw message