Re: [Wrapper-user] java.lang.OutOfMemoryError

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

There are a number of things we can try out to help you track this down.

1) The Wrapper has a property which lets you monitor the JVM and
Wrapper memory usage at regular intervals over time.  This tends to be
more accurate than the values that can be taken from within Java.
They are not yet documented as I have waiting to add support on UNIX
platforms as well.  The following will dump memory stats to the log
file once every minute.  Hopefully this will help you to pinpoint the
precise actions which are causing the problem.
---
wrapper.memory_output=TRUE
wrapper.memory_output.interval=60
---

2) Enable profiling in the JVM.  This will greatly decrease the
performance of the JVM but it will produce very detailed heap dumps
that let you find the precise stack traces where objects are being
created.  It is possible that you have some kind of an object leak in
your code someplace.  The first property is to enable the profiling.
Be sure to change the "7" to whatever is appropriate for your
configuration.  The long shutdown timeouts are to make sure that the
Wrapper gives the JVM time to write out its dump file on shutdown.
---
wrapper.java.additional.7=-Xrunhprof:heap=sites,depth=8
wrapper.shutdown.timeout=1800
wrapper.jvm_exit.timeout=1800
---
I would suggest running on a test machine for a few hours and then
hitting CTRL-C to kill the JVM.  After a couple minutes, the Wrapper
will stop and you will find a profile file in the directory where the
wrapper.exe is located.   The very end of the file contains object
counts in order of their total number.  Next to each object is a
location number where that object is created.  Search for that number
in the first 95% of the file to get the stack trace where it is being
created.   The format can take a little work to get used to and you
will need an editor that is capable of handling such huge files.  I
have used SitePadPro for many years, a great editor.

3) The Professional Edition of the Wrapper has a feature which will
let you avoid this problem before it gets too bad while you are
attempting to get the root cause resolved.  The following properties
can be used to tell the Wrapper to restart the JVM at specific times
when you know it will not affect your customer's business.
http://wrapper.tanukisoftware.org/doc/english/prop-timer-n.html
---
wrapper.timer.action.1=RESTART
wrapper.timer.interval.1=day-of-week=1; hour=4
---
That will restart the JVM every Sunday morning at 4am.
The following settings will also tell the Wrapper to invoke a thread
dump once every 3 hours
---
wrapper.timer.action.2=DUMP
wrapper.timer.interval.2=hour=*/3
---
I would be happy to provide you with a trial license to test this out.

4) An aside, but you can greatly clean up your classpath configuration
by using wildcards as follows:
wrapper.java.classpath.1=../javawrapper/lib/wrapper.jar
wrapper.java.classpath.2=classes
wrapper.java.classpath.3=lib/*.jar


I notice that you are  using some other JNI libraries.  Memory leaks
in there will appear to be part of the JVM's memory but you will not
be able to locate many of those problems using the profiling in 2)
unless the memory being leaked is Java objects.   In that case 3) may
be the best short term solution for you.

Cheers,
Leif

2009/3/19 no spam <mrs...@gm...>:
> I have a production application that dumps every few months and takes out a
> large number of recording devices.  Needless to say my client is not happy.
>  I don't always get a thread dump ( I'd like to know how to always get one )
> but I managed to capture one of them below from the hotspot jvm.  You'll see
> at the bottom of the dump that this is a windows server 2003 server and it
> has 4 gigs of memory.  I am running 2 separate jvms on this machine both via
> java service wrapper.
> Here is my java service wrapper setup.  Currently I have it set to 512 megs
> of ram and just last week we looked and it wasn't taking up around 220 megs
> as shown via the task manager.  It consumes memory at a slow rate.
>
> #********************************************************************
> # Java Application
>
> wrapper.java.command=C:/Program Files/Java/jre1.6.0_03/bin/java
>
> #
> # Memory / GC Tuning
> #
> wrapper.java.maxmemory=512
> wrapper.ping.timeout=600
> wrapper.ntservice.account=<user>
> wrapper.ntservice.password.prompt=TRUE
> wrapper.java.mainclass=org.tanukisoftware.wrapper.WrapperSimpleApp
> wrapper.app.parameter.1=com.proxygen.mvcp.MVCPDaemon
> wrapper.working.dir=c:/<working dir>
> wrapper.java.classpath.1=../javawrapper/lib/wrapper.jar
> wrapper.java.classpath.2=classes
> wrapper.java.classpath.3=lib/antlr-2.7.6.jar
> wrapper.java.classpath.4=lib/asm-1.5.3.jar
> wrapper.java.classpath.5=lib/asm-attrs-1.5.3.jar
> wrapper.java.classpath.6=lib/cglib-2.1.3.jar;lib/commons-beanutils-1.7.0.jar
> wrapper.java.classpath.7=lib/commons-codec-1.3.jar
> wrapper.java.classpath.8=lib/commons-collections-3.2.jar
> wrapper.java.classpath.9=lib/commons-dbcp-1.2.1.jar
> wrapper.java.classpath.10=lib/commons-httpclient-3.0.1.jar
> wrapper.java.classpath.11=lib/commons-lang-2.1.jar
> wrapper.java.classpath.12=lib/commons-logging-1.0.4.jar
> wrapper.java.classpath.13=lib/commons-net-1.2.2.jar
> wrapper.java.classpath.14=lib/commons-pool-1.3.jar
> wrapper.java.classpath.15=lib/dom4j-1.6.1.jar
> wrapper.java.classpath.16=lib/ehcache-1.2.3.jar
> wrapper.java.classpath.17=lib/hibernate-3.2.1.ga.jar
> wrapper.java.classpath.18=lib/jdom-1.0.jar
> wrapper.java.classpath.19=lib/jta-1.0.1B.jar
> wrapper.java.classpath.20=lib/kfservice-1.0.0.16.jar
> wrapper.java.classpath.21=lib/log4j-1.2.13.jar
> .
> .
> .
> wrapper.java.classpath.25=lib/ojdbc-9.0.2.0.0.jar
> wrapper.java.classpath.26=lib/proxybrowse-1.0.0.12.jar
> wrapper.java.classpath.27=lib/spring-2.0.1.jar
> wrapper.java.classpath.28=lib/xpp3_min-1.1.3.4.O.jar
> wrapper.java.classpath.29=lib/xstream-1.2.1.jar
> wrapper.java.classpath.30=lib/ifxjdbc_3_0_jc3.jar
> wrapper.java.classpath.31=lib/jintegra.jar
> wrapper.java.classpath.32=lib/concurrent.jar
>
>
> # Java Library Path (location of Wrapper.DLL or libwrapper.so)
> wrapper.java.library.path.1=../javawrapper/lib
> wrapper.java.library.path.2=lib/jintegra
> wrapper.java.library.path.3=lib/jintegra/international
>
> #********************************************************************
> # Wrapper Logging Properties
> #********************************************************************
> # Format of output for the console.  (See docs for formats)
> wrapper.console.format=PM
> # Log Level for console output.  (See docs for log levels)
> wrapper.console.loglevel=INFO
> # Log file to use for wrapper output logging.
> wrapper.logfile=log/wrapper_mvcp-YYYYMMDD.log
> # Format of output for the log file.  (See docs for formats)
> wrapper.logfile.format=LPTM
> # Log Level for log file output.  (See docs for log levels)
> wrapper.logfile.loglevel=INFO
> # Maximum size that the log file will be allowed to grow to before
> #  the log is rolled. Size is specified in bytes.  The default value
> #  of 0, disables log rolling.  May abbreviate with the 'k' (kb) or
> #  'm' (mb) suffix.  For example: 10m = 10 megabytes.
> # wrapper.logfile.maxsize=10m
> # Maximum number of rolled log files which will be allowed before old
> #  files are deleted.  The default value of 0 implies no limit.
> wrapper.logfile.maxfiles=30
> #
> # roll daily
> wrapper.logfile.rollmode=DATE
> # Log Level for sys/event log output.  (See docs for log levels)
> wrapper.syslog.loglevel=NONE
> # Mode in which the service is installed.  AUTO_START or DEMAND_START
> wrapper.ntservice.starttype=AUTO_START
> # Allow the service to interact with the desktop.
> wrapper.ntservice.interactive=false
>
>
>
> #
> # An unexpected error has been detected by Java Runtime Environment:
> #
> # java.lang.OutOfMemoryError: requested 32756 bytes for ChunkPool::allocate.
> Out of swap space?
> #
> #  Internal Error (414C4C4F434154494F4E0E4350500065), pid=9928, tid=5936
> #
> # Java VM: Java HotSpot(TM) Client VM (1.6.0_03-b05 mixed mode, sharing)
> # If you would like to submit a bug report, please visit:
> #   http://java.sun.com/webapps/bugreport/crash.jsp
> #
> ---------------  T H R E A D  ---------------
> Current thread (0x03205c00):  JavaThread "J-Integra COM initialization
> thread (please don't touch)" daemon [_thread_in_vm, id=5936]
> Stack: [0x03bb0000,0x03c00000)
> [error occurred during error reporting, step 110, id 0xc0000005]
> Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
> j  com.linar.jintegra.NativeObjRef.initializeCOM(IZZZZZ)Ljava/lang/String;+0
> j  com.linar.jintegra.NativeInitThread.run()V+32
> j  java.lang.Thread.run()V+11
> v  ~StubRoutines::call_stub
> ---------------  P R O C E S S  ---------------
> Java Threads: ( => current thread )
> =>0x03205c00 JavaThread "J-Integra COM initialization thread (please don't
> touch)" daemon [_thread_in_vm, id=5936]
>   0x03198400 JavaThread "Protocol Worker" [_thread_blocked, id=7660]
>   0x0311a800 JavaThread "MVCP Daemon" [_thread_in_native, id=10056]
>   0x0323e400 JavaThread "Mediasource QueueWorker" [_thread_blocked,
> id=10052]
>   0x03206800 JavaThread "RestRequest QueueWorker" [_thread_blocked, id=9988]
>   0x031e3800 JavaThread "Client Command Manager" [_thread_blocked, id=9996]
>   0x03227400 JavaThread "record cleanup" [_thread_blocked, id=10048]
>   0x02d7d800 JavaThread "Timer-2" [_thread_blocked, id=10044]
>   0x02e08000 JavaThread "Timer-1" [_thread_blocked, id=10040]
>   0x02e09400 JavaThread "Timer-0" [_thread_blocked, id=10036]
>   0x02e5f800 JavaThread "record cleanup" [_thread_blocked, id=10032]
>   0x00297800 JavaThread "DestroyJavaVM" [_thread_blocked, id=9936]
>   0x02dd1800 JavaThread "Wrapper-Connection" daemon [_thread_in_native,
> id=7484]
>   0x02d74c00 JavaThread "Wrapper-Control-Event-Monitor" daemon
> [_thread_blocked, id=9976]
>   0x0290dc00 JavaThread "Low Memory Detector" daemon [_thread_blocked,
> id=9968]
>   0x02909000 JavaThread "CompilerThread0" daemon [_thread_blocked, id=7332]
>   0x02908000 JavaThread "Attach Listener" daemon [_thread_blocked, id=9960]
>   0x02907000 JavaThread "Signal Dispatcher" daemon [_thread_blocked,
> id=9952]
>   0x028ff400 JavaThread "Finalizer" daemon [_thread_blocked, id=9948]
>   0x028fe400 JavaThread "Reference Handler" daemon [_thread_blocked,
> id=9944]
> Other Threads:
>   0x028fd000 VMThread [id=9940]
>   0x02918400 WatcherThread [id=9972]
> VM state:not at safepoint (normal execution)
> VM Mutex/Monitor currently owned by a thread: None
> Heap
>  def new generation   total 960K, used 413K [0x06970000, 0x06a70000,
> 0x090d0000)
>   eden space 896K,  38% used [0x06970000, 0x069c7478, 0x06a50000)
>   from space 64K, 100% used [0x06a50000, 0x06a60000, 0x06a60000)
>   to   space 64K,   0% used [0x06a60000, 0x06a60000, 0x06a70000)
>  tenured generation   total 4096K, used 1104K [0x090d0000, 0x094d0000,
> 0x26970000)
>    the space 4096K,  26% used [0x090d0000, 0x091e41c8, 0x091e4200,
> 0x094d0000)
>  compacting perm gen  total 12288K, used 4494K [0x26970000, 0x27570000,
> 0x2a970000)
>    the space 12288K,  36% used [0x26970000, 0x26dd3bd8, 0x26dd3c00,
> 0x27570000)
>     ro space 8192K,  62% used [0x2a970000, 0x2ae714a8, 0x2ae71600,
> 0x2b170000)
>     rw space 12288K,  52% used [0x2b170000, 0x2b7b7278, 0x2b7b7400,
> 0x2bd70000)
> Dynamic libraries:
> 0x00400000 - 0x00423000 C:\Program Files\Java\jre1.6.0_03\bin\java.exe
> 0x7c800000 - 0x7c8c0000 C:\WINDOWS\system32\ntdll.dll
> 0x77e40000 - 0x77f42000 C:\WINDOWS\system32\kernel32.dll
> 0x77f50000 - 0x77feb000 C:\WINDOWS\system32\ADVAPI32.dll
> 0x77c50000 - 0x77cef000 C:\WINDOWS\system32\RPCRT4.dll
> 0x76f50000 - 0x76f63000 C:\WINDOWS\system32\Secur32.dll
> 0x7c340000 - 0x7c396000 C:\Program Files\Java\jre1.6.0_03\bin\msvcr71.dll
> 0x6d7c0000 - 0x6da0a000 C:\Program Files\Java\jre1.6.0_03\bin\client\jvm.dll
> 0x77380000 - 0x77411000 C:\WINDOWS\system32\USER32.dll
> 0x77c00000 - 0x77c48000 C:\WINDOWS\system32\GDI32.dll
> 0x76aa0000 - 0x76acd000 C:\WINDOWS\system32\WINMM.dll
> 0x76290000 - 0x762ad000 C:\WINDOWS\system32\IMM32.DLL
> 0x6d310000 - 0x6d318000 C:\Program Files\Java\jre1.6.0_03\bin\hpi.dll
> 0x76b70000 - 0x76b7b000 C:\WINDOWS\system32\PSAPI.DLL
> 0x6d770000 - 0x6d77c000 C:\Program Files\Java\jre1.6.0_03\bin\verify.dll
> 0x6d3b0000 - 0x6d3cf000 C:\Program Files\Java\jre1.6.0_03\bin\java.dll
> 0x6d7b0000 - 0x6d7bf000 C:\Program Files\Java\jre1.6.0_03\bin\zip.dll
> 0x02e60000 - 0x02e77000 C:\ipe\javawrapper\lib\wrapper.dll
> 0x6d570000 - 0x6d583000 C:\Program Files\Java\jre1.6.0_03\bin\net.dll
> 0x71c00000 - 0x71c17000 C:\WINDOWS\system32\WS2_32.dll
> 0x77ba0000 - 0x77bfa000 C:\WINDOWS\system32\msvcrt.dll
> 0x71bf0000 - 0x71bf8000 C:\WINDOWS\system32\WS2HELP.dll
> 0x71b20000 - 0x71b61000 C:\WINDOWS\system32\mswsock.dll
> 0x5f270000 - 0x5f2ca000 C:\WINDOWS\system32\hnetcfg.dll
> 0x71ae0000 - 0x71ae8000 C:\WINDOWS\System32\wshtcpip.dll
> 0x76ed0000 - 0x76efa000 C:\WINDOWS\system32\DNSAPI.dll
> 0x76f70000 - 0x76f77000 C:\WINDOWS\System32\winrnr.dll
> 0x76f10000 - 0x76f3e000 C:\WINDOWS\system32\WLDAP32.dll
> 0x76f80000 - 0x76f85000 C:\WINDOWS\system32\rasadhlp.dll
> 0x68000000 - 0x68035000 C:\WINDOWS\system32\rsaenh.dll
> 0x76920000 - 0x769e2000 C:\WINDOWS\system32\USERENV.dll
> 0x71c40000 - 0x71c97000 C:\WINDOWS\system32\netapi32.dll
> 0x03760000 - 0x037a0000 C:\ipe\mvcp\lib\jintegra\ntvinv.dll
> 0x77670000 - 0x777a9000 C:\WINDOWS\system32\ole32.dll
> 0x77d00000 - 0x77d8b000 C:\WINDOWS\system32\OLEAUT32.dll
> 0x5fcc0000 - 0x5fcc5000 C:\WINDOWS\system32\mtxex.dll
> 0x4a710000 - 0x4a855000 C:\WINDOWS\system32\COMSVCS.dll
> 0x03900000 - 0x03907000
> C:\ipe\mvcp\lib\jintegra\International\ntvinvenglishresourcedll.dll
> 0x73eb0000 - 0x73fd1000 C:\WINDOWS\system32\MFC42.DLL
> 0x46a70000 - 0x46b40000 C:\WINDOWS\system32\WININET.dll
> 0x77da0000 - 0x77df2000 C:\WINDOWS\system32\SHLWAPI.dll
> 0x03910000 - 0x03919000 C:\WINDOWS\system32\Normaliz.dll
> 0x46300000 - 0x46345000 C:\WINDOWS\system32\iertutil.dll
> 0x71bb0000 - 0x71bb9000 C:\WINDOWS\system32\WSOCK32.dll
> 0x48890000 - 0x488cd000 C:\WINDOWS\system32\ODBC32.dll
> 0x77530000 - 0x775c7000
> C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_6595b64144ccf1df_5.82.3790.3959_x-ww_78FCF8D0\COMCTL32.dll
> 0x7c8d0000 - 0x7d0cf000 C:\WINDOWS\system32\SHELL32.dll
> 0x762b0000 - 0x762f9000 C:\WINDOWS\system32\comdlg32.dll
> 0x77420000 - 0x77523000
> C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_6595b64144ccf1df_6.0.3790.3959_x-ww_D8713E55\comctl32.dll
> 0x03b10000 - 0x03b27000 C:\WINDOWS\system32\odbcint.dll
> VM Arguments:
> jvm_args: -Xmx512m
> -Djava.library.path=../javawrapper/lib;lib/jintegra;lib/jintegra/international
> -Dwrapper.key=ewtHOrkX3QrgQGVo -Dwrapper.port=32000
> -Dwrapper.jvm.port.min=31000 -Dwrapper.jvm.port.max=31999 -Dwrapper.pid=1388
> -Dwrapper.version=3.2.3 -Dwrapper.native_library=wrapper
> -Dwrapper.service=TRUE -Dwrapper.cpu.timeout=10 -Dwrapper.jvmid=2
> java_command: org.tanukisoftware.wrapper.WrapperSimpleApp
> com.proxygen.mvcp.MVCPDaemon
> Launcher Type: SUN_STANDARD
> Environment Variables:
> PATH=C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
> USERNAME=<user>
> OS=Windows_NT
> PROCESSOR_IDENTIFIER=x86 Family 6 Model 15 Stepping 6, GenuineIntel
>
>
> ---------------  S Y S T E M  ---------------
> OS: Windows Server 2003 family Build 3790 Service Pack 2
> CPU:total 4 (2 cores per cpu, 1 threads per core) family 6 model 15 stepping
> 6, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3
> Memory: 4k page, physical 2097151k(66888k free), swap 4194303k(5132k free)
> vm_info: Java HotSpot(TM) Client VM (1.6.0_03-b05) for windows-x86, built on
> Sep 24 2007 22:24:33 by "java_re" with unknown MS VC++:1310