Re: [Wrapper-user] JVM exited unexpectedly

[Leif M. <le...@ta...>]

Paul,

>This problem is not caused by the Java Service Wrapper - I just need some
>help to extract some diagnostics please!
>  
>
Lets see what we can do.

>I have a problem where my JVM exits about once a week (not at a consistent
>time) on Windows 2000 Advanced Server, JDK 1.3.1_09.
>
>This is a new box - dual P4 2.4GHz with hyperthreading, 6.3GB of RAM, and 2
>of the Java processes happily consume 1600MB of RAM each under the watchful
>eye of the Java Service Wrapper.  Thankfully the Java Service Wrapper kicks
>things off again when the JVM exits.
>  
>
You have the new record for the largest amount of memory that I have 
ever heard of :-O

>Before utilising the Java Service Wrapper, srvany (MS - yuck!) was used to
>control the application.  It did die every now and then, and normally we
>could explain it with a Dr Watson dialog saying that Java had caused an
>access violation etc.  We don't seem to be getting the Dr Watson errors,
>which is strange.  Peak RAM usage was around 4.25GB, which indicates that
>the Java processes had been hitting the ceiling of 1600MB, but they should
>garbage collect and get on their way.
>  
>
The thing you really have to be careful of with GC is virtual memory.  
If any of the JVMs
memory is being swapped to disk when the GC sweep takes place, the JVM 
can freeze up
for a long time as memory is swapped to and from the disk.  I have seen 
this cause JVM freezes
of 2 minutes on a 256MB JVM.  So I can imagine how long this would take 
on your system.
It sounds like you have plenty of memory to avoid this.  And as you say 
the wrapper is reporting
that the JVM exited unexpectedly, I think this is not the problem here.

>Currently the wrapper log file level is set to WARN, syslog is set to FATAL
>and console is set to FATAL.  As it may be another week before I see this
>happen again, I'm not keen on trial and error of logging levels to dump out
>more info next time the JVM decides to die - debug could result in huge
>files without need.
>  
>
OK.  Your log levels are hiding the information that we are going to 
want to see.
Currently, all JVM output is logged as INFO level messages.   If your 
JVM is crashing
then it will be printing a nice useful (?) core dump to the console.  
Since this is being
logged at a level of INFO, it is currently being thrown away.  The 
wrapper will also kick
out a lot of very useful information when the JVM restarts.  This will 
help us to find the
cause of your problems.

You really should be setting your wrapper log level to INFO.  If you are 
getting too much
output there then you might want to consider using a logging tool inside 
of your application
and redirect all of that extra output to another file.

Also if you are running as an NT service, the console log level does not 
really matter as
all output is ignored due to the lack of a console when running as a 
service.

To debug this, you will want to set the following in your properties file:
wrapper.logfile.format=LPTM
wrapper.logfile.loglevel=DEBUG
wrapper.logfile.maxsize=1m
wrapper.logfile.maxfiles=10

The format is important so I can see the timestamps of each message.
The maxsize and maxfiles will cause the wrapper.log file to roll when it
reaches 1MB in size.  The wrapper will then only keep the last 10 files.
This guarantees that you will never use more than 10MB of disk space.
Just make sure that this is long enough with your application for you to
be able to notice that your application crashed and save the log file
which contains the crash.

When you are able to reproduce the crash, I am going to need to see about
15-20 minutes worth of logs before the crash and then the full startup 
of your
app after the JVM is restarted.

>What can I do to get some info about what happened when the JVM exited?
>  
>
This will show up in the wrapper.log file at DEBUG and INFO log levels.

Cheers,
Leif