AW: ant really slow, 100% CPU?

$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 ...


Jan
 

>-----Ursprüngliche Nachricht-----
>Von: Jan.Maternerzf.fin-nrw.de [mailto:Jan.Maternerzf.fin-nrw.de] 
>Gesendet: Mittwoch, 19. September 2007 15:25
>An: devant.apache.org
>Betreff: AW: ant really slow, 100% CPU?
>
>>I've just rebuilt ant and now its really, really
slow to build. I've 
>>just rolled back those extra synchronized bits I'd
added, and that 
>>doesnt seem to be it.
>>
>>-its spinning at 100%, and its memory footprint is
high, even 
>>given that 
>>this is a 64-bit JVM:
>>
>>
>>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM 
  TIME+  COMMAND 
>>
>>24273 slo       17   0 1402m 326m 9512 S  100  5.5  
2:18.35 java
>>
>>it could be swapping, but heap useage is actually
pretty slow
>(currently 
>>about 50MB, according to jconsole).
>
>>-can anyone think of an obvious change in the last
couple of months
>that 
>>would slow things down?
>
>I had changed the buildfile using an additional JUnit
formatter - but I
>havent realized any slowness ...
>
>
>>-has anyone else noticed a change in performance?
>
>No ...
>I'll do a test ...
>
>Jan
>
>--------------------------------------------------------
-------------
>To unsubscribe, e-mail: dev-unsubscribeant.apache.org
>For additional commands, e-mail: dev-helpant.apache.org
>
>

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

Jan.Maternerzf.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

-steve

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

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

Steve Loughran wrote:
> Jan.Maternerzf.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/sma
rtfrog-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:1
59)

"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(PropertyHelp
er.java:783)
         - waiting to lock <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4459d60> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.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(Propert
y.java:653)
         at 
org.apache.tools.ant.taskdefs.Property.loadEnvironment(Prope
rty.java:643)
         at 
org.apache.tools.ant.taskdefs.Property.execute(Property.java
:478)
         at 
org.apache.tools.ant.UnknownElement.execute(UnknownElement.j
ava:288)
         at
sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
         at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
thodAccessorImpl.java:25)
         at
java.lang.reflect.Method.invoke(Method.java:597)
         at 
org.apache.tools.ant.dispatch.DispatchUtils.execute(Dispatch
Utils.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.ja
va:1324)
         at
org.apache.tools.ant.Project.executeTarget(Project.java:1293
)
         at 
org.apache.tools.ant.helper.DefaultExecutor.executeTargets(D
efaultExecutor.java:41)
         at
org.apache.tools.ant.Project.executeTargets(Project.java:117
6)
         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(PropertyHelp
er.java:786)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4c21d30> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.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(Propert
y.java:653)
         at 
org.apache.tools.ant.taskdefs.Property.loadFile(Property.jav
a:570)
         at 
org.apache.tools.ant.taskdefs.Property.execute(Property.java
:466)
         at 
org.apache.tools.ant.UnknownElement.execute(UnknownElement.j
ava: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.106
0.org/blogxter/publish/5
Author: Ant in Action           http://antbook.org/

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

And, some minutes later, we're still in the same state

"main" prio=10 tid=0x0000000040112c00 nid=0x42cf
runnable 
[0x0000000040229000..0x000000004022aec0]
    java.lang.Thread.State: RUNNABLE
         at java.util.Vector.contains(Vector.java:320)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:105)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
         at 
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
         - locked <0x00002aaab4013548> (a 
org.apache.tools.ant.PropertyHelper)
         at 
org.apache.tools.ant.PropertyHelper.parseNextProperty(Proper
tyHelper.java:541)
         at 
org.apache.tools.ant.PropertyHelper.parseProperties(Property
Helper.java:502)
         at 
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:390)
         - locked <0x00002aaab3f5ea38> (a 
org.apache.tools.ant.RuntimeConfigurable)
         at 
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:349)
         at
org.apache.tools.ant.Task.maybeConfigure(Task.java:202)
         at 
org.apache.tools.ant.UnknownElement.configure(UnknownElement
.java:193)
         at 
org.apache.tools.ant.UnknownElement.maybeConfigure(UnknownEl
ement.java:160)
         at
org.apache.tools.ant.Task.perform(Task.java:347)
         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.ja
va:1324)
         at
org.apache.tools.ant.Project.executeTarget(Project.java:1293
)
         at 
org.apache.tools.ant.helper.DefaultExecutor.executeTargets(D
efaultExecutor.java:41)
         at
org.apache.tools.ant.Project.executeTargets(Project.java:117
6)
         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)



Property/PropertyHelper is the part of the system that has
lots of 
Delegates changes in it. This looks suspiciously like an
infinite loop 
kicking in, even though the stack code in
Property.evaluate() appears 
designed to stop this kind of thing.

I'm rolling back to Ant1.7.0. Something is broken, and it is
breaking my 
new machine. Which, having 4 cpus, is probably more prone
than others to 
concurrency problems.

-steve



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

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

On 9/20/07, Steve Loughran <stevelapache.org> wrote:
> it appears to hang at 100% CPU during gzip
>
> release.gzip-rpm:
>        [tar] Building tar: ...
>       [gzip]
Building:.../smartfrog-rpm-bundle-3.12.003dev.gz
>
> through the miracle that is kill -QUIT, here's the
thread dump

Did I miss the gzip task in the stack trace? In both dumps
you
provided, I see only property stuff, so how does that relate
to
gzip??? Thanks, --DD

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

Dominique Devienne wrote:
> On 9/20/07, Steve Loughran <stevelapache.org> wrote:
>> it appears to hang at 100% CPU during gzip
>>
>> release.gzip-rpm:
>>        [tar] Building tar: ...
>>       [gzip]
Building:.../smartfrog-rpm-bundle-3.12.003dev.gz
>>
>> through the miracle that is kill -QUIT, here's the
thread dump
> 
> Did I miss the gzip task in the stack trace? In both
dumps you
> provided, I see only property stuff, so how does that
relate to
> gzip??? Thanks, --DD
> 

nothing, its just after that task that everything seems to
lock up.

But sometimes it jams in other places; other times it just
keeps going. 
That is all the sign of race conditions to me: inconsistent
behaviour
-- 
Steve Loughran                  http://www.106
0.org/blogxter/publish/5
Author: Ant in Action           http://antbook.org/

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

1) Some of the traces seem to imply a bug.
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
        at
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
        - locked <0x00002aaab4013548> (a
org.apache.tools.ant.PropertyHelper)
        at
org.apache.tools.ant.PropertyHelper.parseNextProperty(Proper
tyHelper.java:541)
        at
org.apache.tools.ant.PropertyHelper.parseProperties(Property
Helper.java:502)
        at
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:390)
The intent of Property.PropertyResolver is I think to remain
in
the Property task - the trace seems to imply that it has
escaped from that task.

2) some of the new code seems to be very inefficent:
    private void resolveAllProperties(Map props) throws
BuildException {
        PropertyHelper propertyHelper = (PropertyHelper)
PropertyHelper.getPropertyHelper(
                getProject()).clone();
        propertyHelper.add(new PropertyResolver(props));
This means that when one does <property
env=".."/>, for
each env variable, the propertyhelper is cloned.

3) The reason for this is to allow different property
demarcations -
using ProperyExpander's.
 The use-case for this is to allow "${$-$}"
type expansion (this is
a much requested enhancement).

and in something like a properties file:

action=cut
cut=the cut action
do=the action is ${$}
paste=the paste action

can get difficult to parse. The new code
does this is a nice way (except for the
ThreadLocal).

Peter
On 9/20/07, Steve Loughran <stevelapache.org> wrote:
> Dominique Devienne wrote:
> > On 9/20/07, Steve Loughran <stevelapache.org> wrote:
> >> it appears to hang at 100% CPU during gzip
> >>
> >> release.gzip-rpm:
> >>        [tar] Building tar: ...
> >>       [gzip]
Building:.../smartfrog-rpm-bundle-3.12.003dev.gz
> >>
> >> through the miracle that is kill -QUIT, here's
the thread dump
> >
> > Did I miss the gzip task in the stack trace? In
both dumps you
> > provided, I see only property stuff, so how does
that relate to
> > gzip??? Thanks, --DD
> >
>
> nothing, its just after that task that everything seems
to lock up.
>
> But sometimes it jams in other places; other times it
just keeps going.
> That is all the sign of race conditions to me:
inconsistent behaviour
It appears that the new code for
> --
> Steve Loughran                  http://www.106
0.org/blogxter/publish/5
> Author: Ant in Action           http://antbook.org/
>
>
------------------------------------------------------------
---------
> To unsubscribe, e-mail: dev-unsubscribeant.apache.org
> For additional commands, e-mail: dev-helpant.apache.org
>
>

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

Peter Reilly wrote:
> 1) Some of the traces seem to imply a bug.


clearly 

>
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
>         at
>
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
>         - locked <0x00002aaab4013548> (a
> org.apache.tools.ant.PropertyHelper)
>         at
>
org.apache.tools.ant.PropertyHelper.parseNextProperty(Proper
tyHelper.java:541)
>         at
>
org.apache.tools.ant.PropertyHelper.parseProperties(Property
Helper.java:502)
>         at
>
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:390)
> The intent of Property.PropertyResolver is I think to
remain in
> the Property task - the trace seems to imply that it
has
> escaped from that task.

I think it is looping. There is a per-thread stack to detect
this, but 
it isnt working. Otherwise the loop wouldnt happen.

This could be some wierd race condition in the JVM itself,
which may be 
reordering operations in the single thread. Remember, unless
your 
variable  is tagged as volatile, or the block is
synchronized, Java can 
swap the order of actions. It can even reorder volatile
access in Java <1.5

-steve




------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

On 9/21/07, Steve Loughran <stevelapache.org> wrote:
> Peter Reilly wrote:
> > 1) Some of the traces seem to imply a bug.
>
>
> clearly 
>
> >
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
> >         at
> >
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
> >         - locked <0x00002aaab4013548> (a
> > org.apache.tools.ant.PropertyHelper)
> >         at
> >
org.apache.tools.ant.PropertyHelper.parseNextProperty(Proper
tyHelper.java:541)
> >         at
> >
org.apache.tools.ant.PropertyHelper.parseProperties(Property
Helper.java:502)
> >         at
> >
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:390)
> > The intent of Property.PropertyResolver is I think
to remain in
> > the Property task - the trace seems to imply that
it has
> > escaped from that task.
>
> I think it is looping. There is a per-thread stack to
detect this, but
> it isnt working. Otherwise the loop wouldnt happen.
>
> This could be some wierd race condition in the JVM
itself, which may be
> reordering operations in the single thread. Remember,
unless your
> variable  is tagged as volatile, or the block is
synchronized, Java can
> swap the order of actions. It can even reorder volatile
access in Java <1.5
I know, but 1) I do not know why a ThreadLocal (shudder) is
needed
here, this means
that the code is more complicated than it needs to be.
and 2) even with the above, the clone operation should have
protected
the rest of the system as the tasks deletete is only added
to
the cloned property helper which is local to the method.

In any case, I think that the code is too slow for a very
common code
path in ant.

Peter


>
> -steve
>
>
>
>
>
------------------------------------------------------------
---------
> To unsubscribe, e-mail: dev-unsubscribeant.apache.org
> For additional commands, e-mail: dev-helpant.apache.org
>
>

------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org

Peter Reilly wrote:
> On 9/21/07, Steve Loughran <stevelapache.org> wrote:
>> Peter Reilly wrote:
>>> 1) Some of the traces seem to imply a bug.
>>
>> clearly 
>>
>>>
org.apache.tools.ant.taskdefs.Property$PropertyResolver.eval
uate(Property.java:110)
>>>         at
>>>
org.apache.tools.ant.PropertyHelper.getProperty(PropertyHelp
er.java:787)
>>>         - locked <0x00002aaab4013548> (a
>>> org.apache.tools.ant.PropertyHelper)
>>>         at
>>>
org.apache.tools.ant.PropertyHelper.parseNextProperty(Proper
tyHelper.java:541)
>>>         at
>>>
org.apache.tools.ant.PropertyHelper.parseProperties(Property
Helper.java:502)
>>>         at
>>>
org.apache.tools.ant.RuntimeConfigurable.maybeConfigure(Runt
imeConfigurable.java:390)
>>> The intent of Property.PropertyResolver is I
think to remain in
>>> the Property task - the trace seems to imply
that it has
>>> escaped from that task.
>> I think it is looping. There is a per-thread stack
to detect this, but
>> it isnt working. Otherwise the loop wouldnt
happen.
>>
>> This could be some wierd race condition in the JVM
itself, which may be
>> reordering operations in the single thread.
Remember, unless your
>> variable  is tagged as volatile, or the block is
synchronized, Java can
>> swap the order of actions. It can even reorder
volatile access in Java <1.5
> I know, but 1) I do not know why a ThreadLocal
(shudder) is needed
> here, this means  that the code is more complicated
than it needs to be.
> and

I presume its a way of preventing recursion down the
resolution path. 
When I did something like this in some grid-standard XML
variant of the 
smartfrog language I just passed the stack down as an
explicit parameter.

I dont like threadlocals as they are a way to consume more
memory than 
usual.

> 2) even with the above, the clone operation should have
protected
> the rest of the system as the tasks deletete is only
added to
> the cloned property helper which is local to the
method.
> 

makes sense

> In any case, I think that the code is too slow for a
very common code
> path in ant.
> 

well, let's get it working, then worry about performance.
Actually, both 
may be the same solution. If we can move to a stack param
then the 
concurrency logic changes.


-steve



------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribeant.apache.org
For additional commands, e-mail: dev-helpant.apache.org