79 lines
14 KiB
Plaintext

2026-03-13 04:36:57.590 DEBUG [tests.conftest] Running fixture setup: test_id
2026-03-13 04:36:57.590 DEBUG [tests.conftest] Running test: test_filter_get_message_duplicate_message with id: 2026-03-13_04-36-57__dac2eace-ee0c-4e05-800d-388cd2cfe654
2026-03-13 04:36:57.592 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-03-13 04:36:57.592 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2026-03-13 04:36:57.594 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2026-03-13 04:36:57.601 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-03-13 04:36:57.601 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2026-03-13_04-36-57__dac2eace-ee0c-4e05-800d-388cd2cfe654__wakuorg_nwaku:latest.log
2026-03-13 04:36:57.602 DEBUG [src.node.waku_node] Starting Node...
2026-03-13 04:36:57.602 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-03-13 04:36:57.603 DEBUG [src.node.docker_mananger] Network waku already exists
2026-03-13 04:36:57.603 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.145.135
2026-03-13 04:36:57.603 DEBUG [src.node.docker_mananger] Generated ports ['50965', '50966', '50967', '50968', '50969']
2026-03-13 04:36:57.604 DEBUG [src.node.waku_node] RLN credentials were not set
2026-03-13 04:36:57.604 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-03-13 04:36:57.604 DEBUG [src.node.waku_node] Using volumes []
2026-03-13 04:36:57.604 DEBUG [src.node.docker_mananger] docker run -i -t -p 50965:50965 -p 50966:50966 -p 50967:50967 -p 50968:50968 -p 50969:50969 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=50967 --rest-port=50965 --tcp-port=50966 --discv5-udp-port=50968 --rest-address=0.0.0.0 --nat=extip:172.18.145.135 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=2f33f75a30fdf76c898b6fae2c8f5d977eb0aacb14ce37b1ba0fbb798fbafaad --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=50969 --metrics-logging=true --relay=true --filter=true
2026-03-13 04:36:57.800 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.145.135 waku 011f5ba638e48787fceb4854979a59437cb1fececb7c3fba3ba25e26b7fa35d8
2026-03-13 04:36:57.836 DEBUG [src.node.docker_mananger] Container started with ID 011f5ba638e4. Setting up logs at ./log/docker/node1_2026-03-13_04-36-57__dac2eace-ee0c-4e05-800d-388cd2cfe654__wakuorg_nwaku:latest.log
2026-03-13 04:36:57.837 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 50965
2026-03-13 04:36:57.840 ERROR [src.node.docker_mananger] Max retries reached for container 6cfcefefb574. Exiting log stream.
2026-03-13 04:36:57.840 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-03-13 04:36:58.412 ERROR [src.node.docker_mananger] Max retries reached for container 0a784572f2ab. Exiting log stream.
2026-03-13 04:36:58.843 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:50965/health" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:36:58.845 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"Disconnected","protocolsHealth":[{"Relay":"NOT_READY","desc":"No connected peers"},{"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"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-03-13 04:36:58.846 INFO [src.node.waku_node] Node protocols are initialized !!
2026-03-13 04:36:58.846 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:50965/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:36:58.849 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.145.135/tcp/50966/p2p/16Uiu2HAm36v3uLL5DJhAnMFHcx2JL8GnoAqqcXT6mw14nqJo61cv","/ip4/172.18.145.135/tcp/50967/ws/p2p/16Uiu2HAm36v3uLL5DJhAnMFHcx2JL8GnoAqqcXT6mw14nqJo61cv"],"enrUri":"enr:-L24QHRiWRLq19uo9YyY616EsoRuIqxoHbkzJVRWgZo3p5vzKMRsPz1-ON___9lJrlG-xV-JzujG7L_phlkz-Y5HT3ACgmlkgnY0gmlwhKwSkYeKbXVsdGlhZGRyc5YACASsEpGHBscWAAoErBKRhwbHF90DgnJzhQADAQAAiXNlY3AyNTZrMaECcg9euKXE2rGx3TYMUJptSxD5f75bdgMgi3T6XMZBouuDdGNwgscWg3VkcILHGIV3YWt1MgU"}'
2026-03-13 04:36:58.849 INFO [src.node.waku_node] REST service is ready !!
2026-03-13 04:36:58.849 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2026-03-13 04:36:58.856 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-03-13 04:36:58.856 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2026-03-13_04-36-57__dac2eace-ee0c-4e05-800d-388cd2cfe654__wakuorg_nwaku:latest.log
2026-03-13 04:36:58.856 DEBUG [src.node.waku_node] Starting Node...
2026-03-13 04:36:58.856 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-03-13 04:36:58.858 DEBUG [src.node.docker_mananger] Network waku already exists
2026-03-13 04:36:58.858 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.39.73
2026-03-13 04:36:58.858 DEBUG [src.node.docker_mananger] Generated ports ['53780', '53781', '53782', '53783', '53784']
2026-03-13 04:36:58.858 DEBUG [src.node.waku_node] RLN credentials were not set
2026-03-13 04:36:58.858 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-03-13 04:36:58.858 DEBUG [src.node.waku_node] Using volumes []
2026-03-13 04:36:58.859 DEBUG [src.node.docker_mananger] docker run -i -t -p 53780:53780 -p 53781:53781 -p 53782:53782 -p 53783:53783 -p 53784:53784 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=53782 --rest-port=53780 --tcp-port=53781 --discv5-udp-port=53783 --rest-address=0.0.0.0 --nat=extip:172.18.39.73 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=a5de4c9980eb32f5bddbafb4aa28de29b068e8de4f8afa853301c5acfb6dc6bd --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=53784 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QHRiWRLq19uo9YyY616EsoRuIqxoHbkzJVRWgZo3p5vzKMRsPz1-ON___9lJrlG-xV-JzujG7L_phlkz-Y5HT3ACgmlkgnY0gmlwhKwSkYeKbXVsdGlhZGRyc5YACASsEpGHBscWAAoErBKRhwbHF90DgnJzhQADAQAAiXNlY3AyNTZrMaECcg9euKXE2rGx3TYMUJptSxD5f75bdgMgi3T6XMZBouuDdGNwgscWg3VkcILHGIV3YWt1MgU --filternode=/ip4/172.18.145.135/tcp/50966/p2p/16Uiu2HAm36v3uLL5DJhAnMFHcx2JL8GnoAqqcXT6mw14nqJo61cv
2026-03-13 04:36:59.054 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.39.73 waku d6753f3ad824ab7bc6c9349eea49b8515b8dbed7ee96eea62ab1d6480094bad2
2026-03-13 04:36:59.087 DEBUG [src.node.docker_mananger] Container started with ID d6753f3ad824. Setting up logs at ./log/docker/node2_2026-03-13_04-36-57__dac2eace-ee0c-4e05-800d-388cd2cfe654__wakuorg_nwaku:latest.log
2026-03-13 04:36:59.087 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 53780
2026-03-13 04:36:59.087 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-03-13 04:37:00.088 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:53780/health" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:37:00.091 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"Disconnected","protocolsHealth":[{"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"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-03-13 04:37:00.091 INFO [src.node.waku_node] Node protocols are initialized !!
2026-03-13 04:37:00.091 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:53780/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:37:00.093 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.39.73/tcp/53781/p2p/16Uiu2HAmErX4muCEFrhJqrKCwVJsMnU5ibw8EtzA5b1nLurowQa4","/ip4/172.18.39.73/tcp/53782/ws/p2p/16Uiu2HAmErX4muCEFrhJqrKCwVJsMnU5ibw8EtzA5b1nLurowQa4"],"enrUri":"enr:-L24QG-P9-k_YO_SphZo4O6kdyCpwetfF8F8wQqvydLbFNBBPYUggKaaKp8kKv14jKDvoSWa2nwNnpsL5Uwyu2DTCl0CgmlkgnY0gmlwhKwSJ0mKbXVsdGlhZGRyc5YACASsEidJBtIVAAoErBInSQbSFt0DgnJzhQADAQAAiXNlY3AyNTZrMaEDIKt-G4knfNdIyEBt-pQlMBeYRuWzi5UyS5z2f4-T6CmDdGNwgtIVg3VkcILSF4V3YWt1MgA"}'
2026-03-13 04:37:00.094 INFO [src.node.waku_node] REST service is ready !!
2026-03-13 04:37:00.094 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:53780/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.145.135/tcp/50966/p2p/16Uiu2HAm36v3uLL5DJhAnMFHcx2JL8GnoAqqcXT6mw14nqJo61cv"]'
2026-03-13 04:37:00.127 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-13 04:37:00.128 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2026-03-13 04:37:00.128 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:50965/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2026-03-13 04:37:00.147 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-13 04:37:00.148 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:53780/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "503a5b0f-7610-440e-8b91-0bc9ae36664d", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2026-03-13 04:37:00.160 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"503a5b0f-7610-440e-8b91-0bc9ae36664d","statusDesc":"OK"}'
2026-03-13 04:37:00.162 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:50965/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)'}'
2026-03-13 04:37:00.170 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-13 04:37:00.170 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-03-13 04:37:00.271 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-03-13 04:37:00.271 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:53780/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:37:00.274 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":1773376620162804856,"ephemeral":false}]'
2026-03-13 04:37:00.276 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:50965/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)'}'
2026-03-13 04:37:00.279 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-13 04:37:00.280 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2026-03-13 04:37:00.380 DEBUG [src.steps.filter] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2026-03-13 04:37:00.380 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:53780/filter/v2/messages/%2Ftest%2F1%2Fwaku-filter%2Fproto" -H "Content-Type: application/json" -d 'None'
2026-03-13 04:37:00.383 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[]'
2026-03-13 04:37:00.385 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-03-13 04:37:00.386 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-03-13 04:37:00.386 DEBUG [src.node.waku_node] Stopping container with id 011f5ba638e4
2026-03-13 04:37:00.961 DEBUG [src.node.waku_node] Container stopped.
2026-03-13 04:37:00.962 DEBUG [src.node.waku_node] Stopping container with id d6753f3ad824
2026-03-13 04:37:01.505 DEBUG [src.node.waku_node] Container stopped.
2026-03-13 04:37:01.508 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-03-13 04:37:01.513 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-03-13 04:37:01.517 DEBUG [src.node.docker_mananger] No errors found in the waku logs.