rpcsrv: fix TestSubClientWaitWithMissedEvent #3377

AliceInHunterland · 2024-03-27T08:42:58Z

codecov · 2024-03-27T08:50:36Z

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 84.78%. Comparing base (86f16bb) to head (56e6119).

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #3377      +/-   ##
==========================================
- Coverage   84.80%   84.78%   -0.02%     
==========================================
  Files         331      331              
  Lines       44969    44969              
==========================================
- Hits        38134    38129       -5     
- Misses       5323     5325       +2     
- Partials     1512     1515       +3

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

AliceInHunterland · 2024-03-27T12:29:58Z

still have this but maybe connected with #2956:

RUN   TestFilteredNotaryRequestSubscriptions/matching_sender,_signer_and_type
2024-03-27T12:14:02.4866847Z === NAME  TestFilteredNotaryRequestSubscriptions
2024-03-27T12:14:02.4866992Z     subscription_test.go:38: 
2024-03-27T12:14:02.4867540Z         	Error Trace:	D:/a/neo-go/neo-go/pkg/services/rpcsrv/subscription_test.go:38
2024-03-27T12:14:02.4868202Z         	            				C:/hostedtoolcache/windows/go/1.22.1/x64/src/runtime/asm_amd64.s:1695
2024-03-27T12:14:02.4868409Z         	Error:      	Received unexpected error:
2024-03-27T12:14:02.4868911Z         	            	read tcp4 127.0.0.1:61709->127.0.0.1:61708: i/o timeout
2024-03-27T12:14:02.4869190Z         	Test:       	TestFilteredNotaryRequestSubscriptions
2024-03-27T12:14:02.4869858Z     logger.go:146: 2024-03-27T12:09:15.335Z	DEBUG	processing rpc request	{"method": "subscribe", "params": "[notary_request_event ]"}
2024-03-27T12:14:02.4870598Z     logger.go:146: 2024-03-27T12:09:15.916Z	INFO	persisted to disk	{"blocks": 9, "keys": 794, "headerHeight": 23, "blockHeight": 23, "took": "255.6µs"}
2024-03-27T12:14:02.4870710Z panic: test timed out after 15m0s
2024-03-27T12:14:02.4870802Z running tests:
2024-03-27T12:14:02.4870982Z 	TestFilteredNotaryRequestSubscriptions (3m21s)
2024-03-27T12:14:02.4871301Z 	TestFilteredNotaryRequestSubscriptions/matching_sender,_signer_and_type (3m20s)
2024-03-27T12:14:02.4871319Z 
2024-03-27T12:14:02.4871414Z goroutine 13900 [running]:
2024-03-27T12:14:02.4871517Z testing.(*M).startAlarm.func1()
2024-03-27T12:14:02.4871812Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:2366 +0x265
2024-03-27T12:14:02.4871905Z created by time.goFunc
2024-03-27T12:14:02.4872156Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/time/sleep.go:177 +0x45
2024-03-27T12:14:02.4872163Z 
2024-03-27T12:14:02.4872277Z goroutine 1 [chan receive, 3 minutes]:
2024-03-27T12:14:02.4872470Z testing.(*T).Run(0xc0003281a0, {0x141581c75, 0x26}, 0x141687388)
2024-03-27T12:14:02.4872798Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:1750 +0x851
2024-03-27T12:14:02.4872945Z testing.runTests.func1(0xc0003281a0)
2024-03-27T12:14:02.4873225Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:2161 +0x86
2024-03-27T12:14:02.4873350Z testing.tRunner(0xc0003281a0, 0xc0001e3b10)
2024-03-27T12:14:02.4873636Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:1689 +0x21f
2024-03-27T12:14:02.4873980Z testing.runTests(0xc000300168, {0x1412d57e0, 0x31, 0x31}, {0xc0001e3bb8?, 0xc0001e3c00?, 0x1421220e0?})
2024-03-27T12:14:02.4874257Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:2159 +0x8bf
2024-03-27T12:14:02.4874353Z testing.(*M).Run(0xc000330000)
2024-03-27T12:14:02.4874623Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/testing/testing.go:2027 +0xf18
2024-03-27T12:14:02.4874707Z main.main()
2024-03-27T12:14:02.4874818Z 	_testmain.go:145 +0x2be
2024-03-27T12:14:02.4874824Z 
2024-03-27T12:14:02.4874956Z goroutine 14164 [chan receive, 3 minutes]:
2024-03-27T12:14:02.4875283Z github.com/nspcc-dev/neo-go/pkg/network/bqueue.(*Queue).Run(0xc00086ae00)
2024-03-27T12:14:02.4875527Z 	D:/a/neo-go/neo-go/pkg/network/bqueue/queue.go:60 +0x9b
2024-03-27T12:14:02.4875908Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4876132Z 	D:/a/neo-go/neo-go/pkg/network/server.go:295 +0x557
2024-03-27T12:14:02.4876137Z 
2024-03-27T12:14:02.4876238Z goroutine 14171 [select]:
2024-03-27T12:14:02.4876544Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).runProto(0xc00086f808)
2024-03-27T12:14:02.4876763Z 	D:/a/neo-go/neo-go/pkg/network/server.go:553 +0x229
2024-03-27T12:14:02.4877123Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).run in goroutine 14167
2024-03-27T12:14:02.4877337Z 	D:/a/neo-go/neo-go/pkg/network/server.go:453 +0x295
2024-03-27T12:14:02.4877342Z 
2024-03-27T12:14:02.4877447Z goroutine 14144 [select, 3 minutes]:
2024-03-27T12:14:02.4877784Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).txHandlerLoop(0xc00086f808)
2024-03-27T12:14:02.4878011Z 	D:/a/neo-go/neo-go/pkg/network/server.go:1155 +0x23c
2024-03-27T12:14:02.4878370Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4878624Z 	D:/a/neo-go/neo-go/pkg/network/server.go:291 +0x31c
2024-03-27T12:14:02.4878660Z 
2024-03-27T12:14:02.4878753Z goroutine 14135 [select]:
2024-03-27T12:14:02.4879052Z github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run(0xc0000e4908)
2024-03-27T12:14:02.4879278Z 	D:/a/neo-go/neo-go/pkg/core/blockchain.go:1074 +0x2dc
2024-03-27T12:14:02.4879816Z created by github.com/nspcc-dev/neo-go/pkg/services/rpcsrv.getUnitTestChainWithCustomConfig in goroutine 14133
2024-03-27T12:14:02.4880139Z 	D:/a/neo-go/neo-go/pkg/services/rpcsrv/server_helper_test.go:85 +0x737
2024-03-27T12:14:02.4880144Z 
2024-03-27T12:14:02.4880248Z goroutine 14139 [select, 3 minutes]:
2024-03-27T12:14:02.4880643Z github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).notificationDispatcher(0xc0000e4908)
2024-03-27T12:14:02.4880864Z 	D:/a/neo-go/neo-go/pkg/core/blockchain.go:1336 +0x4b6
2024-03-27T12:14:02.4881232Z created by github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run in goroutine 14135
2024-03-27T12:14:02.4881453Z 	D:/a/neo-go/neo-go/pkg/core/blockchain.go:1071 +0x18b
2024-03-27T12:14:02.4881460Z 
2024-03-27T12:14:02.4881560Z goroutine 5013 [runnable]:
2024-03-27T12:14:02.4881892Z github.com/nspcc-dev/neo-go/pkg/rpcclient.(*Internal).eventLoop(0xc0004d4e00)
2024-03-27T12:14:02.4882112Z 	D:/a/neo-go/neo-go/pkg/rpcclient/local.go:54 +0x194
2024-03-27T12:14:02.4882480Z created by github.com/nspcc-dev/neo-go/pkg/rpcclient.NewInternal in goroutine 5007
2024-03-27T12:14:02.4882692Z 	D:/a/neo-go/neo-go/pkg/rpcclient/local.go:45 +0x3cd
2024-03-27T12:14:02.4882697Z 
2024-03-27T12:14:02.4882807Z goroutine 14167 [select, 3 minutes]:
2024-03-27T12:14:02.4883089Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).run(0xc00086f808)
2024-03-27T12:14:02.4883346Z 	D:/a/neo-go/neo-go/pkg/network/server.go:484 +0x919
2024-03-27T12:14:02.4883745Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4883953Z 	D:/a/neo-go/neo-go/pkg/network/server.go:303 +0x874
2024-03-27T12:14:02.4883965Z 
2024-03-27T12:14:02.4884069Z goroutine 14145 [select, 3 minutes]:
2024-03-27T12:14:02.4884401Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).txHandlerLoop(0xc00086f808)
2024-03-27T12:14:02.4884628Z 	D:/a/neo-go/neo-go/pkg/network/server.go:1155 +0x23c
2024-03-27T12:14:02.4884982Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4885193Z 	D:/a/neo-go/neo-go/pkg/network/server.go:291 +0x31c
2024-03-27T12:14:02.4885199Z 
2024-03-27T12:14:02.4885301Z goroutine 14163 [select, 3 minutes]:
2024-03-27T12:14:02.4885652Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).relayBlocksLoop(0xc00086f808)
2024-03-27T12:14:02.4885873Z 	D:/a/neo-go/neo-go/pkg/network/server.go:1589 +0x225
2024-03-27T12:14:02.4886243Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4886458Z 	D:/a/neo-go/neo-go/pkg/network/server.go:294 +0x4ab
2024-03-27T12:14:02.4886464Z 
2024-03-27T12:14:02.4886578Z goroutine 14137 [IO wait, 3 minutes]:
2024-03-27T12:14:02.4886732Z internal/poll.runtime_pollWait(0x4891c018, 0x72)
2024-03-27T12:14:02.4887010Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/runtime/netpoll.go:345 +0x85
2024-03-27T12:14:02.4887188Z internal/poll.(*pollDesc).wait(0xc00085b840, 0x72, 0x0)
2024-03-27T12:14:02.4887525Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/internal/poll/fd_poll_runtime.go:84 +0xb1
2024-03-27T12:14:02.4887666Z internal/poll.execIO(0xc00085b6a0, 0xc000bb3930)
2024-03-27T12:14:02.4887989Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/internal/poll/fd_windows.go:175 +0x271
2024-03-27T12:14:02.4888294Z internal/poll.(*FD).acceptOne(0xc00085b688, 0x4f4, {0xc0006fdb30, 0x2, 0x2}, 0xc00085b6a0)
2024-03-27T12:14:02.4888614Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/internal/poll/fd_windows.go:944 +0xf8
2024-03-27T12:14:02.4888778Z internal/poll.(*FD).Accept(0xc00085b688, 0xc000ba7ba8)
2024-03-27T12:14:02.4889141Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/internal/poll/fd_windows.go:978 +0x3cb
2024-03-27T12:14:02.4889275Z net.(*netFD).accept(0xc00085b688)
2024-03-27T12:14:02.4889539Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/net/fd_windows.go:178 +0x85
2024-03-27T12:14:02.4889658Z net.(*TCPListener).accept(0xc000e9bf40)
2024-03-27T12:14:02.4889932Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/net/tcpsock_posix.go:159 +0x3e
2024-03-27T12:14:02.4890052Z net.(*TCPListener).Accept(0xc000e9bf40)
2024-03-27T12:14:02.4890301Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/net/tcpsock.go:327 +0x65
2024-03-27T12:14:02.4890519Z net/http.(*Server).Serve(0xc0018cba40, {0x141869d60, 0xc000e9bf40})
2024-03-27T12:14:02.4890785Z 	C:/hostedtoolcache/windows/go/1.22.1/x64/src/net/http/server.go:3255 +0x672
2024-03-27T12:14:02.4891161Z github.com/nspcc-dev/neo-go/pkg/services/rpcsrv.(*Server).Start.func1(0xc0018cba40)
2024-03-27T12:14:02.4891418Z 	D:/a/neo-go/neo-go/pkg/services/rpcsrv/server.go:403 +0x79
2024-03-27T12:14:02.4891838Z created by github.com/nspcc-dev/neo-go/pkg/services/rpcsrv.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4892101Z 	D:/a/neo-go/neo-go/pkg/services/rpcsrv/server.go:402 +0x1c5
2024-03-27T12:14:02.4892107Z 
2024-03-27T12:14:02.4892209Z goroutine 14142 [select, 3 minutes]:
2024-03-27T12:14:02.4892546Z github.com/nspcc-dev/neo-go/pkg/network.(*Server).txHandlerLoop(0xc00086f808)
2024-03-27T12:14:02.4892763Z 	D:/a/neo-go/neo-go/pkg/network/server.go:1155 +0x23c
2024-03-27T12:14:02.4893133Z created by github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start in goroutine 14133
2024-03-27T12:14:02.4893344Z 	D:/a/neo-go/neo-go/pkg/network/server.go:291 +0x31c

pkg/services/rpcsrv/client_test.go

AnnaShaleva · 2024-03-27T18:29:46Z

still have this but maybe connected with #2956:

Don't pollute the PR comments with unrelated logs, otherwise we have a mess in logs and PRs/Issues links. It's a different test that is failing (TestFilteredNotaryRequestSubscriptions), and the reason is completely different from the current test failure. The reason looks more like #3314. Create a separate issue for this test and try to solve it with the approach presented in #3368.

UPD: see #3378.

pkg/services/rpcsrv/client_test.go

Add error channel to prevent data race in the test. Increase waiting interval for subscriptions awaiting up to 2 seconds. Failing is caused by slow subscriptions. Close #2958 Signed-off-by: Ekaterina Pavlova <[email protected]> Signed-off-by: Ekaterina Pavlova <[email protected]>

AnnaShaleva

I'm still not quite sure that it fixes the problem, but let's try, because I don't have any other suggestions.

AliceInHunterland requested review from AnnaShaleva and roman-khimov as code owners March 27, 2024 08:42

AliceInHunterland force-pushed the test-subclient branch from dc9b9c0 to e10c584 Compare March 27, 2024 13:02

AnnaShaleva requested changes Mar 27, 2024

View reviewed changes

pkg/services/rpcsrv/client_test.go Outdated Show resolved Hide resolved

pkg/services/rpcsrv/client_test.go Outdated Show resolved Hide resolved

AliceInHunterland force-pushed the test-subclient branch from e10c584 to 89b62e3 Compare March 28, 2024 08:18

AliceInHunterland requested a review from AnnaShaleva March 28, 2024 09:15

AnnaShaleva reviewed Mar 28, 2024

View reviewed changes

pkg/services/rpcsrv/client_test.go Show resolved Hide resolved

AliceInHunterland force-pushed the test-subclient branch from 89b62e3 to 7f50bb1 Compare March 29, 2024 06:51

AliceInHunterland requested a review from AnnaShaleva March 29, 2024 06:52

AliceInHunterland force-pushed the test-subclient branch from 7f50bb1 to 56e6119 Compare April 1, 2024 07:52

AnnaShaleva approved these changes Apr 1, 2024

View reviewed changes

AnnaShaleva merged commit 00ac38b into master Apr 1, 2024
18 of 20 checks passed

AnnaShaleva deleted the test-subclient branch April 1, 2024 08:13

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

rpcsrv: fix TestSubClientWaitWithMissedEvent #3377

rpcsrv: fix TestSubClientWaitWithMissedEvent #3377

AliceInHunterland commented Mar 27, 2024

codecov bot commented Mar 27, 2024 •

edited

Loading

AliceInHunterland commented Mar 27, 2024 •

edited

Loading

AnnaShaleva commented Mar 27, 2024 •

edited

Loading

AnnaShaleva left a comment

rpcsrv: fix TestSubClientWaitWithMissedEvent #3377

rpcsrv: fix TestSubClientWaitWithMissedEvent #3377

Conversation

AliceInHunterland commented Mar 27, 2024

codecov bot commented Mar 27, 2024 • edited Loading

Codecov Report

AliceInHunterland commented Mar 27, 2024 • edited Loading

AnnaShaleva commented Mar 27, 2024 • edited Loading

AnnaShaleva left a comment

Choose a reason for hiding this comment

codecov bot commented Mar 27, 2024 •

edited

Loading

AliceInHunterland commented Mar 27, 2024 •

edited

Loading

AnnaShaleva commented Mar 27, 2024 •

edited

Loading