82 lines
14 KiB
Plaintext
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

2026-04-22 23:56:53.742 INFO [tests.conftest] Fleet bootstrap inactive pass --fleet (or set FLEET_BOOTSTRAP=true) to connect local nodes to the waku.test fleet
2026-04-22 23:56:53.742 DEBUG [tests.conftest] Running fixture setup: test_id
2026-04-22 23:56:53.743 DEBUG [tests.conftest] Running test: test_filter_unsubscribe_with_very_large_request_id with id: 2026-04-22_23-56-53__5ddebb4e-2756-409c-9779-d863b44100ff
2026-04-22 23:56:53.743 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-04-22 23:56:53.744 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2026-04-22 23:56:53.744 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2026-04-22 23:56:53.756 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 23:56:53.756 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2026-04-22_23-56-53__5ddebb4e-2756-409c-9779-d863b44100ff__wakuorg_nwaku:latest.log
2026-04-22 23:56:53.756 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 23:56:53.756 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 23:56:53.757 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 23:56:53.758 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.140.8
2026-04-22 23:56:53.758 DEBUG [src.node.docker_mananger] Generated ports ['55244', '55245', '55246', '55247', '55248']
2026-04-22 23:56:53.758 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 23:56:53.758 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 23:56:53.758 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 23:56:53.758 DEBUG [src.node.docker_mananger] docker run -i -t -p 55244:55244 -p 55245:55245 -p 55246:55246 -p 55247:55247 -p 55248:55248 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=55246 --rest-port=55244 --tcp-port=55245 --discv5-udp-port=55247 --rest-address=0.0.0.0 --nat=extip:172.18.140.8 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=08bff006eed2940efeace4bebba047de4decc43c51adaeb9cce528a6dafd72ee --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=55248 --metrics-logging=true --relay=true --filter=true
2026-04-22 23:56:53.933 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.140.8 waku 9f0c5a11b065e62237a14cba1601763cfcc61b688912508072ae8ec4f6d973e3
2026-04-22 23:56:53.970 DEBUG [src.node.docker_mananger] Container started with ID 9f0c5a11b065. Setting up logs at ./log/docker/node1_2026-04-22_23-56-53__5ddebb4e-2756-409c-9779-d863b44100ff__wakuorg_nwaku:latest.log
2026-04-22 23:56:53.970 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 55244
2026-04-22 23:56:53.972 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 23:56:54.090 ERROR [src.node.docker_mananger] Max retries reached for container ed16395a1358. Exiting log stream.
2026-04-22 23:56:54.565 ERROR [src.node.docker_mananger] Max retries reached for container 0624073b5ffc. Exiting log stream.
2026-04-22 23:56:54.972 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:55244/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:54.975 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"Disconnected","protocolsHealth":[{"Relay":"NOT_READY","desc":"No connected peers"},{"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"},{"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"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 23:56:54.975 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 23:56:54.975 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:55244/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:54.978 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.140.8/tcp/55245/p2p/16Uiu2HAmSfvvTRxrWFpLKKtgC9rTV2w8q7XPMV4xXfeypHpHjzQV","/ip4/172.18.140.8/tcp/55246/ws/p2p/16Uiu2HAmSfvvTRxrWFpLKKtgC9rTV2w8q7XPMV4xXfeypHpHjzQV"],"enrUri":"enr:-L24QM7D8-9NbS-D7xuUDI7O8jm1nO4EGxjJCG6wn27hvxVMcfBRA445ZuKHNf0PrRj9W2FxYNizGwuDKLptCw0rZ94CgmlkgnY0gmlwhKwSjAiKbXVsdGlhZGRyc5YACASsEowIBtfNAAoErBKMCAbXzt0DgnJzhQDGAQAAiXNlY3AyNTZrMaED0EFSUK0MgPNx-1R7f4Eawa8HKKKyGZU2w_2KbJBlicaDdGNwgtfNg3VkcILXz4V3YWt1MgU"}'
2026-04-22 23:56:54.978 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 23:56:54.978 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2026-04-22 23:56:54.984 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 23:56:54.984 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2026-04-22_23-56-53__5ddebb4e-2756-409c-9779-d863b44100ff__wakuorg_nwaku:latest.log
2026-04-22 23:56:54.984 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 23:56:54.985 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 23:56:54.986 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 23:56:54.986 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.239.104
2026-04-22 23:56:54.986 DEBUG [src.node.docker_mananger] Generated ports ['47067', '47068', '47069', '47070', '47071']
2026-04-22 23:56:54.986 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 23:56:54.986 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 23:56:54.986 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 23:56:54.987 DEBUG [src.node.docker_mananger] docker run -i -t -p 47067:47067 -p 47068:47068 -p 47069:47069 -p 47070:47070 -p 47071:47071 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=47069 --rest-port=47067 --tcp-port=47068 --discv5-udp-port=47070 --rest-address=0.0.0.0 --nat=extip:172.18.239.104 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=2fad0aecd16157682ed37bddd6be49dd917220ef170b8ca7beb7d87c3d383d80 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=47071 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QM7D8-9NbS-D7xuUDI7O8jm1nO4EGxjJCG6wn27hvxVMcfBRA445ZuKHNf0PrRj9W2FxYNizGwuDKLptCw0rZ94CgmlkgnY0gmlwhKwSjAiKbXVsdGlhZGRyc5YACASsEowIBtfNAAoErBKMCAbXzt0DgnJzhQDGAQAAiXNlY3AyNTZrMaED0EFSUK0MgPNx-1R7f4Eawa8HKKKyGZU2w_2KbJBlicaDdGNwgtfNg3VkcILXz4V3YWt1MgU --filternode=/ip4/172.18.140.8/tcp/55245/p2p/16Uiu2HAmSfvvTRxrWFpLKKtgC9rTV2w8q7XPMV4xXfeypHpHjzQV
2026-04-22 23:56:55.170 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.239.104 waku 20a99062f6ea8a955cd69afed956e5a55907a69d1ec1dca57716d3e8886c3dcf
2026-04-22 23:56:55.208 DEBUG [src.node.docker_mananger] Container started with ID 20a99062f6ea. Setting up logs at ./log/docker/node2_2026-04-22_23-56-53__5ddebb4e-2756-409c-9779-d863b44100ff__wakuorg_nwaku:latest.log
2026-04-22 23:56:55.208 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 47067
2026-04-22 23:56:55.209 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 23:56:56.210 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:47067/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:56.212 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"Disconnected","protocolsHealth":[{"Relay":"NOT_MOUNTED"},{"Lightpush":"NOT_MOUNTED"},{"Legacy Lightpush":"NOT_MOUNTED"},{"Filter":"NOT_MOUNTED"},{"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"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 23:56:56.213 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 23:56:56.213 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:47067/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:56.215 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.239.104/tcp/47068/p2p/16Uiu2HAmCNWyfq1to3tez38QcBskc54Pz8wGmjEgfXeMriYd1apB","/ip4/172.18.239.104/tcp/47069/ws/p2p/16Uiu2HAmCNWyfq1to3tez38QcBskc54Pz8wGmjEgfXeMriYd1apB"],"enrUri":"enr:-L24QPUeBI1lEQi1azEtQRfAnC7NK-R1xJkmlGL0hfH7uj2lHWqofsK21QIfK9ydQGRGGrBryHRCBr0V16LHo4EvaEACgmlkgnY0gmlwhKwS72iKbXVsdGlhZGRyc5YACASsEu9oBrfcAAoErBLvaAa33d0DgnJzhQDGAQAAiXNlY3AyNTZrMaEC-8fBr5YMoEkxxz5P_7zIkmmJnDUGXbbRaHzWMAP1wbSDdGNwgrfcg3VkcIK33oV3YWt1MgA"}'
2026-04-22 23:56:56.215 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 23:56:56.215 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:47067/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.140.8/tcp/55245/p2p/16Uiu2HAmSfvvTRxrWFpLKKtgC9rTV2w8q7XPMV4xXfeypHpHjzQV"]'
2026-04-22 23:56:56.235 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:56:56.238 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2026-04-22 23:56:56.238 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:55244/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/198/1"]'
2026-04-22 23:56:56.244 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:56:56.245 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:47067/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "9c72ef74-5725-46bc-884d-674d30137915", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/198/1"}'
2026-04-22 23:56:56.260 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"9c72ef74-5725-46bc-884d-674d30137915","statusDesc":"OK"}'
2026-04-22 23:56:56.261 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:55244/relay/v1/messages/%2Fwaku%2F2%2Frs%2F198%2F1" -H "Content-Type: application/json" -d '{"payload": "RmlsdGVyIHdvcmtzISE=", "contentTopic": "/test/1/waku-filter/proto", "timestamp": '$(date +%s%N)'}'
2026-04-22 23:56:56.268 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:56:56.268 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-04-22 23:56:56.369 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-04-22 23:56:56.369 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:47067/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:56.372 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"RmlsdGVyIHdvcmtzISE=","contentTopic":"/test/1/waku-filter/proto","version":0,"timestamp":1776902216261623170,"ephemeral":false}]'
2026-04-22 23:56:56.373 INFO [src.node.api_clients.base_client] curl -v -X DELETE "http://127.0.0.1:47067/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "12345678901234567890123456789012345678901234567890", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/198/1"}'
2026-04-22 23:56:56.382 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"12345678901234567890123456789012345678901234567890","statusDesc":"OK"}'
2026-04-22 23:56:56.383 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:55244/relay/v1/messages/%2Fwaku%2F2%2Frs%2F198%2F1" -H "Content-Type: application/json" -d '{"payload": "RmlsdGVyIHdvcmtzISE=", "contentTopic": "/test/1/waku-filter/proto", "timestamp": '$(date +%s%N)'}'
2026-04-22 23:56:56.386 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:56:56.387 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-04-22 23:56:56.487 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-04-22 23:56:56.487 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:47067/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:56:56.489 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:47067/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto. Response content: b'Not subscribed to topic: /test/1/waku-filter/proto'
2026-04-22 23:56:56.492 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-04-22 23:56:56.494 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-04-22 23:56:56.494 DEBUG [src.node.waku_node] Stopping container with id 9f0c5a11b065
2026-04-22 23:56:56.951 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 23:56:56.955 DEBUG [src.node.waku_node] Stopping container with id 20a99062f6ea
2026-04-22 23:56:57.405 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 23:56:57.406 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-04-22 23:56:57.414 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-04-22 23:56:57.420 DEBUG [src.node.docker_mananger] No errors found in the waku logs.