69 lines
12 KiB
Plaintext

2025-12-19 04:14:13.303 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-19 04:14:13.303 DEBUG [tests.conftest] Running test: test_filter_update_subscription_with_invalid_request_id with id: 2025-12-19_04-14-13__c202273c-df8e-43a9-9bc7-89ad1097b05d
2025-12-19 04:14:13.304 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-19 04:14:13.304 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2025-12-19 04:14:13.304 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2025-12-19 04:14:13.310 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-19 04:14:13.311 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-19_04-14-13__c202273c-df8e-43a9-9bc7-89ad1097b05d__wakuorg_nwaku:latest.log
2025-12-19 04:14:13.311 DEBUG [src.node.waku_node] Starting Node...
2025-12-19 04:14:13.311 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-19 04:14:13.312 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-19 04:14:13.312 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.155.151
2025-12-19 04:14:13.313 DEBUG [src.node.docker_mananger] Generated ports ['43915', '43916', '43917', '43918', '43919']
2025-12-19 04:14:13.313 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-19 04:14:13.313 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-19 04:14:13.313 DEBUG [src.node.waku_node] Using volumes []
2025-12-19 04:14:13.313 DEBUG [src.node.docker_mananger] docker run -i -t -p 43915:43915 -p 43916:43916 -p 43917:43917 -p 43918:43918 -p 43919:43919 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=43917 --rest-port=43915 --tcp-port=43916 --discv5-udp-port=43918 --rest-address=0.0.0.0 --nat=extip:172.18.155.151 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=57e8df0af7ca08aa2acd14e96eb04fca92bf3517fbe3b65ffa88c2f3df75fe5d --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=43919 --metrics-logging=true --relay=true --filter=true
2025-12-19 04:14:13.503 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.155.151 waku ce36b9831e79176c0716e6a3c9cbffbc49b611dd32a1dbfd07568251776a47ed
2025-12-19 04:14:13.536 DEBUG [src.node.docker_mananger] Container started with ID ce36b9831e79. Setting up logs at ./log/docker/node1_2025-12-19_04-14-13__c202273c-df8e-43a9-9bc7-89ad1097b05d__wakuorg_nwaku:latest.log
2025-12-19 04:14:13.538 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 43915
2025-12-19 04:14:13.538 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-19 04:14:13.551 ERROR [src.node.docker_mananger] Max retries reached for container dab1cdabe97b. Exiting log stream.
2025-12-19 04:14:14.063 ERROR [src.node.docker_mananger] Max retries reached for container 6f15a02ca0b8. Exiting log stream.
2025-12-19 04:14:14.538 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:43915/health" -H "Content-Type: application/json" -d 'None'
2025-12-19 04:14:14.542 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-19 04:14:14.542 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-19 04:14:14.542 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:43915/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-19 04:14:14.544 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.155.151/tcp/43916/p2p/16Uiu2HAmQFxtehh4ehNjLLkw4ddBCS7nEVaUtfUxNEZ22Wws7srk","/ip4/172.18.155.151/tcp/43917/ws/p2p/16Uiu2HAmQFxtehh4ehNjLLkw4ddBCS7nEVaUtfUxNEZ22Wws7srk"],"enrUri":"enr:-L24QLwqkKQAzwwivOikjjK7eNzkp66NrlwUfGmujUW8Gyq0BPYt4j6LaTC3m7t4YOSfy8ig5PNW_Q6IKxtOknE4D-oCgmlkgnY0gmlwhKwSm5eKbXVsdGlhZGRyc5YACASsEpuXBquMAAoErBKblwarjd0DgnJzhQADAQAAiXNlY3AyNTZrMaEDrGY8Bs8KNyzJNuj_UerZrJ2S0vOOr4QgAwq57eAwYt2DdGNwgquMg3VkcIKrjoV3YWt1MgU"}'
2025-12-19 04:14:14.545 INFO [src.node.waku_node] REST service is ready !!
2025-12-19 04:14:14.545 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2025-12-19 04:14:14.552 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-19 04:14:14.552 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-19_04-14-13__c202273c-df8e-43a9-9bc7-89ad1097b05d__wakuorg_nwaku:latest.log
2025-12-19 04:14:14.552 DEBUG [src.node.waku_node] Starting Node...
2025-12-19 04:14:14.552 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-19 04:14:14.554 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-19 04:14:14.554 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.122.73
2025-12-19 04:14:14.554 DEBUG [src.node.docker_mananger] Generated ports ['3053', '3054', '3055', '3056', '3057']
2025-12-19 04:14:14.555 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-19 04:14:14.555 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-19 04:14:14.555 DEBUG [src.node.waku_node] Using volumes []
2025-12-19 04:14:14.555 DEBUG [src.node.docker_mananger] docker run -i -t -p 3053:3053 -p 3054:3054 -p 3055:3055 -p 3056:3056 -p 3057:3057 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=3055 --rest-port=3053 --tcp-port=3054 --discv5-udp-port=3056 --rest-address=0.0.0.0 --nat=extip:172.18.122.73 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=c55222ee5ec682ea7c5bd0decadbbeadcedfb8abdbcf4ff71bacaef8d457a2a0 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=3057 --metrics-logging=true --relay=false --discv5-bootstrap-node=enr:-L24QLwqkKQAzwwivOikjjK7eNzkp66NrlwUfGmujUW8Gyq0BPYt4j6LaTC3m7t4YOSfy8ig5PNW_Q6IKxtOknE4D-oCgmlkgnY0gmlwhKwSm5eKbXVsdGlhZGRyc5YACASsEpuXBquMAAoErBKblwarjd0DgnJzhQADAQAAiXNlY3AyNTZrMaEDrGY8Bs8KNyzJNuj_UerZrJ2S0vOOr4QgAwq57eAwYt2DdGNwgquMg3VkcIKrjoV3YWt1MgU --filternode=/ip4/172.18.155.151/tcp/43916/p2p/16Uiu2HAmQFxtehh4ehNjLLkw4ddBCS7nEVaUtfUxNEZ22Wws7srk
2025-12-19 04:14:14.748 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.122.73 waku def467879ec6dab17991054520cf98fdfcd867f5e1256b67184a20862f42bb6a
2025-12-19 04:14:14.782 DEBUG [src.node.docker_mananger] Container started with ID def467879ec6. Setting up logs at ./log/docker/node2_2025-12-19_04-14-13__c202273c-df8e-43a9-9bc7-89ad1097b05d__wakuorg_nwaku:latest.log
2025-12-19 04:14:14.783 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 3053
2025-12-19 04:14:14.783 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-19 04:14:15.783 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:3053/health" -H "Content-Type: application/json" -d 'None'
2025-12-19 04:14:15.788 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-19 04:14:15.788 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-19 04:14:15.788 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:3053/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-19 04:14:15.790 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.122.73/tcp/3054/p2p/16Uiu2HAmAnnbhDcqaAGohR69uzf8U7ocfrEw2NawMtgkfF7hbFQ2","/ip4/172.18.122.73/tcp/3055/ws/p2p/16Uiu2HAmAnnbhDcqaAGohR69uzf8U7ocfrEw2NawMtgkfF7hbFQ2"],"enrUri":"enr:-L24QN3mJDEBaA8FO56eYVgEB3X4p-mCEOJRjrZ8uGkYQeMkLjL_IV9NaTTIf0zyWBIdRJMbxJ-XCOkH0GM4-Q_zyo0CgmlkgnY0gmlwhKwSekmKbXVsdGlhZGRyc5YACASsEnpJBgvuAAoErBJ6SQYL790DgnJzhQADAQAAiXNlY3AyNTZrMaEC5Ef8KCjMD52k8lHE2HNViDwGrA_URkT8Z_9V_kEA1j-DdGNwggvug3VkcIIL8IV3YWt1MgA"}'
2025-12-19 04:14:15.791 INFO [src.node.waku_node] REST service is ready !!
2025-12-19 04:14:15.791 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:3053/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.155.151/tcp/43916/p2p/16Uiu2HAmQFxtehh4ehNjLLkw4ddBCS7nEVaUtfUxNEZ22Wws7srk"]'
2025-12-19 04:14:15.818 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-19 04:14:15.819 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2025-12-19 04:14:15.820 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:43915/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/1"]'
2025-12-19 04:14:15.834 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-19 04:14:15.839 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:3053/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "3bb1040b-36bf-42c3-9d71-faf7b03edf89", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/3/1"}'
2025-12-19 04:14:15.852 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"3bb1040b-36bf-42c3-9d71-faf7b03edf89","statusDesc":"OK"}'
2025-12-19 04:14:15.853 INFO [src.node.api_clients.base_client] curl -v -X PUT "http://127.0.0.1:3053/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-19 04:14:15.856 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:3053/filter/v2/subscriptions. Response content: b'{"requestId":"unknown","statusDesc":"BAD_REQUEST: Failed to decode request: (status: 400 Bad Request, headers: , kind: Error, errobj: (status: 400 Bad Request, message: \\"Invalid content body, could not decode. Unable to deserialize data: \\", contentType: \\"text/plain\\"))"}'
2025-12-19 04:14:15.858 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-19 04:14:15.859 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-19 04:14:15.859 DEBUG [src.node.waku_node] Stopping container with id ce36b9831e79
2025-12-19 04:14:16.393 DEBUG [src.node.waku_node] Container stopped.
2025-12-19 04:14:16.394 DEBUG [src.node.waku_node] Stopping container with id def467879ec6
2025-12-19 04:14:16.931 DEBUG [src.node.waku_node] Container stopped.
2025-12-19 04:14:16.932 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-19 04:14:16.937 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-19 04:14:16.942 DEBUG [src.node.docker_mananger] No errors found in the waku logs.