You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-user@db.apache.org by mogoye <sy...@eloquant.com> on 2012/06/27 15:15:58 UTC

Strange OutOfMemory in unittest

Hello, 

I'm currently working on a some junit tests to validate My DB using Derby
1.8.1.2.
My code is using JPA annotations and Eclipselink implementation.

The purpose of this test is to evaluate the performances of my requests.
My test is doing the following things :
- Create an empty DB.
- Fill DB with 200 000 entries
- Performs some requests.
- Check answers are Ok and measure time to proccess them.

The thing I don't understant is why my test can be executed 50% of the time
with no problem, and the other 50% I have OutOfMemory that occurs at various
tests execution.

I don't understand why the same code executed few seconds later can sometime
be a success or failure.


For example here is one of the request that is executed.
In that case the request is a native querry and a very basic request: 
SELECT * FROM TICKET ORDER BY EXPECTED_DATE ASC OFFSET 33000 ROWS FETCH
FIRST 20 ROWS ONLY


My DB (measured on the file system) is only 100Mb so not very big one
See bellow the stack trace.

I have no idea how I can go further as I'm not very familliar with derby
tools or logs to help debugging.

Does any one have some idea ?

Thanks a lot.
Sylvain




Here is the complete Stack trace I can get (sometimes I do not have any
stack info): 

java.lang.OutOfMemoryError: Java heap space
	at
sun.text.resources.DateFormatZoneData.getContents(DateFormatZoneData.java:299)
	at
sun.text.resources.DateFormatZoneData.loadLookup(DateFormatZoneData.java:144)
	at
sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:100)
	at
sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:105)
	at java.text.DateFormatSymbols.loadZoneStrings(DateFormatSymbols.java:449)
	at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:489)
	at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:103)
	at java.util.TimeZone.retrieveDisplayNames(TimeZone.java:412)
	at java.util.TimeZone.getDisplayNames(TimeZone.java:401)
	at java.util.TimeZone.getDisplayName(TimeZone.java:352)
	at java.util.Date.toString(Date.java:1024)
	at java.lang.String.valueOf(String.java:2615)
	at java.lang.StringBuffer.append(StringBuffer.java:220)
	at
org.apache.derby.impl.services.stream.BasicGetLogHeader.getHeader(Unknown
Source)
	at org.apache.derby.iapi.error.ErrorStringBuilder.appendln(Unknown Source)
	at
org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown
Source)
	at
org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown
Source)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown
Source)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown
Source)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown
Source)
	at
org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown
Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown
Source)
	at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
	at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
	at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:931)
	at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:607)
	at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:535)
	at
org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1702)
	at
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
	at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:207)
	at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:193)
	at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:264)






-- 
View this message in context: http://old.nabble.com/Strange-OutOfMemory-in-unittest-tp34080334p34080334.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Re: Strange OutOfMemory in unittest

Posted by Kristian Waagan <kr...@oracle.com>.
On 28.06.2012 12:18, mogoye wrote:
> Problem is found :
>
> You were right, the problem was that my JVM starts with only 64m of heap
> size.
> I don't know why but I was sure I read somewhere that with JDK 1.5 the
> default max heap size was 512m...

It can vary depending on the machine, platform, Java version and whether 
you run with -client or -server. What's happening has changed with the 
Java versions, so this is getting a bit muddy...
It may be useful to set the maximum heap size explicitly.

In any case, good to hear that you figured out what the problem was :)


Cheers,
-- 
Kristian

> So I was on the wrong track.
>
> Sorry to make you loose precious time for a stupid mistake

Re: Strange OutOfMemory in unittest

Posted by mogoye <sy...@eloquant.com>.
Problem is found : 

You were right, the problem was that my JVM starts with only 64m of heap
size.
I don't know why but I was sure I read somewhere that with JDK 1.5 the
default max heap size was 512m...
So I was on the wrong track.

Sorry to make you loose precious time for a stupid mistake
-- 
View this message in context: http://old.nabble.com/Strange-OutOfMemory-in-unittest-tp34080334p34085473.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Re: Strange OutOfMemory in unittest

Posted by mogoye <sy...@eloquant.com>.
Thx for your answer, 

When you said :

Kristian Waagan-2 wrote:
> 
> As already mentioned, you should check what your maximum heap size is 
> set to. If Derby is run with the default page cache size, it normally 
> shouldn't occupy much more than 4 MB of heap.
> 

I think you refer to derby.storage.pageCacheSize option (before your mail I
was not aware of this option).
I that case the OutOfMemory could not be a pbm with the JVM heap, but just
with derby configuration.

I'm going to make some new test with that option.
-- 
View this message in context: http://old.nabble.com/Strange-OutOfMemory-in-unittest-tp34080334p34084791.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Re: Strange OutOfMemory in unittest

Posted by Kristian Waagan <kr...@oracle.com>.
On 27.06.12 15:15, mogoye wrote:
>
> Hello,
>
> I'm currently working on a some junit tests to validate My DB using Derby
> 1.8.1.2.
> My code is using JPA annotations and Eclipselink implementation.
>
> The purpose of this test is to evaluate the performances of my requests.
> My test is doing the following things :
> - Create an empty DB.
> - Fill DB with 200 000 entries
> - Performs some requests.
> - Check answers are Ok and measure time to proccess them.
>
> The thing I don't understant is why my test can be executed 50% of the time
> with no problem, and the other 50% I have OutOfMemory that occurs at various
> tests execution.
>
> I don't understand why the same code executed few seconds later can sometime
> be a success or failure.
>
>
> For example here is one of the request that is executed.
> In that case the request is a native querry and a very basic request:
> SELECT * FROM TICKET ORDER BY EXPECTED_DATE ASC OFFSET 33000 ROWS FETCH
> FIRST 20 ROWS ONLY
>
>
> My DB (measured on the file system) is only 100Mb so not very big one
> See bellow the stack trace.
>
> I have no idea how I can go further as I'm not very familliar with derby
> tools or logs to help debugging.
>
> Does any one have some idea ?

As already mentioned, you should check what your maximum heap size is 
set to. If Derby is run with the default page cache size, it normally 
shouldn't occupy much more than 4 MB of heap.

If your VM supports it, you could dump the heap when the OOME occurs 
[1], or use something like VisualVM (maybe with the visualgc plugin) to 
observe the memory usage. If you obtain a dump, you have to extract 
information from it afterwards, for instance with jhat. If you search 
the web, you'll probably find other tools doing similar things.
Note that you can always obtain heap dumps with VisualVM, and 
information like the max heap size.

You could also sample the heap manually by using a tool like jmap to get 
a heap histogram.

In many cases the thread stack trace is a red herring, at least in 
multi-threaded applications, since the OOME can happen at any place 
where memory is needed/allocated.


Regards,
-- 
Kristian

[1] For the Sun/Oracle JVMs that would be -XX:+HeapDumpOnOutOfMemoryError

>
> Thanks a lot.
> Sylvain
>
>
>
>
> Here is the complete Stack trace I can get (sometimes I do not have any
> stack info):
>
> java.lang.OutOfMemoryError: Java heap space
> 	at
> sun.text.resources.DateFormatZoneData.getContents(DateFormatZoneData.java:299)
> 	at
> sun.text.resources.DateFormatZoneData.loadLookup(DateFormatZoneData.java:144)
> 	at
> sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:100)
> 	at
> sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:105)
> 	at java.text.DateFormatSymbols.loadZoneStrings(DateFormatSymbols.java:449)
> 	at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:489)
> 	at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:103)
> 	at java.util.TimeZone.retrieveDisplayNames(TimeZone.java:412)
> 	at java.util.TimeZone.getDisplayNames(TimeZone.java:401)
> 	at java.util.TimeZone.getDisplayName(TimeZone.java:352)
> 	at java.util.Date.toString(Date.java:1024)
> 	at java.lang.String.valueOf(String.java:2615)
> 	at java.lang.StringBuffer.append(StringBuffer.java:220)
> 	at
> org.apache.derby.impl.services.stream.BasicGetLogHeader.getHeader(Unknown
> Source)
> 	at org.apache.derby.iapi.error.ErrorStringBuilder.appendln(Unknown Source)
> 	at
> org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown
> Source)
> 	at
> org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown
> Source)
> 	at
> org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown
> Source)
> 	at
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> 	at
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:931)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:607)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:535)
> 	at
> org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1702)
> 	at
> org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:207)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:193)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:264)
>
>
>
>
>
>


Re: Strange OutOfMemory in unittest

Posted by mogoye <sy...@eloquant.com>.
Thx a lot for your answer.



> I can only speculate on the 'why' but perhaps more importantly is how
> big a heap are you currently allocating and have you tried bumping that 
> up? 
> 
I've connected JConsole to my process I it seems that the process never
allocate more than 80Mb (so very few memory). I'm currently trying to
reproduce the OutOfMemory, with JVM launched with
-XX:+HeapDumpOnOutOfMemoryError parameter. But Since I added this param I
could not reproduce the problem.



> As to 'why', well perhaps it is just a timing thing where the code needs 
> to allocate more objects but the gc hasn't run yet to free more space. 
> 
My last tests are consistent with the hypothesis of a timming problem.
But has my process does not use more than 80Mb I don't think this a a pbm
with GC as JVM could still allocate memory.



> One other question:  Are you running your tests from Eclipse in the same 
> jvm?  If you run them from a shell would you get the same failure rate? 
> 
Yes my test was running using eclispe "run as Junit Test". 
Actually I could not reproduce pbm running the test in command line (mvn
clean install).

Sylvain

-- 
View this message in context: http://old.nabble.com/Strange-OutOfMemory-in-unittest-tp34080334p34084681.html
Sent from the Apache Derby Users mailing list archive at Nabble.com.


Re: Strange OutOfMemory in unittest

Posted by Tim Watts <ti...@cliftonfarm.org>.
On Wed, 2012-06-27 at 06:15 -0700, mogoye wrote:
> Hello, 
> 
> I'm currently working on a some junit tests to validate My DB using Derby
> 1.8.1.2.
> My code is using JPA annotations and Eclipselink implementation.
> 
> The purpose of this test is to evaluate the performances of my requests.
> My test is doing the following things :
> - Create an empty DB.
> - Fill DB with 200 000 entries
> - Performs some requests.
> - Check answers are Ok and measure time to proccess them.
> 
> The thing I don't understant is why my test can be executed 50% of the time
> with no problem, and the other 50% I have OutOfMemory that occurs at various
> tests execution.
> 
> I don't understand why the same code executed few seconds later can sometime
> be a success or failure.
> 
I can only speculate on the 'why' but perhaps more importantly is how
big a heap are you currently allocating and have you tried bumping that
up?

As to 'why', well perhaps it is just a timing thing where the code needs
to allocate more objects but the gc hasn't run yet to free more space.
I don't know if a forced gc would occur if the jvm didn't have enough
heap but it seems like it would.  Or perhaps you're running parallel
tests and the timing is such that there aren't enough unreferenced
objects to gc when another test needs to create more.

All speculation, I know.  I confess I'm not an expert in this area.  I
would just try bumping -Xmx first.

One other question:  Are you running your tests from Eclipse in the same
jvm?  If you run them from a shell would you get the same failure rate?

> 
> For example here is one of the request that is executed.
> In that case the request is a native querry and a very basic request: 
> SELECT * FROM TICKET ORDER BY EXPECTED_DATE ASC OFFSET 33000 ROWS FETCH
> FIRST 20 ROWS ONLY
> 
> 
> My DB (measured on the file system) is only 100Mb so not very big one
> See bellow the stack trace.
> 
> I have no idea how I can go further as I'm not very familliar with derby
> tools or logs to help debugging.
> 
> Does any one have some idea ?
> 
> Thanks a lot.
> Sylvain
> 
> 
> 
> 
> Here is the complete Stack trace I can get (sometimes I do not have any
> stack info): 
> 
> java.lang.OutOfMemoryError: Java heap space
> 	at
> sun.text.resources.DateFormatZoneData.getContents(DateFormatZoneData.java:299)
> 	at
> sun.text.resources.DateFormatZoneData.loadLookup(DateFormatZoneData.java:144)
> 	at
> sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:100)
> 	at
> sun.text.resources.DateFormatZoneData.getKeys(DateFormatZoneData.java:105)
> 	at java.text.DateFormatSymbols.loadZoneStrings(DateFormatSymbols.java:449)
> 	at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:489)
> 	at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:103)
> 	at java.util.TimeZone.retrieveDisplayNames(TimeZone.java:412)
> 	at java.util.TimeZone.getDisplayNames(TimeZone.java:401)
> 	at java.util.TimeZone.getDisplayName(TimeZone.java:352)
> 	at java.util.Date.toString(Date.java:1024)
> 	at java.lang.String.valueOf(String.java:2615)
> 	at java.lang.StringBuffer.append(StringBuffer.java:220)
> 	at
> org.apache.derby.impl.services.stream.BasicGetLogHeader.getHeader(Unknown
> Source)
> 	at org.apache.derby.iapi.error.ErrorStringBuilder.appendln(Unknown Source)
> 	at
> org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown
> Source)
> 	at
> org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown
> Source)
> 	at
> org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown
> Source)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown
> Source)
> 	at
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> 	at
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:931)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:607)
> 	at
> org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:535)
> 	at
> org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1702)
> 	at
> org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:207)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:193)
> 	at
> org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:264)
> 
> 
> 
> 
> 
> 
> -- 
> View this message in context: http://old.nabble.com/Strange-OutOfMemory-in-unittest-tp34080334p34080334.html
> Sent from the Apache Derby Users mailing list archive at Nabble.com.
>