73 lines
13 KiB
Plaintext

2025-12-08 12:10:17.895 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-08 12:10:17.895 DEBUG [tests.conftest] Running test: test_filter_get_message_with_version with id: 2025-12-08_12-10-17__5e91ccff-fdfc-4553-a659-5fc679c1238d
2025-12-08 12:10:17.895 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-08 12:10:17.896 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2025-12-08 12:10:17.896 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2025-12-08 12:10:17.902 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-08 12:10:17.902 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-08_12-10-17__5e91ccff-fdfc-4553-a659-5fc679c1238d__wakuorg_nwaku:latest.log
2025-12-08 12:10:17.902 DEBUG [src.node.waku_node] Starting Node...
2025-12-08 12:10:17.902 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-08 12:10:17.904 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-08 12:10:17.904 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.200.211
2025-12-08 12:10:17.904 DEBUG [src.node.docker_mananger] Generated ports ['48164', '48165', '48166', '48167', '48168']
2025-12-08 12:10:17.904 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-08 12:10:17.904 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-08 12:10:17.904 DEBUG [src.node.waku_node] Using volumes []
2025-12-08 12:10:17.904 DEBUG [src.node.docker_mananger] docker run -i -t -p 48164:48164 -p 48165:48165 -p 48166:48166 -p 48167:48167 -p 48168:48168 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=48166 --rest-port=48164 --tcp-port=48165 --discv5-udp-port=48167 --rest-address=0.0.0.0 --nat=extip:172.18.200.211 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=ddab560ca92014dfde4aafea3fb13bad8deaaecfafcbbc5df8e1c7abcabacf27 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=48168 --metrics-logging=true --relay=true --filter=true
2025-12-08 12:10:18.059 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.200.211 waku 940e3b595ed246c453d957cc114f77c4dbda9e7868e359580378bcf9fd7c91f9
2025-12-08 12:10:18.087 DEBUG [src.node.docker_mananger] Container started with ID 940e3b595ed2. Setting up logs at ./log/docker/node1_2025-12-08_12-10-17__5e91ccff-fdfc-4553-a659-5fc679c1238d__wakuorg_nwaku:latest.log
2025-12-08 12:10:18.088 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 48164
2025-12-08 12:10:18.089 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-08 12:10:18.153 ERROR [src.node.docker_mananger] Max retries reached for container 9c3d03354470. Exiting log stream.
2025-12-08 12:10:18.626 ERROR [src.node.docker_mananger] Max retries reached for container 2a38679fddf1. Exiting log stream.
2025-12-08 12:10:19.089 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:48164/health" -H "Content-Type: application/json" -d 'None'
2025-12-08 12:10:19.093 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-08 12:10:19.093 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-08 12:10:19.093 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:48164/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-08 12:10:19.095 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.200.211/tcp/48165/p2p/16Uiu2HAmTfZ3VPVvAUSbf7UdS4j3oXNn7vaY9heazKwuovQzNc93","/ip4/172.18.200.211/tcp/48166/ws/p2p/16Uiu2HAmTfZ3VPVvAUSbf7UdS4j3oXNn7vaY9heazKwuovQzNc93"],"enrUri":"enr:-L24QJ0hyCwPAdotKIWNwJeYk2yY2W1jPKT4iAyMwuVyqQpfbECR_JYlVYxlP5vYfppCDr5GOOmXPrH-lqEO6z9lRXMCgmlkgnY0gmlwhKwSyNOKbXVsdGlhZGRyc5YACASsEsjTBrwlAAoErBLI0wa8Jt0DgnJzhQADAQAAiXNlY3AyNTZrMaED3wRFJhvyHrOqbIo7ubPDxsXYmeFa7aWWsKynhP6pSzaDdGNwgrwlg3VkcIK8J4V3YWt1MgU"}'
2025-12-08 12:10:19.096 INFO [src.node.waku_node] REST service is ready !!
2025-12-08 12:10:19.096 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2025-12-08 12:10:19.102 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-08 12:10:19.102 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-08_12-10-17__5e91ccff-fdfc-4553-a659-5fc679c1238d__wakuorg_nwaku:latest.log
2025-12-08 12:10:19.102 DEBUG [src.node.waku_node] Starting Node...
2025-12-08 12:10:19.103 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-08 12:10:19.104 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-08 12:10:19.104 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.72.210
2025-12-08 12:10:19.104 DEBUG [src.node.docker_mananger] Generated ports ['60343', '60344', '60345', '60346', '60347']
2025-12-08 12:10:19.104 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-08 12:10:19.104 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-08 12:10:19.104 DEBUG [src.node.waku_node] Using volumes []
2025-12-08 12:10:19.105 DEBUG [src.node.docker_mananger] docker run -i -t -p 60343:60343 -p 60344:60344 -p 60345:60345 -p 60346:60346 -p 60347:60347 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=60345 --rest-port=60343 --tcp-port=60344 --discv5-udp-port=60346 --rest-address=0.0.0.0 --nat=extip:172.18.72.210 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=903ef45b23a8accab0bbafbd70ebe1f45b2a85fdaa2dac708cd37761a38ed42d --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=60347 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QJ0hyCwPAdotKIWNwJeYk2yY2W1jPKT4iAyMwuVyqQpfbECR_JYlVYxlP5vYfppCDr5GOOmXPrH-lqEO6z9lRXMCgmlkgnY0gmlwhKwSyNOKbXVsdGlhZGRyc5YACASsEsjTBrwlAAoErBLI0wa8Jt0DgnJzhQADAQAAiXNlY3AyNTZrMaED3wRFJhvyHrOqbIo7ubPDxsXYmeFa7aWWsKynhP6pSzaDdGNwgrwlg3VkcIK8J4V3YWt1MgU --filternode=/ip4/172.18.200.211/tcp/48165/p2p/16Uiu2HAmTfZ3VPVvAUSbf7UdS4j3oXNn7vaY9heazKwuovQzNc93
2025-12-08 12:10:19.260 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.72.210 waku 2e7bbd3f72ef24accfc218fb37476a9c7c233ee072b99f115d901d7eb0ec567d
2025-12-08 12:10:19.285 DEBUG [src.node.docker_mananger] Container started with ID 2e7bbd3f72ef. Setting up logs at ./log/docker/node2_2025-12-08_12-10-17__5e91ccff-fdfc-4553-a659-5fc679c1238d__wakuorg_nwaku:latest.log
2025-12-08 12:10:19.285 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 60343
2025-12-08 12:10:19.285 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-08 12:10:20.286 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:60343/health" -H "Content-Type: application/json" -d 'None'
2025-12-08 12:10:20.289 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-08 12:10:20.289 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-08 12:10:20.290 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:60343/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-08 12:10:20.292 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.72.210/tcp/60344/p2p/16Uiu2HAkxpgvvPkJJKbcX7qQfp1MkVr1rpRExqsJkZQuMnUdWhdL","/ip4/172.18.72.210/tcp/60345/ws/p2p/16Uiu2HAkxpgvvPkJJKbcX7qQfp1MkVr1rpRExqsJkZQuMnUdWhdL"],"enrUri":"enr:-L24QKSnbGNpVYftFhPW6uB71_8B2NL9UWRod6ltARomtOf-T4LvEVRKuBpkDw_ekW9erHj3Ip37qimg1f8AiIfdZ8ECgmlkgnY0gmlwhKwSSNKKbXVsdGlhZGRyc5YACASsEkjSBuu4AAoErBJI0gbrud0DgnJzhQADAQAAiXNlY3AyNTZrMaECMnh-fUliD9cqHQCI74YvrsmldVlLA3OSH4OGFn8xJ8ODdGNwguu4g3VkcILruoV3YWt1MgA"}'
2025-12-08 12:10:20.292 INFO [src.node.waku_node] REST service is ready !!
2025-12-08 12:10:20.292 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:60343/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.200.211/tcp/48165/p2p/16Uiu2HAmTfZ3VPVvAUSbf7UdS4j3oXNn7vaY9heazKwuovQzNc93"]'
2025-12-08 12:10:20.319 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 12:10:20.320 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2025-12-08 12:10:20.320 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:48164/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-08 12:10:20.331 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 12:10:20.333 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:60343/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "e476e3c6-59d3-4fa5-b235-190c68e2fa48", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2025-12-08 12:10:20.342 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"e476e3c6-59d3-4fa5-b235-190c68e2fa48","statusDesc":"OK"}'
2025-12-08 12:10:20.345 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:48164/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d '{"payload": "RmlsdGVyIHdvcmtzISE=", "contentTopic": "/test/1/waku-filter/proto", "timestamp": '$(date +%s%N)', "version": 10}'
2025-12-08 12:10:20.351 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 12:10:20.351 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-08 12:10:20.452 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2025-12-08 12:10:20.452 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:60343/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-08 12:10:20.455 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"RmlsdGVyIHdvcmtzISE=","contentTopic":"/test/1/waku-filter/proto","version":10,"timestamp":1765195820344853703,"ephemeral":false}]'
2025-12-08 12:10:20.458 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-08 12:10:20.459 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-08 12:10:20.459 DEBUG [src.node.waku_node] Stopping container with id 940e3b595ed2
2025-12-08 12:10:20.956 DEBUG [src.node.waku_node] Container stopped.
2025-12-08 12:10:20.957 DEBUG [src.node.waku_node] Stopping container with id 2e7bbd3f72ef
2025-12-08 12:10:21.420 DEBUG [src.node.waku_node] Container stopped.
2025-12-08 12:10:21.422 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-08 12:10:21.427 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-08 12:10:21.432 DEBUG [src.node.docker_mananger] No errors found in the waku logs.