85 lines
15 KiB
Plaintext

2025-12-17 04:27:54.249 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-17 04:27:54.249 DEBUG [tests.conftest] Running test: test_message_published_on_different_pubsub_topic_is_not_retrieved with id: 2025-12-17_04-27-54__294a0c34-26cf-427b-8257-b6ca5ba4e344
2025-12-17 04:27:54.250 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-17 04:27:54.250 DEBUG [src.steps.relay] Running fixture setup: relay_setup
2025-12-17 04:27:54.250 DEBUG [src.steps.relay] Running fixture setup: setup_main_relay_nodes
2025-12-17 04:27:54.256 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-17 04:27:54.256 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-17_04-27-54__294a0c34-26cf-427b-8257-b6ca5ba4e344__wakuorg_nwaku:latest.log
2025-12-17 04:27:54.257 DEBUG [src.node.waku_node] Starting Node...
2025-12-17 04:27:54.257 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-17 04:27:54.258 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-17 04:27:54.258 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.47.133
2025-12-17 04:27:54.258 DEBUG [src.node.docker_mananger] Generated ports ['25001', '25002', '25003', '25004', '25005']
2025-12-17 04:27:54.258 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-17 04:27:54.258 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-17 04:27:54.259 DEBUG [src.node.waku_node] Using volumes []
2025-12-17 04:27:54.259 DEBUG [src.node.docker_mananger] docker run -i -t -p 25001:25001 -p 25002:25002 -p 25003:25003 -p 25004:25004 -p 25005:25005 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=25003 --rest-port=25001 --tcp-port=25002 --discv5-udp-port=25004 --rest-address=0.0.0.0 --nat=extip:172.18.47.133 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=23a1a9bd2cecc9bc6edfaceaffb6be51d1c27e7d133ce5690dfd5e5755cef65e --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=25005 --metrics-logging=true --relay=true
2025-12-17 04:27:54.443 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.47.133 waku 0cd30dfb0eae6a77f06834581501ad4abe4a86601edf40bc87431147bddc16e1
2025-12-17 04:27:54.479 DEBUG [src.node.docker_mananger] Container started with ID 0cd30dfb0eae. Setting up logs at ./log/docker/node1_2025-12-17_04-27-54__294a0c34-26cf-427b-8257-b6ca5ba4e344__wakuorg_nwaku:latest.log
2025-12-17 04:27:54.479 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 25001
2025-12-17 04:27:54.480 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-17 04:27:54.503 ERROR [src.node.docker_mananger] Max retries reached for container ffead200e872. Exiting log stream.
2025-12-17 04:27:55.050 ERROR [src.node.docker_mananger] Max retries reached for container fab081920502. Exiting log stream.
2025-12-17 04:27:55.481 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:25001/health" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:55.484 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_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":"NOT_READY","desc":"No Filter service peer available yet"}]}'
2025-12-17 04:27:55.484 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-17 04:27:55.484 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:25001/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:55.487 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.47.133/tcp/25002/p2p/16Uiu2HAmVrFpe7yv7utEQddbdKvNPUMrQLEGA1o91oFvUAj1EXuE","/ip4/172.18.47.133/tcp/25003/ws/p2p/16Uiu2HAmVrFpe7yv7utEQddbdKvNPUMrQLEGA1o91oFvUAj1EXuE"],"enrUri":"enr:-L24QDoUFbbb_XxjwCE72nh9WsQYpaKreYaIgQQ5SaDXUE1EBQFagss2Vy4TVInKb2HvUnNbBJDJxbSEklJxMKZvlQUCgmlkgnY0gmlwhKwSL4WKbXVsdGlhZGRyc5YACASsEi-FBmGqAAoErBIvhQZhq90DgnJzhQADAQAAiXNlY3AyNTZrMaED_3mPdr1pejB7D_-_wqrG6rP38Sx_Y03MXpiSgqh8oxWDdGNwgmGqg3VkcIJhrIV3YWt1MgE"}'
2025-12-17 04:27:55.487 INFO [src.node.waku_node] REST service is ready !!
2025-12-17 04:27:55.493 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-17 04:27:55.493 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-17_04-27-54__294a0c34-26cf-427b-8257-b6ca5ba4e344__wakuorg_nwaku:latest.log
2025-12-17 04:27:55.493 DEBUG [src.node.waku_node] Starting Node...
2025-12-17 04:27:55.494 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-17 04:27:55.495 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-17 04:27:55.495 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.12.155
2025-12-17 04:27:55.495 DEBUG [src.node.docker_mananger] Generated ports ['49212', '49213', '49214', '49215', '49216']
2025-12-17 04:27:55.495 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-17 04:27:55.495 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-17 04:27:55.495 DEBUG [src.node.waku_node] Using volumes []
2025-12-17 04:27:55.496 DEBUG [src.node.docker_mananger] docker run -i -t -p 49212:49212 -p 49213:49213 -p 49214:49214 -p 49215:49215 -p 49216:49216 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=49214 --rest-port=49212 --tcp-port=49213 --discv5-udp-port=49215 --rest-address=0.0.0.0 --nat=extip:172.18.12.155 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=a8fe5feee5a82be74d85a7beade5e3addfda5c0adfb75b6bc8414eeacff3b843 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=49216 --metrics-logging=true --relay=true --discv5-bootstrap-node=enr:-L24QDoUFbbb_XxjwCE72nh9WsQYpaKreYaIgQQ5SaDXUE1EBQFagss2Vy4TVInKb2HvUnNbBJDJxbSEklJxMKZvlQUCgmlkgnY0gmlwhKwSL4WKbXVsdGlhZGRyc5YACASsEi-FBmGqAAoErBIvhQZhq90DgnJzhQADAQAAiXNlY3AyNTZrMaED_3mPdr1pejB7D_-_wqrG6rP38Sx_Y03MXpiSgqh8oxWDdGNwgmGqg3VkcIJhrIV3YWt1MgE
2025-12-17 04:27:55.673 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.12.155 waku 1bd2b474fb07dba10d92635a4cf748829030650a95e02cc8e5e0a18a86695d3f
2025-12-17 04:27:55.704 DEBUG [src.node.docker_mananger] Container started with ID 1bd2b474fb07. Setting up logs at ./log/docker/node2_2025-12-17_04-27-54__294a0c34-26cf-427b-8257-b6ca5ba4e344__wakuorg_nwaku:latest.log
2025-12-17 04:27:55.705 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 49212
2025-12-17 04:27:55.705 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-17 04:27:56.706 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:49212/health" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:56.715 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_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":"NOT_READY","desc":"No Filter service peer available yet"}]}'
2025-12-17 04:27:56.717 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-17 04:27:56.717 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:49212/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:56.721 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.12.155/tcp/49213/p2p/16Uiu2HAkuuPBrgPVHBQY1nCKMoAxtwPcSpCjyjFqQqPeZVNc8QLW","/ip4/172.18.12.155/tcp/49214/ws/p2p/16Uiu2HAkuuPBrgPVHBQY1nCKMoAxtwPcSpCjyjFqQqPeZVNc8QLW"],"enrUri":"enr:-L24QHX_vO-MgpvB2JjFmylcEIn4fhCVhlvRDOoRycT_mI3PY9y8qPpkqSD-SXvfJ7EfiQjuvwXebEkxisUO-jaWZCMCgmlkgnY0gmlwhKwSDJuKbXVsdGlhZGRyc5YACASsEgybBsA9AAoErBIMmwbAPt0DgnJzhQADAQAAiXNlY3AyNTZrMaECBxlGn86lJsfEHEIpb_HD7f4AZspinC0hOYcZsov58Q-DdGNwgsA9g3VkcILAP4V3YWt1MgE"}'
2025-12-17 04:27:56.722 INFO [src.node.waku_node] REST service is ready !!
2025-12-17 04:27:56.722 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:49212/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.47.133/tcp/25002/p2p/16Uiu2HAmVrFpe7yv7utEQddbdKvNPUMrQLEGA1o91oFvUAj1EXuE"]'
2025-12-17 04:27:56.728 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.729 DEBUG [src.steps.relay] Running fixture setup: subscribe_main_relay_nodes
2025-12-17 04:27:56.729 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:25001/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-17 04:27:56.732 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.733 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:49212/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-17 04:27:56.738 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.739 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:25001/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d '{"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": '$(date +%s%N)'}'
2025-12-17 04:27:56.744 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.744 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-17 04:27:56.845 DEBUG [src.steps.relay] Checking that peer NODE_1:wakuorg/nwaku:latest can find the published message
2025-12-17 04:27:56.845 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:25001/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:56.847 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","version":0,"timestamp":1765945676738864640,"ephemeral":false,"proof":""}]'
2025-12-17 04:27:56.849 DEBUG [src.steps.relay] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2025-12-17 04:27:56.849 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:49212/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:56.851 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"UmVsYXkgd29ya3MhIQ==","contentTopic":"/test/1/waku-relay/proto","version":0,"timestamp":1765945676738864640,"ephemeral":false,"proof":""}]'
2025-12-17 04:27:56.852 INFO [src.steps.relay] WARM UP successful!!
2025-12-17 04:27:56.853 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:25001/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0", "/waku/2/rs/3/1", "/waku/2/rs/3/9", "/waku/2/rs/3/25", "/waku/2/rs/3/1000"]'
2025-12-17 04:27:56.858 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.859 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:49212/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0", "/waku/2/rs/3/1", "/waku/2/rs/3/9", "/waku/2/rs/3/25", "/waku/2/rs/3/1000"]'
2025-12-17 04:27:56.866 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.866 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:25001/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "UmVsYXkgd29ya3MhIQ==", "contentTopic": "/test/1/waku-relay/proto", "timestamp": '$(date +%s%N)'}'
2025-12-17 04:27:56.874 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-17 04:27:56.874 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-17 04:27:56.975 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:49212/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F1" -H "Content-Type: application/json" -d 'None'
2025-12-17 04:27:56.977 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[]'
2025-12-17 04:27:56.979 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-17 04:27:56.981 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-17 04:27:56.981 DEBUG [src.node.waku_node] Stopping container with id 0cd30dfb0eae
2025-12-17 04:27:57.504 DEBUG [src.node.waku_node] Container stopped.
2025-12-17 04:27:57.506 DEBUG [src.node.waku_node] Stopping container with id 1bd2b474fb07
2025-12-17 04:27:58.061 DEBUG [src.node.waku_node] Container stopped.
2025-12-17 04:27:58.062 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-17 04:27:58.075 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-17 04:27:58.081 DEBUG [src.node.docker_mananger] No errors found in the waku logs.