[
https://issues.apache.org/jira/browse/DERBY-7075?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17088261#comment-17088261
]
Vamsavardhana Reddy edited comment on DERBY-7075 at 4/21/20, 3:59 AM:
----------------------------------------------------------------------
Hi Richard, thank you very much for your help on this JIRA. I will try to put
as much information as possible here to assist you in the investigation. I
have uploaded some screenshots. Not sure if it would be possible for you to
get into a screenshare to speed things up. Do let me know.
Here is the analysis of heap and javacore from the 10.8.3.3 OOM scenario.
--------
There are two heapdumps both show same objects on heap (leak suspects)
Dump Event "systhrow" (00040000) Detail "java/lang/OutOfMemoryError" "Java
heap space" received
Date: 2020/04/16 at 14:42:23:368
JRE 1.8.0 Linux amd64-64 (build 8.0.6.0 - pxa6480sr6-20191107_01(SR6))
-Xgcpolicy:gencon
-Xmn192m
-Xms512m
-Xmx512m
-Xverbosegclog:/var/log/derbyserver_gc.log,10,1000
Total memory free: 5,500,848 (0x000000000053EFB0) = 5M
Total memory in use: 531,370,064 (0x000000001FAC1050) = 507M
From heapdump review I see below objects (leak suspects)
1)
"org.apache.derby.impl.store.access.RAMTransaction" 97,807,424 (22.04%) bytes
<-- 93.3MB The memory is accumulated in one instance of
"org.apache.derby.impl.store.access.sort.SortBuffer"
2)
"org.apache.derby.impl.store.access.RAMTransaction" 94,323,360 (21.25%) bytes
<-- 90MB The memory is accumulated in one instance of
"org.apache.derby.impl.store.access.sort.SortBuffer"
3) "org.apache.derby.impl.services.cache.ConcurrentCache" (12.48%) bytes <--
52.8MB.
The memory is accumulated in one instance of
"org.apache.derby.impl.services.cache.ConcurrentCache"
4)
org.apache.derby.impl.services.cache.ConcurrentCache" 54,617,784 (12.31%)
bytes <--52.1MB The memory is accumulated in one instance of
"org.apache.derby.impl.services.cache.ConcurrentCache"First two leak suspects
are coming from below current thread in Javacore. "DRDAConnThread_37"
J9VMThread:0x00000000030C5200, omrthread_t:0x00007F97301F7830,
java/lang/Thread:0x00000000E101CE70, state:R, prio=5
(java/lang/Thread getId:0x8B, isDaemon:true)
Java callstack:
at org/apache/derby/iapi/types/SQLChar.getString(Bytecode PC:18(Compiled Code))
at org/apache/derby/iapi/types/SQLVarchar.cloneValue(Bytecode PC:5(Compiled
Code))
at org/apache/derby/impl/sql/execute/BasicSortObserver.getClone(Bytecode
PC:22(Compiled Code))
at
org/apache/derby/impl/sql/execute/BasicSortObserver.insertNonDuplicateKey(Bytecode
PC:9(Compiled Code))
at org/apache/derby/impl/store/access/sort/SortBuffer.insert(Bytecode
PC:331(Compiled Code))
at org/apache/derby/impl/store/access/sort/MergeInserter.insert(Bytecode
PC:13(Compiled Code))
at org/apache/derby/impl/sql/execute/SortResultSet.loadSorter(Bytecode
PC:112(Compiled Code))
at org/apache/derby/impl/sql/execute/SortResultSet.openCore(Bytecode
PC:90(Compiled Code))
at
org/apache/derby/impl/sql/execute/ScrollInsensitiveResultSet.openCore(Bytecode
PC:14(Compiled Code))
at org/apache/derby/impl/sql/execute/BasicNoPutResultSetImpl.open(Bytecode
PC:10(Compiled Code))
at org/apache/derby/impl/sql/GenericPreparedStatement.executeStmt(Bytecode
PC:357(Compiled Code))
at org/apache/derby/impl/sql/GenericPreparedStatement.execute(Bytecode
PC:5(Compiled Code))
at org/apache/derby/impl/jdbc/EmbedStatement.executeStatement(Bytecode
PC:136(Compiled Code))
(entered lock: org/apache/derby/impl/jdbc/EmbedConnection@0x00000000E6723348,
entry count: 1)
at org/apache/derby/impl/jdbc/EmbedPreparedStatement.executeStatement(Bytecode
PC:16(Compiled Code))
at org/apache/derby/impl/jdbc/EmbedPreparedStatement.execute(Bytecode
PC:9(Compiled Code))
at org/apache/derby/impl/drda/DRDAStatement.execute(Bytecode PC:6(Compiled
Code))
at org/apache/derby/impl/drda/DRDAConnThread.processCommands(Bytecode
PC:611(Compiled Code))
at org/apache/derby/impl/drda/DRDAConnThread.run(Bytecode PC:115)
was (Author: vamsic):
Hi Richard, thank you very much for your help on this JIRA. I will try to put
as much information as possible here to assist you in the investigation.
Here is the analysis of heap and javacore from the 10.8.3.3 OOM scenario.
--------
There are two heapdumps both show same objects on heap (leak suspects)
Dump Event "systhrow" (00040000) Detail "java/lang/OutOfMemoryError" "Java heap
space" received
Date: 2020/04/16 at 14:42:23:368
JRE 1.8.0 Linux amd64-64 (build 8.0.6.0 - pxa6480sr6-20191107_01(SR6))
-Xgcpolicy:gencon
-Xmn192m
-Xms512m
-Xmx512m
-Xverbosegclog:/var/log/derbyserver_gc.log,10,1000
Total memory free: 5,500,848 (0x000000000053EFB0) = 5M
Total memory in use: 531,370,064 (0x000000001FAC1050) = 507M
>From heapdump review I see below objects (leak suspects)
1)
"org.apache.derby.impl.store.access.RAMTransaction" 97,807,424 (22.04%) bytes
<-- 93.3MB The memory is accumulated in one instance of
"org.apache.derby.impl.store.access.sort.SortBuffer"
2)
"org.apache.derby.impl.store.access.RAMTransaction" 94,323,360 (21.25%) bytes
<-- 90MB The memory is accumulated in one instance of
"org.apache.derby.impl.store.access.sort.SortBuffer"
3) "org.apache.derby.impl.services.cache.ConcurrentCache" (12.48%) bytes <--
52.8MB.
The memory is accumulated in one instance of
"org.apache.derby.impl.services.cache.ConcurrentCache"
4)
org.apache.derby.impl.services.cache.ConcurrentCache" 54,617,784 (12.31%) bytes
<--52.1MB The memory is accumulated in one instance of
"org.apache.derby.impl.services.cache.ConcurrentCache"First two leak suspects
are coming from below current thread in Javacore. "DRDAConnThread_37"
J9VMThread:0x00000000030C5200, omrthread_t:0x00007F97301F7830,
java/lang/Thread:0x00000000E101CE70, state:R, prio=5
(java/lang/Thread getId:0x8B, isDaemon:true)
Java callstack:
at org/apache/derby/iapi/types/SQLChar.getString(Bytecode PC:18(Compiled Code))
at org/apache/derby/iapi/types/SQLVarchar.cloneValue(Bytecode PC:5(Compiled
Code))
at org/apache/derby/impl/sql/execute/BasicSortObserver.getClone(Bytecode
PC:22(Compiled Code))
at
org/apache/derby/impl/sql/execute/BasicSortObserver.insertNonDuplicateKey(Bytecode
PC:9(Compiled Code))
at org/apache/derby/impl/store/access/sort/SortBuffer.insert(Bytecode
PC:331(Compiled Code))
at org/apache/derby/impl/store/access/sort/MergeInserter.insert(Bytecode
PC:13(Compiled Code))
at org/apache/derby/impl/sql/execute/SortResultSet.loadSorter(Bytecode
PC:112(Compiled Code))
at org/apache/derby/impl/sql/execute/SortResultSet.openCore(Bytecode
PC:90(Compiled Code))
at
org/apache/derby/impl/sql/execute/ScrollInsensitiveResultSet.openCore(Bytecode
PC:14(Compiled Code))
at org/apache/derby/impl/sql/execute/BasicNoPutResultSetImpl.open(Bytecode
PC:10(Compiled Code))
at org/apache/derby/impl/sql/GenericPreparedStatement.executeStmt(Bytecode
PC:357(Compiled Code))
at org/apache/derby/impl/sql/GenericPreparedStatement.execute(Bytecode
PC:5(Compiled Code))
at org/apache/derby/impl/jdbc/EmbedStatement.executeStatement(Bytecode
PC:136(Compiled Code))
(entered lock: org/apache/derby/impl/jdbc/EmbedConnection@0x00000000E6723348,
entry count: 1)
at org/apache/derby/impl/jdbc/EmbedPreparedStatement.executeStatement(Bytecode
PC:16(Compiled Code))
at org/apache/derby/impl/jdbc/EmbedPreparedStatement.execute(Bytecode
PC:9(Compiled Code))
at org/apache/derby/impl/drda/DRDAStatement.execute(Bytecode PC:6(Compiled
Code))
at org/apache/derby/impl/drda/DRDAConnThread.processCommands(Bytecode
PC:611(Compiled Code))
at org/apache/derby/impl/drda/DRDAConnThread.run(Bytecode PC:115)
> OutOfMemory Exceptions in derby server process
> ----------------------------------------------
>
> Key: DERBY-7075
> URL: https://issues.apache.org/jira/browse/DERBY-7075
> Project: Derby
> Issue Type: Bug
> Components: Network Server
> Affects Versions: 10.8.3.0, 10.14.2.0
> Reporter: Vamsavardhana Reddy
> Priority: Major
> Attachments: image-101420-1.png, image-101420-2.png,
> image-101420-3.png, image-10833-1.png, image-10833-2.png,
> javaheapdump-oom-derby-101420.zip, javaheapdump-oom-derby-v10833.zip
>
>
> We have two runtime environments v7.5.4 and v7.5.3 similar in terms of OS
> memory, java version and java launch command settings for the derby and other
> java processes required for our application in which similar
> projects/workloads are running. But in one of the environments we are seeing
> out of memory (OOM) exceptions in the derby server java process. In this
> environment where OOM is occurring, we even refreshed Apache derby to the
> latest version available for Java 8 and still encountered OOM exceptions.
> Please help resolve this OOM issue.
>
> Exception in thread "DRDAConnThread_39" Exception in thread
> "DRDAConnThread_41" java/lang/OutOfMemoryError: Java heap space
> at java/nio/CharBuffer.wrap (CharBuffer.java:373)
> at sun/nio/cs/StreamEncoder.implWrite (StreamEncoder.java:277)
> at sun/nio/cs/StreamEncoder.write (StreamEncoder.java:137)
> at java/io/OutputStreamWriter.write (OutputStreamWriter.java:244)
> at java/io/BufferedWriter.flushBuffer (BufferedWriter.java:140)
> at java/io/PrintStream.write (PrintStream.java:550)
> at java/io/PrintStream.print (PrintStream.java:693)
> at java/io/PrintStream.append (PrintStream.java:1089)
> at java/io/PrintStream.append (PrintStream.java:70)
> at com/ibm/oti/util/Util.appendTo (Util.java:225)
> at java/lang/Throwable.printStackTrace (Throwable.java:506)
> at java/lang/Throwable.printStackTrace (Throwable.java:302)
> at java/lang/Throwable.printStackTrace (Throwable.java:247)
> Exception in thread "DRDAConnThread_43"
> java.lang.OutOfMemoryErrorjava.lang.OutOfMemoryError(?)java.lang.OutOfMemoryError:
> Java heap space
> at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:872)
> at
> java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:8java/lang/OutOfMemoryError:
> Java heap space
> at java/lang/ThreadGroup.uncaughtException (ThreadGroup.java:872)
> at java/lang/ThreadGroup.uncaughtException (ThreadGroup.java:866)
> at java/lang/ThreadGroup.uncaughtException (ThreadGroup.java:866)
> at java/lang/Thread.uncaughtException (Thread.java:1332)
> -----------------------
> :*v7.5.4*
> OS: RHELv8 with 4GB RAM
> Java: IBM Java SDK v8.0.6.0
> Apache Derby v10.8.3.3, Apache Derby v10.14.2.0
> [bceglc385/Standalone ~]# /usr/java/default/jre/bin/java -version
> java version "1.8.0_231"
> Java(TM) SE Runtime Environment (build 8.0.6.0 - pxa6480sr6-20191107_01(SR6))
> IBM J9 VM (build 2.9, JRE 1.8.0 Linux amd64-64-Bit Compressed References
> 20191106_432135 (JIT enabled, AOT enabled)
> OpenJ9 - f0b6be7
> OMR - 18d8f94
> IBM - 233dfb5)
> JCL - 20191016_01 based on Oracle jdk8u231-b10
>
> /usr/java/default/bin/java -server -Xdump:heap+system+snap:none
> -Xdump:heap:events=user,file=/var/log/javaheapdump-user-derby.ph
> -Xdump:heap:events=systhrow,filter=java/lang/OutOfMemoryError,file=/var/log/javaheapdump-oom-derby.phd,range=1..1
>
> -Xdump!https://emoji.slack-edge.com/T27SFGS2W/java/c0a6f7d2f3faab62.png!defaults:file=/var/log/javacore-derby.txt
> -Xmx512m -Xms512m -Xmn192m -agentlib:CastIron
> -Xbootclasspath/p:/usr/ironhide/maestro/bundles/com.approuter.management.jmxremote-1.0.0.jar:
> -Xgcpolicy:gencon -Xverbosegclog:/var/log/derbyserver_gc.log,10,1000
> -XX:+HeapManagementMXBeanCompatibility
> -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger
> -Dderby.system.home=/usr/ironhide/var/db/staging
> -Dcom.sun.management.jmxremote
> -Dcom.approuter.management.jmxremote.connectorserver.port=31997
> -Djmx.remote.protocol.provider.pkgs=com.approuter.management.jmxremote
> -Dcom.sun.management.jmxremote.port=1997
> -Dcom.sun.management.jmxremote.local.only=false
> -Dcom.sun.management.jmxremote.ssl=false
> -Dcom.sun.management.jmxremote.authenticate=true
> -Dcom.sun.management.jmxremote.password.file=/usr/ironhide/maestro/management/jmxremote.password
>
> -Dcom.sun.management.jmxremote.access.file=/usr/ironhide/maestro/management/jmxremote.access
> -Dcom.approuter.logging.filename=derbyserver.log
> -Djava.rmi.server.hostname=9.121.242.177
> -[Djava.net|https://slack-redir.net/link?url=http%3A%2F%2FDjava.net].preferIPv4Stack=true
> -Dcom.approuter.sysconf.appliance=true
> -Dcom.mchange.v2.log.MLog=com.mchange.v2.log.jdk14logging.Jdk14MLog
> -Dcom.mchange.v2.resourcepool.experimental.useScatteredAcquireTask=true
> -Dc3p0.checkoutTimeout=30000 -Dc3p0.maxIdleTimeExcessConnections=30
> -Dc3p0.maxStatementsPerConnection=100 -Dc3p0.testConnectionOnCheckin=true
> -Dc3p0.testConnectionOnCheckout=true -Dc3p0.numHelperThreads=10
> -Dosgi.clean=true
> -Dosgi.configuration.area=/usr/ironhide/maestro/bundles/derbyserver
> -Dorg.osgi.framework.bootdelegation=* -Declipse.application.noDefault=true
> -Declipse.consoleLog=true
> -Dcom.approuter.orcmon.purger.compressionmode=sequential
> -DIH_ROOT=/usr/ironhide
> -Djava.util.logging.config.file=/usr/ironhide/maestro/etc/logging.properties
> -jar /usr/ironhide/maestro/bundles/org.eclipse.osgi_3.10.1.v20140909-1633.jar
>
> [bceglc390/Standalone ~]# cat /proc/meminfo
> MemTotal: 4057920 kB
> MemFree: 152896 kB
> Buffers: 342624 kB
> Cached: 729112 kB
> SwapCached: 3428 kB
> Active: 2644068 kB
> Inactive: 1066404 kB
> Active(anon): 1951704 kB
> Inactive(anon): 712696 kB
> Active(file): 692364 kB
> Inactive(file): 353708 kB
> Unevictable: 20 kB
> Mlocked: 20 kB
> SwapTotal: 3999736 kB
> SwapFree: 3988760 kB
> Dirty: 720 kB
> Writeback: 0 kB
> AnonPages: 2636560 kB
> Mapped: 38508 kB
> Shmem: 25648 kB
> Slab: 129600 kB
> SReclaimable: 48320 kB
> SUnreclaim: 81280 kB
> KernelStack: 6568 kB
> PageTables: 11116 kB
> NFS_Unstable: 0 kB
> Bounce: 0 kB
> WritebackTmp: 0 kB
> CommitLimit: 6028696 kB
> Committed_AS: 1658244 kB
> VmallocTotal: 34359738367 kB
> VmallocUsed: 152396 kB
> VmallocChunk: 34359582800 kB
> AnonHugePages: 2433024 kB
> HugePages_Total: 0
> HugePages_Free: 0
> HugePages_Rsvd: 0
> HugePages_Surp: 0
> Hugepagesize: 2048 kB
> DirectMap4k: 4096 kB
> DirectMap2M: 4190208 kB
>
> ----------
> *v7.5.3*
> OS: Bedrock v5 which is custom OS based on RHELv7 with 4GB RAM
> Java: IBM Java SDK v8.0.6.0
> Apache Derby v10.8.3.3
>
> [bceglc390/Standalone ~]# /usr/java/default/jre/bin/java -version
> java version "1.8.0_231"
> Java(TM) SE Runtime Environment (build 8.0.6.0 - pxa6480sr6-20191107_01(SR6))
> IBM J9 VM (build 2.9, JRE 1.8.0 Linux amd64-64-Bit Compressed References
> 20191106_432135 (JIT enabled, AOT enabled)
> OpenJ9 - f0b6be7
> OMR - 18d8f94
> IBM - 233dfb5)
> JCL - 20191016_01 based on Oracle jdk8u231-b10
>
> /usr/java/default/bin/java -server -Xdump:heap+system+snap:none
> -Xdump:heap:events=user,file=/var/log/javaheapdump-user-derby.phd
> -Xdump:heap:events=systhrow,filter=java/lang/OutOfMemoryError,file=/var/log/javaheapdump-oom-derby.phd,range=1..1
>
> -Xdump!https://emoji.slack-edge.com/T27SFGS2W/java/c0a6f7d2f3faab62.png!defaults:file=/var/log/javacore-derby.txt
> -Xmx512m -Xms512m -Xmn192m -agentlib:CastIron
> -Xbootclasspath/p:/usr/ironhide/maestro/bundles/com.approuter.management.jmxremote-1.0.0.jar:
> -Xgcpolicy:gencon -Xverbosegclog:/var/log/derbyserver_gc.log,10,1000
> -XX:+HeapManagementMXBeanCompatibility
> -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger
> -Dderby.system.home=/usr/ironhide/var/db/staging
> -Dcom.sun.management.jmxremote
> -Dcom.approuter.management.jmxremote.connectorserver.port=31997
> -Djmx.remote.protocol.provider.pkgs=com.approuter.management.jmxremote
> -Dcom.sun.management.jmxremote.port=1997
> -Dcom.sun.management.jmxremote.local.only=false
> -Dcom.sun.management.jmxremote.ssl=false
> -Dcom.sun.management.jmxremote.authenticate=true
> -Dcom.sun.management.jmxremote.password.file=/usr/ironhide/maestro/management/jmxremote.password
>
> -Dcom.sun.management.jmxremote.access.file=/usr/ironhide/maestro/management/jmxremote.access
> -Dcom.approuter.logging.filename=derbyserver.log
> -Djava.rmi.server.hostname=9.124.112.240
> -[Djava.net|https://slack-redir.net/link?url=http%3A%2F%2FDjava.net].preferIPv4Stack=true
> -Dcom.approuter.sysconf.appliance=true
> -Dcom.mchange.v2.log.MLog=com.mchange.v2.log.jdk14logging.Jdk14MLog
> -Dcom.mchange.v2.resourcepool.experimental.useScatteredAcquireTask=true
> -Dc3p0.checkoutTimeout=30000 -Dc3p0.maxIdleTimeExcessConnections=30
> -Dc3p0.maxStatementsPerConnection=100 -Dc3p0.testConnectionOnCheckin=true
> -Dc3p0.testConnectionOnCheckout=true -Dc3p0.numHelperThreads=10
> -Dosgi.clean=true
> -Dosgi.configuration.area=/usr/ironhide/maestro/bundles/derbyserver
> -Dorg.osgi.framework.bootdelegation=* -Declipse.application.noDefault=true
> -Declipse.consoleLog=true
> -Dcom.approuter.orcmon.purger.compressionmode=sequential
> -DIH_ROOT=/usr/ironhide
> -Djava.util.logging.config.file=/usr/ironhide/maestro/etc/logging.properties
> -jar /usr/ironhide/maestro/bundles/org.eclipse.osgi_3.10.1.v20140909-1633.jar
>
> [cldegdh9/Standalone log]# cat /proc/meminfo
> MemTotal: 3872868 kB
> MemFree: 343700 kB
> MemAvailable: 374676 kB
> Buffers: 33100 kB
> Cached: 170624 kB
> SwapCached: 3848 kB
> Active: 2540784 kB
> Inactive: 710092 kB
> Active(anon): 2429812 kB
> Inactive(anon): 621324 kB
> Active(file): 110972 kB
> Inactive(file): 88768 kB
> Unevictable: 20 kB
> Mlocked: 20 kB
> SwapTotal: 5345272 kB
> SwapFree: 5280760 kB
> Dirty: 1880 kB
> Writeback: 0 kB
> AnonPages: 3044312 kB
> Mapped: 33676 kB
> Shmem: 3984 kB
> Slab: 119980 kB
> SReclaimable: 71120 kB
> SUnreclaim: 48860 kB
> KernelStack: 15116 kB
> PageTables: 13936 kB
> NFS_Unstable: 0 kB
> Bounce: 0 kB
> WritebackTmp: 0 kB
> CommitLimit: 7281704 kB
> Committed_AS: 1755044 kB
> VmallocTotal: 34359738367 kB
> VmallocUsed: 0 kB
> VmallocChunk: 0 kB
> HardwareCorrupted: 0 kB
> AnonHugePages: 2885632 kB
> ShmemHugePages: 0 kB
> ShmemPmdMapped: 0 kB
> HugePages_Total: 0
> HugePages_Free: 0
> HugePages_Rsvd: 0
> HugePages_Surp: 0
> Hugepagesize: 2048 kB
> Hugetlb: 0 kB
> DirectMap4k: 126912 kB
> DirectMap2M: 4067328 kB
--
This message was sent by Atlassian Jira
(v8.3.4#803005)