View Issue Details

IDProjectCategoryView StatusLast Update
0003762SymmetricDSBugpublic2018-11-07 00:51
Reporterwoehrl01Assigned Tojosh-a-hicks 
Prioritynormal 
Status assignedResolutionreopened 
Product Version3.9.14 
Target VersionFixed in Version3.9.15 
Summary0003762: Bulk loader fallback to default loader and fails will mark batch ok on source when it did not load the batch.
DescriptionSince the introduction we experience missing rows on a fresh initial load (reproducable).

If we enable debug mode we see that it fails at DataLoaderService.java:1045

Solution is to revert the code in BulkdDataLoaderFactory to Fallback to the DefaultDataLoaderFactory
Steps To Reproduce1. Create a channel bulk channel
2. Start an initial_load
3. The entry in the sym_node_security doesn't get updated to initial_load_enabled = 0
Additional InformationUsing MSSQL Server on the Corp

Using Sqlite as Store

Activities

admin

2018-10-24 13:48

administrator   ~0001294

Sounds like Josh reproduced and fixed this one. You see incoming batches in error status while the outgoing status is okay. It's any bulk loader that falls back to the default loader and then still gets an error.

woehrl01

2018-10-26 06:48

reporter   ~0001298

After merging the latest changes, this still failes with the same error. Reverthing the BulkDataLoaderFactory to DefaultDataLoaderFactory is still required.

2018-10-26 10:24:33,930 INFO [mobil-SYMCLIENT] [ManageIncomingBatchListener] [mobil-symclient-dataloader-4] Bulk loading failed for this batch 4, falling back to default loading. (org.jumpmind.db.sql.UniqueKeyException: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_PRIMARYKEY] A PRIMARY KEY constraint failed (UNIQUE constraint failed: sym_node_security.node_id))
2018-10-26 10:24:33,931 INFO [mobil-SYMCLIENT] [DataLoaderService] [mobil-symclient-dataloader-4] Bulk loader failed : StackTraceKey.init [UniqueKeyException:3600483701]
org.jumpmind.db.sql.UniqueKeyException: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_PRIMARYKEY] A PRIMARY KEY constraint failed (UNIQUE constraint failed: sym_node_security.node_id)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:296)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291)
    at org.jumpmind.db.sql.JdbcSqlTransaction.flush(JdbcSqlTransaction.java:184)
    at org.jumpmind.db.sql.JdbcSqlTransaction.commit(JdbcSqlTransaction.java:117)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.commit(DefaultDatabaseWriter.java:159)
    at org.jumpmind.symmetric.io.data.writer.DynamicDefaultDatabaseWriter.commit(DynamicDefaultDatabaseWriter.java:128)
    at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.end(AbstractDatabaseWriter.java:514)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.end(DefaultDatabaseWriter.java:143)
    at org.jumpmind.symmetric.io.AbstractBulkDatabaseWriter.end(AbstractBulkDatabaseWriter.java:42)
    at org.jumpmind.symmetric.io.JdbcBatchBulkDatabaseWriter.end(JdbcBatchBulkDatabaseWriter.java:51)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.end(NestedDataWriter.java:72)
    at org.jumpmind.symmetric.model.ProcessInfoDataWriter.end(ProcessInfoDataWriter.java:77)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.end(NestedDataWriter.java:72)
    at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:137)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1039)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1016)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_PRIMARYKEY] A PRIMARY KEY constraint failed (UNIQUE constraint failed: sym_node_security.node_id)
    at org.sqlite.core.DB.newSQLException(DB.java:908)
    at org.sqlite.core.DB.newSQLException(DB.java:921)
    at org.sqlite.core.DB.throwex(DB.java:886)
    at org.sqlite.core.DB.executeBatch(DB.java:774)
    at org.sqlite.core.CorePreparedStatement.executeBatch(CorePreparedStatement.java:79)
    at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
    at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
    at org.jumpmind.db.sql.JdbcSqlTransaction.flush(JdbcSqlTransaction.java:175)
    ... 17 more
2018-10-26 10:24:33,937 INFO [mobil-SYMCLIENT] [IncomingBatchService] [mobil-symclient-dataloader-4] Retrying batch 0-4

josh-a-hicks

2018-10-26 12:50

developer   ~0001300

I put in a fix for this issue if you want to retry.

woehrl01

2018-10-26 12:54

reporter   ~0001301

Awesome! Will give you a feedback on Monday!

woehrl01

2018-10-29 03:41

reporter   ~0001302

Thanks Josh! With your fix, this is working flawless now. Thank your for the quick revision and great work!

woehrl01

2018-11-06 08:27

reporter   ~0001325

sorry, but I think I found another issue regarding the bulkloader:


2018-11-06 08:56:50,989 INFO [mobil-SYMCLIENT] [ManageIncomingBatchListener] [mobil-symclient-dataloader-32] Bulk loading failed for this batch 5641, falling back to default loading. (org.jumpmind.db.sql.UniqueKeyException: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_UNIQUE] A UNIQUE constraint failed (UNIQUE constraint failed: TABLE.COLUMN))
2018-11-06 08:56:50,989 INFO [mobil-SYMCLIENT] [DataLoaderService] [mobil-symclient-dataloader-32] Bulk loader failed : StackTraceKey.init [UniqueKeyException:2890802646]
org.jumpmind.db.sql.UniqueKeyException: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_UNIQUE] A UNIQUE constraint failed (UNIQUE constraint failed: TABLE.COLUMN)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:296)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291)
    at org.jumpmind.db.sql.JdbcSqlTransaction.flush(JdbcSqlTransaction.java:184)
    at org.jumpmind.db.sql.JdbcSqlTransaction.commit(JdbcSqlTransaction.java:117)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.commit(DefaultDatabaseWriter.java:159)
    at org.jumpmind.symmetric.io.data.writer.DynamicDefaultDatabaseWriter.commit(DynamicDefaultDatabaseWriter.java:128)
    at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.end(AbstractDatabaseWriter.java:514)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.end(DefaultDatabaseWriter.java:143)
    at org.jumpmind.symmetric.io.AbstractBulkDatabaseWriter.end(AbstractBulkDatabaseWriter.java:45)
    at org.jumpmind.symmetric.io.JdbcBatchBulkDatabaseWriter.end(JdbcBatchBulkDatabaseWriter.java:51)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.end(NestedDataWriter.java:72)
    at org.jumpmind.symmetric.model.ProcessInfoDataWriter.end(ProcessInfoDataWriter.java:77)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.end(NestedDataWriter.java:72)
    at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:137)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1039)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1016)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.sqlite.SQLiteException: [SQLITE_CONSTRAINT_UNIQUE] A UNIQUE constraint failed (UNIQUE constraint failed: TABLE.COLUMN)
    at org.sqlite.core.DB.newSQLException(DB.java:908)
    at org.sqlite.core.DB.newSQLException(DB.java:921)
    at org.sqlite.core.DB.throwex(DB.java:886)
    at org.sqlite.core.DB.executeBatch(DB.java:774)
    at org.sqlite.core.CorePreparedStatement.executeBatch(CorePreparedStatement.java:79)
    at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
    at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
    at org.jumpmind.db.sql.JdbcSqlTransaction.flush(JdbcSqlTransaction.java:175)
    ... 17 more
2018-11-06 08:56:50,991 INFO [mobil-SYMCLIENT] [IncomingBatchService] [mobil-symclient-dataloader-32] Retrying batch 0-5641
2018-11-06 08:56:50,999 INFO [mobil-SYMCLIENT] [DefaultDatabaseWriter] [mobil-symclient-dataloader-32] Failed to process insert event in batch 0-5641 on channel 'reload'.
Failed sql was: insert into [....]
Failed sql parameters: [....]
Failed sql parameters types: [....]
Failed sql state and code: null (0)
Failed row data was: [....]
 StackTraceKey.init [SqlException:5149692]
org.jumpmind.db.sql.SqlException: statement is not executing
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:302)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291)
    at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:466)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.execute(DefaultDatabaseWriter.java:922)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.insert(DefaultDatabaseWriter.java:205)
    at org.jumpmind.symmetric.io.JdbcBatchBulkDatabaseWriter.insert(JdbcBatchBulkDatabaseWriter.java:28)
    at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:191)
    at org.jumpmind.symmetric.io.AbstractBulkDatabaseWriter.writeDefault(AbstractBulkDatabaseWriter.java:56)
    at org.jumpmind.symmetric.io.AbstractBulkDatabaseWriter.write(AbstractBulkDatabaseWriter.java:36)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
    at org.jumpmind.symmetric.model.ProcessInfoDataWriter.write(ProcessInfoDataWriter.java:84)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
    at org.jumpmind.symmetric.io.data.writer.TransformWriter.write(TransformWriter.java:201)
    at org.jumpmind.symmetric.io.data.DataProcessor.forEachDataInTable(DataProcessor.java:213)
    at org.jumpmind.symmetric.io.data.DataProcessor.forEachTableInBatch(DataProcessor.java:177)
    at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:123)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1052)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1016)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: statement is not executing
    at org.sqlite.core.CoreStatement.checkOpen(CoreStatement.java:50)
    at org.sqlite.core.CorePreparedStatement.batch(CorePreparedStatement.java:117)
    at org.sqlite.jdbc3.JDBC3PreparedStatement.setString(JDBC3PreparedStatement.java:421)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135)
    at org.springframework.jdbc.core.StatementCreatorUtils.setValue(StatementCreatorUtils.java:346)
    at org.springframework.jdbc.core.StatementCreatorUtils.setParameterValueInternal(StatementCreatorUtils.java:241)
    at org.springframework.jdbc.core.StatementCreatorUtils.setParameterValue(StatementCreatorUtils.java:172)
    at org.jumpmind.db.platform.sqlite.SqliteJdbcSqlTemplate.setValues(SqliteJdbcSqlTemplate.java:119)
    at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:447)
    ... 19 more

Related Changesets

SymmetricDS: 3.9 1e690279

2018-10-24 13:45:11

josh-a-hicks

Details Diff
0003762: Jdbc Batch bulk data loader causes missing rows on initial load
0003762
mod - symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java Diff File

SymmetricDS: 3.9 bf744546

2018-10-26 12:48:41

josh-a-hicks

Details Diff
0003762: Bulk loader fallback to default loader and fails will mark
batch ok on source when it did not load the batch.

0003762
mod - symmetric-client/src/main/java/org/jumpmind/symmetric/io/AbstractBulkDatabaseWriter.java Diff File
mod - symmetric-client/src/main/java/org/jumpmind/symmetric/io/JdbcBatchBulkDatabaseWriter.java Diff File

Issue History

Date Modified Username Field Change
2018-10-18 09:03 woehrl01 New Issue
2018-10-24 13:46 josh-a-hicks Assigned To => josh-a-hicks
2018-10-24 13:46 josh-a-hicks Status new => resolved
2018-10-24 13:46 josh-a-hicks Resolution open => fixed
2018-10-24 13:46 josh-a-hicks Fixed in Version => 3.9.15
2018-10-24 13:48 admin Note Added: 0001294
2018-10-24 13:49 josh-a-hicks Summary Jdbc Batch bulk data loader causes missing rows on initial load => Bulk loader fallback to default loader and fails will mark batch ok on source when it did not load the batch.
2018-10-24 14:00 josh-a-hicks Changeset attached => SymmetricDS 3.9 1e690279
2018-10-26 06:48 woehrl01 Status resolved => feedback
2018-10-26 06:48 woehrl01 Resolution fixed => reopened
2018-10-26 06:48 woehrl01 Note Added: 0001298
2018-10-26 12:50 josh-a-hicks Note Added: 0001300
2018-10-26 12:54 woehrl01 Note Added: 0001301
2018-10-26 12:54 woehrl01 Status feedback => assigned
2018-10-26 13:00 josh-a-hicks Changeset attached => SymmetricDS 3.9 bf744546
2018-10-29 03:41 woehrl01 Note Added: 0001302
2018-11-06 08:27 woehrl01 Note Added: 0001325