Problems with IpSubscription while setting up a private Cardano Blockchain

English Community Technical Support
1

Hello there,

I’ve been working on setting up a private Cardano Blockchain for research purposes and ran into some problems. My two nodes don’t seem to establish a connection, I get several IpSubscription Errors.
My setup is the following:

I’m working on 2 virtual machines that each have the cardano-node version 1.25.1 installed. I am able to telnet the nodes from each other on port 3001 if the nodes are running. I have generated a genesis.json file based on generated keys for both nodes.
It looks like this:

{
    "activeSlotsCoeff": 5.0e-2,
    "protocolParams": {
        "poolDeposit": 0,
        "protocolVersion": {
            "minor": 0,
            "major": 0
        },
        "minUTxOValue": 0,
        "decentralisationParam": 1,
        "maxTxSize": 16384,
        "minPoolCost": 0,
        "minFeeA": 0,
        "maxBlockBodySize": 65536,
        "minFeeB": 0,
        "eMax": 18,
        "extraEntropy": {
            "tag": "NeutralNonce"
        },
        "maxBlockHeaderSize": 1100,
        "keyDeposit": 0,
        "nOpt": 100,
        "rho": 0,
        "tau": 0,
        "a0": 0
    },
    "genDelegs": {
        "6371a1d68ac2c0d2bfc0f7246577ee52c462e2f8c24c2a7bf31bc973": {
            "delegate": "c76ed9f1e78c345176a321047736d963edf66bd062ef9f3a37311dc5",
            "vrf": "b8882e1505dd3708bd330d1ae6b7075748cc996147cda3dea352dffa47a5225a"
        },
        "cf81637c4a0bbddac48cede3e307714af88988de5be5776733a6edc8": {
            "delegate": "4730f0a6f49f32f90e15a9265e2c24604777a5a087cf5fc5773975f0",
            "vrf": "352b6bd54edf99758ea70ec75ab0bc62c56b6ea2f33e208cc742ac92c78f6990"
        }
    },
    "updateQuorum": 5,
    "networkId": "Testnet",
    "initialFunds": {
        "600d2c10a710c36e70d2ff051b6e80ae9aafa5de6206f9546fa1ff7dfb": 500000,
        "6029c410da64e03bdacd3677d33e99e77dd17cc04272c1622093e00f30": 500000
    },
    "maxLovelaceSupply": 1000000,
    "networkMagic": 420,
    "epochLength": 432000,
    "staking": {
        "pools": {},
        "stake": {}
    },
    "systemStart": "2021-03-05T14:55:37.743339617Z",
    "slotsPerKESPeriod": 129600,
    "slotLength": 1,
    "maxKESEvolutions": 60,
    "securityParam": 2160
}

My configuration.yaml file looks like this (based on the Byron configuration.yaml):

##### Locations #####

GenesisFile: genesis.json
SocketPath: db/node.socket


##### Blockfetch Protocol

# The maximum number of used peers during bulk sync.
MaxConcurrencyBulkSync: 1
# The maximum number of used peers when fetching newly forged blocks.
MaxConcurrencyDeadline: 2


##### Core protocol parameters #####

# This is the instance of the Ouroboros family that we are running.
Protocol: TPraos

# The mainnet does not include the network magic into addresses. Testnets do.
RequiresNetworkMagic: RequiresMagic


##### Update system parameters #####

# This protocol version number gets used by block producing nodes as part
# of the system for agreeing on and synchronising protocol updates.
LastKnownBlockVersion-Major: 0
LastKnownBlockVersion-Minor: 2
LastKnownBlockVersion-Alt: 0

# In the Byron era some software versions are also published on the chain.
# We do this only for Byron compatibility now.
ApplicationName: cardano-sl
ApplicationVersion: 1


##### Logging configuration #####
...

My topology files each look like this:

{
  "Producers": [
    {
      "addr": "xxx.xxx.xxx.xxx",
      "port": 3001,
      "valency": 1
    }
  ]
}

I start my nodes like this:

cardano-node run \
    --config path/configuration.yaml \
    --topology path/topology.json \
    --database-path path/db \
    --socket-path path/node.sock \
    --shelley-kes-key path/kes.skey \
    --shelley-vrf-key path/delegateX.vrf.skey \
    --shelley-operational-certificate path/cert \
    --port 3001
    --host-addr xxx.xxx.xxx.xxx

It seems like my nodes cannot connect to each other, I get the following errors and warnings on node 1:

[cardano1:cardano.node.IpSubscription:Debug:47] [2021-03-05 17:58:30.10 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Starting Subscription Worker, valency 1
[cardano1:cardano.node.ForgeTime:Info:33] [2021-03-05 17:58:30.10 UTC] fromList []
[cardano1:cardano.node.IpSubscription:Info:47] [2021-03-05 17:58:30.10 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Trying to connect to xxx.xxx.xxx.xxx:3001
[cardano1:cardano.node.IpSubscription:Info:50] [2021-03-05 17:58:30.10 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt Start, destination xxx.xxx.xxx.xxx:3001
[cardano1:cardano.node.IpSubscription:Notice:47] [2021-03-05 17:58:30.10 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Waiting 0.025s before attempting a new connection
[cardano1:cardano.node.IpSubscription:Debug:50] [2021-03-05 17:58:30.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Allocate socket to xxx.xxx.xxx.xxx:3001
[cardano1:cardano.node.IpSubscription:Error:50] [2021-03-05 17:58:30.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt Exception, destination xxx.xxx.xxx.xxx:3001 exception: Network.Socket.connec>
[cardano1:cardano.node.IpSubscription:Info:50] [2021-03-05 17:58:30.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Closed socket to xxx.xxx.xxx.xxx:3001
[cardano1:cardano.node.ErrorPolicy:Notice:40] [2021-03-05 17:58:30.11 UTC] IP xxx.xxx.xxx.xxx:3001 ErrorPolicySuspendConsumer (Just (ConnectionExceptionTrace Network.Socket.connect: <socket: 26>: does not exist (Conne>
[cardano1:cardano.node.IpSubscription:Error:47] [2021-03-05 17:58:30.13 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Failed to start all required subscriptions

[cardano1:cardano.node.IpSubscription:Info:47] [2021-03-05 17:58:31.13 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Restarting Subscription after 1.026468901s desired valency 1 current valency 0

[cardano1:cardano.node.ErrorPolicy:Warning:44] [2021-03-05 17:58:48.93 UTC] IP xxx.xxx.xxx.xxx:35399 ErrorPolicySuspendPeer (Just (ApplicationExceptionTrace (MuxError MuxBearerClosed "<socket: 33> closed when reading >

[cardano1:cardano.node.IpSubscription:Debug:47] [2021-03-05 17:58:50.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Starting Subscription Worker, valency 1
[cardano1:cardano.node.IpSubscription:Info:47] [2021-03-05 17:58:50.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Skipping peer xxx.xxx.xxx.xxx:3001
[cardano1:cardano.node.IpSubscription:Error:47] [2021-03-05 17:58:50.11 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Failed to start all required subscriptions

And these on node 2:

[cardano2:cardano.node.IpSubscription:Debug:45] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Starting Subscription Worker, valency 1
[cardano2:cardano.node.IpSubscription:Info:45] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Trying to connect to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Info:50] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt Start, destination xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Debug:50] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Allocate socket to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Notice:45] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Waiting 0.025s before attempting a new connection
[cardano2:cardano.node.IpSubscription:Notice:50] [2021-03-05 18:09:26.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt End, destination xxx.xxx.xxx.xxx:3001 outcome: ConnectSuccessLast
[cardano2:cardano.node.IpSubscription:Error:50] [2021-03-05 18:09:26.31 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Application Exception: xxx.xxx.xxx.xxx:3001 HeaderError (At (Block {blockPointSlot = SlotNo 2260, blockPointHa>
[cardano2:cardano.node.IpSubscription:Info:50] [2021-03-05 18:09:26.31 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Closed socket to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.ErrorPolicy:Warning:41] [2021-03-05 18:09:26.31 UTC] IP xxx.xxx.xxx.xxx:3001 ErrorPolicySuspendPeer (Just (ApplicationExceptionTrace (HeaderError (At (Block {blockPointSlot = SlotNo 2260, blockPointHash = a445>
[cardano2:cardano.node.IpSubscription:Error:45] [2021-03-05 18:09:26.32 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Failed to start all required subscriptions

[cardano2:cardano.node.IpSubscription:Debug:45] [2021-03-05 18:09:36.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Starting Subscription Worker, valency 1
[cardano2:cardano.node.IpSubscription:Info:45] [2021-03-05 18:09:36.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Trying to connect to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Notice:45] [2021-03-05 18:09:36.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Waiting 0.025s before attempting a new connection
[cardano2:cardano.node.IpSubscription:Info:66] [2021-03-05 18:09:36.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt Start, destination xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Debug:66] [2021-03-05 18:09:36.29 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Allocate socket to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.IpSubscription:Notice:66] [2021-03-05 18:09:36.30 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Connection Attempt End, destination xxx.xxx.xxx.xxx:3001 outcome: ConnectSuccessLast
[cardano2:cardano.node.IpSubscription:Debug:45] [2021-03-05 18:09:36.32 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Required subscriptions started
[cardano2:cardano.node.IpSubscription:Error:66] [2021-03-05 18:09:36.32 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Application Exception: xxx.xxx.xxx.xxx:3001 HeaderError (At (Block {blockPointSlot = SlotNo 2260, blockPointHash = a44564db0e3b8acaacc6bd0bba2f9952a3739355c9e41e0cf1e21b53f2732063})) (HeaderProtocolError (HardForkValidationErrFromEra Z (WrapValidationErr {unwrapValidationErr = ChainTransitionError [OverlayFailure (VRFKeyBadNonce (Nonce "81e47a19e6b29b0a65b9591762ce5143ed30d0261e5d24a3201752506b20f15c") (SlotNo 2260) (Nonce "d66fc0e927fe29023d1556fff10459bfd9d63a6f9db6eea3b2ede08189e9634e") (CertifiedVRF {certifiedOutput = OutputVRF {getOutputVRFBytes = "\132\EMh\146'\ENQ\219Ei\tRe5X\SOH\171\187A\251\162\bC\217\186\234#;\EM\158\146\SO\151\161\242\&5\254\187\176\203\EOT\187\181\208\200_\144\143G7\173\n\STX\177m\165#\154\207\212\218A\157C\DEL"}, certifiedProof = CertPraosVRF "}\210\"u\218;\173\234v\207:t_g\SOH.\199\186n\DEL\STX\ETX\ESC\218g\r\233a\227\235\f+\176\166\163&J\187\130\f\169\154\178\SI\DC4\227~\NUL\SI\249&.\156k\157\226|\142;\225\CAN\t1\158\STX-\DC3\149\201\167\214_2*\218\FS\225\STX>\SOH"}))]}))) (Tip (SlotNo 11000) 110596ba3d0122b9b885dfc8229b66c8a534ad98c44d5aa348795086e63e61e3 (BlockNo 6)) (Tip (SlotNo 10980) e4ea7a9aedaf4533cfed19fe02528147df6a1307c990278a518d37f38308356f (BlockNo 9))
[cardano2:cardano.node.IpSubscription:Info:66] [2021-03-05 18:09:36.33 UTC] IPs: 0.0.0.0:0 [::]:0 [xxx.xxx.xxx.xxx:3001] Closed socket to xxx.xxx.xxx.xxx:3001
[cardano2:cardano.node.ErrorPolicy:Warning:41] [2021-03-05 18:09:36.33 UTC] IP xxx.xxx.xxx.xxx:3001 ErrorPolicySuspendPeer (Just (ApplicationExceptionTrace (HeaderError (At (Block {blockPointSlot = SlotNo 2260, blockPointHash = a445>

I in part followed the tutorial in the cardano documentation but haven’t gotten this to work so far.

Thanks in advance for any help.

2

Try to start the nodes with host addres 0.0.0.0

Cheers,

3

I still get the same errors when I do that. I also tried starting the nodes without any host-addr argument but that does not fix my issue.
Nethertheless, thanks for the suggestion!

4

Can you try this out: GitHub - yihuang/cardano-devnet: Start cardano devnet locally
It’ll run devnet with native processes rather than virtual machines.
Maybe you can adapt it to VMs.

5

Thanks, I will look into the scripts. Great resource you provide there!

6

Update from my side:
I have been working with your script as well as with the original from the cardano-node repository. It works (mostly) fine when I directly transition to Mary like you added in your repository. Without it I run into problems. A few slots/blocks go by fine and then the slot count and block count just stops right after I get these errors several times:

[cardano1:cardano.node.Forge:Error:33] [2021-03-19 17:31:31.00 UTC] fromList [("credentials",String "Cardano"),("val",Object (fromList [("kind",String "TraceNodeCannotForge"),("reason",Object (fromList [("kind",String "PBftCannotForgeThresholdExceeded"),("numForged",Number 7.0)])),("slot",Number 31.0)]))]
[cardano1:cardano.node.Forge:Error:33] [2021-03-19 17:31:32.00 UTC] fromList [("credentials",String "Cardano"),("val",Object (fromList [("kind",String "TraceNoLedgerView"),("slot",Number 32.0)]))]

The only logs then are [cardano.node.resources:Info:18]
Any ideas what is wrong here?

1 Like
7

Were you able go figure a solution? Here are my errors:

[myhost:cardano.node.ChainDB:Notice:229] Chain extended, new tip: bdf60622b20e3b268aad4b2a0f649e1d7850e81e11de436178654feee41f20eb at slot 23230004
[myhost:cardano.node.LeadershipCheck:Info:239]{"kind":"TraceStartLeadershipCheck","chainDensity":5.0138175e-2,"slot":35717440,"delegMapSize":304077,"utxoSize":1436175,"credentials":"Cardano"}
[myhost:cardano.node.Forge:Error:239] fromList [("val",Object (fromList [("kind",String "TraceNoLedgerView"),("slot",Number 3.571744e7)])),("credentials",String "Cardano")]