non-deterministic failures starting Tomcat in debugger : IDEA-33615

Back to Search

Project	IntelliJ IDEA
Priority	Normal
Type	Bug
Fix versions	No Fix versions
State	Open
Assignee	Nikolay Chashnikov
Subsystem	J2EE.Tomcat
Affected versions	No Affected versions
Fixed in build	No Fixed in build

Created by Dean Thompson
5 years ago (01 Sep 2006 19:45)
Updated by root
2 years ago (17 Jan 2010 20:32)
Jira: IDEADEV-11540
(history, comments)

IDEA-33615 non-deterministic failures starting Tomcat in debugger

Issue is visible to: All Users

idea_tomcat_startup_race.zip (5 KB)

When I try to start a Tomcat project in the debugger, it fails about 20% to 50% of the time. (I go through good periods where it is about 20%, and bad periods where it is more like 50%.) I suspect a race condition, for several reasons:

There are a variety of failure modes, from missing jar files (which will not be missing next time) to mysterious unloading or reloading of the context. I will attach a zip file containing the log output from 4 different failure modes.
If I have a client attempting HTTP requests of Tomcat while I am starting Tomcat, the startup attempt is much more likely to fail – it sometimes seems 80% likely to fail.
I get the impression that if I wait longer after stopping Tomcat before restarting it, the startup is less likely to fail. It is hard to be sure of this, though.

I should also mention that startup very rarely fails on the first attempt in a newly started Idea.

Environment: Windows XP.
Tomcat 5.5.16.

Dean Thompson

15 Sep 2006 02:45

5 years ago

Now this is happening to make on perhaps 90% of startup attempts. It makes it very difficult to use Tomcat within IDEA at all. I have to try over and over again until eventually it starts successfully. If there is anything I can do to help debug this, please let me know.

Dean Thompson

16 Sep 2006 02:12

5 years ago

I just experienced a new failure mode:

cmd /c C:\apache-tomcat-5.5.16\bin\catalina.bat run
Connected to the target VM, address: '127.0.0.1:3242', transport: 'socket'
Using CATALINA_BASE: C:\Documents and Settings\Dean Thompson\.IntelliJIdea60\system\tomcat_Tomcat_CME_2ca89961
Using CATALINA_HOME: C:\apache-tomcat-5.5.16
Using CATALINA_TMPDIR: C:\apache-tomcat-5.5.16\temp
Using JRE_HOME: C:\Program Files\Java\jdk1.5.0_06
Sep 15, 2006 5:10:35 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.5.0_06\bin;.;C:\WINDOWS\system32;C:\WINDOWS;c:\cygwin\home\Dean Thompson\bin;c:\Program Files\Java\jdk1.5.0_06\bin;c:\ruby\bin;c:\cygwin\usr\bin;c:\Program Files\apache-ant-1.6.5\bin;c:\java\anteater-0.9.16\bin;C:\Program Files\MySQL\MySQL Server 5.0\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\ATI Technologies\ATI Control Panel;C:\Program Files\Microsoft Office\OFFICE11\Business Contact Manager\IM;C:\Program Files\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\Microsoft Office\OFFICE11\Business Contact Manager\
Sep 15, 2006 5:10:36 PM org.apache.coyote.http11.Http11BaseProtocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Sep 15, 2006 5:10:36 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 984 ms
Sep 15, 2006 5:10:36 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Sep 15, 2006 5:10:36 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.16
Sep 15, 2006 5:10:36 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Sep 15, 2006 5:10:37 PM org.apache.catalina.core.StandardContext resourcesStart
SEVERE: Error starting static Resources

java.lang.IllegalArgumentException: Document base C:\apache-tomcat-5.5.16\webapps\cme does not exist or is not a readable directory

…

java.lang.IllegalArgumentException: Document base C:\apache-tomcat-5.5.16\webapps\cme does not exist or is not a readable directory
 at org.apache.naming.resources.FileDirContext.setDocBase(FileDirContext.java:140)
 at org.apache.catalina.core.StandardContext.resourcesStart(StandardContext.java:3814)
 at org.apache.catalina.core.StandardContext.start(StandardContext.java:3985)
 at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:759)
 at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:739)
 at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:524)
 at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:904)
 at org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.java:867)
 at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:474)
 at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1112)
 at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:310)
 at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
 at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1021)
 at org.apache.catalina.core.StandardHost.start(StandardHost.java:718)
 at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
 at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:442)
 at org.apache.catalina.core.StandardService.start(StandardService.java:450)
 at org.apache.catalina.core.StandardServer.start(StandardServer.java:709)
 at org.apache.catalina.startup.Catalina.start(Catalina.java:551)
 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 org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:275)
 at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)

Sep 15, 2006 5:10:37 PM org.apache.catalina.core.StandardContext start
SEVERE: Error in resourceStart()
Sep 15, 2006 5:10:37 PM org.apache.catalina.core.StandardContext start
SEVERE: Error getConfigured
Sep 15, 2006 5:10:37 PM org.apache.catalina.core.StandardContext start
SEVERE: Context [/cme] startup failed due to previous errors
Sep 15, 2006 5:10:37 PM org.apache.catalina.core.StandardContext stop
INFO: Container org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/cme] has not been started
Sep 15, 2006 5:10:38 PM org.apache.coyote.http11.Http11BaseProtocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
Sep 15, 2006 5:10:38 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Sep 15, 2006 5:10:38 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/78 config=null
Sep 15, 2006 5:10:38 PM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Sep 15, 2006 5:10:39 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 2891 ms
Connected to server

Dean Thompson

03 Nov 2006 19:18

5 years ago

I have discovered a work-around that sheds light on the underlying problem. It turns out that every time I run Tomcat within IDEA, it creates a deployment directory within $CATALINA_HOME/webapps. (I don't know why it creates it there – seems to me that it should only create the deployment directory within $CATALINA_BASE/webapps.) If I delete the deployment directory from $CATALINA_HOME/webapps before starting Tomcat inside IDEA (every time I start Tomcat!), it reliably starts.

Vladimir

31 Jul 2008 20:12

3 years ago

Similar behaviour with IDEA 7.0.3 and Tomcat 6.0.16. Workaround was the same - ant task that removes deployment directory before every application launch. But it was real pain to work with Tomcat in IDEA before Dean's tip was found!