You are viewing a plain text version of this content. The canonical link for it is here.
Posted to yarn-issues@hadoop.apache.org by "Bibin A Chundatt (JIRA)" <ji...@apache.org> on 2016/06/16 15:29:05 UTC
[jira] [Commented] (YARN-5240)
TestSystemMetricsPublisher.testPublishApplicationMetrics fails in trunk
[ 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