69 lines
12 KiB
Plaintext

2025-12-29 04:23:05.799 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-29 04:23:05.800 DEBUG [tests.conftest] Running test: test_filter_unsubscribe_with_invalid_request_id with id: 2025-12-29_04-23-05__879afcce-e9f2-4253-93dd-4f56c9162638
2025-12-29 04:23:05.800 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-29 04:23:05.800 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2025-12-29 04:23:05.800 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2025-12-29 04:23:05.807 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-29 04:23:05.807 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-29_04-23-05__879afcce-e9f2-4253-93dd-4f56c9162638__wakuorg_nwaku:latest.log
2025-12-29 04:23:05.807 DEBUG [src.node.waku_node] Starting Node...
2025-12-29 04:23:05.807 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-29 04:23:05.809 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-29 04:23:05.809 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.242.41
2025-12-29 04:23:05.809 DEBUG [src.node.docker_mananger] Generated ports ['10934', '10935', '10936', '10937', '10938']
2025-12-29 04:23:05.809 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-29 04:23:05.809 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-29 04:23:05.809 DEBUG [src.node.waku_node] Using volumes []
2025-12-29 04:23:05.810 DEBUG [src.node.docker_mananger] docker run -i -t -p 10934:10934 -p 10935:10935 -p 10936:10936 -p 10937:10937 -p 10938:10938 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=10936 --rest-port=10934 --tcp-port=10935 --discv5-udp-port=10937 --rest-address=0.0.0.0 --nat=extip:172.18.242.41 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=390f0aebc9edac7be2b00dffdb5602673f8eb79faef79abebab6ffbdfe06619f --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=10938 --metrics-logging=true --relay=true --filter=true
2025-12-29 04:23:05.998 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.242.41 waku 2d3050772b41db7559dac8f0430b9fec7d210bce1570e7827250661bca79cf31
2025-12-29 04:23:06.024 ERROR [src.node.docker_mananger] Max retries reached for container f305514fb449. Exiting log stream.
2025-12-29 04:23:06.030 DEBUG [src.node.docker_mananger] Container started with ID 2d3050772b41. Setting up logs at ./log/docker/node1_2025-12-29_04-23-05__879afcce-e9f2-4253-93dd-4f56c9162638__wakuorg_nwaku:latest.log
2025-12-29 04:23:06.031 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 10934
2025-12-29 04:23:06.031 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-29 04:23:06.603 ERROR [src.node.docker_mananger] Max retries reached for container 54d7a2089f12. Exiting log stream.
2025-12-29 04:23:07.031 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:10934/health" -H "Content-Type: application/json" -d 'None'
2025-12-29 04:23:07.035 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"}]}'
2025-12-29 04:23:07.035 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-29 04:23:07.035 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:10934/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-29 04:23:07.038 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.242.41/tcp/10935/p2p/16Uiu2HAmKeJQrp2WSMSK9TWvEmsc4znNexUZ5UVskg2C9Ffme2bm","/ip4/172.18.242.41/tcp/10936/ws/p2p/16Uiu2HAmKeJQrp2WSMSK9TWvEmsc4znNexUZ5UVskg2C9Ffme2bm"],"enrUri":"enr:-L24QFZOCGvYtQN0FteDVMytAkLiWxrXEFStEknyCGuwvKtAN5xcpJhgpcKigtdDjriwMsrfqI3hnfww3xPpsbpPAn4CgmlkgnY0gmlwhKwS8imKbXVsdGlhZGRyc5YACASsEvIpBiq3AAoErBLyKQYquN0DgnJzhQADAQAAiXNlY3AyNTZrMaEDZ9SmYfNKDsJdbD7GNpeZoLlMLzF-q2OSZH-7tx8L1cyDdGNwgiq3g3VkcIIquYV3YWt1MgU"}'
2025-12-29 04:23:07.038 INFO [src.node.waku_node] REST service is ready !!
2025-12-29 04:23:07.038 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2025-12-29 04:23:07.045 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-29 04:23:07.045 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-29_04-23-05__879afcce-e9f2-4253-93dd-4f56c9162638__wakuorg_nwaku:latest.log
2025-12-29 04:23:07.045 DEBUG [src.node.waku_node] Starting Node...
2025-12-29 04:23:07.045 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-29 04:23:07.047 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-29 04:23:07.047 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.90.148
2025-12-29 04:23:07.047 DEBUG [src.node.docker_mananger] Generated ports ['50970', '50971', '50972', '50973', '50974']
2025-12-29 04:23:07.047 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-29 04:23:07.047 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-29 04:23:07.047 DEBUG [src.node.waku_node] Using volumes []
2025-12-29 04:23:07.048 DEBUG [src.node.docker_mananger] docker run -i -t -p 50970:50970 -p 50971:50971 -p 50972:50972 -p 50973:50973 -p 50974:50974 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=50972 --rest-port=50970 --tcp-port=50971 --discv5-udp-port=50973 --rest-address=0.0.0.0 --nat=extip:172.18.90.148 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=8c0db4ff1dcf4fbcc5fdb1d65c23d0cd8c3beebb5b0cbed74b81f2babdff8c80 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=50974 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QFZOCGvYtQN0FteDVMytAkLiWxrXEFStEknyCGuwvKtAN5xcpJhgpcKigtdDjriwMsrfqI3hnfww3xPpsbpPAn4CgmlkgnY0gmlwhKwS8imKbXVsdGlhZGRyc5YACASsEvIpBiq3AAoErBLyKQYquN0DgnJzhQADAQAAiXNlY3AyNTZrMaEDZ9SmYfNKDsJdbD7GNpeZoLlMLzF-q2OSZH-7tx8L1cyDdGNwgiq3g3VkcIIquYV3YWt1MgU --filternode=/ip4/172.18.242.41/tcp/10935/p2p/16Uiu2HAmKeJQrp2WSMSK9TWvEmsc4znNexUZ5UVskg2C9Ffme2bm
2025-12-29 04:23:07.241 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.90.148 waku 96de4ffe55568d7025e69b4e79c4adff2f9245cd14df26e2fc48b4e0daaef24e
2025-12-29 04:23:07.272 DEBUG [src.node.docker_mananger] Container started with ID 96de4ffe5556. Setting up logs at ./log/docker/node2_2025-12-29_04-23-05__879afcce-e9f2-4253-93dd-4f56c9162638__wakuorg_nwaku:latest.log
2025-12-29 04:23:07.272 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 50970
2025-12-29 04:23:07.272 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-29 04:23:08.273 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:50970/health" -H "Content-Type: application/json" -d 'None'
2025-12-29 04:23:08.277 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"}]}'
2025-12-29 04:23:08.277 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-29 04:23:08.277 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:50970/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-29 04:23:08.280 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.90.148/tcp/50971/p2p/16Uiu2HAmAdb9Ukn2q3ZXmJtDdE9wBM8PuazrSg3SoxGhzP7B7296","/ip4/172.18.90.148/tcp/50972/ws/p2p/16Uiu2HAmAdb9Ukn2q3ZXmJtDdE9wBM8PuazrSg3SoxGhzP7B7296"],"enrUri":"enr:-L24QH1M5BEiF5BCFqiPAUZvVtSA-ymAlOzavDZ4CvcP68t8TzbXYxMcH0e4NxhsEgrf6Xo46kD4DvpQflPf9pNJqNcCgmlkgnY0gmlwhKwSWpSKbXVsdGlhZGRyc5YACASsElqUBscbAAoErBJalAbHHN0DgnJzhQADAQAAiXNlY3AyNTZrMaEC4ezPFL-cRcTAdJdifFcGX-xqm4lHubQDKJJPeMzT-kmDdGNwgscbg3VkcILHHYV3YWt1MgA"}'
2025-12-29 04:23:08.280 INFO [src.node.waku_node] REST service is ready !!
2025-12-29 04:23:08.281 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:50970/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.242.41/tcp/10935/p2p/16Uiu2HAmKeJQrp2WSMSK9TWvEmsc4znNexUZ5UVskg2C9Ffme2bm"]'
2025-12-29 04:23:08.310 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-29 04:23:08.311 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2025-12-29 04:23:08.311 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:10934/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-29 04:23:08.325 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-29 04:23:08.327 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:50970/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "c21b14f3-62b2-4a61-804f-23b3529452d6", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2025-12-29 04:23:08.339 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"c21b14f3-62b2-4a61-804f-23b3529452d6","statusDesc":"OK"}'
2025-12-29 04:23:08.340 INFO [src.node.api_clients.base_client] curl -v -X DELETE "http://127.0.0.1:50970/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": 1, "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2025-12-29 04:23:08.343 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:50970/filter/v2/subscriptions. Response content: b'{"requestId":"unknown","statusDesc":"BAD_REQUEST: Failed to decode request: (status: 400 Bad Request, headers: , kind: Error, errobj: (status: 400 Bad Request, message: \\"Invalid content body, could not decode. Unable to deserialize data: \\", contentType: \\"text/plain\\"))"}'
2025-12-29 04:23:08.345 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-29 04:23:08.346 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-29 04:23:08.346 DEBUG [src.node.waku_node] Stopping container with id 2d3050772b41
2025-12-29 04:23:08.858 DEBUG [src.node.waku_node] Container stopped.
2025-12-29 04:23:08.858 DEBUG [src.node.waku_node] Stopping container with id 96de4ffe5556
2025-12-29 04:23:09.390 DEBUG [src.node.waku_node] Container stopped.
2025-12-29 04:23:09.392 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-29 04:23:09.397 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-29 04:23:09.401 DEBUG [src.node.docker_mananger] No errors found in the waku logs.