search

LF-Decentralized-Trust-labs / paladin

Programmable privacy for EVM
https://lf-decentralized-trust-labs.github.io/paladin
Apache License 2.0
15 stars 6 forks source link

bug: Test failure in TestBlockListenerWSShoulderTap #420

Open awrichar opened 1 week ago

awrichar commented 1 week ago

What happened?

Failure in TestBlockListenerWSShoulderTap https://github.com/LF-Decentralized-Trust-labs/paladin/actions/runs/11746268909/job/32730295774?pr=406

2024-11-08T18:46:48.3532685Z 2024/11/08 18:46:47 http: panic serving 127.0.0.1:34976: fail once here
2024-11-08T18:46:48.3533424Z goroutine 2246 [running]:
2024-11-08T18:46:48.3533987Z net/http.(*conn).serve.func1()
2024-11-08T18:46:48.3534883Z    /opt/hostedtoolcache/go/1.22.9/x64/src/net/http/server.go:1903 +0xbe
2024-11-08T18:46:48.3535704Z panic({0xf85240?, 0x12d21f0?})
2024-11-08T18:46:48.3536425Z    /opt/hostedtoolcache/go/1.22.9/x64/src/runtime/panic.go:770 +0x132
2024-11-08T18:46:48.3538173Z github.com/kaleido-io/paladin/core/pkg/blockindexer.TestBlockListenerWSShoulderTap.func1(0x7fea57875ab8?)
2024-11-08T18:46:48.3539839Z    /home/runner/work/paladin/paladin/core/go/pkg/blockindexer/block_listener_test.go:212 +0x33
2024-11-08T18:46:48.3541651Z github.com/hyperledger/firefly-common/pkg/wsclient.NewTestWSServer.func1({0x12ddea0, 0xc000564000}, 0xc00024a000)
2024-11-08T18:46:48.3543850Z    /home/runner/go/pkg/mod/github.com/hyperledger/firefly-common@v1.4.11/pkg/wsclient/wstestserver.go:154 +0x88
2024-11-08T18:46:48.3824133Z net/http.HandlerFunc.ServeHTTP(0x475cb9?, {0x12ddea0?, 0xc000564000?}, 0xc0004b2b68?)
2024-11-08T18:46:48.3825555Z    /opt/hostedtoolcache/go/1.22.9/x64/src/net/http/server.go:2171 +0x29
2024-11-08T18:46:48.3826853Z net/http.serverHandler.ServeHTTP({0xc0006a9380?}, {0x12ddea0?, 0xc000564000?}, 0x6?)
2024-11-08T18:46:48.3828194Z    /opt/hostedtoolcache/go/1.22.9/x64/src/net/http/server.go:3142 +0x8e
2024-11-08T18:46:48.3829288Z net/http.(*conn).serve(0xc00073fcb0, {0x12e0548, 0xc0006a9260})
2024-11-08T18:46:48.3830452Z    /opt/hostedtoolcache/go/1.22.9/x64/src/net/http/server.go:2044 +0x5e8
2024-11-08T18:46:48.3831501Z created by net/http.(*Server).Serve in goroutine 2240
2024-11-08T18:46:48.3832654Z    /opt/hostedtoolcache/go/1.22.9/x64/src/net/http/server.go:3290 +0x4b4
2024-11-08T18:46:48.3834274Z [2024-11-08T18:46:47.472Z]  WARN WS ws://127.0.0.1:42947 connect attempt 1 failed [-1]: 
2024-11-08T18:46:48.3836551Z [2024-11-08T18:46:47.472Z]  WARN WebSocket connection failed, blocking startup of block listener: FF00148: Websocket connect failed: unexpected EOF role=blocklistener
2024-11-08T18:46:48.3838925Z [2024-11-08T18:46:47.472Z] ERROR FF00148: Websocket connect failed: unexpected EOF (attempt=1) role=blocklistener
2024-11-08T18:46:48.3840462Z [2024-11-08T18:46:47.724Z]  INFO WS ws://127.0.0.1:42947 connected
2024-11-08T18:46:48.3842493Z [2024-11-08T18:46:47.724Z]  WARN RPC[000000001] <-- Error creating subscription 81eec5bb-5e87-4f0b-b915-9adadd7beb18: null role=rpc_websocket
2024-11-08T18:46:48.3844110Z [2024-11-08T18:46:47.724Z] ERROR pop (attempt=2) role=blocklistener
2024-11-08T18:46:48.3846062Z [2024-11-08T18:46:48.228Z]  INFO Subscribed 0f5b2b12-4a78-4946-89c3-a313586b6aa4 with server subscription ID 'e83bbad1-06d8-4643-b494-b92bed92442e' role=rpc_websocket
2024-11-08T18:46:48.3847941Z [2024-11-08T18:46:48.228Z]  INFO RPC[000000003] <-- eth_blockNumber OK (0.09ms)
2024-11-08T18:46:48.3849211Z [2024-11-08T18:46:48.228Z]  INFO RPC[000000004] <-- eth_newBlockFilter OK (0.09ms)
2024-11-08T18:46:48.3850788Z [2024-11-08T18:46:48.230Z] ERROR WS ws://127.0.0.1:42947 closing: FF00150: Websocket heartbeat timed out after 0.02ms
2024-11-08T18:46:48.3852612Z [2024-11-08T18:46:48.230Z] ERROR RPC[000000005] <-- ERROR: FF22063: Request with id 000000005 failed due to canceled context
2024-11-08T18:46:48.3854765Z [2024-11-08T18:46:48.230Z] ERROR Failed to query block filter changes: FF22063: Request with id 000000005 failed due to canceled context role=blocklistener
2024-11-08T18:46:48.3857001Z [2024-11-08T18:46:48.230Z]  INFO WS ws://127.0.0.1:42947 closed: read tcp 127.0.0.1:34990->127.0.0.1:42947: use of closed network connection
2024-11-08T18:46:48.3858861Z [2024-11-08T18:46:48.230Z]  INFO Unsubscribed 81eec5bb-5e87-4f0b-b915-9adadd7beb18 (subid=,result=false)
2024-11-08T18:46:48.3860279Z [2024-11-08T18:46:48.230Z] ERROR RPC[000000006] <-- ERROR: FF00147: Websocket closing
2024-11-08T18:46:48.3862172Z [2024-11-08T18:46:48.230Z] ERROR Failed to unsubscribe 0f5b2b12-4a78-4946-89c3-a313586b6aa4: FF22012: Backend RPC request failed: FF00147: Websocket closing
2024-11-08T18:46:48.3863615Z panic: send on closed channel
2024-11-08T18:46:48.3863951Z 
2024-11-08T18:46:48.3864133Z goroutine 2241 [running]:
2024-11-08T18:46:48.3865297Z github.com/kaleido-io/paladin/core/pkg/blockindexer.TestBlockListenerWSShoulderTap.func2()
2024-11-08T18:46:48.3867054Z    /home/runner/work/paladin/paladin/core/go/pkg/blockindexer/block_listener_test.go:279 +0x165
2024-11-08T18:46:48.3869343Z created by github.com/kaleido-io/paladin/core/pkg/blockindexer.TestBlockListenerWSShoulderTap in goroutine 2239
2024-11-08T18:46:48.3871249Z    /home/runner/work/paladin/paladin/core/go/pkg/blockindexer/block_listener_test.go:228 +0x328
2024-11-08T18:46:48.3872655Z FAIL   github.com/kaleido-io/paladin/core/pkg/blockindexer 1.596s

What did you expect to happen?

Test should pass

How can we reproduce it (as minimally and precisely as possible)?

See logs

Anything else we need to know?

No response

OS version

No response