85 lines
15 KiB
Plaintext

2026-02-10 04:47:11.951 DEBUG [tests.conftest] Running fixture setup: test_id
2026-02-10 04:47:11.951 DEBUG [tests.conftest] Running test: test_filter_unsubscribe_from_all_subscribed_content_topics with id: 2026-02-10_04-47-11__2c1cdddc-b8da-4e5f-aa57-12c5d8465b2a
2026-02-10 04:47:11.952 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-02-10 04:47:11.952 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2026-02-10 04:47:11.952 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2026-02-10 04:47:11.959 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-02-10 04:47:11.959 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2026-02-10_04-47-11__2c1cdddc-b8da-4e5f-aa57-12c5d8465b2a__wakuorg_nwaku:latest.log
2026-02-10 04:47:11.959 DEBUG [src.node.waku_node] Starting Node...
2026-02-10 04:47:11.959 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-02-10 04:47:11.960 DEBUG [src.node.docker_mananger] Network waku already exists
2026-02-10 04:47:11.960 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.29.25
2026-02-10 04:47:11.961 DEBUG [src.node.docker_mananger] Generated ports ['33003', '33004', '33005', '33006', '33007']
2026-02-10 04:47:11.961 DEBUG [src.node.waku_node] RLN credentials were not set
2026-02-10 04:47:11.961 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-02-10 04:47:11.961 DEBUG [src.node.waku_node] Using volumes []
2026-02-10 04:47:11.961 DEBUG [src.node.docker_mananger] docker run -i -t -p 33003:33003 -p 33004:33004 -p 33005:33005 -p 33006:33006 -p 33007:33007 wakuorg/nwaku:latest --listen-address=0.0.0.0 --rest=true --rest-admin=true --websocket-support=true --log-level=TRACE --rest-relay-cache-capacity=100 --websocket-port=33005 --rest-port=33003 --tcp-port=33004 --discv5-udp-port=33006 --rest-address=0.0.0.0 --nat=extip:172.18.29.25 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=f34557dadfbc3aec16b887341adabafcf1929510ecd648cabdea2c31b82cdbda --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=33007 --metrics-logging=true --relay=true --filter=true
2026-02-10 04:47:12.144 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.29.25 waku 0ac204a386ab91138b98fd0018852837a3a51d7168fb6834d094352be76ca406
2026-02-10 04:47:12.175 DEBUG [src.node.docker_mananger] Container started with ID 0ac204a386ab. Setting up logs at ./log/docker/node1_2026-02-10_04-47-11__2c1cdddc-b8da-4e5f-aa57-12c5d8465b2a__wakuorg_nwaku:latest.log
2026-02-10 04:47:12.175 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 33003
2026-02-10 04:47:12.176 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-02-10 04:47:12.207 ERROR [src.node.docker_mananger] Max retries reached for container 4ab07a8f8d0d. Exiting log stream.
2026-02-10 04:47:12.759 ERROR [src.node.docker_mananger] Max retries reached for container 731efe10f4b9. Exiting log stream.
2026-02-10 04:47:13.177 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:33003/health" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:13.180 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","protocolsHealth":[{"Relay":"NOT_READY","desc":"No connected peers"},{"Rln Relay":"NOT_MOUNTED"},{"Lightpush":"NOT_MOUNTED"},{"Legacy Lightpush":"NOT_MOUNTED"},{"Filter":"NOT_READY","desc":"Relay is not ready, filter will not be able to sort out messages"},{"Store":"NOT_MOUNTED"},{"Legacy Store":"NOT_MOUNTED"},{"Peer Exchange":"READY"},{"Rendezvous":"NOT_READY","desc":"No Rendezvous peers are available yet"},{"Mix":"NOT_MOUNTED"},{"Lightpush Client":"NOT_READY","desc":"No Lightpush service peer available yet"},{"Legacy Lightpush Client":"NOT_READY","desc":"No Lightpush service peer available yet"},{"Store Client":"NOT_READY","desc":"No Store service peer available yet, neither Store service set up for the node"},{"Legacy Store Client":"NOT_READY","desc":"No Legacy Store service peers are available yet, neither Store service set up for the node"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"}]}'
2026-02-10 04:47:13.180 INFO [src.node.waku_node] Node protocols are initialized !!
2026-02-10 04:47:13.181 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:33003/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:13.183 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.29.25/tcp/33004/p2p/16Uiu2HAmHPL9ioU9Xue1RGA5JU7dVtevWTD1HX9L4iQhYkyhxRKp","/ip4/172.18.29.25/tcp/33005/ws/p2p/16Uiu2HAmHPL9ioU9Xue1RGA5JU7dVtevWTD1HX9L4iQhYkyhxRKp"],"enrUri":"enr:-L24QI0Bhj0eGtYf6eZhWjALg97z_Fk_OInq6eUlUOwAgQdaVL72eQpmAX1lzMIfOj-CDjOnsyqcXOg0cc5RZJJnd5sCgmlkgnY0gmlwhKwSHRmKbXVsdGlhZGRyc5YACASsEh0ZBoDsAAoErBIdGQaA7d0DgnJzhQADAQAAiXNlY3AyNTZrMaEDRkeHvXpW4vR9SJBO6SAih_HyXgnf3uIs_TS4HDHCX_uDdGNwgoDsg3VkcIKA7oV3YWt1MgU"}'
2026-02-10 04:47:13.183 INFO [src.node.waku_node] REST service is ready !!
2026-02-10 04:47:13.183 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2026-02-10 04:47:13.190 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-02-10 04:47:13.190 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2026-02-10_04-47-11__2c1cdddc-b8da-4e5f-aa57-12c5d8465b2a__wakuorg_nwaku:latest.log
2026-02-10 04:47:13.190 DEBUG [src.node.waku_node] Starting Node...
2026-02-10 04:47:13.190 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-02-10 04:47:13.191 DEBUG [src.node.docker_mananger] Network waku already exists
2026-02-10 04:47:13.191 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.56.57
2026-02-10 04:47:13.191 DEBUG [src.node.docker_mananger] Generated ports ['31137', '31138', '31139', '31140', '31141']
2026-02-10 04:47:13.192 DEBUG [src.node.waku_node] RLN credentials were not set
2026-02-10 04:47:13.192 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-02-10 04:47:13.192 DEBUG [src.node.waku_node] Using volumes []
2026-02-10 04:47:13.192 DEBUG [src.node.docker_mananger] docker run -i -t -p 31137:31137 -p 31138:31138 -p 31139:31139 -p 31140:31140 -p 31141:31141 wakuorg/nwaku:latest --listen-address=0.0.0.0 --rest=true --rest-admin=true --websocket-support=true --log-level=TRACE --rest-relay-cache-capacity=100 --websocket-port=31139 --rest-port=31137 --tcp-port=31138 --discv5-udp-port=31140 --rest-address=0.0.0.0 --nat=extip:172.18.56.57 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=7da0ba6210b7fe606cf3bdc2bdcfe6724abfa04cf9ffb6cceefb2dcd7cd5e6c6 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=31141 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QI0Bhj0eGtYf6eZhWjALg97z_Fk_OInq6eUlUOwAgQdaVL72eQpmAX1lzMIfOj-CDjOnsyqcXOg0cc5RZJJnd5sCgmlkgnY0gmlwhKwSHRmKbXVsdGlhZGRyc5YACASsEh0ZBoDsAAoErBIdGQaA7d0DgnJzhQADAQAAiXNlY3AyNTZrMaEDRkeHvXpW4vR9SJBO6SAih_HyXgnf3uIs_TS4HDHCX_uDdGNwgoDsg3VkcIKA7oV3YWt1MgU --filternode=/ip4/172.18.29.25/tcp/33004/p2p/16Uiu2HAmHPL9ioU9Xue1RGA5JU7dVtevWTD1HX9L4iQhYkyhxRKp
2026-02-10 04:47:13.376 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.56.57 waku b39769e76d2588c019a6229409a723f6965559045c967231663b8fdf9335c7b0
2026-02-10 04:47:13.409 DEBUG [src.node.docker_mananger] Container started with ID b39769e76d25. Setting up logs at ./log/docker/node2_2026-02-10_04-47-11__2c1cdddc-b8da-4e5f-aa57-12c5d8465b2a__wakuorg_nwaku:latest.log
2026-02-10 04:47:13.410 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 31137
2026-02-10 04:47:13.410 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-02-10 04:47:14.410 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:31137/health" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:14.414 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","protocolsHealth":[{"Relay":"NOT_MOUNTED"},{"Rln Relay":"NOT_MOUNTED"},{"Lightpush":"NOT_MOUNTED"},{"Legacy Lightpush":"NOT_MOUNTED"},{"Filter":"NOT_MOUNTED"},{"Store":"NOT_MOUNTED"},{"Legacy Store":"NOT_MOUNTED"},{"Peer Exchange":"READY"},{"Rendezvous":"NOT_READY","desc":"No Rendezvous peers are available yet"},{"Mix":"NOT_MOUNTED"},{"Lightpush Client":"NOT_READY","desc":"No Lightpush service peer available yet"},{"Legacy Lightpush Client":"NOT_READY","desc":"No Lightpush service peer available yet"},{"Store Client":"NOT_READY","desc":"No Store service peer available yet, neither Store service set up for the node"},{"Legacy Store Client":"NOT_READY","desc":"No Legacy Store service peers are available yet, neither Store service set up for the node"},{"Filter Client":"READY"}]}'
2026-02-10 04:47:14.415 INFO [src.node.waku_node] Node protocols are initialized !!
2026-02-10 04:47:14.415 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:31137/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:14.417 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.56.57/tcp/31138/p2p/16Uiu2HAmUrxDzEXndviFEgwcxo8RZFSF5xwqwgHSXT73E96UY8tz","/ip4/172.18.56.57/tcp/31139/ws/p2p/16Uiu2HAmUrxDzEXndviFEgwcxo8RZFSF5xwqwgHSXT73E96UY8tz"],"enrUri":"enr:-L24QF4pFRBDP6X3EnM5vw8zkZsGh9WMDbcJI9vYdR1Z37Tje-3dDRmow8ZAnDkmkl5LQkPsrJm7I3lhvqf-ZP7h_X0CgmlkgnY0gmlwhKwSODmKbXVsdGlhZGRyc5YACASsEjg5BnmiAAoErBI4OQZ5o90DgnJzhQADAQAAiXNlY3AyNTZrMaED8MuOiDr0idHU3YfERJN9QaXoFN8MJhrxWep0FTyHn-uDdGNwgnmig3VkcIJ5pIV3YWt1MgA"}'
2026-02-10 04:47:14.418 INFO [src.node.waku_node] REST service is ready !!
2026-02-10 04:47:14.418 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:31137/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.29.25/tcp/33004/p2p/16Uiu2HAmHPL9ioU9Xue1RGA5JU7dVtevWTD1HX9L4iQhYkyhxRKp"]'
2026-02-10 04:47:14.450 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-10 04:47:14.453 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2026-02-10 04:47:14.454 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:33003/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2026-02-10 04:47:14.462 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-10 04:47:14.463 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:31137/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "9c798025-6cec-47cf-831f-9f89a51b3128", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2026-02-10 04:47:14.476 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"9c798025-6cec-47cf-831f-9f89a51b3128","statusDesc":"OK"}'
2026-02-10 04:47:14.478 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:33003/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2026-02-10 04:47:14.480 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-10 04:47:14.480 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:31137/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "543e4253-1ef0-427a-b5ce-ef421459d33a", "contentFilters": ["Hello World!", "1234567890"], "pubsubTopic": "/waku/2/rs/3/1"}'
2026-02-10 04:47:14.489 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"543e4253-1ef0-427a-b5ce-ef421459d33a","statusDesc":"OK"}'
2026-02-10 04:47:14.490 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:33003/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d '{"payload": "RmlsdGVyIHdvcmtzISE=", "contentTopic": "1234567890", "timestamp": '$(date +%s%N)'}'
2026-02-10 04:47:14.497 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-10 04:47:14.497 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-02-10 04:47:14.597 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-02-10 04:47:14.598 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:31137/filter/v2/messages/1234567890" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:14.601 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"RmlsdGVyIHdvcmtzISE=","contentTopic":"1234567890","version":0,"timestamp":1770698834489912997,"ephemeral":false}]'
2026-02-10 04:47:14.603 INFO [src.node.api_clients.base_client] curl -v -X DELETE "http://127.0.0.1:31137/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "1", "contentFilters": ["Hello World!", "1234567890"], "pubsubTopic": "/waku/2/rs/3/1"}'
2026-02-10 04:47:14.611 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"1","statusDesc":"OK"}'
2026-02-10 04:47:14.612 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:33003/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d '{"payload": "RmlsdGVyIHdvcmtzISE=", "contentTopic": "1234567890", "timestamp": '$(date +%s%N)'}'
2026-02-10 04:47:14.616 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-10 04:47:14.616 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-02-10 04:47:14.716 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-02-10 04:47:14.717 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:31137/filter/v2/messages/1234567890" -H "Content-Type: application/json" -d 'None'
2026-02-10 04:47:14.719 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:31137/filter/v2/messages/1234567890. Response content: b'Not subscribed to topic: 1234567890'
2026-02-10 04:47:14.722 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-02-10 04:47:14.723 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-02-10 04:47:14.723 DEBUG [src.node.waku_node] Stopping container with id 0ac204a386ab
2026-02-10 04:47:15.259 DEBUG [src.node.waku_node] Container stopped.
2026-02-10 04:47:15.260 DEBUG [src.node.waku_node] Stopping container with id b39769e76d25
2026-02-10 04:47:15.788 DEBUG [src.node.waku_node] Container stopped.
2026-02-10 04:47:15.789 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-02-10 04:47:15.796 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-02-10 04:47:15.802 DEBUG [src.node.docker_mananger] No errors found in the waku logs.