Ğ1-test bloquée : bloc généré mais refusé de part sa taille

Moul · 22 January 2019 19:56

2019-01-22T20:18:56+01:00 - error:  Error: ruleBlockSize
    at Function.checkBlock (/home/gtest/duniter/app/lib/blockchain/DuniterBlockchain.js:56:19)
    at <anonymous>

En essayant de générer le bloc suivant j’ai une liste de transaction immense :

duniter gen-next 2 --submit-host g1-test.duniter.org --submit-port 443
2019-01-22T20:52:42+01:00 - debug: Plugging file system...
2019-01-22T20:52:43+01:00 - debug: Loading conf...
2019-01-22T20:52:43+01:00 - debug: Configuration saved.
2019-01-22T20:52:43+01:00 - debug: Opening SQLite database "/home/gtest/.config/duniter/duniter_default/duniter.db"...
2019-01-22T20:52:43+01:00 - debug: Opening SQLite database "/home/gtest/.config/duniter/duniter_default/txs.db"...
2019-01-22T20:52:43+01:00 - debug: Opening SQLite database "/home/gtest/.config/duniter/duniter_default/peers.db"...
2019-01-22T20:52:43+01:00 - debug: Upgrade database...
2019-01-22T20:52:43+01:00 - info: Block resolution: 3 potential blocks after current#311527...
2019-01-22T20:52:45+01:00 - error:  Error: ruleBlockSize
    at Function.checkBlock (/home/gtest/duniter/app/lib/blockchain/DuniterBlockchain.js:56:19)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
2019-01-22T20:52:47+01:00 - error:  Error: ruleBlockSize
    at Function.checkBlock (/home/gtest/duniter/app/lib/blockchain/DuniterBlockchain.js:56:19)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
2019-01-22T20:52:49+01:00 - error:  Error: ruleBlockSize
    at Function.checkBlock (/home/gtest/duniter/app/lib/blockchain/DuniterBlockchain.js:56:19)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
2019-01-22T20:52:49+01:00 - debug: Key CyqdW36qXuPfEXxGoArRoBW5aDXdchsCnhiTyrFn7dA1 does not have enough links (0/5)
2019-01-22T20:52:49+01:00 - debug: Key 82CxhDBJwJ5tmpDuKuzdcM5AnzGNc3hfyEweWnuSvpSt does not have enough links (0/5)
2019-01-22T20:52:49+01:00 - debug: Key 63QymzVaknTSyasv1Zhr8suwae34Y9K4pr3riabAFVdq does not have enough links (0/5)
2019-01-22T20:52:49+01:00 - debug: Key 3sEFrd39ExRFHWYnnhp85r2ZWWPruQ2jx95HraQikTXA does not have enough links (0/5)
2019-01-22T20:52:49+01:00 - info: Transaction 763D5649F9530B595D4B359A739999D97D5AD9AD7AAD1CCA4F27E8CB72448864 added to block
2019-01-22T20:52:49+01:00 - info: Transaction 9016FA88B83253EF411D38530585BFB05653B9BEF6D9429C408BFCB62B4DF971 added to block
2019-01-22T20:52:49+01:00 - info: Transaction D47B2111D69435591DBAA1F56036DD23D46A76ECAF3C0BC274CB4F1FAD617139 added to block
2019-01-22T20:52:49+01:00 - info: Transaction 6CFE1D4A217D6307200F67938DC6B40B5F709F0C641307C214F3E13BEC69A0C1 added to block
2019-01-22T20:52:49+01:00 - info: Transaction A3F5FDC8F82107CFF456E4DD92A3EE0C025E598C16A804820DF1689B4665D053 added to block
2019-01-22T20:52:50+01:00 - info: Transaction 0CB9B637A626404EF824F7A3CBAE6EBD802476246DC779A3839ED3E99335987D added to block
2019-01-22T20:52:50+01:00 - info: Transaction A8D8F44C28992A49CE051286741722FD3647419175BE6953CD28DC3CB96A0C86 added to block
2019-01-22T20:52:50+01:00 - info: Transaction 02A481AEA395DF17AF5A443C78E4F4B7F7D0A42B8C6994FC9AF9FC322221D24B added to block
2019-01-22T20:52:50+01:00 - info: Transaction 896689CE36523512729628189A12F61A530000CFA49D19A6740529BDDED1B7AF added to block
2019-01-22T20:52:50+01:00 - info: Transaction 4694B5591A6D29B27FD330EF44F21B643FAB222C91AD41987EF71E9E48C0A16B added to block
2019-01-22T20:52:50+01:00 - info: Transaction 4796B50679E9CCF1F3D19387BD9B519A71E5D047A2B14D7B56E9A5BC16719F4C added to block
2019-01-22T20:52:50+01:00 - info: Transaction 96276FC5DC1E02C0E476B3BA74CD097A6527B82F831C0B33FDDCAB92A79FE1A9 added to block
2019-01-22T20:52:50+01:00 - info: Transaction 2B91B7E4785951F4C04C00694B16829E72D334E1B45DA91D5EE3A90D6F59A5EA added to block
2019-01-22T20:52:50+01:00 - info: Transaction 7A414DFEDE0F11DAB93482316F4DB7196D1C2BF0BFFADEA14A398D1B4A9CE658 added to block
2019-01-22T20:52:50+01:00 - info: Transaction 6E75868E989C75FD7095EEF92B7B30D28D444E01D658465E3E2F697BD360B9A0 added to block
2019-01-22T20:52:50+01:00 - info: Transaction 687609A9EEDE3E5F24FB805F6883A7C60AD6F98E47098B8CAB4B2EBE9FA1F57E added to block
2019-01-22T20:52:51+01:00 - info: Transaction AC4D0C2BC4C4192DFAD9DC7BBFEB1CEEEDAE8D53F2EEA317D50D2081EAD5C7CD added to block
…

matograine · 23 January 2019 09:38

Hum, ça doit être mon fuzzer. Donc on atteint une limite en taille de bloc ? La blockchain semble arrétée depuis 16h26 hier. (bloc 311527)

Je compte repasser chez moi vers 14h, je l’éteins ?

Moul · 23 January 2019 10:43

Tu veux dire ton spammer de transactions ? Oui, il vaudrait mieux le temps de débloquer la situation.
Il doit y avoir un bug dans l’implémentation qui fait que ça bloque.
Duniter est censé passé à l’échelle en termes de taille de bloc.

cgeek · 23 January 2019 18:25

En effet, voici comment isoler le problème :

Stopper duniter

Lancer la commande suivante :

duniter --mdb gt gen-next --check --submit-local

Détail de chaque paramètre :

--mdb gt : option pour utiliser la base de données gt (ma machine qui fait tourner la ğ1 et ğtest)
gen-next : demander à duniter de générer le prochain bloc
--check : faire une vérification du bloc généré vis-à-vis des règles du protocole (validation hors preuve de travail, cette dernière ne sera donc pas réalisée afin de ne pas perdre de temps, on veut juste vérifier que le bloc généré est valide hors PoW)
--submit-local : s’envoyer le bloc à soi-même à la fin de la procédure de génération, si celle-ci a fonctionné (paramètre obligatoire)

À la fin de la procédure, on tombe sur :

error: Error: ruleBlockSize
  at Function.checkBlock (/opt/duniter/app/lib/blockchain/DuniterBlockchain.js:56:19)
  at <anonymous>
  at process._tickCallback (internal/process/next_tick.js:160:7)

Concernant la cause du bug, j’investiguerai dans 1h30 environ (sauf si quelqu’un a repéré le bug avant moi ! facile quand on a un nœud membre sur ğtest qui bloque : il suffit de copier le dossier de données et de lancer la même commande que ci-dessus avec des points d’arrêt dans son IDE préféré).

cgeek · 23 January 2019 21:09

Du coup, j’ai mis un point d’arrêt sur cette ligne pour observer le comportement du bloc de code qui ajoute les transactions :

/*****
 * Priority 4: transactions
 */
block.transactions = [];
blockLen = BlockDTO.getLen(block);
if (blockLen < maxLenOfBlock) {
  transactions.forEach((tx:any) => {
    const txDTO = TransactionDTO.fromJSONObject(tx)
    const txLen = txDTO.getLen()
    if (txLen <= CommonConstants.MAXIMUM_LEN_OF_COMPACT_TX && blockLen + txLen <= maxLenOfBlock && tx.version == CommonConstants.TRANSACTION_VERSION) {
      block.transactions.push(txDTO);
    }
    blockLen += txLen;
  });
}

Ce que je note :

blockLen + txLen <= maxLenOfBlock

Or dans le protocole c’est plutôt :

HEAD.size < MAX(500 ; CEIL(1.10 * HEAD.avgBlockSize))

Je traduis : dans le code on vérifie que si l’on ajoute la transaction, la nouvelle taille du bloc sera inférieure ou égale à maxLenOfBlock, la taille maximale du bloc que l’on a calculé (500 en l’occurrence quand je débogue).

Par contre dans le protocole, on vérifie que la taille du bloc est strictement inférieure à la taille maximale du bloc.

Je vous le donne en mille : la taille du bloc généré dans ğtest faisait exactement 500 en tenant compte des transactions.

Voici donc :

Je publie de ce pas une version corrective 1.7.11 et 1.6.30. @jytou, peux-tu gérer les versions ARM + Win stp ?

Merci à @Moul pour sa vigilance ainsi qu’à @matograine pour son générateur qui a révélé ce bug. Sans vous, celui-ci aurait éclaté plus tard et possiblement en prod, sur la Ğ1.

Moul · 23 January 2019 21:33

J’invite @Inso, @Melua et @bobvador à mettre à jour pour débloquer la Ğ1-test.
Et @Attilax quand le build ARM sera là.

jytou · 23 January 2019 21:56

Je m’en occupe de suite…

PS: je n’ai pas eu de mail pour me prévenir de ce thread, il se trouve que je passais par là… problème de mail ?

Moul · 23 January 2019 22:18

On ne reçoit pas de mail quand on passe par là, comme tu le dis. C’est le fonctionnement de Discourse.

jytou · 23 January 2019 22:19

Sauf que le mail en question datait de 30 minutes quand je suis arrivé… mais discourse attend peut-être un peu plus que ça, je ne sais pas.

jytou · 23 January 2019 22:49

Version 1.7 pour ARM releasée. Pour windows, j’ai raté un truc et je dois la relancer…

Sinon, pour ma part, aucun des deux raspi ne tourne, même avec la 1.7 : duniter part en out of memory assez rapidement (il tient moins d’une journée). Y aurait-il un problème de fuite mémoire ?

jytou · 23 January 2019 23:56

Voilà, les 4 releases sont faites.

cgeek · 24 January 2019 08:59

Oui Discourse attend un certain laps de temps avant de t’envoyer un mail. Notre serveur de mail tombe parfois en rade mais là, il fonctionne bien.

edit : ah, @elois indique que lui constate un problème de son côté…

Possible, mais il me semble qu’il y a d’autres utilisateurs de Raspberry PI et tu es le premier à remonter ce problème.

Merci pour les releases

cgeek · 24 January 2019 09:01

Je viens juste de relancer mon noeud, ça devrait débloquer la situation je suppose (si tu ne l’as pas déjà fait).

Moul · 24 January 2019 10:15

Il nous faut une troisième identité pour débloquer car cgeek et moi sont isolés de la Pow.
@Inso, @Melua, @bobvador, @Attilax, @vit.

Attilax · 24 January 2019 10:37

J’ai pas tout compris. Faut que je réinstalle duniter en dernière version, c’est ça ? J’ai vu que la G1-test avait sauté ce matin, mais je pensais m’y être “rattaché” avec un restart. J’apparais comme comptant les blocs sur cesium G1-test… Dis-moi ce que je dois faire et je le ferai.

Moul · 24 January 2019 10:40

Ça semble être reparti. Mais oui, une màj. Mais, tu sembles avoir trouvé des blocs. Donc, ça semble pas nécessaire.

Attilax · 24 January 2019 11:00

Ouf, tant mieux. Ça prend des plombes sur mon pauvre raspberry
Je mettrai à jour à la prochaine grosse plantade (j’en ai régulièrement)…

matograine · 24 January 2019 11:34

Salut !

On est le 24/01 à 12h31 (heure réelle). Le noeud de @cgeek fait la course en tête, seul, et nous pond une vingtaine de blocs à la minute. Il est tellement en avance que sa montre affiche 13h01. Le peloton est totalement désynchronisé, arrivera-t-il à rattraper le noeud de cgeek ?

Je pense qu’il recevra le maillot jaune pour cette étape.

Bloc 312338…339…340… Ah ça va trop vite !

Moul · 24 January 2019 11:44

Ça va tellement vite que mon nœud est également partit dans sa propre direction.

Attilax · 24 January 2019 14:05

Grave, il n’y a plus que lui dans les calculateurs de blocs !
Mon pauvre rasp est aller pleurnicher dans les bras de sa maman…