Menu
▾
▴
Re: [Wrapper-user] JVM hang - Xms / Xmx
|
From: Leif M. <le...@ta...> - 2004-04-01 08:13:14
|
Paul,
Paul Casanova wrote:
>Thanks for your info - I think I might have to buy a book and learn inside
>out about Java GC/memory usage.
>
>Our app takes around 950MB to start due to loading all the GIS stuff into
>RAM upon startup. The application author's theory was that reading the GIS
>stuff from RAM is heaps faster than from disk and it has to be read into
>RAM at some stage (when used), so it might as well stay there!
>
>
Not sure if this is an option. But would is it possible to break the
data up into
3 groups?
1) Data that is currently in use (stored in memory and on the local disk)
2) Data that is likely to be used (transfered and then stored to the
local disk)
3) Other data (stored only on the remote server)
Net, is it possible to timestamp the data so you know when you need to
obtain the
latest data from the remote server again? If data has not changed then
you could
continue using data stored on the disk.
This would increase the complexity of your app a bit (If it is even
possible) But should
reduce the memory footprint by quite a bit and also improve startup
times, at least for
the second invocation of the application.
>Our app takes around 15 minutes to start on a fairly decent pair of boxes -
>the bottleneck is a gigabit Ethernet crossover cable running between the
>servers. Our client has ordered a pair of fibre gigabit cards for each box
>and a managed fibre switch, but they haven't turned up yet. The app takes
>6 minutes to start when app and DB are on the same box, but that's less
>scalable (HD / RAM capacity constraints).
>
>Due to the startup time, we don't want to do anything to extend startup -
>that's why we're happy to allocate a fair chunk to the initial memory.
>
>It's interesting though - I've noticed that since reducing the initial
>memory value, the peak memory usage (according to Windows anyway) tends to
>remain pretty darn close to the initial memory value. This indicates that
>what you've outlined below seems to be working pretty well (ie when more
>RAM is needed, try a GC first).
>
>
Good that sounds like you are seeing what I expected. Just as an
experiment. Try
lowering the initial memory down to the default (3MB) and see how much of a
difference there is in your application's startup time. Your app is
much larger than
anything I have used. But I have not seen all that large a difference
when the app
is in the 512MB range. I am interested to hear how significant the
difference is.
This experiment will also give you a better understanding of how much
memory the
application really needs and when that memory is needed. Do this at the
same time
as you have that memory logging background thread running. You should
then be
able to monitor how memory is allocated as your app is starting up and
running.
>So what I've found is that by reducing the initial memory value in the
>config file, our JVM hasn't hung for the past 3 weeks. This is a good
>sign.
>
>The problem that's now occurring more frequently is the
>java.lang.OutOfMemoryError, which indicates that at some stage the process
>needs more RAM than is available: either the GC fails or something else is
>going on. And now that I think of it, we can't tell what the process maxes
>out at because by the time that I realise there's a problem the app has
>been restarted and Windows has lost the peak memory of the process that
>crashed (of course).
>
>
I think it is fairly safe to assume that GC is working correctly. Which
means that
something in the application is actually eating up all available
memory. What
exactly that is yet to be determined.
1) The obvious is an object leak someplace. These are easily located by
adding the
following to your Wrapper.conf file:
wrapper.java.additional.1=-Xrunhprof:depth=8
wrapper.shutdown.timeout=0
This will increase the runtime memory usage some and also affects the
performance of
the application. But it should still be usable. When you go to
shutdown the JVM. I
will appear to be locked up for quite a while as it writes out the
profile data file. I
have seen this take a couple minutes. But I would not be surprised if
it took 10
minutes for your application. (That is the reason for the shutdown
timeout setting.
We don't want the Wrapper killing the JVM as it tries to save all the
data we worked
so hard to collect)
When the JVM exits you will see the following in the console or log file.
---
Dumping Java heap ... allocation sites ... done.
---
Look in the directory where Wrapper.exe is located and you will fine a
file: java.hprof.txt
This file could be quite large, so I hope you have a good editor.
Search for "SITES BEGIN". You will see a section toward the end of the
file that looks
like this:
---
SITES BEGIN (ordered by live bytes) Fri Oct 11 12:56:48 2002
percent live alloc'ed stack class
rank self accum bytes objs bytes objs trace name
1 6.80% 6.80% 544264 4779 544264 4779 0 [C
2 2.78% 9.59% 222624 964 223280 966 6361 [C
3 2.14% 11.73% 171248 1262 173504 1299 1 [C
4 2.12% 13.85% 169368 106 169368 106 17124 [B
5 2.08% 15.93% 166736 183 166736 183 0 [B
6 1.71% 17.64% 136624 397 208088 796 17100 [C
7 1.55% 19.18% 123664 435 123664 435 16788 [C
---
This section is ordered by how much memory is being used by objects which
were created at specific places in the code. If you are lucky, the
first row will
be a very large number.
The second to the last column is the Trace number. This says where the
objects
were created. In the above example this is "4779".
To find out where these [C (Character Arrays) where created, do another
search
for "TRACE 4779:"
I get the following:
---
TRACE 4779:
java.lang.StringBuffer.toString(StringBuffer.java:1233)
org.apache.catalina.startup.Catalina.createContextCommon(Catalina.java:614)
org.apache.catalina.startup.Catalina.createStartMapperDefaultContext(Catalina.java:521)
org.apache.catalina.startup.Catalina.createStartMapper(Catalina.java:391)
org.apache.catalina.startup.Catalina.start(Catalina.java:722)
org.apache.catalina.startup.Catalina.execute(Catalina.java:681)
org.apache.catalina.startup.Catalina.process(Catalina.java:179)
sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:Native
method)
---
You may find that you need to increase the stack depth, but that takes
more memory
and I usually find a depth of 8 to be sufficient.
2) I have seen cases where synchronization errors in HotSpot compiled
applications
have caused memory corruption. In most cases, such corruption will
cause the JVM
to crash, but in others it has simply resulted in a memory leak that
doesn't show up
in the profiling output above.
I wonder about this second option because you are also experiencing JVM
crashes.
These can be a real bi_ch to track down, so lets hope this is not the cause.
One way to check this is to try disabling the JIT/HotSpot compiler.
Doing so will
often cause more Java like errors to start showing up as nothing has
been optimized
into fast machine code.
>I've turned on some logging as suggested to dump out memory usage, so we'll
>see what this shows.
>
>Incidently, the most I've been able to allocate to Java (Xmx) is about
>1625MB on Windows 2000 Advanced Server. On NT (previous platform) it was
>only about 1100MB - although that was with JDK 1.3.0, so that may have had
>an impact. If I attempt starting with more than 1625MB, the app fails to
>start. I think this is just a Java/Windows relationship thing.
>
>
Looking at the following page, it looks like Java started supporting
2GB+ heap sizes as
of 1.3.1. You might want to give that a try. There are also several
command line
options described on this page which could interest you.
http://java.sun.com/docs/hotspot/ism.html
Looking at those docs means that I need to change the way I handle the
memory settings
in the Wrapper. Some of them require that the -Xms and -Xmx values
which are always
set by the Wrapper not be set.
>The log files show the java.lang.OutOfMemoryError's for a while before the
>JVM eventually crashes. Is there anyway to set up the Wrapper so that I
>can be notified (preferably by email) of this error so that I can remote
>takeover the box and have a look at things before the Wrapper restarts it?
>
>
Not really at the moment. What is triggering the JVM to be restarted now?
Have you registered an output trigger on the OutOfMemoryError console
output?
If the Wrapper is killing the JVM because it stops responding to pings
then you can
simply set the Ping timeout to 0. This will not enable you to get an
email, but it would
stop the JVM from restarting it.
Cheers,
Leif
|
