search

bcgov / von-network

A portable development level Indy Node network.
Apache License 2.0
160 stars 188 forks source link

Webserver/Ledger Pool: Pool timeout occured #313

Open arminveres opened 3 months ago

arminveres commented 3 months ago

I have used von-network for a small demo a while back (December 2023) and pinned it as a dependency in one of my repos. Back then, all worked, although, on a different machine. Now, when I ./manage build and then ./manage start the webserver times out, and I cannot connect to the pool from other Hyperledger Aries based nodes either...

As I mentioned, the only change was a new machine, the 'codebase' was not changed. The nodes and web-server try to connect to the Docker network, but even starting the network with ./manage start <local-ip> the error still persists.

EDIT: Additionally, I noticed, that the nodes are only checked at 172.17.0.1, which is yielded by getDockerHost.sh, but running docker network inspect von_von yields a different network altogether. Therefore, I am suspecting some form of false network configuration...

Web-server log:

Ledger does not exist - Creating genesis data...
von_generate_transactions -n

================================================================================================
Generating genesis transaction file:
nodeArg:
ipAddresses: 172.17.0.1,172.17.0.1,172.17.0.1,172.17.0.1
genesisFilePath: /home/indy/ledger/sandbox/pool_transactions_genesis
------------------------------------------------------------------------------------------------
generate_indy_pool_transactions --nodes 4 --clients 0 --ips 172.17.0.1,172.17.0.1,172.17.0.1,172.17.0.1

BLS Public key is 4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba
Proof of possession for BLS key is RahHYiCvoNCtPTrVtP7nMC5eTYrsUA8WjXbdhNc8debh1agE9bGiJxWBXYNFbnJXoXhWFMvyqhqhRoq737YQemH5ik9oL7R4NTTCz2LEZhkgLJzB3QRQqJyBNyv7acbdHrAT8nQ9UkLbaVL9NBpnWXBTw4LEMePaSHEw66RzPNdAX1
BLS Public key is 37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk
Proof of possession for BLS key is Qr658mWZ2YC8JXGXwMDQTzuZCWF7NK9EwxphGmcBvCh6ybUuLxbG65nsX4JvD4SPNtkJ2w9ug1yLTj6fgmuDg41TgECXjLCij3RMsV8CwewBVgVN67wsA45DFWvqvLtu4rjNnE9JbdFTc1Z4WCPA3Xan44K1HoHAq9EVeaRYs8zoF5
BLS Public key is 3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5
Proof of possession for BLS key is QwDeb2CkNSx6r8QC8vGQK3GRv7Yndn84TGNijX8YXHPiagXajyfTjoR87rXUu4G4QLk2cF8NNyqWiYMus1623dELWwx57rLCFqGh7N4ZRbGDRP4fnVcaKg1BcUxQ866Ven4gw8y4N56S5HzxXNBZtLYmhGHvDtk6PFkFwCvxYrNYjh
BLS Public key is 2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw
Proof of possession for BLS key is RPLagxaR5xdimFzwmzYnz4ZhWtYQEj8iR5ZU53T2gitPCyCHQneUn2Huc4oeLd2B2HzkGnjAff4hWTJT6C7qHYB1Mv2wU5iHHGFWkhnTX9WsEAbunJCV2qcaXScKj4tTfvdDKfLiVuU2av6hbsMztirRze7LvYBkRHV3tGwyCptsrP

------------------------------------------------------------------------------------------------
Generated genesis transaction file; /home/indy/ledger/sandbox/pool_transactions_genesis

{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node1","blskey":"4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba","blskey_pop":"RahHYiCvoNCtPTrVtP7nMC5eTYrsUA8WjXbdhNc8debh1agE9bGiJxWBXYNFbnJXoXhWFMvyqhqhRoq737YQemH5ik9oL7R4NTTCz2LEZhkgLJzB3QRQqJyBNyv7acbdHrAT8nQ9UkLbaVL9NBpnWXBTw4LEMePaSHEw66RzPNdAX1","client_ip":"172.17.0.1","client_port":9702,"node_ip":"172.17.0.1","node_port":9701,"services":["VALIDATOR"]},"dest":"Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv"},"metadata":{"from":"Th7MpTaRZVRYnPiabds81Y"},"type":"0"},"txnMetadata":{"seqNo":1,"txnId":"fea82e10e894419fe2bea7d96296a6d46f50f93f9eeda954ec461b2ed2950b62"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node2","blskey":"37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk","blskey_pop":"Qr658mWZ2YC8JXGXwMDQTzuZCWF7NK9EwxphGmcBvCh6ybUuLxbG65nsX4JvD4SPNtkJ2w9ug1yLTj6fgmuDg41TgECXjLCij3RMsV8CwewBVgVN67wsA45DFWvqvLtu4rjNnE9JbdFTc1Z4WCPA3Xan44K1HoHAq9EVeaRYs8zoF5","client_ip":"172.17.0.1","client_port":9704,"node_ip":"172.17.0.1","node_port":9703,"services":["VALIDATOR"]},"dest":"8ECVSk179mjsjKRLWiQtssMLgp6EPhWXtaYyStWPSGAb"},"metadata":{"from":"EbP4aYNeTHL6q385GuVpRV"},"type":"0"},"txnMetadata":{"seqNo":2,"txnId":"1ac8aece2a18ced660fef8694b61aac3af08ba875ce3026a160acbc3a3af35fc"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node3","blskey":"3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5","blskey_pop":"QwDeb2CkNSx6r8QC8vGQK3GRv7Yndn84TGNijX8YXHPiagXajyfTjoR87rXUu4G4QLk2cF8NNyqWiYMus1623dELWwx57rLCFqGh7N4ZRbGDRP4fnVcaKg1BcUxQ866Ven4gw8y4N56S5HzxXNBZtLYmhGHvDtk6PFkFwCvxYrNYjh","client_ip":"172.17.0.1","client_port":9706,"node_ip":"172.17.0.1","node_port":9705,"services":["VALIDATOR"]},"dest":"DKVxG2fXXTU8yT5N7hGEbXB3dfdAnYv1JczDUHpmDxya"},"metadata":{"from":"4cU41vWW82ArfxJxHkzXPG"},"type":"0"},"txnMetadata":{"seqNo":3,"txnId":"7e9f355dffa78ed24668f0e0e369fd8c224076571c51e2ea8be5f26479edebe4"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node4","blskey":"2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw","blskey_pop":"RPLagxaR5xdimFzwmzYnz4ZhWtYQEj8iR5ZU53T2gitPCyCHQneUn2Huc4oeLd2B2HzkGnjAff4hWTJT6C7qHYB1Mv2wU5iHHGFWkhnTX9WsEAbunJCV2qcaXScKj4tTfvdDKfLiVuU2av6hbsMztirRze7LvYBkRHV3tGwyCptsrP","client_ip":"172.17.0.1","client_port":9708,"node_ip":"172.17.0.1","node_port":9707,"services":["VALIDATOR"]},"dest":"4PS3EDQ3dW1tci1Bp6543CfuuebjFrg36kLAUcskGfaA"},"metadata":{"from":"TWwCRQRZ2ZHMJFn9TzLp7W"},"type":"0"},"txnMetadata":{"seqNo":4,"txnId":"aa5e817d7cc626170eca175822029339a444eb0ee8f0bd20d3b0b76e566fb008"},"ver":"1"}
================================================================================================

INFO:__main__:REGISTER_NEW_DIDS is set to True
INFO:__main__:LEDGER_INSTANCE_NAME is set to "localhost"
INFO:__main__:Web analytics are DISABLED
INFO:__main__:Running webserver...
INFO:__main__:Creating trust anchor...
INFO:server.anchor:Ledger cache will be stored in :memory:
======== Running on http://0.0.0.0:8000 ========
(Press CTRL+C to quit)
INFO:server.anchor:Initializing transaction database
INFO:server.anchor:Genesis file found: /home/indy/ledger/sandbox/pool_transactions_genesis
INFO:server.anchor:Connecting to ledger pool
INFO:server.anchor:Pool timeout occurred, waiting 10 seconds to retry
INFO:server.anchor:Connecting to ledger pool
INFO:server.anchor:Pool timeout occurred, waiting 10 seconds to retry
INFO:server.anchor:Connecting to ledger pool
INFO:server.anchor:Pool timeout occurred, waiting 10 seconds to retry
INFO:server.anchor:Connecting to ledger pool
INFO:server.anchor:Pool timeout occurred, waiting 10 seconds to retry
INFO:server.anchor:Connecting to ledger pool
INFO:server.anchor:Pool timeout occurred, waiting 10 seconds to retry
INFO:server.anchor:Connecting to ledger pool
ERROR:server.anchor:Initialization error:
Traceback (most recent call last):
  File "/home/indy/server/anchor.py", line 211, in _open_pool
    self._pool = await open_pool(transactions_path=genesis)
  File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/indy_vdr/pool.py", line 177, in open_pool
    await pool.refresh()
  File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/indy_vdr/pool.py", line 58, in refresh
    await bindings.pool_refresh(self.handle)
indy_vdr.error.VdrError: Pool timeout: Request was interrupted

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/indy/server/anchor.py", line 307, in open
    await self._open_pool()
  File "/home/indy/server/anchor.py", line 221, in _open_pool
    raise AnchorException("Error opening pool ledger connection") from e
server.anchor.AnchorException: Error opening pool ledger connection
INFO:__main__:--- Trust anchor initialized ---

Node-1 log:

================================================================================================
Generating genesis transaction file:
nodeArg: --nodeNum 1
ipAddresses: 172.17.0.1,172.17.0.1,172.17.0.1,172.17.0.1
genesisFilePath: /home/indy/ledger/sandbox/pool_transactions_genesis
------------------------------------------------------------------------------------------------
generate_indy_pool_transactions --nodes 4 --clients 0 --nodeNum 1 --ips 172.17.0.1,172.17.0.1,172.17.0.1,172.17.0.1

Generating keys for provided seed b'000000000000000000000000000Node1'
Init local keys for client-stack
Public key is HXrfcFWDjWusENBoXhV8mARzq51f1npWYWaA1GzfeMDG
Verification key is Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv
Init local keys for node-stack
Public key is HXrfcFWDjWusENBoXhV8mARzq51f1npWYWaA1GzfeMDG
Verification key is Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv
BLS Public key is 4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba
Proof of possession for BLS key is RahHYiCvoNCtPTrVtP7nMC5eTYrsUA8WjXbdhNc8debh1agE9bGiJxWBXYNFbnJXoXhWFMvyqhqhRoq737YQemH5ik9oL7R4NTTCz2LEZhkgLJzB3QRQqJyBNyv7acbdHrAT8nQ9UkLbaVL9NBpnWXBTw4LEMePaSHEw66RzPNdAX1
Nodes will not run locally, so writing /etc/indy/indy.env
This node with name Node1 will use ports 9701 and 9702 for nodestack and clientstack respectively
BLS Public key is 37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk
Proof of possession for BLS key is Qr658mWZ2YC8JXGXwMDQTzuZCWF7NK9EwxphGmcBvCh6ybUuLxbG65nsX4JvD4SPNtkJ2w9ug1yLTj6fgmuDg41TgECXjLCij3RMsV8CwewBVgVN67wsA45DFWvqvLtu4rjNnE9JbdFTc1Z4WCPA3Xan44K1HoHAq9EVeaRYs8zoF5
BLS Public key is 3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5
Proof of possession for BLS key is QwDeb2CkNSx6r8QC8vGQK3GRv7Yndn84TGNijX8YXHPiagXajyfTjoR87rXUu4G4QLk2cF8NNyqWiYMus1623dELWwx57rLCFqGh7N4ZRbGDRP4fnVcaKg1BcUxQ866Ven4gw8y4N56S5HzxXNBZtLYmhGHvDtk6PFkFwCvxYrNYjh
BLS Public key is 2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw
Proof of possession for BLS key is RPLagxaR5xdimFzwmzYnz4ZhWtYQEj8iR5ZU53T2gitPCyCHQneUn2Huc4oeLd2B2HzkGnjAff4hWTJT6C7qHYB1Mv2wU5iHHGFWkhnTX9WsEAbunJCV2qcaXScKj4tTfvdDKfLiVuU2av6hbsMztirRze7LvYBkRHV3tGwyCptsrP
BLS Public key is 4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba
Proof of possession for BLS key is RahHYiCvoNCtPTrVtP7nMC5eTYrsUA8WjXbdhNc8debh1agE9bGiJxWBXYNFbnJXoXhWFMvyqhqhRoq737YQemH5ik9oL7R4NTTCz2LEZhkgLJzB3QRQqJyBNyv7acbdHrAT8nQ9UkLbaVL9NBpnWXBTw4LEMePaSHEw66RzPNdAX1
BLS Public key is 37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk
Proof of possession for BLS key is Qr658mWZ2YC8JXGXwMDQTzuZCWF7NK9EwxphGmcBvCh6ybUuLxbG65nsX4JvD4SPNtkJ2w9ug1yLTj6fgmuDg41TgECXjLCij3RMsV8CwewBVgVN67wsA45DFWvqvLtu4rjNnE9JbdFTc1Z4WCPA3Xan44K1HoHAq9EVeaRYs8zoF5
BLS Public key is 3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5
Proof of possession for BLS key is QwDeb2CkNSx6r8QC8vGQK3GRv7Yndn84TGNijX8YXHPiagXajyfTjoR87rXUu4G4QLk2cF8NNyqWiYMus1623dELWwx57rLCFqGh7N4ZRbGDRP4fnVcaKg1BcUxQ866Ven4gw8y4N56S5HzxXNBZtLYmhGHvDtk6PFkFwCvxYrNYjh
BLS Public key is 2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw
Proof of possession for BLS key is RPLagxaR5xdimFzwmzYnz4ZhWtYQEj8iR5ZU53T2gitPCyCHQneUn2Huc4oeLd2B2HzkGnjAff4hWTJT6C7qHYB1Mv2wU5iHHGFWkhnTX9WsEAbunJCV2qcaXScKj4tTfvdDKfLiVuU2av6hbsMztirRze7LvYBkRHV3tGwyCptsrP

------------------------------------------------------------------------------------------------
Generated genesis transaction file; /home/indy/ledger/sandbox/pool_transactions_genesis

{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node1","blskey":"4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba","blskey_pop":"RahHYiCvoNCtPTrVtP7nMC5eTYrsUA8WjXbdhNc8debh1agE9bGiJxWBXYNFbnJXoXhWFMvyqhqhRoq737YQemH5ik9oL7R4NTTCz2LEZhkgLJzB3QRQqJyBNyv7acbdHrAT8nQ9UkLbaVL9NBpnWXBTw4LEMePaSHEw66RzPNdAX1","client_ip":"172.17.0.1","client_port":9702,"node_ip":"172.17.0.1","node_port":9701,"services":["VALIDATOR"]},"dest":"Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv"},"metadata":{"from":"Th7MpTaRZVRYnPiabds81Y"},"type":"0"},"txnMetadata":{"seqNo":1,"txnId":"fea82e10e894419fe2bea7d96296a6d46f50f93f9eeda954ec461b2ed2950b62"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node2","blskey":"37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk","blskey_pop":"Qr658mWZ2YC8JXGXwMDQTzuZCWF7NK9EwxphGmcBvCh6ybUuLxbG65nsX4JvD4SPNtkJ2w9ug1yLTj6fgmuDg41TgECXjLCij3RMsV8CwewBVgVN67wsA45DFWvqvLtu4rjNnE9JbdFTc1Z4WCPA3Xan44K1HoHAq9EVeaRYs8zoF5","client_ip":"172.17.0.1","client_port":9704,"node_ip":"172.17.0.1","node_port":9703,"services":["VALIDATOR"]},"dest":"8ECVSk179mjsjKRLWiQtssMLgp6EPhWXtaYyStWPSGAb"},"metadata":{"from":"EbP4aYNeTHL6q385GuVpRV"},"type":"0"},"txnMetadata":{"seqNo":2,"txnId":"1ac8aece2a18ced660fef8694b61aac3af08ba875ce3026a160acbc3a3af35fc"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node3","blskey":"3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5","blskey_pop":"QwDeb2CkNSx6r8QC8vGQK3GRv7Yndn84TGNijX8YXHPiagXajyfTjoR87rXUu4G4QLk2cF8NNyqWiYMus1623dELWwx57rLCFqGh7N4ZRbGDRP4fnVcaKg1BcUxQ866Ven4gw8y4N56S5HzxXNBZtLYmhGHvDtk6PFkFwCvxYrNYjh","client_ip":"172.17.0.1","client_port":9706,"node_ip":"172.17.0.1","node_port":9705,"services":["VALIDATOR"]},"dest":"DKVxG2fXXTU8yT5N7hGEbXB3dfdAnYv1JczDUHpmDxya"},"metadata":{"from":"4cU41vWW82ArfxJxHkzXPG"},"type":"0"},"txnMetadata":{"seqNo":3,"txnId":"7e9f355dffa78ed24668f0e0e369fd8c224076571c51e2ea8be5f26479edebe4"},"ver":"1"}
{"reqSignature":{},"txn":{"data":{"data":{"alias":"Node4","blskey":"2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw","blskey_pop":"RPLagxaR5xdimFzwmzYnz4ZhWtYQEj8iR5ZU53T2gitPCyCHQneUn2Huc4oeLd2B2HzkGnjAff4hWTJT6C7qHYB1Mv2wU5iHHGFWkhnTX9WsEAbunJCV2qcaXScKj4tTfvdDKfLiVuU2av6hbsMztirRze7LvYBkRHV3tGwyCptsrP","client_ip":"172.17.0.1","client_port":9708,"node_ip":"172.17.0.1","node_port":9707,"services":["VALIDATOR"]},"dest":"4PS3EDQ3dW1tci1Bp6543CfuuebjFrg36kLAUcskGfaA"},"metadata":{"from":"TWwCRQRZ2ZHMJFn9TzLp7W"},"type":"0"},"txnMetadata":{"seqNo":4,"txnId":"aa5e817d7cc626170eca175822029339a444eb0ee8f0bd20d3b0b76e566fb008"},"ver":"1"}
================================================================================================

start_indy_node Node1 0.0.0.0 9701 0.0.0.0 9702
2024-07-11 08:53:05,285|INFO|notifier_plugin_manager.py|Found notifier plugins: []
2024-07-11 08:53:05,341|INFO|notifier_plugin_manager.py|Found notifier plugins: []
2024-07-11 08:53:05,375|INFO|looper.py|Starting up indy-node
2024-07-11 08:53:05,426|INFO|ledger.py|Starting ledger...
2024-07-11 08:53:05,449|INFO|ledger.py|Recovering tree from transaction log
2024-07-11 08:53:05,498|INFO|ledger.py|Recovered tree in 0.04957106100027886 seconds
2024-07-11 08:53:05,557|INFO|ledger.py|Starting ledger...
2024-07-11 08:53:05,576|INFO|ledger.py|Recovering tree from transaction log
2024-07-11 08:53:05,692|INFO|ledger.py|Recovered tree in 0.11656944500009558 seconds
2024-07-11 08:53:05,742|INFO|ledger.py|Starting ledger...
2024-07-11 08:53:05,757|INFO|ledger.py|Recovering tree from transaction log
2024-07-11 08:53:05,786|INFO|ledger.py|Recovered tree in 0.028618037000342156 seconds
2024-07-11 08:53:05,827|INFO|ledger.py|Starting ledger...
2024-07-11 08:53:05,843|INFO|ledger.py|Recovering tree from transaction log
2024-07-11 08:53:05,874|INFO|ledger.py|Recovered tree in 0.031026632999783033 seconds
2024-07-11 08:53:05,997|NOTIFICATION|node_bootstrap.py|BLS: BLS Signatures will be used for Node Node1
2024-07-11 08:53:05,998|INFO|pool_manager.py|Node1 sets node Node1 (Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv) order to 5
2024-07-11 08:53:05,998|INFO|pool_manager.py|Node1 sets node Node2 (8ECVSk179mjsjKRLWiQtssMLgp6EPhWXtaYyStWPSGAb) order to 5
2024-07-11 08:53:05,998|INFO|pool_manager.py|Node1 sets node Node3 (DKVxG2fXXTU8yT5N7hGEbXB3dfdAnYv1JczDUHpmDxya) order to 5
2024-07-11 08:53:05,998|INFO|pool_manager.py|Node1 sets node Node4 (4PS3EDQ3dW1tci1Bp6543CfuuebjFrg36kLAUcskGfaA) order to 5
2024-07-11 08:53:06,002|INFO|notifier_plugin_manager.py|Found notifier plugins: []
2024-07-11 08:53:06,002|INFO|notifier_plugin_manager.py|Found notifier plugins: []
2024-07-11 08:53:06,004|INFO|stacks.py|Node1C: clients connections tracking is enabled.
2024-07-11 08:53:06,004|INFO|stacks.py|Node1C: client stack restart is enabled.
2024-07-11 08:53:06,031|NOTIFICATION|plugin_loader.py|skipping plugin plugin_firebase_stats_consumer[class: typing.Dict] because it does not have a 'pluginType' attribute
2024-07-11 08:53:06,031|NOTIFICATION|plugin_loader.py|skipping plugin plugin_firebase_stats_consumer[class: <class 'plenum.server.plugin.stats_consumer.stats_publisher.StatsPublisher'>] because it does not have a 'pluginType' attribute
2024-07-11 08:53:06,031|NOTIFICATION|plugin_loader.py|skipping plugin plugin_firebase_stats_consumer[class: <enum 'Topic'>] because it does not have a 'pluginType' attribute
2024-07-11 08:53:06,032|NOTIFICATION|plugin_loader.py|skipping plugin plugin_firebase_stats_consumer[class: <class 'plenum.server.plugin_loader.HasDynamicallyImportedModules'>] because it does not have a 'pluginType' attribute
2024-07-11 08:53:06,032|NOTIFICATION|plugin_loader.py|skipping plugin plugin_firebase_stats_consumer[class: <class 'plenum.server.stats_consumer.StatsConsumer'>] because it does not have a 'pluginType' attribute
2024-07-11 08:53:06,032|INFO|plugin_loader.py|plugin FirebaseStatsConsumer successfully loaded from module plugin_firebase_stats_consumer
2024-07-11 08:53:06,032|INFO|node.py|Node1 updated its pool parameters: f 1, totalNodes 4, allNodeNames {'Node4', 'Node3', 'Node2', 'Node1'}, requiredNumberOfInstances 2, minimumNodes 3, quorums {'n': 4, 'f': 1, 'weak': Quorum(2), 'strong': Quorum(3), 'propagate': Quorum(2), 'prepare': Quorum(2), 'commit': Quorum(3), 'reply': Quorum(2), 'view_change': Quorum(3), 'election': Quorum(3), 'view_change_ack': Quorum(2), 'view_change_done': Quorum(3), 'same_consistency_proof': Quorum(2), 'consistency_proof': Quorum(2), 'ledger_status': Quorum(2), 'ledger_status_last_3PC': Quorum(2), 'checkpoint': Quorum(2), 'timestamp': Quorum(2), 'bls_signatures': Quorum(3), 'observer_data': Quorum(2), 'backup_instance_faulty': Quorum(2)}
2024-07-11 08:53:06,032|INFO|consensus_shared_data.py|Node1:0 updated validators list to ['Node1', 'Node2', 'Node3', 'Node4']
2024-07-11 08:53:06,034|INFO|primary_connection_monitor_service.py|Node1:0 scheduling primary connection check in 60 sec
2024-07-11 08:53:06,034|NOTIFICATION|replicas.py|Node1 added replica Node1:0 to instance 0 (master)
2024-07-11 08:53:06,034|INFO|replicas.py|reset monitor due to replica addition
2024-07-11 08:53:06,034|INFO|consensus_shared_data.py|Node1:1 updated validators list to ['Node1', 'Node2', 'Node3', 'Node4']
2024-07-11 08:53:06,035|NOTIFICATION|replicas.py|Node1 added replica Node1:1 to instance 1 (backup)
2024-07-11 08:53:06,035|INFO|replicas.py|reset monitor due to replica addition
2024-07-11 08:53:06,036|INFO|consensus_shared_data.py|Node1:0 updated validators list to {'Node4', 'Node3', 'Node2', 'Node1'}
2024-07-11 08:53:06,036|INFO|consensus_shared_data.py|Node1:1 updated validators list to {'Node4', 'Node3', 'Node2', 'Node1'}
2024-07-11 08:53:06,036|INFO|replica.py|Node1:0 setting primaryName for view no 0 to: Node1:0
2024-07-11 08:53:06,036|NOTIFICATION|primary_connection_monitor_service.py|Node1:0 restored connection to primary of master
2024-07-11 08:53:06,036|NOTIFICATION|node.py|PRIMARY SELECTION:  selected primary Node1:0 for instance 0 (view 0)
2024-07-11 08:53:06,036|INFO|replica.py|Node1:1 setting primaryName for view no 0 to: Node2:1
2024-07-11 08:53:06,036|NOTIFICATION|node.py|PRIMARY SELECTION:  selected primary Node2:1 for instance 1 (view 0)
2024-07-11 08:53:06,036|INFO|node.py|total plugins loaded in node: 0
2024-07-11 08:53:06,037|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> found state to be empty, recreating from ledger 0
2024-07-11 08:53:06,039|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> initialized state for ledger 0: state root 8xwEHCkVcEA9qfBJaESpWKvtHVxUkvzJctAHfBiVhAAJ
2024-07-11 08:53:06,039|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> found state to be empty, recreating from ledger 2
2024-07-11 08:53:06,039|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> initialized state for ledger 2: state root DfNLmH4DAHTKv63YPFJzuRdeEtVwF5RtVnvKYHd8iLEA
2024-07-11 08:53:06,039|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> found state to be empty, recreating from ledger 1
2024-07-11 08:53:06,041|INFO|ledgers_bootstrap.py|<indy_node.server.node_bootstrap.NodeBootstrap object at 0x7fdd6a3bf358> initialized state for ledger 1: state root GWEizEWQdGH5QFdxRpoQGvPR42zSUEJoFkQKGBHiNDbM
2024-07-11 08:53:06,041|INFO|motor.py|Node1 changing status from stopped to starting
2024-07-11 08:53:06,042|INFO|zstack.py|Node1 will bind its listener at 0.0.0.0:9701
2024-07-11 08:53:06,042|INFO|stacks.py|CONNECTION: Node1 listening for other nodes at 0.0.0.0:9701
2024-07-11 08:53:06,042|INFO|zstack.py|Node1C will bind its listener at 0.0.0.0:9702
2024-07-11 08:53:06,054|INFO|node.py|Node1 first time running...
2024-07-11 08:53:06,054|INFO|node.py|Node1 processed 0 Ordered batches for instance 0 before starting catch up
2024-07-11 08:53:06,055|INFO|node.py|Node1 processed 0 Ordered batches for instance 1 before starting catch up
2024-07-11 08:53:06,055|INFO|ordering_service.py|Node1:0 reverted 0 batches before starting catch up
2024-07-11 08:53:06,055|INFO|node_leecher_service.py|Node1:NodeLeecherService starting catchup (is_initial=True)
2024-07-11 08:53:06,055|INFO|node_leecher_service.py|Node1:NodeLeecherService transitioning from Idle to PreSyncingPool
2024-07-11 08:53:06,055|INFO|cons_proof_service.py|Node1:ConsProofService:0 starts
2024-07-11 08:53:06,056|INFO|kit_zstack.py|CONNECTION: Node1 found the following missing connections: Node4, Node3, Node2
2024-07-11 08:53:06,056|INFO|zstack.py|CONNECTION: Node1 looking for Node4 at 172.17.0.1:9707
2024-07-11 08:53:06,058|INFO|zstack.py|CONNECTION: Node1 looking for Node3 at 172.17.0.1:9705
2024-07-11 08:53:06,058|INFO|zstack.py|CONNECTION: Node1 looking for Node2 at 172.17.0.1:9703
2024-07-11 08:53:21,056|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
2024-07-11 08:53:36,066|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
2024-07-11 08:53:51,069|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
2024-07-11 08:54:06,080|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
2024-07-11 08:54:21,082|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
2024-07-11 08:54:36,094|INFO|cons_proof_service.py|Node1:ConsProofService:0 asking for ledger status of ledger 0
WadeBarnes commented 3 months ago

Please ensure you are running the latest code. Also try resetting the environment by running ./manage rm before ./mange start.

On which platform are you running?

arminveres commented 3 months ago

Hi @WadeBarnes, yes, I always run down/rm and start. I tried with the newest commit as well.

I am running on NixOS x86-64.

UPDATE: I opened the TCP ports and now it works... maybe there some networking magic going on inside NixOS that I missed, but since it is local, I have the intuition, that this shouldn't be necessary...