93 lines
16 KiB
Plaintext

2025-12-21 04:33:51.366 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-21 04:33:51.367 DEBUG [tests.conftest] Running test: test_time_filter_matches_multiple_messages with id: 2025-12-21_04-33-51__bc0fdb19-566c-44e5-bdba-3215f8e9123d
2025-12-21 04:33:51.367 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-21 04:33:51.367 DEBUG [src.steps.store] Running fixture setup: store_setup
2025-12-21 04:33:51.367 DEBUG [src.steps.store] Running fixture setup: node_setup
2025-12-21 04:33:51.373 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-21 04:33:51.373 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/publishing_node1_2025-12-21_04-33-51__bc0fdb19-566c-44e5-bdba-3215f8e9123d__wakuorg_nwaku:latest.log
2025-12-21 04:33:51.374 DEBUG [src.node.waku_node] Starting Node...
2025-12-21 04:33:51.374 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-21 04:33:51.375 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-21 04:33:51.375 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.64.28
2025-12-21 04:33:51.375 DEBUG [src.node.docker_mananger] Generated ports ['5854', '5855', '5856', '5857', '5858']
2025-12-21 04:33:51.376 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-21 04:33:51.376 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-21 04:33:51.376 DEBUG [src.node.waku_node] Using volumes []
2025-12-21 04:33:51.376 DEBUG [src.node.docker_mananger] docker run -i -t -p 5854:5854 -p 5855:5855 -p 5856:5856 -p 5857:5857 -p 5858:5858 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=5856 --rest-port=5854 --tcp-port=5855 --discv5-udp-port=5857 --rest-address=0.0.0.0 --nat=extip:172.18.64.28 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=d84b63fecec8a9b0e8f0df5c7004d08db7cad42a1d55f3ffc47deeab4b9fcaff --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=5858 --metrics-logging=true --store=true --relay=true
2025-12-21 04:33:51.537 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.64.28 waku cfe17466d4e4840cb044eb853d8ef2095df6c045277bf4ed23b1472758c64977
2025-12-21 04:33:51.568 DEBUG [src.node.docker_mananger] Container started with ID cfe17466d4e4. Setting up logs at ./log/docker/publishing_node1_2025-12-21_04-33-51__bc0fdb19-566c-44e5-bdba-3215f8e9123d__wakuorg_nwaku:latest.log
2025-12-21 04:33:51.568 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 5854
2025-12-21 04:33:51.568 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-21 04:33:51.658 ERROR [src.node.docker_mananger] Max retries reached for container 23cbe5ed24e4. Exiting log stream.
2025-12-21 04:33:52.174 ERROR [src.node.docker_mananger] Max retries reached for container 7b17742da2a7. Exiting log stream.
2025-12-21 04:33:52.569 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:5854/health" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:52.572 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-21 04:33:52.572 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-21 04:33:52.572 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:5854/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:52.574 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.64.28/tcp/5855/p2p/16Uiu2HAm38RdgCffC1LXiCWnYfHmABrwb2tXmS1JhnxsoJ4a8a4b","/ip4/172.18.64.28/tcp/5856/ws/p2p/16Uiu2HAm38RdgCffC1LXiCWnYfHmABrwb2tXmS1JhnxsoJ4a8a4b"],"enrUri":"enr:-L24QJahrvFlb5l-oUmB94PrJVoTgX9l1tLcAJPQV7tjE-NXbqkA98lP0WIG3mL9PxmRBDi_Gj4mzZ-8Ptdev55EVOsCgmlkgnY0gmlwhKwSQByKbXVsdGlhZGRyc5YACASsEkAcBhbfAAoErBJAHAYW4N0DgnJzhQADAQAAiXNlY3AyNTZrMaECcnJmTjYlUNfeWF5MgmZvGSIoHW7MDWl98MP9riSrsryDdGNwghbfg3VkcIIW4YV3YWt1MgM"}'
2025-12-21 04:33:52.575 INFO [src.node.waku_node] REST service is ready !!
2025-12-21 04:33:52.581 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-21 04:33:52.582 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/store_node1_2025-12-21_04-33-51__bc0fdb19-566c-44e5-bdba-3215f8e9123d__wakuorg_nwaku:latest.log
2025-12-21 04:33:52.582 DEBUG [src.node.waku_node] Starting Node...
2025-12-21 04:33:52.582 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-21 04:33:52.583 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-21 04:33:52.583 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.135.54
2025-12-21 04:33:52.583 DEBUG [src.node.docker_mananger] Generated ports ['14979', '14980', '14981', '14982', '14983']
2025-12-21 04:33:52.583 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-21 04:33:52.584 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-21 04:33:52.584 DEBUG [src.node.waku_node] Using volumes []
2025-12-21 04:33:52.584 DEBUG [src.node.docker_mananger] docker run -i -t -p 14979:14979 -p 14980:14980 -p 14981:14981 -p 14982:14982 -p 14983:14983 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=14981 --rest-port=14979 --tcp-port=14980 --discv5-udp-port=14982 --rest-address=0.0.0.0 --nat=extip:172.18.135.54 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=bee49479ddf61e4a14556bc12a31f1af6faae11a1aa4ac9edafdc586e168d3ed --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=14983 --metrics-logging=true --discv5-bootstrap-node=enr:-L24QJahrvFlb5l-oUmB94PrJVoTgX9l1tLcAJPQV7tjE-NXbqkA98lP0WIG3mL9PxmRBDi_Gj4mzZ-8Ptdev55EVOsCgmlkgnY0gmlwhKwSQByKbXVsdGlhZGRyc5YACASsEkAcBhbfAAoErBJAHAYW4N0DgnJzhQADAQAAiXNlY3AyNTZrMaECcnJmTjYlUNfeWF5MgmZvGSIoHW7MDWl98MP9riSrsryDdGNwghbfg3VkcIIW4YV3YWt1MgM --storenode=/ip4/172.18.64.28/tcp/5855/p2p/16Uiu2HAm38RdgCffC1LXiCWnYfHmABrwb2tXmS1JhnxsoJ4a8a4b --store=true --relay=true
2025-12-21 04:33:52.734 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.135.54 waku 648e2f759b1d5eaca02c4648314b9306b4dba96c95350cf93d7afbfa45267a51
2025-12-21 04:33:52.759 DEBUG [src.node.docker_mananger] Container started with ID 648e2f759b1d. Setting up logs at ./log/docker/store_node1_2025-12-21_04-33-51__bc0fdb19-566c-44e5-bdba-3215f8e9123d__wakuorg_nwaku:latest.log
2025-12-21 04:33:52.760 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 14979
2025-12-21 04:33:52.761 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-21 04:33:53.761 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:14979/health" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:53.765 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-21 04:33:53.765 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-21 04:33:53.765 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:14979/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:53.768 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.135.54/tcp/14980/p2p/16Uiu2HAmFSJuC9dTrm2WSdq8YMBXb9BB6Rj9mv8e9rb8e2ifRqJT","/ip4/172.18.135.54/tcp/14981/ws/p2p/16Uiu2HAmFSJuC9dTrm2WSdq8YMBXb9BB6Rj9mv8e9rb8e2ifRqJT"],"enrUri":"enr:-L24QN_aLckpPZJe2hscQA3VZ0CF4uUiW1fq9qEwAb5jnKM0OcPKjVqB-oRMB1v_nN1kE50rdjstmxE7XCjwwGsgrcMCgmlkgnY0gmlwhKwShzaKbXVsdGlhZGRyc5YACASsEoc2BjqEAAoErBKHNgY6hd0DgnJzhQADAQAAiXNlY3AyNTZrMaEDKVN8IL1KXWBR4gQGOxNEX71Ij1lZkWaw7ay6fKEqLzSDdGNwgjqEg3VkcII6hoV3YWt1MgM"}'
2025-12-21 04:33:53.768 INFO [src.node.waku_node] REST service is ready !!
2025-12-21 04:33:53.768 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:14979/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.64.28/tcp/5855/p2p/16Uiu2HAm38RdgCffC1LXiCWnYfHmABrwb2tXmS1JhnxsoJ4a8a4b"]'
2025-12-21 04:33:53.771 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:53.771 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2025-12-21 04:33:53.773 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:53.773 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:14979/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2025-12-21 04:33:53.775 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:53.776 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:53.776 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:53.781 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:53.781 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:53.982 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:53.982 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:53.988 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:53.988 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:54.189 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:54.189 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:54.194 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:54.194 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:54.395 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:54.395 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:54.400 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:54.401 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:54.601 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:54.602 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:54.607 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:54.608 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:54.809 DEBUG [src.steps.store] Relaying message
2025-12-21 04:33:54.809 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:5854/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-21 04:33:54.814 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-21 04:33:54.814 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2025-12-21 04:33:55.016 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:5854/store/v3/messages?pubsubTopic=%2Fwaku%2F2%2Frs%2F3%2F0&startTime=1766291630776282976&endTime=1766291635776493984&pageSize=20&ascending=true" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:55.019 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"","statusCode":200,"statusDesc":"OK","messages":[{"messageHash":"0x7c61411d50e446254d7ef107dbe371c89d508ff0a6aae779775cad570b140133"},{"messageHash":"0xc8de09703255644a7173fb182ffa139457a0a8f46e868d0607b253619c484169"},{"messageHash":"0xae2c1e9efd338bf4cba14d2f0d86bd51d8a53b8a6fcf4732d12a51f276bc1826"},{"messageHash":"0x9ed0c8f81a86caa4a264846f82bec86583907553ac95ad0042f51e8e4259ba87"},{"messageHash":"0x87badb49fdc4d69612c318da870d33d8786684aae67472920e15691db1f11a03"}]}'
2025-12-21 04:33:55.019 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:14979/store/v3/messages?pubsubTopic=%2Fwaku%2F2%2Frs%2F3%2F0&startTime=1766291630776282976&endTime=1766291635776493984&pageSize=20&ascending=true" -H "Content-Type: application/json" -d 'None'
2025-12-21 04:33:55.022 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"","statusCode":200,"statusDesc":"OK","messages":[{"messageHash":"0x7c61411d50e446254d7ef107dbe371c89d508ff0a6aae779775cad570b140133"},{"messageHash":"0xc8de09703255644a7173fb182ffa139457a0a8f46e868d0607b253619c484169"},{"messageHash":"0xae2c1e9efd338bf4cba14d2f0d86bd51d8a53b8a6fcf4732d12a51f276bc1826"},{"messageHash":"0x9ed0c8f81a86caa4a264846f82bec86583907553ac95ad0042f51e8e4259ba87"},{"messageHash":"0x87badb49fdc4d69612c318da870d33d8786684aae67472920e15691db1f11a03"}]}'
2025-12-21 04:33:55.024 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-21 04:33:55.025 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-21 04:33:55.025 DEBUG [src.node.waku_node] Stopping container with id cfe17466d4e4
2025-12-21 04:33:55.552 DEBUG [src.node.waku_node] Container stopped.
2025-12-21 04:33:55.552 DEBUG [src.node.waku_node] Stopping container with id 648e2f759b1d
2025-12-21 04:33:56.035 DEBUG [src.node.waku_node] Container stopped.
2025-12-21 04:33:56.037 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-21 04:33:56.043 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-21 04:33:56.050 DEBUG [src.node.docker_mananger] No errors found in the waku logs.