Обсуждение: Transient runtime error: java.lang.NegativeArraySizeException from org.postgresql.core.PGStream.ReceiveTupleV3(PGStream.java:349) ...
Our application has been in production for a couple of years. Recent investigation into a problem revealed the following error started a few months back. I restarted the application, but the error appears after a few days and the thread dies.
Any ideas on how to debug this issue is appreciated.
- Ravi
[21/06/2010 13:49:27] WARN org.hibernate.util.JDBCExceptionReporter - SQL Error: 0, SQLState: null
[21/06/2010 13:49:27] ERROR org.hibernate.util.JDBCExceptionReporter - An SQLException was provoked by the following failure: java.lang.NegativeArraySizeException
[21/06/2010 13:49:27] ERROR com.aw.cac.nms.poller.ConfigurationService - Thread terminated with exception: pool-1-thread-1
org.hibernate.exception.GenericJDBCException: could not execute query
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.loader.Loader.doList(Loader.java:2147)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
at org.hibernate.loader.Loader.list(Loader.java:2023)
at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:289)
at org.hibernate.impl.SessionImpl.listCustomQuery(SessionImpl.java:1695)
at org.hibernate.impl.AbstractSessionImpl.list(AbstractSessionImpl.java:142)
at org.hibernate.impl.SQLQueryImpl.list(SQLQueryImpl.java:150)
at com.aw.cac.nms.mgmt.uw.UwDeviceManager.getDevices(UwDeviceManager.java:223)
at $DeviceManager_1294c519b0c.getDevices($DeviceManager_1294c519b0c.java)
at $DeviceManager_1294c519b0d.getDevices($DeviceManager_1294c519b0d.java)
at com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl$ManagedAddressLoader.getAddresses(ConfigurationServiceImpl.java:194)
at com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl.reload(ConfigurationServiceImpl.java:93)
at com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl$1.run(ConfigurationServiceImpl.java:84)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.SQLException: An SQLException was provoked by the following failure: java.lang.NegativeArraySizeException
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106)
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65)
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:62)
at com.mchange.v2.c3p0.impl.NewPooledConnection.handleThrowable(NewPooledConnection.java:369)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:93)
at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1668)
at org.hibernate.loader.Loader.doQuery(Loader.java:662)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.doList(Loader.java:2144)
... 21 more
Caused by: java.lang.NegativeArraySizeException
at org.postgresql.core.PGStream.ReceiveTupleV3(PGStream.java:349)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1306)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:451)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:350)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:254)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
... 26 more
--
---
Please DO NOT add my email to any marketing/communication/distribution lists or social networking sites, without my explicit permission to do so.
First guess would be a signed array index overflowing. You might be able to look at the stack trace and easily find the culprit in the codebase. It probably started showing up because a condition in your data set caused the overflow. row count or something. I don't have any significant experience debugging the jdbc driver, but the reason I'm on the list is because I did have to find and fix one bug, which I did by simply building the thing from source (really easy, just run ant in the source dir), and then just used eclipse's debugger to find and fix my problem. The process proved easy enough and code clean enough that it was actually quite painless. Then when I went to submit my patch, it turned out that my exact fix had already been applied to the latest code. So you may just trying building and running the latest codebase to see if it fixes your problem. --sam On Tue, Jun 22, 2010 at 7:07 PM, S K <extsknk@gmail.com> wrote: > > Our application has been in production for a couple of years. Recent > investigation into a problem revealed the following error started a few > months back. I restarted the application, but the error appears after a few > days and the thread dies. > Any ideas on how to debug this issue is appreciated. > - Ravi > > [21/06/2010 13:49:27] WARN org.hibernate.util.JDBCExceptionReporter - SQL > Error: 0, SQLState: null > [21/06/2010 13:49:27] ERROR org.hibernate.util.JDBCExceptionReporter - An > SQLException was provoked by the following failure: > java.lang.NegativeArraySizeException > [21/06/2010 13:49:27] ERROR com.aw.cac.nms.poller.ConfigurationService - > Thread terminated with exception: pool-1-thread-1 > org.hibernate.exception.GenericJDBCException: could not execute query > at > org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103) > at > org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91) > at > org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43) > at org.hibernate.loader.Loader.doList(Loader.java:2147) > at > org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028) > at org.hibernate.loader.Loader.list(Loader.java:2023) > at > org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:289) > at > org.hibernate.impl.SessionImpl.listCustomQuery(SessionImpl.java:1695) > at > org.hibernate.impl.AbstractSessionImpl.list(AbstractSessionImpl.java:142) > at org.hibernate.impl.SQLQueryImpl.list(SQLQueryImpl.java:150) > at > com.aw.cac.nms.mgmt.uw.UwDeviceManager.getDevices(UwDeviceManager.java:223) > at > $DeviceManager_1294c519b0c.getDevices($DeviceManager_1294c519b0c.java) > at > $DeviceManager_1294c519b0d.getDevices($DeviceManager_1294c519b0d.java) > at > com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl$ManagedAddressLoader.getAddresses(ConfigurationServiceImpl.java:194) > at > com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl.reload(ConfigurationServiceImpl.java:93) > > at com.aw.cac.nms.poller.reachability.ConfigurationServiceImpl$1.run(ConfigurationServiceImpl.java:84) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417) > at > java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280) > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166) > at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) > at java.lang.Thread.run(Thread.java:595) > Caused by: java.sql.SQLException: An SQLException was provoked by the > following failure: java.lang.NegativeArraySizeException > at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106) > at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65) > at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:62) > at > com.mchange.v2.c3p0.impl.NewPooledConnection.handleThrowable(NewPooledConnection.java:369) > at > com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:93) > at > org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186) > at org.hibernate.loader.Loader.getResultSet(Loader.java:1668) > at org.hibernate.loader.Loader.doQuery(Loader.java:662) > at > org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224) > at org.hibernate.loader.Loader.doList(Loader.java:2144) > ... 21 more > Caused by: java.lang.NegativeArraySizeException > at org.postgresql.core.PGStream.ReceiveTupleV3(PGStream.java:349) > at > org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1306) > at > org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192) > at > org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:451) > at > org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:350) > at > org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:254) > at > com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76) > ... 26 more > > > > -- > > --- > Please DO NOT add my email to any marketing/communication/distribution lists > or social networking sites, without my explicit permission to do so. >
On Tue, 22 Jun 2010, S K wrote: > > Our application has been in production for a couple of years. Recent > investigation into a problem revealed the following error started a few > months back. I restarted the application, but the error appears after a few > days and the thread dies. > > Caused by: java.lang.NegativeArraySizeException > at org.postgresql.core.PGStream.ReceiveTupleV3(PGStream.java:349) > atorg.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.j > ava:1306) > atorg.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192 > ) > atorg.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement. > java:451) > atorg.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2S > tatement.java:350) > atorg.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2State > ment.java:254) I haven't seen an error like this before. It most likely indicates that the driver has lost protocol sync with the server and is reading the wrong part of the message. This is difficult to debug because it's unknown how far back synchronization was lost. To try to debug this I would modify the driver to log the negative array size value and as much of the message parts I could find around it. That may give some clues as to why the driver is confused. Additionally, I would try to determine the triggering query and see if I could reproduce it. Kris Jurka
Thanks for your replies.
I followed Sam's suggestion and upgraded the jdbc driver to the latest version.
It has been more than a week and problem did not recur. I'm assuming the upgrade
fixed the issue (I saw in the release notes a cryptic note indicating fixes for data transformation).
--
---
Please DO NOT add my email to any marketing/communication/distribution lists or social networking sites, without my explicit permission to do so.
On Thu, Jul 1, 2010 at 6:27 PM, Kris Jurka <books@ejurka.com> wrote:
On Tue, 22 Jun 2010, S K wrote:
Our application has been in production for a couple of years. Recent
investigation into a problem revealed the following error started a few
months back. I restarted the application, but the error appears after a few
days and the thread dies.Caused by: java.lang.NegativeArraySizeExceptionatorg.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.j
at org.postgresql.core.PGStream.ReceiveTupleV3(PGStream.java:349)
ava:1306)
atorg.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192
)
atorg.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.
java:451)
atorg.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2S
tatement.java:350)
atorg.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2State
ment.java:254)
I haven't seen an error like this before. It most likely indicates that the driver has lost protocol sync with the server and is reading the wrong part of the message. This is difficult to debug because it's unknown how far back synchronization was lost. To try to debug this I would modify the driver to log the negative array size value and as much of the message parts I could find around it. That may give some clues as to why the driver is confused. Additionally, I would try to determine the triggering query and see if I could reproduce it.
Kris Jurka
--
---
Please DO NOT add my email to any marketing/communication/distribution lists or social networking sites, without my explicit permission to do so.