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

Resolve fabric/orderer/common/cluster unit test flakes #2835

Closed
denyeart opened this issue Aug 17, 2021 · 3 comments
Closed

Resolve fabric/orderer/common/cluster unit test flakes #2835

denyeart opened this issue Aug 17, 2021 · 3 comments

Comments

@denyeart
Copy link
Contributor

See details and occurrences in https://jira.hyperledger.org/browse/FAB-18506

@denyeart
Copy link
Contributor Author

#2935 fixed the most frequent flake.

The other flake we see sometimes is in TestBlockPullerBadBlocks.

Example here:

https://dev.azure.com/Hyperledger/0227bd2c-c4f6-478f-be00-ee519f115180/_apis/build/builds/39770/logs/9

2021-08-24T16:44:15.7497999Z goroutine 1926 [chan receive, 19 minutes]:
2021-08-24T16:44:15.7498361Z testing.(*T).Run(0xc000252900, 0x1191b40, 0x8, 0xc00023c000, 0x1)
2021-08-24T16:44:15.7498748Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1239 +0x610
2021-08-24T16:44:15.7499163Z github.com/hyperledger/fabric/orderer/common/cluster_test.TestBlockPullerBadBlocks(0xc000252900)
2021-08-24T16:44:15.7499646Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver_test.go:1047 +0x485
2021-08-24T16:44:15.7500044Z testing.tRunner(0xc000252900, 0x11ccd90)
2021-08-24T16:44:15.7500379Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x203
2021-08-24T16:44:15.7500716Z created by testing.(*T).Run
2021-08-24T16:44:15.7501050Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1238 +0x5d8

2021-08-24T16:44:15.7541570Z goroutine 1940 [semacquire, 1 minutes]:
2021-08-24T16:44:15.7541887Z sync.runtime_Semacquire(0xc000175eb8)
2021-08-24T16:44:15.7542213Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/runtime/sema.go:56 +0x45
2021-08-24T16:44:15.7542548Z sync.(*WaitGroup).Wait(0xc000175eb0)
2021-08-24T16:44:15.7542886Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/sync/waitgroup.go:130 +0xe5
2021-08-24T16:44:15.7543312Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).probeEndpoints(0xc000b40000, 0xa, 0x8b)
2021-08-24T16:44:15.7543795Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:341 +0x345
2021-08-24T16:44:15.7544280Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).connectToSomeEndpoint(0xc000b40000, 0xa)
2021-08-24T16:44:15.7544756Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:289 +0x7b
2021-08-24T16:44:15.7545235Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).tryFetchBlock(0xc000b40000, 0xa, 0x59)
2021-08-24T16:44:15.7545718Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:157 +0x15d
2021-08-24T16:44:15.7546194Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).PullBlock(0xc000b40000, 0xa, 0x1)
2021-08-24T16:44:15.7546654Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:100 +0xc5
2021-08-24T16:44:15.7547125Z github.com/hyperledger/fabric/orderer/common/cluster_test.TestBlockPullerBadBlocks.func7(0xc0001c2000)
2021-08-24T16:44:15.7547611Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver_test.go:1089 +0x65e
2021-08-24T16:44:15.7548003Z testing.tRunner(0xc0001c2000, 0xc00023c000)
2021-08-24T16:44:15.7548359Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1193 +0x203
2021-08-24T16:44:15.7548691Z created by testing.(*T).Run
2021-08-24T16:44:15.7549012Z 	/opt/hostedtoolcache/go/1.16.7/x64/src/testing/testing.go:1238 +0x5d8

@denyeart
Copy link
Contributor Author

@Param-S
Copy link
Contributor

Param-S commented Oct 7, 2021

TestBlockPullerBadBlocks Flake:

Status/Observations: (from above attached log)

BlockPuller.PullBlock failing to connect to server with rpc error: "transport is closing"

2021-08-24T16:44:15.7388184Z �[33m2021-08-24 16:44:09.694 UTC 0d56 WARN�[0m [test] �[33;1mfunc1�[0m -> Received error of type 'didn't receive a response within 10s' from 127.0.0.1:45297
2021-08-24T16:44:15.7389242Z �[36m2021-08-24 16:44:09.694 UTC 0d57 DEBU�[0m [grpc] �[36;1mInfoDepth�[0m -> [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2021-08-24T16:44:15.7481399Z github.com/hyperledger/fabric/orderer/common/cluster.(*ImpatientStream).Recv(0xc000dd4100, 0x0, 0x0, 0x0)
2021-08-24T16:44:15.7481871Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:579 +0x2cf
2021-08-24T16:44:15.7482419Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).fetchLastBlockSeq(0xc000b40000, 0xa, 0xc0004f8090, 0xf, 0xc000358e00, 0x0, 0x0, 0x0)
2021-08-24T16:44:15.7482967Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:401 +0x399
2021-08-24T16:44:15.7483642Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).probeEndpoint(0xc000b40000, 0xc0004f8090, 0xf, 0x0, 0x0, 0x0, 0xa, 0x9b0aed, 0x18, 0xc000126570)
2021-08-24T16:44:15.7484194Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:367 +0x34f
2021-08-24T16:44:15.7484800Z github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).probeEndpoints.func1(0xc000175eb0, 0xc000b40000, 0xa, 0xc000175e9c, 0xc000175ec0, 0xc0002acf60, 0xc0004f8090, 0xf, 0x0, 0x0, ...)
2021-08-24T16:44:15.7485413Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:326 +0x118
2021-08-24T16:44:15.7485862Z created by github.com/hyperledger/fabric/orderer/common/cluster.(*BlockPuller).probeEndpoints
2021-08-24T16:44:15.7486327Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver.go:324 +0x305

On the server side, multiple go routines(~8 routines) blocked on RPC service: Deliver

2021-08-24T16:44:15.7469835Z github.com/hyperledger/fabric/orderer/common/cluster_test.(*deliverServer).Deliver(0xc000bd2280, 0x12d0c18, 0xc0002abfb0, 0x0, 0x0)
2021-08-24T16:44:15.7470359Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/orderer/common/cluster/deliver_test.go:199 +0x765
2021-08-24T16:44:15.7471208Z github.com/hyperledger/fabric-protos-go/orderer._AtomicBroadcast_Deliver_Handler(0x115a7c0, 0xc000bd2280, 0x12ce558, 0xc00049ec00, 0x22906b0, 0xc0002c7100)
2021-08-24T16:44:15.7472027Z 	/home/vsts/work/1/go/src/github.com/hyperledger/fabric/vendor/github.com/hyperledger/fabric-protos-go/orderer/ab.pb.go:724 +0xd0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants