Duplicate :
|
|
Relates :
|
This is IBIS case 71036960 Is this issue same as CR 6812738 and 6750401? In the following test, 5 data sets were collected on the same system. set 1 resulted in a JVM crash due to OOM out of swap space, then server was restarted. For set 2 through set 5, manual GC were forced in between in attempted to clear up pending finalizers which might hold up native memory. Data sets A: /net/cores.central/cores/dir22/71036960/060409 Each data set (set1 through set5) contains core file, output from mdb's umausers, pmap -r, gclog. Additional hs_err log collected for set1. Observations 1: Monitor c heap space over a period of time at different stages of execution, this include *both used and free space* % grep heap */info/pmap* set1-06042009/info/pmap.txt:00030000 630592K rwx-- [ heap ] ------------- server restarted ---------------- set2-06042009/info/pmap.txt:00030000 232960K rwx-- [ heap ] set3-06042009/info/pmap.txt:00030000 233792K rwx-- [ heap ] set4-06042009/info/pmap.txt:00030000 234496K rwx-- [ heap ] set5-06042009/info/pmap.txt:00030000 236672K rwx-- [ heap ] 2: Montitor "true" c heap usage, ie used space % cat *mdb | grep "bytes for" | awk '{ sum += $1 } END { print "total=", sum}' set1 257897328 bytes ------------- server restarted ---------------- set2 57781328 bytes set3 59953512 bytes set4 56606376 bytes set5 60171288 bytes 3: Compare c heap used space vs partition size used space partition size set1 ~258M ~630M ------------- server restarted ---------------- set2 ~58m ~230M set3 ~60M ~230M set4 ~57M ~230M set5 ~60M ~230M 4: Monitor top allocators from set1 (where oom out of swap was seen) From mdb umausers output, the top entries from set1 are mostly from PKCS11 related operations. eg 60363072 bytes for 44913 allocations with data size 1344: libumem.so.1`umem_cache_alloc+0x13c libumem.so.1`umem_alloc+0x60 libumem.so.1`malloc+0x28 libpkcs11.so.1`get_master_attributes_by_type+0x34 libpkcs11.so.1`get_master_attributes_by_template+0xcc libpkcs11.so.1`meta_CreateObject+0x398 libpkcs11.so.1`C_CreateObject+0xcc libj2pkcs11.so`Java_sun_security_pkcs11_wrapper_PKCS11_C_1CreateObject+0x7c .... Conclusions 1. Set1 showed ~630MB c heap usage, while the others sets (set 2-5) showed only ~230MB. JVM crashed due to out of swap OOM with set1 only, where the additional ~400M pushed the process size over the 4G limit. 2. Since set 2-5 had implemented the force full gc hack to clean up pending finalizers, the result confirmed that clearing up pending finalizers help in the reduction the c heap growth. 3. Notice even for set1, the real c heap usage when JVM crash was ~258M, but the partition size was up to ~630M. What that means is that the c heap contains ~370M of free space. That means C heap has at one point grew all the way to ~630M, but later when memory was reclaimed (likely due to finalization) Data set B: /net/cores.central/cores/dir22/71036960/0521/work/heap.bin A study of finalizers usage from a previous heap dump shows relatively high number of sun.security.pkcs11.P11Cipher Referees by Type: Class Count java.lang.ref.Finalizer 62599 java.lang.Class 24114 java.lang.ref.ReferenceQueue$Null 14529 java.lang.ref.ReferenceQueue 9585 sun.security.pkcs11.P11Cipher 2016 java.net.SocksSocketImpl 1825 weblogic.jms.frontend.FEConnection 1594 java.util.zip.Inflater 1371 java.util.zip.ZipFile 1266 java.util.jar.JarFile 306 weblogic.utils.classloaders.ClasspathClassFinder$ZipFileWrapper 225 weblogic.connector.outbound.ConnectionWrapper 210 java.util.concurrent.ThreadPoolExecutor 201 weblogic.rmi.internal.LeasedRemoteRef 150 sun.net.www.protocol.jar.URLJarFile 83 weblogic.net.http.HttpClient 64 com.sun.jndi.ldap.LdapCtx 52 com.sun.jndi.ldap.LdapClient 52 com.wily.introscope.agent.probe.io.ManagedFileOutputStream 21 com.rsa.jsafe.JA_DES 18 kodo.kernel.FinalizingKodoBroker 18 com.rsa.jsafe.JA_DESKey 18 weblogic.jms.backend.BackEnd 15 com.sun.crypto.provider.PBEKey 12 java.lang.ClassLoader$NativeLibrary 12 com.rsa.jsafe.JA_3DES_EDE 6 java.io.FileOutputStream 6 com.rsa.jsafe.JG_BlockCipher 6 com.rsa.jsafe.JA_PKCS5Padding 6 com.rsa.jsafe.JA_CBC 6 java.io.FileInputStream 4 java.util.Timer$1 3 com.octetstring.vde.backend.standard.RAFPool 3 java.net.PlainDatagramSocketImpl 2 com.wily.org.apache.log4j.ConsoleAppender 2 sun.jdbc.odbc.JdbcOdbcDriver 1 org.apache.log4j.net.JMSAppender 1 com.octetstring.vde.backend.standard.TransactionProcessor 1 com.wily.introscope.spec.server.beans.properties.PropertyNotification 1 com.wily.introscope.agent.AutoNamingRollingFileAppender 1 weblogic.management.mbeans.custom.Domain 1 sun.security.pkcs11.wrapper.PKCS11 1 weblogic.security.utils.Pool 1 org.apache.log4j.AsyncAppender 1 com.octetstring.vde.backend.standard.TransactionLog 1 com.octetstring.vde.util.Logger 1 netscape.ldap.LDAPConnection 1