search

CounterpartyXCP / counterparty-core

Counterparty Protocol Reference Implementation
http://counterparty.io
MIT License
283 stars 206 forks source link

`KeyError` #2002

Closed adamkrellenstein closed 1 week ago

adamkrellenstein commented 1 week ago 
2024-07-03T13:25:26.993262000+00:00 - [   DEBUG] - API Request - Check Server Health
2024-07-03T13:25:26.994434000+00:00 - [   DEBUG] - API Request - Check Server Health - Response 503 (Counterparty not ready) - 2ms
2024-07-03T13:25:27.625307000+00:00 - [   ERROR] - Counterparty falls behind. 1579333 < 2865781
2024-07-03T13:25:27.629510000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-03T13:25:28.620921000+00:00 - [    INFO] - API Watcher - 2470000/5146684 events parsed in 0h 33m 42s (expected 1h 10m 14s)
2024-07-03T13:25:34.964648000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 72, in run
    reraise(*_capture_exception())
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/_compat.py", line 127, in reraise
    raise value
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 70, in run
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 581, in run
    catch_up(self.api_db, self.ledger_db)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 464, in catch_up
    parse_event(api_db, next_event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 447, in parse_event
    event["insert_rowid"] = execute_event(api_db, event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 434, in execute_event
    sql, sql_bindings = event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 139, in event_to_sql
    return update_event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 127, in update_event_to_sql
    sql_bindings.append(event_bindings[id_field_name])
KeyError: 'tx_hash'
2024-07-03T13:25:38.264019000+00:00 - [   ERROR] - Counterparty falls behind. 1583612 < 2865781
2024-07-03T13:25:38.267395000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-03T13:25:48.903331000+00:00 - [   ERROR] - Counterparty falls behind. 1583612 < 2865781
2024-07-03T13:25:48.907214000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-03T13:25:49.164511000+00:00 - [   DEBUG] - API Request - Check Server Health
adamkrellenstein commented 1 week ago

Still getting this on restarts:

Counterparty Core v10.3.0-rc.1
Verbosity: 1
Quiet: False
Configuration File: /root/.config/counterparty/server.conf
Counterparty Database: /data/counterparty/counterparty.testnet.db
Network: `testnet`
Bitcoin Core: http://rpc:*****@prd-btc-testnet-v2-hzqh:18332
AddrIndexRs: http://prd-btc-testnet-v2-hzqh:18432
Counterparty RPC Server: http://rpc:*****@0.0.0.0:14100/rpc/
Server Log: /root/.cache/counterparty/log/server.testnet.log
API Access Log: /root/.cache/counterparty/log/server.testnet.access.log

------------------------------ START ------------------------------

2024-07-05T07:54:47.573466000+00:00 - [    INFO] - Connecting to database... (SQLite 3.45.1.0)
2024-07-05T07:54:47.575071000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:54:47.590605000+00:00 - [   DEBUG] - Checking database version...
2024-07-05T07:54:47.591243000+00:00 - [    INFO] - Running PRAGMA optimize...
2024-07-05T07:54:47.597233000+00:00 - [   DEBUG] - PRAGMA optimize completed.
2024-07-05T07:54:47.597860000+00:00 - [   DEBUG] - Checking Counterparty version...
2024-07-05T07:54:48.113709000+00:00 - [   DEBUG] - Version check passed.
2024-07-05T07:54:48.135285000+00:00 - [    INFO] - Telemetry enabled.
2024-07-05T07:54:48.136341000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:54:48.171891000+00:00 - [   DEBUG] - Starting API Status Poller...
2024-07-05T07:54:48.173922000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
ERROR:root:SQLITE_LOG: recovered 12 frames from WAL file /data/counterparty/counterparty.testnet.api.db-wal (283) SQLITE_NOTICE_RECOVER_WAL
2024-07-05T07:54:48.187684000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:54:48.199883000+00:00 - [    INFO] - Starting API Server v1...
2024-07-05T07:54:49.062510000+00:00 - [   DEBUG] - Starting Prefetcher...
2024-07-05T07:54:49.065582851+00:00 - [    INFO] - RS Fetcher - Indexer initializing...
2024-07-05T07:54:49.077813281+00:00 - [   DEBUG] - RS Fetcher - 2 BitcoinClient workers started
2024-07-05T07:54:49.078955087+00:00 - [    INFO] - RS Fetcher - Connecting to database: /data/counterparty/fetcherdb.testnet
2024-07-05T07:54:49.144941938+00:00 - [    INFO] - RS Fetcher - Connected
2024-07-05T07:54:49.144989959+00:00 - [    INFO] - RS Fetcher - Initialized
2024-07-05T07:54:49.145360000+00:00 - [   DEBUG] - Current Fetcher version: 10.3.0-rc.1
2024-07-05T07:54:49.146525164+00:00 - [    INFO] - RS Fetcher - First database op: GetMaxBlockHeight...
2024-07-05T07:54:49.146887872+00:00 - [    INFO] - RS Fetcher - First database op: GetMaxBlockHeight took 316.599µs
2024-07-05T07:54:49.147116512+00:00 - [    INFO] - RS Fetcher - First Bitcoin client op: GetBlockchainHeight...
2024-07-05T07:54:49.200164000+00:00 - [   DEBUG] - Initializing API Watcher...
2024-07-05T07:54:49.200668000+00:00 - [   DEBUG] - API Watcher - Applying migrations...
2024-07-05T07:54:49.222040000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:54:49.224961000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:54:49.230176000+00:00 - [    INFO] - Starting API Watcher...
2024-07-05T07:54:49.230289000+00:00 - [    INFO] - Starting API Server...
2024-07-05T07:54:49.235289000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:54:49.237290000+00:00 - [   DEBUG] - API Watcher - 2669667 events to catch up...
2024-07-05T07:54:49.312202000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:54:49.317830000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 72, in run
    reraise(*_capture_exception())
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/_compat.py", line 127, in reraise
    raise value
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 70, in run
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 585, in run
    catch_up(self.api_db, self.ledger_db)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 465, in catch_up
    parse_event(api_db, next_event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 448, in parse_event
    event["insert_rowid"] = execute_event(api_db, event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 435, in execute_event
    sql, sql_bindings = event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 140, in event_to_sql
    return update_event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 128, in update_event_to_sql
    sql_bindings.append(event_bindings[id_field_name])
KeyError: 'tx_hash'
2024-07-05T07:54:49.665347330+00:00 - [    INFO] - RS Fetcher - First Bitcoin client op: GetBlockchainHeight took 518.158323ms
2024-07-05T07:54:49.665384958+00:00 - [    INFO] - RS Fetcher - Starting at block height: 2866098
2024-07-05T07:54:49.665398297+00:00 - [    INFO] - RS Fetcher - Targeting block height: 2866231
2024-07-05T07:54:49.665510166+00:00 - [   DEBUG] - RS Fetcher - 1 Producer workers started
2024-07-05T07:54:49.665781223+00:00 - [   DEBUG] - RS Fetcher - 2 Fetcher workers started
2024-07-05T07:54:49.665923492+00:00 - [   DEBUG] - RS Fetcher - 1 Extractor workers started
2024-07-05T07:54:49.666007258+00:00 - [   DEBUG] - RS Fetcher - 1 Orderer workers started
2024-07-05T07:54:49.666083368+00:00 - [   DEBUG] - RS Fetcher - 1 Writer workers started
2024-07-05T07:54:49.666167263+00:00 - [   DEBUG] - RS Fetcher - 1 Reporter workers started
2024-07-05T07:54:49.666185568+00:00 - [    INFO] - RS Fetcher - Fetcher started
2024-07-05T07:54:49.668325000+00:00 - [   DEBUG] - Starting prefetching blocks...
2024-07-05T07:54:49.670987000+00:00 - [   DEBUG] - Looking for Block 2866098 in prefetch queue...
2024-07-05T07:54:49.671144000+00:00 - [   DEBUG] - No block fetched. Waiting before next fetch.
2024-07-05T07:54:49.671921000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:54:49.673828000+00:00 - [   DEBUG] - Block 2866098 not found in prefetch queue. Waiting...
2024-07-05T07:54:49.774862000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:54:49.775751000+00:00 - [   DEBUG] - Block 2866098 not found in prefetch queue. Waiting...
Counterparty Core v10.3.0-rc.1
Verbosity: 1
Quiet: False
Configuration File: /root/.config/counterparty/server.conf
Counterparty Database: /data/counterparty/counterparty.testnet.db
Network: `testnet`
Bitcoin Core: http://rpc:*****@prd-btc-testnet-v2-hzqh:18332
AddrIndexRs: http://prd-btc-testnet-v2-hzqh:18432
Counterparty RPC Server: http://rpc:*****@0.0.0.0:14100/rpc/
Server Log: /root/.cache/counterparty/log/server.testnet.log
API Access Log: /root/.cache/counterparty/log/server.testnet.access.log

------------------------------ START ------------------------------

2024-07-05T07:55:44.143176000+00:00 - [    INFO] - Connecting to database... (SQLite 3.45.1.0)
2024-07-05T07:55:44.145532000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:55:44.159593000+00:00 - [   DEBUG] - Checking database version...
2024-07-05T07:55:44.160227000+00:00 - [    INFO] - Running PRAGMA optimize...
2024-07-05T07:55:44.165751000+00:00 - [   DEBUG] - PRAGMA optimize completed.
2024-07-05T07:55:44.166321000+00:00 - [   DEBUG] - Checking Counterparty version...
2024-07-05T07:55:44.674152000+00:00 - [   DEBUG] - Version check passed.
2024-07-05T07:55:44.693022000+00:00 - [    INFO] - Telemetry enabled.
2024-07-05T07:55:44.693914000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:55:44.724890000+00:00 - [   DEBUG] - Starting API Status Poller...
2024-07-05T07:55:44.731526000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
ERROR:root:SQLITE_LOG: recovered 16 frames from WAL file /data/counterparty/counterparty.testnet.api.db-wal (283) SQLITE_NOTICE_RECOVER_WAL
2024-07-05T07:55:44.738086000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:55:44.753925000+00:00 - [    INFO] - Starting API Server v1...
2024-07-05T07:55:45.733597000+00:00 - [   DEBUG] - Starting Prefetcher...
2024-07-05T07:55:45.736254478+00:00 - [    INFO] - RS Fetcher - Indexer initializing...
2024-07-05T07:55:45.748485000+00:00 - [   DEBUG] - Initializing API Watcher...
2024-07-05T07:55:45.749220000+00:00 - [   DEBUG] - API Watcher - Applying migrations...
2024-07-05T07:55:45.751093754+00:00 - [   DEBUG] - RS Fetcher - 2 BitcoinClient workers started
2024-07-05T07:55:45.751929103+00:00 - [    INFO] - RS Fetcher - Connecting to database: /data/counterparty/fetcherdb.testnet
2024-07-05T07:55:45.781523000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:55:45.785541000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:55:45.791690000+00:00 - [    INFO] - Starting API Watcher...
2024-07-05T07:55:45.791804000+00:00 - [    INFO] - Starting API Server...
2024-07-05T07:55:45.797309000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:55:45.799205000+00:00 - [   DEBUG] - API Watcher - 2669871 events to catch up...
2024-07-05T07:55:45.807167000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.db`...
2024-07-05T07:55:45.827798834+00:00 - [    INFO] - RS Fetcher - Connected
2024-07-05T07:55:45.827888492+00:00 - [    INFO] - RS Fetcher - Initialized
2024-07-05T07:55:45.828238000+00:00 - [   DEBUG] - Current Fetcher version: 10.3.0-rc.1
2024-07-05T07:55:45.829407971+00:00 - [    INFO] - RS Fetcher - First database op: GetMaxBlockHeight...
2024-07-05T07:55:45.829507915+00:00 - [    INFO] - RS Fetcher - First database op: GetMaxBlockHeight took 61.714µs
2024-07-05T07:55:45.830120651+00:00 - [    INFO] - RS Fetcher - First Bitcoin client op: GetBlockchainHeight...
2024-07-05T07:55:45.838254259+00:00 - [    INFO] - RS Fetcher - First Bitcoin client op: GetBlockchainHeight took 8.052586ms
2024-07-05T07:55:45.838313269+00:00 - [    INFO] - RS Fetcher - Starting at block height: 2866200
2024-07-05T07:55:45.838326590+00:00 - [    INFO] - RS Fetcher - Targeting block height: 2866231
2024-07-05T07:55:45.838416563+00:00 - [   DEBUG] - RS Fetcher - 1 Producer workers started
2024-07-05T07:55:45.838517747+00:00 - [   DEBUG] - RS Fetcher - 2 Fetcher workers started
2024-07-05T07:55:45.838674945+00:00 - [   DEBUG] - RS Fetcher - 1 Extractor workers started
2024-07-05T07:55:45.838765465+00:00 - [   DEBUG] - RS Fetcher - 1 Orderer workers started
2024-07-05T07:55:45.838840063+00:00 - [   DEBUG] - RS Fetcher - 1 Writer workers started
2024-07-05T07:55:45.838918355+00:00 - [   DEBUG] - RS Fetcher - 1 Reporter workers started
2024-07-05T07:55:45.838936280+00:00 - [    INFO] - RS Fetcher - Fetcher started
2024-07-05T07:55:45.839580000+00:00 - [   DEBUG] - Starting prefetching blocks...
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 72, in run
    reraise(*_capture_exception())
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/_compat.py", line 127, in reraise
2024-07-05T07:55:45.846212072+00:00 - [    INFO] - RS Fetcher - Entering reorg window
2024-07-05T07:55:45.841911000+00:00 - [   DEBUG] - Looking for Block 2866200 in prefetch queue...
2024-07-05T07:55:45.847298000+00:00 - [   DEBUG] - No block fetched. Waiting before next fetch.
2024-07-05T07:55:45.848477000+00:00 - [ WARNING] - Prefetch queue is empty.
    raise value
  File "/usr/local/lib/python3.10/dist-packages/sentry_sdk/integrations/threading.py", line 70, in run
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 585, in run
    catch_up(self.api_db, self.ledger_db)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 465, in catch_up
    parse_event(api_db, next_event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 448, in parse_event
    event["insert_rowid"] = execute_event(api_db, event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 435, in execute_event
    sql, sql_bindings = event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 140, in event_to_sql
    return update_event_to_sql(event)
  File "/usr/local/lib/python3.10/dist-packages/counterpartycore/lib/api/api_watcher.py", line 128, in update_event_to_sql
    sql_bindings.append(event_bindings[id_field_name])
KeyError: 'tx_hash'
2024-07-05T07:55:45.854681000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
2024-07-05T07:55:45.905782000+00:00 - [   DEBUG] - Creating connection to `/data/counterparty/counterparty.testnet.api.db`...
2024-07-05T07:55:45.956313000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:55:45.957286000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
2024-07-05T07:55:46.058273000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:55:46.060379000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
2024-07-05T07:55:46.072156939+00:00 - [   DEBUG] - RS Fetcher - Timedout waiting for block at index 2866200 to be written Retrying after error: BlockNotWritten(2866200)
2024-07-05T07:55:46.162091000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:55:46.162908000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
2024-07-05T07:55:46.263891000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:55:46.264692000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
2024-07-05T07:55:46.365700000+00:00 - [ WARNING] - Prefetch queue is empty.
2024-07-05T07:55:46.366480000+00:00 - [   DEBUG] - Block 2866200 not found in prefetch queue. Waiting...
adamkrellenstein commented 1 week ago

Unable to reproduce :/