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.

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

Flaky TestP2P_DBSet #6587

Open
fasmat opened this issue Jan 3, 2025 · 0 comments
Open

Flaky TestP2P_DBSet #6587

fasmat opened this issue Jan 3, 2025 · 0 comments
Labels
technical debt

Comments

@fasmat
Copy link
Member

fasmat commented Jan 3, 2025

Description

TestP2P_DBSet seems to be flaky and failed in an unrelated PR during merge: https://github.com/spacemeshos/go-spacemesh/actions/runs/12597993357/job/35112000860

=== Failed
=== FAIL: sync2 TestP2P_DBSet (0.66s)
    logger.go:146: 2025-01-03T14:11:53.115+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.118+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "2.7425ms"}
    logger.go:146: 2025-01-03T14:11:53.118+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.243375ms"}
    logger.go:146: 2025-01-03T14:11:53.118+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "1.550042ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.952042ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.647417ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.870084ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "1.883417ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.266292ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.427792ms"}
    logger.go:146: 2025-01-03T14:11:53.120+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.431167ms"}
    logger.go:146: 2025-01-03T14:11:53.121+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "1.554875ms"}
    logger.go:146: 2025-01-03T14:11:53.121+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.314917ms"}
    logger.go:146: 2025-01-03T14:11:53.121+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.684333ms"}
    logger.go:146: 2025-01-03T14:11:53.121+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.020917ms"}
    logger.go:146: 2025-01-03T14:11:53.121+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "5.434916ms"}
    logger.go:146: 2025-01-03T14:11:53.122+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "8.548375ms"}
    logger.go:146: 2025-01-03T14:11:53.123+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "8.874459ms"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "9.704167ms"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "10.104667ms"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "5.180583ms"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.124+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "7.119792ms"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "10.557917ms"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "7.874334ms"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "10.655458ms"}
    logger.go:146: 2025-01-03T14:11:53.125+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.128+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.538459ms"}
    logger.go:146: 2025-01-03T14:11:53.128+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "3.342709ms"}
    logger.go:146: 2025-01-03T14:11:53.129+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.310083ms"}
    logger.go:146: 2025-01-03T14:11:53.129+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "3.204125ms"}
    logger.go:146: 2025-01-03T14:11:53.129+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.104291ms"}
    logger.go:146: 2025-01-03T14:11:53.129+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "3.876583ms"}
    logger.go:146: 2025-01-03T14:11:53.129+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.432292ms"}
    logger.go:146: 2025-01-03T14:11:53.130+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.000375ms"}
    logger.go:146: 2025-01-03T14:11:53.130+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.204292ms"}
    logger.go:146: 2025-01-03T14:11:53.132+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "7.45125ms"}
    logger.go:146: 2025-01-03T14:11:53.132+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "7.570583ms"}
    logger.go:146: 2025-01-03T14:11:53.132+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "7.551542ms"}
    logger.go:146: 2025-01-03T14:11:53.193+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.193+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.193+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.195+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "1.656583ms"}
    logger.go:146: 2025-01-03T14:11:53.195+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.407375ms"}
    logger.go:146: 2025-01-03T14:11:53.197+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.186584ms"}
    logger.go:146: 2025-01-03T14:11:53.197+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "3.899459ms"}
    logger.go:146: 2025-01-03T14:11:53.197+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.331542ms"}
    logger.go:146: 2025-01-03T14:11:53.197+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "4.063333ms"}
    logger.go:146: 2025-01-03T14:11:53.210+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.210+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.211+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.211+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "1.182125ms"}
    logger.go:146: 2025-01-03T14:11:53.211+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "957.083µs"}
    logger.go:146: 2025-01-03T14:11:53.213+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.115917ms"}
    logger.go:146: 2025-01-03T14:11:53.213+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.227083ms"}
    logger.go:146: 2025-01-03T14:11:53.213+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "2.805792ms"}
    logger.go:146: 2025-01-03T14:11:53.213+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "2.924333ms"}
    logger.go:146: 2025-01-03T14:11:53.237+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.237+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.238+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.238+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.238+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.240+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.240+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "2.234166ms"}
    logger.go:146: 2025-01-03T14:11:53.240+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.166708ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "2.852458ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.370166ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "3.392708ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "3.698125ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.380334ms"}
    logger.go:146: 2025-01-03T14:11:53.241+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.502709ms"}
    logger.go:146: 2025-01-03T14:11:53.242+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.54675ms"}
    logger.go:146: 2025-01-03T14:11:53.242+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "2.86875ms"}
    logger.go:146: 2025-01-03T14:11:53.242+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.433ms"}
    logger.go:146: 2025-01-03T14:11:53.242+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.918666ms"}
    logger.go:146: 2025-01-03T14:11:53.266+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.266+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.266+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "708.125µs"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "474.708µs"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "867.125µs"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "502.917µs"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "962.375µs"}
    logger.go:146: 2025-01-03T14:11:53.267+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "456µs"}
    logger.go:146: 2025-01-03T14:11:53.283+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.283+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.283+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.284+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "1.107625ms"}
    logger.go:146: 2025-01-03T14:11:53.284+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "1.627208ms"}
    logger.go:146: 2025-01-03T14:11:53.287+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.655625ms"}
    logger.go:146: 2025-01-03T14:11:53.287+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.667209ms"}
    logger.go:146: 2025-01-03T14:11:53.287+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "4.2925ms"}
    logger.go:146: 2025-01-03T14:11:53.287+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "4.297417ms"}
    logger.go:146: 2025-01-03T14:11:53.299+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.299+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.299+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.302+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.17225ms"}
    logger.go:146: 2025-01-03T14:11:53.302+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.384917ms"}
    logger.go:146: 2025-01-03T14:11:53.302+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.001209ms"}
    logger.go:146: 2025-01-03T14:11:53.303+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.880709ms"}
    logger.go:146: 2025-01-03T14:11:53.303+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.407792ms"}
    logger.go:146: 2025-01-03T14:11:53.303+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.90325ms"}
    logger.go:146: 2025-01-03T14:11:53.346+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.346+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.346+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.348+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.838084ms"}
    logger.go:146: 2025-01-03T14:11:53.348+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "2.581208ms"}
    logger.go:146: 2025-01-03T14:11:53.349+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.572584ms"}
    logger.go:146: 2025-01-03T14:11:53.349+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "3.108833ms"}
    logger.go:146: 2025-01-03T14:11:53.349+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "3.820167ms"}
    logger.go:146: 2025-01-03T14:11:53.350+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.4945ms"}
    logger.go:146: 2025-01-03T14:11:53.393+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.393+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.393+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.395+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "2.062459ms"}
    logger.go:146: 2025-01-03T14:11:53.395+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.632875ms"}
    logger.go:146: 2025-01-03T14:11:53.399+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.402+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.402+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.403+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.637875ms"}
    logger.go:146: 2025-01-03T14:11:53.404+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "1.826416ms"}
    logger.go:146: 2025-01-03T14:11:53.405+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "2.982375ms"}
    logger.go:146: 2025-01-03T14:11:53.405+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "8.407375ms"}
    logger.go:146: 2025-01-03T14:11:53.402+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "10.297917ms"}
    logger.go:146: 2025-01-03T14:11:53.405+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "12.868292ms"}
    logger.go:146: 2025-01-03T14:11:53.405+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "12.18675ms"}
    logger.go:146: 2025-01-03T14:11:53.406+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "14.088166ms"}
    logger.go:146: 2025-01-03T14:11:53.406+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "7.065625ms"}
    logger.go:146: 2025-01-03T14:11:53.407+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "10.175917ms"}
    logger.go:146: 2025-01-03T14:11:53.422+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.422+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.422+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "1.584625ms"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "972.541µs"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.005791ms"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.417ms"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.086792ms"}
    logger.go:146: 2025-01-03T14:11:53.423+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.459958ms"}
    logger.go:146: 2025-01-03T14:11:53.428+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.428+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.431+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.432+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.4785ms"}
    logger.go:146: 2025-01-03T14:11:53.432+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.23675ms"}
    logger.go:146: 2025-01-03T14:11:53.432+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.605792ms"}
    logger.go:146: 2025-01-03T14:11:53.432+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "3.246666ms"}
    logger.go:146: 2025-01-03T14:11:53.433+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.894458ms"}
    logger.go:146: 2025-01-03T14:11:53.433+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "1.433792ms"}
==================
WARNING: DATA RACE
Write at 0x00c0007344d0 by goroutine 1150:
  github.com/spacemeshos/go-spacemesh/sync2/sqlstore.(*SQLIDStore).SetSnapshot()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/sqlstore/sqlidstore.go:78 +0x48
  github.com/spacemeshos/go-spacemesh/sync2/fptree.(*DBBackedStore).SetSnapshot()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/fptree/dbbackedstore.go:67 +0x28
  github.com/spacemeshos/go-spacemesh/sync2/dbset.(*DBSet).Advance()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/dbset/dbset.go:226 +0x27c
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start.func1.2()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:171 +0x194
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /Users/m1/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:78 +0x7c

Previous read at 0x00c0007344d0 by goroutine 1149:
  github.com/spacemeshos/go-spacemesh/sync2/sqlstore.(*SQLIDStore).From()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/sqlstore/sqlidstore.go:57 +0x74
  github.com/spacemeshos/go-spacemesh/sync2/sqlstore.(*SQLIDStore).All()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/sqlstore/sqlidstore.go:47 +0xb8
  github.com/spacemeshos/go-spacemesh/sync2/fptree.(*DBBackedStore).All()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/fptree/dbbackedstore.go:51 +0x1c
  github.com/spacemeshos/go-spacemesh/sync2/fptree.(*FPTree).all()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/fptree/fptree.go:381 +0x104
  github.com/spacemeshos/go-spacemesh/sync2/fptree.(*FPTree).FingerprintAll()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/fptree/fptree.go:1177 +0x128
  github.com/spacemeshos/go-spacemesh/sync2/dbset.(*DBSet).SetInfo()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/dbset/dbset.go:187 +0x84
  github.com/spacemeshos/go-spacemesh/sync2/multipeer.(*SetSyncBase).Count()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/multipeer/setsyncbase.go:44 +0xa8
  github.com/spacemeshos/go-spacemesh/sync2/multipeer.(*MultiPeerReconciler).probePeers()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/multipeer/multipeer.go:229 +0x94
  github.com/spacemeshos/go-spacemesh/sync2/multipeer.(*MultiPeerReconciler).syncOnce()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/multipeer/multipeer.go:378 +0x450
  github.com/spacemeshos/go-spacemesh/sync2/multipeer.(*MultiPeerReconciler).Run()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/multipeer/multipeer.go:473 +0xec
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start.func1.1()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:157 +0xc0
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /Users/m1/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:78 +0x7c

Goroutine 1150 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /Users/m1/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:75 +0x10c
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start.func1()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:162 +0x244
  sync.(*Once).doSlow()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/sync/once.go:76 +0xac
  sync.(*Once).Do()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/sync/once.go:67 +0x40
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:150 +0x94
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).Start()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:183 +0xd60
  github.com/spacemeshos/go-spacemesh/sync2_test.TestP2P_DBSet()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p_test.go:271 +0xd5c
  testing.tRunner()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/testing/testing.go:1690 +0x184
  testing.(*T).Run.gowrap1()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/testing/testing.go:1743 +0x40

Goroutine 1149 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /Users/m1/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:75 +0x10c
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start.func1()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:155 +0x168
  sync.(*Once).doSlow()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/sync/once.go:76 +0xac
  sync.(*Once).Do()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/sync/once.go:67 +0x40
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).start()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:150 +0x94
  github.com/spacemeshos/go-spacemesh/sync2.(*P2PHashSync).Start()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p.go:183 +0xd60
  github.com/spacemeshos/go-spacemesh/sync2_test.TestP2P_DBSet()
      /Users/m1/actions-runner/_work/go-spacemesh/go-spacemesh/sync2/p2p_test.go:271 +0xd5c
  testing.tRunner()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/testing/testing.go:1690 +0x184
  testing.(*T).Run.gowrap1()
      /Users/m1/actions-runner/_work/_tool/go/1.23.4/arm64/src/testing/testing.go:1743 +0x40
==================
    logger.go:146: 2025-01-03T14:11:53.519+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.519+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.519+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.521+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "2.357042ms"}
    logger.go:146: 2025-01-03T14:11:53.522+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.673208ms"}
    logger.go:146: 2025-01-03T14:11:53.524+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "4.189583ms"}
    logger.go:146: 2025-01-03T14:11:53.524+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.125583ms"}
    logger.go:146: 2025-01-03T14:11:53.526+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "7.744916ms"}
    logger.go:146: 2025-01-03T14:11:53.526+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "7.121458ms"}
    logger.go:146: 2025-01-03T14:11:53.528+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.528+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.529+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.529+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.297209ms"}
    logger.go:146: 2025-01-03T14:11:53.529+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "1.210916ms"}
    logger.go:146: 2025-01-03T14:11:53.529+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "1.351375ms"}
    logger.go:146: 2025-01-03T14:11:53.529+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.492ms"}
    logger.go:146: 2025-01-03T14:11:53.530+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.158084ms"}
    logger.go:146: 2025-01-03T14:11:53.530+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "546.625µs"}
    logger.go:146: 2025-01-03T14:11:53.548+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.548+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.549+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "4.112709ms"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "4.650291ms"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.668625ms"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "5.284542ms"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.736333ms"}
    logger.go:146: 2025-01-03T14:11:53.553+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.912625ms"}
    logger.go:146: 2025-01-03T14:11:53.555+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.559+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "3.187666ms"}
    logger.go:146: 2025-01-03T14:11:53.559+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.77825ms"}
    logger.go:146: 2025-01-03T14:11:53.559+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.560+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.560+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.985291ms"}
    logger.go:146: 2025-01-03T14:11:53.560+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "1.177083ms"}
    logger.go:146: 2025-01-03T14:11:53.561+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "5.40[233](https://github.com/spacemeshos/go-spacemesh/actions/runs/12597993357/job/35112000860#step:14:234)3ms"}
    logger.go:146: 2025-01-03T14:11:53.561+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "duration": "865.125µs"}
    logger.go:146: 2025-01-03T14:11:53.609+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.609+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.609+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.613+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "3.773542ms"}
    logger.go:146: 2025-01-03T14:11:53.613+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "4.724333ms"}
    logger.go:146: 2025-01-03T14:11:53.616+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "7.971041ms"}
    logger.go:146: 2025-01-03T14:11:53.616+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4[242](https://github.com/spacemeshos/go-spacemesh/actions/runs/12597993357/job/35112000860#step:14:243)", "duration": "7.218125ms"}
    logger.go:146: 2025-01-03T14:11:53.616+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "7.228417ms"}
    logger.go:146: 2025-01-03T14:11:53.616+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "8.125ms"}
    logger.go:146: 2025-01-03T14:11:53.629+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.629+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.630+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.638+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "8.651417ms"}
    logger.go:146: 2025-01-03T14:11:53.638+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "11.897583ms"}
    logger.go:146: 2025-01-03T14:11:53.639+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.639+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.639+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.639+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "9.292584ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "13.027083ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "900.958µs"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.817875ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.303083ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "1.138042ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.435125ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmPRuc6eWcxzE5Y8KHd9uPsn2CLzW3cfF68HXiUz2LZ8qf", "remoteMultiaddr": "/ip6/100::6dc:e44d:b9d:b692/tcp/4242", "duration": "1.18225ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "Qmf2vQDaZgL8qLM38i5pFaifPa6Zt8p551Q3i1QZixWPCP", "remoteMultiaddr": "/ip6/100::9295:cd0e:2d95:c2c4/tcp/4242", "duration": "11.434208ms"}
    logger.go:146: 2025-01-03T14:11:53.640+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "13.834542ms"}
    logger.go:146: 2025-01-03T14:11:53.707+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.707+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.708+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.709+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.729708ms"}
    logger.go:146: 2025-01-03T14:11:53.709+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "2.69[262](https://github.com/spacemeshos/go-spacemesh/actions/runs/12597993357/job/35112000860#step:14:263)5ms"}
    logger.go:146: 2025-01-03T14:11:53.709+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "2.407167ms"}
    logger.go:146: 2025-01-03T14:11:53.709+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "2.373958ms"}
    logger.go:146: 2025-01-03T14:11:53.709+0100	DEBUG	protocol handler execution time	{"protocol": "sync2test", "remotePeer": "QmaYSEHnFc6eqSp2BHV8X7KXwdJ4KGwrucH3zDCTBcbELY", "remoteMultiaddr": "/ip6/100::6c32:e5b7:bd75:4e01/tcp/4242", "duration": "2.010125ms"}
    logger.go:146: 2025-01-03T14:11:53.710+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "3.216917ms"}
    logger.go:146: 2025-01-03T14:11:53.712+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.713+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.713+0100	DEBUG	dispatch	{"handler": "test"}
    logger.go:146: 2025-01-03T14:11:53.718+0100	DEBUG	handler reported error	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "error": "handler \"test\": sync: receive message: EOF"}
    logger.go:146: 2025-01-03T14:11:53.719+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "6.861ms", "error": "handling probe response: receive message: io: read/write on closed pipe"}
    logger.go:146: 2025-01-03T14:11:53.721+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "8.906375ms", "error": "handling probe response: receive message: io: read/write on closed pipe"}
    logger.go:146: 2025-01-03T14:11:53.721+0100	DEBUG	handler reported error	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "error": "handler \"test\": sync: receive message: EOF"}
    logger.go:146: 2025-01-03T14:11:53.721+0100	DEBUG	request execution time	{"protocol": "sync2test", "duration": "9.354041ms", "error": "handling probe response: receive message: io: read/write on closed pipe"}
    logger.go:146: 2025-01-03T14:11:53.721+0100	DEBUG	handler reported error	{"protocol": "sync2test", "remotePeer": "QmR6EEaCQsUCEArwX6g7NeCHLL3zMsXzvnhtL8dMzbrpUt", "remoteMultiaddr": "/ip6/100::f606:49a:3219:c655/tcp/4242", "error": "handler \"test\": sync: receive message: EOF"}
    testing.go:1399: race detected during execution of test
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
technical debt
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@fasmat