Pause between webapp startup (~5 mins)??

[rob_h]

Hi folks,

I have deployed activiti 5.3 now in both a tomcat/RHEL/Oracle and tomcat/Ubuntu/Mysql environments.  Once the server has started, the performance and operation of activiti is fine.  However, during application startup, there seems to be a delay of some minutes between each webapp starting up.  The last line paused on is:

"Registered script processor for javascript extension JS".

We go for a coffee and the startup is successful with no errors on the log.

Any ideas what the application is waiting for?  It doesn't seem to be doing any processing; the CPU utilisation is very low.

Cheers!

[jcosano]

Same installation (this behaviour I had with all activiti versions)

On windows XP
17-mar-2011 8:36:39 org.apache.catalina.startup.Catalina start
INFO: Server startup in 133457 ms

On Red Hat Enterprise Linux Server
14-mar-2011 17:27:57 org.apache.catalina.startup.Catalina start
INFO: Server startup in 590509 ms

[jbarrez]

That's very strange, since I'm also testing it every release on an Ubuntu machine…. and it's faster then my Windows machine on it.

Could you post a full log of the applications booting up? Then I can have a talk with the UI guys.

[jcosano]

Attach log file

[erikwinlof]

Hi, as you've seen in the log the problem occurs when rhino is setup. Kevin's (Spring Surf) guess is that it could be some dtd missing and I think I recall a similar problem in Activiti from before, but that was when you were running your server offline. Could that be the case here?

Anyway Kevin suggested to get a stacktrace when the webapp stalls (see below), unfortunately I only have, WinXP, MacOS & Ubuntu installed so it would be excellent if any of you could provide the stacktrace.

Cheers

:: Erik

———–

Can you get a thread dump (CTRL+BREAK) during the pause?

The only time I've seen this is when it's waiting on remote resources. Could
either be the app-server insisting on downloading DTD or similar files to
validate XML (tends to be an app-server specific issue, i.e. JBoss or
similar) or a Surf configured "remote" store (but I don't think you are
using any?)

Kevin

[jcosano]

I'm using a tomcat  and I have only activiti applications.

I'm starting tomcat with 'ant tomcat.start' then, How can I force thread dump?

[jcosano]

I remember, that this machine has a proxy, but I didn't configure anything in tomcat…

anyone know how can I configure my proxy settings under tomcat… anyway I'll search into web

[erikwinlof]

Hi, you can run tomcat in the current window using:

${TOMCAT_HOME}/bin/catalina.sh run

[jcosano]

2011-03-24 09:00:15
Full thread dump Java HotSpot(TM) 64-Bit Server VM (17.0-b16 mixed mode):

"GC Daemon" daemon prio=10 tid=0x00002aaaf80ea800 nid=0x1a28 in Object.wait() [0x0000000040fc8000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00002aaab24192d0> (a sun.misc.GC$LatencyLock)
        at sun.misc.GC$Daemon.run(GC.java:100)
        - locked <0x00002aaab24192d0> (a sun.misc.GC$LatencyLock)

"Low Memory Detector" daemon prio=10 tid=0x0000000052b9e800 nid=0x1a22 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x0000000052b9c000 nid=0x1a21 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x0000000052b97800 nid=0x1a20 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x0000000052b95000 nid=0x1a1f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x0000000052b71000 nid=0x1a1e in Object.wait() [0x00000000418f8000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00002aaab22010e8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
        - locked <0x00002aaab22010e8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x0000000052b6f000 nid=0x1a1d in Object.wait() [0x000000004175c000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00002aaab2200f50> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:485)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0x00002aaab2200f50> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x0000000052b15800 nid=0x1a1b runnable [0x0000000040ec4000]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
        - locked <0x00002aaaafce9d50> (a java.net.SocksSocketImpl)
        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 java.net.Socket.connect(Socket.java:529)
        at java.net.Socket.connect(Socket.java:478)
        at sun.net.NetworkClient.doConnect(NetworkClient.java:163)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:394)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:529)
        - locked <0x00002aaaafce9c80> (a sun.net.www.http.HttpClient)
        at sun.net.www.http.HttpClient.<init>(HttpClient.java:233)
        at sun.net.www.http.HttpClient.New(HttpClient.java:306)
        at sun.net.www.http.HttpClient.New(HttpClient.java:323)
        at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:860)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:801)
        at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:726)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1049)
        - locked <0x00002aaaafce8b28> (a sun.net.www.protocol.http.HttpURLConnection)
        at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.setupCurrentEntity(XMLEntityManager.java:677)
        at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startEntity(XMLEntityManager.java:1315)
        at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startDTDEntity(XMLEntityManager.java:1282)
        at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.setInputSource(XMLDTDScannerImpl.java:283)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.dispatch(XMLDocumentScannerImpl.java:1194)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.next(XMLDocumentScannerImpl.java:1090)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$PrologDriver.next(XMLDocumentScannerImpl.java:1003)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)
        at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:140)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)
        at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)
        at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)
        at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)
        at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)
        at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
        at org.dom4j.io.SAXReader.read(SAXReader.java:465)
        at org.dom4j.DocumentHelper.parseText(DocumentHelper.java:278)
        at org.springframework.extensions.surf.util.XMLUtil.parse(XMLUtil.java:220)
        at org.springframework.extensions.surf.util.XMLUtil.parse(XMLUtil.java:236)
        at org.springframework.extensions.surf.persister.ReadOnlyStoreObjectPersister.getObjectByPath(ReadOnlyStoreObjectPersister.java:559)
        at org.springframework.extensions.surf.persister.ReadOnlyStoreObjectPersister.init(ReadOnlyStoreObjectPersister.java:384)
        at org.springframework.extensions.surf.persister.MultiObjectPersister.init(MultiObjectPersister.java:344)
        at org.springframework.extensions.surf.persister.PersisterService.initPersisters(PersisterService.java:157)
        at org.springframework.extensions.surf.persister.PersisterService.onApplicationEvent(PersisterService.java:117)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:294)
        at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:858)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:419)
        - locked <0x00002aaab1540680> (a java.lang.Object)
        at org.springframework.web.servlet.FrameworkServlet.createWebApplicationContext(FrameworkServlet.java:443)
        at org.springframework.web.servlet.FrameworkServlet.createWebApplicationContext(FrameworkServlet.java:459)
        at org.springframework.web.servlet.FrameworkServlet.initWebApplicationContext(FrameworkServlet.java:340)
        at org.springframework.web.servlet.FrameworkServlet.initServletBean(FrameworkServlet.java:307)
        at org.springframework.web.servlet.HttpServletBean.init(HttpServletBean.java:127)
        at javax.servlet.GenericServlet.init(GenericServlet.java:212)
        at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1173)
        - locked <0x00002aaab298d370> (a org.apache.catalina.core.StandardWrapper)
        at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993)
        - locked <0x00002aaab298d370> (a org.apache.catalina.core.StandardWrapper)
        at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4420)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:4733)
        - locked <0x00002aaab298d6e8> (a org.apache.catalina.core.StandardContext)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:799)
        - locked <0x00002aaab23fa218> (a java.util.HashMap)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:779)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:601)
        at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1079)
        at org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.java:1002)
        at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:506)
        at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1315)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:324)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1061)
        - locked <0x00002aaab23fa0e8> (a org.apache.catalina.core.StandardHost)
        at org.apache.catalina.core.StandardHost.start(StandardHost.java:840)
        - locked <0x00002aaab23fa0e8> (a org.apache.catalina.core.StandardHost)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
        - locked <0x00002aaab23cf8d0> (a org.apache.catalina.core.StandardEngine)
        at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:463)
        at org.apache.catalina.core.StandardService.start(StandardService.java:525)
        - locked <0x00002aaab23cf8d0> (a org.apache.catalina.core.StandardEngine)
        at org.apache.catalina.core.StandardServer.start(StandardServer.java:754)
        - locked <0x00002aaab24035e8> (a [Lorg.apache.catalina.Service
        at org.apache.catalina.startup.Catalina.start(Catalina.java:595)
        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:597)
        at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)

"VM Thread" prio=10 tid=0x0000000052b6a800 nid=0x1a1c runnable

"VM Periodic Task Thread" prio=10 tid=0x0000000052ba9800 nid=0x1a23 waiting on condition

JNI global references: 1347

Heap
def new generation   total 59008K, used 33667K [0x00002aaaae200000, 0x00002aaab2200000, 0x00002aaab2200000)
  eden space 52480K,  54% used [0x00002aaaae200000, 0x00002aaaafdb4e40, 0x00002aaab1540000)
  from space 6528K,  81% used [0x00002aaab1540000, 0x00002aaab1a6bf18, 0x00002aaab1ba0000)
  to   space 6528K,   0% used [0x00002aaab1ba0000, 0x00002aaab1ba0000, 0x00002aaab2200000)
tenured generation   total 65536K, used 10071K [0x00002aaab2200000, 0x00002aaab6200000, 0x00002aaace200000)
   the space 65536K,  15% used [0x00002aaab2200000, 0x00002aaab2bd5f60, 0x00002aaab2bd6000, 0x00002aaab6200000)
compacting perm gen  total 262144K, used 45299K [0x00002aaace200000, 0x00002aaade200000, 0x00002aaaee200000)
   the space 262144K,  17% used [0x00002aaace200000, 0x00002aaad0e3cc30, 0x00002aaad0e3ce00, 0x00002aaade200000)
No shared spaces configured.


[jcosano]

If i configure in catalina.properties (http.proxyHost,http.proxyPort,http.proxyUser,http.proxyPassword) then server starts in 22 sec

but…

I have this error when login

24-mar-2011 9:34:57 org.apache.commons.httpclient.auth.AuthChallengeProcessor selectAuthScheme
INFO: ntlm authentication scheme selected
24-mar-2011 9:34:57 org.apache.commons.httpclient.HttpMethodDirector processProxyAuthChallenge
INFO: No credentials available for NTLM <any realm>@PROXY_URLROXY_PORT
24-mar-2011 9:34:57 org.springframework.extensions.webscripts.connector.AuthenticatingConnector handshake
GRAVE: An exception occurred while attempting authentication handshake for endpoint: http://localhost:8080/activiti-rest/service
org.springframework.extensions.surf.exception.AuthenticationException: Unable to login:<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN" "http://www.w3.org/TR/html4/loose.dtd">
<HTML><HEAD><META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=iso-8859-1">
<TITLE>ERROR: Cache Access Denied</TITLE>
<STYLE type="text/css"><!–BODY{background-color:#ffffff;font-family:verdana,sans-serif}PRE{font-family:sans-serif}–></STYLE>
</HEAD>
<BODY>
<H1>ERROR</H1>
<H2>Cache Access Denied</H2>
<HR noshade size="1px">
<P>
While trying to retrieve the URL:
<A HREF="http://localhost:8080/activiti-rest/service/login">http://localhost:8080/activiti-rest/service/login</A>
<P>
The following error was encountered:
<UL>
<LI>
<STRONG>
Cache Access Denied.
</STRONG>
</UL>
</P>

<P>Sorry, you are not currently allowed to request:
<PRE>    http://localhost:8080/activiti-rest/service/login</PRE>
from this cache until you have authenticated yourself.
</P>

<P>
You need to use Netscape version 2.0 or greater, or Microsoft Internet
Explorer 3.0, or an HTTP/1.1 compliant browser for this to work.  Please
contact the <A HREF="mailto:webmaster">cache administrator</a> if you have
difficulties authenticating yourself or
<A HREF="http://eswbsz32.ggrce.com/cgi-bin/chpasswd.cgi">change</a> your default password.
</P>

<BR clear="all">
<HR noshade size="1px">
<ADDRESS>
Generated Thu, 24 Mar 2011 08:35:06 GMT by eswbsz32.ggrce.com (squid/2.7.STABLE9-20100920)
</ADDRESS>
</BODY></HTML>
  at org.activiti.surf.ActivitiRESTAuthenticator.authenticate(ActivitiRESTAuthenticator.java:101)
        at org.springframework.extensions.webscripts.connector.AuthenticatingConnector.handshake(AuthenticatingConnector.java:403)
        at org.activiti.surf.ActivitiUserFactory.authenticate(ActivitiUserFactory.java:141)
        at org.springframework.extensions.surf.mvc.LoginController.handleRequestInternal(LoginController.java:67)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
        at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:771)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:716)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:647)
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:563)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
        at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:436)
        at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:374)
        at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:302)
        at org.tuckey.web.filters.urlrewrite.NormalRewrittenUrl.doRewrite(NormalRewrittenUrl.java:195)
        at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:159)
        at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:141)
        at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:90)
        at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:417)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
        at java.lang.Thread.run(Thread.java:619)