ant-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Steve Loughran <ste...@apache.org>
Subject Re: AW: ant really slow, 100% CPU?
Date Thu, 20 Sep 2007 13:52:02 GMT
Steve Loughran wrote:
> Jan.Materne@rzf.fin-nrw.de wrote:
>> $rd bootstrap build dist
>> $build dist-lite test
>> on a WinXP with JDK 1.3.
>>
>> 19.09.2007 15:27:38,20 : Starting Ant-Build 19.09.2007 15:35:33,51 : 
>> Finishing Ant-Build
>>
>> so eight minutes for the build including the whole testsuite
>> thats ok with me ...
>>
>>
> 
> Its not ant, its the build I'm doing in smartfrog to create and zip 
> RPMs, what should take 30s was suddenly crawling along. It seems 
> slightly faster now, so maybe its a quirk of machine state. I will try 
> switching to ant1.7.0 to see if it really is an ant version issue. It 
> could just be JVM memory problems; 64 bit processes are very memory 
> hungry, so much so that I'm planning to roll back to Java 32 after the 
> next release

it appears to hang at 100% CPU during gzip

release.gzip-rpm:
       [tar] Building tar: 
/home/slo/Projects/SmartFrog/Forge/core/release/dist/rpm/smartfrog-rpm-bundle-3.12.003dev.tar
      [gzip] Building: 
/home/slo/Projects/SmartFrog/Forge/core/release/build/upload/smartfrog-rpm-bundle-3.12.003dev.gz

through the miracle that is kill -QUIT, here's the thread dump

"Attach Listener" daemon prio=10 tid=0x00002aaaf4eb1800 nid=0x44b1 
runnable [0x0000000000000000..0x0000000041139cd0]
    java.lang.Thread.State: RUNNABLE

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

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

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

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

"Finalizer" daemon prio=10 tid=0x00002aaaf42fb400 nid=0x42d6 in 
Object.wait() [0x0000000040931000..0x0000000040931c00]
    java.lang.Thread.State: WAITING (on object monitor)
         at java.lang.Object.wait(Native Method)
         - waiting on <0x00002aaab3e40380> (a 
java.lang.ref.ReferenceQueue$Lock)
         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
         - locked <0x00002aaab3e40380> (a java.lang.ref.ReferenceQueue$Lock)
         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
         at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x00002aaaf42fa800 nid=0x42d5 in 
Object.wait() [0x0000000040830000..0x0000000040830d80]
    java.lang.Thread.State: WAITING (on object monitor)
         at java.lang.Object.wait(Native Method)
         - waiting on <0x00002aaab3e42178> (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 <0x00002aaab3e42178> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x0000000040112c00 nid=0x42cf runnable 
[0x0000000040229000..0x000000004022aec0]
    java.lang.Thread.State: RUNNABLE
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:783)
         - waiting to lock <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property.resolveAllProperties(Property.java:705)
         at 
org.apache.tools.ant.taskdefs.Property.addProperties(Property.java:653)
         at 
org.apache.tools.ant.taskdefs.Property.loadEnvironment(Property.java:643)
         at 
org.apache.tools.ant.taskdefs.Property.execute(Property.java:478)
         at 
org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:288)
         at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
         at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
         at java.lang.reflect.Method.invoke(Method.java:597)
         at 
org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106)
         at org.apache.tools.ant.Task.perform(Task.java:348)
         at org.apache.tools.ant.Target.execute(Target.java:354)
         at org.apache.tools.ant.Target.performTasks(Target.java:379)
         at 
org.apache.tools.ant.Project.executeSortedTargets(Project.java:1324)
         at org.apache.tools.ant.Project.executeTarget(Project.java:1293)
         at 
org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41)
         at org.apache.tools.ant.Project.executeTargets(Project.java:1176)
         at org.apache.tools.ant.Main.runBuild(Main.java:758)
         at org.apache.tools.ant.Main.startAnt(Main.java:217)
         at org.apache.tools.ant.launch.Launcher.run(Launcher.java:257)
         at org.apache.tools.ant.launch.Launcher.main(Launcher.java:104)

"VM Thread" prio=10 tid=0x00002aaaf42f5c00 nid=0x42d4 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x000000004011d000 
nid=0x42d0 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x000000004011e400 
nid=0x42d1 runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x000000004011f800 
nid=0x42d2 runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000040120c00 
nid=0x42d3 runnable

"VM Periodic Task Thread" prio=10 tid=0x00002aaaf4567000 nid=0x42db 
waiting on condition

JNI global references: 1189

Heap
  PSYoungGen      total 21888K, used 7478K [0x00002aaade8f0000, 
0x00002aaae6a00000, 0x00002aaaf3e40000)
   eden space 21760K, 34% used 
[0x00002aaade8f0000,0x00002aaadf035978,0x00002aaadfe30000)
   from space 128K, 25% used 
[0x00002aaae69c0000,0x00002aaae69c8000,0x00002aaae69e0000)
   to   space 128K, 0% used 
[0x00002aaae69e0000,0x00002aaae69e0000,0x00002aaae6a00000)
  PSOldGen        total 63744K, used 12519K [0x00002aaab3e40000, 
0x00002aaab7c80000, 0x00002aaade8f0000)
   object space 63744K, 19% used 
[0x00002aaab3e40000,0x00002aaab4a79d30,0x00002aaab7c80000)
  PSPermGen       total 21248K, used 16705K [0x00002aaaaea40000, 
0x00002aaaaff00000, 0x00002aaab3e40000)
   object space 21248K, 78% used 
[0x00002aaaaea40000,0x00002aaaafa907e0,0x00002aaaaff00000)



the line, PropertyHelper:110 is Property.evaluate()

                 if (propertyHelper.getProperty(property) != null) { 
//** HERE **
                     return null;
                 }

Looks a bit like a deadlock, but it isnt. Because a minute later and 
we're at

main" prio=10 tid=0x0000000040112c00 nid=0x42cf runnable 
[0x0000000040229000..0x000000004022aec0]
    java.lang.Thread.State: RUNNABLE
         at java.util.ArrayList.size(ArrayList.java:177)
         at java.util.AbstractList$Itr.hasNext(AbstractList.java:339)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:786)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.evaluate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelper.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property.resolveAllProperties(Property.java:705)
         at 
org.apache.tools.ant.taskdefs.Property.addProperties(Property.java:653)
         at 
org.apache.tools.ant.taskdefs.Property.loadFile(Property.java:570)
         at 
org.apache.tools.ant.taskdefs.Property.execute(Property.java:466)
         at 
org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:288)

It does seem to be doing work on the properties structure, work that has 
slowed down from 6 minutes a build last week, to something on a par with 
the time it takes ice to erode mountain ranges.

-steve
-- 
Steve Loughran                  http://www.1060.org/blogxter/publish/5
Author: Ant in Action           http://antbook.org/

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@ant.apache.org
For additional commands, e-mail: dev-help@ant.apache.org


Mime
View raw message