[relay]bug/regression: Unsubscribing from one pubsubtopic seems to unsubscribe from all

[fbarbu15]

Regression because it works fine with wakuorg/go-waku:latest from docker-hub but fails with harbor.status.im/wakuorg/go-waku:latest
Also works fine with harbor.status.im/wakuorg/nwaku:latest

To Reproduce

1. Have 2 relays nodes connected
2. Subscribe both nodes to 2 pubSubtopics and publish messages. This works fine
3. Un-Subscribe both nodes from the 1st pubSubtopics
4. Publish messages on both pubSubtopics

Actual behavior
500 Server Error on both pubSubtopics

Expected behavior
Only the 1st pubSubtopics should fail, the 2nd one should work fine

Additional context
Test logs for more detailed steps

INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:61525/relay/v1/subscriptions with payload: ["/waku/2/default-waku/proto", "/waku/2/rs/0/1"]
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:17685/relay/v1/subscriptions with payload: ["/waku/2/default-waku/proto", "/waku/2/rs/0/1"]
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Fdefault-waku%2Fproto with payload: {"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": 1703245609981811456}
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
DEBUG    src.libs.common:common.py:33 Sleeping for 0.1 seconds
DEBUG    src.steps.relay:relay.py:83 Checking that peer NODE_1:harbor.status.im/wakuorg/go-waku:latest can find the published message
INFO     src.node.api_clients.base_client:base_client.py:11 GET call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Fdefault-waku%2Fproto with payload: None
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","timestamp":1703245609981811456}]'
DEBUG    src.steps.relay:relay.py:83 Checking that peer NODE_2:harbor.status.im/wakuorg/go-waku:latest can find the published message
INFO     src.node.api_clients.base_client:base_client.py:11 GET call: http://127.0.0.1:17685/relay/v1/messages/%2Fwaku%2F2%2Fdefault-waku%2Fproto with payload: None
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","timestamp":1703245609981811456}]'
INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Frs%2F0%2F1 with payload: {"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": 1703245610094566144}
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
DEBUG    src.libs.common:common.py:33 Sleeping for 0.1 seconds
DEBUG    src.steps.relay:relay.py:83 Checking that peer NODE_1:harbor.status.im/wakuorg/go-waku:latest can find the published message
INFO     src.node.api_clients.base_client:base_client.py:11 GET call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Frs%2F0%2F1 with payload: None
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","timestamp":1703245610094566144}]'
DEBUG    src.steps.relay:relay.py:83 Checking that peer NODE_2:harbor.status.im/wakuorg/go-waku:latest can find the published message
INFO     src.node.api_clients.base_client:base_client.py:11 GET call: http://127.0.0.1:17685/relay/v1/messages/%2Fwaku%2F2%2Frs%2F0%2F1 with payload: None
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","timestamp":1703245610094566144}]'
INFO     src.node.api_clients.base_client:base_client.py:11 DELETE call: http://127.0.0.1:61525/relay/v1/subscriptions with payload: ["/waku/2/default-waku/proto"]
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
INFO     src.node.api_clients.base_client:base_client.py:11 DELETE call: http://127.0.0.1:17685/relay/v1/subscriptions with payload: ["/waku/2/default-waku/proto"]
INFO     src.node.api_clients.base_client:base_client.py:22 Response status code: 200. Response content: b'true'
INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Fdefault-waku%2Fproto with payload: {"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": 1703245610216815616}
ERROR    src.node.api_clients.base_client:base_client.py:16 HTTP error occurred: 500 Server Error: Internal Server Error for url: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Fdefault-waku%2Fproto. Response content: b''
INFO     src.node.api_clients.base_client:base_client.py:11 POST call: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Frs%2F0%2F1 with payload: {"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": 1703245610222288384}
ERROR    src.node.api_clients.base_client:base_client.py:16 HTTP error occurred: 500 Server Error: Internal Server Error for url: http://127.0.0.1:61525/relay/v1/messages/%2Fwaku%2F2%2Frs%2F0%2F1. Response content: b''

Node logs:
node1_2023-12-22_13-55-11__e4278b14-05e5-479e-9f75-48efedcb52d6__harbor.status.im_wakuorg_go-wakulatest.log
node2_2023-12-22_13-55-11__e4278b14-05e5-479e-9f75-48efedcb52d6__harbor.status.im_wakuorg_go-wakulatest.log

[chaitanyaprem]

I went through the logs for the nodes and noticed the following which doesn't seem to be right.

The nodes seem to have been started without clusterID 0 which would subcribe them to default pubsubTopic /waku/2/default-waku/proto. Post which subscription is being done to a sharded pubsubTopic /waku/2/rs/0/1. This leads to a situation where the peer is having a mix of named and static sharding (which is not expected to happen).
So, as soon as the node is unsubscribed from default pubsubTopic the peer is not considered valid for sharded pubsubTopic.
Hence when you try to send a message, the log shows not enough peers to publish. This doesn't mean the local node got unsubscribed from the sharded pubsubTopic.

I would correct the test to the following and verify if it works fine. I had tested this locally and noticed that there is no issue.

• Start nodes by subscribing them to some sharded pubsubTopic such as /waku/2/rs/0/1
• Subscribe to additional pubsubTopic /waku/2/rs/0/2
• Publish messages on both pusubtopics
• Unsubscribe from one of the pubsubTopic /waku/2/rs/0/2
• Publish message on /waku/2/rs/0/1 and message should get sent.

Let me know if you require more information.

[fbarbu15]

Makes sense, test works fine if I start the node with clusterID 0. Thanks for the suggestions

Just have one question based on this. Should I split the tests in 2 categories:

1. When node starts with no clusterID, tests should use the default pubsubTopic /waku/2/default-waku/proto
2. When node starts with cluster ID ex 0, tests should use pubsubTopic such as /waku/2/rs/0/1
   ?

[chaitanyaprem]

Makes sense, test works fine if I start the node with clusterID 0. Thanks for the suggestions

Just have one question based on this. Should I split the tests in 2 categories:

1. When node starts with no clusterID, tests should use the default pubsubTopic `/waku/2/default-waku/proto`

2. When node starts with cluster ID ex 0, tests should use pubsubTopic such as `/waku/2/rs/0/1`
   ?

Default pubsub topic will get deprecated soon, so i wouldn't recommend spending time on it. Only static/autosharding would be expected going forward. So, only category-2 i.e which uses sharding should be sufficient.

Also, if tests seem to work fine, do close the issue.