Squid: soucis démarrage de zero pour image 0.5.6

@poka pendant le dernier dev talk ce 2 janvier, on a remarqué avec @BulmAnanaBelle qu’il n’y a pas moyen de démarrer correctement un serveur Squid depuis zero avec l’image 0.5.6.

Je viens de tester en local pour voir; et effectivement; autant j’arrive bien à démarrer de zero avec la 0.5.5; autant avec la 0.5.6 ça plante très rapidement au démarrage:

docker compose up -d  
[+] up 5/5
 ✔ Network duniter-gtest-squid_default       Created                                                                                                                                                                                     0.0s 
 ✔ Volume duniter-gtest-squid_postgres-data  Created                                                                                                                                                                                     0.0s 
 ✔ Container duniter-gtest-squid-db-1        Healthy                                                                                                                                                                                     5.7s 
 ✘ Container duniter-gtest-squid-processor-1 Error dependency processor failed to start                                                                                                                                                  7.7s 
 ✔ Container duniter-gtest-squid-server-1    Created                                                                                                                                                                                     0.0s 
dependency failed to start: container duniter-gtest-squid-processor-1 exited (1)

Et les logs:

processor-1  | {"level":2,"time":1767787126744,"ns":"sqd:processor:mapping","msg":"Flushing changes to storage, this can take a while..."}
processor-1  | {"level":2,"time":1767787126744,"ns":"sqd:processor:mapping","msg":"(about ~5 minutes for all g1 history and genesis data)"}
processor-1  | {"level":2,"time":1767787126767,"ns":"sqd:processor:mapping","msg":"Genesis flushed"}
processor-1  | {"level":2,"time":1767787126767,"ns":"sqd:processor:mapping","msg":"====================="}
processor-1  | {"level":2,"time":1767787126767,"ns":"sqd:processor:mapping","msg":"Starting blockchain indexing with 5 smiths, 9 members and 9 accounts!"}
processor-1  | {"level":5,"time":1767787126787,"ns":"sqd:processor","err":{"stack":"EntityNotFoundError: Could not find any entity of type \"Validator\" matching: {\n    \"id\": \"g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz\"\n}\n    at /squid/node_modules/.pnpm/typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2/node_modules/typeorm/entity-manager/EntityManager.js:682:39\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at async StoreWithCache.findOneByOrFail (/squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.26_ioredis@5.7_0562d5ed8c2d447272b97a9e909772f4/node_modules/@belopash/typeorm-store/lib/store.js:153:21)\n    at async DataHandler.processNewData (/squid/lib/data_handler.js:352:31)\n    at async /squid/lib/main.js:85:5\n    at async TypeormDatabaseWithCache.performUpdates (/squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.26_ioredis@5.7_0562d5ed8c2d447272b97a9e909772f4/node_modules/@belopash/typeorm-store/lib/database.js:45:13)\n    at async /squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2_/node_modules/@subsquid/typeorm-store/lib/database.js:84:13\n    at async EntityManager.transaction (/squid/node_modules/.pnpm/typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2/node_modules/typeorm/entity-manager/EntityManager.js:75:28)\n    at async TypeormDatabaseWithCache.submit (/squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2_/node_modules/@subsquid/typeorm-store/lib/database.js:164:24)\n    at async Runner.withProgressMetrics (/squid/node_modules/.pnpm/@subsquid+util-internal-processor-tools@4.2.1/node_modules/@subsquid/util-internal-processor-tools/lib/runner.js:217:22)","criteria":{"id":"g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz"},"message":"Could not find any entity of type \"Validator\" matching: {\n    \"id\": \"g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz\"\n}"}}

Et la dernière ligne d’erreur en un peu plus lisible:

{
    "level": 5,
    "time": 1767787126787,
    "ns": "sqd:processor",
    "err": {
        "stack": "EntityNotFoundError: Could not find any entity of type \"Validator\" matching: {\n    \"id\": \"g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz\"\n}\n    at /squid/node_modules/.pnpm/typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2/node_modules/typeorm/entity-manager/EntityManager.js:682:39\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at async StoreWithCache.findOneByOrFail (/squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.26_ioredis@5.7_0562d5ed8c2d447272b97a9e909772f4/node_modules/@belopash/typeorm-store/lib/store.js:153:21)\n    at async DataHandler.processNewData (/squid/lib/data_handler.js:352:31)\n    at async /squid/lib/main.js:85:5\n    at async TypeormDatabaseWithCache.performUpdates (/squid/node_modules/.pnpm/@belopash+typeorm-store@1.5.0_@subsquid+typeorm-config@4.1.1_typeorm@0.3.26_ioredis@5.7_0562d5ed8c2d447272b97a9e909772f4/node_modules/@belopash/typeorm-store/lib/database.js:45:13)\n    at async /squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2_/node_modules/@subsquid/typeorm-store/lib/database.js:84:13\n    at async EntityManager.transaction (/squid/node_modules/.pnpm/typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2/node_modules/typeorm/entity-manager/EntityManager.js:75:28)\n    at async TypeormDatabaseWithCache.submit (/squid/node_modules/.pnpm/@subsquid+typeorm-store@1.5.1_@subsquid+big-decimal@1.0.0_typeorm@0.3.26_ioredis@5.7.0_pg@8.16.3_reflect-metadata@0.2.2_/node_modules/@subsquid/typeorm-store/lib/database.js:164:24)\n    at async Runner.withProgressMetrics (/squid/node_modules/.pnpm/@subsquid+util-internal-processor-tools@4.2.1/node_modules/@subsquid/util-internal-processor-tools/lib/runner.js:217:22)",
        "criteria": {
            "id": "g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz"
        },
        "message": "Could not find any entity of type \"Validator\" matching: {\n    \"id\": \"g1PH3gQ4n53EqpcLVLtG77jRRo71tLUjvDYcm87MENkAa1NPz\"\n}"
    }
}
3 Likes

Il semble que la CI ne fonctionne plus depuis ce commit :

Le bug étant assez “énorme” et simple a corriger, on peut se demander si ce n’était pas pour bloquer les builds temporairement.

Et la pipeline du build de la version 5.6 a échouée. Donc je ne sais pas d’où vient l’image 5.6 si elle ne vient pas du build automatique de Gitlab. Peut-être une version poussée par @poka.

1 Like

Avec Nicolas, nous avons également rencontré ce problème bloquant avec la v0.5.6 sur l’infra Duniter. Le log est différent et pas aussi précis :

Feb 02 17:18:28 kepler systemd[1]: Starting docker-indexer-processor.service...
Feb 02 17:18:28 kepler pre-start[1177572]: Error response from daemon: No such container: indexer-processor
Feb 02 17:18:28 kepler systemd[1]: Started docker-indexer-processor.service.
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]: {"level":2,"time":1770052708681,"ns":"sqd:commands","msg":"MIGRATION:COPY-CUSTOM"}
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]: {"level":2,"time":1770052708688,"ns":"sqd:commands","msg":"MIGRATION:APPLY"}
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]: Error: connect ECONNREFUSED 172.18.0.2:5432
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1611:16) {
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:   errno: -111,
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:   code: 'ECONNREFUSED',
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:   syscall: 'connect',
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:   address: '172.18.0.2',
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]:   port: 5432
Feb 02 17:18:28 kepler docker-indexer-processor-start[1177594]: }
Feb 02 17:18:28 kepler systemd[1]: docker-indexer-processor.service: Main process exited, code=exited, status=1/FAILURE
Feb 02 17:18:29 kepler docker-indexer-processor-post-stop[1178054]: Error response from daemon: No such container: indexer-processor
Feb 02 17:18:29 kepler systemd[1]: docker-indexer-processor.service: Failed with result 'exit-code'.

Entre la v0.5.5 et la v0.5.6 il n’y a que ce commit. Ça concerne le processor (Squid) ou le server (Postgraphile) ?

2 Likes

Hello,

Juste pour noter que j’ai bien vue ce topic, je n’ai juste pas eu le temps de me remettre sur squid depuis.
Là je vais pas être trop dispo cette semaine, je devrais pouvoir trouver du temps la semaine prochaine.
Mais en attendant, si jamais l’âme vous en dis, et que vous voulez mettre les mains dans squid pour diag ça, c’est avec grand plaisir :slight_smile:

Hugo et moi on se fera un plaisir de répondre à vos question concernant le mode dev de squid.

Merci pour vos tests !

3 Likes

Un fix pour la db exposé sur le net. Et retour à la v0.5.5 en attendant.

1 Like

La version 0.5.8 corrige ça, dites moi si c’est ok.

Le problème n’était pas du tout lié à ce que vous avez diagnostiqué: En fait j’avais par inadvertance build cette image avec les mauvaises donnée genenis en input/, c’était les données de mock…

Du coup pour éviter que ça se reproduise, j’ai ajouté une vérification au début du script de build docker:

poka@pokaBook duniter-squid % ./scripts/build-and-push-squid.sh
Validating genesis data...


============================================
  GENESIS DATA VALIDATION
============================================

  Network:        ĞTest (gtest)
  Chain type:     Live

  Genesis file:   ./input/gtest.json (22.4 MB)
  Accounts:       44,172
  Identities:     17,400
  Members:        7,589
  Certifications: 92,716
  Smiths:         13

  V1 History:
  Last v1 block:  872,134
  Block history:  872,135 entries (275.6 MB)
  Cert history:   38.6 MB
  Tx history:     174.0 MB

  UD params:      1148 ĞD, reeval at 1766232000

  Checks:
  [OK] Network is 'ĞTest' (not mock)
  [OK] Identities count = 17,400 (> 100)
  [OK] genesis.json present
  [OK] current_block.number = 872,134 (matches block_hist)
  [OK] All history files present and non-empty

============================================

Continue with these genesis data? (y/N)

Pour être propore il faudrait dans l’absolu faire ces builds en CI et pull les fichiers genesis depuis les artefacts de CI à chaque fois (il y a un script pour ça).
Mais je ne le ferais pas.

3 Likes

Cela fonctionne correctement :slight_smile:

Pas de soucis en démarrant de zéro, et cela synchronise bien les blocks - testé également la query pour la version & le dernier block depuis l’interface graphiql.

3 Likes