WS Relay Unsubscribing all subscriptions periodically

[rodgerjohnson]

Description

Our WS Relay periodically closes WS connections without the client initiating the behavior. We only began seeing this behavior after this issue was resolved and we began utilizing the WS_SAME_SUB_FOR_SAME_EVENT="false" parameter.

We're unable to locate what might be causing the relay to initiate this behavior but it looks like unsubscribe is being called to globally shutdown WS connections.

Steps to reproduce

Unable to determine the cause or method of reproducing this behavior. But you should be able to observe this behavior with WS_SAME_SUB_FOR_SAME_EVENT="false" configured, having numerous (5+) newHeads subscriptions and letting it run for an hour or so.

Additional context

[2024-09-17 11:08:21.033 +0000] �[32mINFO�[39m (poller/100 on hedera-testnet-relay-1): �[36mPoller: Tag {"event":"logs","filters":{"address":["0xfe7aba7486b18d79e3df86d054f058f700668206","0x58dc9f50975e42ca40ab393f9d90b64982adc2a8"],"topics":[["0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c","0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c"]]}} removed from polling list�[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mNo subscribers for {"event":"logs","filters":{"address":["0xfe7aba7486b18d79e3df86d054f058f700668206","0x58dc9f50975e42ca40ab393f9d90b64982adc2a8"],"topics":[["0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c","0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c"]]}}. Removing from list.�[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xb6a7a6a947cb11a63c7b2550d88b7efb. Unsubscribing subId: 0xc639297649dd2b3b6e9e60cd21b96ae7; tag: {"event":"logs","filters":{"address":["0xfe7aba7486b18d79e3df86d054f058f700668206","0x58dc9f50975e42ca40ab393f9d90b64982adc2a8"],"topics":[["0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c","0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c"]]}}�[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xb6a7a6a947cb11a63c7b2550d88b7efb. Unsubscribing subId: 0x52423bd8a9feaa1fa3dcfc607297d738; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xb6a7a6a947cb11a63c7b2550d88b7efb. Unsubscribing subId: 0x6519b0dc2571e088bed44ce6eadc47ec; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.033 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xb6a7a6a947cb11a63c7b2550d88b7efb: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.033 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0xb6a7a6a947cb11a63c7b2550d88b7efb] [Request ID: 17569049-4a5e-43eb-a167-32eaff570357] Closing connection 0xb6a7a6a947cb11a63c7b2550d88b7efb | code: 1006, message: �[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x242f7aa7802470a81452abeefa00b5df. Unsubscribing subId: 0x9c1ab5efd9db850ebba5754088f1e35f; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.033 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x242f7aa7802470a81452abeefa00b5df. Unsubscribing subId: 0x3fd7a56f58de98b02525fd1a14d4b32f; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.033 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x242f7aa7802470a81452abeefa00b5df: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.033 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0x242f7aa7802470a81452abeefa00b5df] [Request ID: 1b47f64a-079a-401f-bc1f-38436fbdc3a8] Closing connection 0x242f7aa7802470a81452abeefa00b5df | code: 1006, message: �[39m
[2024-09-17 11:08:21.023 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xcd621f37cb3facd2988ffa3edbfb714c. Unsubscribing subId: 0x919920d072ac280637494f805105beb3; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.023 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xcd621f37cb3facd2988ffa3edbfb714c. Unsubscribing subId: 0xb7f9a8fd906a24df31d2338134c949f3; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.023 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xcd621f37cb3facd2988ffa3edbfb714c: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.023 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0xcd621f37cb3facd2988ffa3edbfb714c] [Request ID: 87922779-15f3-4d8b-9683-8955c1dd9d1d] Closing connection 0xcd621f37cb3facd2988ffa3edbfb714c | code: 1006, message: �[39m
[2024-09-17 11:08:21.022 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x71f8583ce984a6d8bd0841ab18723c5b. Unsubscribing subId: 0x7da565afa86225b7839cbddbb43057c8; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.022 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x71f8583ce984a6d8bd0841ab18723c5b. Unsubscribing subId: 0xf8a5776e432963d30de10a442482cc8c; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.022 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x71f8583ce984a6d8bd0841ab18723c5b: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.022 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0x71f8583ce984a6d8bd0841ab18723c5b] [Request ID: d90aeb37-3fdd-40a1-8a73-663c07df82a6] Closing connection 0x71f8583ce984a6d8bd0841ab18723c5b | code: 1006, message: �[39m
[2024-09-17 11:08:21.022 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x9111b7647446336f92c383461c07b511. Unsubscribing subId: 0x7bf0102398573b99b96af375c0d6cb9d; tag: {"event":"logs","filters":{"address":["0x58dc9f50975e42ca40ab393f9d90b64982adc2a8","0xfe7aba7486b18d79e3df86d054f058f700668206"],"topics":[["0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c","0x41e3990591fd372502daa15842da15bc7f41c75309ab3ff4f56f1848c178825c"]]}}�[39m
[2024-09-17 11:08:21.022 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x9111b7647446336f92c383461c07b511. Unsubscribing subId: 0xf6ed49aa21c7018a09b9973b45fee56f; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.022 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x9111b7647446336f92c383461c07b511. Unsubscribing subId: 0x944e1ddbf8dc70c3ca52b3c9450d4c4b; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.022 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0x9111b7647446336f92c383461c07b511: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.022 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0x9111b7647446336f92c383461c07b511] [Request ID: de2c4444-803a-472f-bb09-1f215416e7ac] Closing connection 0x9111b7647446336f92c383461c07b511 | code: 1006, message: �[39m
[2024-09-17 11:08:21.020 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xd5d5b5633e1297686e0b3d52c8b3c331. Unsubscribing subId: 0xba6ec5d4e2b2aad5286372f45b3894e2; tag: {"event":"newHeads"}�[39m
[2024-09-17 11:08:21.020 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xd5d5b5633e1297686e0b3d52c8b3c331: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.020 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0xd5d5b5633e1297686e0b3d52c8b3c331] [Request ID: 88ce5d7e-38c9-4e5f-ac29-cfda3a0f1b18] Closing connection 0xd5d5b5633e1297686e0b3d52c8b3c331 | code: 1006, message: �[39m
[2024-09-17 11:08:21.020 +0000] �[32mINFO�[39m (poller/100 on hedera-testnet-relay-1): �[36mPoller: Tag {"event":"logs","filters":{"address":["0x58dc9f50975e42ca40ab393f9d90b64982adc2a8","0xfe7aba7486b18d79e3df86d054f058f700668206"],"topics":[["0x0559884fd3a460db3073b7fc896cc77986f16e378210ded43186175bf646fc5f"]]}} removed from polling list�[39m
[2024-09-17 11:08:21.020 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mNo subscribers for {"event":"logs","filters":{"address":["0x58dc9f50975e42ca40ab393f9d90b64982adc2a8","0xfe7aba7486b18d79e3df86d054f058f700668206"],"topics":[["0x0559884fd3a460db3073b7fc896cc77986f16e378210ded43186175bf646fc5f"]]}}. Removing from list.�[39m
[2024-09-17 11:08:21.020 +0000] �[34mDEBUG�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xc241e5fcae5e40ff310c2213c9b74d69. Unsubscribing subId: 0xc77ef08db7369a99542e6a9632bd21d1; tag: {"event":"logs","filters":{"address":["0x58dc9f50975e42ca40ab393f9d90b64982adc2a8","0xfe7aba7486b18d79e3df86d054f058f700668206"],"topics":[["0x0559884fd3a460db3073b7fc896cc77986f16e378210ded43186175bf646fc5f"]]}}�[39m
[2024-09-17 11:08:21.020 +0000] �[32mINFO�[39m (subscr-ctrl/100 on hedera-testnet-relay-1): �[36mConnection 0xc241e5fcae5e40ff310c2213c9b74d69: Unsubscribing from all subscriptions�[39m
[2024-09-17 11:08:21.020 +0000] �[32mINFO�[39m (rpc-ws-server/100 on hedera-testnet-relay-1): �[36m[Connection ID: 0xc241e5fcae5e40ff310c2213c9b74d69] [Request ID: 2fe3b531-d084-42f9-a086-166a1d250fe7] Closing connection 0xc241e5fcae5e40ff310c2213c9b74d69 | code: 1006, message: �[39m
[2024-09-17 11:08:21.195 +0000] �[32mINFO�[39m (rpc-server/100 on hedera-testnet-relay-1): �[36m[Request ID: d024b28c-adfb-492e-88be-5666b6cfde7b] [POST]: eth_getBalance 200 10 ms�[39m
[2024-09-17 11:08:21.195 +0000] �[34mDEBUG�[39m (relay-eth/100 on hedera-testnet-relay-1): �[36m[Request ID: d024b28c-adfb-492e-88be-5666b6cfde7b] Unable to find account 0x181b419d698e334aa72e1846b17f8bc3ee78aa93 in block null(latest), returning 0x0 balance�[39m
[2024-09-17 11:08:21.195 +0000] �[34mDEBUG�[39m (mirror-node/100 on hedera-testnet-relay-1): �[36m[Request ID: d024b28c-adfb-492e-88be-5666b6cfde7b] [GET] accounts/0x181b419d698e334aa72e1846b17f8bc3ee78aa93?limit=100 404 status�[39m
[2024-09-17 11:08:21.190 +0000] �[32mINFO�[39m (rpc-server/100 on hedera-testnet-relay-1): �[36m[Request ID: c7037171-43c7-4961-bbbb-13c9990b8eea] [POST]: eth_getBalance 200 10 ms�[39m
[2024-09-17 11:08:21.192 +0000] �[90mTRACE�[39m (poller/100 on hedera-testnet-relay-0): �[36mPoller: Received 1 result from tag: {"event":"newHeads"}�[39m```

### Hedera network

testnet

### Version

Latest main

### Operating system

None

[rodgerjohnson]

@Nana-EC @victor-yanev
I believe we found the cause for this issue and have found a way to mitigate this on our side. I think we can close this issue out.