Bug subsquid

Je déplace ici la suite du sujet pour historique.

gdev-squid.axiom-team.fr est à la ramasse par rapport à squid.gdev.coinduf.eu

@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:

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 :slight_smile:

1 Like

J’ai à nouveau rencontré cette erreur, ça devient urgent que je mette à jour subsquid. D’autre part, j’ai rencontré un autre bug que je mets là en attendant de pouvoir investiguer :

processor-1  | {"level":2,"time":1725622862991,"ns":"sqd:processor:mapping","msg":"2920654 Identity.IdtyCreated"}
processor-1  | {"level":2,"time":1725622862993,"ns":"sqd:processor:mapping","msg":"2920654 Account.AccountLinked"}
processor-1  | {"level":2,"time":1725622862994,"ns":"sqd:processor:mapping","msg":"2920654 Certification.CertAdded"}
processor-1  | {"level":5,"time":1725622863077,"ns":"sqd:processor","err":{"stack":"QueryFailedError: duplicate key value violates unique constraint \"REL_bafa9e6c71c3f69cef6602a809\"\n    at PostgresQueryRunner.query (/squid/node_modules/.pnpm/typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5/node_modules/typeorm/driver/postgres/PostgresQueryRunner.js:219:19)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at async InsertQueryBuilder.execute (/squid/node_modules/.pnpm/typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5/node_modules/typeorm/query-builder/InsertQueryBuilder.js:106:33)\n    at async StoreWithCache.insert (/squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5_/node_modules/@subsquid/typeorm-store/lib/store.js:88:17)\n    at async /squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.20_ioredis@5.4.1_pg@_yb6gpcigrhh2fl26pnhshf3tbu/node_modules/@belopash/typeorm-store/lib/store.js:219:21","query":"INSERT INTO \"identity\"(\"id\", \"index\", \"name\", \"status\", \"created_on\", \"last_change_on\", \"smith_status\", \"is_member\", \"expire_on\", \"account_id\", \"created_in_id\") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11)","parameters":["0002920654-af135-000002",14584,"0002920654-af135-000002","Unconfirmed",2920654,2920654,null,false,2935054,"5DSF5HxiQvy2xJdtdtMSPYZdSoLAsGDxzJaifiAfAByinrH4","0002920654-af135-000002"],"driverError":{"stack":"error: duplicate key value violates unique constraint \"REL_bafa9e6c71c3f69cef6602a809\"\n    at /squid/node_modules/.pnpm/pg@8.11.5/node_modules/pg/lib/client.js:526:17\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at async PostgresQueryRunner.query (/squid/node_modules/.pnpm/typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5/node_modules/typeorm/driver/postgres/PostgresQueryRunner.js:184:25)\n    at async InsertQueryBuilder.execute (/squid/node_modules/.pnpm/typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5/node_modules/typeorm/query-builder/InsertQueryBuilder.js:106:33)\n    at async StoreWithCache.insert (/squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.20_ioredis@5.4.1_pg@8.11.5_/node_modules/@subsquid/typeorm-store/lib/store.js:88:17)\n    at async /squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.20_ioredis@5.4.1_pg@_yb6gpcigrhh2fl26pnhshf3tbu/node_modules/@belopash/typeorm-store/lib/store.js:219:21","length":278,"name":"error","severity":"ERROR","code":"23505","detail":"Key (account_id)=(5DSF5HxiQvy2xJdtdtMSPYZdSoLAsGDxzJaifiAfAByinrH4) already exists.","schema":"public","table":"identity","constraint":"REL_bafa9e6c71c3f69cef6602a809","file":"nbtinsert.c","line":"664","routine":"_bt_check_unique"},"length":278,"severity":"ERROR","code":"23505","detail":"Key (account_id)=(5DSF5HxiQvy2xJdtdtMSPYZdSoLAsGDxzJaifiAfAByinrH4) already exists.","schema":"public","table":"identity","constraint":"REL_bafa9e6c71c3f69cef6602a809","file":"nbtinsert.c","line":"664","routine":"_bt_check_unique"}}

En résultat, mon indexeur est bloqué au bloc 2920649.

Cet autre bug est attendu. Au bloc 2920654, j’ai essayé de créer une nouvelle identité pour le compte 5DSF5HxiQvy2xJdtdtMSPYZdSoLAsGDxzJaifiAfAByinrH4 qui avait déjà porté une identité. D’un point de vue protocole on ne souhaite pas que ça arrive, mais il n’y a pas vraiment d’intérêt à l’empêcher, donc il faut juste gérer ce cas particulier côté squid.

[edit]

En fait non, j’ai tenté de créer plusieurs fois une identité pour cette clé. Une fois au bloc 2192620 et une deuxième au bloc 2920654. Les identités ne sont pas supprimées côté indexeur, simplement marquées comme “removed”, ce qui est à l’origine du bug.
Ce serait intéressant de conserver un historique des tentatives de création d’identité pour une certaine clé, d’autant plus que des certifications peuvent exister simultanément vers les multiples identités successives associées à une même clé (lié à Durée du dossier d'adhésion).

Ce bug n’est pas évident à résoudre :

  1. si on supprime l’ancienne identité il faut aussi supprimer les certifications qui pointent vers elle, ce qui limite l’intérêt de l’indexeur
  2. si on veut créer une nouvelle identité pour le même compte, ça impose de retirer la contrainte @unique qui est très pratique (un compte ne peut être associé qu’à zéro ou une identité)
  3. si on rend nullable le champ account de identity, ça complique un peu la logique côté client puisqu’il n’est plus garanti qu’une identité soit associée à un compte

Si quelqu’un a une solution astucieuse, je suis preneur :thinking:

Pour choisir le moindre mal, voici les conséquences des trois propositions ci-dessus :

  1. Dans ce cas, on perd la trace des certifications émises vers des identités qui n’ont pas abouti, ce qui rend difficile l’explication de certains phénomènes. Exemple : je certifie qqun qui est sur le point de perdre son dossier d’adhésion, ce qui supprime ma certification, et je ne comprends alors pas pourquoi je ne peux plus certifier dans les cinq jours, puisque la trace a disparu.
  2. Dans ce cas, les développeurs de clients doivent gérer le cas rare où un compte est associé à plusieurs identités, dont au plus une n’a pas le statut “removed”. Ça veut dire que dans une requête graphql, account.identity est une liste (0, 1 ou plus éléments) et plus un élément nullable (0 ou 1 élément).
  3. Dans ce cas, les développeurs de clients doivent gérer le cas où une identité n’est pas associée à un compte. Ceci n’est censé arriver que pour les identité “removed”, mais il devient alors plus compliqué d’afficher quelle est la clé publique associée à cette identité.

Vu les conséquences, je vais adopter la solution 3.

1 Like

J’ai corrigé le bug en local, publié des images en version 0.2.2, je lance une synchro sur mon nœud, et quand j’estime que ça marche, je tag cette version comme latest, et je préviens pour que les autres puissent mettre à jour leur nœud. Il restera toujours la #32 à résoudre pour améliorer la stabilité, mais c’est déjà une grosse amélioration par rapport à une version buguée !!

2 Likes

Si je comprends bien, seul le choix 2 permet d’avoir un historique des identités “removed” dans squid ?

1 Like

Non, en implémentant le choix 3, j’ai ajouté un champ “removedIdentities” qui permet de quand même avoir cet historique schema.graphql · main · nodes / duniter-squid · GitLab. Je l’ai juste mis dans un champ à part pour éviter de perdre les avantages de la contrainte @unique.

2 Likes