WOW!!! Amazing job of debugging/investigating, Kohsuke. Thank you very
much! I will do some trials of my own now with latest builds of ant and
with Java 1.4.
Lee
> -----Original Message-----
> From: Kohsuke Kawaguchi [mailto:Kohsuke.Kawaguchi_at_Sun.COM]
> Sent: Wednesday, April 21, 2004 5:08 PM
> To: users_at_jaxb.dev.java.net
> Subject: investigated --- Re: xjc 20040405 uses 1.4 API
>
>
> I was able to reproduce the problem. Indeed it happens
> sometime with JDK 1.3.
>
> What's strange is that right before OutOfMemoryError, the
> memory usage is just around 7MB and nowhere near the VM
> limit. So initially I thought maybe someone is doing
> something stupid like:
>
> new byte[x];
>
> where x is incredibly large by mistake.
>
> Then I noticed that if I use Windows task manager to monitor
> the memory usage, it grows constantly up to around 54MB
> before it crashes. This doesn't agree with what -verbose:gc
> is showing.
>
> So I then used JVMStat
> (http://developers.sun.com/dev/coolstuff/jvmstat/),
> unfortunately this one only works with JDK 1.4, but even with
> JDK 1.4, I found that it does seem like leaking memory
> (attached.) At this point I decided to work with JDK 1.4 exclusively.
>
> Next I used -Xrunhprof to get the basic profilng. It actually
> generated a huge file, so I only shows the top #20 memory use:
>
> SITES BEGIN (ordered by live bytes) Wed Apr 21 16:24:50 2004
> percent live alloc'ed stack class
> rank self accum bytes objs bytes objs trace name
> 1 13.89% 13.89% 2260072 16685 2260072 16685 3236 [B
> 2 7.37% 21.25% 1198856 23189 1198856 23189 3236 [S
> 3 5.87% 27.12% 955824 24316 986600 25233 3236
> java.lang.Object
> 4 5.74% 32.87% 934360 16685 934360 16685 3236 java.lang.Class
> 5 2.53% 35.40% 412256 212 17192688 9894 4126 [C
> 6 1.88% 37.27% 305376 5849 1294096 20471 218 [C
> 7 1.77% 39.04% 287280 1890 567248 4819 1601 [C
> 8 1.68% 40.72% 273632 5787 273632 5787 3236 [I
> 9 1.39% 42.11% 226544 3867 1729168 39226 1666 [C
> 10 1.31% 43.42% 213200 13 26453200 1613 3505 [C
> 11 1.27% 44.69% 206448 391 10368864 19638 107 [B
> 12 1.21% 45.90% 196800 12 6445200 393 4485 [C
> 13 1.16% 47.06% 188784 23 6287328 766 4484 [B
> 14 1.14% 48.20% 184888 4581 184888 4581 96688 [C
> 15 1.01% 49.20% 164000 10 164000 10 96675 [C
> 16 0.90% 50.10% 146104 93 6077328 4132 4128 [C
> 17 0.89% 50.99% 144480 1806 144480 1806 1762
> java.util.HashMap$Entry
> 18 0.88% 51.87% 142648 582 146064 631 1 [C
> 19 0.81% 52.68% 132168 5507 295728 12322 171 java.lang.String
> 20 0.79% 53.46% 127992 671 127992 671 506 [B
>
> The worst 4 come from the stack trace 3236, which is as follows:
>
> TRACE 3236:
>
> java.lang.ClassLoader.defineClass0(ClassLoader.java:Native method)
> java.lang.ClassLoader.defineClass(ClassLoader.java:537)
>
> org.apache.tools.ant.loader.AntClassLoader2.defineClassFromDat
> a(AntClassLoader2.java:77)
>
> org.apache.tools.ant.AntClassLoader.getClassFromStream(AntClas
> sLoader.java:1074)
>
> So I started suspecting that maybe class loading is an issue.
>
> I re-run visualgc, and noticed that the # of classes loaded
> is around 18500, and this number grows constantly throughout
> the whole build. I took this to mean that new classes are
> constantly being loaded, which doesn't sound right given that
> the build is just running XJC with different schemas (IOW,
> you would expect that a lot of classes to be loaded
> initially, then after the 1st compilation it should finish
> loading most of the classes.)
>
>
> Then I rerun Ant with -verbose:class, and found out that the
> same class (like com.sun.tools.xjc.ConsoleErrorReporter) is
> loaded 14 times. The build scripts compile 1 dummy schema +
> 13 schemas so this seems to imply that somehow a fresh set of
> XJC classes is loaded every time one invokes the XJC task,
> which seems like a terrible waste.
>
> Now that I start to suspect Ant for memory leak, I searched
> Apache BugZilla for some information. And I found this:
>
> http://nagoya.apache.org/bugzilla/show_bug.cgi?id=8689
>
> In particular see the comment "Mike Aizatsky 2004-03-31
> 09:42", which says he doesn't see the clean up to AntClassLoader.
>
> Unless the class loader is freed, no classes loaded from it
> can be freed.
> So this seems to explain why XJC classes are loaded so many
> times. So this bug seems to explain everything.
>
> I'll leave it up to you to apply the suggested patch locally
> and see if the problem goes away. Meanwhile, this seems like
> a restriction of Ant, so I'm afraid there's nothing we can do
> about this.
>
>
> This concludes my little journey. Let me know how you think.
>
> regards,
> --
> Kohsuke Kawaguchi
> Sun Microsystems kohsuke.kawaguchi_at_sun.com
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_jaxb.dev.java.net
> For additional commands, e-mail: users-help_at_jaxb.dev.java.net
>
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe_at_jaxb.dev.java.net
For additional commands, e-mail: users-help_at_jaxb.dev.java.net