Skip to content
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.

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

Flaky test TestHare_ReconstructCollision #6329

Open
fasmat opened this issue Sep 13, 2024 · 0 comments
Open

Flaky test TestHare_ReconstructCollision #6329

fasmat opened this issue Sep 13, 2024 · 0 comments

Comments

@fasmat
Copy link
Member

fasmat commented Sep 13, 2024

Description

Test failed in an unrelated change.

Affected code

Example CI run: https://github.com/spacemeshos/go-spacemesh/actions/runs/10846088503

=== FAIL: hare4 TestHare_ReconstructCollision (13.15s)
    logger.go:146: 2024-09-13T09:09:41.522Z	INFO	hare=0	registered signing key	{"id": "17efe1"}
    logger.go:146: 2024-09-13T09:09:41.522Z	INFO	hare=0	started	{"enabled": false, "enabled layer": 0, "disabled layer": 4294967295, "committee": 50, "leaders": 5, "iterations limit": 4, "preround delay": "25s", "round duration": "12s", "log stats": true, "p2p protocol": "/h/4.0", "enabled": 8, "disabled": 4294967295}
    logger.go:146: 2024-09-13T09:09:41.522Z	INFO	hare=1	registered signing key	{"id": "db54e5"}
    logger.go:146: 2024-09-13T09:09:41.522Z	INFO	hare=1	started	{"enabled": false, "enabled layer": 0, "disabled layer": 4294967295, "committee": 50, "leaders": 5, "iterations limit": 4, "preround delay": "25s", "round duration": "12s", "log stats": true, "p2p protocol": "/h/4.0", "enabled": 8, "disabled": 4294967295}
    logger.go:146: 2024-09-13T09:09:41.522Z	DEBUG	hare=0	notified	{"layer": 8}
    logger.go:146: 2024-09-13T09:09:41.522Z	DEBUG	hare=0	registered layer	{"lid": 8}
    logger.go:146: 2024-09-13T09:09:41.532Z	DEBUG	hare=1	notified	{"layer": 8}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=0	active in preround. waiting for preround delay	{"lid": 8}
    logger.go:146: [202](https://github.com/spacemeshos/go-spacemesh/actions/runs/10846088503/job/30098329333#step:14:203)4-09-13T09:09:41.537Z	DEBUG	hare=0	requested proposals	{"lid": 8, "beacon": "01010101"}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "preround", "sender": "17efe1", "full": ["0d1e08ade5"], "vrf_count": 31, "atxgrade": 5, "malicious": false, "hash": "cef61b7b6d"}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=0	after on message	{"hash": "cef61b7b6d", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=1	registered layer	{"lid": 8}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=1	active in preround. waiting for preround delay	{"lid": 8}
    logger.go:146: 2024-09-13T09:09:41.537Z	DEBUG	hare=1	requested proposals	{"lid": 8, "beacon": "01010101"}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "preround", "sender": "db54e5", "full": ["0d1e08ade5", "5110afb515"], "vrf_count": 24, "atxgrade": 5, "malicious": false, "hash": "2dab7b214b"}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	after on message	{"hash": "2dab7b214b", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "preround", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "preround", "sender": "000000", "full": ["0d1e08ade5"], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "preround", "sender": "db54e5", "full": ["0d1e08ade5", "5110afb515"], "vrf_count": 24, "atxgrade": 5, "malicious": false, "hash": "2dab7b214b"}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	after on message	{"hash": "2dab7b214b", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "preround", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "preround", "sender": "000000", "full": ["0d1e08ade5", "5110afb515"], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "softlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "softlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "softlock", "terminated": false, "coin": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "softlock", "terminated": false, "coin": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "propose", "active": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "propose", "active": true}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "propose", "sender": "17efe1", "full": ["0d1e08ade5"], "vrf_count": 2, "atxgrade": 5, "malicious": false, "hash": "fc90d5d7ca"}
    logger.go:146: 2024-09-13T09:09:41.711Z	DEBUG	hare=0	after on message	{"hash": "fc90d5d7ca", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "propose", "sender": "db54e5", "vrf_count": 3, "atxgrade": 5, "malicious": false, "hash": "291e515fff"}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	after on message	{"hash": "291e515fff", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "propose", "sender": "17efe1", "full": ["0d1e08ade5"], "vrf_count": 2, "atxgrade": 5, "malicious": false, "hash": "fc90d5d7ca"}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	after on message	{"hash": "fc90d5d7ca", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "propose", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "propose", "sender": "000000", "full": ["0d1e08ade5"], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "propose", "sender": "db54e5", "vrf_count": 3, "atxgrade": 5, "malicious": false, "hash": "291e515fff"}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	after on message	{"hash": "291e515fff", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "propose", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "propose", "sender": "000000", "full": [], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "wait1", "active": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "wait1", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "wait1", "active": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "wait2", "active": true}
    logger.go:146: 2024-09-13T09:09:41.721Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "wait1", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.726Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "wait2", "active": true}
    logger.go:146: 2024-09-13T09:09:41.726Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "wait2", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.726Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "wait2", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.726Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "commit", "active": true}
    logger.go:146: 2024-09-13T09:09:41.736Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "commit", "active": true}
    logger.go:146: 2024-09-13T09:09:41.736Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "commit", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 28, "atxgrade": 5, "malicious": false, "hash": "3e67136047"}
    logger.go:146: 2024-09-13T09:09:41.736Z	DEBUG	hare=0	after on message	{"hash": "3e67136047", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.736Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "commit", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 28, "atxgrade": 5, "malicious": false, "hash": "3e67136047"}
    logger.go:146: 2024-09-13T09:09:41.736Z	DEBUG	hare=1	after on message	{"hash": "3e67136047", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "commit", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "commit", "sender": "000000", "ref": "8d6707e28a", "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "commit", "sender": "db54e5", "ref": "af1349b9f5", "vrf_count": 17, "atxgrade": 5, "malicious": false, "hash": "e3e8f631b1"}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=0	after on message	{"hash": "e3e8f631b1", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "commit", "sender": "db54e5", "ref": "af1349b9f5", "vrf_count": 17, "atxgrade": 5, "malicious": false, "hash": "e3e8f631b1"}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=1	after on message	{"hash": "e3e8f631b1", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "commit", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "commit", "sender": "000000", "ref": "af1349b9f5", "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.742Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 0, "round": "notify", "active": true}
    logger.go:146: 2024-09-13T09:09:41.752Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 0, "round": "notify", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 25, "atxgrade": 5, "malicious": false, "hash": "a7048[215](https://github.com/spacemeshos/go-spacemesh/actions/runs/10846088503/job/30098329333#step:14:216)41"}
    logger.go:146: 2024-09-13T09:09:41.752Z	DEBUG	hare=0	after on message	{"hash": "a704821541", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 0, "round": "notify", "active": true}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 0, "round": "notify", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 25, "atxgrade": 5, "malicious": false, "hash": "a704821541"}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=1	after on message	{"hash": "a704821541", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 0, "round": "notify", "terminated": false, "msg": {"lid": 0, "iter": 0, "round": "notify", "sender": "000000", "ref": "8d6707e28a", "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "hardlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 0, "round": "notify", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.758Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "hardlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "hardlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	INFO	hare=1	stats	{"lid": 8, "iter": 0, "threshold": 26, "preround": [{"grade": 1, "tallies": [{"total": 24, "valid": 24, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 2, "tallies": [{"total": 24, "valid": 24, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 3, "tallies": [{"total": 24, "valid": 24, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 4, "tallies": [{"total": 24, "valid": 24, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 5, "tallies": [{"total": 24, "valid": 24, "id": "5110afb515"}, {"total": 24, "valid": 24, "id": "0d1e08ade5"}]}], "propose": [{"ref": "8d6707e28a", "grade": 2, "proposals": ["0d1e08ade5"]}, {"ref": "af1349b9f5", "grade": 2, "proposals": []}], "commit": [{"grade": 4, "tallies": [{"total": 28, "valid": 28, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}, {"total": 17, "valid": 17, "id": "af1349b9f5f9a1a6a0404dea36dcc9499bcb25c9adc112b7cc9a93cae41f3262"}]}, {"grade": 5, "tallies": [{"total": 28, "valid": 28, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}, {"total": 17, "valid": 17, "id": "af1349b9f5f9a1a6a0404dea36dcc9499bcb25c9adc112b7cc9a93cae41f3262"}]}], "notify": [{"grade": 5, "tallies": [{"total": 25, "valid": 25, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}]}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "hardlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	INFO	hare=0	stats	{"lid": 8, "iter": 0, "threshold": 26, "preround": [{"grade": 1, "tallies": [{"total": 24, "valid": 24, "id": "5110afb515"}, {"total": 55, "valid": 55, "id": "0d1e08ade5"}]}, {"grade": 2, "tallies": [{"total": 55, "valid": 55, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 3, "tallies": [{"total": 55, "valid": 55, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 4, "tallies": [{"total": 55, "valid": 55, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}, {"grade": 5, "tallies": [{"total": 55, "valid": 55, "id": "0d1e08ade5"}, {"total": 24, "valid": 24, "id": "5110afb515"}]}], "propose": [{"ref": "8d6707e28a", "grade": 2, "proposals": ["0d1e08ade5"]}, {"ref": "af1349b9f5", "grade": 2, "proposals": []}], "commit": [{"grade": 4, "tallies": [{"total": 28, "valid": 28, "id": "8d6707e28ad5758e3[241](https://github.com/spacemeshos/go-spacemesh/actions/runs/10846088503/job/30098329333#step:14:242)72c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}, {"total": 17, "valid": 17, "id": "af1349b9f5f9a1a6a0404dea36dcc9499bcb25c9adc112b7cc9a93cae41f3262"}]}, {"grade": 5, "tallies": [{"total": 28, "valid": 28, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}, {"total": 17, "valid": 17, "id": "af1349b9f5f9a1a6a0404dea36dcc9499bcb25c9adc112b7cc9a93cae41f3262"}]}], "notify": [{"grade": 5, "tallies": [{"total": 25, "valid": 25, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}]}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "softlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "softlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "softlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "softlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "propose", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "propose", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 1, "round": "propose", "sender": "17efe1", "full": ["0d1e08ade5"], "vrf_count": 4, "atxgrade": 5, "malicious": false, "hash": "52f94566ec"}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	after on message	{"hash": "52f94566ec", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 1, "round": "propose", "sender": "17efe1", "full": ["0d1e08ade5"], "vrf_count": 4, "atxgrade": 5, "malicious": false, "hash": "52f94566ec"}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	after on message	{"hash": "52f94566ec", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "propose", "terminated": false, "msg": {"lid": 0, "iter": 1, "round": "propose", "sender": "000000", "full": ["0d1e08ade5"], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "wait1", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "propose", "terminated": false, "msg": {"lid": 0, "iter": 1, "round": "propose", "sender": "000000", "full": [], "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "wait1", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "wait1", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "wait1", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "wait2", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "wait2", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "wait2", "active": true}
    logger.go:146: 2024-09-13T09:09:41.884Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "wait2", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "commit", "active": true}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "commit", "active": true}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=0	on message	{"lid": 8, "iter": 1, "round": "commit", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 21, "atxgrade": 5, "malicious": false, "hash": "b19a14872b"}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=0	after on message	{"hash": "b19a14872b", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=1	on message	{"lid": 8, "iter": 1, "round": "commit", "sender": "17efe1", "ref": "8d6707e28a", "vrf_count": 21, "atxgrade": 5, "malicious": false, "hash": "b19a14872b"}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=1	after on message	{"hash": "b19a14872b", "gossip": true}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "commit", "terminated": false, "msg": {"lid": 0, "iter": 1, "round": "commit", "sender": "000000", "ref": "8d6707e28a", "vrf_count": 0}}
    logger.go:146: 2024-09-13T09:09:41.905Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "commit", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 1, "round": "notify", "active": true}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 1, "round": "notify", "active": true}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 1, "round": "notify", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 1, "round": "notify", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=0	execute round	{"lid": 8, "iter": 2, "round": "hardlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=1	execute round	{"lid": 8, "iter": 2, "round": "hardlock", "active": true}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=1	round output	{"lid": 8, "iter": 2, "round": "hardlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.915Z	INFO	hare=1	stats	{"lid": 8, "iter": 1, "threshold": 26, "preround": [], "propose": [{"ref": "8d6707e28a", "grade": 2, "proposals": ["0d1e08ade5"]}], "commit": [{"grade": 4, "tallies": [{"total": 21, "valid": 21, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}, {"grade": 5, "tallies": [{"total": 21, "valid": 21, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}], "notify": [{"grade": 5, "tallies": []}]}
    logger.go:146: 2024-09-13T09:09:41.915Z	DEBUG	hare=0	round output	{"lid": 8, "iter": 2, "round": "hardlock", "terminated": false}
    logger.go:146: 2024-09-13T09:09:41.915Z	INFO	hare=0	stats	{"lid": 8, "iter": 1, "threshold": 26, "preround": [], "propose": [{"ref": "8d6707e28a", "grade": 2, "proposals": ["0d1e08ade5"]}], "commit": [{"grade": 4, "tallies": [{"total": 21, "valid": 21, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}, {"grade": 5, "tallies": [{"total": 21, "valid": 21, "id": "8d6707e28ad5758e324172c44b5d8dedc029cf9f32b590cc3eb0d635b978bbc0"}]}], "notify": [{"grade": 5, "tallies": []}]}
    hare_test.go:645: eligibility can't be sent, waited: 10s, stacktraces:
        goroutine 2543 [running]:
        runtime/pprof.writeGoroutineStacks({0x141fbdae0, 0xc000624aa0})
        	C:/hostedtoolcache/windows/go/1.22.7/x64/src/runtime/pprof/pprof.go:743 +0x75
        runtime/pprof.writeGoroutine({0x141fbdae0, 0xc000624aa0}, 0x2)
        	C:/hostedtoolcache/windows/go/1.22.7/x64/src/runtime/pprof/pprof.go:732 +0x45
        runtime/pprof.(*Profile).WriteTo(0x141795d00, {0x141fbdae0, 0xc000624aa0}, 0x2)
        	C:/hostedtoolcache/windows/go/1.22.7/x64/src/runtime/pprof/pprof.go:369 +0x1b4
        github.com/spacemeshos/go-spacemesh/hare4.sendWithTimeout[...]({0x141fe37e0?, 0xc00011f320}, {0xc000130f40, 0x1, 0x1}, 0xc000606e40, 0x2540be400, {0x141b1cb21, 0x19})
        	D:/a/go-spacemesh/go-spacemesh/hare4/hare_test.go:644 +0x19e
        github.com/spacemeshos/go-spacemesh/hare4.(*testTracer).OnActive(0xc0007eaa80, {0xc000130f40, 0x1, 0x1})
        	D:/a/go-spacemesh/go-spacemesh/hare4/hare_test.go:672 +0xb9
        github.com/spacemeshos/go-spacemesh/hare4.(*Hare).run(0xc0003ba480, 0xc0007eb680)
        	D:/a/go-spacemesh/go-spacemesh/hare4/hare.go:669 +0xb67
        github.com/spacemeshos/go-spacemesh/hare4.(*Hare).onLayer.func1()
        	D:/a/go-spacemesh/go-spacemesh/hare4/hare.go:601 +0x5e
        golang.org/x/sync/errgroup.(*Group).Go.func1()
        	C:/Users/runneradmin/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:78 +0x92
        created by golang.org/x/sync/errgroup.(*Group).Go in goroutine [252](https://github.com/spacemeshos/go-spacemesh/actions/runs/10846088503/job/30098329333#step:14:253)1
        	C:/Users/runneradmin/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:75 +0x125
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant