Обсуждение: PostgreSQL JDBC - Long Running Stored Procedure - Out of Memory

Hello.

I have a strange problem when calling a long running stored procedure
from Java JDBC.

process_import_item() is a stored procedure in PostgreSQL which has
boolean as return type.

When I call the stored procedure manually (via psql), it takes about
15 minutes to run.

When I call the stored procedure from Java/JDBC, it runs for some
hours and then crashes the Virtual Machine with an
"java.lang.OutOfMemoryError: Java heap space".

My code is the following (autocommit is enabled):
...
            final CallableStatement st1 = msCon.prepareCall("{call
process_import_item()}");
            st1.execute();
...

The stack trace is the following:

13:47:33,588 ERROR [STDERR] java.lang.OutOfMemoryError: Java heap space
13:47:33,589 ERROR [STDERR]     at java.util.Arrays.copyOf(Arrays.java:2786)
13:47:36,095 ERROR [STDERR]     at
java.lang.StringCoding.safeTrim(StringCoding.java:64)
13:47:36,096 ERROR [STDERR]     at
java.lang.StringCoding.access$300(StringCoding.java:34)
13:47:36,096 ERROR [STDERR]     at
java.lang.StringCoding$StringEncoder.encode(StringCoding.java:251)
13:47:38,585 ERROR [STDERR]     at
java.lang.StringCoding.encode(StringCoding.java:272)
13:47:38,585 ERROR [STDERR]     at java.lang.String.getBytes(String.java:947)
13:47:41,088 ERROR [STDERR]     at
java.io.UnixFileSystem.getBooleanAttributes0(Native Method)
13:47:41,088 ERROR [STDERR]     at
java.io.UnixFileSystem.getBooleanAttributes(UnixFileSystem.java:228)
13:47:46,096 ERROR [STDERR]     at java.io.File.isDirectory(File.java:754)
13:47:48,602 ERROR [STDERR]     at
org.jboss.net.protocol.file.FileURLLister.listFiles(FileURLLister.java:127)
13:47:48,602 ERROR [STDERR]     at
org.jboss.net.protocol.file.FileURLLister.listMembers(FileURLLister.java:75)
13:47:51,115 ERROR [STDERR]     at
org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:497)
13:47:53,614 ERROR [STDERR]     at
org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
13:47:56,113 ERROR [STDERR]     at
org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.loop(AbstractDeploymentScanner.java:274)
13:47:56,113 ERROR [STDERR]     at
org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.run(AbstractDeploymentScanner.java:225)
13:49:05,456 ERROR [[CommandServlet]] Servlet.service() for servlet
CommandServlet threw exception
java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOfRange(Arrays.java:3209)
        at java.lang.String.<init>(String.java:216)
        at org.postgresql.util.ServerErrorMessage.<init>(ServerErrorMessage.java:49)
        at org.postgresql.core.v3.QueryExecutorImpl.receiveNoticeResponse(QueryExecutorImpl.java:1476)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1280)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:175)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:389)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:330)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:321)
        at myapplication.processData(CrmCommandHandler.java:337)

Additionally, during the hours while the stored procedure runs, the
Java VM grows slowly but steadly in the memory usage (some Mb per
minute).

Am I doing something wrong? Where should I look to diagnose/fix this issue?

Thank you!

My setup:
 PostgreSQL 8.2.7-1 with postgresql-8.2-507.jdbc4.jar

java -version:
 java version "1.6.0"
 Java(TM) SE Runtime Environment (build 1.6.0-b105)
 Java HotSpot(TM) Client VM (build 1.6.0-b105, mixed mode, sharing)

Linux 2.6.24-19-generic #1 SMP Wed Aug 20 22:56:21 UTC 2008 i686
GNU/Linux (Ubuntu 8.10).



--
Dr. Andrea Lombardoni
andrea.lombardoni@oneoverzero.net

OneOverZero GmbH http://www.oneoverzero.net/
Militärstrasse 76
CH-8004 Zuerich
T:  +41 (43) 5384294

OK. I found the problem.

The stored procedure "process_import_item()" heavily uses the "RAISE
NOTICE" construct to print debugging information.

It seems that calling a stored procedure via JDBC in this way:
 final CallableStatement st1 = msCon.prepareCall("{call
process_import_item()}");

Makes the Java side keep in memory all the output of the RAISE NOTICE
statements (which amounts to hundreds of Mb).

By removing the RAISE NOTICE from the stored procedure, everything now
works fine.

I solved my problem, but really, why does the PostgreSQL JDBC driver
have to keep in memory all the RAISE NOTICE texts?
Can't they simply be discarded/ignored?

Bye

> On Thu, Jan 22, 2009 at 9:24 AM, Andrea Lombardoni <and...@lombardoni.ch>wrote:
>
> > Hello.
>
> > I have a strange problem when calling a long running stored procedure
> > from Java JDBC.
>
> > process_import_item() is a stored procedure in PostgreSQL which has
> > boolean as return type.
>
> > When I call the stored procedure manually (via psql), it takes about
> > 15 minutes to run.
>
> > When I call the stored procedure from Java/JDBC, it runs for some
> > hours and then crashes the Virtual Machine with an
> > "java.lang.OutOfMemoryError: Java heap space".
>
> > My code is the following (autocommit is enabled):
> > ...
> >            final CallableStatement st1 = msCon.prepareCall("{call
> > process_import_item()}");
> >            st1.execute();
> > ...
>
> > The stack trace is the following:
>
> > 13:47:33,588 ERROR [STDERR] java.lang.OutOfMemoryError: Java heap space
> > 13:47:33,589 ERROR [STDERR]     at
> > java.util.Arrays.copyOf(Arrays.java:2786)
> > 13:47:36,095 ERROR [STDERR]     at
> > java.lang.StringCoding.safeTrim(StringCoding.java:64)
> > 13:47:36,096 ERROR [STDERR]     at
> > java.lang.StringCoding.access$300(StringCoding.java:34)
> > 13:47:36,096 ERROR [STDERR]     at
> > java.lang.StringCoding$StringEncoder.encode(StringCoding.java:251)
> > 13:47:38,585 ERROR [STDERR]     at
> > java.lang.StringCoding.encode(StringCoding.java:272)
> > 13:47:38,585 ERROR [STDERR]     at
> > java.lang.String.getBytes(String.java:947)
> > 13:47:41,088 ERROR [STDERR]     at
> > java.io.UnixFileSystem.getBooleanAttributes0(Native Method)
> > 13:47:41,088 ERROR [STDERR]     at
> > java.io.UnixFileSystem.getBooleanAttributes(UnixFileSystem.java:228)
> > 13:47:46,096 ERROR [STDERR]     at java.io.File.isDirectory(File.java:754)
> > 13:47:48,602 ERROR [STDERR]     at
> > org.jboss.net.protocol.file.FileURLLister.listFiles(FileURLLister.java:127)
> > 13:47:48,602 ERROR [STDERR]     at
>
> > org.jboss.net.protocol.file.FileURLLister.listMembers(FileURLLister.java:75)
> > 13:47:51,115 ERROR [STDERR]     at
>
> > org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:497)
> > 13:47:53,614 ERROR [STDERR]     at
>
> > org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
> > 13:47:56,113 ERROR [STDERR]     at
>
> > org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.loop(AbstractDeploymentScanner.java:274)
> > 13:47:56,113 ERROR [STDERR]     at
>
> > org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.run(AbstractDeploymentScanner.java:225)
> > 13:49:05,456 ERROR [[CommandServlet]] Servlet.service() for servlet
> > CommandServlet threw exception
> > java.lang.OutOfMemoryError: Java heap space
> >        at java.util.Arrays.copyOfRange(Arrays.java:3209)
> >        at java.lang.String.<init>(String.java:216)
> >        at
> > org.postgresql.util.ServerErrorMessage.<init>(ServerErrorMessage.java:49)
> >        at
> > org.postgresql.core.v3.QueryExecutorImpl.receiveNoticeResponse(QueryExecutorImpl.java:1476)
> >        at
> > org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1280)
> >        at
> > org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:175)
> >        at
> > org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:389)
> >        at
> > org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:330)
> >        at
> > org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:321)
> >        at myapplication.processData(CrmCommandHandler.java:337)
>
> > Additionally, during the hours while the stored procedure runs, the
> > Java VM grows slowly but steadly in the memory usage (some Mb per
> > minute).
>
> > Am I doing something wrong? Where should I look to diagnose/fix this issue?
>
> > Thank you!
>
> > My setup:
> >  PostgreSQL 8.2.7-1 with postgresql-8.2-507.jdbc4.jar
>
> > java -version:
> >  java version "1.6.0"
> >  Java(TM) SE Runtime Environment (build 1.6.0-b105)
> >  Java HotSpot(TM) Client VM (build 1.6.0-b105, mixed mode, sharing)
>
> > Linux 2.6.24-19-generic #1 SMP Wed Aug 20 22:56:21 UTC 2008 i686
> > GNU/Linux (Ubuntu 8.10).
>
> > --
> > Dr. Andrea Lombardoni
> > andrea.lombard...@oneoverzero.net
>
> > OneOverZero GmbHhttp://www.oneoverzero.net/
> > Militärstrasse 76
> > CH-8004 Zuerich
> > T:  +41 (43) 5384294
>
> > --
> > Sent via pgsql-jdbc mailing list (pgsql-j...@postgresql.org)
> > To make changes to your subscription:
> >http://www.postgresql.org/mailpref/pgsql-jdbc

On Thu, 22 Jan 2009, ErMejo wrote:

> I solved my problem, but really, why does the PostgreSQL JDBC driver
> have to keep in memory all the RAISE NOTICE texts?
> Can't they simply be discarded/ignored?

The notices are available from Statement.getWarnings().  Why output them
if you were just going to throw them away?

Kris Jurka

Andrea Lombardoni wrote:
>>> I solved my problem, but really, why does the PostgreSQL JDBC driver
>>> have to keep in memory all the RAISE NOTICE texts?
>>> Can't they simply be discarded/ignored?
>> The notices are available from Statement.getWarnings().
>
> Is there a way to make the JDBC driver ignore them?
>
>> Why output them if
>> you were just going to throw them away?
>
> They are meant to be stored in the PostgreSQL server logs (and later
> analyzed), but there is no use for them on the Java side.
>

If you don't want them sent to the client, you should adjust the setting
of client_min_messages to a higher value to keep them from being sent to
the JDBC driver at all.

Kris Jurka