Consensys / quorum-kubernetes

Helm charts for Hyperledger Besu and GoQuorum
Apache License 2.0
116 stars 127 forks source link

Validators cannot find each others using a permissions nodes config file (Kubernetes, minikube) #198

Closed je-martinez closed 11 months ago

je-martinez commented 1 year ago

Hi, everyone.

I tried to run the example provided on the Playground using minikube and works with no issues, but when I added these two parameters --permissions-nodes-config-file-enabled=true and --permissions-nodes-config-file=/permissions/nodes-allowlist.toml, the validators nodes are not able to find each other, I don't know if I have something setup wrong, you can see my current "project example" here:

Github Repository - Besu Example Kubernetes

Note: If you run the nodes without these arguments, on the statefuls, nodes are able to find each other

            --permissions-nodes-config-file-enabled=true \
            --permissions-nodes-config-file=/permissions/nodes-allowlist.toml \

I'm using a configMap to mount a file to get the nodes permissions.

joshuafernandes commented 1 year ago

Hello @je-martinez

Could you give us steps to reproduce this please? Is it clean minikube and your repo with the params added?

Cheers Josh

je-martinez commented 1 year ago

Hello @je-martinez

Could you give us steps to reproduce this please? Is it clean minikube and your repo with the params added?

Cheers Josh

Hello there @joshuafernandes, sure no problem, and yes here are the steps to reproduce this issue:

  1. Clone this repository git clone https://github.com/je-martinez/besu-minikube-playground.git
  2. Switch to this branch question/minikube-permissioned-peers using git checkout question/minikube-permissioned-peers
  3. Go to v1 folder using cd v1
  4. Deploy to minikube with sh deploy.sh (you would need installminikube and kubectl)
  5. Wait a expect your pods running correctly, you can check that out using kubectl get pod -A and expect something like this:
    NAMESPACE              NAME                                        READY   STATUS    RESTARTS      AGE
    besu                   validator1-0                                1/1     Running   0             10m
    besu                   validator2-0                                1/1     Running   0             10m
    besu                   validator3-0                                1/1     Running   0             10m
    besu                   validator4-0                                1/1     Running   0             10m
    kube-system            coredns-787d4945fb-n8xfn                    1/1     Running   0             13m
    kube-system            etcd-minikube                               1/1     Running   0             13m
    kube-system            kube-apiserver-minikube                     1/1     Running   0             13m
    kube-system            kube-controller-manager-minikube            1/1     Running   0             13m
    kube-system            kube-proxy-rbvf4                            1/1     Running   0             13m
    kube-system            kube-scheduler-minikube                     1/1     Running   0             13m
    kube-system            storage-provisioner                         1/1     Running   1 (12m ago)   13m
    kubernetes-dashboard   dashboard-metrics-scraper-5c6664855-s6lgj   1/1     Running   0             13m
    kubernetes-dashboard   kubernetes-dashboard-55c4cbbc7c-v66cc       1/1     Running   0             13m
    monitoring             grafana-66549db44d-ldq5t                    1/1     Running   0             10m
    monitoring             prometheus-649ff5958c-ffhb4                 1/1     Running   0             10m

Now if you check any validator logs using kubectl logs -f validator1-0 -n besu you will notice that the node cannot find the other nodes even when the argument --bootnodes is set up in the rest of the nodes.

2023-06-30 04:48:53.148+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:48:58.154+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:03.160+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:08.167+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:13.176+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:18.179+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:23.181+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:28.183+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:33.187+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:38.194+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:43.198+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:48.201+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:53.204+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:49:58.216+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:50:03.233+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 04:50:08.238+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness

My first thought was probably something is wrong with my permission file but if I go inside the pod the file is there, you can checkout using kubectl exec -i -t validator1-0 -n besu -- /bin/bash and then cat /permissions/nodes-allowlist.toml

besu@validator1-0:~$ cat /permissions/nodes-allowlist.toml
nodes-allowlist=[
  "enode://b1cd275d17109e0abfcfd6a2aca92b0ed51b2de54f9f8e6a21ba8634d8efc8627d4cd3871fbad937015ffcc85362dacb07a0c9698534bff5953e7647f89d5e2a@validator1-0.besu-validator1.besu.svc.cluster.local:30303",
  "enode://b2f4f82ddd35370be6e2d8675883746ebb98fda88e5f699773b605a838ae4595fdb0b18f5d2a579e531ebcf6b83c3016411dbe4a2b73729fea4e9bcee463e78a@validator2-0.besu-validator2.besu.svc.cluster.local:30303",
  "enode://6d21d4cd712a15510c9d29e890d15ab01f2b53f30c14344feeacff80482fbc4bab1eecbdd74d5357078eaf320a3fe461511f10cdcc6476e9ad7cf8772af2d141@validator3-0.besu-validator3.besu.svc.cluster.local:30303",
  "enode://4a4a91742d5250c6bf8939f2cfa5ca9fa902c490c36e6bce1e6ed75484844840aee51889c27fe8f519eccf011a691acf72ee6507d263a91daef62a6918f763d4@validator4-0.besu-validator4.besu.svc.cluster.local:30303"
]besu@validator1-0:~$ 

I'm not pretty sure if the issue is something related with my permission file or something wrong on my syntax on the statefulset.yaml files because if I remove these two arguments from these files --permissions-nodes-config-file-enabled=true and --permissions-nodes-config-file=/permissions/nodes-allowlist.toml nodes had no problem finding each others

2023-06-30 05:00:25.674+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 05:00:30.676+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 05:00:35.680+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 05:00:40.684+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 0 peers for usefulness
2023-06-30 05:00:44.156+00:00 | nioEventLoopGroup-3-2 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 1 peers for usefulness
2023-06-30 05:00:44.559+00:00 | nioEventLoopGroup-3-4 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 2 peers for usefulness
2023-06-30 05:00:46.654+00:00 | nioEventLoopGroup-3-6 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 3 peers for usefulness
2023-06-30 05:00:51.655+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 3 peers for usefulness
2023-06-30 05:00:56.494+00:00 | EthScheduler-Workers-0 | INFO  | PersistBlockTask | Imported #1 / 0 tx / 0 om / 0 (0.0%) gas / (0x7f837ac2e4cf4cb5dd01322d9358b6e06d41315206dfee046c5add75cd4f452c) in 0.010s. Peers: 3
2023-06-30 05:00:56.659+00:00 | EthScheduler-Timer-0 | INFO  | FullSyncTargetManager | Unable to find sync target. Currently checking 3 peers for usefulness
2023-06-30 05:00:58.074+00:00 | EthScheduler-Workers-0 | INFO  | PersistBlockTask | Imported #2 / 0 tx / 0 om / 0 (0.0%) gas / (0x4a05d2c25489b783bdd94ec0af2964862ccfd5e8a659522de132d3ba57ccce39) in 0.002s. Peers: 3
2023-06-30 05:00:58.088+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #2 / 0 tx / 0 pending / 0 (0.0%) gas / (0x4a05d2c25489b783bdd94ec0af2964862ccfd5e8a659522de132d3ba57ccce39)
2023-06-30 05:01:00.161+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #3 / 0 tx / 0 pending / 0 (0.0%) gas / (0xfa4d794d8eb4d57c511b129a68aabd55dfc6d796a038cd5e5c061cddeacac914)
2023-06-30 05:01:02.067+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Produced #4 / 0 tx / 0 pending / 0 (0.0%) gas / (0x32dd836ab048eba7579fc411cb235764a6956ac70a05766d38d6d52a8fd18844)
2023-06-30 05:01:04.050+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #5 / 0 tx / 0 pending / 0 (0.0%) gas / (0x73e3e1b60649a49fab7806021bd123c5cd04dc9bea485813d26fcc0140b0769b)
2023-06-30 05:01:06.073+00:00 | EthScheduler-Workers-0 | INFO  | PersistBlockTask | Block 6 (0x4ecd7aaba9d59b02237a64fa8f889a7bfe6cf7339409ee8b0108c063aca9df60) is already imported
2023-06-30 05:01:06.075+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #6 / 0 tx / 0 pending / 0 (0.0%) gas / (0x4ecd7aaba9d59b02237a64fa8f889a7bfe6cf7339409ee8b0108c063aca9df60)
2023-06-30 05:01:08.043+00:00 | EthScheduler-Workers-0 | INFO  | PersistBlockTask | Imported #7 / 0 tx / 0 om / 0 (0.0%) gas / (0x75e4bcbefb6e9e450377ab8e93009b0fe488331d3db5a6aae03d767a5b559e88) in 0.001s. Peers: 3
2023-06-30 05:01:10.055+00:00 | EthScheduler-Workers-0 | INFO  | PersistBlockTask | Imported #8 / 0 tx / 0 om / 0 (0.0%) gas / (0xf1e4a72a62a00ba21d20be2081e570794a9b5b7289d4be2c64d5c81447450705) in 0.004s. Peers: 3

Thanks in advance for your help

danielherrero commented 12 months ago

Hi Same here using latest docker-desktop and besu image 21.1.2 fo member1 and latest for the rest,). I havent modififed de playground repo. If hay enable permission ( permissions-nodes-config-file-enabled=true ) then It doesn work. It seems the connections are rejected but I cannot see any clue in logs. The only error I see is something commented in otyer issues: Nat manager failed to configure itself automatically due to the following reason : org.hyperledger.besu.nat.core.exception.NatInitializationException: . NONE mode will be used as a fallback. Any clue? tested on a fresh docker-desktop 4.23.0 and besu image 21.1.2

joshuafernandes commented 11 months ago

Hello @je-martinez apologies that I've not been able to test out your repo yet. I'll do this today/tomorrow

@danielherrero @je-martinez, I've tested the playground repo and I've pushed https://github.com/Consensys/quorum-kubernetes/commit/3ed4fddf456108fd0149446c01965a236fb24bae which just bumps the version to the newest version, however am not able to reproduce this issue. It may take a few mins for the nodes to peer, but they work fine to create blocks from what I can see. I've got WSL2 with Ubuntu 22.04 and minikube and this is what I see:

2023-09-25 02:34:58.019+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Produced #138 / 0 tx / 0 pending / 0 (0.0%) gas / (0x8c112b9434c6046d129496858bae1fae359064e04b600781e001bf6b266fccb7)
2023-09-25 02:34:58.019+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | BaseBftController | New chain head detected (block number=138), currently mining on top of 137.
2023-09-25 02:34:58.522+00:00 | EthScheduler-Timer-0 | DEBUG | FullSyncTargetManager | Caught up to best peer: PeerId 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1, reputation PeerReputation 101, validated? true, disconnected? false, client: besu/v23.7.0/linux-x86_64/openjdk-java-17, connection [Connection with hashCode 1795717998 with peer 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1 inboundInitiated true initAt 1695608630985], enode enode://ad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1@10.244.0.54:30303?discport=0, chain state: ChainState{estimatedHeight=137, bestBlock=BestBlock{totalDifficulty=0x000000000000000000000000000000000000000000000000000000000000008a, blockHash=0xcf315a32e3de2d08c1c3d288186582ae226a85fab2e4a169a9b24ea0e403b2d9, number=137}}. Current peers: 5
2023-09-25 02:34:58.522+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 5 peers currently connected.
2023-09-25 02:35:03.523+00:00 | EthScheduler-Timer-0 | DEBUG | FullSyncTargetManager | Caught up to best peer: PeerId 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1, reputation PeerReputation 101, validated? true, disconnected? false, client: besu/v23.7.0/linux-x86_64/openjdk-java-17, connection [Connection with hashCode 1795717998 with peer 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1 inboundInitiated true initAt 1695608630985], enode enode://ad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1@10.244.0.54:30303?discport=0, chain state: ChainState{estimatedHeight=137, bestBlock=BestBlock{totalDifficulty=0x000000000000000000000000000000000000000000000000000000000000008a, blockHash=0xcf315a32e3de2d08c1c3d288186582ae226a85fab2e4a169a9b24ea0e403b2d9, number=137}}. Current peers: 5
2023-09-25 02:35:03.523+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 5 peers currently connected.
2023-09-25 02:35:08.085+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftBlockHeightManager | Round has expired, creating PreparedCertificate and notifying peers. round=ConsensusRoundIdentifier{Sequence=139, Round=0}
2023-09-25 02:35:08.085+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftBlockHeightManager | Starting new round 1
2023-09-25 02:35:08.097+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftBlockHeightManager | Received sufficient RoundChange messages to change round to targetRound=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.105+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a proposal message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.106+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | RoundChangeCertificateValidator | No round change messages have a preparedCertificate, any valid block may be proposed.
2023-09-25 02:35:08.107+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Sending prepare message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.186+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a prepare message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.186+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Sending commit message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.190+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a commit message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.194+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a commit message. round=ConsensusRoundIdentifier{Sequence=139, Round=1}
2023-09-25 02:35:08.196+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftRound | Importing block to chain. round=ConsensusRoundIdentifier{Sequence=139, Round=1}, hash=0xbddd63b69c4fa8dc3f675f123df87794b18a22fade891c2f478b3d6928cf967c
2023-09-25 02:35:08.201+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | TransactionLogBloomCacher | Caching logs bloom for block 0x8b.
2023-09-25 02:35:08.205+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #139 / 0 tx / 0 pending / 0 (0.0%) gas / (0xbddd63b69c4fa8dc3f675f123df87794b18a22fade891c2f478b3d6928cf967c)
2023-09-25 02:35:08.206+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | BaseBftController | New chain head detected (block number=139), currently mining on top of 138.
2023-09-25 02:35:08.586+00:00 | EthScheduler-Timer-0 | DEBUG | FullSyncTargetManager | Caught up to best peer: PeerId 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1, reputation PeerReputation 101, validated? true, disconnected? false, client: besu/v23.7.0/linux-x86_64/openjdk-java-17, connection [Connection with hashCode 1795717998 with peer 0xad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1 inboundInitiated true initAt 1695608630985], enode enode://ad2c79c6561bc8212c2e8382611c62e406e767d1f3106c68ca206900f575cb8ba9a8be111c645cd9803701d684454c782c40d2361b000a32ed03d26228b30ec1@10.244.0.54:30303?discport=0, chain state: ChainState{estimatedHeight=138, bestBlock=BestBlock{totalDifficulty=0x000000000000000000000000000000000000000000000000000000000000008b, blockHash=0x8c112b9434c6046d129496858bae1fae359064e04b600781e001bf6b266fccb7, number=138}}. Current peers: 5
2023-09-25 02:35:08.587+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 5 peers currently connected.
2023-09-25 02:35:10.006+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a proposal message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.009+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Sending prepare message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.013+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a prepare message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.013+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Sending commit message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.016+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a commit message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.017+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Received a commit message. round=ConsensusRoundIdentifier{Sequence=140, Round=0}
2023-09-25 02:35:10.017+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | IbftRound | Importing block to chain. round=ConsensusRoundIdentifier{Sequence=140, Round=0}, hash=0x2443128ae663911038791585145ccf4e7233feefac62b36422935e7e86925242
2023-09-25 02:35:10.018+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | TransactionLogBloomCacher | Caching logs bloom for block 0x8c.
2023-09-25 02:35:10.019+00:00 | BftProcessorExecutor-IBFT-0 | INFO  | IbftBesuControllerBuilder | Imported #140 / 0 tx / 0 pending / 0 (0.0%) gas / (0x2443128ae663911038791585145ccf4e7233feefac62b36422935e7e86925242)
2023-09-25 02:35:10.019+00:00 | BftProcessorExecutor-IBFT-0 | DEBUG | BaseBftController | New chain head detected (block number=140), currently mining on top of 139.
joshuafernandes commented 11 months ago

Hi @je-martinez

Had a look at your repo and got them peering fine. Changes I made were:

At any rate, I've verified that the playground in this repo works so it should be simple enough to compare with your repo

Cheers