Durée entre l'intégration d'un block et le début du calcul du suivant

J’ai remarqué qu’il se passe plusieurs minutes entre le moment où mon nœud apprend qu’un bloc a été trouvé, et le moment où il commence à calculer le suivant :

2018-03-08T14:15:49+01:00 - info: GIVEN proof-of-work for block#144772 with 3 leading zeros followed by [0-2]! stop PoW for EPKuZA
2018-03-08T14:18:31+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-2]... (CPU usage set to 40%) for block#144773 EPKuZA
2018-03-08T14:18:38+01:00 - info: GIVEN proof-of-work for block#144773 with 3 leading zeros followed by [0-2]! stop PoW for EPKuZA
2018-03-08T14:21:13+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-2]... (CPU usage set to 40%) for block#144776 EPKuZA
2018-03-08T14:23:16+01:00 - info: GIVEN proof-of-work for block#144776 with 3 leading zeros followed by [0-2]! stop PoW for EPKuZA
2018-03-08T14:25:56+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-2]... (CPU usage set to 40%) for block#144777 EPKuZA
2018-03-08T14:26:01+01:00 - info: GIVEN proof-of-work for block#144777 with 3 leading zeros followed by [0-2]! stop PoW for EPKuZA
2018-03-08T14:28:42+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-2]... (CPU usage set to 40%) for block#144778 EPKuZA
2018-03-08T14:28:52+01:00 - info: GIVEN proof-of-work for block#144778 with 3 leading zeros followed by [0-2]! stop PoW for EPKuZA
2018-03-08T14:31:27+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-1]... (CPU usage set to 40%) for block#144781 EPKuZA
2018-03-08T14:31:32+01:00 - info: GIVEN proof-of-work for block#144781 with 3 leading zeros followed by [0-1]! stop PoW for EPKuZA
2018-03-08T14:34:19+01:00 - info: Generating proof-of-work with 3 leading zeros followed by [0-1]... (CPU usage set to 40%) for block#144783 EPKuZA

Cela a pour conséquence que mon nœud calcule très peu de blocs, parce qu’il n’a pas le temps de commencer les calculs qu’un nouveau bloc a déjà été trouvé. J’ai remarqué que cette durée semble augmenter avec le temps… Il y a quelques jours elle était de 90 secondes. J’ai essayé de relancer le nœud, et cela diminue un peu la latence mais pas tant que cela.

Est-ce que c’est un bug ? Est-ce que vous observez la même chose ?

Je regarde les logs dans l’IHM de mon noeud et je vois ça :

2018-03-08T14:55:31+01:00 info GIVEN proof-of-work for block#101058 with 5 leading zeros followed by [0-8]! stop PoW for 5cnvo5
2018-03-08T14:55:54+01:00 info Generating proof-of-work with 5 leading zeros followed by [0-8]... (CPU usage set to 10%) for block#101059 5cnvo5

J’ai environ 20-30 secondes sur chacun de ces évènements.

Donc je dirais que je n’ai pas ton bug. Mais ça me parait long ce que tu as comme comportement oui… C’est quoi comme matériel ?

Et qu’as-tu en terme de connexion réseau ? Débit ? Latence ?

C’est un odroid U3 avec 2GO de RAM (1GO est libre selon top). Je n’ai pas l’impression que le débit soit le problème (connexion ADSL raisonnable), mais je remarque que le processus g1test est à 100% de cpu en permanence. (Ajout : il est à 100% entre GIVEN et Generating, mais sinon il tombe à moins de 10%.)

Un peu plus de détail en regardant les logs:

  • block GIVEN, je ne vois que des trucs sur WS2P dans les logs
  • puis une série d’erreurs “Source already consumed”
  • puis cela parle majoritairement de transactions (avec un peu de WS2P), avec des erreurs “It cannot exist 2 identical sources for transactions inside a given block”
  • enfin ça lance le Generating et cela parle de transactions encore (sans erreurs)
  • et cela recommence, typiquement avec un bloc trouvé par quelqu’un d’autre presque immédiatement

Le point important est que toujours durant la seconde avant la génération, j’ai cette grande séquence d’erreurs sur les “Sources already consumed” et sur les “identical sources”. Je suppose donc que mon nœud prend longtemps à vérifier le bloc qu’on lui soumet, parce que (hypothèse) il y a plein de transactions (malformées ?) en piscine ?

@Alan_Schmitt c’est normal le réseau GT est bombardé de transactions, on a 5 A 6 transactions par bloc en moyenne en ce moment c’est plus qu’avant, c’est donc une montée en charge qui augmente le temps de génération des blocs c’est tout a fait normal :slight_smile:

C’est qui qui nous spamme ? Et c’est intéressant de voir ceci arriver avec “seulement” 5 ou 6 transactions par blocs. Est-ce que cela suggère que les petites machines ne pourront pas calculer parce qu’il leur faudra trop de temps pour vérifier les blocs (si c’est bien là qu’est le problème) ?

C’est inquiétant si on à ce genre de ralentissement à 6tx/bloc.

Duniter est fortement optimisable, nous ne sommes encore qu’en v1 :wink:

1 « J'aime »

Il faudrait arriver à trouver l’origine de ces ralentissements pour pas avoir ce problème sur le futur protocole, vu le nombre de tx/bloc ciblé :wink:

Ah mais d’ailleurs 6tx/bloc c’est la limite sur Bitcoin non ?

Non c’est bien plus ^^ https://blockchain.info/fr/charts/n-transactions-per-block

Après, ça peut avoir plusieurs causes :

  • Un problème d’implémentation dans le code (requêtage bdd trop intense, algorithme mal calibré…)
  • Un probleme algorithmique au niveau du protocole blockchain en lui même

Pour commencer, il faudrait faire du profilage sur le noeud de @Alan_Schmitt. ( https://nodejs.org/en/docs/guides/simple-profiling/ )

1 « J'aime »

J’ai buggé et ai confondu tx/bloc et tx/sec x)

1 « J'aime »

Je veux bien donner un coup de main, mais il faudrait m’indiquer comment modifier le script duniter pour ça. (Idéalement il pourrait fournir une option --profile)