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

XML

Word

Printable

JSON

Details

Type: Bug
Status: Open
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.14.2.0, 10.15.2.0, 10.16.1.1, 10.17.1.0
Fix Version/s: None
Component/s: SQL
Labels:
None
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.

Urgency:
Normal
Bug behavior facts:

Seen in production, Wrong query result

Description

[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:

$ mkdir classes
$ javac -d classes src/net/example/derby/*.java

Run to see the problem:

$ java -cp "classes;lib/*" net.example.derby.BugDemo -seed -merge -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.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

or:

$ 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

The crashes and corrupted/wrong results vary depending on the option combination, so be sure to try all of:

-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

They also appear to vary depending on the exact declaration of this column (sqlStatements.properties):

  TMP       BIGINT    DEFAULT 1 NOT NULL,

  TMP       INTEGER   DEFAULT 1 NOT NULL,

  TMP       SMALLINT  DEFAULT 1 NOT NULL,

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):

(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

(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

Then with no -seed:

(Actual)$ java -cp "classes;lib/*" net.example.derby.BugDemo -merge -print

ID,     CATEGORY,       VALUE,  ATTIME, AGGDATE,        AGGCOUNT,       TMP
        rows: 0

(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

The -workaround (but not -workaround2) option appears to be the only one that yields no crashes and correct results in all cases.

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending

bug-demo3.zip
30/Jul/22 17:33
5 kB
Stanimir Stamenkov
derby.log
01/Aug/22 19:31
38 kB
Stanimir Stamenkov
derby2.log
01/Aug/22 19:46
40 kB
Stanimir Stamenkov
sysinfo.txt
01/Aug/22 19:31
2 kB
Stanimir Stamenkov

Issue Links

relates to

DERBY-7144 MERGE INSERT failing when target has GENERATED IDENTITY column

Closed

Activity

People

Assignee:: Unassigned

Reporter:: Stanimir Stamenkov

Votes:: 0 Vote for this issue

Watchers:: 3 Start watching this issue

Dates

Created:: 30/Jul/22 16:42

Updated:: 12/Oct/22 10:16