[embedded] GFv3 is started on already bound port

glassfishrobot commented 15 years ago

Steps to reproduce: 1. Start something on port 8080 (e.g., Tomcat 6.0) 2. Try to start GFv3 on the same HTTP port.

As the result GFv3 is successfully started instead of throwing exception that port is already in use.

Both standalone and embedded GFv3 are affected.

Environment

Operating System: Windows XP Platform: PC

Affected Versions

[V3]

glassfishrobot commented 6 years ago

Issue Imported From: https://github.com/javaee/glassfish/issues/10690
Original Issue Raised By:@glassfishrobot
Original Issue Assigned To: @yaminikb
Original Issue Closed By:@glassfishrobot

glassfishrobot commented 15 years ago

@glassfishrobot Commented bavik78 said: kromanvs and victa are CC-ed

glassfishrobot commented 15 years ago

@glassfishrobot Commented jfarcand said: The issue seems to only happens on win XP as on linux I do get:

SEVERE: doSelect IOException java.net.BindException: Address already in use: 8080=com.sun.enterprise.v3.services.impl.monitor.MonitorableSelectorHandler@12fb24c at com.sun.grizzly.TCPSelectorHandler.initSelector(TCPSelectorHandler.java:446) at com.sun.grizzly.TCPSelectorHandler.preSelect(TCPSelectorHandler.java:393) at com.sun.grizzly.SelectorHandlerRunner.doSelect(SelectorHandlerRunner.java:183) at com.sun.grizzly.SelectorHandlerRunner.run(SelectorHandlerRunner.java:130) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619)

glassfishrobot commented 15 years ago

@glassfishrobot Commented jfarcand said: Do not allow binding on occupied port for win32

Sending http/src/main/java/com/sun/grizzly/http/SelectorThreadConfig.java Transmitting file data . Committed revision 3835.

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: Still reproduced on b74. Moreover, PortImpl.bind method never throws IOException.

glassfishrobot commented 14 years ago

@glassfishrobot Commented jfarcand said: True. You need to add -Dcom.sun.grizzly.http.setReuseAddress=false.

This is most likely a bug in the JDK. I will update the issue once I have received the confirmation.

In any case, this cannot be fixed for v3 FCS as it create too many side effect.

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: Small correction - the property name is com.sun.grizzly.http.reuseAddress.

However, the use of this property cannot be considered as workaround. With reuseAddress=false the behavior is following: 1. Server is not bound to already bound port. This is OK. 2. But logs contain no errors and server thinks that it is correctly started on the already bound port.

Fortunately, the problem can be easily workarounded in another way in case of embedded GF (just to create ServerSocket on the port and close it before server.creationPort method invocation. However, in case of standalone GF this can be an issue

glassfishrobot commented 14 years ago

@glassfishrobot Commented jfarcand said: Found a workaround that will work for all I think...is to not call setReuseAddress. The default JDK setting should will be used instead based on the platform. Will do more test and try to get it included in v3 FCS.

glassfishrobot commented 14 years ago

@glassfishrobot Commented jfarcand said: Alexey is now the owner

glassfishrobot commented 14 years ago

@glassfishrobot Commented kumara said: Addressed by integration of grizzly build 1.9.18k to b74b and to trunk.

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: After the fix the behavior is changed, but in fact the issue still not be considered as fixed.

Currently (b74b), starting GFv3 on already bound port: 1. Does not acquire this port. This is result of the fix. 2. But, there are no any errors in the log. Moreover, GF thinks that it is successfully started on the port with the corresponding message in the log.

Expected behavior must be: 1. Error message with IOException in the log. 2. For GF embedded: server.createPort MUST throw IOException.

glassfishrobot commented 14 years ago

@glassfishrobot Commented cheeser said: asadmin properly reports that the start up failed. Using "java -jar glassfish.jar" also properly logs the port is in use but is a little less clear about the failure to start up. Here's the output I get on Windows XP with 1.6.0_17 and tomcat 6.0.20 running on port 8080:

C:\glassfishv3\glassfish\modules>echo %ERRORLEVEL% 0

It seems that we're properly responding to the port in use though the second case could probably be improved to make the failure more obvious.

glassfishrobot commented 14 years ago

@glassfishrobot Commented cheeser said: adding myself to the CC list

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: My fault. The standalone version is not affected. Only GF-embedded has this problem. See log of startup and deployemnt of GF-embedded on already bound port below. As you can see no exceptions are thrown.

08.12.2009 21:27:31 Launcher startup INFO: Prepare embedded server file system builder. 08.12.2009 21:27:31 Launcher startup INFO: Prepare embedded server builder. 08.12.2009 21:27:31 Launcher startup INFO: Build server. 08.12.2009 21:27:34 com.sun.enterprise.v3.server.AppServerStartup run INFO: GlassFish v3 (74b) startup time : Embedded(1610ms) startup services(1234ms) total(2844ms) 08.12.2009 21:27:35 com.sun.enterprise.transaction.JavaEETransactionManagerSimplified initDelegates INFO: Using com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate as the delegate 08.12.2009 21:27:35 org.glassfish.admin.mbeanserver.JMXStartupService$JMXConnectorsStarterThread run INFO: JMXStartupService: JMXConnector system is disabled, skipping. 08.12.2009 21:27:35 AppServerStartup run INFO: [Thread[GlassFish Kernel Main Thread,5,main]] started 08.12.2009 21:27:35 Launcher startup INFO: Add web container to server. 08.12.2009 21:27:35 Launcher startup INFO: Create port HTTP port. 08.12.2009 21:27:36 org.hibernate.validator.util.Version INFO: Hibernate Validator null 08.12.2009 21:27:36 org.hibernate.validator.engine.resolver.DefaultTraversableResolver detectJPA INFO: Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver. 08.12.2009 21:27:37 Launcher startup INFO: Starting server. 08.12.2009 21:27:37 Launcher startup INFO: Deploying application to embedded server. 08.12.2009 21:27:38 com.sun.common.util.logging.LoggingConfigImpl openPropFile INFO: Cannot read logging.properties file. 08.12.2009 21:27:38 com.sun.enterprise.web.WebContainer createHttpListener INFO: Created HTTP listener embedded-listener on port 8080 08.12.2009 21:27:38 com.sun.enterprise.web.WebContainer configureHttpServiceProperties WARNING: pewebcontainer.invalid_http_service_property 08.12.2009 21:27:38 com.sun.enterprise.web.WebContainer createHosts INFO: Created virtual server server 08.12.2009 21:27:40 com.sun.enterprise.web.WebContainer loadSystemDefaultWebModules INFO: Virtual server server loaded system default web module 08.12.2009 21:27:50 com.sun.enterprise.security.SecurityLifecycle INFO: security.secmgroff 08.12.2009 21:27:51 com.sun.enterprise.security.SecurityLifecycle onInitialization INFO: Security startup service called 08.12.2009 21:27:51 com.sun.enterprise.security.PolicyLoader loadPolicy INFO: policy.loading 08.12.2009 21:27:51 com.sun.enterprise.security.auth.realm.Realm doInstantiate INFO: Realm admin-realm of classtype com.sun.enterprise.security.auth.realm.file.FileRealm successfully created. 08.12.2009 21:27:51 com.sun.enterprise.security.auth.realm.Realm doInstantiate INFO: Realm file of classtype com.sun.enterprise.security.auth.realm.file.FileRealm successfully created. 08.12.2009 21:27:51 com.sun.enterprise.security.auth.realm.Realm doInstantiate INFO: Realm certificate of classtype com.sun.enterprise.security.auth.realm.certificate.CertificateRealm successfully created. 08.12.2009 21:27:51 com.sun.enterprise.security.SecurityLifecycle onInitialization INFO: Security service(s) started successfully.... classLoader = WebappClassLoader (delegate=true; repositories=WEB-INF/classes/) SharedSecrets.getJavaNetAccess()=java.net.URLClassLoader$7@1087d61 08.12.2009 21:27:57 com.sun.enterprise.web.WebApplication start INFO: Loading application SampleApplication at /SampleApplication

glassfishrobot commented 14 years ago

@glassfishrobot Commented kumara said: The issue affects only embedded GlassFish where most users specify their own ports and hence the probability of the issue occurring is low. Excluding from v3 list because it is not a show stopper.

glassfishrobot commented 14 years ago

@glassfishrobot Commented @bshannon said: Cc

glassfishrobot commented 14 years ago

@glassfishrobot Commented oleksiys said: Can you pls. describe the step how I can reproduce the issue locally?

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: Created an attachment (id=4186) Code snipped to reproduce the problem

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: 1. Download latest embedded GF library (e.g., from http://download.java.net/maven/glassfish/org/glassfish/extras/glassfish-embedded-web/3.0.1-b01/glassfish-embedded-web-3.0.1-b01.jar) 2. Start something on port "X" (e.g., Tomcat) 3. Launch attached Launcher class with the downloaded embedded GF library in classpath and following parameters: <port "X" from previous step>

As you can see, no exception is thrown and no errors in the log. Expected behavior must be: IOException is thrown on the line "server.createPort(port);"

glassfishrobot commented 14 years ago

@glassfishrobot Commented oleksiys said: target for ms7

glassfishrobot commented 14 years ago

@glassfishrobot Commented oleksiys said: reassigning to Ryan

glassfishrobot commented 14 years ago

@glassfishrobot Commented @rlubke said: Would it be possible for you to double check the Launcher code?

When I run this code with out having another process on, say port 8080, I'm not able to see 8080 in netstat.

Thanks, -rl

glassfishrobot commented 14 years ago

@glassfishrobot Commented bavik78 said: Works for me.

"netstat -a" command answers following message: TCP 0.0.0.0:8080 :0 LISTENING

glassfishrobot commented 14 years ago

@glassfishrobot Commented @rlubke said: OK, it seems there some issue with the 3.1 version of the embedded web jar, but that's a separate issue.

As far as this issue goes, the output provided on Dec 8 18:27:16 does show the web container logging this output:

INFO: Created HTTP listener embedded-listener on port 8080

But at no point in time is a Selector initialized for grizzly. If it were, we'd see the following message:

Grizzly Framework 1.9.18-o started in: 192ms listening on port 8080

So that leads me to believe that it isn't really binding to an already bound port.

Using the attached test case when no other process is bound to 8080 yields the following log message:

Nov 3, 2010 9:24:47 PM com.sun.enterprise.v3.services.impl.GrizzlyProxy$2$1 onReady INFO: Grizzly Framework 1.9.18-k started in: 114ms listening on port 8080

However, once another process is bound to 8080, and the test case is launched, no such message is logged.

There seems to be a timing issue in the embedded case. AppServerStartup attempts to determine if the server should shut down if there are any severe issue starting any of the server services.

for (Future<Result> future : futures) { try { try { // wait for 3 seconds for an eventual status, otherwise ignore if (future.get(3, TimeUnit.SECONDS).isFailure())

{ final Throwable t = future.get().exception(); logger.log(Level.SEVERE, "Shutting down v3 due to startup exception : " + t.getMessage()); logger.log(Level.FINE, future.get().exception().getMessage(), t); events.send(new Event(EventTypes.SERVER_SHUTDOWN)); shutdown(); return; }

} catch(TimeoutException e)

{ logger.warning("Timed out, ignoring some startup service status"); }

} catch(Throwable t)

{ logger.log(Level.SEVERE, t.getMessage(), t); }

}

In the case of the non-embedded case, if the server starts and there was an issue binding to one of the configured ports, the failure logic above is invoked as the list of futures has values.

In the embedded case, at the time this logic is invoked, the grizzly framework hasn't been initialized, so the list is empty. Once grizzly is initialized, an exception does occur on the bind and it pushes the future to the list, but as that list is never checked again after the pass shown above, no error is displayed.

Re-assigning to the embedded team for further evaluation.

glassfishrobot commented 13 years ago

@glassfishrobot Commented bhavanishankar said: This is fixed in v3.1. If the port is already occupied, Embedded GlassFish shuts down immediately with "no free port within range" error.

I tried this Launcher.java (as per new APIs) on a Windows machine and it works as expected:

import org.glassfish.embeddable.*;

public class Launcher {

public static void main(String[] args) { try

{ GlassFishProperties props = new GlassFishProperties(); props.setPort("http-listener", 8080); GlassFish gf = GlassFishRuntime.bootstrap().newGlassFish(props); gf.start(); gf.dispose(); }

catch (Throwable t)

{ t.printStackTrace(); }

} }

If the GlassFish is already running, then this program aborts with the following output:

Nov 30, 2010 3:40:01 PM com.sun.enterprise.util.EarlyLogger add INFO: Total time to parse domain.xml: 115 milliseconds Nov 30, 2010 3:40:01 PM com.sun.logging.LogDomains$1 log INFO: Cannot find javadb client jar file, derby jdbc driver will not be available by default. Nov 30, 2010 3:40:01 PM org.hibernate.validator.util.Version INFO: Hibernate Validator null Nov 30, 2010 3:40:01 PM org.hibernate.validator.engine.resolver.DefaultTraversableResolver detectJPA INFO: Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver. Nov 30, 2010 3:40:02 PM com.sun.enterprise.v3.services.impl.GrizzlyService createNetworkProxy INFO: Network listener https-listener on port 0 disabled per domain.xml Nov 30, 2010 3:40:02 PM com.sun.logging.LogDomains$1 log INFO: GlassFish Server Open Source Edition 3.1-SNAPSHOT (Bhavani-private) startup time : Embedded (1,212ms), startup ser vices(641ms), total(1,853ms) Nov 30, 2010 3:40:02 PM com.sun.logging.LogDomains$1 log SEVERE: Shutting down v3 due to startup exception : No free port within range: 8080=com.sun.enterprise.v3.services.impl. monitor.MonitorableSelectorHandler@1ec58a Nov 30, 2010 3:40:02 PM com.sun.logging.LogDomains$1 log INFO: Server shutdown initiated Nov 30, 2010 3:40:02 PM AppServerStartup run INFO: [Thread[GlassFish Kernel Main Thread,5,main]] started Nov 30, 2010 3:40:02 PM com.sun.logging.LogDomains$1 log INFO: Already stopped, so just returning

glassfishrobot commented 14 years ago

@glassfishrobot Commented File: Launcher.java Attached By: bavik78

glassfishrobot commented 15 years ago

@glassfishrobot Commented Issue-Links: depends on GLASSFISH-10553

glassfishrobot commented 15 years ago

@glassfishrobot Commented Was assigned to bhavanishankar

glassfishrobot commented 7 years ago

@glassfishrobot Commented This issue was imported from java.net JIRA GLASSFISH-10690

glassfishrobot commented 15 years ago

@glassfishrobot Commented Reported by bavik78

glassfishrobot commented 13 years ago

@glassfishrobot Commented Marked as fixed on Monday, November 29th 2010, 6:15:16 pm

eclipse-ee4j / glassfish

[embedded] GFv3 is started on already bound port #10690

Environment

Affected Versions

}