74 lines
13 KiB
Plaintext

2025-12-08 08:56:43.526 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-08 08:56:43.526 DEBUG [tests.conftest] Running test: test_filter_update_subscription_refresh_existing with id: 2025-12-08_08-56-43__19264e8c-c795-49bf-971b-887fd1fd6153
2025-12-08 08:56:43.527 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-08 08:56:43.527 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2025-12-08 08:56:43.527 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2025-12-08 08:56:43.534 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-08 08:56:43.534 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-08_08-56-43__19264e8c-c795-49bf-971b-887fd1fd6153__wakuorg_nwaku:latest.log
2025-12-08 08:56:43.534 DEBUG [src.node.waku_node] Starting Node...
2025-12-08 08:56:43.534 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-08 08:56:43.535 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-08 08:56:43.536 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.203.177
2025-12-08 08:56:43.536 DEBUG [src.node.docker_mananger] Generated ports ['57290', '57291', '57292', '57293', '57294']
2025-12-08 08:56:43.536 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-08 08:56:43.536 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-08 08:56:43.536 DEBUG [src.node.waku_node] Using volumes []
2025-12-08 08:56:43.536 DEBUG [src.node.docker_mananger] docker run -i -t -p 57290:57290 -p 57291:57291 -p 57292:57292 -p 57293:57293 -p 57294:57294 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=57292 --rest-port=57290 --tcp-port=57291 --discv5-udp-port=57293 --rest-address=0.0.0.0 --nat=extip:172.18.203.177 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=a9cd0f08dd2ddcfcca14a4fb515cb2d3a63da8dac2b9d9d43aeb1aceb7dfeffb --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=57294 --metrics-logging=true --relay=true --filter=true
2025-12-08 08:56:43.715 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.203.177 waku b6992475f7b21e4947dc6442ad085c5e5ae46029ad59b21c707f94836853a6f3
2025-12-08 08:56:43.747 DEBUG [src.node.docker_mananger] Container started with ID b6992475f7b2. Setting up logs at ./log/docker/node1_2025-12-08_08-56-43__19264e8c-c795-49bf-971b-887fd1fd6153__wakuorg_nwaku:latest.log
2025-12-08 08:56:43.747 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 57290
2025-12-08 08:56:43.747 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-08 08:56:43.799 ERROR [src.node.docker_mananger] Max retries reached for container 5e1bd2bcdf8c. Exiting log stream.
2025-12-08 08:56:44.333 ERROR [src.node.docker_mananger] Max retries reached for container a48b9ef82b8e. Exiting log stream.
2025-12-08 08:56:44.748 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:57290/health" -H "Content-Type: application/json" -d 'None'
2025-12-08 08:56:44.751 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 08:56:44.751 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-08 08:56:44.751 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:57290/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-08 08:56:44.753 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.203.177/tcp/57291/p2p/16Uiu2HAmJgQVhpojoQv7FsBKJzAoby52z2yYfUqELonRzQ1tUbP4","/ip4/172.18.203.177/tcp/57292/ws/p2p/16Uiu2HAmJgQVhpojoQv7FsBKJzAoby52z2yYfUqELonRzQ1tUbP4"],"enrUri":"enr:-L24QBXQY8bEb4c2nolI2JIVLwL3j04nWqIivO3owh78eUr2LLHIOojBNIqFEmpTlm6YPAyBdTOfZ44Gyfb_RuyVKnUCgmlkgnY0gmlwhKwSy7GKbXVsdGlhZGRyc5YACASsEsuxBt_LAAoErBLLsQbfzN0DgnJzhQADAQAAiXNlY3AyNTZrMaEDWYMA2Ds6bbtCfAPxV2WaVkg5_1kw8CqnJPVX6JEIkG-DdGNwgt_Lg3VkcILfzYV3YWt1MgU"}'
2025-12-08 08:56:44.753 INFO [src.node.waku_node] REST service is ready !!
2025-12-08 08:56:44.754 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2025-12-08 08:56:44.760 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-08 08:56:44.760 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-08_08-56-43__19264e8c-c795-49bf-971b-887fd1fd6153__wakuorg_nwaku:latest.log
2025-12-08 08:56:44.760 DEBUG [src.node.waku_node] Starting Node...
2025-12-08 08:56:44.761 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-08 08:56:44.762 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-08 08:56:44.762 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.77.0
2025-12-08 08:56:44.762 DEBUG [src.node.docker_mananger] Generated ports ['11024', '11025', '11026', '11027', '11028']
2025-12-08 08:56:44.762 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-08 08:56:44.763 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-08 08:56:44.763 DEBUG [src.node.waku_node] Using volumes []
2025-12-08 08:56:44.763 DEBUG [src.node.docker_mananger] docker run -i -t -p 11024:11024 -p 11025:11025 -p 11026:11026 -p 11027:11027 -p 11028:11028 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=11026 --rest-port=11024 --tcp-port=11025 --discv5-udp-port=11027 --rest-address=0.0.0.0 --nat=extip:172.18.77.0 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=bd2f6cae8f2484b30ebb25f849fcf55f5ded419b32e3c2cfcdee4d3c50a15eb6 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=11028 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QBXQY8bEb4c2nolI2JIVLwL3j04nWqIivO3owh78eUr2LLHIOojBNIqFEmpTlm6YPAyBdTOfZ44Gyfb_RuyVKnUCgmlkgnY0gmlwhKwSy7GKbXVsdGlhZGRyc5YACASsEsuxBt_LAAoErBLLsQbfzN0DgnJzhQADAQAAiXNlY3AyNTZrMaEDWYMA2Ds6bbtCfAPxV2WaVkg5_1kw8CqnJPVX6JEIkG-DdGNwgt_Lg3VkcILfzYV3YWt1MgU --filternode=/ip4/172.18.203.177/tcp/57291/p2p/16Uiu2HAmJgQVhpojoQv7FsBKJzAoby52z2yYfUqELonRzQ1tUbP4
2025-12-08 08:56:44.955 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.77.0 waku 149fca9cee71244a9c30cfb677ac2c385dc81de6954d1cadb0f25cb248f7c659
2025-12-08 08:56:44.985 DEBUG [src.node.docker_mananger] Container started with ID 149fca9cee71. Setting up logs at ./log/docker/node2_2025-12-08_08-56-43__19264e8c-c795-49bf-971b-887fd1fd6153__wakuorg_nwaku:latest.log
2025-12-08 08:56:44.986 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 11024
2025-12-08 08:56:44.986 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-08 08:56:45.986 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:11024/health" -H "Content-Type: application/json" -d 'None'
2025-12-08 08:56:45.990 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 08:56:45.990 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-08 08:56:45.991 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:11024/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-08 08:56:45.993 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.77.0/tcp/11025/p2p/16Uiu2HAmUhiVt5RjhR7RkfNWz6Nih7yp8GZzQA4rvGfH3WBaop7q","/ip4/172.18.77.0/tcp/11026/ws/p2p/16Uiu2HAmUhiVt5RjhR7RkfNWz6Nih7yp8GZzQA4rvGfH3WBaop7q"],"enrUri":"enr:-L24QL2evBAK2O_SGqPNMYOMfo6f-6Umsy_8Y3aY2kDG-tZlGydu8qVZ3epO8d_XeIrGmgLysf7KawNKkQJ7Ne431pQCgmlkgnY0gmlwhKwSTQCKbXVsdGlhZGRyc5YACASsEk0ABisRAAoErBJNAAYrEt0DgnJzhQADAQAAiXNlY3AyNTZrMaED7m3POkRINGdUPAiPFrl-r959dsH_tiLw5P2qnTrlL-iDdGNwgisRg3VkcIIrE4V3YWt1MgA"}'
2025-12-08 08:56:45.993 INFO [src.node.waku_node] REST service is ready !!
2025-12-08 08:56:45.994 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:11024/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.203.177/tcp/57291/p2p/16Uiu2HAmJgQVhpojoQv7FsBKJzAoby52z2yYfUqELonRzQ1tUbP4"]'
2025-12-08 08:56:46.026 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 08:56:46.029 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:57290/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-08 08:56:46.040 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 08:56:46.041 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:11024/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "69718af4-8206-4ca1-83fb-f61a1952cdae", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2025-12-08 08:56:46.052 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"69718af4-8206-4ca1-83fb-f61a1952cdae","statusDesc":"OK"}'
2025-12-08 08:56:46.053 INFO [src.node.api_clients.base_client] curl -v -X PUT "http://127.0.0.1:11024/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-08 08:56:46.061 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"1","statusDesc":"OK"}'
2025-12-08 08:56:46.062 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:57290/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)'}'
2025-12-08 08:56:46.068 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-08 08:56:46.069 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-08 08:56:46.169 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2025-12-08 08:56:46.169 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:11024/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-08 08:56:46.172 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":1765184206061945640,"ephemeral":false}]'
2025-12-08 08:56:46.175 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-08 08:56:46.176 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-08 08:56:46.176 DEBUG [src.node.waku_node] Stopping container with id b6992475f7b2
2025-12-08 08:56:46.704 DEBUG [src.node.waku_node] Container stopped.
2025-12-08 08:56:46.705 DEBUG [src.node.waku_node] Stopping container with id 149fca9cee71
2025-12-08 08:56:47.209 DEBUG [src.node.waku_node] Container stopped.
2025-12-08 08:56:47.212 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-08 08:56:47.218 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-08 08:56:47.225 DEBUG [src.node.docker_mananger] No errors found in the waku logs.