docker logs indexer 2>&1 | grep -C 10 LATEST_KNOWN_LOST
++ echo '[220,50,13,108,195,124,128,118,142,194,14,202,135,249,184,166,123,99,135,164,78,155,198,172,185,155,122,105,163,231,220,67,172,81,251,248,161,189,168,240,146,0,77,214,220,232,225,117,35,102,177,173,194,242,83,50,143,147,218,252,23,72,219,5]'
++ EXTRA_ARGS_TIMEOUT=' --timeout 300'
++ EXTRA_ARGS+=' --timeout 300'
+++ mktemp -d
++ export PROMETHEUS_MULTIPROC_DIR=/tmp/tmp.ersMhyYSnT
++ PROMETHEUS_MULTIPROC_DIR=/tmp/tmp.ersMhyYSnT
+ python3 -m proxy
{"level": "INFO", "date": "2023-05-08T20:03:38.583147", "module": "indexer_app.py:23", "process": 13, "message": "Running indexer with params: <proxy.common_neon.config.Config object at 0x7fe58e33d3a0>"}
Will run in indexer mode
{"level": "INFO", "date": "2023-05-08T20:03:38.588026", "module": "pickable_data_server.py:70", "process": 15, "message": "Listen port: 9093 on: 0.0.0.0"}
{"level": "INFO", "date": "2023-05-08T20:03:38.755316", "module": "indexer_base.py:31", "process": 13, "message": "Starting receipt slot with LATEST_KNOWN_LOST=16465346 and START_SLOT=0"}
{"level": "INFO", "date": "2023-05-08T20:03:38.755527", "module": "indexer_base.py:52", "process": 13, "message": "START_SLOT=0: started the receipt slot from previous run, because 0 < 16465346"}
{"level": "INFO", "date": "2023-05-08T20:03:38.761988", "module": "middleware.py:129", "process": 13, "message": "Init statistic middleware client, enabled: True"}
{"level": "WARNING", "date": "2023-05-08T20:03:40.978174", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "JQYQ93m_16465364_2", "ident": "JQYQ93m_16465364", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:03:46.500047", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "3wtqmGv_16465508_2", "ident": "3wtqmGv_16465508", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:03:52.060452", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "egESYHx_16465585_2", "ident": "egESYHx_16465585", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:03:57.544210", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "GMAto1Z_16465694_2", "ident": "GMAto1Z_16465694", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:04:02.686193", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "6DieWJ4_16465846_2", "ident": "6DieWJ4_16465846", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:04:09.022839", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "5jVsEpG_16466033_2", "ident": "5jVsEpG_16466033", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
{"level": "WARNING", "date": "2023-05-08T20:04:13.675459", "module": "indexer_base.py:67", "process": 13, "message": "Exception on transactions processing.", "sol_neon_ix": "L5WPHWU_16466087_2", "ident": "L5WPHWU_16466087", "exc_info": {"type": "<class 'AssertionError'>", "exception": "the tx {key} already in use!", "traceback": ["File '/opt/proxy/indexer/indexer_base.py', line 65, in run self.process_functions()", "File '/opt/proxy/indexer/indexer.py', line 317, in process_functions self._run_sol_tx_collector(state, 0)", "File '/opt/proxy/indexer/indexer.py', line 286, in _run_sol_tx_collector sol_neon_ix_decoder.execute()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 250, in execute return self._decode_tx('NeonTx exec from SolIx.Data')", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 223, in _decode_tx tx: Optional[NeonIndexedTxInfo] = self._add_neon_indexed_tx()", "File '/opt/proxy/indexer/neon_ix_decoder.py', line 94, in _add_neon_indexed_tx return block.add_neon_tx(tx_type, neon_tx, holder_account, iter_blocked_account, ix)", "File '/opt/proxy/indexer/indexed_objects.py', line 406, in add_neon_tx assert key.value not in self._neon_tx_dict, 'the tx {key} already in use!'"]}}
Latest DB Values (a few minutes later because indexer was running actively)
The values above seem weird or out of sync. latest_block_slot > latest_processed_slot and min_receipt_block_slot and finalized_block_slot are both further behind than that. start_block_slot was also wrong because it started at 16465346 as indicated in the log. Also since the indexer is redoing work that is previously done it keeps getting transaction processing exceptions. Sometimes it can continue, but sometimes it get stuck in infinite loop, throwing same error on the same slot.
Indexer does not save the last worked on slot so when indexer restarts due to exception or other reasons, it starts from way back in the past.
Latest block from Neon Proxy RPC: 16529318
Latest according to indexer: 16465346
Latest DB Values (a few minutes later because indexer was running actively)
Converted to Human Readable:
The values above seem weird or out of sync. latest_block_slot > latest_processed_slot and min_receipt_block_slot and finalized_block_slot are both further behind than that. start_block_slot was also wrong because it started at 16465346 as indicated in the log. Also since the indexer is redoing work that is previously done it keeps getting transaction processing exceptions. Sometimes it can continue, but sometimes it get stuck in infinite loop, throwing same error on the same slot.