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 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

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
Projects
None yet
Development

No branches or pull requests

1 participant