STS very slow in building workspace. "Loading *-context.xml". Network activity

[swiss-chris]

Hello

I am working on various spring projects and have a particularly annoying delay upon building my project in STS. The most time is spent on "Loading */WEB-INF/spring/*-context.xml" files. Per file (we have around 10) it takes around 10 seconds !

I have noticed that during this build my network activity goes from flat (zero) to active and then back to flat after the build. I'm wondering if STS is sending some kind of request and timing out for every single *-context.xml file.

Does any one have any experience with this and know how to stop this useless waiting during build?

Your help is very much appreciated.

Chris

[Martin Lippert]

Hey Chris!

Can you tell me some more details about your setting? Which version of STS are you using? And maybe capture a stack-trace when the build is showing network activity and is stalling? (using jps and jstack for example)

Thanks!
-Martin

[swiss-chris]

Dear Martin,

Thank you very much for your reply.

The STS version I am using is 2.7.1.RELEASE. I'll try to get you that stack trace after I have a look at jps and jstack (never used them before).

Best regards,
Chris

[swiss-chris]

Hello Martin

Below is the (top) part of the jstack output - this is the only part that is different/additional compared to a jstack output when STS is idle.

What does this tell you? I'm presuming STS is calling the same Spring XSD files for every *-context.xml file.

Our *-context.xml files include the following xsi:schemaLocations:

http://www.springframework.org/schema/tx/spring-tx-2.5.xsd
http://www.springframework.org/schema/util/spring-util-2.5.xsd
http://www.springframework.org/schema/flex/spring-flex-1.0.xsd
http://www.springframework.org/schema/aop/spring-aop-2.5.xsd
http://www.springframework.org/schema/context/spring-context.xsd
http://www.springframework.org/schema/beans/spring-beans-2.5.xsd
http://www.springframework.org/schema/security/spring-security-2.0.4.xsd

If STS is really calling each of these XSD files multiple times, my question is: how most elegantly to prevent this?

A) can I turn off validation?
B) should I copy replace the schemas with local copies?
C) Can it be cached somehow?

Thanks for your help on this!

:::::::::::::::::::::::::::::::::::::::::: JSTACK :::::::::::::::::::::::::::::::::::::::::::::::::: :::

2011-10-17 21:38:07
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.2-b03 mixed mode):

"Keep-Alive-Timer" daemon prio=8 tid=0x0000000007f0c000 nid=0x117c waiting on condition [0x000000001760f000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at sun.net.www.http.KeepAliveCache.run(KeepAliveCache .java:149)
at java.lang.Thread.run(Thread.java:662)

"Background Thread-3 (Spring IDE/2.7.2)" daemon prio=6 tid=0x0000000007f0b800 nid=0x1064 runnable [0x0000000011b6e000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream. java:129)
at java.io.BufferedInputStream.fill(BufferedInputStre am.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStr eam.java:258)
at java.io.BufferedInputStream.read(BufferedInputStre am.java:317)
- locked <0x00000007fe450138> (a java.io.BufferedInputStream)
at sun.net.www.MeteredStream.read(MeteredStream.java: 116)
- locked <0x00000007fe452e00> (a sun.net.www.http.KeepAliveStream)
at java.io.FilterInputStream.read(FilterInputStream.j ava:116)
at sun.net.www.protocol.http.HttpURLConnection$HttpIn putStream.read(HttpURLConnection.java:2676)
at org.apache.xerces.impl.XMLEntityManager$Rewindable InputStream.read(Unknown Source)
at org.apache.xerces.impl.io.UTF8Reader.read(Unknown Source)
at org.apache.xerces.impl.XMLEntityScanner.load(Unkno wn Source)
at org.apache.xerces.impl.XMLEntityScanner.skipString (Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerI mpl$FragmentContentDispatcher.dispatch(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerI mpl.scanDocument(Unknown Source)
at org.apache.xerces.impl.xs.opti.SchemaParsingConfig .parse(Unknown Source)
at org.apache.xerces.impl.xs.opti.SchemaParsingConfig .parse(Unknown Source)
at org.apache.xerces.impl.xs.opti.SchemaDOMParser.par se(Unknown Source)
at org.apache.xerces.impl.xs.traversers.XSDHandler.ge tSchemaDocument(Unknown Source)
at org.apache.xerces.impl.xs.traversers.XSDHandler.pa rseSchema(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaLoader.loadSche ma(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.findS chemaGrammar(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.handl eStartElement(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.start Element(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl.sc anStartElement(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl$NS ContentDispatcher.scanRootElementHook(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerI mpl$FragmentContentDispatcher.dispatch(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerI mpl.scanDocument(Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse (Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse (Unknown Source)
at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
at org.apache.xerces.parsers.DOMParser.parse(Unknown Source)
at org.springframework.ide.eclipse.core.io.xml.Xerces DocumentLoader.loadDocument(XercesDocumentLoader.j ava:48)
at org.springframework.beans.factory.xml.XmlBeanDefin itionReader.doLoadBeanDefinitions(XmlBeanDefinitio nReader.java:388)
at org.springframework.beans.factory.xml.XmlBeanDefin itionReader.loadBeanDefinitions(XmlBeanDefinitionR eader.java:334)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$2.loadBeanDefinitions(BeansCon fig.java:376)
at org.springframework.beans.factory.xml.XmlBeanDefin itionReader.loadBeanDefinitions(XmlBeanDefinitionR eader.java:302)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$3.call(BeansConfig.java:422)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$3.call(BeansConfig.java:1)
at java.util.concurrent.FutureTask$Sync.innerRun(Futu reTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.jav a:138)
at java.util.concurrent.Executors$RunnableAdapter.cal l(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(Futu reTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.jav a:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.run Task(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

"Worker-56" prio=6 tid=0x0000000008b6f800 nid=0x10c4 in Object.wait() [0x00000000169df000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007815f5ad0> (a org.eclipse.core.internal.jobs.WorkerPool)
at org.eclipse.core.internal.jobs.WorkerPool.sleep(Wo rkerPool.java:188)
- locked <0x00000007815f5ad0> (a org.eclipse.core.internal.jobs.WorkerPool)
at org.eclipse.core.internal.jobs.WorkerPool.startJob (WorkerPool.java:220)
at org.eclipse.core.internal.jobs.Worker.run(Worker.j ava:50)

"Worker-55" prio=6 tid=0x0000000008b77800 nid=0x15c4 in Object.wait() [0x00000000168df000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007815f5ad0> (a org.eclipse.core.internal.jobs.WorkerPool)
at org.eclipse.core.internal.jobs.WorkerPool.sleep(Wo rkerPool.java:188)
- locked <0x00000007815f5ad0> (a org.eclipse.core.internal.jobs.WorkerPool)
at org.eclipse.core.internal.jobs.WorkerPool.startJob (WorkerPool.java:220)
at org.eclipse.core.internal.jobs.Worker.run(Worker.j ava:50)

"Worker-54" prio=6 tid=0x0000000008b78000 nid=0xf10 waiting on condition [0x000000000e11e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007fe4154e8> (a java.util.concurrent.FutureTask$Sync)
at java.util.concurrent.locks.LockSupport.parkNanos(L ockSupport.java:196)
at java.util.concurrent.locks.AbstractQueuedSynchroni zer.doAcquireSharedNanos(AbstractQueuedSynchronize r.java:1011)
at java.util.concurrent.locks.AbstractQueuedSynchroni zer.tryAcquireSharedNanos(AbstractQueuedSynchroniz er.java:1303)
at java.util.concurrent.FutureTask$Sync.innerGet(Futu reTask.java:227)
at java.util.concurrent.FutureTask.get(FutureTask.jav a:91)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig.readConfig(BeansConfig.java:44 8)
at org.springframework.ide.eclipse.beans.core.interna l.model.AbstractBeansConfig.getBeans(AbstractBeans Config.java:269)
at org.springframework.ide.eclipse.beans.core.interna l.model.validation.BeansConfigReloadingProjectCont ributionEventListener.start(BeansConfigReloadingPr ojectContributionEventListener.java:118)
at org.springframework.ide.eclipse.core.internal.proj ect.SpringProjectContributionManager$1.execute(Spr ingProjectContributionManager.java:88)
at org.springframework.ide.eclipse.core.internal.proj ect.SpringProjectContributionManager$9.run(SpringP rojectContributionManager.java:269)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner .java:42)
at org.springframework.ide.eclipse.core.internal.proj ect.SpringProjectContributionManager.execute(Sprin gProjectContributionManager.java:272)
at org.springframework.ide.eclipse.core.internal.proj ect.SpringProjectContributionManager.build(SpringP rojectContributionManager.java:85)
at org.eclipse.core.internal.events.BuildManager$2.ru n(BuildManager.java:728)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner .java:42)
at org.eclipse.core.internal.events.BuildManager.basi cBuild(BuildManager.java:199)
at org.eclipse.core.internal.events.BuildManager.basi cBuild(BuildManager.java:239)
at org.eclipse.core.internal.events.BuildManager$1.ru n(BuildManager.java:292)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner .java:42)
at org.eclipse.core.internal.events.BuildManager.basi cBuild(BuildManager.java:295)
at org.eclipse.core.internal.events.BuildManager.basi cBuildLoop(BuildManager.java:351)
at org.eclipse.core.internal.events.BuildManager.buil d(BuildManager.java:374)
at org.eclipse.core.internal.resources.Workspace.buil dInternal(Workspace.java:513)
at org.eclipse.core.internal.resources.Workspace.buil d(Workspace.java:422)
at org.eclipse.ui.actions.GlobalBuildAction$1.run(Glo balBuildAction.java:180)
at org.eclipse.core.internal.jobs.Worker.run(Worker.j ava:54)

[Martin Lippert]

Thanks for posting the stack trace, this provides some details on what is going on. I will try to take a closer look to see what happens and how to avoid that.

Thanks for bringing this up!
-Martin

[swiss-chris]

Hello Martin,

That would be great, thanks!

In the mean time I tried turning off all kinds of "validation" options in STS preferences, but to no avail.

Another strange feature: I have a second project that depends on a .jar created from the first project. When I clean the first project, I have the dreadfully long builds. When I clean the second project, where the *-context.xml files are taken from the .jar file created from the first project, I never get those long waits... even though I'm including almost all of the same *-context.xml files in my second project as well. Don't know if that makes any sense to any one?

Cheers,

[Martin Lippert]

This is definitely an interesting observation. Thanks for letting me know about this. I will try to see what is going on.

-Martin

[swiss-chris]

I noticed that the build is not always slow as described. It seems that often it skips the XML Schema validation. I'm thinking there might be some kind of cache and timer. Does anyone know where I might find such a setting? In that case I would tell it to validate only 1nce per day until we find a better solution.

[Kevin Tronkowski]

I am also experiencing the intermittent delay in building our project in STS in the "Loading *-context.xml" operation. I saw it in STS 2.5.2 and now in 2.8.0.

The stack trace for the Background Thread-3 does not appear to be stuck on a read though:


Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.1-b02-383 mixed mode):

"Background Thread-3 (Spring IDE/2.8.0)" daemon prio=5 tid=13c277800 nid=0x11db33000 waiting on condition [11db31000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.eclipse.jdt.internal.core.JavaModelManager.sec ondaryTypes(JavaModelManager.java:4429)
at org.eclipse.jdt.internal.core.NameLookup.findSecon daryType(NameLookup.java:591)
at org.eclipse.jdt.internal.core.NameLookup.findType( NameLookup.java:697)
at org.eclipse.jdt.internal.core.NameLookup.findType( NameLookup.java:816)
at org.eclipse.jdt.internal.core.JavaProject.findType (JavaProject.java:1262)
at org.eclipse.jdt.internal.core.JavaProject.findType (JavaProject.java:1351)
at org.eclipse.jdt.internal.core.JavaProject.findType (JavaProject.java:1255)
at org.springframework.ide.eclipse.core.java.JdtUtils .getJavaType(JdtUtils.java:350)
at org.springframework.ide.eclipse.core.java.JdtUtils .resolveClassName(JdtUtils.java:776)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtAnnotationUtils.processAnnotation(JdtAnnot ationUtils.java:41)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtMethodMetadata.init(JdtMethodMetadata.java :110)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtMethodMetadata.<init>(JdtMethodMetadata.ja va:40)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtAnnotationMetadata.init(JdtAnnotationMetad ata.java:110)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtAnnotationMetadata.<init>(JdtAnnotationMet adata.java:43)
at org.springframework.ide.eclipse.core.java.classrea ding.JdtMetadataReader.getAnnotationMetadata(JdtMe tadataReader.java:35)
at org.springframework.context.annotation.Configurati onClassUtils.checkConfigurationClassCandidate(Conf igurationClassUtils.java:70)
at org.springframework.context.annotation.Configurati onClassPostProcessor.processConfigBeanDefinitions( ConfigurationClassPostProcessor.java:216)
at com.springsource.sts.ide.metadata.process.JdtConfi gurationClassPostProcessor.postProcess(JdtConfigur ationClassPostProcessor.java:58)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$4.run(BeansConfig.java:747)
at org.eclipse.core.runtime.SafeRunner.run(SafeRunner .java:42)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig.executePostProcessor(BeansConf ig.java:740)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig.postProcess(BeansConfig.java:6 24)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig.access$8(BeansConfig.java:583)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$3.call(BeansConfig.java:449)
at org.springframework.ide.eclipse.beans.core.interna l.model.BeansConfig$3.call(BeansConfig.java:1)
at java.util.concurrent.FutureTask$Sync.innerRun(Futu reTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.jav a:138)
at java.util.concurrent.Executors$RunnableAdapter.cal l(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(Futu reTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.jav a:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.run Task(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:680)


I can provide additional thread stacks if that would be of assistance.

-- Kevin

[swiss-chris]

I temporarily solved this problem with a workaround. I removed all other project dependencies from the buildpath for the project in question (am using a jar instead). For some reason the slow xml validation only occurs when i have other STS projects on the buildpath.