Skip to content

WIP: consensus traffic via pubsub #6501

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Draft
algorandskiy wants to merge 1 commit into
base: master
Choose a base branch
from
Draft

WIP: consensus traffic via pubsub #6501

algorandskiy wants to merge 1 commit into from

Conversation

@algorandskiy
Copy link
Contributor

@algorandskiy algorandskiy commented Nov 19, 2025

Summary

Test Plan

@algorandskiy algorandskiy self-assigned this Nov 19, 2025
@codecov
Copy link

codecov bot commented Nov 19, 2025 •
edited
Loading

❌ 1 Tests Failed:

Tests completed Failed Passed Skipped
40796 1 40795 2570
View the top 2 failed test(s) by shortest run time 
::TestMain
Stack Traces | 0s run time 
PASS
Node at .../go/TestP2PFiveNodes/PartNode2 has terminated with error code -1 (signal: killed)
Node at .../go/TestP2PFiveNodes/PartNode2 has terminated with an error: signal: killed. Dumping logs...
=================================
PartNode2/node.log:
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Initialize","level":"info","line":225,"msg":"++++++++++++++++++++++++++++++++++++++++","time":"2025-11-19T01:24:05.961769Z"}
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Initialize","level":"info","line":226,"msg":"Logging Starting","time":"2025-11-19T01:24:05.961991Z"}
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Initialize","level":"info","line":233,"msg":"Telemetry Disabled","time":"2025-11-19T01:24:05.962130Z"}
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Initialize","level":"info","line":235,"msg":"++++++++++++++++++++++++++++++++++++++++","time":"2025-11-19T01:24:05.962250Z"}
{"file":"p2pNetwork.go","function":"github..../algorand/go-algorand/network.NewP2PNetwork","level":"info","line":317,"msg":"P2P host created: peer ID 12D3KooWR1xt7rC7ThwPeJsZp4hswFLa2XV5i1tsdHP6Cp6zsRfw addrs []","name":"","time":"2025-11-19T01:24:05.994386Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":72,"msg":"trackerDBInitialize upgrading database schema from version 0 to version 11","name":"","time":"2025-11-19T01:24:06.064964Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 0","name":"","time":"2025-11-19T01:24:06.065193Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.(*trackerDBSchemaInitializer).upgradeDatabaseSchema0","level":"info","line":189,"msg":"upgradeDatabaseSchema0 initializing schema","name":"","time":"2025-11-19T01:24:06.065417Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 1","name":"","time":"2025-11-19T01:24:06.066702Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 2","name":"","time":"2025-11-19T01:24:06.066919Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 3","name":"","time":"2025-11-19T01:24:06.067117Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 4","name":"","time":"2025-11-19T01:24:06.070765Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.(*trackerDBSchemaInitializer).upgradeDatabaseSchema4","level":"info","line":338,"msg":"upgradeDatabaseSchema4: deleted 0 rows","name":"","time":"2025-11-19T01:24:06.070960Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 5","name":"","time":"2025-11-19T01:24:06.071222Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.(*trackerDBSchemaInitializer).upgradeDatabaseSchema5.func1","level":"info","line":365,"msg":"upgradeDatabaseSchema5 upgraded 1 out of 5 accounts [ 20.0% ]","name":"","time":"2025-11-19T01:24:06.073144Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 6","name":"","time":"2025-11-19T01:24:06.075292Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.(*trackerDBSchemaInitializer).upgradeDatabaseSchema6.func1","level":"info","line":432,"msg":"upgradeDatabaseSchema6 upgraded 1 out of 5 accounts [ 20.0% ]","name":"","time":"2025-11-19T01:24:06.076233Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 7","name":"","time":"2025-11-19T01:24:06.077095Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 8","name":"","time":"2025-11-19T01:24:06.077499Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 9","name":"","time":"2025-11-19T01:24:06.077759Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":76,"msg":"trackerDBInitialize performing upgrade from version 10","name":"","time":"2025-11-19T01:24:06.078094Z"}
{"file":"trackerdbV2.go","function":"github..../store/trackerdb/sqlitedriver.RunMigrations","level":"info","line":149,"msg":"trackerDBInitialize database schema upgrade complete","name":"","time":"2025-11-19T01:24:06.078822Z"}
{"file":"catchpointtracker.go","function":"github..../algorand/go-algorand/ledger.(*catchpointTracker).initializeHashes","level":"info","line":1584,"msg":"initializeHashes rebuilding merkle trie for round 0","name":"","time":"2025-11-19T01:24:06.160047Z"}
{"file":"catchpointtracker.go","function":"github..../algorand/go-algorand/ledger.(*catchpointTracker).initializeHashes","level":"info","line":1701,"msg":"initializeHashes rebuilt the merkle trie with 5 entries in 4.438077ms","name":"","time":"2025-11-19T01:24:06.164724Z"}
{"file":"accountManager.go","function":"github..../algorand/go-algorand/data.(*AccountManager).AddParticipation","level":"info","line":121,"msg":"Inserted key (YH4X6MLFCCNZWF23T4SPDZ3GUN2N6NCC5HF3Y3PGPUCZP4U4KM4Q) for account (ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA) first valid (0) last valid (5000)\n","time":"2025-11-19T01:24:06.223601Z"}
{"file":"node.go","function":"github..../algorand/go-algorand/node.(*AlgorandFullNode).loadParticipationKeys","level":"info","line":1079,"msg":"Loaded participation keys from storage: ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA SmallWallet.0.5000.partkey","name":"","time":"2025-11-19T01:24:06.223854Z"}
{"file":"interface.go","function":"github..../go-algorand/network/messagetracer.NewTracer","level":"info","line":53,"msg":"graphtrace factory DISabled","time":"2025-11-19T01:24:06.265018Z"}
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Start","level":"info","line":324,"msg":"Trying to start an Algorand node","time":"2025-11-19T01:24:06.265248Z"}
{"Context":"Agreement","file":"persistence.go","function":"github..../algorand/go-algorand/agreement.restore","level":"info","line":159,"msg":"restore (agreement): crash state table initialized","time":"2025-11-19T01:24:06.269873Z"}
{"file":"participationRegistry.go","function":"github..../go-algorand/data/account.(*participationDB).Register","level":"info","line":950,"msg":"Registered key (YH4X6MLFCCNZWF23T4SPDZ3GUN2N6NCC5HF3Y3PGPUCZP4U4KM4Q) for account (ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA) first valid (0) last valid (5000)\n","name":"","time":"2025-11-19T01:24:06.273391Z"}
{"Context":"heartbeat","file":"service.go","function":"github..../algorand/go-algorand/heartbeat.(*Service).Start","level":"info","line":66,"msg":"starting heartbeat service","name":"","time":"2025-11-19T01:24:06.277641Z"}
{"file":"server.go","function":"github..../go-algorand/daemon/algod.(*Server).Start","level":"info","line":333,"msg":"Successfully started an Algorand node.","time":"2025-11-19T01:24:06.278142Z"}
{"Context":"Agreement","ObjectPeriod":0,"ObjectRound":1,"Type":"ProposalAssembled","WeightTotal":1,"file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeProposalsTask.execute","level":"info","line":517,"msg":"pseudonode: made 1 proposals","time":"2025-11-19T01:24:06.287141Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":0,"Type":"ProposalBroadcast","Weight":0,"WeightTotal":0,"file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeProposalsTask.execute","level":"info","line":564,"msg":"pseudonode.makeProposals: proposal created for (1, 0)","time":"2025-11-19T01:24:06.309168Z"}
{"Context":"Agreement","file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeProposalsTask.execute","level":"info","line":574,"msg":"pseudonode.makeProposals: 1 proposals created for round 1, period 0","time":"2025-11-19T01:24:06.314106Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":0,"Period":0,"Round":1,"Sender":"ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA","Step":1,"Type":"ProposalAccepted","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"info","line":365,"msg":"proposal {{} 0 ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA VVW3DGEGSUTLTEOIXK6HSXPU2VLRJPLGEHBMEAZFVQTBUYF23ZLA} accepted at (1, 0)","time":"2025-11-19T01:24:06.320416Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":0,"Period":0,"Round":1,"Sender":"ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA","Step":0,"Type":"BlockAssembled","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"info","line":389,"msg":"block assembled for TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA at (1, 0)","time":"2025-11-19T01:24:06.327445Z"}
{"file":"logger.go","function":"github..../server/lib/middlewares.(*LoggerMiddleware).handler-fm.(*LoggerMiddleware).handler.func1","level":"info","line":56,"msg":"127.0.0.1:44038 - - [2025-11-19 01:24:06.379529862 +0000 UTC m=+0.705472466] \"GET /health HTTP/1.1\" 200 0 \"Go-http-client/1.1\" 13.093268ms","time":"2025-11-19T01:24:06.392708Z"}
{"file":"p2pNetwork.go","function":"github..../algorand/go-algorand/network.(*P2PNetwork).baseWsStreamHandler","level":"warning","line":1033,"msg":"Could not get local address","name":"","time":"2025-11-19T01:24:06.427287Z"}
{"event":"ConnectedOut","file":"p2pNetwork.go","function":"github..../algorand/go-algorand/network.(*P2PNetwork).baseWsStreamHandler","level":"info","line":1064,"local":"","msg":"Made outgoing connection to peer 12D3KooWHRqVVzRmugUcuF22JvpVDdFLXHg1R6FTHxrgvLjaydse","name":"","remote":"/ip4/127.0.0.1/tcp/44591","time":"2025-11-19T01:24:06.429268Z"}
{"Context":"sync","file":"service.go","function":"github..../algorand/go-algorand/catchup.(*Service).sync","level":"info","line":733,"msg":"Catchup Service: finished catching up, now at round 0 (previously 0). Total time catching up 77.344039ms.","name":"","time":"2025-11-19T01:24:06.512581Z"}
{"Context":"Agreement","Hash":"","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":1,"Type":"StepTimeout","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logTimeout","level":"info","line":196,"msg":"timeout fired on (1, 0, 1) with value {{} 400ms 2} (napping: false)","time":"2025-11-19T01:24:06.675174Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":0,"Period":0,"Round":0,"Sender":"","Step":0,"Type":"ProposalFrozen","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalFrozen","level":"info","line":219,"msg":"froze proposal {{} 0 ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA VVW3DGEGSUTLTEOIXK6HSXPU2VLRJPLGEHBMEAZFVQTBUYF23ZLA} for (1, 0)","time":"2025-11-19T01:24:06.675601Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":1,"Type":"VoteAttest","Weight":0,"WeightTotal":0,"file":"actions.go","function":"github..../algorand/go-algorand/agreement.pseudonodeAction.do","level":"info","line":436,"msg":"attested to {{} 0 ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA VVW3DGEGSUTLTEOIXK6HSXPU2VLRJPLGEHBMEAZFVQTBUYF23ZLA} at (1, 0, 1)","time":"2025-11-19T01:24:06.675976Z"}
{"Context":"Agreement","file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeVotesTask.execute","level":"info","line":388,"msg":"pseudonode: made 1 votes","time":"2025-11-19T01:24:06.678763Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":1,"Period":0,"Round":1,"Sender":"ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA","Step":1,"Type":"VoteBroadcast","Weight":302,"WeightTotal":302,"file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeVotesTask.execute","level":"info","line":435,"msg":"vote created for broadcast (weight 302, total weight 302)","time":"2025-11-19T01:24:06.684003Z"}
{"Context":"Agreement","file":"pseudonode.go","function":"github..../algorand/go-algorand/agreement.pseudonodeVotesTask.execute","level":"info","line":451,"msg":"pseudonode.makeVotes: 1 votes created for {{} 0 ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA VVW3DGEGSUTLTEOIXK6HSXPU2VLRJPLGEHBMEAZFVQTBUYF23ZLA} at (1, 0, 1), total weight 302","time":"2025-11-19T01:24:06.691781Z"}
{"Context":"Agreement","Hash":"","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":2,"Type":"Persisted","Weight":0,"WeightTotal":0,"file":"persistence.go","function":"github..../algorand/go-algorand/agreement.persist.func1","level":"info","line":106,"msg":"persisted state to the database","time":"2025-11-19T01:24:06.696711Z"}
{"Context":"Agreement","Hash":"","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":2,"Type":"Persisted","Weight":0,"WeightTotal":0,"file":"actions.go","function":"github..../algorand/go-algorand/agreement.checkpointAction.do","level":"info","line":556,"msg":"checkpoint at (1, 0, 2)","time":"2025-11-19T01:24:06.697532Z"}
{"Context":"Agreement","Hash":"TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":1,"Period":0,"Round":1,"Sender":"ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA","Step":2,"Type":"VoteAccepted","Weight":302,"WeightTotal":302,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logVoteTrackerResult","level":"info","line":482,"msg":"vote accepted for {{} 0 ELUQKZW375CQELBBSAVKBTNLZTIY4HEUOKO5QQHNLM4W6ZXLDTYAJKMFMA TTPC64JFY6NP2NGE2QVC3ZEI2RBPHJANVA2CE4REBNJSU7L5MQEA VVW3DGEGSUTLTEOIXK6HSXPU2VLRJPLGEHBMEAZFVQTBUYF23ZLA} at (1, 0, 1)","time":"2025-11-19T01:24:06.698751Z"}
{"Context":"Agreement","Hash":"XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":2,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":2,"Type":"VoteAccepted","Weight":1283,"WeightTotal":1283,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logVoteTrackerResult","level":"info","line":482,"msg":"vote accepted for {{} 0 VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA FFCY5JOJKQ7YBVKJS6MCNH5EAT6MAA2GJNZFTRXVL4UPFPRS4INQ} at (1, 0, 2)","time":"2025-11-19T01:24:06.892309Z"}
{"Context":"Agreement","Hash":"XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":2,"Period":0,"Round":1,"Sender":"","Step":2,"Type":"ThresholdReached","Weight":1283,"WeightTotal":1112,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logVoteTrackerResult","level":"info","line":497,"msg":"threshold reached for XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA at (1, 0, 2)","time":"2025-11-19T01:24:06.892702Z"}
{"Context":"Agreement","Hash":"XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":0,"Type":"RoundWaiting","Weight":0,"WeightTotal":0,"file":"actions.go","function":"github..../algorand/go-algorand/agreement.stageDigestAction.do","level":"info","line":325,"msg":"round 1 concluded without block for {{} 0 VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA FFCY5JOJKQ7YBVKJS6MCNH5EAT6MAA2GJNZFTRXVL4UPFPRS4INQ}; (async) waiting on ledger","time":"2025-11-19T01:24:06.893498Z"}
{"Context":"Agreement","Hash":"GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ","ObjectPeriod":0,"ObjectRound":2,"ObjectStep":0,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":2,"Type":"ProposalAccepted","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"info","line":365,"msg":"proposal {{} 0 VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ AFTYGMWMTJWOWQM6JASDQU36UAAJKPCRQWNQRALGBE6LQ6L5FDDA} accepted at (2, 0)","time":"2025-11-19T01:24:06.901266Z"}
{"Context":"Agreement","Hash":"GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ","ObjectPeriod":0,"ObjectRound":2,"ObjectStep":0,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":2,"Type":"BlockPipelined","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"info","line":347,"msg":"pipelined block for (2, 0): \u003cnil\u003e","time":"2025-11-19T01:24:06.909122Z"}
{"Context":"Agreement","Hash":"GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ","ObjectPeriod":0,"ObjectRound":2,"ObjectStep":2,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":2,"Type":"VoteAccepted","Weight":1327,"WeightTotal":1327,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logVoteTrackerResult","level":"info","line":482,"msg":"vote accepted for {{} 0 VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ AFTYGMWMTJWOWQM6JASDQU36UAAJKPCRQWNQRALGBE6LQ6L5FDDA} at (2, 0, 2)","time":"2025-11-19T01:24:06.910982Z"}
{"Context":"Agreement","Hash":"GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ","ObjectPeriod":0,"ObjectRound":2,"ObjectStep":2,"Period":0,"Round":1,"Sender":"","Step":2,"Type":"ThresholdReached","Weight":1327,"WeightTotal":1112,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logVoteTrackerResult","level":"info","line":497,"msg":"threshold reached for GMFPLVL5FR7Z2B72MJEGIFUT5XDD3X5OKUQFVFMLXC2NTEUF74LQ at (2, 0, 2)","time":"2025-11-19T01:24:06.911286Z"}
{"Context":"Agreement","Hash":"XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA","ObjectPeriod":0,"ObjectRound":1,"ObjectStep":0,"Period":0,"Round":1,"Sender":"VPGLQA6DG2I3ATBTF6XP6EIU5ZBCXR33RWD4H7TGFN54XVXS4KM5GVSFZI","Step":2,"Type":"BlockPipelined","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"info","line":347,"msg":"pipelined block for (1, 0): \u003cnil\u003e","time":"2025-11-19T01:24:06.922931Z"}
{"Context":"Agreement","Hash":"XXLWOQMOQZ5Y2FXPQUBO27JB7OROLZKDBOOTMVF2KZS2ECZHJHBA","ObjectPeriod":0,"ObjectRound":0,"ObjectStep":0,"Period":0,"Round":1,"Sender":"","Step":2,"Type":"BlockRejected","Weight":0,"WeightTotal":0,"file":"trace.go","function":"github..../algorand/go-algorand/agreement.(*tracer).logProposalManagerResult","level":"warning","line":329,"msg":"rejected block for (1, 0): rejected invalid proposalPayload: EntryValidator rejected entry: block evaluation for round 1 requires sequential evaluation while the latest round is 1","time":"2025-11-19T01:24:06.925832Z"}
{"file":"wsPeer.go","function":"github..../algorand/go-algorand/network.(*wsPeer).reportReadErr","level":"warning","line":489,"msg":"peer[/ip4/127.0.0.1/tcp/44591] line=522 read err: stream reset","name":"","time":"2025-11-19T01:24:10.665249Z"}
{"Context":"sync","file":"service.go","function":"github..../algorand/go-algorand/catchup.(*Service).periodicSync","level":"info","line":661,"msg":"It's been too long since our ledger advanced; resyncing","name":"","time":"2025-11-19T01:24:23.912689Z"}
{"Context":"sync","file":"service.go","function":"github..../algorand/go-algorand/catchup.(*Service).sync","level":"info","line":733,"msg":"Catchup Service: finished catching up, now at round 1 (previously 1). Total time catching up 290.902µs.","name":"","time":"2025-11-19T01:24:23.913186Z"}

panic: Log in goroutine after TestP2PFiveNodes has completed: 
	    	Error Trace:	.../framework/fixtures/libgoalFixture.go:176
	    	            				.../go-algorand/nodecontrol/algodControl.go:248
	    	            				.../hostedtoolcache/go/1.25.3.../src/runtime/asm_amd64.s:1693
	    	Error:      	Received unexpected error:
	    	            	signal: killed
	    	Test:       	TestP2PFiveNodes
	

goroutine 373 [running]:
testing.(*common).log(0xc00072d340, {0xc000838d80, 0x178})
	.../hostedtoolcache/go/1.25.3.../src/testing/testing.go:1030 +0x1df
testing.(*common).Errorf(0xc00072d340, {0x1c6ec5e, 0x3}, {0xc0000b2510, 0x1, 0x1})
	.../hostedtoolcache/go/1.25.3.../src/testing/testing.go:1204 +0x8f
github..../test/framework/fixtures.(*synchTest).Errorf(0xc00072b920, {0x1c6ec5e, 0x3}, {0xc0000b2510, 0x1, 0x1})
	.../framework/fixtures/fixture.go:120 +0x10f
github..../stretchr/testify/assert.Fail({0x7fbf993f8c10, 0xc00072b920}, {0xc000968420, 0x29}, {0x0, 0x0, 0x0})
	.../pkg/mod/github.com/stretchr/[email protected]/assert/assertions.go:369 +0x44c
github..../stretchr/testify/assert.NoError({0x7fbf993f8c10, 0xc00072b920}, {0x21b6720, 0xc000120460}, {0x0, 0x0, 0x0})
	.../pkg/mod/github.com/stretchr/[email protected]/assert/assertions.go:1586 +0x13a
github..../stretchr/testify/require.NoError({0x7fbf993ee8c0, 0xc00072b920}, {0x21b6720, 0xc000120460}, {0x0, 0x0, 0x0})
	.../pkg/mod/github.com/stretchr/[email protected]/require/require.go:1354 +0xc5
github..../test/framework/fixtures.(*LibGoalFixture).nodeExitWithError(0xc0001c3088, 0xc000930480, {0x21b6720, 0xc000120460})
	.../framework/fixtures/libgoalFixture.go:176 +0x525
github..../algorand/go-algorand/nodecontrol.(*NodeController).StartAlgod.func2()
	.../go-algorand/nodecontrol/algodControl.go:248 +0xbc
created by github..../algorand/go-algorand/nodecontrol.(*NodeController).StartAlgod in goroutine 259
	.../go-algorand/nodecontrol/algodControl.go:240 +0x82b
FAIL	github..../e2e-go/features/p2p	38.148s

github.com/algorand/go-algorand/test/e2e-go/features/p2p::TestP2PTwoNodes
Stack Traces | 33.2s run time 
=== RUN   TestP2PTwoNodes
Created new rootkey: .../go/TestP2PTwoNodes/Wallet2.rootkey
Created new rootkey: .../go/TestP2PTwoNodes/Wallet1.rootkey
Generating Wallet2's keys for a period of 3000 rounds
Generating Wallet1's keys for a period of 3000 rounds
participation key generation for Wallet1 completed successfully
participation key generation for Wallet2 completed successfully
https://github..../specs/tree/953304de35264fc3ef91bcd05c123242015eeaed 100000
Created 2 new rootkeys and 2 new partkeys in 570.886885ms.
NOTICE: Participation keys are valid for a period of 3000 rounds. After this many rounds the network will stall unless new keys are registered.
algod(42540) : Config loaded from .../go/TestP2PTwoNodes/Primary
algod(42540) : Configuration after loading/defaults merge: 
algod(42540) : {"Version":37,"Archival":false,"GossipFanout":1,"NetAddress":"127.0.0.1:0","ReconnectTime":60000000000,"PublicAddress":"","MaxConnectionsPerIP":8,"PeerPingPeriodSeconds":0,"TLSCertFile":"","TLSKeyFile":"","BaseLoggerDebugLevel":4,"CadaverSizeTarget":0,"CadaverDirectory":"","HotDataDir":"","ColdDataDir":"","TrackerDBDir":"","BlockDBDir":"","CatchpointDir":"","StateproofDir":"","CrashDBDir":"","LogFileDir":"","LogArchiveDir":"","IncomingConnectionsLimit":2400,"P2PHybridIncomingConnectionsLimit":1200,"BroadcastConnectionsLimit":-1,"AnnounceParticipationKey":true,"PriorityPeers":{},"ReservedFDs":256,"EndpointAddress":"127.0.0.1:0","EnablePrivateNetworkAccessHeader":false,"RestReadTimeoutSeconds":15,"RestWriteTimeoutSeconds":120,"DNSBootstrapID":"","LogSizeLimit":1073741824,"LogArchiveName":"node.archive.log","LogArchiveMaxAge":"","CatchupFailurePeerRefreshRate":10,"NodeExporterListenAddress":":9100","EnableMetricReporting":false,"EnableTopAccountsReporting":false,"EnableAgreementReporting":false,"EnableAgreementTimeMetrics":false,"NodeExporterPath":"./node_exporter","FallbackDNSResolverAddress":"","TxPoolExponentialIncreaseFactor":2,"SuggestedFeeBlockHistory":3,"TxBacklogServiceRateWindowSeconds":10,"TxBacklogReservedCapacityPerPeer":20,"TxBacklogAppTxRateLimiterMaxSize":1048576,"TxBacklogAppTxPerSecondRate":100,"TxBacklogRateLimitingCongestionPct":50,"EnableTxBacklogAppRateLimiting":true,"TxBacklogAppRateLimitingCountERLDrops":false,"EnableTxBacklogRateLimiting":true,"TxBacklogSize":26000,"TxPoolSize":75000,"TxSyncTimeoutSeconds":30,"TxSyncIntervalSeconds":60,"IncomingMessageFilterBucketCount":5,"IncomingMessageFilterBucketSize":512,"OutgoingMessageFilterBucketCount":3,"OutgoingMessageFilterBucketSize":128,"EnableOutgoingNetworkMessageFiltering":true,"EnableIncomingMessageFilter":false,"DeadlockDetection":0,"DeadlockDetectionThreshold":30,"RunHosted":false,"CatchupParallelBlocks":16,"EnableAssembleStats":false,"EnableProcessBlockStats":false,"SuggestedFeeSlidingWindowSize":50,"TxSyncServeResponseSize":1000000,"UseXForwardedForAddressField":"","ForceRelayMessages":false,"ConnectionsRateLimitingWindowSeconds":1,"ConnectionsRateLimitingCount":60,"EnableRequestLogger":false,"PeerConnectionsUpdateInterval":3600,"HeartbeatUpdateInterval":600,"EnableProfiler":true,"EnableRuntimeMetrics":true,"EnableNetDevMetrics":false,"TelemetryToLog":true,"DNSSecurityFlags":9,"EnablePingHandler":true,"DisableOutgoingConnectionThrottling":false,"NetworkProtocolVersion":"","CatchpointInterval":10000,"CatchpointFileHistoryLength":365,"EnableGossipService":true,"EnableLedgerService":true,"EnableBlockService":true,"EnableGossipBlockService":true,"CatchupHTTPBlockFetchTimeoutSec":4,"CatchupGossipBlockFetchTimeoutSec":4,"CatchupLedgerDownloadRetryAttempts":50,"CatchupBlockDownloadRetryAttempts":1000,"EnableDeveloperAPI":false,"OptimizeAccountsDatabaseOnStartup":false,"CatchpointTracking":0,"LedgerSynchronousMode":2,"AccountsRebuildSynchronousMode":1,"MaxCatchpointDownloadDuration":43200000000000,"MinCatchpointFileDownloadBytesPerSecond":20480,"NetworkMessageTraceServer":"","VerifiedTranscationsCacheSize":150000,"DisableLocalhostConnectionRateLimit":true,"BlockServiceCustomFallbackEndpoints":"","CatchupBlockValidateMode":0,"EnableAccountUpdatesStats":false,"AccountUpdatesStatsInterval":5000000000,"ParticipationKeysRefreshInterval":60000000000,"DisableNetworking":false,"ForceFetchTransactions":false,"EnableVerbosedTransactionSyncLogging":false,"TransactionSyncDataExchangeRate":0,"TransactionSyncSignificantMessageThreshold":0,"ProposalAssemblyTime":500000000,"RestConnectionsSoftLimit":1024,"RestConnectionsHardLimit":2048,"MaxAPIResourcesPerAccount":100000,"AgreementIncomingVotesQueueLength":20000,"AgreementIncomingProposalsQueueLength":50,"AgreementIncomingBundlesQueueLength":15,"MaxAcctLookback":4,"MaxBlockHistoryLookback":20000,"EnableUsageLog":false,"MaxAPIBoxPerApplication":100000,"TxIncomingFilteringFlags":1,"EnableExperimentalAPI":true,"DisableLedgerLRUCache":false,"EnableFollowMode":false,"EnableTxnEvalTracer":false,"StorageEngine":"sqlite","TxIncomingFilterMaxSize":500000,"BlockServiceMemCap":500000000,"EnableP2P":true,"EnableP2PHybridMode":false,"P2PHybridNetAddress":"","EnableDHTProviders":false,"P2PPersistPeerID":false,"P2PPrivateKeyLocation":"","DisableAPIAuth":false,"GoMemLimit":0,"EnableVoteCompression":true,"StatefulVoteCompressionTableSize":2048,"EnableBatchVerification":true}
algod(42540) : No REST API Token found. Generated token: 94a083464b50d7f62092ab3726d4ee3016308692ed627df64e4dc9fbac41ca09
algod(42540) : No Admin REST API Token found. Generated token: 1a09ed28076364e6834ed69c338b5a8c8e5083b5cbe885b10b176a6cfb73eb10
algod(42540) : Logging to:  .../go/TestP2PTwoNodes/Primary/node.log
algod(42540) : Deadlock detection is set to: enabled (Default state is 'enable')
algod(42540) : Initializing the Algorand node... 
algod(42540) : Success!
algod(42540) : API authentication disabled: false
algod(42540) : ⇨ http server started on 127.0.0.1:44517
algod(42540) : Node running and accepting RPC requests over HTTP on port 127.0.0.1:44517. Press Ctrl-C to exit
algod(42550) : Config loaded from .../go/TestP2PTwoNodes/Node
algod(42550) : Configuration after loading/defaults merge: 
algod(42550) : {"Version":37,"Archival":false,"GossipFanout":1,"NetAddress":"","ReconnectTime":60000000000,"PublicAddress":"","MaxConnectionsPerIP":8,"PeerPingPeriodSeconds":0,"TLSCertFile":"","TLSKeyFile":"","BaseLoggerDebugLevel":4,"CadaverSizeTarget":0,"CadaverDirectory":"","HotDataDir":"","ColdDataDir":"","TrackerDBDir":"","BlockDBDir":"","CatchpointDir":"","StateproofDir":"","CrashDBDir":"","LogFileDir":"","LogArchiveDir":"","IncomingConnectionsLimit":0,"P2PHybridIncomingConnectionsLimit":1200,"BroadcastConnectionsLimit":-1,"AnnounceParticipationKey":true,"PriorityPeers":{},"ReservedFDs":256,"EndpointAddress":"127.0.0.1:0","EnablePrivateNetworkAccessHeader":false,"RestReadTimeoutSeconds":15,"RestWriteTimeoutSeconds":120,"DNSBootstrapID":"","LogSizeLimit":1073741824,"LogArchiveName":"node.archive.log","LogArchiveMaxAge":"","CatchupFailurePeerRefreshRate":10,"NodeExporterListenAddress":":9100","EnableMetricReporting":false,"EnableTopAccountsReporting":false,"EnableAgreementReporting":false,"EnableAgreementTimeMetrics":false,"NodeExporterPath":"./node_exporter","FallbackDNSResolverAddress":"","TxPoolExponentialIncreaseFactor":2,"SuggestedFeeBlockHistory":3,"TxBacklogServiceRateWindowSeconds":10,"TxBacklogReservedCapacityPerPeer":20,"TxBacklogAppTxRateLimiterMaxSize":1048576,"TxBacklogAppTxPerSecondRate":100,"TxBacklogRateLimitingCongestionPct":50,"EnableTxBacklogAppRateLimiting":true,"TxBacklogAppRateLimitingCountERLDrops":false,"EnableTxBacklogRateLimiting":true,"TxBacklogSize":26000,"TxPoolSize":75000,"TxSyncTimeoutSeconds":30,"TxSyncIntervalSeconds":60,"IncomingMessageFilterBucketCount":5,"IncomingMessageFilterBucketSize":512,"OutgoingMessageFilterBucketCount":3,"OutgoingMessageFilterBucketSize":128,"EnableOutgoingNetworkMessageFiltering":true,"EnableIncomingMessageFilter":false,"DeadlockDetection":0,"DeadlockDetectionThreshold":30,"RunHosted":false,"CatchupParallelBlocks":16,"EnableAssembleStats":false,"EnableProcessBlockStats":false,"SuggestedFeeSlidingWindowSize":50,"TxSyncServeResponseSize":1000000,"UseXForwardedForAddressField":"","ForceRelayMessages":false,"ConnectionsRateLimitingWindowSeconds":1,"ConnectionsRateLimitingCount":60,"EnableRequestLogger":false,"PeerConnectionsUpdateInterval":3600,"HeartbeatUpdateInterval":600,"EnableProfiler":true,"EnableRuntimeMetrics":true,"EnableNetDevMetrics":false,"TelemetryToLog":true,"DNSSecurityFlags":9,"EnablePingHandler":true,"DisableOutgoingConnectionThrottling":false,"NetworkProtocolVersion":"","CatchpointInterval":10000,"CatchpointFileHistoryLength":365,"EnableGossipService":true,"EnableLedgerService":false,"EnableBlockService":false,"EnableGossipBlockService":true,"CatchupHTTPBlockFetchTimeoutSec":4,"CatchupGossipBlockFetchTimeoutSec":4,"CatchupLedgerDownloadRetryAttempts":50,"CatchupBlockDownloadRetryAttempts":1000,"EnableDeveloperAPI":false,"OptimizeAccountsDatabaseOnStartup":false,"CatchpointTracking":0,"LedgerSynchronousMode":2,"AccountsRebuildSynchronousMode":1,"MaxCatchpointDownloadDuration":43200000000000,"MinCatchpointFileDownloadBytesPerSecond":20480,"NetworkMessageTraceServer":"","VerifiedTranscationsCacheSize":150000,"DisableLocalhostConnectionRateLimit":true,"BlockServiceCustomFallbackEndpoints":"","CatchupBlockValidateMode":0,"EnableAccountUpdatesStats":false,"AccountUpdatesStatsInterval":5000000000,"ParticipationKeysRefreshInterval":60000000000,"DisableNetworking":false,"ForceFetchTransactions":false,"EnableVerbosedTransactionSyncLogging":false,"TransactionSyncDataExchangeRate":0,"TransactionSyncSignificantMessageThreshold":0,"ProposalAssemblyTime":500000000,"RestConnectionsSoftLimit":1024,"RestConnectionsHardLimit":2048,"MaxAPIResourcesPerAccount":100000,"AgreementIncomingVotesQueueLength":20000,"AgreementIncomingProposalsQueueLength":50,"AgreementIncomingBundlesQueueLength":15,"MaxAcctLookback":4,"MaxBlockHistoryLookback":0,"EnableUsageLog":false,"MaxAPIBoxPerApplication":100000,"TxIncomingFilteringFlags":1,"EnableExperimentalAPI":true,"DisableLedgerLRUCache":false,"EnableFollowMode":false,"EnableTxnEvalTracer":false,"StorageEngine":"sqlite","TxIncomingFilterMaxSize":500000,"BlockServiceMemCap":500000000,"EnableP2P":true,"EnableP2PHybridMode":false,"P2PHybridNetAddress":"","EnableDHTProviders":false,"P2PPersistPeerID":false,"P2PPrivateKeyLocation":"","DisableAPIAuth":false,"GoMemLimit":0,"EnableVoteCompression":true,"StatefulVoteCompressionTableSize":2048,"EnableBatchVerification":true}
algod(42550) : No REST API Token found. Generated token: bdc780ab3b2e885e5645d06f6550a03b123c3a1c28365396f6c19bfe1d30ff04
algod(42550) : No Admin REST API Token found. Generated token: 5de5befdd8bce2ff7c1f6dac9d82bd3b7709d1becb403a261daf8c9e09baf45f
algod(42550) : Logging to:  .../go/TestP2PTwoNodes/Node/node.log
algod(42550) : Deadlock detection is set to: enabled (Default state is 'enable')
algod(42550) : Initializing the Algorand node... 
algod(42550) : Success!
algod(42550) : API authentication disabled: false
algod(42550) : ⇨ http server started on 127.0.0.1:37047
algod(42550) : Node running and accepting RPC requests over HTTP on port 127.0.0.1:37047. Press Ctrl-C to exit
    fixture.go:120: 
        	Error Trace:	.../features/p2p/p2p_basic_test.go:51
        	            				.../features/p2p/p2p_basic_test.go:58
        	Error:      	Received unexpected error:
        	            	timeout waiting for round 10 with last round = 7
        	Test:       	TestP2PTwoNodes
--- FAIL: TestP2PTwoNodes (33.19s)

To view more test analytics, go to the Test Analytics Dashboard
📋 Got 3 mins? Take this short survey to help us improve Test Analytics.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

@algorandskiy algorandskiy

Labels

New Feature

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

1 participant

@algorandskiy