Lot of strange messages from cardano-node

[Michal_Matousek]

Hi,

since last few days the relay nodes produce lot of strange log Info messages, any idea what it means? Does it indicate some problem? Rate is ~50 per minute.

Example:
[RelayNod:cardano.node.ChainSyncHeaderServer:Info:15231] [2021-08-28 11:58:44.36 UTC] fromList [(“kind”,String “ChainSyncServerEvent.TraceChainSyncServerRead.AddBlock”),(“slot”,Number 3.858562e7),(“block”,String “4fde6a183e959634b258e98ec52ba9fed661ba6fa5333e20fad724a1d4e5e5a5”),(“blockNo”,Number 6170944.0)]
[RelayNod:cardano.node.ChainSyncHeaderServer:Info:15231] [2021-08-28 11:58:44.36 UTC] fromList [(“point”,Object (fromList [(“headerHash”,String “978c35fb201bb1fa0f7c73dbd5ca1b30b66b71b5b45b0f81477515f3b3041ef5”),(“kind”,String “BlockPoint”),(“slot”,Number 459876.0)])),(“kind”,String “ChainSyncServerEvent.TraceChainSyncRollForward”)]
[RelayNod:cardano.node.Mempool:Info:15525] [2021-08-28 11:58:46.07 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “524940f9409f854fe08fcddb2824d675d64fe4f1b5b807b8e397da6373ce752b”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 38853.0),(“numTxs”,Number 19.0)])),(“kind”,String “TraceMempoolAddedTx”)]
[RelayNod:cardano.node.Mempool:Info:15525] [2021-08-28 11:58:46.99 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “7ec4ad369aee1a8de36b0b7109fa4ecd4ba6c03ea5bf35d503e80b78be54268e”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 39195.0),(“numTxs”,Number 20.0)])),(“kind”,String “TraceMempoolAddedTx”)]
[RelayNod:cardano.node.Mempool:Info:15525] [2021-08-28 11:58:47.25 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “df622dcdb875da09abb7ede03cc1dd27707493265394a3b06ceab183355e48ed”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 39562.0),(“numTxs”,Number 21.0)])),(“kind”,String “TraceMempoolAddedTx”)]
[RelayNod:cardano.node.Mempool:Info:15271] [2021-08-28 11:58:47.25 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “df622dcdb875da09abb7ede03cc1dd27707493265394a3b06ceab183355e48ed”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 39562.0),(“numTxs”,Number 21.0)])),(“kind”,String “TraceMempoolRejectedTx”),(“err”,Object (fromList [(“badInputs”,Array [String “5ec587dba05c2e2d2f52ea55c952bc015c2e2ff9de48936758801dafe16a2e13#0”]),(“consumed”,Object (fromList [(“lovelace”,Number 1.19713458e8),(“policies”,Object (fromList ))])),(“error”,String “This transaction consumed Value 119713458 (fromList ) but produced Value 610741337 (fromList )”),(“incorrectWithdrawals”,Array [Array [Object (fromList [(“credential”,Object (fromList [(“key hash”,String “89abbafdbf994cd8187d403a557519096f2be128821495b2f367653e”)])),(“network”,String “Mainnet”)]),Number 1.19713458e8]]),(“kind”,String “ValueNotConservedUTxO”),(“produced”,Object (fromList [(“lovelace”,Number 6.10741337e8),(“policies”,Object (fromList ))]))]))]

[dvekris]

I am experiencing the same exact issue on my block producer.

My gLive console shows outgoing connections but NO INCOMING connections, which I feel may be related to the fact that I haven’t minted a block in over two weeks. I’m running 1.29.0 on Ubuntu 20.04.LTS and these strange events and lack of incoming connections started on or around my update to 1.29.0.

Yes, I confirmed tcp/6001 access for BP and tcp/6000 access to my two relays.

Any help would be most appreciated.

Sep 28 15:11:10 block-producer bash[1078937]: [block-pr:cardano.node.Forge:Info:381] [2021-09-28 19:11:10.00 UTC] fromList [(“val”,Object (fromList [(“kind”,String “TraceNodeNotLeader”),(“slot”,Number 4.1289979e7)])),(“credentials”,String “Cardano”)]
Sep 28 15:11:10 block-producer bash[1078937]: [block-pr:cardano.node.Mempool:Info:446] [2021-09-28 19:11:10.45 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “0c9b3c71ec4647d79470232f2a1e91d9345c11c58a311181d6a67205fa4bd04b”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 3678.0),(“numTxs”,Number 7.0)])),(“kind”,String “TraceMempoolAddedTx”)]
Sep 28 15:11:10 block-producer bash[1078937]: [block-pr:cardano.node.Mempool:Info:456] [2021-09-28 19:11:10.47 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “0c9b3c71ec4647d79470232f2a1e91d9345c11c58a311181d6a67205fa4bd04b”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 3678.0),(“numTxs”,Number 7.0)])),(“kind”,String “TraceMempoolRejectedTx”),(“err”,Object (fromList [(“badInputs”,Array [String “2a6e6639b3f4fff715f3a8d8809372ef8ec0335cb0bcd3ed067485184dfeae20#0”,String “2a6e6639b3f4fff715f3a8d8809372ef8ec0335cb0bcd3ed067485184dfeae20#1”]),(“consumed”,Object (fromList [(“lovelace”,Number 3391191.0),(“policies”,Object (fromList ))])),(“error”,String “This transaction consumed Value 3391191 (fromList ) but produced Value 3206930628 (fromList )”),(“incorrectWithdrawals”,Array [Array [Object (fromList [(“credential”,Object (fromList [(“key hash”,String “465987b5b8a9281b2dcaa4cab739dbdf67fe39b20c3546adb69f72a5”)])),(“network”,String “Mainnet”)]),Number 3391191.0]]),(“kind”,String “ValueNotConservedUTxO”),(“produced”,Object (fromList [(“lovelace”,Number 3.206930628e9),(“policies”,Object (fromList ))]))]))]
Sep 28 15:11:11 block-producer bash[1078937]: [block-pr:cardano.node.LeadershipCheck:Info:381] [2021-09-28 19:11:11.00 UTC] {“kind”:“TraceStartLeadershipCheck”,“chainDensity”:4.9669866e-2,“slot”:41289980,“delegMapSize”:869365,“utxoSize”:3557882,“credentials”:“Cardano”}
Sep 28 15:11:11 block-producer bash[1078937]: [block-pr:cardano.node.Forge:Info:381] [2021-09-28 19:11:11.00 UTC] fromList [(“val”,Object (fromList [(“kind”,String “TraceNodeNotLeader”),(“slot”,Number 4.128998e7)])),(“credentials”,String “Cardano”)]
Sep 28 15:11:11 block-producer bash[1078937]: [block-pr:cardano.node.Mempool:Info:456] [2021-09-28 19:11:11.08 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “9c667e1b7eb8fe5b1f8066459931f7248f0aa06053af0baaae1473643cf01705”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 3975.0),(“numTxs”,Number 8.0)])),(“kind”,String “TraceMempoolAddedTx”)]
Sep 28 15:11:11 block-producer bash[1078937]: [block-pr:cardano.node.Mempool:Info:456] [2021-09-28 19:11:11.58 UTC] fromList [(“tx”,Object (fromList [(“txid”,String “txid: TxId {_unTxId = SafeHash “7f5bd7dc33755c2efc62d26418a3c46fb1e050ea206af012bc737afc4843ecc2”}”)])),(“mempoolSize”,Object (fromList [(“bytes”,Number 4567.0),(“numTxs”,Number 9.0)])),(“kind”,String “TraceMempoolAddedTx”)]
Sep 28 15:11:12 block-producer bash[1078937]: [block-pr:cardano.node.LeadershipCheck:Info:381] [2021-09-28 19:11:12.00 UTC] {“kind”:“TraceStartLeadershipCheck”,“chainDensity”:4.9669866e-2,“slot”:41289981,“delegMapSize”:869365,“utxoSize”:3557882,“credentials”:“Cardano”}

[muffinetics]

I started seeing [Cardano-:cardano.node.ChainSyncHeaderServer:Info:471] after starting my node to sync from my relay. these errors on my relay, not from the BP. Full error is
[Cardano-:cardano.node.ChainSyncHeaderServer:Info:471] [2021-10-08 14:06:34.35 UTC] fromList [(“kind”,String “ChainSyncServerEvent.TraceChainSyncServerRead.AddBlock”),(“slot”,Number 3.6671604e7),(“block”,String “89a2e7119c5932ecb169b348b39cc24bbac0ff1e5c252a7f3e0c85a1d337b51b”),(“blockNo”,Number 6076083.0)].
looks like its litem item just adding more slots as its syncing.
Not sure why it would start displaying this once a node it connecting to a relay.
mainnet-topolofy file reflects both IPs from node to relay and relay to node. I’m gonna let it run and see what it says once everything is at 100%