Very long startup time with 100% CPU on 3.3g

cmgray — Wed, 15 Sep 2010 14:06:24 GMT

We just upgraded to 3.3g and now each time we need to restart the Alfresco app, startup takes forever, usually longer than an hour.Startup was quick, just a couple of minutes on 3.2.It get to this point in the startup process06:04:56,419 INFO [org.alfresco.service.descriptor.DescriptorService] Alfr

Re: Very long startup time with 100% CPU on 3.3g

mrogers — Wed, 15 Sep 2010 14:16:33 GMT

Is that just the first restart or does it happen every time?

And in general Java will use all the memory that is allocated to it. Was there anything that made you think there was a problem?

Re: Very long startup time with 100% CPU on 3.3g

bnice — Thu, 16 Sep 2010 09:57:20 GMT

What does your log say?

Re: Very long startup time with 100% CPU on 3.3g

cmgray — Fri, 17 Sep 2010 15:46:42 GMT

Is that just the first restart or does it happen every time?

And in general Java will use all the memory that is allocated to it. Was there anything that made you think there was a problem?

It is happening every time. This morning I needed to restart and it took nearly an hour and half to get from the first line in this log to the final one when the web app was finally available to users.

07:23:01,228 INFO  [org.alfresco.util.OpenOfficeConnectionTester] The OpenOffice connection was re-established.
08:40:34,958 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 342 Web Scripts (+0 failed), 577 URLs
08:40:34,958 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 2 Package Description Documents (+0 failed) 
08:40:34,958 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 1 Schema Description Documents (+0 failed) 
08:40:34,960 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Repository Web Script Container (in 3887844.0ms)
08:40:34,960 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:34,961 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:40,304 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 225 Web Scripts (+0 failed), 232 URLs
08:40:40,306 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed) 
08:40:40,306 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed) 
08:40:40,352 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 1276.385ms)
08:40:40,404 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:40,470 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:40,521 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:40,525 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:40,578 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:40,582 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:44,557 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 51 Web Scripts (+0 failed), 58 URLs
08:40:44,558 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 8 Package Description Documents (+0 failed) 
08:40:44,558 INFO  [org.springframework.extensions.webscripts.DeclarativeRegistry] Registered 0 Schema Description Documents (+0 failed) 
08:40:44,567 INFO  [org.springframework.extensions.webscripts.AbstractRuntimeContainer] Initialised Spring Surf Container Web Script Container (in 597.23596ms)
08:40:44,727 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:44,807 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:44,823 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:44,827 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
08:40:44,842 INFO  [org.springframework.extensions.webscripts.TemplateProcessorRegistry] Registered template processor freemarker for extension ftl
08:40:44,846 INFO  [org.springframework.extensions.webscripts.ScriptProcessorRegistry] Registered script processor javascript for extension js
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

I have a 2 GB max set for the Java heap and I understand that Java will allocate most/all of that right away but the machine has 12GB of memory allocated to it. Java uses its 2GB and something else (openoffice possibly) is sucking up the rest.

There are no errors in the log or anything that I can see. It just goes through normal startup, gets to the line where it says the OpenOffice connection was re-established. Then the CPU usage goes to 100% and it does something for over an hour then finishes starting up. The behavior is very repeatable.

Re: Very long startup time with 100% CPU on 3.3g

cmgray — Fri, 17 Sep 2010 15:51:06 GMT

Another side-effect that we during this period of 100% cpu usage is that the number of open files is huge. We usually go over 8000 open files during this time. And then once the app finishes starting and the CPU's settle down, the number of open files drops to a few hundred.

The majority of the open files appear to be lucene-index files.

Re: Very long startup time with 100% CPU on 3.3g

cmgray — Fri, 17 Sep 2010 21:50:11 GMT

I may have solved this.

Turns out that the user that starts alfresco no longer had access to a few folders within the lucene-indexes folder. This was apparently causing the delay on startup because after fixing this it started up in just about 3 minutes instead of the 1.5 hours it had been taking.

So for now things look back to normal.

topic Re: Very long startup time with 100% CPU on 3.3g in Alfresco Archive

Very long startup time with 100% CPU on 3.3g

Re: Very long startup time with 100% CPU on 3.3g

Re: Very long startup time with 100% CPU on 3.3g

Re: Very long startup time with 100% CPU on 3.3g

Re: Very long startup time with 100% CPU on 3.3g

Re: Very long startup time with 100% CPU on 3.3g