I followed the official documentation.
I started a passive relay node and let it sync all the way to the latest tip.
After that I started the Block producer node.
Block node connects to the relay node and syncs perfectly for a while (~2 hours).
After that, there is suddenly a bunch of these for the next 1 minute…
(Log Block 1)
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:09.48 UTC] Chain extended, new tip: d4f220d1c030d8be888e0324aafcdbac3d13267d05b8c53b90c5355f960d7c3d at slot 4471155
[host:cardano.node.ChainDB:Info:47] [2021-07-25 10:06:09.85 UTC] before next, messages elided = 32847590585417
[host:cardano.node.ChainDB:Info:47] [2021-07-25 10:06:09.85 UTC] Valid candidate 586525732f41fa76f2c3b6d97831c2b68158b3429901e5c3c4f39506d1029f55 at slot 4471417
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:09.85 UTC] Chain extended, new tip: 586525732f41fa76f2c3b6d97831c2b68158b3429901e5c3c4f39506d1029f55 at slot 4471417
Event: LedgerUpdate (HardForkUpdateInEra Z (WrapLedgerUpdate {unwrapLedgerUpdate = ByronUpdatedProtocolUpdates [ProtocolUpdate {protocolUpdateVersion = 2.0.0, protocolUpdateState = UpdateRegistered (SlotNo 4471417)}]}))
When the above (log Block 1) repeats a bunch a time, I also get the following intermittently for that 1 minute…
(Log Block 2)
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:18.54 UTC] Chain extended, new tip: 690c2ee8e24ac1c8d8d949e1557332d970daca91ea37ffd33f7f89ef75bc7744 at slot 4475740
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:19.80 UTC] Chain extended, new tip: 96c07f00c505d91942bc69b7dee6d9527156a8e4afed97e0598130c1f3817a8b at slot 4476352
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:21.05 UTC] Chain extended, new tip: a92d92fd9228cdd67c0ef8f5e5da11235471597b3c0ac4d52eda1f3410b32bd0 at slot 4476914
But right after that one minute, the following is thrown repeatedly and block producing node stops listening on port 3001.
(Log Block 3)
[host:cardano.node.ChainDB:Notice:47] [2021-07-25 10:06:44.42 UTC] Chain extended, new tip: a6d419dd77a9ab542053ee7bbe0dbbb796790500e6d36c6e6456577422e47bd4 at slot 4488338
cardano-node: symbol lookup error: cardano-node: undefined symbol: crypto_vrf_publickeybytes
bash: line 1: --shelley-kes-key: command not found
Listening on http://127.0.0.1:12798
[host:cardano.node.networkMagic:Notice:5] [2021-07-25 10:06:45.51 UTC] NetworkMagic 764824073
[host:cardano.node.basicInfo.protocol:Notice:5] [2021-07-25 10:06:45.51 UTC] Byron; Shelley
[host:cardano.node.basicInfo.version:Notice:5] [2021-07-25 10:06:45.51 UTC] 1.27.0
[host:cardano.node.basicInfo.commit:Notice:5] [2021-07-25 10:06:45.51 UTC] 8fe46140a52810b6ca456be01d652ca08fe730bf
[host:cardano.node.basicInfo.nodeStartTime:Notice:5] [2021-07-25 10:06:45.51 UTC] 2021-07-25 10:06:45.513386229 UTC
[host:cardano.node.basicInfo.systemStartTime:Notice:5] [2021-07-25 10:06:45.51 UTC] 2017-09-23 21:44:51 UTC
[host:cardano.node.basicInfo.slotLengthByron:Notice:5] [2021-07-25 10:06:45.51 UTC] 20s
[host:cardano.node.basicInfo.epochLengthByron:Notice:5] [2021-07-25 10:06:45.51 UTC] 21600
...
[host:cardano.node.addresses:Notice:5] [2021-07-25 10:06:45.51 UTC] [SocketInfo 0.0.0.0:3001]
[host:cardano.node.diffusion-mode:Notice:5] [2021-07-25 10:06:45.51 UTC] InitiatorAndResponderDiffusionMode
[host:cardano.node.dns-producers:Notice:5] [2021-07-25 10:06:45.51 UTC] [DnsSubscriptionTarget {dstDomain = "relay.example.com", dstPort = 3001, dstValency = 1}]
[host:cardano.node.ip-producers:Notice:5] [2021-07-25 10:06:45.51 UTC] IPSubscriptionTarget {ispIps = [], ispValency = 0}
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:45.15 UTC] Opened imm db with immutable tip at c44f8d234a406cf17495839ab768c101e4e79ce69284c70f9fd88da87f58f6f8 at slot 4486254 and chunk 207
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:50.84 UTC] Opened vol db
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:51.86 UTC] Replaying ledger from snapshot DiskSnapshot {dsNumber = 4329214, dsSuffix = Nothing} at 22eab95a805b7c1faa96950bfb4e320622b638f0ecc67b253d63780534f89452 at slot 4329214
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:51.97 UTC] Replayed block: slot SlotNo 4329215 of At (SlotNo 4486254)
...
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:54.66 UTC] block replay progress (%) = 96.8
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:54.73 UTC] before next, messages elided = 4329215
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:54.73 UTC] Replayed block: slot SlotNo 4341598 of At (SlotNo 4486254)
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:09:54.77 UTC] Replayed block: slot SlotNo 4341599 of At (SlotNo 4486254)
...
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:10:30.26 UTC] block replay progress (%) = 100.0
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:10:30.41 UTC] before next, messages elided = 4483575
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:10:30.41 UTC] Replayed block: slot SlotNo 4486254 of At (SlotNo 4486254)
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:10:30.41 UTC] Opened lgr db
[host:cardano.node.ChainDB:Info:5] [2021-07-25 10:10:32.20 UTC] Opened db with immutable tip at c44f8d234a406cf17495839ab768c101e4e79ce69284c70f9fd88da87f58f6f8 at slot 4486254 and tip 2d4670e35bb9db7c1f9a0e3958d8702e438026a78d45abf3f822062047c6c901 at slot 4488415
[host:cardano.node.DiffusionInitializationTracer:Info:283] [2021-07-25 10:10:32.20 UTC] CreatingServerSocket 0.0.0.0:3001
[host:cardano.node.DiffusionInitializationTracer:Info:283] [2021-07-25 10:10:32.20 UTC] ConfiguringServerSocket 0.0.0.0:3001
[host:cardano.node.DiffusionInitializationTracer:Info:283] [2021-07-25 10:10:32.20 UTC] ListeningServerSocket 0.0.0.0:3001
[host:cardano.node.DiffusionInitializationTracer:Info:283] [2021-07-25 10:10:32.20 UTC] ServerSocketUp 0.0.0.0:3001
[host:cardano.node.DiffusionInitializationTracer:Info:283] [2021-07-25 10:10:32.20 UTC] RunServer 0.0.0.0:3001
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] CreateSystemdSocketForSnocketPath "/opt/cardano/db/node.socket"
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] CreatedLocalSocket "/opt/cardano/db/node.socket"
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] ConfiguringLocalSocket "/opt/cardano/db/node.socket" (FileDescriptor 26)
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] ListeningLocalSocket "/opt/cardano/db/node.socket" (FileDescriptor 26)
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] LocalSocketUp "/opt/cardano/db/node.socket" (FileDescriptor 26)
[host:cardano.node.DiffusionInitializationTracer:Info:285] [2021-07-25 10:10:32.20 UTC] RunLocalServer (LocalAddress "/opt/cardano/db/node.socket")
[host:cardano.node.DnsSubscription:Notice:294] [2021-07-25 10:10:32.50 UTC] Domain: "relay.example.com" Connection Attempt Start, destination 34.223.90.69:3001
[host:cardano.node.DnsSubscription:Notice:294] [2021-07-25 10:10:32.50 UTC] Domain: "relay.example.com" Connection Attempt End, destination 34.223.90.69:3001 outcome: ConnectSuccessLast
[host:cardano.node.ChainDB:Notice:261] [2021-07-25 10:10:32.52 UTC] Chain extended, new tip: dc82a32ecd091801b26204cbce8920132295ea418be49308d440198cfa789150 at slot 4488416
[host:cardano.node.ChainDB:Notice:265] [2021-07-25 10:10:33.46 UTC] before next, messages elided = 33110636782604
[host:cardano.node.ChainDB:Notice:265] [2021-07-25 10:10:33.46 UTC] Chain extended, new tip: 0fc638b151051b7900c7088236a634a3a6a83de58fc02797c9c818cb7bc25f37 at slot 4488589
[host:cardano.node.ChainDB:Info:265] [2021-07-25 10:10:33.46 UTC] Took ledger snapshot DiskSnapshot {dsNumber = 4486255, dsSuffix = Nothing} at c70a0988a0a075fa841c7c3f7a2ff555468009ad065c6d5bb387999302d50fa7 at slot 4486255
[host:cardano.node.ChainDB:Notice:261] [2021-07-25 10:10:33.47 UTC] Chain extended, new tip: 000c99b757ccefa7530b0cd365bf9142a9a1439e1938a936447e72cc783fadef at slot 4488590
[host:cardano.node.ChainDB:Notice:261] [2021-07-25 10:10:33.49 UTC] Chain extended, new tip: ae3bcb884b49dd763b866ba1925f37e48a500e15f4a790d014538e4052e8bdd4 at slot 4488598
[host:cardano.node.ChainDB:Notice:261] [2021-07-25 10:10:34.74 UTC] Chain extended, new tip: 4e7791d59db5f4d005745d3f64af2e7a217ed5f047fa13195ac296011be5ecac at slot 4489071
cardano-node: symbol lookup error: cardano-node: undefined symbol: crypto_vrf_publickeybytes
bash: line 1: --shelley-kes-key: command not found
Listening on http://127.0.0.1:12798
...(repeat)
The following command returns nothing at this point,
$ sudo lsof -i:3001
However the process is running,
$ ps -eac | grep cardano-node
56026 TS 19 pts/1 00:02:19 cardano-node
If I restart the ‘cardano-node’ process, it still does not listen on port 3001 and continues to repeat the above log (Log Block 3) starting with,
Listening on http://127.0.0.1:12798
[host:cardano.node.networkMagic:Notice:5] [2021-07-25 18:46:10.13 UTC] NetworkMagic 764824073
...
If I remove the ‘db’ folder, block node again syncs perfectly for 2 hours until the logs (Log Block 1,2,3) show up and then it stops listening on port 3001.
I have libsodium on block producer node as well and .bashrc has the following:
export LD_LIBRARY_PATH=“/usr/local/lib:$LD_LIBRARY_PATH”
export PKG_CONFIG_PATH=“/usr/local/lib/pkgconfig:$PKG_CONFIG_PATH”
export CARDANO_NODE_SOCKET_PATH=/opt/cardano/db/node.socket
cardano-node run \
--topology /opt/cardano/config/mainnet-topology.json \
--database-path /opt/cardano/db \
--socket-path /opt/cardano/db/node.socket \
--host-addr 0.0.0.0 \
--port 3001 \
--config /opt/cardano/config/mainnet-config.json
--shelley-kes-key /opt/cardano/keys/kes.skey \
--shelley-vrf-key /opt/cardano/keys/vrf.skey \
--shelley-operational-certificate /opt/cardano/certs/node.cert
{
"Producers": [
{
"addr": "relay.example.com",
"port": 3001,
"valency": 1
}
]
}
This is the last error preventing me from going live for the last 4 days. Any help is highly appreciated.