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 "Stanimir Stamenkov (Jira)" <ji...@apache.org> on 2022/07/30 17:01:00 UTC

[jira] [Updated] (DERBY-7145) MERGE UPDATE failing: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored

     [ https://issues.apache.org/jira/browse/DERBY-7145?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Stanimir Stamenkov updated DERBY-7145:
--------------------------------------
    Environment: 
Windows 10, JDK 8, Derby 10.14.2.0;
Windows 10 , JDK 11, Derby 10.15.2.0;
Windows 10 , JDK 17, Derby 10.16.1.1.


  was:
Windows 10, JDK 8 ,Derby 10.14.2.0;
Windows 10 , JDK 11 ,Derby 10.15.2.0;
Windows 10 , JDK 17 ,Derby 10.16.1.1.



> MERGE UPDATE failing: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored
> -----------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: DERBY-7145
>                 URL: https://issues.apache.org/jira/browse/DERBY-7145
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.14.2.0, 10.15.2.0, 10.16.1.1
>         Environment: Windows 10, JDK 8, Derby 10.14.2.0;
> Windows 10 , JDK 11, Derby 10.15.2.0;
> Windows 10 , JDK 17, Derby 10.16.1.1.
>            Reporter: Stanimir Stamenkov
>            Priority: Major
>         Attachments: bug-demo3.zip
>
>
> _\[May be related to DERBY-7144.\]_
> [^bug-demo3.zip] – a revision of {{bug-demo2.zip}} in DERBY-7144.  Extract;  Copy the Derby JARs to a {{lib/}} subdirectory; Compile:
> {noformat}
> $ mkdir classes
> $ javac -d classes src/net/example/derby/*.java
> {noformat}
> Run to see the problem:
> {noformat}
> $ java -cp "classes;lib/*" net.example.derby.BugDemo -seed -merge -print
> {noformat}
> {noformat}
> Exception in thread "main" java.sql.SQLException: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:115)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:141)
> 	at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:252)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:431)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353)
> 	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2405)
> 	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:88)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1436)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1709)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeLargeUpdate(EmbedPreparedStatement.java:320)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:309)
> 	at net.example.derby.BugDemo.mergeData(BugDemo.java:125)
> 	at net.example.derby.BugDemo.run(BugDemo.java:254)
> 	at net.example.derby.BugDemo.main(BugDemo.java:224)
> Caused by: ERROR XSDA7: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored
> 	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory.java:170)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:75)
> 	... 13 more
> Caused by: java.io.EOFException
> 	at org.apache.derby.iapi.services.io.ArrayInputStream.readLong(ArrayInputStream.java:323)
> 	at org.apache.derby.iapi.types.SQLLongint.readExternal(SQLLongint.java:184)
> 	at org.apache.derby.iapi.types.DataType.readExternalFromArray(DataType.java:276)
> 	at org.apache.derby.impl.store.raw.data.StoredPage.readRecordFromArray(StoredPage.java:5676)
> 	at org.apache.derby.impl.store.raw.data.StoredPage.restoreRecordFromSlot(StoredPage.java:1514)
> 	at org.apache.derby.impl.store.raw.data.BasePage.fetchFromSlot(BasePage.java:450)
> 	at org.apache.derby.impl.store.raw.data.CachedPage.fetchFromSlot(CachedPage.java:53)
> 	at org.apache.derby.impl.store.access.conglomerate.GenericScanController.fetch(GenericScanController.java:1518)
> 	at org.apache.derby.impl.store.access.conglomerate.GenericScanController.fetch(GenericScanController.java:1487)
> 	at org.apache.derby.impl.sql.execute.TemporaryRowHolderResultSet.getNextRowCore(TemporaryRowHolderResultSet.java:499)
> 	at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:148)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.getNextRowCore(UpdateResultSet.java:670)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:656)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:272)
> 	at org.apache.derby.impl.sql.execute.MatchingClauseConstantAction.executeConstantAction(MatchingClauseConstantAction.java:183)
> 	at org.apache.derby.impl.sql.execute.MergeResultSet.open(MergeResultSet.java:124)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:472)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:351)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1344)
> 	... 6 more
> {noformat}
> or:
> {noformat:title=$ java -cp "classes;lib/*" net.example.derby.BugDemo -workaround2 -print}
> Exception in thread "main" java.sql.SQLException: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:115)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:141)
> 	at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:252)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:431)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353)
> 	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2405)
> 	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:88)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1436)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.execute(EmbedStatement.java:710)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeLargeUpdate(EmbedStatement.java:183)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeUpdate(EmbedStatement.java:172)
> 	at net.example.derby.BugDemo.mergeWorkaround2(BugDemo.java:215)
> 	at net.example.derby.BugDemo.run(BugDemo.java:258)
> 	at net.example.derby.BugDemo.main(BugDemo.java:224)
> 	Suppressed: java.sql.SQLException: Cannot close a connection while a transaction is still active.
> 		at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:115)
> 		at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:141)
> 		at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:225)
> 		at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:220)
> 		at org.apache.derby.impl.jdbc.EmbedConnection.newSQLException(EmbedConnection.java:3215)
> 		at org.apache.derby.impl.jdbc.EmbedConnection.checkForTransactionInProgress(EmbedConnection.java:2009)
> 		at org.apache.derby.impl.jdbc.EmbedConnection.close(EmbedConnection.java:1990)
> 		at net.example.derby.BugDemo.mergeWorkaround2(BugDemo.java:219)
> 		... 2 more
> 	Caused by: ERROR 25001: Cannot close a connection while a transaction is still active.
> 		at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
> 		at org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory.java:170)
> 		at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:75)
> 		... 9 more
> Caused by: ERROR XSDA7: Restore of a serializable or SQLData object of class , attempted to read more data than was originally stored
> 	at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:290)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory.java:170)
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:75)
> 	... 13 more
> Caused by: java.io.EOFException
> 	at org.apache.derby.iapi.services.io.ArrayInputStream.readLong(ArrayInputStream.java:323)
> 	at org.apache.derby.iapi.types.SQLLongint.readExternal(SQLLongint.java:184)
> 	at org.apache.derby.iapi.types.DataType.readExternalFromArray(DataType.java:276)
> 	at org.apache.derby.impl.store.raw.data.StoredPage.readRecordFromArray(StoredPage.java:5676)
> 	at org.apache.derby.impl.store.raw.data.StoredPage.restoreRecordFromSlot(StoredPage.java:1514)
> 	at org.apache.derby.impl.store.raw.data.BasePage.fetchFromSlot(BasePage.java:450)
> 	at org.apache.derby.impl.store.raw.data.CachedPage.fetchFromSlot(CachedPage.java:53)
> 	at org.apache.derby.impl.store.access.conglomerate.GenericScanController.fetch(GenericScanController.java:1518)
> 	at org.apache.derby.impl.store.access.conglomerate.GenericScanController.fetch(GenericScanController.java:1487)
> 	at org.apache.derby.impl.sql.execute.TemporaryRowHolderResultSet.getNextRowCore(TemporaryRowHolderResultSet.java:499)
> 	at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:148)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.getNextRowCore(UpdateResultSet.java:670)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:656)
> 	at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:272)
> 	at org.apache.derby.impl.sql.execute.MatchingClauseConstantAction.executeConstantAction(MatchingClauseConstantAction.java:183)
> 	at org.apache.derby.impl.sql.execute.MergeResultSet.open(MergeResultSet.java:124)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:472)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:351)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1344)
> 	... 6 more
> {noformat}
> The crashes and corrupted/wrong results vary depending on the option combination, so be sure to try all of:
> {noformat}
> -seed -merge -print
> -seed -workaround -print
> -seed -workaround2 -print
> -seed 2 -merge -print
> -seed 2 -workaround -print
> -seed 2 -workaround2 -print
> -merge -print
> -workaround -print
> -workaround2 -print
> {noformat}
> They also appear to vary depending on the exact declaration of this column ({{sqlStatements.properties}}):
> {code:sql}
>   TMP       BIGINT    DEFAULT 1 NOT NULL,
>   TMP       INTEGER   DEFAULT 1 NOT NULL,
>   TMP       SMALLINT  DEFAULT 1 NOT NULL,
> {code}
> With the last definition, I observe no crashes with the given demo (while I observe the crashes in a more complicated production setup), but I notice a manifestation of the magic number 5 from DERBY-7144 with corrupted results (_note the zeroes in the last column starting from row 6 and below_):
> {noformat:title=(Actual)$ java -cp "classes;lib/*" net.example.derby.BugDemo -seed -merge -print}
> ID,     CATEGORY,       VALUE,  ATTIME, AGGDATE,        AGGCOUNT,       TMP
> 1,      2,      246.68, 2022-07-30 10:40:29.701,        2022-07-30,     6,      2
> 2,      1,      157.8,  2022-07-30 10:40:29.701,        2022-07-30,     4,      2
> 3,      3,      2.4,    2022-07-30 10:40:29.701,        2022-07-30,     2,      2
> 4,      4,      11.2,   2022-07-30 10:40:29.701,        2022-07-30,     2,      2
> 5,      2,      13.56,  2022-07-29 11:24:21.336,        2022-07-29,     2,      2
> 6,      1,      91.34,  2022-07-29 11:24:21.336,        2022-07-29,     6,      0
> 7,      4,      74.3,   2022-07-29 11:24:21.336,        2022-07-29,     6,      0
> 8,      2,      246.68, 2022-07-31 11:38:24.66, 2022-07-31,     6,      0
> 9,      1,      157.8,  2022-07-31 11:38:24.66, 2022-07-31,     4,      0
> 10,     3,      2.4,    2022-07-31 11:38:24.66, 2022-07-31,     2,      0
> 11,     4,      11.2,   2022-07-31 11:38:24.66, 2022-07-31,     2,      0
>         rows: 11
> {noformat}
> {noformat:title=(Expected)$ java -cp "classes;lib/*" net.example.derby.BugDemo -seed -workaround -print}
> ID,     CATEGORY,       VALUE,  ATTIME, AGGDATE,        AGGCOUNT,       TMP
> 1,      2,      246.68, 2022-07-30 10:40:29.701,        2022-07-30,     6,      2
> 2,      1,      157.8,  2022-07-30 10:40:29.701,        2022-07-30,     4,      2
> 3,      3,      2.4,    2022-07-30 10:40:29.701,        2022-07-30,     2,      2
> 4,      4,      11.2,   2022-07-30 10:40:29.701,        2022-07-30,     2,      2
> 5,      2,      13.56,  2022-07-29 11:24:21.336,        2022-07-29,     2,      2
> 6,      1,      91.34,  2022-07-29 11:24:21.336,        2022-07-29,     6,      2
> 7,      4,      74.3,   2022-07-29 11:24:21.336,        2022-07-29,     6,      2
> 8,      2,      246.68, 2022-07-31 11:38:24.66, 2022-07-31,     6,      2
> 9,      1,      157.8,  2022-07-31 11:38:24.66, 2022-07-31,     4,      2
> 10,     3,      2.4,    2022-07-31 11:38:24.66, 2022-07-31,     2,      2
> 11,     4,      11.2,   2022-07-31 11:38:24.66, 2022-07-31,     2,      2
>         rows: 11
> {noformat}
> Then with no {{-seed}}:
> {noformat:title=(Actual)$ java -cp "classes;lib/*" net.example.derby.BugDemo -merge -print}
> ID,     CATEGORY,       VALUE,  ATTIME, AGGDATE,        AGGCOUNT,       TMP
>         rows: 0
> {noformat}
> {noformat:title=(Expected)$ java -cp "classes;lib/*" net.example.derby.BugDemo -workaround -print}
> ID,     CATEGORY,       VALUE,  ATTIME, AGGDATE,        AGGCOUNT,       TMP
> 1,      2,      123.34, 2022-07-30 10:40:29.701,        2022-07-30,     3,      1
> 2,      1,      78.9,   2022-07-30 10:40:29.701,        2022-07-30,     2,      1
> 3,      3,      1.2,    2022-07-30 10:40:29.701,        2022-07-30,     1,      1
> 4,      4,      5.6,    2022-07-30 10:40:29.701,        2022-07-30,     1,      1
> 5,      2,      6.78,   2022-07-29 11:24:21.336,        2022-07-29,     1,      1
> 6,      1,      45.67,  2022-07-29 11:24:21.336,        2022-07-29,     3,      1
> 7,      4,      37.15,  2022-07-29 11:24:21.336,        2022-07-29,     3,      1
> 8,      2,      123.34, 2022-07-31 11:38:24.66, 2022-07-31,     3,      1
> 9,      1,      78.9,   2022-07-31 11:38:24.66, 2022-07-31,     2,      1
> 10,     3,      1.2,    2022-07-31 11:38:24.66, 2022-07-31,     1,      1
> 11,     4,      5.6,    2022-07-31 11:38:24.66, 2022-07-31,     1,      1
>         rows: 11
> {noformat}
> The {{-workaround}} (but not {{-workaround2}}) option appears to be the only one that yields no crashes and correct results in all cases.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)