@HugoTrentesaux Voici les logs pertinents, du processor:
duniter-squid-processor-1 | {"level":2,"time":1720554246107,"ns":"sqd:processor","msg":"2169697 / 2169697, rate: 0 blocks/sec, mapping: 43 blocks/sec, 129 items/sec, eta: 0s"}
duniter-squid-processor-1 | {"level":2,"time":1720554252211,"ns":"sqd:processor","msg":"2169698 / 2169698, rate: 0 blocks/sec, mapping: 43 blocks/sec, 130 items/sec, eta: 0s"}
duniter-squid-processor-1 | {"level":2,"time":1720554264256,"ns":"sqd:processor","msg":"2169699 / 2169699, rate: 0 blocks/sec, mapping: 31 blocks/sec, 93 items/sec, eta: 0s"}
duniter-squid-processor-1 | {"level":2,"time":1720554708561,"ns":"sqd:processor","msg":"2169707 / 2169707, rate: 0 blocks/sec, mapping: 25 blocks/sec, 75 items/sec, eta: 0s"}
duniter-squid-processor-1 | {"level":5,"time":1720554708768,"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)"}}
Ce sont les dernier logs du processor, rien après.
Zoom sur l’erreur:
{
"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)"
}
On remarque qu’il traite les block les un à la suite des autres, jusqu’au block 2169699
où il saute directement au block 2169707
.
Issue déjà ouverte par moi même à ce sujet, fermé depuis mais tu constatera dans les commentaires que j’avais bien sentie que ça avait été fermé un peu au pif:
opened 01:33AM - 07 Mar 24 UTC
closed 05:12PM - 26 Jun 24 UTC
My subsquid node processor crashed with this logs:
```
duniter-squid-process… or-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)"}}
```
Error: `[ERR_ASSERTION]: The expression evaluated to a falsy value:\n\n (0, assert_1.default)(head.height >= this.chain[0].height)`
It look likes it missed 8 higher blocks, between `435163` and `435172`, which is the cause of this error.
This 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`
---
We observe that the problem occurs exactly at midnight, which would be a strange 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
```
We also notice a gap of 6 minutes and 48 seconds between block 435163 and 435172, whereas only 48 seconds should have passed.
---
Disturbingly, the missing blocks in the logs seem to be present in the DB, and correctly dated:
```
{
"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"
}
]
}
}
```
Here a simple processor restart solve the problem, but whatever the cause of the problem, processor should be able to recover using its checkpoints, without manual restart.
Version: `"@subsquid/substrate-processor": "^8.1.1"`
La dernière fois c’était 9 block de sautés, cette fois ci 8 block.
J’ai donc relancé @belopash sur ce sujet.
edit: qui m’a répondu en moins de 5 minutes: Processor crashed with missing blocks despite correct DB entries · Issue #253 · subsquid/squid-sdk · GitHub
Il utilise VSCode, cet homme a du goût.
Donc il faut mettre à jour squid.
cc @bgallois étant donné que je vois dans les commits que tu bosses sur squid en ce moment