dev@glassfish.java.net

Re: possible patch for JmxConnectorServerDriver.java

From: Wolfram Rittmeyer <w.rittmeyer_at_jsptutorial.org>
Date: Mon, 21 Apr 2008 23:10:08 +0200

Nandini Ektare wrote:
> Hi Wolfram,
>
> Wolfram Rittmeyer wrote:
>> Nandini Ektare wrote:
>>> Hi Wolfram,
>>>
>>> This looks like the issue
>>> https://glassfish.dev.java.net/issues/show_bug.cgi?id=3289
>>>
>>> It has been fixed on GF v2. You can instead take that patch on GF.
>>
>> Hi Nandini,
>>
>> I've done a fresh install of glassfish-v2-b50g and of
>> glassfish-installer-v2ur1-b09d and the issue is reproducible easily.
>> Just change the address-attribute of the jmx-connector element to a
>> specific address and the following stack trace gets printed in
>> server.log (see log below). The same is true for a freshly build of
>> SJSAS91_FCS_BRANCH. Applying the path I sent to this list yesterday
>> fixes the issue (though granted there might be more elegant ways to
>> deal with the issue).
>>
>> Could it be that the fix you mentioned is not ported to the v2.1 branch?
> Hmm.. depends on when this branch forked off. I see I checked in for
> 3289 between 2007-07-16 and 2007-08-01
> If you can verify any one of the following diffs, it will be clear.
> http://fisheye5.cenqua.com/browse/glassfish/jmx-remote/rjmx-impl/src/java/com/sun/enterprise/admin/jmx/remote/server/rmi/RmiStubRegistryHandler.java?r1=1.6&r2=1.7
>
> http://fisheye5.cenqua.com/browse/glassfish/jmx-remote/rjmx-impl/src/java/com/sun/enterprise/admin/jmx/remote/server/rmi/JmxConnectorServerDriver.java?r1=1.8&r2=1.9
>
> http://fisheye5.cenqua.com/browse/glassfish/appserv-core/src/java/com/sun/enterprise/admin/server/core/JmxConnectorLifecycle.java?r1=1.15&r2=1.16
>
> http://fisheye5.cenqua.com/browse/glassfish/admin-ee/nodeagent/src/java/com/sun/enterprise/ee/nodeagent/NodeAgent.java?r1=1.27&r2=1.28
>

Hi Nandini,

these are all part of main trunk and these changes are part of the
sources I used to verify the problem described on the glassfish forum.
Thus the problem is not fixed in the main trunk!

Also setting ASQuickStartup to false doesn't change anything.


Now by digging a bit deeper into the sources I've understood the following:
In the prepare-method of JmxConnectorServerDriver a ServerSocket on the
JMX-port is opened and set to "LISTEN". This doesn't cause an exception
to be thrown.

Actually - being no JMX-server developer - I hadn't expected a
ServerSocket to be opened that early. I would have expected this to
happen a little bit later.

Nevertheless the exception gets thrown in the start()-method of the
JMXConnectorServer. Why is that? After all the ServerSocket has already
been opened successfully.

Two more observations:
The URL passed to the creation of the JMXConnectorServer points to
localhost - even though I have specified an explicit IP address in
domain.xml, which is not surprising given the way the URLs are created.

The env-object passed to the creation of the JMXConnectorServer contains
a reference to the RMIServerSocketFactory-object created in prepare. Yet
this object's createServerSocket()-method has already been called in
prepare and after that gets not called again.

BTW: I have tested this on Linux with a Glassfish developer profile.


Given the above observations it looks to me like the URL is relevant
after all. But I guess this issue needs quite a lot of testing
(different operating systems, different profiles and so on). Thus my
rather optimistic patch is probably only a first step ;-)


Regards,

Wolfram Rittmeyer


>
> Also, I went back and saw closing comments for 3289 :
>
> <snip>
>
> This bug (DAS fails to start with a specific IP for
> system-jmx-connector) can be reproduced consistently only on Developer
> profile (PE) with ASQuickStart=true (the default value for Developer
> profile)
> With ASQuickStart=false it is not reproducible.
>
> The flag is not considered in Cluster profile, so no matter what value
> you set for the flag for Cluster profile, it is not reproducible (which
> is why I couldn't reproduce it anytime.)
> </snip>
>
> Can you please vary the value of this flag and report your observation?
>
> Lastly, to give you more details of what your fix achieves and what
> 3289's fix does:
> - Fix for 3289 uproots the issues right at the point where
> JMXConnectorServer finally binds to a port. The connector server is
> nothing but a RMI server object and socket creation for it is controlled
> by GlassFish using custom server socket factories. All the custom server
> socket factories have the 0.0.0.0 vs specified port address logic. So it
> would be surprising why you should observe otherwise
> - Your patch fixes the JMXServiceUrl used by JDK's JMX code in creating
> the JMXConnectorServer. I remember at one point bug reporter for 3289
> confirmed that fixing URL did not fix the issue which is why I am not so
> sure about including the patch. At that time, since I could not change
> what was being done within JDK, I had finally resorted to modifying the
> last point in control flow just before socket creation in
> GlassFish-provided server socket factory (JDK delegates control to the
> custom socket factory if one exists).
>
> Please let me know if you see the 3289 diffs in the branch you are
> working on and your observation for the ASQuickStart flag.
>
> Regards,
> Nandini
>> Regards,
>>
>> Wolfram Rittmeyer
>> P.S.: Quicklook results:
>> [java] [java] ************************
>> [java] [java] PASSED= 69
>> [java] [java] ------------ =========
>> [java] [java] FAILED= 0
>> [java] [java] ------------ =========
>> [java] [java] DID NOT RUN= 0
>> [java] [java] ------------ =========
>> [java] [java] Total Expected=69
>> [java] [java] ************************
>>
>>
>>
>> server.log:
>>
>> [#|2008-04-20T00:47:03.968+0200|INFO|sun-appserver9.1|javax.enterprise.system.tools.admin|_ThreadID=10;_ThreadName=main;|ADM1079:
>> Initialization of AMX MBeans started|#]
>>
>> [#|2008-04-20T00:47:04.264+0200|SEVERE|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;com.sun.enterprise.admin.server.core.JmxConnectorLifecycle_at_247d4a;com.sun.appserv.server.ServerLifecycleException:
>> Cannot bind to URL
>> [rmi://localhost:8686/management/rmi-jmx-connector]:
>> javax.naming.ServiceUnavailableException [Root exception is
>> java.rmi.ConnectException: Connection refused to host: localhost;
>> nested exception is:
>> java.net.ConnectException: Connection
>> refused];_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|Service
>> com.sun.enterprise.admin.server.core.JmxConnectorLifecycle_at_247d4a
>> cannot be started! : com.sun.appserv.server.ServerLifecycleException:
>> Cannot bind to URL
>> [rmi://localhost:8686/management/rmi-jmx-connector]:
>> javax.naming.ServiceUnavailableException [Root exception is
>> java.rmi.ConnectException: Connection refused to host: localhost;
>> nested exception is:
>> java.net.ConnectException: Connection refused]|#]
>>
>> [#|2008-04-20T00:47:04.269+0200|SEVERE|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|CORE5071:
>> An error occured during initialization
>> com.sun.appserv.server.ServerLifecycleException: Cannot bind to URL
>> [rmi://localhost:8686/management/rmi-jmx-connector]:
>> javax.naming.ServiceUnavailableException [Root exception is
>> java.rmi.ConnectException: Connection refused to host: localhost;
>> nested exception is:
>> java.net.ConnectException: Connection refused]
>> at
>> com.sun.enterprise.admin.server.core.JmxConnectorLifecycle.onStartup(JmxConnectorLifecycle.java:153)
>>
>> at
>> com.sun.enterprise.server.ApplicationServer.onStartup(ApplicationServer.java:442)
>>
>> at
>> com.sun.enterprise.server.ondemand.OnDemandServer.onStartup(OnDemandServer.java:120)
>>
>> at com.sun.enterprise.server.PEMain.run(PEMain.java:411)
>> at com.sun.enterprise.server.PEMain.main(PEMain.java:338)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at com.sun.enterprise.server.PELaunch.main(PELaunch.java:412)
>> Caused by: java.io.IOException: Cannot bind to URL
>> [rmi://localhost:8686/management/rmi-jmx-connector]:
>> javax.naming.ServiceUnavailableException [Root exception is
>> java.rmi.ConnectException: Connection refused to host: localhost;
>> nested exception is:
>> java.net.ConnectException: Connection refused]
>> at
>> javax.management.remote.rmi.RMIConnectorServer.newIOException(RMIConnectorServer.java:814)
>>
>> at
>> javax.management.remote.rmi.RMIConnectorServer.start(RMIConnectorServer.java:431)
>>
>> at
>> com.sun.enterprise.admin.jmx.remote.server.rmi.JmxConnectorServerDriver.startConnectorServer(JmxConnectorServerDriver.java:218)
>>
>> at
>> com.sun.enterprise.admin.server.core.JmxConnectorLifecycle.onStartup(JmxConnectorLifecycle.java:134)
>>
>> ... 9 more
>> Caused by: javax.naming.ServiceUnavailableException [Root exception is
>> java.rmi.ConnectException: Connection refused to host: localhost;
>> nested exception is:
>> java.net.ConnectException: Connection refused]
>> at
>> com.sun.jndi.rmi.registry.RegistryContext.bind(RegistryContext.java:122)
>> at
>> com.sun.jndi.toolkit.url.GenericURLContext.bind(GenericURLContext.java:208)
>>
>> at javax.naming.InitialContext.bind(InitialContext.java:359)
>> at
>> javax.management.remote.rmi.RMIConnectorServer.bind(RMIConnectorServer.java:635)
>>
>> at
>> javax.management.remote.rmi.RMIConnectorServer.start(RMIConnectorServer.java:427)
>>
>> ... 11 more
>> Caused by: java.rmi.ConnectException: Connection refused to host:
>> localhost; nested exception is:
>> java.net.ConnectException: Connection refused
>> at
>> sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:574)
>> at
>> sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:185)
>> at
>> sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:171)
>> at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:306)
>> at sun.rmi.registry.RegistryImpl_Stub.bind(Unknown Source)
>> at
>> com.sun.jndi.rmi.registry.RegistryContext.bind(RegistryContext.java:116)
>> ... 15 more
>> Caused by: java.net.ConnectException: Connection refused
>> at java.net.PlainSocketImpl.socketConnect(Native Method)
>> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
>> at
>> java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
>> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
>> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at
>> com.sun.enterprise.server.ss.provider.ASPlainSocketImpl$2.run(ASPlainSocketImpl.java:419)
>>
>> at java.security.AccessController.doPrivileged(Native Method)
>> at
>> com.sun.enterprise.server.ss.provider.ASPlainSocketImpl._invoke(ASPlainSocketImpl.java:416)
>>
>> at
>> com.sun.enterprise.server.ss.provider.ASPlainSocketImpl.connect(ASPlainSocketImpl.java:288)
>>
>> at
>> com.sun.enterprise.server.ss.provider.ASClientSocketImpl.connect(ASClientSocketImpl.java:267)
>>
>> at java.net.Socket.connect(Socket.java:516)
>> at java.net.Socket.connect(Socket.java:466)
>> at java.net.Socket.<init>(Socket.java:366)
>> at java.net.Socket.<init>(Socket.java:179)
>> at
>> sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(RMIDirectSocketFactory.java:22)
>>
>> at
>> sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(RMIMasterSocketFactory.java:128)
>>
>> at
>> sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:569)
>> ... 20 more
>> |#]
>>
>> [#|2008-04-20T00:47:04.287+0200|SEVERE|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|Server
>> Startup failed. Exiting...|#]
>>
>> [#|2008-04-20T00:47:04.288+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|Server
>> shutdown in progress...|#]
>>
>> [#|2008-04-20T00:47:04.288+0200|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=10;_ThreadName=main;|WEB0303:
>> Stopping Sun-Java-System/Application-Server.|#]
>>
>> [#|2008-04-20T00:47:04.289+0200|WARNING|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|CORE5061:
>> Exception :
>> com.sun.appserv.server.ServerLifecycleException: WEB0106: An error
>> occurred while stopping the web container
>> at
>> com.sun.enterprise.web.PEWebContainer.stopInstance(PEWebContainer.java:822)
>>
>> at
>> com.sun.enterprise.web.PEWebContainerLifecycle.onShutdown(PEWebContainerLifecycle.java:95)
>>
>> at
>> com.sun.enterprise.server.ApplicationServer.onShutdown(ApplicationServer.java:549)
>>
>> at
>> com.sun.enterprise.server.ondemand.OnDemandServer.onShutdown(OnDemandServer.java:131)
>>
>> at com.sun.enterprise.server.PEMain.run(PEMain.java:429)
>> at com.sun.enterprise.server.PEMain.main(PEMain.java:338)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at com.sun.enterprise.server.PELaunch.main(PELaunch.java:412)
>> Caused by: LifecycleException: WEB0103: This web container has not
>> yet been started
>> at
>> com.sun.enterprise.web.WebContainer.stop(WebContainer.java:913)
>> at
>> com.sun.enterprise.web.PEWebContainer.stopInstance(PEWebContainer.java:814)
>>
>> ... 10 more
>> |#]
>>
>> [#|2008-04-20T00:47:04.290+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|CORE5051:
>> Shutting down all J2EE applications ...|#]
>>
>> [#|2008-04-20T00:47:04.290+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|CORE
>> 5060 : Stopping all J2EE Connector 1.5 Compliant resource adapters
>> ...|#]
>>
>> [#|2008-04-20T00:47:04.292+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|CORE
>> 5061 : Resource adapters Stop() Complete|#]
>>
>> [#|2008-04-20T00:47:04.293+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|CORE5052:
>> Application shutdown complete.|#]
>>
>> [#|2008-04-20T00:47:04.293+0200|WARNING|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|CORE5061:
>> Exception :
>> java.lang.NullPointerException
>> at
>> com.sun.enterprise.util.InvocationManagerImpl.preInvoke(InvocationManagerImpl.java:136)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.preInvoke(ServerLifecycleModule.java:178)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.postEvent(ServerLifecycleModule.java:219)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.onShutdown(ServerLifecycleModule.java:273)
>>
>> at
>> com.sun.appserv.server.LifecycleModuleService.onShutdown(LifecycleModuleService.java:487)
>>
>> at
>> com.sun.enterprise.server.ApplicationServer.onShutdown(ApplicationServer.java:549)
>>
>> at
>> com.sun.enterprise.server.ondemand.OnDemandServer.onShutdown(OnDemandServer.java:131)
>>
>> at com.sun.enterprise.server.PEMain.run(PEMain.java:429)
>> at com.sun.enterprise.server.PEMain.main(PEMain.java:338)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at com.sun.enterprise.server.PELaunch.main(PELaunch.java:412)
>> |#]
>>
>> [#|2008-04-20T00:47:04.303+0200|WARNING|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|CORE5061:
>> Exception :
>> com.sun.appserv.server.ServerLifecycleException
>> at
>> com.sun.enterprise.admin.server.core.JmxConnectorLifecycle.onShutdown(JmxConnectorLifecycle.java:171)
>>
>> at
>> com.sun.enterprise.server.ApplicationServer.onShutdown(ApplicationServer.java:549)
>>
>> at
>> com.sun.enterprise.server.ondemand.OnDemandServer.onShutdown(OnDemandServer.java:131)
>>
>> at com.sun.enterprise.server.PEMain.run(PEMain.java:429)
>> at com.sun.enterprise.server.PEMain.main(PEMain.java:338)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at com.sun.enterprise.server.PELaunch.main(PELaunch.java:412)
>> |#]
>>
>> [#|2008-04-20T00:47:04.872+0200|WARNING|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|CORE5061:
>> Exception :
>> java.lang.NullPointerException
>> at
>> com.sun.enterprise.util.InvocationManagerImpl.preInvoke(InvocationManagerImpl.java:136)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.preInvoke(ServerLifecycleModule.java:178)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.postEvent(ServerLifecycleModule.java:219)
>>
>> at
>> com.sun.appserv.server.ServerLifecycleModule.onTermination(ServerLifecycleModule.java:277)
>>
>> at
>> com.sun.appserv.server.LifecycleModuleService.onTermination(LifecycleModuleService.java:496)
>>
>> at
>> com.sun.enterprise.server.ApplicationServer.onTermination(ApplicationServer.java:587)
>>
>> at com.sun.enterprise.server.PEMain.run(PEMain.java:434)
>> at com.sun.enterprise.server.PEMain.main(PEMain.java:338)
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>> at java.lang.reflect.Method.invoke(Method.java:585)
>> at com.sun.enterprise.server.PELaunch.main(PELaunch.java:412)
>> |#]
>>
>> [#|2008-04-20T00:47:04.873+0200|SEVERE|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;_RequestID=0324a2d5-9ad6-416d-b6aa-a122b9380c38;|Server
>> stopped due to Server startup failure.|#]
>>
>> [#|2008-04-20T00:47:04.874+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=12;_ThreadName=Thread-1;|sending
>> notification to server...server|#]
>>
>> [#|2008-04-20T00:47:04.876+0200|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=12;_ThreadName=Thread-1;|Server
>> shutdown complete.|#]
>>
>>
>>>
>>> Regards,
>>> Nandini
>>>
>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>
>