Test end2end non reproductible

J’ai lancé deux fois de suite un test end2end et ai eu le comportement suivant :

    ~/dev/duniter-v2s    hugo-quotas ⇡1  cargo cucumber -i "account_creat*"                                                                          ✔  2m 19s  
    Finished test [unoptimized + debuginfo] target(s) in 1.55s
     Running tests/cucumber_tests.rs (target/debug/deps/cucumber_tests-94a7c6ae440c6d0e)
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
Feature: Account creation
  Scenario: Create a new account with enough funds
   ✔  When alice sends 5 ĞD to dave
   ✔  Then dave should have 5 ĞD
   ✔  When 1 block later
   ✔  Then dave should have 2 ĞD
  Scenario: Create a new account without enough funds then retry with enough funds
   ✔  When alice sends 2 ĞD to eve
   ✔  Then eve should have 2 ĞD
   ✔  When 1 block later
   ✔  Then eve should have 0 ĞD
   ✔  When alice send 5 ĞD to eve
   ✔  Then eve should have 5 ĞD
   ✔  When 1 block later
   ✔  Then eve should have 2 ĞD
  Scenario: Create a new account without any funds
   ✔  Then eve should have 0 ĞD
   ✔  Then alice should have 9 ĞD
   ✔  When eve send 0 ĞD to alice
   ✔  Then alice should have 9 ĞD
   ✔  When alice send 5 ĞD to eve
   ✘  Then eve should have 5 ĞD
      Step failed: ./cucumber-features/account_creation.feature:37:5
      Captured output: 
      Step panicked. Captured output: assertion `left == right` failed
        left: 700
       right: 500
[Summary]
1 feature
3 scenarios (2 passed, 1 failed)
18 steps (17 passed, 1 failed)
thread 'main' panicked at /home/hugo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/cucumber-0.11.3/src/cucumber.rs:1309:13:
1 step failed
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
error: test failed, to rerun pass `-p duniter-end2end-tests --test cucumber_tests`
    ~/dev/duniter-v2s    hugo-quotas ⇡1  cargo cucumber -i "account_creat*"                                                                         101 ✘  15s  
    Finished test [unoptimized + debuginfo] target(s) in 0.40s
     Running tests/cucumber_tests.rs (target/debug/deps/cucumber_tests-94a7c6ae440c6d0e)
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
maybe_genesis_conf_file=Some("cucumber-genesis/default.json")
Feature: Account creation
  Scenario: Create a new account with enough funds
   ✔  When alice sends 5 ĞD to dave
   ✔  Then dave should have 5 ĞD
   ✔  When 1 block later
   ✔  Then dave should have 2 ĞD
  Scenario: Create a new account without enough funds then retry with enough funds
   ✔  When alice sends 2 ĞD to eve
   ✔  Then eve should have 2 ĞD
   ✔  When 1 block later
   ✔  Then eve should have 0 ĞD
   ✔  When alice send 5 ĞD to eve
   ✔  Then eve should have 5 ĞD
   ✔  When 1 block later
   ✔  Then eve should have 2 ĞD
  Scenario: Create a new account without any funds
   ✔  Then eve should have 0 ĞD
   ✔  Then alice should have 9 ĞD
   ✔  When eve send 0 ĞD to alice
   ✔  Then alice should have 9 ĞD
   ✔  When alice send 5 ĞD to eve
   ✔  Then eve should have 5 ĞD
   ✔  When 1 block later
   ✔  Then eve should have 2 ĞD
[Summary]
1 feature
3 scenarios (3 passed)
20 steps (20 passed)

Le premier est en échec, car Eve a 7 ĞD au lieu de 5 ĞD (??). Le deuxième passe. Je n’ai rien changé entre les deux lancements.

Je ne sais pas ce qui a pu se passer, mais si quelqu’un rencontre la même chose il saura que ça n’arrive pas qu’à lui :laughing:

En le relançant plusieurs fois, je peux même avoir plusieurs échecs :

Feature: Account creation
  Scenario: Create a new account with enough funds
   ✔  When alice sends 5 ĞD to dave
   ✔  Then dave should have 5 ĞD
   ✔  When 1 block later
   ✔  Then dave should have 2 ĞD
  Scenario: Create a new account without enough funds then retry with enough funds
   ✔  When alice sends 2 ĞD to eve
   ✔  Then eve should have 2 ĞD
   ✔  When 1 block later
   ✘  Then eve should have 0 ĞD
      Step failed: ./cucumber-features/account_creation.feature:20:5
      Captured output: 
      Step panicked. Captured output: assertion `left == right` failed
        left: 500
       right: 0
  Scenario: Create a new account without any funds
   ✔  Then eve should have 0 ĞD
   ✔  Then alice should have 9 ĞD
   ✔  When eve send 0 ĞD to alice
   ✔  Then alice should have 9 ĞD
   ✔  When alice send 5 ĞD to eve
   ✘  Then eve should have 5 ĞD
      Step failed: ./cucumber-features/account_creation.feature:37:5
      Captured output: 
      Step panicked. Captured output: assertion `left == right` failed
        left: 700
       right: 500

Étrange…

Ah, je crois savoir d’où ça vient : dans la dernière modification de cgeek, le port du client + la manière de spawner les nœuds a été changée, donc c’est possible que le client ne se connecte pas au bon nœud. Je regarde.

Hypothèse actuelle : un collision dans les fichiers temporaires :

ls -1 /tmp/
substrate2qltrV
substrate37oZFC
substrate90Cfj2
substrateEpnxyp
substratefEDX4m
substratefqiDE6
substrateg3yjBq
substrateihLvB0
substrateIjIQk2
substrateKKEqfj
substratel75vgM
substrateLnvsct
substratemA83bE
substrateNtgfIz
substrateO2SVFm
substratep4NBHq
substratePpLagw
substrateQjotlK
substrateQYTEJ5
substraterm5nLw
substrateScEYtK
substrateSOuIJy
substratesSg3UT
substratesyh577
substrateT8GFEX
substrateTcELX4
substratexzggrW
substrateZEKjVX
substrateZULcwV
substratezuQsXU

C’était pas mal d’avoir le --base-path dans /tmp/duniter-cucumber, mais c’est tuxmain qui l’a supprimé, pour le coup.

2 Likes

Je reviens plus tard sur ce sujet et je me rends compte que j’étais sur une mauvaise piste. En regardant dans les logs des nœuds, je vois “💔 Error importing block”, ce qui veut dire que les trois nœuds lancés pour ce test cucumber communiquent entre eux par le réseau (et non par les fichiers) au lieu d’être indépendants ! On voit aussi :

discovered: 12D3KooWJ86goiyRsPJ4UonCM373FrVjCaWGPoyNfXwNnzjYiYgb /ip4/192.168.1.106/tcp/24809

J’avais déjà eu ce problème en travaillant sur l’indexeur, les chainspecs générées sur la branche de cgeek incluent systématiquement un bootnode alors que j’aimerais bien des chainspecs sans bootnode, et les ajouter à la main. Je poursuis sur cette piste…

En voyant ça, je me dis qu’on pourrait avoir un problème d’interférence si on lance plusieurs tests de distance en parallèle (pour l’instant un seul dans identity_creation.feature) parce que When alice runs distance oracle utilise un dossier temporaire par défaut. Donc vigilance pour la suite, sinon on risque d’avoir des comportement imprévisibles dans les tests de distance.

Je crois que j’ai trouvé. Dans la doc il y a marqué :

 --reserved-only
    Whether to only synchronize the chain with reserved nodes.
    Also disables automatic peer discovery. TCP connections might
    still be established with non-reserved nodes. In particular, if you
    are a validator your node might still connect to other validator
    nodes and collator nodes regardless of whether they are defined
    as reserved nodes
--no-mdns
   Disable mDNS discovery. By default, the network will use mDNS
    to discover other nodes on the local network. This disables it.
    Automatically implied when using --dev
--discover-local
    Enable peer discovery on local networks. By default this option
    is `true` for `--dev` or when the chain type is `Local`/`Development`
    and false otherwise

Donc en retirant l’option --dev, @cgeek a également retiré (sans le savoir) l’option --no-mdns, et donc les nœuds de test se découvrent entre eux et forment un seul réseau, d’où l’apparition de comportements imprévisibles en fonction de l’ordre dans lequel étaient effectuées les actions.

Donc le fix est simple, ajouter l’option --reserved-only pour empêcher de se connecter à autre chose que des bootnodes.

Ça m’a fait découvrir le concept de “reserved nodes” qu’on pourrait utiliser pour notre réseau.

1 Like

Bravo pour l’avoir trouvé, c’est vrai que localement les tests E2E échouaient parfois.

J’ai pourtant bien regardé la documentation en ligne de commande :

--dev
    Specify the development chain.
    
    This flag sets `--chain=dev`, `--force-authoring`, `--rpc-cors=all`, `--alice`, and `--tmp` flags, unless explicitly overridden.

Mais manifestement celle-ci est incomplète. :confused:

Je viens de l’ajouter sur ma branche. Merci :slight_smile:

C’est un concept qui existe dans Duniter v1 depuis 2017. Oui, c’est intéressant.

Il ne manquerait plus qu’à trouver le concept dans le sens inverse (nœuds entrants), les priviledgedNodes, mais je n’ai pas vu ça dans Substrate.

3 Likes