Crash processor: [ERR_ASSERTION]: The expression evaluated to a falsy value: (0, assert_1.default)(head.height >= this.chain[0].height)

My subsquid node processor crashed with this logs:

duniter-squid-processor-1     | {"level":2,"time":1709683102158,"ns":"sqd:processor","msg":"435146 / 435146, rate: 0 blocks/sec, mapping: 71 blocks/sec, 212 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683107158,"ns":"sqd:processor","msg":"435147 / 435147, rate: 0 blocks/sec, mapping: 69 blocks/sec, 208 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683112158,"ns":"sqd:processor","msg":"435148 / 435148, rate: 0 blocks/sec, mapping: 70 blocks/sec, 210 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683117157,"ns":"sqd:processor","msg":"435149 / 435149, rate: 0 blocks/sec, mapping: 73 blocks/sec, 218 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683122287,"ns":"sqd:processor","msg":"435150 / 435150, rate: 0 blocks/sec, mapping: 45 blocks/sec, 136 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683128168,"ns":"sqd:processor","msg":"435151 / 435151, rate: 0 blocks/sec, mapping: 48 blocks/sec, 144 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683134763,"ns":"sqd:processor","msg":"435152 / 435152, rate: 0 blocks/sec, mapping: 47 blocks/sec, 142 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683140126,"ns":"sqd:processor","msg":"435153 / 435153, rate: 0 blocks/sec, mapping: 47 blocks/sec, 141 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683146170,"ns":"sqd:processor","msg":"435154 / 435154, rate: 0 blocks/sec, mapping: 46 blocks/sec, 137 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683152090,"ns":"sqd:processor","msg":"435155 / 435155, rate: 0 blocks/sec, mapping: 80 blocks/sec, 239 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683158108,"ns":"sqd:processor","msg":"435156 / 435156, rate: 0 blocks/sec, mapping: 77 blocks/sec, 231 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683164127,"ns":"sqd:processor","msg":"435157 / 435157, rate: 0 blocks/sec, mapping: 81 blocks/sec, 243 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683170090,"ns":"sqd:processor","msg":"435158 / 435158, rate: 0 blocks/sec, mapping: 82 blocks/sec, 245 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683176077,"ns":"sqd:processor","msg":"435159 / 435159, rate: 0 blocks/sec, mapping: 85 blocks/sec, 254 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683182174,"ns":"sqd:processor","msg":"435160 / 435160, rate: 0 blocks/sec, mapping: 86 blocks/sec, 259 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683188188,"ns":"sqd:processor","msg":"435161 / 435161, rate: 0 blocks/sec, mapping: 91 blocks/sec, 274 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683194091,"ns":"sqd:processor","msg":"435162 / 435162, rate: 0 blocks/sec, mapping: 90 blocks/sec, 270 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683200099,"ns":"sqd:processor","msg":"435163 / 435163, rate: 0 blocks/sec, mapping: 90 blocks/sec, 269 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":2,"time":1709683608909,"ns":"sqd:processor","msg":"435172 / 435172, rate: 0 blocks/sec, mapping: 138 blocks/sec, 415 items/sec, eta: 0s"}
duniter-squid-processor-1     | {"level":5,"time":1709683609149,"ns":"sqd:processor","err":{"generatedMessage":true,"code":"ERR_ASSERTION","actual":false,"expected":true,"operator":"==","stack":"AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:\n\n  (0, assert_1.default)(head.height >= this.chain[0].height)\n\n    at HotProcessor.moveToBlocks (/squid/node_modules/@subsquid/util-internal-ingest-tools/lib/hot.js:60:30)\n    at HotProcessor.goto (/squid/node_modules/@subsquid/util-internal-ingest-tools/lib/hot.js:38:24)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at async RpcDataSource.handleNewHeads (/squid/node_modules/@subsquid/substrate-data-raw/lib/datasource.js:213:24)\n    at async RpcDataSource.subscription (/squid/node_modules/@subsquid/substrate-data-raw/lib/datasource.js:198:25)\n    at async RpcDataSource.processHotBlocks (/squid/node_modules/@subsquid/substrate-data-raw/lib/datasource.js:113:13)"}}

(Thanks to ĞCli indexer check command)

It look likes it missed 8 higher blocks, between 435163 and 435172, which is the cause of this error.

This is indexer is listening a local duniter v2s archive node.

indexer enpoind: https://gdev-squid.axiom-team.fr/v1/graphql

duniter endpoint: wss://gdev.p2p.legal/ws

On observe que le problème intervient à minuit pile, ce qui serait une étrange coincidence:

Bloc 435160 : 2024-03-05 23:59:42
Bloc 435161 : 2024-03-05 23:59:48
Bloc 435162 : 2024-03-05 23:59:54
Bloc 435163 : 2024-03-06 00:00:00
Bloc 435172 : 2024-03-06 00:06:48

On remarque également un trou de 6 minutes et 48 secondes entre le bloc 435163 et 435172, alors qu'il n'aurait dû s'écouler que 48 secondes.

Fait perturbant, les blocks manquants dans les logs semblent être présents en DB, et correctement datés:

{
  "data": {
    "block": [
      {
        "height": 435172,
        "timestamp": "2024-03-06T00:01:06+00:00"
      },
      {
        "height": 435171,
        "timestamp": "2024-03-06T00:01:00+00:00"
      },
      {
        "height": 435170,
        "timestamp": "2024-03-06T00:00:54.001+00:00"
      },
      {
        "height": 435169,
        "timestamp": "2024-03-06T00:00:48.002+00:00"
      },
      {
        "height": 435168,
        "timestamp": "2024-03-06T00:00:42+00:00"
      },
      {
        "height": 435167,
        "timestamp": "2024-03-06T00:00:24+00:00"
      },
      {
        "height": 435166,
        "timestamp": "2024-03-06T00:00:18+00:00"
      },
      {
        "height": 435165,
        "timestamp": "2024-03-06T00:00:12.001+00:00"
      },
      {
        "height": 435164,
        "timestamp": "2024-03-06T00:00:06.001+00:00"
      },
      {
        "height": 435163,
        "timestamp": "2024-03-06T00:00:00.001+00:00"
      },
      {
        "height": 435162,
        "timestamp": "2024-03-05T23:59:54+00:00"
      },
      {
        "height": 435161,
        "timestamp": "2024-03-05T23:59:48+00:00"
      },
      {
        "height": 435160,
        "timestamp": "2024-03-05T23:59:42.001+00:00"
      },
      {
        "height": 435159,
        "timestamp": "2024-03-05T23:59:36.001+00:00"
      },
      {
        "height": 435158,
        "timestamp": "2024-03-05T23:59:30.001+00:00"
      }
    ]
  }
}

Edited Mar 07, 2024 by poka