You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Chris Wilson (JIRA)" <ji...@apache.org> on 2010/04/18 15:20:25 UTC

[jira] Created: (DERBY-4620) Query optimizer causes OOM error on a complex query

Query optimizer causes OOM error on a complex query
---------------------------------------------------

                 Key: DERBY-4620
                 URL: https://issues.apache.org/jira/browse/DERBY-4620
             Project: Derby
          Issue Type: Bug
          Components: SQL
    Affects Versions: 10.5.3.0
         Environment: java version "1.6.0_17"
Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
            Reporter: Chris Wilson


I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.

I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.

You can check out the test case from our Subversion server here:

  http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query

which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.

Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:

  http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql

The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:

JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
is a pending operation in the parent connection.
(process exits)

It does not output the query plan in this case.

Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858869#action_12858869 ] 

Chris Wilson commented on DERBY-4620:
-------------------------------------

It seems possible to reproduce the issue on 1.6.0_20 with the following command:

    JAVA=/usr/lib/jvm/jdk1.6.0_20/bin/java JAVA_OPTS="-Xmx62m -Dderby.language.maxMemoryPerTable=512" ./test.sh

(you may need to svn update to get the latest version of test.sh).

Perhaps using derby.language.maxMemoryPerTable allows us to separate the "reasonable memory detection" and the "overflowing hash tables" parts of the problem?

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858543#action_12858543 ] 

Chris Wilson commented on DERBY-4620:
-------------------------------------

I don't think it's the wrong dump, I just copied it from my Subversion checkout directory, bunzipped it, and opened it in Eclipse. The file I opened was:

$ md5sum /tmp/java_pid32345.hprof 
a493898efa0834726b163f126422bf02  /tmp/java_pid32345.hprof

I see the same counts for some objects as in your histogram, e.g.

Class Name                            | Objects | Shallow Heap | Retained Heap 

------------------------------------------------------------------------------

org.apache.derby.iapi.types.SQLVarchar| 233,173 |    9,326,920 | >= 13,057,688 

org.apache.derby.iapi.types.DataValueDescriptor[]| 100,376 |    7,641,528 | >= 48,864,896 

char[][]  | 365,401 |    5,847,240 |  >= 5,850,664 

--------------------------------------------------


I don't see all the classes that you see, and I see some that you don't. Could it be due to a filter in your Eclipse?

Re: What was the max heap size set to when you got this OOME? it was the default for Sun Java 1.6.0_17, which behaves the same way if it's set to -Xmx64m, although I can't promise you that it was actually that value as I don't normally specify it.

Re: What was the Derby page cache size set to? (looks like maybe the default of 1000?) I haven't changed it from the default.

Re: If this is a JVM bug, it will be hard to - and maybe not predictable - to make a work-around for it in Derby. I understand that it would be difficult to regression-test it without bundling a separate copy of Java along with the test.

However once we understand the bug we can probably write a test case that would use ridiculously large amounts of memory, e.g. joining a table to itself thousands of times in a way that forces a hash join. This should cause a very quick failure if the JVM problem reoccurs, or if something else triggers an increase in the memory used by such joins.

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Chris Wilson updated DERBY-4620:
--------------------------------

    Attachment: query-plan.txt

Query plan attached. The heap dump is too large to upload here, please download it from http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query/java_pid32345.hprof.bz2 instead.

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Kristian Waagan (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858532#action_12858532 ] 

Kristian Waagan commented on DERBY-4620:
----------------------------------------

>From the HPROF dump you referenced, I get the (partial) histogram below. Doesn't seem too bad to me.
Two questions:
 o What was the max heap size set to when you got this OOME?
 o What was the Derby page cache size set to? (looks like maybe the default of 1000?)

If this is a JVM bug, it will be hard to - and maybe not predictable - to make a work-around for it in Derby.


Instance Count    Size (KB) Class
233'173               7'286 class org.apache.derby.iapi.types.SQLVarchar
100'376               7'018 class [Lorg.apache.derby.iapi.types.DataValueDescriptor;
  5'276               5'533 class [B
365'401               4'282 class [[C
118'855               3'714 class org.apache.derby.iapi.types.SQLChar
705'875               3'446 class org.apache.derby.iapi.types.SQLInteger
158'660               1'859 class org.apache.derby.iapi.types.SQLDecimal
 85'835               1'437 class [Ljava.lang.Object;
 70'744               1'105 class java.util.HashMap$Entry
 50'995                 957 class [C
 84'979                 746 class org.apache.derby.iapi.types.SQLLongint
 40'015                 664 class org.apache.derby.impl.store.raw.data.StoredRecordHeader
216'015                 632 class org.apache.derby.iapi.types.SQLSmallint
    307                 600 class [Ljava.util.HashMap$Entry;
 38'259                 597 class org.apache.derby.iapi.types.SQLTimestamp
 13'270                 518 class org.apache.derby.iapi.types.SQLClob
 40'018                 468 class org.apache.derby.impl.store.raw.data.RecordId
 70'179                 274 class org.apache.derby.iapi.store.access.KeyHasher
 13'298                 207 class org.apache.derby.impl.store.access.heap.HeapRowLocation
  1'000                 175 class org.apache.derby.impl.store.raw.data.StoredPage
 14'866                 174 class java.util.ArrayList
  2'487                 170 class [I
  1'000                 164 class [Lorg.apache.derby.impl.store.raw.data.StoredRecordHeader;
  2'104                 156 class java.lang.Class
  1'542                 110 class [S
 12'753                  99 class org.apache.derby.iapi.types.SQLDate
  3'939                  61 class java.lang.String
    368                  46 class [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Kristian Waagan (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858298#action_12858298 ] 

Kristian Waagan commented on DERBY-4620:
----------------------------------------

I haven't had the time to investigate further, but on my laptop (Tecra M9, dual core Centrino) the repro runs okay:

2038 rows inserted/updated/deleted
ij> 
real    0m21.677s
user   0m27.563s
sys     0m0.851s

$ java -version
java version "1.6.0_18"
Java(TM) SE Runtime Environment (build 1.6.0_18-b07)
Java HotSpot(TM) Server VM (build 16.0-b13, mixed mode)

Derby 10.5.3.0

With -Xmx128m and -client :
2038 rows inserted/updated/deleted
ij> 
real    0m19.518s
user   0m17.211s
sys     0m0.498s

Can you run the repro on your side with -XX:+HeapDumpOnOutOfMemoryError and generate a heap histogram from the dump?

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858504#action_12858504 ] 

Chris Wilson commented on DERBY-4620:
-------------------------------------

Thanks Bryan! This does indeed look like a very useful tool. I use Eclipse anyway so I just integrated it.

It looks like you were bang on about the hash joins too. The tool says:

One instance of "org.apache.derby.impl.sql.execute.GroupedAggregateResultSet" loaded by "sun.misc.Launcher$AppClassLoader @ 0x8bcf0c18" occupies 56,391,208 (84.51%) bytes. The memory is accumulated in one instance of "org.apache.derby.impl.sql.execute.HashJoinResultSet" loaded by "sun.misc.Launcher$AppClassLoader @ 0x8bcf0c18".Keywords
org.apache.derby.impl.sql.execute.HashJoinResultSet
org.apache.derby.impl.sql.execute.GroupedAggregateResultSet
sun.misc.Launcher$AppClassLoader @ 0x8bcf0c18

Shortest Paths To the Accumulation Point
Class Name	Shallow Heap	Retained Heap

    * org.apache.derby.impl.sql.execute.HashJoinResultSet @ 0x8c340338

	224	37,137,944
\

    * leftResultSet org.apache.derby.impl.sql.execute.HashJoinResultSet @ 0x8c340418

	224	38,803,032
.\

    * leftResultSet org.apache.derby.impl.sql.execute.HashJoinResultSet @ 0x8c3404f8

	224	42,779,744
..\

    * leftResultSet org.apache.derby.impl.sql.execute.HashJoinResultSet @ 0x8c3405d8

	224	49,585,056
...\

    * leftResultSet org.apache.derby.impl.sql.execute.HashJoinResultSet @ 0x8c3406b8

	224	56,390,424
....\

    * source org.apache.derby.impl.sql.execute.ProjectRestrictResultSet @ 0x8c340798

	200	56,390,624
.....\

    * originalSource, source org.apache.derby.impl.sql.execute.GroupedAggregateResultSet @ 0x8c340860

	240	56,391,208
......+

    * <Java Local> java.lang.Thread @ 0x8bcf0e18 main Thread

	104	116,856
......+

    * source org.apache.derby.impl.sql.execute.ProjectRestrictResultSet @ 0x8c340950 ยป

	200	200
......\

    * Total: 2 entries

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Kristian Waagan (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858535#action_12858535 ] 

Kristian Waagan commented on DERBY-4620:
----------------------------------------

Deleted my previous comment.
I didn't see the same as what Chris sees, maybe it was the wrong dump or something?

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858802#action_12858802 ] 

Chris Wilson commented on DERBY-4620:
-------------------------------------

Thanks Bryan.

I can reproduce the OOM error with Sun Java 1.6.0_20 by running:

  JAVA=/usr/lib/jvm/jdk1.6.0_20/bin/java JAVA_OPTS=-Xmx64m ./test.sh

although it doesn't take 10 minutes to fail. From Bryan's explanation, I don't think this should happen, so something appears to be wrong in the hash join decision logic, and we should be able to write a test for it that fails on more recent JVMs, and doesn't take 10 minutes to do so.

This does appear to be related to DERBY-106, as setting derby.language.maxMemoryPerTable=0 causes the query to complete successfully with -Xmx64m, albeit quite slowly (in about four minutes).

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Bryan Pendleton (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858490#action_12858490 ] 

Bryan Pendleton commented on DERBY-4620:
----------------------------------------

jhat requires enormous amounts of memory; there is a special flag that you can
use when running it.

Or, better, try the Eclipse Memory Analysis Tool -- it's a MUCH better tool.

You can download the tool in a standalone package; you don't have to use all of Eclipse.
http://www.eclipse.org/mat/downloads.php

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Bryan Pendleton (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858299#action_12858299 ] 

Bryan Pendleton commented on DERBY-4620:
----------------------------------------

Chris, thanks for filing this issue. Can you also attach 
the query plan that you posted to the derby-users list?

I noticed in a quick scan of the query plan that there were
multiple internal hash joins being performed.

Perhaps this is a situation where the intermediate hash
tables don't fit in memory, and are being paged from disk.
I think I recall some very pathological performance behaviors
when hash join tables don't fit into real memory.


> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Chris Wilson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858438#action_12858438 ] 

Chris Wilson commented on DERBY-4620:
-------------------------------------

Thanks Kristian, I downloaded and tested 1.6.0_20 and it behaves normally (doesn't crash) with this version, so it appears to be a bug in Sun Java 1.6.0_17 that has been fixed in more recent versions.

Unfortunately this is the default packaged version of Java in Ubuntu Hardy, but that's their fault and not Derby's. I will add my voice to those trying to persuade them to push out an update. In the mean time I still need a workaround for this version.

Bryan, I will attach the query plan. Perhaps improving the optimisation of the query might enable it to run without exhausting memory or increasing the default limits even on older JDKs? Using the -server VM doesn't seem to help.

I'll also attach the heap dump, which ironically causes jhat to crash with an OOM error as well :)

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Kristian Waagan (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Kristian Waagan updated DERBY-4620:
-----------------------------------

    Comment: was deleted

(was: From the HPROF dump you referenced, I get the (partial) histogram below. Doesn't seem too bad to me.
Two questions:
 o What was the max heap size set to when you got this OOME?
 o What was the Derby page cache size set to? (looks like maybe the default of 1000?)

If this is a JVM bug, it will be hard to - and maybe not predictable - to make a work-around for it in Derby.


Instance Count    Size (KB) Class
233'173               7'286 class org.apache.derby.iapi.types.SQLVarchar
100'376               7'018 class [Lorg.apache.derby.iapi.types.DataValueDescriptor;
  5'276               5'533 class [B
365'401               4'282 class [[C
118'855               3'714 class org.apache.derby.iapi.types.SQLChar
705'875               3'446 class org.apache.derby.iapi.types.SQLInteger
158'660               1'859 class org.apache.derby.iapi.types.SQLDecimal
 85'835               1'437 class [Ljava.lang.Object;
 70'744               1'105 class java.util.HashMap$Entry
 50'995                 957 class [C
 84'979                 746 class org.apache.derby.iapi.types.SQLLongint
 40'015                 664 class org.apache.derby.impl.store.raw.data.StoredRecordHeader
216'015                 632 class org.apache.derby.iapi.types.SQLSmallint
    307                 600 class [Ljava.util.HashMap$Entry;
 38'259                 597 class org.apache.derby.iapi.types.SQLTimestamp
 13'270                 518 class org.apache.derby.iapi.types.SQLClob
 40'018                 468 class org.apache.derby.impl.store.raw.data.RecordId
 70'179                 274 class org.apache.derby.iapi.store.access.KeyHasher
 13'298                 207 class org.apache.derby.impl.store.access.heap.HeapRowLocation
  1'000                 175 class org.apache.derby.impl.store.raw.data.StoredPage
 14'866                 174 class java.util.ArrayList
  2'487                 170 class [I
  1'000                 164 class [Lorg.apache.derby.impl.store.raw.data.StoredRecordHeader;
  2'104                 156 class java.lang.Class
  1'542                 110 class [S
 12'753                  99 class org.apache.derby.iapi.types.SQLDate
  3'939                  61 class java.lang.String
    368                  46 class [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;)

> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DERBY-4620) Query optimizer causes OOM error on a complex query

Posted by "Bryan Pendleton (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DERBY-4620?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12858745#action_12858745 ] 

Bryan Pendleton commented on DERBY-4620:
----------------------------------------

Chris, thanks for posting the detailed heap information.

Your problem seems in some ways similar to DERBY-106, which was
supposed to be fixed a long time ago.

My vague understanding of how hash joins are supposed to use memory is:
1) The HashJoin code is supposed to call some JVM call (Runtime.getFreeMemory?)
    to figure out how much memory is available, and then only use a small part of it.
2) The execution of a HashJoin is supposed to use a BackingStoreHashTable,
    which is supposed to be able to gracefully overflow to disk when there is
    not enough memory. Here's an ancient message from Jack about how this
    is supposed to work: http://www.mail-archive.com/derby-dev@db.apache.org/msg01914.html
    and a related message from Mike about possible problems with it:
    http://www.mail-archive.com/derby-dev@db.apache.org/msg01360.html
3) There is an undocumented derby.language.maxMemoryPerTable setting that
    is supposed to influence this processing (see DERBY-1397)

It seems clear that, in your case, the hash join strategy is doubly flawed:
1) To run efficiently, it needed much more memory than you initially gave it, so
    since that memory wasn't available, the Optimizer shouldn't have chosen the hash joins
2) Having chosen the hash joins, the execution code isn't supposed to run out of memory,
    because it's supposed to use only a portion of the available memory and then
    start overflowing to disk.

Here's an interesting message from Army from a few years back discussing 
some of these issues in a different scenario:
http://www.mailinglistarchive.com/html/derby-user@db.apache.org/2008-07/msg00897.html

I have this vague memory that, some time ago, we looked at a problem where it
seemed that BackingStoreHashTable wasn't behaving correctly, but I don't recall
the outcome of that conversation and I wasn't successful searching for it. This thread
seems to discuss the issues in great detail, but I don't know what came of it, entirely,
as it was rather before my time with Derby:
http://mail-archives.apache.org/mod_mbox/db-derby-dev/200501.mbox/%3C41F6A8F9.7030806@Mutagen.Net%3E

I'm not quite sure where to take this information next, but I wanted to get it into
the JIRA entry while I was thinking about it.


> Query optimizer causes OOM error on a complex query
> ---------------------------------------------------
>
>                 Key: DERBY-4620
>                 URL: https://issues.apache.org/jira/browse/DERBY-4620
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.5.3.0
>         Environment: java version "1.6.0_17"
> Java(TM) SE Runtime Environment (build 1.6.0_17-b04)
> Java HotSpot(TM) Client VM (build 14.3-b01, mixed mode, sharing)
> Linux rocio.xxx 2.6.24-27-generic #1 SMP Fri Mar 12 01:10:31 UTC 2010 i686 GNU/Linux
>            Reporter: Chris Wilson
>         Attachments: query-plan.txt
>
>
> I have a query that generates about 2,000 rows in a summary table. It runs fast enough (~30 seconds) on MySQL. The same query on Derby runs for about 10 minutes and then fails with an OutOfMemoryError.
> I have created a test case to reproduce the problem. It's not minimal because it relies on a rather large dataset to reproduce it, and it's not trivial, but I don't mind doing a bit of work trimming it if someone can point me in the necessary direction.
> You can check out the test case from our Subversion server here:
>   http://rita.wfplogistics.org/svn/trackrita/rita/doc/derby-oom-slow-query
> which includes a pre-built Derby database in "testdb.derby". If this database is deleted, "test.sh" will recreate it, but that takes about 10-15 minutes.
> Just modify the script "test.sh" to point to your Derby libraries, and run it (or just execute the commands in "movement_complete.sql") to demonstrate the problem. You can view the source of that file online here:
>   http://rita.wfplogistics.org/trac/browser/rita/conf/movement_complete.sql
> The first "insert into movement_complete" (starting around line 4) takes about 15 seconds to complete and inserts 5890 rows. The second, starting around line 54, does not complete in reasonable time on Derby. On MySQL, it runs in 28 seconds and inserts 2038 rows. On Derby, after 10 minutes I get:
> JAVA ERROR: java.lang.OutOfMemoryError: Java heap space
> ij> ERROR X0Y67: Cannot issue rollback in a nested connection when there 
> is a pending operation in the parent connection.
> (process exits)
> It does not output the query plan in this case.
> Following the suggestion of Bryan Pendleton, I tried increasing the JVM memory limit from the default to 1024m, and this allows the query to finish executing quite quickly. I guess that means that the optimiser is just taking a lot of memory to 
> optimise the query, and it spends forever in GC before finally hitting OOM and giving up when using the default settings.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.