View Issue Details

Related ChangesetsJump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0005375SymmetricDSBugpublic2022-07-22 07:042022-08-30 13:03
Reporterkraynopp Assigned Toemiller  
Priorityhigh 
Status closedResolutionfixed 
Product Version3.13.5 
Target Version3.13.7Fixed in Version3.13.7 
Summary0005375: Entire batch is ignored in PostgreSQL in case of error
DescriptionIn case of any error during loading I see following in log file:

ERROR: current transaction is aborted, commands ignored until end of transaction block

for all rows after erroneous row. So this transaction is rolled back and all rows in this batch (even first successfully loaded rows) will be lost.

I have error load filter such as Example 23 but returns false.
Tagsdialect: postgresql

Activities

elong

2022-07-27 17:44

developer   ~0002113

When you return false from a load filter, it will not load the row. It sounds like it's working as designed. Return true to ensure that the row is attempted to load.

kraynopp

2022-08-01 12:53

reporter   ~0002122

Yes, load filter returns false, this row wiil not be loaded again. But attempt to load erroneous row has been made. Now entire transaction is invalid. Any attempt to process remaining rows of batch will cause "ERROR: current transaction is aborted, commands ignored until end of transaction block". So this transaction will not be commited. It is a PostgreSQL feature and such behavior can not be changed unfortunately...

I suppose in case of error the transaction should be rolled back and batch should be loaded again with exception of erroneous row(s).

kraynopp

2022-08-01 12:58

reporter   ~0002123

Maybe creating savepoints before every operation of batch will be useful...

kraynopp

2022-08-03 08:24

reporter   ~0002139

I have made simple testcase for symmetric 3.14

Source table (oracle):
CREATE TABLE "DATA"."SYMERRTEST"
(
    "ID" NUMBER(10,0) NOT NULL ENABLE,
    "DATA" VARCHAR2(20 BYTE),
     CONSTRAINT "SYMERRTEST_PK" PRIMARY KEY ("ID")
)

Target table(PostgreSQL):
CREATE TABLE IF NOT EXISTS data.symerrtest
(
    id numeric(10,0) NOT NULL,
    data character varying(10) COLLATE pg_catalog."default",
    CONSTRAINT symerrtest_pkey PRIMARY KEY (id)
        USING INDEX TABLESPACE ksu_tablespace
);

Field "data" in target table much smaller than in source table in order to make failure.

Initial data:
id=1, data='q'
id=2, data='w'
id=3, data='e'

Execute script in source database:
begin
    update data.symerrtest set data='qqqqq' where id=1;
    update data.symerrtest set data='wwwwwwwwwwwwwww' where id=2;
    update data.symerrtest set data='eeeee' where id=3;
    commit;
end;

First and last rows are normal and should be loaded. Second row is erroneous.
Execution of script is successful, all rows are updated in source table.

Resulting batch:
nodeid,001
binary,BASE64
channel,dev-main-channel
batch,563
catalog,
schema,data
table,symerrtest
keys,ID
columns,ID,DATA
basetime,1659513698700
old,"1","q"
update,"1","qqqqq","1"
ts,2
old,"2","w"
update,"2","wwwwwwwwwwwwwww","2"
ts,3
old,"3","e"
update,"3","eeeee","3"
commit,563

No rows has been updated in target table. All rows remained intact in initial state:
id=1, data='q'
id=2, data='w'
id=3, data='e'

SymmetricDS log of target database:
2022-08-03 11:01:21,752 INFO [pgsql-000] [ConfigurationChangedHelper] [pgsql-000-dataloader-19] Clearing cache for load filters
2022-08-03 11:01:21,767 INFO [pgsql-000] [DataLoaderService] [qtp940857381-17] 2 data and 1 batches loaded during push request from oracle:001:001
2022-08-03 11:01:40,626 INFO [pgsql-000] [RouterService] [pgsql-000-job-19] Routed 2 data events in 57 ms
2022-08-03 11:02:21,715 INFO [pgsql-000] [DefaultDatabaseWriter] [pgsql-000-dataloader-20] Failed to process update event in batch 001-563 on channel 'dev-main-channel'.
Failed sql was: update "data"."symerrtest" set "data" = 'wwwwwwwwwwwwwww' where "data" = 'w' and "id" = 2
Failed raw sql was: update "data"."symerrtest" set "data" = ? where "data" = ? and "id" = ?
Failed sql parameters: ['wwwwwwwwwwwwwww', 'w', 2]
Failed sql parameters types: [VARCHAR, VARCHAR, NUMERIC]
Failed sql state and code: 22001 (0)
Failed truncation column: data with size of: 10 failed to load data: wwwwwwwwwwwwwww
Failed pk data was: "2"
Failed row data was: "2","wwwwwwwwwwwwwww"
Failed old data was: "2","w"
 StackTraceKey [DataTruncationException:2462517055]
2022-08-03 11:02:21,730 INFO [pgsql-000] [DefaultDatabaseWriter] [pgsql-000-dataloader-20] Failed to process update event in batch 001-563 on channel 'dev-main-channel'.
Failed sql was: update "data"."symerrtest" set "data" = 'eeeee' where "data" = 'e' and "id" = 3
Failed raw sql was: update "data"."symerrtest" set "data" = ? where "data" = ? and "id" = ?
Failed sql parameters: ['eeeee', 'e', 3]
Failed sql parameters types: [VARCHAR, VARCHAR, NUMERIC]
Failed sql state and code: 25P02 (0)
Failed pk data was: "3"
Failed row data was: "3","eeeee"
Failed old data was: "3","e"
 StackTraceKey.init [SqlException:780865428] org.jumpmind.db.sql.SqlException: ERROR: current transaction is aborted, commands ignored until end of transaction block
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:308)
    at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:297)
    at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:443)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.execute(DefaultDatabaseWriter.java:1026)
    at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.update(DefaultDatabaseWriter.java:558)
    at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:166)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:62)
    at org.jumpmind.symmetric.model.ProcessInfoDataWriter.write(ProcessInfoDataWriter.java:84)
    at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:62)
    at org.jumpmind.symmetric.io.data.writer.TransformWriter.write(TransformWriter.java:190)
    at org.jumpmind.symmetric.io.data.DataProcessor.forEachDataInTable(DataProcessor.java:194)
    at org.jumpmind.symmetric.io.data.DataProcessor.forEachTableInBatch(DataProcessor.java:160)
    at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:108)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1043)
    at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1021)
    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.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block
    at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:355)
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:490)
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:408)
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:166)
    at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:134)
    at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:136)
    at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:136)
    at org.jumpmind.db.sql.JdbcSqlTransaction.executePreparedUpdate(JdbcSqlTransaction.java:462)
    at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:440)
    ... 16 more
Caused by: org.postgresql.util.PSQLException: ERROR: value too long for type character varying(10)
    ... 27 more

2022-08-03 11:02:21,741 INFO [pgsql-000] [ManageIncomingBatchListener] [pgsql-000-dataloader-20] Ignoring batch 001-563
2022-08-03 11:02:21,756 INFO [pgsql-000] [DataLoaderService] [qtp940857381-11] 3 data and 1 batches loaded during push request from oracle:001:001

Related Changesets

SymmetricDS: 3.13 d3456f0a

2022-08-03 19:47:47

evan-miller-jumpmind

Details Diff 		0005375: Fixed how handleError() load filter method is handled for Postgres Affected Issues
0005375
mod - symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/AbstractDatabaseWriter.java Diff File

SymmetricDS: 3.14 094d67ab

2022-08-03 19:52:13

evan-miller-jumpmind

Details Diff 		0005375: Fixed how handleError() load filter method is handled for Postgres Affected Issues
0005375
mod - symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/AbstractDatabaseWriter.java Diff File

Issue History

Date Modified Username Field Change
2022-07-22 07:04 kraynopp New Issue
2022-07-22 07:04 kraynopp Tag Attached: dialect: postgresql
2022-07-27 17:44 elong Note Added: 0002113
2022-07-27 17:44 elong Status new => feedback
2022-08-01 12:53 kraynopp Note Added: 0002122
2022-08-01 12:53 kraynopp Status feedback => new
2022-08-01 12:58 kraynopp Note Added: 0002123
2022-08-03 08:24 kraynopp Note Added: 0002139
2022-08-03 19:48 emiller Assigned To => emiller
2022-08-03 19:48 emiller Status new => resolved
2022-08-03 19:48 emiller Resolution open => fixed
2022-08-03 19:48 emiller Fixed in Version => 3.13.7
2022-08-03 20:00 Changeset attached => SymmetricDS 3.13 d3456f0a
2022-08-03 20:00 Changeset attached => SymmetricDS 3.14 094d67ab
2022-08-04 18:44 elong Target Version => 3.13.7
2022-08-30 13:03 admin Status resolved => closed