Polling crashing when attempting to poll chaintips of invalid block

[losh11]

The node poller, polls getchaintips and handles this info. However when a node's response to getchaintips includes a block where the status is invalid, it crashes with error about not being able to find the block on disk.

Example response of getchaintips:

...
{
    "height": 2216081,
    "hash": "df4692279ce71d76965b92f1d55624a7f0c8870e731636da5585959873e1bcc6",
    "branchlen": 81,
    "status": "invalid"
},

Crash stack trace:

I, [2022-02-26T23:45:52.211654 #66157]  INFO -- : RPC getblock df4692279ce71d76965b92f1d55624a7f0c8870e731636da5585959873e1bcc6 1 on TBTC poopynode (id=1)
D, [2022-02-26T23:45:52.213537 #66157] DEBUG -- : ETHON: performed EASY effective_url=http://127.0.0.1:18335/ response_code=500 return_code=ok total_time=0.000788
#<Thread:0x00007f87f4093bd8 /home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:140 run> terminated with exception (report_on_exception is true):
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:90:in `parse_body': code: `500`; return_code: `ok`; body: `{"result":null,"error":{"code":-1,"message":"Block not found on disk"},"id":"jsonrpc"} (Bitcoiner::Client::JSONRPCError)
`
	from /home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:75:in `single_request'
	from /home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:37:in `request'
	from /home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:302:in `request'
	from /home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:140:in `block (2 levels) in getblock'
rake aborted!
BitcoinUtil::RPC::BlockNotFoundError: BitcoinUtil::RPC::BlockNotFoundError
/home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:148:in `rescue in getblock'
/home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:138:in `getblock'
/home/forkmonitor/forkmonitor/app/models/concerns/rpc_concern.rb:40:in `getblock'
/home/forkmonitor/forkmonitor/app/models/block.rb:594:in `find_or_create_block_and_ancestors!'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:134:in `process_chaintip_result'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:142:in `block in process_getchaintips'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:141:in `each'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:141:in `process_getchaintips'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:185:in `block (2 levels) in check!'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:184:in `collect'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:184:in `block in check!'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/transaction.rb:310:in `block in within_new_transaction'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/transaction.rb:308:in `within_new_transaction'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/activerecord-6.1.3.2/lib/active_record/transactions.rb:209:in `transaction'
/home/forkmonitor/forkmonitor/app/models/chaintip.rb:183:in `check!'
/home/forkmonitor/forkmonitor/app/models/node.rb:692:in `check_chaintips!'
/home/forkmonitor/forkmonitor/app/models/node.rb:464:in `poll!'
/home/forkmonitor/forkmonitor/lib/tasks/nodes.rake:6:in `block (2 levels) in <main>'

Caused by:
Bitcoiner::Client::JSONRPCError: code: `500`; return_code: `ok`; body: `{"result":null,"error":{"code":-1,"message":"Block not found on disk"},"id":"jsonrpc"}
`
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:90:in `parse_body'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:75:in `single_request'
/home/forkmonitor/.rvm/gems/ruby-3.0.1/gems/bitcoiner-0.2.1/lib/bitcoiner/client.rb:37:in `request'
/home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:302:in `request'
/home/forkmonitor/forkmonitor/app/services/bitcoin_client.rb:140:in `block (2 levels) in getblock'
Tasks: TOP => nodes:poll
(See full trace by running task with --trace)

From what I understand this should be handled here, but initially check should be made if block is valid, and then get block should be run, if getblock responds with error, this should be handled correctly. https://github.com/BitMEXResearch/forkmonitor/blob/ad8dbf6ac5a5f2a67474de3e7d1503bc8b1d1239/app/models/chaintip.rb#L111

[Sjors]

I'd have to look at the code close, but perhaps we should check first if the node actually has this block. Or indeed just catch the error if it doesn't. You'd have to wrap the call in something like:

begin
  getblock...
catch BitcoinUtil::RPC::BlockNotFoundError
   # Node may not have the full invalid block if it only checked the header.
end