The compare or repair fails with “compare client got timed out error” on compare server log (*desvr* log) and “sqlite record not found” in compare client log (*declt* log) when SP_OPO_POSTER_DELAY is configured. (4297577)

On source and target, we set SP_DEQ_TIMEOUT to 180 seconds which translates to 3 minutes.

On target we set SP_OPO_POSTER_DELAY to 10 minutes.

The following errors are seen when the parameter SP_OPO_POSTER_DELAY is set to a value higher than SP_DEQ_TIMEOUT.

Here are the event logs and compare logs from source and target when the failure occurs:

Source:

sp_ctrl (alvsupl14:9239)> show log reverse

Info     2019-05-21 15:02:55.966880 27601 1783700144 Compare server exited normally, pid = 27810  [sp_desvr]

Error    2019-05-21 15:02:50.919308 27810 1117784384 [1] Compare server: Error 50001 sending version info, see desvr_1_o.ORA11GR2_p27810  [sp_desvr] [module deq]

Info     2019-05-21 14:58:47.086010 27810 3801786320 Compare server completed

Notice   2019-05-21 14:58:47.085746 27810 3801786320 Compare server: Opened Compare session log file /home/paul/p92139-11g/var/log/desvr_1_o.ORA11GR2_p27810  [sp_desvr] [module deq]

Notice   2019-05-21 14:58:47.047394 27810 3801786320 Compare server: Replicating according to target compatibility of "9.2.0"  [sp_desvr] [module sys]

Info     2019-05-21 14:58:46.783721 27810 1783700144 Compare server launched, pid = 27810  [sp_desvr]

desvr log tail portion:

desvr    2019-05-21 15:02:50.906255 27810 1117784384 [1] Error: compare client got timed out error (failed to receive consistent view marker)

desvr    2019-05-21 15:02:50.908044 27810 1117784384 [1] DEBUG:schema=SHA92, table name=TABLE1, column_count=2 (de_table_list_table_info,L2333)

desvr    2019-05-21 15:02:50.908475 27810 1117784384 [1] DEBUG:colName=NUM_COL, column[0].number=1, type=2 (NUMBER), dsize=22, cform=0, csid=0

desvr    2019-05-21 15:02:50.908511 27810 1117784384 [1] DEBUG:colName=CHAR_COL, column[1].number=2, type=1 (CHAR), dsize=10, cform=1, csid=873

desvr    2019-05-21 15:02:50.911926 27810 1117784384 [1] Status: WaitMarker    Elapsed time: 239.214 seconds

desvr    2019-05-21 15:02:50.917189 27810 1117784384 [1] Status : Error

desvr    2019-05-21 15:02:50.919630 27810 1117784384 [1] Error: compare client timed out.

desvr    2019-05-21 15:02:50.919708 27810 1117784384 [1] Compare SHA92.TABLE1 to SHA92.TABLE1 failed. See error message above.

desvr    2019-05-21 15:02:53.962549 27810 1117784384 [0] Exiting........

Target:

sp_ctrl (alvsupl17:9239)> show log reverse

Info     2019-05-21 14:54:38.893998 32309 2396256096 Compare client exited normally, pid = 32423  [sp_declt]

Error    2019-05-21 14:54:28.887986 32423 2331826016 Compare client: Error, sqlite record not found (sp_declt.cpp,L1240)  [sp_declt] [module deq]

Error    2019-05-21 14:54:28.887626 32423 2331826016 Compare client: Error timed out occurred after 240 seconds (../src/deqtr/sp_declt.cpp,L909)  [sp_declt] [module deq]

Info     2019-05-21 14:53:59.575468 32309 2396256096 Poster exited normally, pid = 32368  (posting from o.ORA11GR2, queue asdf, to o.ORA11GR2)

Notice   2019-05-21 14:53:58.930752 32368 2949576544 Poster: Highest committed SCN 0  (posting from o.ORA11GR2, queue asdf, to o.ORA11GR2) [module opo]

Notice   2019-05-21 14:53:58.830259 32368 2949576544 Poster: Shutting down by request  (posting from o.ORA11GR2, queue asdf, to o.ORA11GR2) [module opo]

Notice   2019-05-21 14:53:58.828896 32446 1060800384 User command: paul stop post queue asdf (from alvsupl17.prod.quest.corp)

Notice   2019-05-21 14:50:28.820772 32423 2331826016 Compare client: Opened DataEquator client session log file /home/paul/p92139-11g/var/log/declt_1-1_o.ORA11GR2_a01174f_p32423.log  [sp_declt] [module deq]

Info     2019-05-21 14:50:27.237942 32423 2396256096 Compare client launched, pid = 32423  [sp_declt]

declt log tail portion:

declt    2019-05-21 14:54:28.887534 32423 2331826016 Error timed out occurred after 240 seconds (sp_declt_wait_for_sqlite_record,L907)

declt    2019-05-21 14:54:28.887935 32423 2331826016 Status : Error

declt    2019-05-21 14:54:28.887976 32423 2331826016 Error, sqlite record not found (sp_declt.cpp,L1239)

declt    2019-05-21 14:54:28.888185 32423 2331826016 Exiting . .