View Issue Details

IDProjectCategoryView StatusLast Update
0005358SymmetricDSBugpublic2022-07-25 16:52
Reporterpmarzullo Assigned Topmarzullo  
Prioritynormal 
Status assignedResolutionopen 
Product Version3.12.5 
Target Version3.14.1 
Summary0005358: Row not found when previously inserted
DescriptionI have an issue in dev (3.12.4) that is not happening in prod (3.9.13). Essentially, the insert in cli_bkdn_psn at the bottom of the log is failing because a row is not found in cli_bkdn (the check is done in a trigger, code listed at the bottom for reference) but as you can see, the row is inserted as shown at the beginning of the log snippet.

 

It looks like the two inserts are run in separate connections, and therefore the lookup in the second insert can’t see the data from the first insert.

 

Was something changed in the new version that would impact this behavior?

 

 

2020-11-17 16:07:47,752 INFO [EDB_SYBASE-EDB_SYB] [IncomingBatchService] [edb_sybase-edb_syb-dataloader-90] Retrying batch MF_PG-948128

2020-11-17 16:07:47,789 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Preparing dml: update orgd1_organization.dbo.cli_bkdn set corp_cd = ?, cli_no = ?, bkdn_nm = ?, bkdn_sta = ?, ver_svc_ind = ?, auto_svc_only_ind = ?, bkdn_stat_dt = ?, to_dt = ? where org_id = ? and bkdn_typ_cd = ? and bkdn = ? and frm_dt = ?

2020-11-17 16:07:47,790 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Submitting data ['FA', '17710', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, 465235, 'BLG ', '025033-000000-002051-0SALES', null] with types [CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, INTEGER, CHAR, VARCHAR, TIMESTAMP]

2020-11-17 16:07:47,796 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values (?,?,?,?,?,?,?,?,?,?,?,?)

2020-11-17 16:07:47,797 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Submitting data [465235, 'BLG ', '025033-000000-002051-0SALES', 'FA', '17710', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, {ts '2020-11-17 15:49:20.766'}] with types [INTEGER, CHAR, VARCHAR, CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, TIMESTAMP]

[***** … rows deleted; see log file if needed… ****]

2020-11-17 16:07:47,911 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)

2020-11-17 16:07:47,912 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Submitting data [21569799, 465235, 'BLG ', '025033-000000-002051-0SALES', 'AE ', {ts '2020-11-17 15:49:20.766'}, null] with types [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]

2020-11-17 16:07:47,913 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-90] Failed to process insert event in batch MF_PG-948128 on channel 'MF_PG_CLI'.

Failed sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (21569799,465235,'BLG ','025033-000000-002051-0SALES','AE ',{ts '2020-11-17 15:49:20.766'},null)

Failed raw sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)

Failed sql parameters: [21569799, 465235, 'BLG ', '025033-000000-002051-0SALES', 'AE ', {ts '2020-11-17 15:49:20.766'}, null]

Failed sql parameters types: [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]

Failed sql state and code: null (30156)

Failed row data was: "21569799","465235","BLG","025033-000000-002051-0SALES","AE","2020-11-17 15:49:20.766",,

StackTraceKey [SqlException:3994122867]

2020-11-17 16:07:47,927 ERROR [EDB_SYBASE-EDB_SYB] [ManageIncomingBatchListener] [edb_sybase-edb_syb-dataloader-90] Failed to load batch MF_PG-948128 StackTraceKey [SqlException:3994122867]

2020-11-17 16:07:47,947 ERROR [MF_POSTGRES-MF_PG] [AcknowledgeService] [mf_postgres-mf_pg-push-MF_PG_ASSET_Q-9] The outgoing batch EDB_SYB-948128 failed: [null,30156] Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: 465235 with {bkdn_typ_cd}: BLG for {bkdn}: 025033-000000-002051-0SALES does not exist in "cli_bkdn".

 

 

TRIGGER CODE:

    select @nullcnt = 0

    select @validcnt = count(*)

      from inserted,cli_bkdn

        where

              inserted.org_id = cli_bkdn.org_id and

              inserted.bkdn_typ_cd = cli_bkdn.bkdn_typ_cd and

              inserted.bkdn = cli_bkdn.bkdn and

              cli_bkdn.to_dt = null

 

    if @validcnt + @nullcnt != @numrows

    begin

    /* Start_PHH_trigger_error_message*/

     select @errno = 30156

    /* exec sp_addmessage 30156, 'Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: %1! with {bkdn_typ_cd}: %2! for {bkdn}: %3 does not exist in "cli_bkdn". '*/

    /* End_PHH_trigger_error_message*/

    goto error_cli_bkdn_001

    end
Additional InformationOne configuration that I am questioning is the "PGMF cli_bkdn EDB cli_bkdn load" transform that occurs on the load side.
The column "frm_dt" is marked as a primary key.
When the update statement is attempted, the fourth column in the where clause becomes "and frm_dt = null" because there is no value found in the lookup transform.

Also, can you execute the query on the target side and show the result set?
select * from orgd1_organization.dbo.cli_bkdn where org_id = 465235 and bkdn_typ_cd = 'BLG ' and bkdn = '025033-000000-002051-0SALES';

And, there were more changes in the conflict resolution functionality in 3.12.5, right around where the issue that you are referring to occurred. When SymmetricDS was loading the batch for the cli_bkdn table, it attempted an UPDATE statement first with a where clause of "where org_id = 465235 and bkdn_typ_cd = 'BLG ' and bkdn = '025033-000000-002051-0SALES' and frm_dt = null", and because the update did not update anything, it executed an insert statement using the conflict resolution functionality that was changed in 3.12.5.

It looks like the code change in 3.12.5 may fix this issue.
Tagsdialect: postgresql, dialect: sybase

Activities

pmarzullo

2022-07-11 17:12

developer  

pmarzullo

2022-07-11 17:14

developer   ~0002098

We upgraded to 3.12.5 but it did not fix the issue.

I change the transformation to remove the "update First" flag on the " PGMF cli_bkdn EDB cli_bkdn load" but it still does not work. It looks like the insert in cli_bkdn_psn is using a different connection from the one used for the insert into cli_bkdn. Is it possible?

2020-11-19 12:06:56,159 INFO [EDB_SYBASE-EDB_SYB] [IncomingBatchService] [edb_sybase-edb_syb-dataloader-514] Retrying batch MF_PG-948184
2020-11-19 12:06:56,161 INFO [MF_POSTGRES-MF_PG] [PushService] [mf_postgres-mf_pg-push-MF_PG_ASSET_Q-9] Push data sent to EDB_SYBASE:EDB_SYB:EDB_SYB
2020-11-19 12:06:56,176 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values (?,?,?,?,?,?,?,?,?,?,?,?)
2020-11-19 12:06:56,177 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [465258, 'BLG ', '025262-000000-001759-0SALES', 'FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, {ts '2020-11-19 11:57:06.270'}] with types [INTEGER, CHAR, VARCHAR, CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, TIMESTAMP]
2020-11-19 12:06:56,210 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-19 12:06:56,211 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-19 12:06:56,212 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-514] Unique violation from index psn_i01 on table psn during INSERT with batch MF_PG-948184. Attempting to correct.
2020-11-19 12:06:56,221 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-19 12:06:56,222 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-19 12:06:56,231 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: update psnd1_person.dbo.psn set psn_frst_nm = ?, psn_lst_nm = ? where psn_id = ?
2020-11-19 12:06:56,232 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data ['SCOTT ', 'NICOLAUS ', 21569799] with types [CHAR, CHAR, INTEGER]
2020-11-19 12:06:56,234 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-19 12:06:56,235 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799] with types [INTEGER]
2020-11-19 12:06:56,236 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-514] Unique violation from index phh_emp_i01 on table phh_emp during INSERT with batch MF_PG-948184. Attempting to correct.
2020-11-19 12:06:56,238 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-19 12:06:56,238 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799] with types [INTEGER]
2020-11-19 12:06:56,243 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-19 12:06:56,244 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-19 12:06:56,244 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-514] Unique violation from index psn_psn_typ_i01 on table psn_psn_typ during INSERT with batch MF_PG-948184. Attempting to correct.
2020-11-19 12:06:56,246 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-19 12:06:56,248 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-19 12:06:56,250 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-19 12:06:56,251 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-19 12:06:56,252 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-514] Unique violation from index phh_emp_xref_i01 on table phh_emp_xref during INSERT with batch MF_PG-948184. Attempting to correct.
2020-11-19 12:06:56,254 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-19 12:06:56,255 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-19 12:06:56,256 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
2020-11-19 12:06:56,257 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Submitting data [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-19 11:57:06.270'}, null] with types [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
2020-11-19 12:06:56,259 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-514] Failed to process insert event in batch MF_PG-948184 on channel 'MF_PG_CLI'.
Failed sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (21569799,465258,'BLG ','025262-000000-001759-0SALES','AE ',{ts '2020-11-19 11:57:06.270'},null)
Failed raw sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
Failed sql parameters: [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-19 11:57:06.270'}, null]
Failed sql parameters types: [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
Failed sql state and code: null (30156)
Failed row data was: "21569799","465258","BLG","025262-000000-001759-0SALES","AE","2020-11-19 11:57:06.270",,
 StackTraceKey [SqlException:4084838048]
2020-11-19 12:06:56,272 ERROR [EDB_SYBASE-EDB_SYB] [ManageIncomingBatchListener] [edb_sybase-edb_syb-dataloader-514] Failed to load batch MF_PG-948184 StackTraceKey [SqlException:4084838048]
2020-11-19 12:06:56,292 ERROR [MF_POSTGRES-MF_PG] [AcknowledgeService] [mf_postgres-mf_pg-push-MF_PG_ASSET_Q-9] The outgoing batch EDB_SYB-948184 failed: [null,30156] Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: 465258 with {bkdn_typ_cd}: BLG for {bkdn}: 025262-000000-001759-0SALES does not exist in "cli_bkdn".

pmarzullo

2022-07-11 17:15

developer   ~0002099

2020-11-20 14:29:28,241 INFO [MF_POSTGRES-MF_PG] [PushService] [mf_postgres-mf_pg-push-MF_PG_Q-7] Push data sent to EDB_SYBASE:EDB_SYB:EDB_SYB
2020-11-20 14:29:28,259 INFO [EDB_SYBASE-EDB_SYB] [IncomingBatchService] [edb_sybase-edb_syb-dataloader-53] Retrying batch MF_PG-955478
2020-11-20 14:29:28,287 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: update orgd1_organization.dbo.cli_bkdn set corp_cd = ?, cli_no = ?, bkdn_nm = ?, bkdn_sta = ?, ver_svc_ind = ?, auto_svc_only_ind = ?, bkdn_stat_dt = ?, to_dt = ? where org_id = ? and bkdn_typ_cd = ? and bkdn = ? and frm_dt = ?
2020-11-20 14:29:28,289 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data ['FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, 465258, 'BLG ', '025262-000000-001759-0SALES', null] with types [CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, INTEGER, CHAR, VARCHAR, TIMESTAMP]
2020-11-20 14:29:28,289 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,291 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values (?,?,?,?,?,?,?,?,?,?,?,?)
2020-11-20 14:29:28,293 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [465258, 'BLG ', '025262-000000-001759-0SALES', 'FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, {ts '2020-11-20 14:28:18.866'}] with types [INTEGER, CHAR, VARCHAR, CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, TIMESTAMP]
2020-11-20 14:29:28,293 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,333 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-20 14:29:28,334 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-20 14:29:28,334 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,335 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-53] Unique violation from index psn_i01 on table psn during INSERT with batch MF_PG-955478. Attempting to correct.
2020-11-20 14:29:28,347 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-20 14:29:28,349 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-20 14:29:28,349 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,360 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: update psnd1_person.dbo.psn set psn_frst_nm = ?, psn_lst_nm = ? where psn_id = ?
2020-11-20 14:29:28,362 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data ['SCOTT ', 'NICOLAUS ', 21569799] with types [CHAR, CHAR, INTEGER]
2020-11-20 14:29:28,362 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,364 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-20 14:29:28,365 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799] with types [INTEGER]
2020-11-20 14:29:28,365 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,366 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-53] Unique violation from index phh_emp_i01 on table phh_emp during INSERT with batch MF_PG-955478. Attempting to correct.
2020-11-20 14:29:28,368 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-20 14:29:28,369 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799] with types [INTEGER]
2020-11-20 14:29:28,369 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,375 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-20 14:29:28,376 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-20 14:29:28,376 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,377 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-53] Unique violation from index psn_psn_typ_i01 on table psn_psn_typ during INSERT with batch MF_PG-955478. Attempting to correct.
2020-11-20 14:29:28,380 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-20 14:29:28,381 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-20 14:29:28,381 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,382 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-20 14:29:28,383 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-20 14:29:28,383 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,384 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-53] Unique violation from index phh_emp_xref_i01 on table phh_emp_xref during INSERT with batch MF_PG-955478. Attempting to correct.
2020-11-20 14:29:28,387 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-20 14:29:28,388 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-20 14:29:28,388 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,389 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
2020-11-20 14:29:28,391 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Submitting data [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-20 14:28:18.866'}, null] with types [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
2020-11-20 14:29:28,391 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Using connection [org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]
2020-11-20 14:29:28,393 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-53] Failed to process insert event in batch MF_PG-955478 on channel 'MF_PG_CLI'.
Failed sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (21569799,465258,'BLG ','025262-000000-001759-0SALES','AE ',{ts '2020-11-20 14:28:18.866'},null)
Failed raw sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
Failed sql parameters: [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-20 14:28:18.866'}, null]
Failed sql parameters types: [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
Failed sql state and code: null (30156)
Failed row data was: "21569799","465258","BLG","025262-000000-001759-0SALES","AE","2020-11-20 14:28:18.866",,
 StackTraceKey [SqlException:4078871201]
2020-11-20 14:29:28,410 ERROR [EDB_SYBASE-EDB_SYB] [ManageIncomingBatchListener] [edb_sybase-edb_syb-dataloader-53] Failed to load batch MF_PG-955478 StackTraceKey [SqlException:4078871201]
2020-11-20 14:29:28,432 ERROR [MF_POSTGRES-MF_PG] [AcknowledgeService] [mf_postgres-mf_pg-push-MF_PG_Q-7] The outgoing batch EDB_SYB-955478 failed: [null,30156] Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: 465258 with {bkdn_typ_cd}: BLG for {bkdn}: 025262-000000-001759-0SALES does not exist in "cli_bkdn".

pmarzullo

2022-07-11 17:16

developer   ~0002100

It is the same connection for each of those update/insert statements. The object ID for the connection is:
[org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper@167094e0]

and is the same for each statement.

One thing that I still see as odd is the very first update statement, that has a where clause of:
where org_id = ? and bkdn_typ_cd = ? and bkdn = ? and frm_dt = ?
with dynamic values of:
465258,'BLG ', '025262-000000-001759-0SALES', null

It still seems odd to me that the frm_dt column is included in the where clause, which is normally just primary key columns.
The reason that the frm_dt column is showing up there is that the cli_bkdn transform for the frm_dt column marks frm_dt as a primary key.
Is that correct?

pmarzullo

2022-07-11 17:16

developer   ~0002101

Yes it is. The target table creates a history of the changes on the row. The source does not have such a feature.

The primary key on the source is (corp_cd, client_no, bkdn).

The primary key on the target is (org_id, bkdn_typ_cd, bkdn, frm_dt). The corp_cd/cli_no always maps to the same org_id value and bkdn_typ_cd is hard-coded to BLG for the data from this source. So the key is essentially (corp_cd, cli_no, bkdn, frm_dt).

Here is an example of the data on th4e source compared to the target (not all columns are listed):

select corp_cd, client_no, bkdn, bkdn_nm_key from sysusr.cli_bkdn where corp_cd = 'FA' and client_no = '2536' and bkdn = '9600-8529'
corp_cd client_no bkdn bkdn_nm_key
---------- ------------ ------------------------------------------ --------------------
FA 2536 9600-8529 SELMA 8529

select org_id, bkdn_typ_cd, bkdn, frm_dt, to_dt, corp_cd, cli_no, bkdn_nm from cli_bkdn where org_id = 249086 and bkdn = '9600-8529' order by frm_dt
org_id bkdn_typ_cd bkdn frm_dt to_dt corp_cd cli_no bkdn_nm
--------- -------------- --------- --------------------------- --------------------------- ---------- --------- --------------
249086 BLG 9600-8529 2005-05-06 00:00:00.000 EDT 2020-04-09 12:40:59.656 EDT FA 2536 SELMA CA 8529
249086 BLG 9600-8529 2020-04-09 12:40:59.656 EDT 2020-04-10 12:35:34.570 EDT FA 2536 SELMA 8529
249086 BLG 9600-8529 2020-04-10 12:35:34.570 EDT 2020-04-13 11:25:28.803 EDT FA 2536 SELMA, CA 8529
249086 BLG 9600-8529 2020-04-13 11:25:28.803 EDT (null) FA 2536 SELMA 8529

If I run these two statements manually, they work just fine (see below).

The only reason to get this error is if the row does not exist in cli_bkdn. So, it seems the very first insert is not being run successfully (or at all). The other possibility I had in mind was a different connection was used but you disproved that. Is it possible to add a trace to print out something returned by the server on success (such as the number of rows affected for example)? Or maybe you have another idea!

insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values
(465235, 'BLG ', '025033-000000-002051-0SALES', 'FA', '17710', ' ', 'A', 0, 0, '2020-11-16 00:00:00.000', null, '2020-11-17 15:35:00.346')
insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values
(21569799,465235,'BLG ','025033-000000-002051-0SALES','AE','2020-11-17 15:29:50.183', null)
select * from cli_bkdn where org_id = 465235 and bkdn = '025033-000000-002051-0SALES' order by bkdn
select * from cli_bkdn_psn where org_id = 465235 and bkdn = '025033-000000-002051-0SALES' order by bkdn
org_id bkdn_typ_cd bkdn frm_dt to_dt corp_cd cli_no bkdn_nm bkdn_sta fas_ind ver_svc_ind auto_svc_only_ind bkdn_stat_dt
--------- -------------- --------------------------- --------------------------- -------- ---------- --------- ---------- ----------- ---------- -------------- -------------------- ---------------------------
465235 BLG 025033-000000-002051-0SALES 2020-11-17 15:35:00.346 EST (null) FA 17710 A N 0 0 2020-11-16 00:00:00.000 EST

 1 record(s) selected [Fetch MetaData: 0ms] [Fetch Data: 0ms]

 org_id bkdn_typ_cd bkdn psn_id role_typ_cd frm_dt to_dt
--------- -------------- --------------------------- --------- -------------- --------------------------- --------
465235 BLG 025033-000000-002051-0SALES 21569799 AE 2020-11-17 15:29:50.183 EST (null)

 1 record(s) selected [Fetch MetaData: 0ms] [Fetch Data: 0ms]

pmarzullo

2022-07-11 17:17

developer   ~0002102

Could the trigger text be incorrect?

The part that says "cli_bkdn.to_dt = null", should that say "cli_bkdn.to_dt is null"?

pmarzullo

2022-07-11 17:17

developer   ~0002103

This is Sybase syntax for 25 years ago. It means the same thing. We now use the ansi-sql syntax when writing code (or, at least, should) but we did not fix the old code (no reason to).

pmarzullo

2022-07-11 17:18

developer   ~0002104

Can you put in place the following patch? It has debug level output that indicates whether the insert, update, or delete affects any rows.

pmarzullo

2022-07-11 17:18

developer   ~0002105

Here is the log. I hope it helps. Is it possible one of the other errors ("Unique violation from index ...") is doing a rollback, removing the insert into cli_bkdn?

I dropped the cli_bkdn_psn_i_t trigger and, while the batch processed successfully, the row was not in the cli_bkdn table afterward either.

Thanks,

Charles

2020-11-30 17:55:01,797 INFO [MF_POSTGRES-MF_PG] [PushService] [mf_postgres-mf_pg-push-MF_PG_PSN_Q-8] Push data sent to EDB_SYBASE:EDB_SYB:EDB_SYB
2020-11-30 17:55:01,814 INFO [EDB_SYBASE-EDB_SYB] [IncomingBatchService] [edb_sybase-edb_syb-dataloader-393] Retrying batch MF_PG-966780
2020-11-30 17:55:01,845 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: update orgd1_organization.dbo.cli_bkdn set corp_cd = ?, cli_no = ?, bkdn_nm = ?, bkdn_sta = ?, ver_svc_ind = ?, auto_svc_only_ind = ?, bkdn_stat_dt = ?, to_dt = ? where org_id = ? and bkdn_typ_cd = ? and bkdn = ? and frm_dt = ?
2020-11-30 17:55:01,846 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data ['FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, 465258, 'BLG ', '025262-000000-001759-0SALES', null] with types [CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, INTEGER, CHAR, VARCHAR, TIMESTAMP]
2020-11-30 17:55:01,847 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Update returned 0 rows updated
2020-11-30 17:55:01,847 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values (?,?,?,?,?,?,?,?,?,?,?,?)
2020-11-30 17:55:01,848 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [465258, 'BLG ', '025262-000000-001759-0SALES', 'FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, {ts '2020-11-30 16:54:40.280'}] with types [INTEGER, CHAR, VARCHAR, CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, TIMESTAMP]
2020-11-30 17:55:01,850 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Insert returned 1 rows inserted
2020-11-30 17:55:01,887 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-30 17:55:01,888 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-30 17:55:01,890 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-393] Unique violation from index psn_i01 on table psn during INSERT with batch MF_PG-966780. Attempting to correct.
2020-11-30 17:55:01,901 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-11-30 17:55:01,902 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-11-30 17:55:01,911 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: update psnd1_person.dbo.psn set psn_frst_nm = ?, psn_lst_nm = ? where psn_id = ?
2020-11-30 17:55:01,912 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data ['SCOTT ', 'NICOLAUS ', 21569799] with types [CHAR, CHAR, INTEGER]
2020-11-30 17:55:01,913 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Update returned 1 rows updated
2020-11-30 17:55:01,914 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-30 17:55:01,915 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799] with types [INTEGER]
2020-11-30 17:55:01,915 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-393] Unique violation from index phh_emp_i01 on table phh_emp during INSERT with batch MF_PG-966780. Attempting to correct.
2020-11-30 17:55:01,918 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-11-30 17:55:01,919 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799] with types [INTEGER]
2020-11-30 17:55:01,919 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Insert returned 1 rows inserted
2020-11-30 17:55:01,923 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-30 17:55:01,924 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-30 17:55:01,924 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-393] Unique violation from index psn_psn_typ_i01 on table psn_psn_typ during INSERT with batch MF_PG-966780. Attempting to correct.
2020-11-30 17:55:01,926 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-11-30 17:55:01,927 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-11-30 17:55:01,928 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Insert returned 1 rows inserted
2020-11-30 17:55:01,929 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-30 17:55:01,930 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-30 17:55:01,930 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-393] Unique violation from index phh_emp_xref_i01 on table phh_emp_xref during INSERT with batch MF_PG-966780. Attempting to correct.
2020-11-30 17:55:01,932 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-11-30 17:55:01,933 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-11-30 17:55:01,934 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Insert returned 1 rows inserted
2020-11-30 17:55:01,935 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
2020-11-30 17:55:01,936 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Submitting data [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-30 16:54:40.280'}, null] with types [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
2020-11-30 17:55:01,938 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-393] Failed to process insert event in batch MF_PG-966780 on channel 'MF_PG_CLI'.
Failed sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (21569799,465258,'BLG ','025262-000000-001759-0SALES','AE ',{ts '2020-11-30 16:54:40.280'},null)
Failed raw sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
Failed sql parameters: [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-11-30 16:54:40.280'}, null]
Failed sql parameters types: [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
Failed sql state and code: null (30156)
Failed row data was: "21569799","465258","BLG","025262-000000-001759-0SALES","AE","2020-11-30 16:54:40.280",,
 StackTraceKey [SqlException:2240136511]
2020-11-30 17:55:01,952 ERROR [EDB_SYBASE-EDB_SYB] [ManageIncomingBatchListener] [edb_sybase-edb_syb-dataloader-393] Failed to load batch MF_PG-966780 StackTraceKey [SqlException:2240136511]
2020-11-30 17:55:01,974 ERROR [MF_POSTGRES-MF_PG] [AcknowledgeService] [mf_postgres-mf_pg-push-MF_PG_PSN_Q-8] The outgoing batch EDB_SYB-966780 failed: [null,30156] Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: 465258 with {bkdn_typ_cd}: BLG for {bkdn}: 025262-000000-001759-0SALES does not exist in "cli_bkdn".

pmarzullo

2022-07-11 17:19

developer   ~0002106

Can you go to Manage -> Logging, hit the Set Levels button, and turn on debug logging for the "Conflicts" entry?

I can't get the same path through the code that you are getting.

pmarzullo

2022-07-11 17:19

developer   ~0002107

Here is the trace. Let me know if you want an updated snapshot. Thanks

2020-12-02 12:26:15,693 INFO [MF_POSTGRES-MF_PG] [PushService] [mf_postgres-mf_pg-push-MF_PG_VMA_Q-8] Push data sent to EDB_SYBASE:EDB_SYB:EDB_SYB
2020-12-02 12:26:15,711 INFO [EDB_SYBASE-EDB_SYB] [IncomingBatchService] [edb_sybase-edb_syb-dataloader-8] Retrying batch MF_PG-969142
2020-12-02 12:26:15,743 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: update orgd1_organization.dbo.cli_bkdn set corp_cd = ?, cli_no = ?, bkdn_nm = ?, bkdn_sta = ?, ver_svc_ind = ?, auto_svc_only_ind = ?, bkdn_stat_dt = ?, to_dt = ? where org_id = ? and bkdn_typ_cd = ? and bkdn = ? and frm_dt = ?
2020-12-02 12:26:15,748 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data ['FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, 465258, 'BLG ', '025262-000000-001759-0SALES', null] with types [CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, INTEGER, CHAR, VARCHAR, TIMESTAMP]
2020-12-02 12:26:15,750 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Update returned 0 rows updated
2020-12-02 12:26:15,750 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Conflict detected: MF_POSTGRES to EDB_SYBASE in batch MF_PG-969142 at line 1 for table orgd1_organization.dbo.cli_bkdn
2020-12-02 12:26:15,750 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Row data: "465258","BLG","025262-000000-001759-0SALES","FA","17739"," ","A","0","0","2020-11-16",,,"2020-12-02 12:21:17.712"
2020-12-02 12:26:15,751 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn (org_id, bkdn_typ_cd, bkdn, corp_cd, cli_no, bkdn_nm, bkdn_sta, ver_svc_ind, auto_svc_only_ind, bkdn_stat_dt, to_dt, frm_dt) values (?,?,?,?,?,?,?,?,?,?,?,?)
2020-12-02 12:26:15,754 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [465258, 'BLG ', '025262-000000-001759-0SALES', 'FA', '17739', ' ', 'A', 0, 0, {ts '2020-11-16 00:00:00.000'}, null, {ts '2020-12-02 12:21:17.712'}] with types [INTEGER, CHAR, VARCHAR, CHAR, VARCHAR, VARCHAR, CHAR, TINYINT, TINYINT, TIMESTAMP, TIMESTAMP, TIMESTAMP]
2020-12-02 12:26:15,756 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Insert returned 1 rows inserted
2020-12-02 12:26:15,800 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-12-02 12:26:15,803 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-12-02 12:26:15,804 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Conflict detected: MF_POSTGRES to EDB_SYBASE in batch MF_PG-969142 at line 2 for table psnd1_person.dbo.psn
2020-12-02 12:26:15,804 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Row data: "21569799",,"SCOTT","NICOLAUS","cli_bkdn"
2020-12-02 12:26:15,804 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Unique violation from index psn_i01 on table psn during INSERT with batch MF_PG-969142. Attempting to correct.
2020-12-02 12:26:15,818 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.psn (psn_id, psn_frst_nm, psn_lst_nm) values (?,?,?)
2020-12-02 12:26:15,819 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'SCOTT ', 'NICOLAUS '] with types [INTEGER, CHAR, CHAR]
2020-12-02 12:26:15,831 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: update psnd1_person.dbo.psn set psn_frst_nm = ?, psn_lst_nm = ? where psn_id = ?
2020-12-02 12:26:15,832 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data ['SCOTT ', 'NICOLAUS ', 21569799] with types [CHAR, CHAR, INTEGER]
2020-12-02 12:26:15,833 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Update returned 1 rows updated
2020-12-02 12:26:15,835 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-12-02 12:26:15,837 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799] with types [INTEGER]
2020-12-02 12:26:15,838 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Conflict detected: MF_POSTGRES to EDB_SYBASE in batch MF_PG-969142 at line 3 for table psnd1_person.dbo.phh_emp
2020-12-02 12:26:15,838 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Row data: "21569799",,"cli_bkdn"
2020-12-02 12:26:15,838 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Unique violation from index phh_emp_i01 on table phh_emp during INSERT with batch MF_PG-969142. Attempting to correct.
2020-12-02 12:26:15,841 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.phh_emp (psn_id) values (?)
2020-12-02 12:26:15,842 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799] with types [INTEGER]
2020-12-02 12:26:15,843 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Insert returned 1 rows inserted
2020-12-02 12:26:15,848 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-12-02 12:26:15,852 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-12-02 12:26:15,854 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Conflict detected: MF_POSTGRES to EDB_SYBASE in batch MF_PG-969142 at line 4 for table psnd1_person.dbo.psn_psn_typ
2020-12-02 12:26:15,854 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Row data: "21569799","EMP",,"cli_bkdn"
2020-12-02 12:26:15,854 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Unique violation from index psn_psn_typ_i01 on table psn_psn_typ during INSERT with batch MF_PG-969142. Attempting to correct.
2020-12-02 12:26:15,858 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.psn_psn_typ (psn_id, psn_typ_cd) values (?,?)
2020-12-02 12:26:15,860 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'EMP '] with types [INTEGER, CHAR]
2020-12-02 12:26:15,861 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Insert returned 1 rows inserted
2020-12-02 12:26:15,863 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-12-02 12:26:15,864 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-12-02 12:26:15,865 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Conflict detected: MF_POSTGRES to EDB_SYBASE in batch MF_PG-969142 at line 5 for table psnd1_person.dbo.phh_emp_xref
2020-12-02 12:26:15,865 DEBUG [EDB_SYBASE-EDB_SYB] [AbstractDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Row data: "21569799",,"FA","S1N","cli_bkdn"
2020-12-02 12:26:15,865 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriterConflictResolver] [edb_sybase-edb_syb-dataloader-8] Unique violation from index phh_emp_xref_i01 on table phh_emp_xref during INSERT with batch MF_PG-969142. Attempting to correct.
2020-12-02 12:26:15,869 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into psnd1_person.dbo.phh_emp_xref (psn_id, corp_cd, ae_cd) values (?,?,?)
2020-12-02 12:26:15,871 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 'FA', 'S1N'] with types [INTEGER, CHAR, CHAR]
2020-12-02 12:26:15,872 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Insert returned 1 rows inserted
2020-12-02 12:26:15,874 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Preparing dml: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
2020-12-02 12:26:15,878 DEBUG [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Submitting data [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-12-02 12:21:17.712'}, null] with types [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
2020-12-02 12:26:15,881 INFO [EDB_SYBASE-EDB_SYB] [DefaultDatabaseWriter] [edb_sybase-edb_syb-dataloader-8] Failed to process insert event in batch MF_PG-969142 on channel 'MF_PG_CLI'.
Failed sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (21569799,465258,'BLG ','025262-000000-001759-0SALES','AE ',{ts '2020-12-02 12:21:17.712'},null)
Failed raw sql was: insert into orgd1_organization.dbo.cli_bkdn_psn (psn_id, org_id, bkdn_typ_cd, bkdn, role_typ_cd, frm_dt, to_dt) values (?,?,?,?,?,?,?)
Failed sql parameters: [21569799, 465258, 'BLG ', '025262-000000-001759-0SALES', 'AE ', {ts '2020-12-02 12:21:17.712'}, null]
Failed sql parameters types: [INTEGER, INTEGER, CHAR, VARCHAR, CHAR, TIMESTAMP, TIMESTAMP]
Failed sql state and code: null (30156)
Failed row data was: "21569799","465258","BLG","025262-000000-001759-0SALES","AE","2020-12-02 12:21:17.712",,
 StackTraceKey [SqlException:2240136511]
2020-12-02 12:26:15,898 ERROR [EDB_SYBASE-EDB_SYB] [ManageIncomingBatchListener] [edb_sybase-edb_syb-dataloader-8] Failed to load batch MF_PG-969142 StackTraceKey [SqlException:2240136511]
2020-12-02 12:26:15,923 ERROR [MF_POSTGRES-MF_PG] [AcknowledgeService] [mf_postgres-mf_pg-push-MF_PG_VMA_Q-8] The outgoing batch EDB_SYB-969142 failed: [null,30156] Attempt to INSERT a row into "cli_bkdn_psn" failed because {org_id}: 465258 with {bkdn_typ_cd}: BLG for {bkdn}: 025262-000000-001759-0SALES does not exist in "cli_bkdn".

pmarzullo

2022-07-11 17:20

developer   ~0002108

Issue History

Date Modified Username Field Change
2022-07-11 17:12 pmarzullo New Issue
2022-07-11 17:12 pmarzullo Status new => assigned
2022-07-11 17:12 pmarzullo Assigned To => pmarzullo
2022-07-11 17:12 pmarzullo Tag Attached: dialect: postgresql
2022-07-11 17:12 pmarzullo Tag Attached: dialect: sybase
2022-07-11 17:12 pmarzullo File Added: MF_POSTGRES-MF_PG-20201117164701.zip
2022-07-11 17:14 pmarzullo Note Added: 0002098
2022-07-11 17:14 pmarzullo File Added: MF_POSTGRES-MF_PG-20201119121236.zip
2022-07-11 17:15 pmarzullo Note Added: 0002099
2022-07-11 17:16 pmarzullo Note Added: 0002100
2022-07-11 17:16 pmarzullo Note Added: 0002101
2022-07-11 17:17 pmarzullo Note Added: 0002102
2022-07-11 17:17 pmarzullo Note Added: 0002103
2022-07-11 17:18 pmarzullo Note Added: 0002104
2022-07-11 17:18 pmarzullo Note Added: 0002105
2022-07-11 17:19 pmarzullo Note Added: 0002106
2022-07-11 17:19 pmarzullo Note Added: 0002107
2022-07-11 17:20 pmarzullo Note Added: 0002108
2022-07-11 17:20 pmarzullo File Added: MF_POSTGRES-MF_PG-20201202161112.zip
2022-07-25 16:52 elong Target Version 3.14.0 => 3.14.1