| Summary: | Tomcat port-check ignores address-binding | ||
|---|---|---|---|
| Product: | [RT] Virgo | Reporter: | david.nyffenegger |
| Component: | unknown | Assignee: | Project Inbox <virgo-inbox> |
| Status: | CLOSED FIXED | QA Contact: | |
| Severity: | normal | ||
| Priority: | P3 | CC: | eclipse, glyn.normington |
| Version: | 2.1.0.RELEASE | ||
| Target Milestone: | 3.0.0.M01 | ||
| Hardware: | All | ||
| OS: | All | ||
| Whiteboard: | |||
|
Description
david.nyffenegger
Thanks for reporting this. Please could you clarify something to be on the safe side: after you disabled the check in ServerLifecycleLoggingListener, did you test the scenario of having two Virgo instances on the same machine, IP address, and port and see reasonable behaviour (exception, bundle stop, Virgo stop) in that case? Assume: start two virgo processes on the same machine, bind tomcat to 10.3.5.162, resp. to 10.3.5.185. With the check enabled, the second virgo dies like that: [2010-11-05 14:15:17.031] INFO system-artifacts <DE0004I> Starting plan 'org.eclipse.virgo.web' version '2.1.0'. [2010-11-05 14:15:17.034] INFO system-artifacts <DE0004I> Starting bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 14:15:17.045] INFO start-signalling-2 <DE0005I> Started bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 14:15:17.048] INFO system-artifacts <DE0004I> Starting bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 14:15:17.421] ERROR system-artifacts <TC0011E> Failed to start Tomcat. Port 8080 is in use. [2010-11-05 14:15:17.424] INFO System Bundle Shutdown <KE0010I> Shutdown initiated. With the check disabled, the second virgo starts. Output of "netstat -l --numeric-ports -n | grep 8080" tcp 0 0 10.3.5.185:8080 0.0.0.0:* LISTEN tcp 0 0 10.3.5.162:8080 0.0.0.0:* LISTEN Now start a third virgo process with the tomcat bound on 10.3.5.185. It dies like that: [2010-11-05 13:40:34.035] INFO system-artifacts <DE0004I> Starting plan 'org.eclipse.virgo.web' version '2.1.0'. [2010-11-05 13:40:34.037] INFO system-artifacts <DE0004I> Starting bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.065] INFO start-signalling-2 <DE0005I> Started bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.068] INFO system-artifacts <DE0004I> Starting bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.365] INFO system-artifacts <TC0000I> Starting Tomcat. [2010-11-05 13:40:34.412] INFO system-artifacts <TC0010I> Creating HTTP/1.1 connector with scheme http on port 8080. [2010-11-05 13:40:34.427] INFO system-artifacts <DE0010I> Stopping bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.437] ERROR start-signalling-2 <DE0006E> Start failed for bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. java.lang.RuntimeException: bundle stopped at org.eclipse.virgo.kernel.core.internal.BundleStartTracker$StartupTrackerBundleListener.bundleChanged(BundleStartTracker.java:246) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:919) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227) at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:149) at org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1350) at org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1301) at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:377) at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:280) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:57) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:45) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy61.start(Unknown Source) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.startBundle(StandardBundleDriver.java:168) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.start(StandardBundleDriver.java:149) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.doStart(StandardBundleInstallArtifact.java:253) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.start(StandardBundleInstallArtifact.java:242) at org.eclipse.virgo.kernel.install.artifact.internal.StandardPlanInstallArtifact.doStart(StandardPlanInstallArtifact.java:121) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.start(AbstractInstallArtifact.java:193) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.start(PipelinedApplicationDeployer.java:282) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.deploy(PipelinedApplicationDeployer.java:192) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.deployArtifacts(InitialArtifactDeployer.java:155) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.run(InitialArtifactDeployer.java:145) at java.lang.Thread.run(Unknown Source) [2010-11-05 13:40:34.443] INFO system-artifacts <DE0011I> Stopped bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.450] ERROR system-artifacts <DE0006E> Start failed for bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. org.eclipse.virgo.kernel.deployer.core.DeploymentException: BundleException at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.startBundle(StandardBundleDriver.java:170) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.start(StandardBundleDriver.java:149) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.doStart(StandardBundleInstallArtifact.java:253) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.start(StandardBundleInstallArtifact.java:242) at org.eclipse.virgo.kernel.install.artifact.internal.StandardPlanInstallArtifact.doStart(StandardPlanInstallArtifact.java:121) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.start(AbstractInstallArtifact.java:193) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.start(PipelinedApplicationDeployer.java:282) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.deploy(PipelinedApplicationDeployer.java:192) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.deployArtifacts(InitialArtifactDeployer.java:155) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.run(InitialArtifactDeployer.java:145) at java.lang.Thread.run(Unknown Source) Caused by: org.osgi.framework.BundleException: Exception in org.eclipse.gemini.web.tomcat.internal.Activator.start() of bundle org.eclipse.gemini.web.tomcat. at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:806) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:755) at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:352) at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:280) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:57) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:45) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy61.start(Unknown Source) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.startBundle(StandardBundleDriver.java:168) ... 12 common frames omitted Caused by: org.eclipse.gemini.web.core.spi.ServletContainerException: Unable to start Tomcat. at org.eclipse.gemini.web.tomcat.internal.TomcatServletContainer.start(TomcatServletContainer.java:77) at org.eclipse.gemini.web.tomcat.internal.Activator.start(Activator.java:51) at org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run(BundleContextImpl.java:783) at java.security.AccessController.doPrivileged(Native Method) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:774) ... 36 common frames omitted Caused by: org.apache.catalina.LifecycleException: service.getName(): "Catalina"; Protocol handler start failed: java.net.BindException: Address already in use /10.3.5.185:8080 at org.apache.catalina.connector.Connector.start(Connector.java:1137) at org.apache.catalina.core.StandardService.start(StandardService.java:530) at org.apache.catalina.core.StandardServer.start(StandardServer.java:708) at org.eclipse.gemini.web.tomcat.internal.Tomcat.start(Tomcat.java:75) at org.eclipse.gemini.web.tomcat.internal.TomcatServletContainer.doStart(TomcatServletContainer.java:145) at org.eclipse.gemini.web.tomcat.internal.TomcatServletContainer.start(TomcatServletContainer.java:75) ... 40 common frames omitted [2010-11-05 13:40:34.452] ERROR start-signalling-2 <DE0006E> Start failed for plan 'org.eclipse.virgo.web' version '2.1.0'. java.lang.RuntimeException: bundle stopped at org.eclipse.virgo.kernel.core.internal.BundleStartTracker$StartupTrackerBundleListener.bundleChanged(BundleStartTracker.java:246) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:919) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227) at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:149) at org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1350) at org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1301) at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:377) at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:280) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:57) at org.eclipse.virgo.kernel.core.internal.StandardBundleStarter.start(StandardBundleStarter.java:45) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy61.start(Unknown Source) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.startBundle(StandardBundleDriver.java:168) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleDriver.start(StandardBundleDriver.java:149) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.doStart(StandardBundleInstallArtifact.java:253) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.bundle.StandardBundleInstallArtifact.start(StandardBundleInstallArtifact.java:242) at org.eclipse.virgo.kernel.install.artifact.internal.StandardPlanInstallArtifact.doStart(StandardPlanInstallArtifact.java:121) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.driveDoStart(AbstractInstallArtifact.java:202) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.start(AbstractInstallArtifact.java:193) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.start(PipelinedApplicationDeployer.java:282) at org.eclipse.virgo.kernel.deployer.core.internal.PipelinedApplicationDeployer.deploy(PipelinedApplicationDeployer.java:192) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.deployArtifacts(InitialArtifactDeployer.java:155) at org.eclipse.virgo.kernel.userregion.internal.InitialArtifactDeployer$ArtifactDeployingRunnable.run(InitialArtifactDeployer.java:145) at java.lang.Thread.run(Unknown Source) [2010-11-05 13:40:34.458] INFO system-artifacts <DE0013I> Uninstalling plan 'org.eclipse.virgo.web' version '2.1.0'. [2010-11-05 13:40:34.460] INFO system-artifacts <DE0010I> Stopping bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.464] INFO system-artifacts <DE0011I> Stopped bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.467] INFO system-artifacts <DE0013I> Uninstalling bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.471] INFO system-artifacts <DE0014I> Uninstalled bundle 'org.eclipse.gemini.web.core' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.493] INFO system-artifacts <DE0013I> Uninstalling bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.498] INFO system-artifacts <DE0014I> Uninstalled bundle 'org.eclipse.gemini.web.tomcat' version '1.1.0.M02-incubation'. [2010-11-05 13:40:34.513] INFO system-artifacts <DE0013I> Uninstalling bundle 'org.eclipse.virgo.web.core' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.517] INFO system-artifacts <DE0014I> Uninstalled bundle 'org.eclipse.virgo.web.core' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.530] INFO system-artifacts <DE0013I> Uninstalling bundle 'org.eclipse.virgo.web.dm' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.534] INFO system-artifacts <DE0014I> Uninstalled bundle 'org.eclipse.virgo.web.dm' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.553] INFO system-artifacts <DE0013I> Uninstalling bundle 'org.eclipse.virgo.web.tomcat' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.557] INFO system-artifacts <DE0014I> Uninstalled bundle 'org.eclipse.virgo.web.tomcat' version '2.1.0.M02-incubation'. [2010-11-05 13:40:34.569] INFO system-artifacts <DE0014I> Uninstalled plan 'org.eclipse.virgo.web' version '2.1.0'. [2010-11-05 13:40:34.572] ERROR system-artifacts <UR0002E> User region failed while deploying initial artifacts. Shutting down. [2010-11-05 13:40:34.574] INFO System Bundle Shutdown <KE0010I> Shutdown initiated. I must admit, that there are some other things to do to run multiple virgo processes on one machine, especially using JMX. But we achieved all of them without patching virgo except this tomcat issue. Some initial thinking on this issue... I agree this issue needs fixing, but the question is how. The rationale for putting that check in ServerLifecycleLoggingListener was to avoid such a stack trace mess on the console for what is essentially a common operator error. The basic fix is, of course, to delete the check and live with the mess, but I wonder if we can do better? One approach would be to attempt to beef up the check to make it match Tomcat's logic. It might be possible to get that to work, but it would be a pain to test and could get out of step with Tomcat in due course, so I wouldn't recommend it. A better approach could be to set up some kind of listener for the error detected by Tomcat. I don't know whether Tomcat supports that. Failing that, it may be possible to use some other listener approach in the Virgo code. However, the listener would need to issue a reasonable event log message and then terminate the server immediately to avoid the mess also appearing. If we can't find such a solution without adding a bunch of code and delaying the fix, it makes sense to rip out the check under this bugzilla and create an enhancement bugzilla to improve the diagnostic mess. A SpringSource Tomcat expert has suggested that we could reasonably beef up the check to include the address being bound to since the corresponding Tomcat code is simple-minded and unlikely to change. So we'll look into this unless someone has a better suggestion. Ok for me... Fixed. This will appear in 2.2.0.M02. David, I'm leaving the status as RESOLVED until you get a chance to verify this fixes the problem, at which point please would you change the status to CLOSED. Closing. |