Je remarque ce matin que plusieurs nœuds semblent « bloqués » dans un fork, sans raison valable.
Redémarrer le nœud suffit à débloquer la situation.
cc @MarcelDoppagne (pour le nœud Adélaïde), @Inso, @guenoel, @dom, @Vincent_Rousseau
Plusieurs miroirs sont aussi impactés :
J’investigue pour comprendre d’où vient le bug.
Voilà ce que je trouve dans mes logs, en boucle :
2019-05-11T10:50:00+02:00 - info: Block resolution: 0 potential blocks after current#219619...
2019-05-11T10:50:00+02:00 - info: Fork resolution: 20 potential block(s) found...
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:00+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
2019-05-11T10:50:12+02:00 - info: [5cnvo5bm] ⬇ PEER 2ny7YAdm 219606-0
2019-05-11T10:50:12+02:00 - info: [5cnvo5bm] ✔ PEER 2ny7YAdm 219606-0
2019-05-11T10:50:12+02:00 - info: [5cnvo5bm] ⬇ PEER 2ny7YAdm 219606-0
Oui, mais il faut remonter à ce “bloc incorrect” pour comprendre.
C’est à dire ? Tu souhaites un dump de ma db ?
Non, mais dans les logs tu peux remonter jusqu’à trouver d’autres mentions de ce block #219621.
root@yunohost:/opt/g1/.config/duniter/duniter_default# grep -rn 219621 *.log
duniter.log:8448:2019-05-11T09:11:53+02:00 - info: SIDE Block #219621-000005B9 added to the blockchain in 0 ms
duniter.log:8580:2019-05-11T09:14:02+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219621-0
duniter.log:8582:2019-05-11T09:14:02+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219621-0
duniter.log:8584:2019-05-11T09:14:02+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219621-0
duniter.log:8586:2019-05-11T09:14:03+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219621-0
duniter.log:8601:2019-05-11T09:14:16+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219621-0
duniter.log:8603:2019-05-11T09:14:16+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219621-0
duniter.log:8605:2019-05-11T09:14:16+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219621-0
duniter.log:8607:2019-05-11T09:14:17+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219621-0
duniter.log:8683:2019-05-11T09:16:52+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219621-0
duniter.log:8685:2019-05-11T09:16:52+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219621-0
duniter.log:8687:2019-05-11T09:16:52+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219621-0
duniter.log:8689:2019-05-11T09:16:52+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219621-0
duniter.log:8730:2019-05-11T09:17:31+02:00 - info: Block #219621 added to the blockchain in 30 ms
duniter.log:8731:2019-05-11T09:17:31+02:00 - info: Fork resolution: suite 1/1 added block#219621-000005B9943225F80F519ADB022FFFA5623E4BA753565C0354AC3915B3E5A4F4
duniter.log:8746:2019-05-11T09:17:45+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
duniter.log:8747:2019-05-11T09:17:45+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
duniter.log:8751:2019-05-11T09:17:48+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
duniter.log:8752:2019-05-11T09:17:48+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
duniter.log:8753:2019-05-11T09:17:48+02:00 - info: Fork resolution: block #219621-000005B9 is known as incorrect. Skipping.
Dit moi ce que je dois chercher d’autre…
Remonte à ce log, et regarde tout ce qu’il se passe à ce moment-là. Tu auras des infos.
Et si tu n’en n’as toujours pas, fait de même avec le précédent, jusqu’à trouver le moment où l’erreur se produit.
edit : un meilleur mot-clé de recherche est “added”, tu tombes sur tous les blocs ajoutés, que ce soit à leur arrivée, lors de leur résolution sur la branche principale ou pendant un fork.
Alors le comportement a l’air douteux.
2019-05-11T09:11:53+02:00 - ESC[32minfoESC[39m: SIDE Block #219621-000005B9 added to the blockchain in 0 ms
2019-05-11T09:11:53+02:00 - ESC[32minfoESC[39m: Block resolution: 0 potential blocks after current#219619...
2019-05-11T09:12:08+02:00 - ESC[32minfoESC[39m: ⬇ TX 10070:0 from 5UGxjjevfX4vJwH3Q4e76nFEppfXFx6wyKzVBjRK8om5
2019-05-11T09:12:08+02:00 - ESC[32minfoESC[39m: ✔ TX 10070:0 from 5UGxjjevfX4vJwH3Q4e76nFEppfXFx6wyKzVBjRK8om5
2019-05-11T09:12:10+02:00 - ESC[32minfoESC[39m: Matched 3 zeros 000F6F5C5673EF7DD978FD3CE68F7CD4AA12C53108FFF9924C02918BBC6CCBCD with Nonce = 10200000032619 for block#219620 by 5cnvo5
Mon noeud cherche un bloc 219620 alors qu’il a reçu un block 219621. Comme si un block 219620 manquait quelque part…
C’est effectivement bizarre :
duniter.log:7245:2019-05-11T08:42:59+02:00 - info: Generating proof-of-work with 5 leading zeros followed by [0-5]... (CPU usage set to 10%) for block#219620 5cnvo5
duniter.log:7288:2019-05-11T08:43:51+02:00 - info: Matched 3 zeros 000C9EA844643E8DC9BC9021CC36527C8845926CBFBF4A5108AE734558A47881 with Nonce = 10200000001499 for block#219620 by 5cnvo5
duniter.log:7420:2019-05-11T08:46:48+02:00 - info: Matched 3 zeros 0004881446D654B1851798FED7E6B5147D1924E6A97B1991FEBC0907B34163BE with Nonce = 10100000005428 for block#219620 by 5cnvo5
duniter.log:7556:2019-05-11T08:50:50+02:00 - info: Matched 3 zeros 0005848B271D83A49A83A98445FBDC07796443BBB2364F16EF802F76044BD705 with Nonce = 10100000009823 for block#219620 by 5cnvo5
duniter.log:7829:2019-05-11T08:56:39+02:00 - info: Matched 3 zeros 000ADB3F31AE4627A2D98D62F23797AB118D055F9B383118269D95659A74B9CF with Nonce = 10200000016668 for block#219620 by 5cnvo5
duniter.log:7880:2019-05-11T08:58:04+02:00 - info: Matched 3 zeros 000E9817175E417516B38A8B76806C7B0E89B0C7C679556841AA8883F92903E1 with Nonce = 10100000017239 for block#219620 by 5cnvo5
duniter.log:7887:2019-05-11T08:58:46+02:00 - info: Matched 3 zeros 000B6E5225E9E1BB857F7D6EB10DDAEECEFF70C6966993E9D762F638441FB961 with Nonce = 10100000017977 for block#219620 by 5cnvo5
duniter.log:7904:2019-05-11T08:59:34+02:00 - info: Matched 3 zeros 0007A9E6AF0099C7C209E09625871D97C4BACA303ADF4A7751D04CA93F1D2CB4 with Nonce = 10100000018804 for block#219620 by 5cnvo5
duniter.log:8024:2019-05-11T09:01:25+02:00 - info: Matched 3 zeros 00066B65028E0ACBAB282210C4F44B9AE077F846C1EC17847D5EB4063ECC5159 with Nonce = 10200000021565 for block#219620 by 5cnvo5
duniter.log:8135:2019-05-11T09:03:56+02:00 - info: Matched 3 zeros 0007202D7E6CEAD4B2CF2F930C828C2CECA712729E1449CFEE422B7EDFA72F88 with Nonce = 10200000024043 for block#219620 by 5cnvo5
duniter.log:8142:2019-05-11T09:04:09+02:00 - info: Matched 3 zeros 000A8F15CE1671E767AB24242AD68FA86FB7DEA983B3B0EB4EA993B517398FD2 with Nonce = 10200000024316 for block#219620 by 5cnvo5
duniter.log:8151:2019-05-11T09:04:31+02:00 - info: Matched 3 zeros 0005571C371D96D417FAB58AC4A188622F374A9797992C7C5D33A494A99503FD with Nonce = 10200000024719 for block#219620 by 5cnvo5
duniter.log:8159:2019-05-11T09:04:54+02:00 - info: Matched 3 zeros 000F1A5263A5FB2DBA92CC05E6085D572BA7BD544CDBE474F9A989354565A563 with Nonce = 10100000024672 for block#219620 by 5cnvo5
duniter.log:8179:2019-05-11T09:05:26+02:00 - info: Matched 3 zeros 00058DC2DDFECFCFB00F78FCF35253EC7C04C4BF9FD7B90760BBC23C346EE802 with Nonce = 10200000025661 for block#219620 by 5cnvo5
duniter.log:8225:2019-05-11T09:06:53+02:00 - info: SIDE Block #219620-000005E9 added to the blockchain in 1 ms
duniter.log:8228:2019-05-11T09:06:57+02:00 - info: Matched 3 zeros 000770FA2FC1FD826C35F1983F73B33063A446FA68497AD3FC959D989BBDD1EE with Nonce = 10200000027232 for block#219620 by 5cnvo5
duniter.log:8239:2019-05-11T09:07:15+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219620-0
duniter.log:8241:2019-05-11T09:07:15+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219620-0
duniter.log:8243:2019-05-11T09:07:15+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219620-0
duniter.log:8247:2019-05-11T09:07:30+02:00 - info: [5cnvo5bm] ⬇ PEER FEkbc4Bf 219620-0
duniter.log:8299:2019-05-11T09:09:19+02:00 - info: Matched 3 zeros 0009E92CC60E15DD0030710ECEDAA9352FC9BFB384798B5EFEABD1662A8F212D with Nonce = 10200000029650 for block#219620 by 5cnvo5
duniter.log:8330:2019-05-11T09:10:12+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219620-0
duniter.log:8332:2019-05-11T09:10:12+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219620-0
duniter.log:8334:2019-05-11T09:10:12+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219620-0
duniter.log:8336:2019-05-11T09:10:13+02:00 - info: [5cnvo5bm] ⬇ PEER D9D2zaJo 219620-0
duniter.log:8383:2019-05-11T09:10:47+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219620-0
duniter.log:8385:2019-05-11T09:10:47+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219620-0
duniter.log:8387:2019-05-11T09:10:47+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219620-0
duniter.log:8389:2019-05-11T09:10:47+02:00 - info: [5cnvo5bm] ⬇ PEER GfKERHnJ 219620-0
duniter.log:8452:2019-05-11T09:12:10+02:00 - info: Matched 3 zeros 000F6F5C5673EF7DD978FD3CE68F7CD4AA12C53108FFF9924C02918BBC6CCBCD with Nonce = 10200000032619 for block#219620 by 5cnvo5
duniter.log:8460:2019-05-11T09:12:17+02:00 - info: Matched 3 zeros 000D244FF7C65A71E52FF146E36DD1117ED3C25BBE4D8159E59888A9DBD05076 with Nonce = 10100000032388 for block#219620 by 5cnvo5
duniter.log:8461:2019-05-11T09:12:24+02:00 - info: [5cnvo5bm] ⬇ PEER HmH5beJq 219620-0
duniter.log:8463:2019-05-11T09:12:24+02:00 - info: [5cnvo5bm] ⬇ PEER HmH5beJq 219620-0
duniter.log:8465:2019-05-11T09:12:24+02:00 - info: [5cnvo5bm] ⬇ PEER HmH5beJq 219620-0
duniter.log:8483:2019-05-11T09:12:34+02:00 - info: [5cnvo5bm] ⬇ PEER HmH5beJq 219620-0
duniter.log:8516:2019-05-11T09:13:02+02:00 - info: Matched 3 zeros 00094239CFFC77FB3C43BB41006AF7841B4858BEDC65CE005F8D998E75A15EED with Nonce = 10200000033426 for block#219620 by 5cnvo5
duniter.log:8625:2019-05-11T09:14:47+02:00 - info: Matched 3 zeros 0007512BB114A90FD711BAB6D6F75324F4FEA3105854FB289A888E87B002759A with Nonce = 10100000034897 for block#219620 by 5cnvo5
duniter.log:8664:2019-05-11T09:15:57+02:00 - info: Matched 3 zeros 0008F543ED8A522BA3A9443D811F17E14062D2B19C1C56A44B8906CC0C7F2B0F with Nonce = 10200000036432 for block#219620 by 5cnvo5
duniter.log:8709:2019-05-11T09:17:09+02:00 - info: Matched 3 zeros 0003E6EACDBBF4FAA0E870C01FA279FCBA0CFD52B4FFB3D7B444788BFFF3852C with Nonce = 10100000037187 for block#219620 by 5cnvo5
duniter.log:8728:2019-05-11T09:17:30+02:00 - info: Block #219620 added to the blockchain in 24 ms
duniter.log:8729:2019-05-11T09:17:30+02:00 - info: Fork resolution: suite 1/1 added block#219620-000005E9E86D9D0BF7F5C58C2F5FD6A06FD39B50497734E0DF615CA5031DDC7C
duniter.log:8931:2019-05-11T09:21:12+02:00 - info: Matched 3 zeros 000295C2514021D4230DF353F3129B5F239BB95E417B2B84747A278E7CEDBF3C with Nonce = 10200000041842 for block#219620 by 5cnvo5
duniter.log:9181:2019-05-11T09:27:15+02:00 - info: Matched 3 zeros 00024AE130BDC2080157B05074F61B804E93B671B0B26FDE74AE25B0EE270762 with Nonce = 10100000047595 for block#219620 by 5cnvo5
duniter.log:9214:2019-05-11T09:27:57+02:00 - info: Matched 3 zeros 00032A6FF583B030ACBF9C1204BC867FE431E091847DE51028DA2276D65DDA9E with Nonce = 10100000048239 for block#219620 by 5cnvo5
duniter.log:9376:2019-05-11T09:32:17+02:00 - info: Matched 3 zeros 0001E8832618014ACAB5B9BFC543506C254A731420FC62B91013618246B25719 with Nonce = 10100000052625 for block#219620 by 5cnvo5
On voit que le block 219620 est bien reçu, il est ajouté à la chaine, mais mon noeud continue de chercher un 219620 dans son coin.
En fouillant la résolution de fork démarrée au bloc 219620, on observe ça :
019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: SIDE Block #219622-0000021C added to the blockchain in 1 ms
2019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: Block resolution: 0 potential blocks after current#219619...
2019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: Fork resolution: 1 potential block(s) found...
2019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: Fork resolution: 1 potential suite(s) found...
2019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: Fork resolution: HEAD = block#219619
2019-05-11T09:17:28+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 (-> #219622-000002) revert to fork point block#219616
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Block #219617 added to the blockchain in 35 ms
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 added block#219617-00000310A4FEBF49052F59CAC51C36CFD224DD71658D2A1350AD1F6B3C9FEBCA
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Block #219618 added to the blockchain in 91 ms
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 added block#219618-000002972B79E84BDD337D6C7FEE31D50DC142264324E8F39C43005B00BCA4B0
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Block #219619 added to the blockchain in 28 ms
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 added block#219619-000003D8FAB7F6C8E4FAAAF3D0A34FB47A22A165E6758915A574CD6AA12EBE8D
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Block #219620 added to the blockchain in 24 ms
2019-05-11T09:17:30+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 added block#219620-000005E9E86D9D0BF7F5C58C2F5FD6A06FD39B50497734E0DF615CA5031DDC7C
2019-05-11T09:17:31+02:00 - ESC[32minfoESC[39m: Block #219621 added to the blockchain in 30 ms
2019-05-11T09:17:31+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 added block#219621-000005B9943225F80F519ADB022FFFA5623E4BA753565C0354AC3915B3E5A4F4
2019-05-11T09:17:31+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 REFUSED block#219622: Block's signature must match
2019-05-11T09:17:31+02:00 - ESC[32minfoESC[39m: Fork resolution: suite 1/1 reached HEAD + 2. Now rolling back.
La signature du block 219622 ne match pas.
Comme tu peux le voir dans les logs, le 219620 a bien été reçu en deux versions (fork). Il y en a un seul des deux qui passe mais pendant la résolution, or celle-ci bute sur le 219622 et finit par ne pas ajouter ce 219620.
Ce que je viens de vérifier en copiant les valeurs du bloc dans un test unitaire :
it('219622', function(){
const msg = "InnerHash: 07EBE55CFCDA35D54C7893436ABB15B3FD14836A645FAA174A7B87DBCC7F8161\nNonce: 10600000032050\n"
const verified = verify(msg, "shI9+eS8dEXE4FnBkqFnqrJEnSfS5/6P2itPM+VdBFoJXFnweyAxnevf4PqUqMuD09CYi7J/vvlH/1iB3tjbBw==", "2ny7YAdmzReQxAayyJZsyVYwYhVyax2thKcGknmQy5nQ")
verified.should.equal(true)
})
Le test passe, donc il y a une anomalie au moment de la vérification dans la résolution de fork.
J’en suis là.
Ce qui explique pourquoi ça fonctionne quand le noeud est redémarré. Ca doit réinitialiser une donnée en défaut qui provoque l’anomalie.
Oui, le “know as incorrect” est une donnée mémoire. Un redémarrage permet de redéclencher la vérification. Mais aussi en premier lieu, le bloc aurait dû être valide.
À toutes fins utiles, un log un peu plus “propre” de ce qui s’est passé :
fork.bug.log.txt (919,3 Ko)
Et création du ticket#1375.
Le fork est intégralement résolu : est-ce que vous êtes tous intervenus ou bien la résolution s’est faite automatiquement ?
Non je ne gère plus le nœud du MLO depuis bien longtemps, j’avais délégué à @Patrice_F qui a peut etre encore délégué depuis je ne sais pas 
Perso je n’ai rien fait, il semble s’être résolu tout seul .
Si tu pouvais déposer l’intégralité du fichier de logs quelque part, ça me serait d’une grande aide !
Salut,
je ne sais pas si ça viens de là mais j’ai remarqué ces derniers temps des forks résolus.
Le problème provenais de la validation des certifications de “Deborah” qui ne peut pas devenir membre pour cause de distance ko mais certains noeuds l’inclus quand même dans un bloc.
Tu peux télécharger mon duniter.log ici
Oui, pour les nœuds en version < 1.7.17 (ou supérieure qui n’aurait pas été resynchronisée depuis).
Merci ! En première lecture, je vois que ton nœud a réussi à calculer un bloc et que cela a débloqué la résolution de fork.
Ce genre de blocage peut donc passer relativement inaperçu 
À ce sujet,
Merci à @MarcelDoppagne de mettre à jour ton nœud en dernière version (1.7.18).
Pour dom ça semble être fait ce matin.
C’est surement une raison de forks du réseau.
Ton nœud calcule des blocs ajoutant le nouveau membre Deborah, en ne respectant par la règle de distance.