Ora2pg crash ERROR: Timed out: [Timed out (yb/rpc/rpc.cc:213)

Hi

I use ora2pg but I have an error on insert

I import 30,000 or 250,000 lines and crashes after

C:\temp\ora2pg-master\ora2pg-master>ora2pg -t COPY -o table.sql -b C:\ora2pg\datahubdbprd\datahub\schema\tables  -c c:\ora2pg\ora2pg_dist2.conf
[========================>] 1/1 tables (100.0%) end of scanning.
DBD::Pg::db pg_putcopyend failed: ERROR:  Timed out: [Timed out (yb/rpc/rpc.cc:213): Write(tablet: 9b2420b56d3b400188b646ed7d194b05, num_ops: 512, num_attempts: 87, txn: 1400a6c6-b1fd-4640-8c5f-f576119205e5) passed its deadline 1664119.950s (passed: 60.021s): Illegal state (yb/consensus/consensus.cc:150): Not the leader (tablet server error 15)] at C:/Strawberry/perl/site/lib/Ora2Pg.pm line 14938.
FATAL: ERROR:  Timed out: [Timed out (yb/rpc/rpc.cc:213): Write(tablet: 9b2420b56d3b400188b646ed7d194b05, num_ops: 512, num_attempts: 87, txn: 1400a6c6-b1fd-4640-8c5f-f576119205e5) passed its deadline 1664119.950s (passed: 60.021s): Illegal state (yb/consensus/consensus.cc:150): Not the leader (tablet server error 15)]
DBI::db=HASH(0x498a960)->disconnect invalidates 1 active statement handle (either destroy statement handles or call finish on them before disconnecting) at C:/Strawberry/perl/site/lib/Ora2Pg.pm line 14075.
Aborting export...

ORACLE_HOME C:\oracle\product\12.2.0
ORACLE_DSN dbi:Oracle:host=xxxxxxxx;sid=xxxxx
PG_VERSION 11
ORACLE_USER sys
ORACLE_PWD xxxxxxxxxxx
USER_GRANTS 0
DEBUG 0
EXPORT_SCHEMA 0
SCHEMA OPERA
CREATE_SCHEMA 0
COMPILE_SCHEMA 0
EXPORT_INVALID 0
TYPE TABLE
ALLOW NAME_PHONE
PG_DSN dbi:Pg:dbname=test;host=172.22.6.146;port=5433
PG_USER postgres
PG_PWD xxxxxx

Log path is: /home/sbmautomation/yugadisk/yb-data/tserver/logs/yb-tserver.INFO

I1109 14:56:07.349265 23678 event_logger.cc:77] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [I]: EVENT_LOG_v1 {"time_micros": 1604933767349091, "job": 6127, "event": "flush_finished", "lsm_state": [1]}
I1109 14:56:13.146649  4973 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.478s: Failed to obtain locks until deadline: 1666250.113s
W1109 14:56:13.146852  4973 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 91) took 2501ms (client timeout 2500ms).
I1109 14:56:15.725142  4975 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.475s: Failed to obtain locks until deadline: 1666252.691s
W1109 14:56:15.725461  4975 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 100) took 2501ms (client timeout 2500ms).
I1109 14:56:18.315866  4976 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.473s: Failed to obtain locks until deadline: 1666255.279s
W1109 14:56:18.316067  4976 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 109) took 2504ms (client timeout 2500ms).
I1109 14:56:20.927563  4973 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.463s: Failed to obtain locks until deadline: 1666257.894s
W1109 14:56:20.927842  4973 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 118) took 2501ms (client timeout 2500ms).
I1109 14:56:23.550160  4969 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.464s: Failed to obtain locks until deadline: 1666260.516s
W1109 14:56:23.550527  4969 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 127) took 2501ms (client timeout 2500ms).
I1109 14:56:26.223302  4961 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.465s: Failed to obtain locks until deadline: 1666263.189s
W1109 14:56:26.223485  4961 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 136) took 2501ms (client timeout 2500ms).
I1109 14:56:28.892099  4964 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.479s: Failed to obtain locks until deadline: 1666265.858s
W1109 14:56:28.892444  4964 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 146) took 2501ms (client timeout 2500ms).
I1109 14:56:31.571507  1612 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.466s: Failed to obtain locks until deadline: 1666268.538s
W1109 14:56:31.571784  1612 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 155) took 2501ms (client timeout 2500ms).
I1109 14:56:34.269677  4972 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.463s: Failed to obtain locks until deadline: 1666271.236s
W1109 14:56:34.270004  4972 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 164) took 2501ms (client timeout 2500ms).
I1109 14:56:36.980190  4959 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.468s: Failed to obtain locks until deadline: 1666273.946s
W1109 14:56:36.980453  4959 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 174) took 2501ms (client timeout 2500ms).
I1109 14:56:39.705796  4976 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.461s: Failed to obtain locks until deadline: 1666276.672s
W1109 14:56:39.706025  4976 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 183) took 2501ms (client timeout 2500ms).
I1109 14:56:42.453452  4963 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.466s: Failed to obtain locks until deadline: 1666279.420s
W1109 14:56:42.453709  4963 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 193) took 2501ms (client timeout 2500ms).
I1109 14:56:45.211055  4977 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.468s: Failed to obtain locks until deadline: 1666282.177s
W1109 14:56:45.211316  4977 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 202) took 2501ms (client timeout 2500ms).
I1109 14:56:47.982533  4974 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.473s: Failed to obtain locks until deadline: 1666284.949s
W1109 14:56:47.982779  4974 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 212) took 2501ms (client timeout 2500ms).
I1109 14:56:50.773999  4968 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.476s: Failed to obtain locks until deadline: 1666287.741s
W1109 14:56:50.774907  4968 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 221) took 2500ms (client timeout 2500ms).
I1109 14:56:53.589908  4975 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.462s: Failed to obtain locks until deadline: 1666290.556s
W1109 14:56:53.590184  4975 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 231) took 2501ms (client timeout 2500ms).
I1109 14:56:56.403705  4966 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.469s: Failed to obtain locks until deadline: 1666293.370s
W1109 14:56:56.403896  4966 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 240) took 2501ms (client timeout 2500ms).
I1109 14:56:59.244814  4965 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.476s: Failed to obtain locks until deadline: 1666296.211s
W1109 14:56:59.245036  4965 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 250) took 2501ms (client timeout 2500ms).
I1109 14:57:02.090994  4962 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.460s: Failed to obtain locks until deadline: 1666299.058s
W1109 14:57:02.091255  4962 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 259) took 2500ms (client timeout 2500ms).
I1109 14:57:04.970521  4972 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.469s: Failed to obtain locks until deadline: 1666301.937s
W1109 14:57:04.970701  4972 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 269) took 2500ms (client timeout 2500ms).
I1109 14:57:07.869343  4959 tablet_service.cc:401] Write failed: Operation failed. Try again. (yb/docdb/lock_batch.cc:31): Timeout: 2.463s: Failed to obtain locks until deadline: 1666304.835s
W1109 14:57:07.869581  4959 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 279) took 2501ms (client timeout 2500ms).
I1109 14:57:23.859531 23216 tablet.cc:800] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f: Intents SST file will be deleted: { total_size: 11416589 base_size: 552463 uncompressed_size: 51230679 name: "/000139.sst" db_path: "/home/sbmautomation/yugadisk/yb-data/tserver/data/rocksdb/table-00004104000030008000000000000000.colocated.parent.uuid/tablet-9b2420b56d3b400188b646ed7d194b05.intents" imported: 0 being_compacted: 0 column_family_name: default level: 0 smallest: { seqno: 1125900175890176 user_frontier: 0x000000006b696e40 -> { op_id: 3.513798 hybrid_time: { physical: 1604933743351554 } history_cutoff:  hybrid_time_filter:  } } largest: { seqno: 1125900178046071 user_frontier: 0x000000006b697cb0 -> { op_id: 3.513839 hybrid_time: { physical: 1604933763014534 } history_cutoff:  hybrid_time_filter:  } } }, max ht: { physical: 1604933763014534 }, min running transaction start ht: 
I1109 14:57:23.859678 23216 db_impl.cc:5339] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] New memtable created with log file: #88
I1109 14:57:23.859833 23678 db_impl.cc:3197] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: Calling FlushMemTableToOutputFile with column family [default], flush slots scheduled 1, total flush slots 1, compaction slots scheduled 0, compaction tasks [], total compaction slots 1
I1109 14:57:23.859892 23678 flush_job.cc:258] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] [JOB 86] Flushing memtable with next log file: 88
I1109 14:57:23.859927 23678 event_logger.cc:67] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: EVENT_LOG_v1 {"time_micros": 1604933843859917, "job": 86, "event": "flush_started", "num_memtables": 1, "num_entries": 280000, "num_deletes": 0, "memory_usage": 23681296}
I1109 14:57:23.859946 23678 flush_job.cc:286] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] [JOB 86] Level-0 flush table #178: started
W1109 14:57:23.970588 23224 yb_rpc.cc:426] Call yb.tserver.TabletServerService.Write 172.22.6.146:42932 => 172.22.6.146:9100 (request call id 82) took 75901ms (client timeout 2500ms).
I1109 14:57:24.324949 23678 flush_job.cc:318] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] [JOB 86] Level-0 flush table #178: 5065028 bytes OK
I1109 14:57:24.325037 23678 event_logger.cc:67] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: EVENT_LOG_v1 {"time_micros": 1604933844325019, "cf_name": "default", "job": 86, "event": "table_file_creation", "file_number": 178, "file_size": 5065028, "table_properties": {"data_size": 4986049, "data_index_size": 18345, "filter_size": 65482, "filter_index_size": 22, "raw_key_size": 13701677, "raw_average_key_size": 48, "raw_value_size": 4832371, "raw_average_value_size": 17, "num_data_blocks": 392, "num_entries": 280000, "num_filter_blocks": 1, "num_data_index_blocks": 1, "filter_policy_name": "DocKeyV2Filter", "kDeletedKeys": "0"}}
I1109 14:57:24.325341 23678 db_impl.cc:1879] [default] Level summary: files[4] max score 0.80
I1109 14:57:24.325433 23678 memtable_list.cc:374] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] Level-0 commit table #178 started
I1109 14:57:24.325454 23678 memtable_list.cc:390] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: [default] Level-0 commit table #178: memtable #1 done
I1109 14:57:24.325467 23678 event_logger.cc:77] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [R]: EVENT_LOG_v1 {"time_micros": 1604933844325261, "job": 86, "event": "flush_finished", "lsm_state": [4]}
I1109 14:57:24.327672 23216 db_impl.cc:1158] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [I]: [JOB 6128] Delete /home/sbmautomation/yugadisk/yb-data/tserver/data/rocksdb/table-00004104000030008000000000000000.colocated.parent.uuid/tablet-9b2420b56d3b400188b646ed7d194b05.intents/000139.sst type=2 #139 -- OK
I1109 14:57:24.327764 23216 event_logger.cc:67] T 9b2420b56d3b400188b646ed7d194b05 P 9b1133f470914931a526d160b4209c3f [I]: EVENT_LOG_v1 {"time_micros": 1604933844327752, "job": 6128, "event": "table_file_deletion", "file_number": 139}

Thank you for your support!

Hi @dab

Can you paste also some .WARNING logs ?

What is the hardware of the server ? (cpu,ram,ssd/hdd)

Can you try with a colocated database ?

Can you paste a screenshot of http://:7000/tablet-servers ?

hi
I created a database in collated but I have this error
DBD::Pg::db pg_putcopyend failed: ERROR: Already present: [Already present (yb/consensus/retryable_requests.cc:241): Duplicate request] at C:/Strawberry/perl/site/lib/Ora2Pg.pm line 14938.
FATAL: ERROR: Already present: [Already present (yb/consensus/retryable_requests.cc:241): Duplicate request]
DBI::db=HASH(0x47fb8f0)->disconnect invalidates 1 active statement handle (either destroy statement handles or call finish on them before disconnecting) at C:/Strawberry/perl/site/lib/Ora2Pg.pm line 14075.
Aborting export…

i think it’s related to hdd disk
3 server

Capture2

Thank you for your support!

here is the link for the logs

thank you so much

Hi @dab

Yes HDD is unsupported.
You MUST use SSD: https://docs.yugabyte.com/latest/deploy/checklist/#disks

Can you try again with recommended hardware ?

we ordered
ssd disks we haven’t received them yet.
But I created tables made insertions and delete and update without problem but not in bulk
I can’t wait to have my ssd drives to continue exploring the potential of yugabyte
Thank you for your time

I understand that it is frustrating. But the database on HDD will not be stable at best.
If you can handle losing data over restarts, you can use a RAMDISK and continue testing with HDD.