95 lines
17 KiB
Plaintext
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

2026-04-22 23:54:27.947 INFO [tests.conftest] Fleet bootstrap patch active NODE1→/dns4/node-01.do-ams3.waku.test.status.im/tcp/30303/p2p/16Uiu2HAkykgaECHswi3YKJ5dMLbq2kPVCo89fcyTd38UcQD6ej5W NODE2→/dns4/node-01.gc-us-central1-a.waku.test.status.im/tcp/30303/p2p/16Uiu2HAmDCp8XJ9z1ev18zuv8NHekAsjNyezAvmMfFEJkiharitG (additional nodes→/dns4/node-01.do-ams3.waku.test.status.im/tcp/30303/p2p/16Uiu2HAkykgaECHswi3YKJ5dMLbq2kPVCo89fcyTd38UcQD6ej5W) dns_discovery_url=enrtree://AOGYWMBYOUIMOENHXCHILPKY3ZRFEULMFI4DOM442QSZ73TT2A7VI@test.waku.nodes.status.im
2026-04-22 23:54:27.947 DEBUG [tests.conftest] Running fixture setup: test_id
2026-04-22 23:54:27.948 DEBUG [tests.conftest] Running test: test_filter_subscribe_with_extra_field with id: 2026-04-22_23-54-27__36531086-26a5-440c-bd52-a176fe3ce3ee
2026-04-22 23:54:27.948 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-04-22 23:54:27.948 DEBUG [src.steps.filter] Running fixture setup: filter_setup
2026-04-22 23:54:27.948 DEBUG [src.steps.filter] Running fixture setup: setup_main_relay_node
2026-04-22 23:54:27.954 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 23:54:27.955 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2026-04-22_23-54-27__36531086-26a5-440c-bd52-a176fe3ce3ee__wakuorg_nwaku:latest.log
2026-04-22 23:54:27.955 DEBUG [tests.conftest] fleet_joined_start: injecting waku.test bootstrap args into WakuNode.start()
2026-04-22 23:54:27.955 DEBUG [tests.conftest] fleet_joined_start: NODE1 bootstrapping from config-n1.toml (/dns4/node-01.do-ams3.waku.test.status.im/tcp/30303/p2p/16Uiu2HAkykgaECHswi3YKJ5dMLbq2kPVCo89fcyTd38UcQD6ej5W)
2026-04-22 23:54:27.955 DEBUG [tests.conftest] fleet_joined_start: staticnode=/dns4/node-01.do-ams3.waku.test.status.im/tcp/30303/p2p/16Uiu2HAkykgaECHswi3YKJ5dMLbq2kPVCo89fcyTd38UcQD6ej5W dns_discovery_url=enrtree://AOGYWMBYOUIMOENHXCHILPKY3ZRFEULMFI4DOM442QSZ73TT2A7VI@test.waku.nodes.status.im
2026-04-22 23:54:27.955 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 23:54:27.955 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 23:54:27.957 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 23:54:27.957 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.235.103
2026-04-22 23:54:27.957 DEBUG [src.node.docker_mananger] Generated ports ['17913', '17914', '17915', '17916', '17917']
2026-04-22 23:54:27.957 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 23:54:27.957 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 23:54:27.957 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 23:54:27.958 DEBUG [src.node.docker_mananger] docker run -i -t -p 17913:17913 -p 17914:17914 -p 17915:17915 -p 17916:17916 -p 17917:17917 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=17915 --rest-port=17913 --tcp-port=17914 --discv5-udp-port=17916 --rest-address=0.0.0.0 --nat=extip:172.18.235.103 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=54f61ffc4ad69db1aacf458e5629d1deacdcebe8b842dd6a6853fb4f0b94eba8 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=17917 --metrics-logging=true --relay=true --filter=true --staticnode=/dns4/node-01.do-ams3.waku.test.status.im/tcp/30303/p2p/16Uiu2HAkykgaECHswi3YKJ5dMLbq2kPVCo89fcyTd38UcQD6ej5W --dns-discovery=true --dns-discovery-url=enrtree://AOGYWMBYOUIMOENHXCHILPKY3ZRFEULMFI4DOM442QSZ73TT2A7VI@test.waku.nodes.status.im
2026-04-22 23:54:28.131 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.235.103 waku 38ba8fbe6cbe54cf3aa996016d0fe8cdb170ae9304d307ff188b93ae1e003749
2026-04-22 23:54:28.163 DEBUG [src.node.docker_mananger] Container started with ID 38ba8fbe6cbe. Setting up logs at ./log/docker/node1_2026-04-22_23-54-27__36531086-26a5-440c-bd52-a176fe3ce3ee__wakuorg_nwaku:latest.log
2026-04-22 23:54:28.164 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 17913
2026-04-22 23:54:28.164 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 23:54:28.290 ERROR [src.node.docker_mananger] Max retries reached for container 89d171cf4780. Exiting log stream.
2026-04-22 23:54:28.755 ERROR [src.node.docker_mananger] Max retries reached for container 48895dcc18f2. Exiting log stream.
2026-04-22 23:54:29.164 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.167 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.267 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.270 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.370 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.372 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.473 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.475 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.575 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.578 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.678 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.680 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:29.780 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.783 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"PartiallyConnected","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"},{"Peer Exchange":"READY"},{"Rendezvous":"NOT_READY","desc":"No Rendezvous peers are available yet"},{"Mix":"NOT_MOUNTED"},{"Lightpush Client":"READY"},{"Legacy Lightpush Client":"READY"},{"Store Client":"READY"},{"Filter Client":"READY"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 23:54:29.783 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 23:54:29.783 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17913/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:29.785 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.235.103/tcp/17914/p2p/16Uiu2HAm712GsPw6S4GhiFXXL4gxmhgzYWLn31r1edRs1b1N4WmD","/ip4/172.18.235.103/tcp/17915/ws/p2p/16Uiu2HAm712GsPw6S4GhiFXXL4gxmhgzYWLn31r1edRs1b1N4WmD"],"enrUri":"enr:-L24QGN5tp1iAkW9UWDimmMBduANaIjMdY0y-p5duU0zeH7XIoWx1-uHVFg8rPyawi1Mc8sbbFUCmDKfhVZakz9caLQCgmlkgnY0gmlwhKwS62eKbXVsdGlhZGRyc5YACASsEutnBkX6AAoErBLrZwZF-90DgnJzhQDGAQAAiXNlY3AyNTZrMaECq_ure-6KLIXIaS3Y88fVZxMJ68F-xkxqLPw9RHmQFmCDdGNwgkX6g3VkcIJF_IV3YWt1MgU"}'
2026-04-22 23:54:29.785 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 23:54:29.786 DEBUG [src.steps.filter] Running fixture setup: setup_main_filter_node
2026-04-22 23:54:29.792 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 23:54:29.792 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2026-04-22_23-54-27__36531086-26a5-440c-bd52-a176fe3ce3ee__wakuorg_nwaku:latest.log
2026-04-22 23:54:29.792 DEBUG [tests.conftest] fleet_joined_start: injecting waku.test bootstrap args into WakuNode.start()
2026-04-22 23:54:29.792 DEBUG [tests.conftest] fleet_joined_start: NODE2 bootstrapping from config-n2.toml (/dns4/node-01.gc-us-central1-a.waku.test.status.im/tcp/30303/p2p/16Uiu2HAmDCp8XJ9z1ev18zuv8NHekAsjNyezAvmMfFEJkiharitG)
2026-04-22 23:54:29.792 DEBUG [tests.conftest] fleet_joined_start: dropping local discv5_bootstrap_node=enr:-L24QGN5tp1iAkW9UWDimmMBduANaIjMdY0y-p5duU0zeH7XIoWx1-uHVFg8rPyawi1Mc8sbbFUCmDKfhVZakz9caLQCgmlkgnY0gmlwhKwS62eKbXVsdGlhZGRyc5YACASsEutnBkX6AAoErBLrZwZF-90DgnJzhQDGAQAAiXNlY3AyNTZrMaECq_ure-6KLIXIaS3Y88fVZxMJ68F-xkxqLPw9RHmQFmCDdGNwgkX6g3VkcIJF_IV3YWt1MgU (fleet DNS discovery replaces it)
2026-04-22 23:54:29.792 DEBUG [tests.conftest] fleet_joined_start: staticnode=/dns4/node-01.gc-us-central1-a.waku.test.status.im/tcp/30303/p2p/16Uiu2HAmDCp8XJ9z1ev18zuv8NHekAsjNyezAvmMfFEJkiharitG dns_discovery_url=enrtree://AOGYWMBYOUIMOENHXCHILPKY3ZRFEULMFI4DOM442QSZ73TT2A7VI@test.waku.nodes.status.im
2026-04-22 23:54:29.793 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 23:54:29.793 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 23:54:29.794 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 23:54:29.794 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.192.31
2026-04-22 23:54:29.794 DEBUG [src.node.docker_mananger] Generated ports ['21569', '21570', '21571', '21572', '21573']
2026-04-22 23:54:29.795 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 23:54:29.795 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 23:54:29.795 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 23:54:29.795 DEBUG [src.node.docker_mananger] docker run -i -t -p 21569:21569 -p 21570:21570 -p 21571:21571 -p 21572:21572 -p 21573:21573 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=21571 --rest-port=21569 --tcp-port=21570 --discv5-udp-port=21572 --rest-address=0.0.0.0 --nat=extip:172.18.192.31 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=95dbb99dbce04f7aede12723cae5deaeeafc4e622deaeeb4bbd4259d9cc9051e --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=21573 --metrics-logging=true --relay=false --filternode=/ip4/172.18.235.103/tcp/17914/p2p/16Uiu2HAm712GsPw6S4GhiFXXL4gxmhgzYWLn31r1edRs1b1N4WmD --staticnode=/dns4/node-01.gc-us-central1-a.waku.test.status.im/tcp/30303/p2p/16Uiu2HAmDCp8XJ9z1ev18zuv8NHekAsjNyezAvmMfFEJkiharitG --dns-discovery=true --dns-discovery-url=enrtree://AOGYWMBYOUIMOENHXCHILPKY3ZRFEULMFI4DOM442QSZ73TT2A7VI@test.waku.nodes.status.im
2026-04-22 23:54:29.984 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.192.31 waku 8acc2b33f3cb3921b04943d78154336dc258a2190b08f21ee2e945e603ea84a8
2026-04-22 23:54:30.012 DEBUG [src.node.docker_mananger] Container started with ID 8acc2b33f3cb. Setting up logs at ./log/docker/node2_2026-04-22_23-54-27__36531086-26a5-440c-bd52-a176fe3ce3ee__wakuorg_nwaku:latest.log
2026-04-22 23:54:30.013 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 21569
2026-04-22 23:54:30.013 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 23:54:31.014 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:21569/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:31.017 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:31.117 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:21569/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:31.119 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:31.220 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:21569/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:31.222 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"INITIALIZING","connectionStatus":"Disconnected","protocolsHealth":[]}'
2026-04-22 23:54:31.322 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:21569/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:31.325 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"PartiallyConnected","protocolsHealth":[{"Relay":"NOT_MOUNTED"},{"Lightpush":"NOT_MOUNTED"},{"Legacy Lightpush":"NOT_MOUNTED"},{"Filter":"NOT_MOUNTED"},{"Store":"NOT_MOUNTED"},{"Peer Exchange":"READY"},{"Rendezvous":"NOT_READY","desc":"No Rendezvous peers are available yet"},{"Mix":"NOT_MOUNTED"},{"Lightpush Client":"READY"},{"Legacy Lightpush Client":"READY"},{"Store Client":"READY"},{"Filter Client":"READY"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 23:54:31.325 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 23:54:31.325 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:21569/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 23:54:31.327 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.192.31/tcp/21570/p2p/16Uiu2HAmU72a4Es3XJorsSSc2VXAGurQ9vBLmoThAFiTFc9ntgsh","/ip4/172.18.192.31/tcp/21571/ws/p2p/16Uiu2HAmU72a4Es3XJorsSSc2VXAGurQ9vBLmoThAFiTFc9ntgsh"],"enrUri":"enr:-L24QJPbuzRKdFMZ_H2_gUpzrPWCL6aa5I64VfSSm2fu5sOPN_bHgxW4qi5lb1lNRyVJfUuqZYblZONg9R9PMM-3ybkCgmlkgnY0gmlwhKwSwB-KbXVsdGlhZGRyc5YACASsEsAfBlRCAAoErBLAHwZUQ90DgnJzhQDGAQAAiXNlY3AyNTZrMaED5YrqTDg-uKqfvcL3RReMpdd46lBUYVy4t3Q43hTnDICDdGNwglRCg3VkcIJURIV3YWt1MgA"}'
2026-04-22 23:54:31.327 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 23:54:31.328 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:21569/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.235.103/tcp/17914/p2p/16Uiu2HAm712GsPw6S4GhiFXXL4gxmhgzYWLn31r1edRs1b1N4WmD"]'
2026-04-22 23:54:31.354 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:54:31.355 DEBUG [src.steps.filter] Running fixture setup: subscribe_main_nodes
2026-04-22 23:54:31.357 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:17913/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/198/1"]'
2026-04-22 23:54:31.365 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 23:54:31.366 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:21569/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "5f3cd0c1-fcb0-4956-b50d-27d85dcea3d4", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/198/1"}'
2026-04-22 23:54:31.378 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"5f3cd0c1-fcb0-4956-b50d-27d85dcea3d4","statusDesc":"OK"}'
2026-04-22 23:54:31.379 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:21569/filter/v2/subscriptions" -H "Content-Type: application/json" -d '{"requestId": "1", "contentFilters": ["/test/1/waku-filter/proto"], "pubsubTopic": "/waku/2/rs/198/1", "extraField": "extraValue"}'
2026-04-22 23:54:31.382 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:21569/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\\"))"}'
2026-04-22 23:54:31.384 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-04-22 23:54:31.386 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-04-22 23:54:31.386 DEBUG [src.node.waku_node] Stopping container with id 38ba8fbe6cbe
2026-04-22 23:54:31.807 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 23:54:31.809 DEBUG [src.node.waku_node] Stopping container with id 8acc2b33f3cb
2026-04-22 23:54:32.253 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 23:54:32.255 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-04-22 23:54:32.276 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-04-22 23:54:32.291 DEBUG [src.node.docker_mananger] No errors found in the waku logs.