Hi, Naga, I reproduce it with hadoop 2.6 in my email. I remember, I meet same problem with hadoop 2.7 some days ago. I can create a jira for it, but I don't know how to fix it. I really appreciate it if you could help fix it. Thank you!
On Mon, Dec 14, 2015 at 4:37 PM, Naganarasimha G R (Naga) < [email protected]> wrote: > Hi Wen Lin, > > This seems to be a bug in the code, which version are you using, seems > like it can happen in any version but just to confirm > Would you like to raise and handle the issue or shall i ? > > Regards, > + Naga > ________________________________________ > From: Wen Lin [[email protected]] > Sent: Monday, December 14, 2015 13:40 > To: [email protected] > Subject: Re: Meet A java null pointer when use unmanaged AM and > yarn.resourcemanager.system-metrics-publisher.enabled is enable > > Hi, Yarn Developers, > > I have found another reproduce for this bug. > I am using hortonworks' simple-yarn-app( > https://github.com/hortonworks/simple-yarn-app), and start it in > "unmanaged > AM" mode. > On Hadoop Yarn, timeline server is started/enabled and > "yarn.resourcemanager.system-metrics-publisher.enabled" is enable. > On the client side, the output is: > > [gpadmin@master simple-yarn-app]$ hadoop jar > > ~/hadoop/singlecluster/hadoop/share/hadoop/yarn/hadoop-yarn-applications-unmanaged-am-launcher- > 2.6.0.3.0.0.0-120.jar > Client --classpath ./target/simple-yarn-app-1.1.0.jar -cmd "java > com.hortonworks.simpleyarnapp.ApplicationMaster /bin/date 2" > > 15/12/14 07:57:04 INFO unmanagedamlauncher.UnmanagedAMLauncher: > Initializing Client > > 15/12/14 07:57:06 INFO impl.TimelineClientImpl: Timeline service address: > http://master:8188/ws/v1/timeline/ > > 15/12/14 07:57:06 INFO unmanagedamlauncher.UnmanagedAMLauncher: Starting > Client > > 15/12/14 07:57:06 INFO unmanagedamlauncher.UnmanagedAMLauncher: Setting up > application submission context for ASM > > 15/12/14 07:57:06 INFO unmanagedamlauncher.UnmanagedAMLauncher: Setting > unmanaged AM > > 15/12/14 07:57:06 INFO unmanagedamlauncher.UnmanagedAMLauncher: Submitting > application to ASM > > 15/12/14 07:57:07 INFO impl.YarnClientImpl: Submitted application > application_1450079798629_0001 > > 15/12/14 07:57:08 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=N/A, appQueue=default, appMasterRpcPort=-1, > appStartTime=1450079827025, yarnAppState=ACCEPTED, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:08 INFO unmanagedamlauncher.UnmanagedAMLauncher: Launching > AM with application attempt id appattempt_1450079798629_0001_000001 > > 15/12/14 07:57:09 INFO impl.ContainerManagementProtocolProxy: > yarn.client.max-cached-nodemanagers-proxies : 0 > > registerApplicationMaster 0 > > registerApplicationMaster 1 > > Making res-req 0 > > Making res-req 1 > > 15/12/14 07:57:10 INFO impl.AMRMClientImpl: Received new token for : > node2:46502 > > Launching container container_1450079798629_0001_01_000001 > > 15/12/14 07:57:10 INFO impl.ContainerManagementProtocolProxy: Opening proxy > : node2:46502 > > 15/12/14 07:57:10 INFO impl.AMRMClientImpl: Received new token for : > node3:28286 > > Launching container container_1450079798629_0001_01_000002 > > 15/12/14 07:57:10 INFO impl.ContainerManagementProtocolProxy: Opening proxy > : node3:28286 > > Completed container container_1450079798629_0001_01_000001 > > Completed container container_1450079798629_0001_01_000002 > > 15/12/14 07:57:11 INFO unmanagedamlauncher.UnmanagedAMLauncher: AM process > exited with value: 0 > > 15/12/14 07:57:12 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:13 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:14 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:15 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:16 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:17 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:18 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:19 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:20 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:21 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:22 INFO unmanagedamlauncher.UnmanagedAMLauncher: Got > application report from ASM for, appId=1, > appAttemptId=appattempt_1450079798629_0001_000001, clientToAMToken=null, > appDiagnostics=, appMasterHost=, appQueue=default, appMasterRpcPort=0, > appStartTime=1450079827025, yarnAppState=RUNNING, > distributedFinalState=UNDEFINED, appTrackingUrl=N/A, appUser=gpadmin > > 15/12/14 07:57:22 WARN unmanagedamlauncher.UnmanagedAMLauncher: Waited 10 > seconds after process completed for AppReport to reach desired final state. > Not waiting anymore.CurrentState = RUNNING, ExpectedStates = > FINISHED,FAILED,KILLED > > 15/12/14 07:57:23 FATAL unmanagedamlauncher.UnmanagedAMLauncher: Error > running Client > > java.lang.RuntimeException: Failed to receive final expected state in > ApplicationReport, CurrentState=RUNNING, > ExpectedStates=FINISHED,FAILED,KILLED > > at > > org.apache.hadoop.yarn.applications.unmanagedamlauncher.UnmanagedAMLauncher.monitorApplication(UnmanagedAMLauncher.java:487) > > at > > org.apache.hadoop.yarn.applications.unmanagedamlauncher.UnmanagedAMLauncher.run(UnmanagedAMLauncher.java:355) > > at > > org.apache.hadoop.yarn.applications.unmanagedamlauncher.UnmanagedAMLauncher.main(UnmanagedAMLauncher.java:110) > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > > at > > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > > at > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > > at java.lang.reflect.Method.invoke(Method.java:606) > > at org.apache.hadoop.util.RunJar.run(RunJar.java:221) > > at org.apache.hadoop.util.RunJar.main(RunJar.java:136) > > In Yarn's RM log file, there is also a javaNullException, same with the > situation I use libyarn as a "unmanaged AM" mentioned in my first email. > > 2015-12-14 07:57:06,960 INFO > org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Allocated > new applicationId: 1 > > 640 2015-12-14 07:57:07,025 WARN > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: The specific > max attempts: 0 for application: 1 is invalid, because it is out of the > range [1, 2]. Use the global max attempts instead. > > 641 2015-12-14 07:57:07,029 INFO > org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Application > with id 1 submitted by user gpadmin > > 642 2015-12-14 07:57:07,029 INFO > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Storing > application with id application_1450079798629_0001 > > 643 2015-12-14 07:57:07,029 INFO > org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=gpadmin > IP=192.168.2.201 OPERATION=Submit Application Request > TARGET=ClientRMService RESULT=SUCCESS APPID=application_145007979862 > 9_0001 > > 644 2015-12-14 07:57:07,031 INFO > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > application_1450079798629_0001 State change from NEW to NEW_SAVING > > 645 2015-12-14 07:57:07,043 INFO > org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: > Storing info for app: application_1450079798629_0001 > > 646 2015-12-14 07:57:07,044 INFO > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > application_1450079798629_0001 State change from NEW_SAVING to SUBMITTED > > 647 2015-12-14 07:57:07,046 INFO > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.ParentQueue: > Application added - appId: application_1450079798629_0001 user: gpadmin > leaf-queue of parent: root #applications: 1 > > 648 2015-12-14 07:57:07,047 INFO > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: > Accepted application application_1450079798629_0001 from user: gpadmin, in > queue: default > > 649 2015-12-14 07:57:07,105 INFO > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > application_1450079798629_0001 State change from SUBMITTED to ACCEPTED > > 650 2015-12-14 07:57:07,146 INFO > org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: > Registering app attempt : appattempt_1450079798629_0001_000001 > > 651 2015-12-14 07:57:07,147 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > appattempt_1450079798629_0001_000001 State change from NEW to SUBMITTED > > 652 2015-12-14 07:57:07,162 INFO > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > Application application_1450079798629_0001 from user: gpadmin activated in > queue: default > > 653 2015-12-14 07:57:07,162 INFO > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > Application added - appId: application_1450079798629_0001 user: > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity. > LeafQueue$User@68d50d2f, leaf-queue: default #user-pending-applications: 0 > #user-active-applications: 1 #queue-pending-applications: 0 > #queue-active-applications: 1 > > 654 2015-12-14 07:57:07,162 INFO > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: > Added Application Attempt appattempt_1450079798629_0001_000001 to scheduler > from user gpadmin in queue default > > 655 2015-12-14 07:57:07,163 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > Storing attempt: AppId: application_1450079798629_0001 AttemptId: > appattempt_1450079798629_0001_000001 MasterContainer: null > > 656 2015-12-14 07:57:07,165 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > appattempt_1450079798629_0001_000001 State change from SUBMITTED to > LAUNCHED_UNMANAGED_SAVING > > 657 2015-12-14 07:57:07,178 INFO > > org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: > Create AMRMToken for ApplicationAttempt: > appattempt_1450079798629_0001_000001 > > 658 2015-12-14 07:57:07,183 INFO > > org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: > Creating password for appattempt_1450079798629_0001_000001 > > 659 2015-12-14 07:57:07,188 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > appattempt_1450079798629_0001_000001 State change from > LAUNCHED_UNMANAGED_SAVING to LAUNCHED > > 660 2015-12-14 07:57:10,078 INFO > SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for > appattempt_1450079798629_0001_000001 (auth:SIMPLE) > > 661 2015-12-14 07:57:10,108 INFO > org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: AM > registration appattempt_1450079798629_0001_000001 > > 662 2015-12-14 07:57:10,109 INFO > org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=gpadmin > IP=192.168.2.201 OPERATION=Register App Master > TARGET=ApplicationMasterService RESULT=SUCCESS > APPID=application_145007979862 9_0001 > APPATTEMPTID=appattempt_1450079798629_0001_000001 > > 663 2015-12-14 07:57:10,111 ERROR > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Error in > handling event type REGISTERED for applicationAttempt > application_1450079798629_0001 > > 664 java.lang.NullPointerException > > 665 at > > org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher.appAttemptRegistered(SystemMetricsPublisher.java:143) > > 666 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl$AMRegisteredTransition.transition(RMAppAttemptImpl.java:1365) > > 667 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl$AMRegisteredTransition.transition(RMAppAttemptImpl.java:1341) > > 668 at > > org.apache.hadoop.yarn.state.StateMachineFactory$SingleInternalArc.doTransition(StateMachineFactory.java:362) > > 669 at > > org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:302) > > 670 at > > org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46) > > 671 at > > org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448) > > 672 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:755) > > 673 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:106) > > 674 at > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:849) > > 675 at > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:830) > > 676 at > > org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:173) > > 677 at > > org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:106) > > 678 at java.lang.Thread.run(Thread.java:745) > > 679 2015-12-14 07:57:10,113 INFO > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > application_1450079798629_0001 State change from ACCEPTED to RUNNING > > 680 2015-12-14 07:57:10,196 ERROR > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > Can't handle this event at current state > > 681 org.apache.hadoop.yarn.state.InvalidStateTransitonException: Invalid > event: STATUS_UPDATE at LAUNCHED > > 682 at > > org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:305) > > 683 at > > org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46) > > 684 at > > org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448) > > 685 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:755) > > 686 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:106) > > 687 at > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:849) > > 688 at > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:830) > > 689 at > > org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:173) > > 690 at > > org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:106) > > 691 at java.lang.Thread.run(Thread.java:745) > > 692 2015-12-14 07:57:10,331 ERROR > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > Can't handle this event at current state > > 693 org.apache.hadoop.yarn.state.InvalidStateTransitonException: Invalid > event: STATUS_UPDATE at LAUNCHED > > 694 at > > org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:305) > > 695 at > > org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46) > > 696 at > > org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448) > > 697 at > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:755) > > > > > So I can conclude that, if a unmanaged AM tries to register in Yarn, when > timeline server is configured and > "yarn.resourcemanager.system-metrics-publisher.enabled" > is enable, a java NullPointerException occurs in Yarn. > Would you please fix it? > Thanks! > > On Thu, Dec 10, 2015 at 10:45 PM, Wen Lin <[email protected]> wrote: > > > Hi, Yarn Developers, > > > > I am writing to report a strange case I meet here. > > I was using libyarn( > > https://github.com/apache/incubator-hawq/tree/master/depends/libyarn), a > > kind of C++ client library to communicate with Hadoop Yarn. It acts as a > > "Unmanaged Application Master", doing things such as register > application, > > request to allocate/release containers from Yarn, activate containers, > > etc(sample app is in /libyarn/sample/c_client_main.c). > > > > What is strange to me is, when configure timeline server and > > yarn.resourcemanager.system-metrics-publisher.enabled is enable in > > yarn-site.xml. Something strange happens. > > > > If the property "yarn.resourcemanager.system-metrics-publisher.enabled" > is > > not enable and no timeline server is configured, things goes well. > > Once Yarn RM gets a heartbeat from my application, the progress becomes > > 50%, 50% is hard coded in allocate request. > > > > [gpadmin@master ~]$ yarn application -list > > > > 15/12/09 08:12:54 INFO impl.TimelineClientImpl: Timeline service address: > > http://master:8188/ws/v1/timeline/ > > > > Total number of applications (application-types: [] and states: > > [SUBMITTED, ACCEPTED, RUNNING]):1 > > > > Application-Id Application-Name Application-Type > > User Queue State Final-State Progress > > Tracking-URL > > > > application_1449630430655_0007 libyarn YARN > > gpadmin default RUNNING UNDEFINED 50% > > url > > > > However if timeline server is configured, and > > "yarn.resourcemanager.system-metrics-publisher.enabled" is enable, > > Even my application can allocate/activate/release containers, the > progress > > of my application is ALWAYS 0%! > > > > I've check the log of Yarn resource manager, I find > > a NullPointerException in log. > > I've google this exception with such callstack. there is a question, > which > > is similar to mine. > > > > > http://zh.hortonworks.com/community/forums/topic/error-in-handling-event-type-registered-for-applicationattempt/ > > > > I can see below information in log in log file: > > 2015-12-10 02:52:19,025 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > Storing attempt: AppId: application_1449744734026_0001 AttemptId: > > appattempt_1449744734026_0001_000001 MasterContainer: null > > ... > > 2015-12-10 02:52:19,946 ERROR > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Error in > > handling event type REGISTERED for applicationAttempt > > application_1449744734026_0001 > > java.lang.NullPointerException > > at > > > org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher.appAttemptRegistered(SystemMetricsPublisher.java:145) > > > > Below is related Yarn codes: > > private void storeAttempt() { > > // store attempt data in a non-blocking manner to prevent dispatcher > > // thread starvation and wait for state to be saved > > LOG.info("Storing attempt: AppId: " + > > getAppAttemptId().getApplicationId() > > + " AttemptId: " + > > getAppAttemptId() > > + " MasterContainer: " + masterContainer); > > rmContext.getStateStore().storeNewApplicationAttempt(this); > > } > > > > public void appAttemptRegistered(RMAppAttempt appAttempt, > > long registeredTime) { > > if (publishSystemMetrics) { > > dispatcher.getEventHandler().handle( > > new AppAttemptRegisteredEvent( > > appAttempt.getAppAttemptId(), > > appAttempt.getHost(), > > appAttempt.getRpcPort(), > > appAttempt.getTrackingUrl(), > > appAttempt.getOriginalTrackingUrl(), > > appAttempt.getMasterContainer().getId(), > > registeredTime)); > > } > > } > > I guess since libyarn is a "unmanaged" application master, there is no > > container allocated for it, so MasterContainer is null. But when Yarn > > register this application into SystemMetricsPublisher, it requires a > > container and its id. That's why this null exception happens. > > In a word, if a unmanaged AM tries to register in Yarn, when timeline > > server is configured and > > "yarn.resourcemanager.system-metrics-publisher.enabled" is enable, a > java > > NullPointerException occurs in Yarn. > > I am not sure if it's my app's fault or Yarn's bug. Would you please help > > me take a look at it? > > > > Thanks, > > Wen > > > > 2015-12-10 02:52:18,842 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: Allocated > > new applicationId: 1 > > 2015-12-10 02:52:18,873 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ClientRMService: > Application > > with id 1 submitted by user gpadmin > > 2015-12-10 02:52:18,874 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: Storing > > application with id application_1449744734026_0001 > > 2015-12-10 02:52:18,874 INFO > > org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=gpadmin > > IP=10.32.34.218 OPERATION=Submit Application Request > > TARGET=ClientRMService RESULT=SUCCESS > > APPID=application_1449744734026_0001 > > 2015-12-10 02:52:18,883 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > > application_1449744734026_0001 State change from NEW to NEW_SAVING > > 2015-12-10 02:52:18,884 INFO > > org.apache.hadoop.yarn.server.resourcemanager.recovery.RMStateStore: > > Storing info for app: application_1449744734026_0001 > > 2015-12-10 02:52:18,908 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > > application_1449744734026_0001 State change from NEW_SAVING to SUBMITTED > > 2015-12-10 02:52:18,910 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.ParentQueue: > > Application added - appId: application_1449744734026_0001 user: gpadmin > > leaf-queue of parent: root #applications: 1 > > 2015-12-10 02:52:18,911 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: > > Accepted application application_1449744734026_0001 from user: gpadmin, > in > > queue: default > > 2015-12-10 02:52:18,969 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > > application_1449744734026_0001 State change from SUBMITTED to ACCEPTED > > 2015-12-10 02:52:19,004 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: > > Registering app attempt : appattempt_1449744734026_0001_000001 > > 2015-12-10 02:52:19,006 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > appattempt_1449744734026_0001_000001 State change from NEW to SUBMITTED > > 2015-12-10 02:52:19,023 WARN > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > > maximum-am-resource-percent is insufficient to start a single application > > in queue, it is likely set too low. skipping enforcement to allow at > least > > one application to start > > 2015-12-10 02:52:19,024 WARN > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > > maximum-am-resource-percent is insufficient to start a single application > > in queue for user, it is likely set too low. skipping enforcement to > allow > > at least one application to start > > 2015-12-10 02:52:19,024 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > > Application application_1449744734026_0001 from user: gpadmin activated > in > > queue: default > > 2015-12-10 02:52:19,024 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue: > > Application added - appId: application_1449744734026_0001 user: > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.LeafQueue$User@6a7edb15 > , > > leaf-queue: default #user-pending-applications: 0 > > #user-active-applications: 1 #queue-pending-applications: 0 > > #queue-active-applications: 1 > > 2015-12-10 02:52:19,024 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler: > > Added Application Attempt appattempt_1449744734026_0001_000001 to > scheduler > > from user gpadmin in queue default > > 2015-12-10 02:52:19,025 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > Storing attempt: AppId: application_1449744734026_0001 AttemptId: > > appattempt_1449744734026_0001_000001 MasterContainer: null > > 2015-12-10 02:52:19,039 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > appattempt_1449744734026_0001_000001 State change from SUBMITTED to > > LAUNCHED_UNMANAGED_SAVING > > 2015-12-10 02:52:19,039 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: > > Create AMRMToken for ApplicationAttempt: > > appattempt_1449744734026_0001_000001 > > 2015-12-10 02:52:19,042 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.security.AMRMTokenSecretManager: > > Creating password for appattempt_1449744734026_0001_000001 > > 2015-12-10 02:52:19,046 INFO > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > appattempt_1449744734026_0001_000001 State change from > > LAUNCHED_UNMANAGED_SAVING to LAUNCHED > > 2015-12-10 02:52:19,936 INFO SecurityLogger.org.apache.hadoop.ipc.Server: > > Auth successful for appattempt_1449744734026_0001_000001 (auth:SIMPLE) > > 2015-12-10 02:52:19,944 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService: > AM > > registration appattempt_1449744734026_0001_000001 > > 2015-12-10 02:52:19,945 INFO > > org.apache.hadoop.yarn.server.resourcemanager.RMAuditLogger: USER=gpadmin > > IP=10.32.34.218 OPERATION=Register App Master > > TARGET=ApplicationMasterService RESULT=SUCCESS > > APPID=application_1449744734026_0001 > > APPATTEMPTID=appattempt_1449744734026_0001_000001 > > 2015-12-10 02:52:19,946 ERROR > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Error in > > handling event type REGISTERED for applicationAttempt > > application_1449744734026_0001 > > java.lang.NullPointerException > > at > > > org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher.appAttemptRegistered(SystemMetricsPublisher.java:145) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl$AMRegisteredTransition.transition(RMAppAttemptImpl.java:1405) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl$AMRegisteredTransition.transition(RMAppAttemptImpl.java:1380) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory$SingleInternalArc.doTransition(StateMachineFactory.java:362) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:302) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:786) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:108) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:850) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:831) > > at > > > org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:175) > > at > > > org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:108) > > at java.lang.Thread.run(Thread.java:745) > > 2015-12-10 02:52:19,947 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.RMAppImpl: > > application_1449744734026_0001 State change from ACCEPTED to RUNNING > > 2015-12-10 02:52:19,963 ERROR > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl: > > Can't handle this event at current state > > org.apache.hadoop.yarn.state.InvalidStateTransitonException: Invalid > > event: STATUS_UPDATE at LAUNCHED > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:305) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46) > > at > > > org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:786) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.rmapp.attempt.RMAppAttemptImpl.handle(RMAppAttemptImpl.java:108) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:850) > > at > > > org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$ApplicationAttemptEventDispatcher.handle(ResourceManager.java:831) > > at > > > org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:175) > > at > > > org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:108) > > at java.lang.Thread.run(Thread.java:745) > > 2015-12-10 02:52:38,864 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: > Node > > not found resyncing test2:9983 > > 2015-12-10 02:52:39,884 INFO org.apache.hadoop.yarn.util.RackResolver: > > Resolved test2 to /default-rack > > 2015-12-10 02:52:39,886 INFO > > org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService: > > NodeManager from node test2(cmPort: 9983 httpPort: 8042) registered with > > capability: <memory:12288, vCores:6>, assigned nodeId test2:9983 > > 2015-12-10 02:52:39,886 WARN > > org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: Cannot > get > > RMApp by appId=application_1449655982302_0004, just added it to > > finishedApplications list for cleanup > > 2015-12-10 02:52:39,886 WARN > > org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: Cannot > get > > RMApp by appId=application_1449743958580_0001, just added it to > > finishedApplications list for cleanup > > 2015-12-10 02:52:39,889 INFO > > org.apache.hadoop.yarn.server.resourcemanager.rmnode.RMNodeImpl: > test2:9983 > > Node Transitioned from NEW to RUNNING > > >
