93 lines
15 KiB
Plaintext

2025-12-14 04:28:45.465 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-14 04:28:45.465 DEBUG [tests.conftest] Running test: test_time_filter_matches_no_message with id: 2025-12-14_04-28-45__52b7c7b8-2d74-481d-8e07-9f0e4f4f5f37
2025-12-14 04:28:45.466 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-14 04:28:45.466 DEBUG [src.steps.store] Running fixture setup: store_setup
2025-12-14 04:28:45.466 DEBUG [src.steps.store] Running fixture setup: node_setup
2025-12-14 04:28:45.473 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-14 04:28:45.473 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/publishing_node1_2025-12-14_04-28-45__52b7c7b8-2d74-481d-8e07-9f0e4f4f5f37__wakuorg_nwaku:latest.log
2025-12-14 04:28:45.473 DEBUG [src.node.waku_node] Starting Node...
2025-12-14 04:28:45.473 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-14 04:28:45.474 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-14 04:28:45.475 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.75.12
2025-12-14 04:28:45.475 DEBUG [src.node.docker_mananger] Generated ports ['56531', '56532', '56533', '56534', '56535']
2025-12-14 04:28:45.475 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-14 04:28:45.475 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-14 04:28:45.475 DEBUG [src.node.waku_node] Using volumes []
2025-12-14 04:28:45.475 DEBUG [src.node.docker_mananger] docker run -i -t -p 56531:56531 -p 56532:56532 -p 56533:56533 -p 56534:56534 -p 56535:56535 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=56533 --rest-port=56531 --tcp-port=56532 --discv5-udp-port=56534 --rest-address=0.0.0.0 --nat=extip:172.18.75.12 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=ee54f4fabaa9b7edc5acdcf3e26a2de1cc0de159e6cac90fdb5971146a34fccf --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=56535 --metrics-logging=true --store=true --relay=true
2025-12-14 04:28:45.660 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.75.12 waku 5b1c43c7bf8cca452f7f80a91a2c357c222a6a76ca38759cdc0332fee062266b
2025-12-14 04:28:45.691 DEBUG [src.node.docker_mananger] Container started with ID 5b1c43c7bf8c. Setting up logs at ./log/docker/publishing_node1_2025-12-14_04-28-45__52b7c7b8-2d74-481d-8e07-9f0e4f4f5f37__wakuorg_nwaku:latest.log
2025-12-14 04:28:45.693 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 56531
2025-12-14 04:28:45.693 ERROR [src.node.docker_mananger] Max retries reached for container 0c012bb595ec. Exiting log stream.
2025-12-14 04:28:45.696 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-14 04:28:46.259 ERROR [src.node.docker_mananger] Max retries reached for container 7eab65747edd. Exiting log stream.
2025-12-14 04:28:46.697 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:56531/health" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:46.700 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":"READY"},{"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":"READY"},{"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-14 04:28:46.700 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-14 04:28:46.700 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:56531/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:46.703 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.75.12/tcp/56532/p2p/16Uiu2HAmV5MEC6NUaFZK4ynv5po4CFLpZNBU6DL11QMnqwuYbsfB","/ip4/172.18.75.12/tcp/56533/ws/p2p/16Uiu2HAmV5MEC6NUaFZK4ynv5po4CFLpZNBU6DL11QMnqwuYbsfB"],"enrUri":"enr:-L24QLWz1FDGVHGGbBd_JTiVSfn7LcT0y5A0eLtOLjI_dvUOWvc9Mu1tXM2pNTpyLtN54FNItbAJS0fQiOfSeIYCK28CgmlkgnY0gmlwhKwSSwyKbXVsdGlhZGRyc5YACASsEksMBtzUAAoErBJLDAbc1d0DgnJzhQADAQAAiXNlY3AyNTZrMaED8_iJYYLdtJprrSlQxxIThNGXTPUG8hEJabiQQJg8pu6DdGNwgtzUg3VkcILc1oV3YWt1MgM"}'
2025-12-14 04:28:46.703 INFO [src.node.waku_node] REST service is ready !!
2025-12-14 04:28:46.710 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-14 04:28:46.710 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/store_node1_2025-12-14_04-28-45__52b7c7b8-2d74-481d-8e07-9f0e4f4f5f37__wakuorg_nwaku:latest.log
2025-12-14 04:28:46.710 DEBUG [src.node.waku_node] Starting Node...
2025-12-14 04:28:46.710 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-14 04:28:46.712 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-14 04:28:46.712 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.217.134
2025-12-14 04:28:46.712 DEBUG [src.node.docker_mananger] Generated ports ['10447', '10448', '10449', '10450', '10451']
2025-12-14 04:28:46.712 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-14 04:28:46.712 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-14 04:28:46.712 DEBUG [src.node.waku_node] Using volumes []
2025-12-14 04:28:46.712 DEBUG [src.node.docker_mananger] docker run -i -t -p 10447:10447 -p 10448:10448 -p 10449:10449 -p 10450:10450 -p 10451:10451 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=10449 --rest-port=10447 --tcp-port=10448 --discv5-udp-port=10450 --rest-address=0.0.0.0 --nat=extip:172.18.217.134 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=8dac0d2c9ebebd1fccb3357cbce0aaaaabef4f3e826556dda68d7f09d8d8ebef --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=10451 --metrics-logging=true --discv5-bootstrap-node=enr:-L24QLWz1FDGVHGGbBd_JTiVSfn7LcT0y5A0eLtOLjI_dvUOWvc9Mu1tXM2pNTpyLtN54FNItbAJS0fQiOfSeIYCK28CgmlkgnY0gmlwhKwSSwyKbXVsdGlhZGRyc5YACASsEksMBtzUAAoErBJLDAbc1d0DgnJzhQADAQAAiXNlY3AyNTZrMaED8_iJYYLdtJprrSlQxxIThNGXTPUG8hEJabiQQJg8pu6DdGNwgtzUg3VkcILc1oV3YWt1MgM --storenode=/ip4/172.18.75.12/tcp/56532/p2p/16Uiu2HAmV5MEC6NUaFZK4ynv5po4CFLpZNBU6DL11QMnqwuYbsfB --store=true --relay=true
2025-12-14 04:28:46.897 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.217.134 waku 50ae696f8bf971d1b4bab336625a54cfc4e86bd61f4b44a9a99a9636b04bec48
2025-12-14 04:28:46.929 DEBUG [src.node.docker_mananger] Container started with ID 50ae696f8bf9. Setting up logs at ./log/docker/store_node1_2025-12-14_04-28-45__52b7c7b8-2d74-481d-8e07-9f0e4f4f5f37__wakuorg_nwaku:latest.log
2025-12-14 04:28:46.930 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 10447
2025-12-14 04:28:46.930 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-14 04:28:47.930 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:10447/health" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:47.935 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","protocolsHealth":[{"Relay":"READY"},{"Rln Relay":"NOT_MOUNTED"},{"Lightpush":"NOT_MOUNTED"},{"Legacy Lightpush":"NOT_MOUNTED"},{"Filter":"NOT_MOUNTED"},{"Store":"READY"},{"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":"READY"},{"Legacy Store Client":"READY"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"}]}'
2025-12-14 04:28:47.935 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-14 04:28:47.935 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:10447/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:47.937 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.217.134/tcp/10448/p2p/16Uiu2HAkua3hGXHVihAGgz9U2oTA7F1q7ThS2YCvep9msFN3L2qM","/ip4/172.18.217.134/tcp/10449/ws/p2p/16Uiu2HAkua3hGXHVihAGgz9U2oTA7F1q7ThS2YCvep9msFN3L2qM"],"enrUri":"enr:-L24QCNrWvYWb1GtxJXFkU2eMK03QcVgjslK0nsYpN0B5sKLMu_vrJmblw3qnNpqdr5bMvTPhFsuzo32FBKB3Ju667cCgmlkgnY0gmlwhKwS2YaKbXVsdGlhZGRyc5YACASsEtmGBijQAAoErBLZhgYo0d0DgnJzhQADAQAAiXNlY3AyNTZrMaECAiUzJesp5kYICvmI98tA2B8dAIHtSDH_yQifJu-9ndCDdGNwgijQg3VkcIIo0oV3YWt1MgM"}'
2025-12-14 04:28:47.938 INFO [src.node.waku_node] REST service is ready !!
2025-12-14 04:28:47.938 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:10447/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.75.12/tcp/56532/p2p/16Uiu2HAmV5MEC6NUaFZK4ynv5po4CFLpZNBU6DL11QMnqwuYbsfB"]'
2025-12-14 04:28:47.940 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:47.941 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2025-12-14 04:28:47.943 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:47.943 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:10447/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2025-12-14 04:28:47.946 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:47.947 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:47.947 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:47.952 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:47.952 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:48.153 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:48.153 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:48.158 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:48.158 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:48.359 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:48.360 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:48.365 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:48.366 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:48.567 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:48.567 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:48.572 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:48.573 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:48.773 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:48.774 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:48.779 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:48.779 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:48.980 DEBUG [src.steps.store] Relaying message
2025-12-14 04:28:48.981 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:56531/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-14 04:28:48.986 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-14 04:28:48.986 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-14 04:28:49.187 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:56531/store/v3/messages?pubsubTopic=%2Fwaku%2F2%2Frs%2F3%2F0&startTime=1765686524946783072&endTime=1765686524946882972&pageSize=20&ascending=true" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:49.190 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"","statusCode":200,"statusDesc":"OK","messages":[]}'
2025-12-14 04:28:49.191 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:10447/store/v3/messages?pubsubTopic=%2Fwaku%2F2%2Frs%2F3%2F0&startTime=1765686524946783072&endTime=1765686524946882972&pageSize=20&ascending=true" -H "Content-Type: application/json" -d 'None'
2025-12-14 04:28:49.194 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"","statusCode":200,"statusDesc":"OK","messages":[]}'
2025-12-14 04:28:49.195 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-14 04:28:49.197 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-14 04:28:49.197 DEBUG [src.node.waku_node] Stopping container with id 5b1c43c7bf8c
2025-12-14 04:28:49.782 DEBUG [src.node.waku_node] Container stopped.
2025-12-14 04:28:49.782 DEBUG [src.node.waku_node] Stopping container with id 50ae696f8bf9
2025-12-14 04:28:50.337 DEBUG [src.node.waku_node] Container stopped.
2025-12-14 04:28:50.338 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-14 04:28:50.346 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-14 04:28:50.353 DEBUG [src.node.docker_mananger] No errors found in the waku logs.