2026-03-18 09:27:31 +00:00

84 lines
17 KiB
Plaintext

2026-03-18 09:13:46.185 DEBUG [tests.conftest] Running fixture setup: test_id
2026-03-18 09:13:46.185 DEBUG [tests.conftest] Running test: test_store_with_wrongPeerAddr with id: 2026-03-18_09-13-46__53c68d95-54c1-4adf-b079-ecf35e95e53f
2026-03-18 09:13:46.186 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-03-18 09:13:46.186 DEBUG [src.steps.store] Running fixture setup: store_setup
2026-03-18 09:13:46.186 DEBUG [src.steps.store] Running fixture setup: node_setup
2026-03-18 09:13:46.193 DEBUG [src.node.docker_mananger] Docker client initialized with image harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0
2026-03-18 09:13:46.193 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/publishing_node1_2026-03-18_09-13-46__53c68d95-54c1-4adf-b079-ecf35e95e53f__harbor.status.im_wakuorg_nwaku:v0.38.0-rc.0.log
2026-03-18 09:13:46.193 DEBUG [src.node.waku_node] Starting Node...
2026-03-18 09:13:46.193 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-03-18 09:13:46.194 DEBUG [src.node.docker_mananger] Network waku already exists
2026-03-18 09:13:46.194 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.136.187
2026-03-18 09:13:46.195 DEBUG [src.node.docker_mananger] Generated ports ['40993', '40994', '40995', '40996', '40997']
2026-03-18 09:13:46.195 DEBUG [src.node.waku_node] RLN credentials were not set
2026-03-18 09:13:46.195 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-03-18 09:13:46.195 DEBUG [src.node.waku_node] Using volumes []
2026-03-18 09:13:46.195 DEBUG [src.node.docker_mananger] docker run -i -t -p 40993:40993 -p 40994:40994 -p 40995:40995 -p 40996:40996 -p 40997:40997 harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0 --listen-address=0.0.0.0 --rest=true --rest-admin=true --websocket-support=true --log-level=TRACE --rest-relay-cache-capacity=100 --websocket-port=40995 --rest-port=40993 --tcp-port=40994 --discv5-udp-port=40996 --rest-address=0.0.0.0 --nat=extip:172.18.136.187 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=3647beaacccdd0236637a4a1bb31cdaffdfa44af10281c4c97f8dfa07a1aa457 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=40997 --metrics-logging=true --store=true --relay=true
2026-03-18 09:13:46.386 ERROR [src.node.docker_mananger] Max retries reached for container dd1f550cb0ea. Exiting log stream.
2026-03-18 09:13:46.397 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.136.187 waku ad75b83289a5a2fc801fdaf1f86a7619400cb713de7625067cbfe52984a6ba91
2026-03-18 09:13:46.433 DEBUG [src.node.docker_mananger] Container started with ID ad75b83289a5. Setting up logs at ./log/docker/publishing_node1_2026-03-18_09-13-46__53c68d95-54c1-4adf-b079-ecf35e95e53f__harbor.status.im_wakuorg_nwaku:v0.38.0-rc.0.log
2026-03-18 09:13:46.435 DEBUG [src.node.waku_node] Started container from image harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0. REST: 40993
2026-03-18 09:13:46.435 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-03-18 09:13:46.987 ERROR [src.node.docker_mananger] Max retries reached for container 55e6d4744c96. Exiting log stream.
2026-03-18 09:13:47.436 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:40993/health" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:47.438 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_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"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-03-18 09:13:47.439 INFO [src.node.waku_node] Node protocols are initialized !!
2026-03-18 09:13:47.439 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:40993/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:47.441 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.136.187/tcp/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC","/ip4/172.18.136.187/tcp/40995/ws/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC"],"enrUri":"enr:-L24QCrfqaLJlgcCl_CLGhDFUi_c6QZggq4igP_G-XLzS98QNk7DoGyO6DzWtRKRzj1I_5kuoSK_Kab1txmxNAFeGF8CgmlkgnY0gmlwhKwSiLuKbXVsdGlhZGRyc5YACASsEoi7BqAiAAoErBKIuwagI90DgnJzhQDGAQAAiXNlY3AyNTZrMaECBdrOGhkbPwE3HUcM0h6CVzmlj890vnf1dxAANn-d1kWDdGNwgqAig3VkcIKgJIV3YWt1MgM"}'
2026-03-18 09:13:47.442 INFO [src.node.waku_node] REST service is ready !!
2026-03-18 09:13:47.449 DEBUG [src.node.docker_mananger] Docker client initialized with image harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0
2026-03-18 09:13:47.449 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/store_node1_2026-03-18_09-13-46__53c68d95-54c1-4adf-b079-ecf35e95e53f__harbor.status.im_wakuorg_nwaku:v0.38.0-rc.0.log
2026-03-18 09:13:47.449 DEBUG [src.node.waku_node] Starting Node...
2026-03-18 09:13:47.449 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-03-18 09:13:47.450 DEBUG [src.node.docker_mananger] Network waku already exists
2026-03-18 09:13:47.450 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.22.11
2026-03-18 09:13:47.451 DEBUG [src.node.docker_mananger] Generated ports ['17523', '17524', '17525', '17526', '17527']
2026-03-18 09:13:47.451 DEBUG [src.node.waku_node] RLN credentials were not set
2026-03-18 09:13:47.451 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-03-18 09:13:47.451 DEBUG [src.node.waku_node] Using volumes []
2026-03-18 09:13:47.451 DEBUG [src.node.docker_mananger] docker run -i -t -p 17523:17523 -p 17524:17524 -p 17525:17525 -p 17526:17526 -p 17527:17527 harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0 --listen-address=0.0.0.0 --rest=true --rest-admin=true --websocket-support=true --log-level=TRACE --rest-relay-cache-capacity=100 --websocket-port=17525 --rest-port=17523 --tcp-port=17524 --discv5-udp-port=17526 --rest-address=0.0.0.0 --nat=extip:172.18.22.11 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=6ce81f06ddaacfedfdb5730cbdc1a5329c6b8c2feeed5c5df8abcdaa204fbce9 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=17527 --metrics-logging=true --discv5-bootstrap-node=enr:-L24QCrfqaLJlgcCl_CLGhDFUi_c6QZggq4igP_G-XLzS98QNk7DoGyO6DzWtRKRzj1I_5kuoSK_Kab1txmxNAFeGF8CgmlkgnY0gmlwhKwSiLuKbXVsdGlhZGRyc5YACASsEoi7BqAiAAoErBKIuwagI90DgnJzhQDGAQAAiXNlY3AyNTZrMaECBdrOGhkbPwE3HUcM0h6CVzmlj890vnf1dxAANn-d1kWDdGNwgqAig3VkcIKgJIV3YWt1MgM --storenode=/ip4/172.18.136.187/tcp/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC --store=true --relay=true
2026-03-18 09:13:47.649 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.22.11 waku a41c9328d315eee96734c8257e163f3341ed36e9c4bda4676c98958007bf554b
2026-03-18 09:13:47.686 DEBUG [src.node.docker_mananger] Container started with ID a41c9328d315. Setting up logs at ./log/docker/store_node1_2026-03-18_09-13-46__53c68d95-54c1-4adf-b079-ecf35e95e53f__harbor.status.im_wakuorg_nwaku:v0.38.0-rc.0.log
2026-03-18 09:13:47.686 DEBUG [src.node.waku_node] Started container from image harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0. REST: 17523
2026-03-18 09:13:47.688 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-03-18 09:13:48.688 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17523/health" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:48.691 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","connectionStatus":"PartiallyConnected","protocolsHealth":[{"Relay":"READY"},{"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"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-03-18 09:13:48.691 INFO [src.node.waku_node] Node protocols are initialized !!
2026-03-18 09:13:48.691 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17523/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:48.693 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.22.11/tcp/17524/p2p/16Uiu2HAmFjKgQExR9r2JSAHi9oeP6MrmkbGuA5LyL9Po5EeZbBbj","/ip4/172.18.22.11/tcp/17525/ws/p2p/16Uiu2HAmFjKgQExR9r2JSAHi9oeP6MrmkbGuA5LyL9Po5EeZbBbj"],"enrUri":"enr:-L24QHjQigdy-ZZr9a0uFZA0m3qfahwNYhH9rumX3xMn7ltYHZPHRTeeLVneP-YpYy_ROrxHce5Q0Y36oOb6Q0NRG8ICgmlkgnY0gmlwhKwSFguKbXVsdGlhZGRyc5YACASsEhYLBkR0AAoErBIWCwZEdd0DgnJzhQDGAQAAiXNlY3AyNTZrMaEDLa89bjn63xEq6IY2ehRStLgHuXnplcBhsTvu2Xy1I_aDdGNwgkR0g3VkcIJEdoV3YWt1MgM"}'
2026-03-18 09:13:48.694 INFO [src.node.waku_node] REST service is ready !!
2026-03-18 09:13:48.694 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:17523/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.136.187/tcp/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC"]'
2026-03-18 09:13:48.697 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-18 09:13:48.697 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:40993/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/198/0"]'
2026-03-18 09:13:48.700 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-18 09:13:48.700 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:17523/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/198/0"]'
2026-03-18 09:13:48.702 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-18 09:13:48.703 DEBUG [src.steps.store] Relaying message
2026-03-18 09:13:48.704 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:40993/relay/v1/messages/%2Fwaku%2F2%2Frs%2F198%2F0" -H "Content-Type: application/json" -d '{"payload": "U3RvcmUgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2026-03-18 09:13:48.708 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-03-18 09:13:48.709 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-03-18 09:13:48.910 DEBUG [tests.store.test_api_flags] Running test with wrong_peer_addr: ip4/172.18.136.187/tcp/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC
2026-03-18 09:13:48.910 DEBUG [src.steps.store] Checking that peer harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0 can find the stored messages
2026-03-18 09:13:48.911 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17523/store/v3/messages?peerAddr=ip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:48.913 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=ip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0. Response content: b'Failed parsing remote peer info: MultiAddress.init [multiaddress: Invalid MultiAddress, must start with `/`]'
2026-03-18 09:13:48.914 DEBUG [tests.store.test_api_flags] Response with wrong peer address is Error: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=ip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0 with response: b'Failed parsing remote peer info: MultiAddress.init [multiaddress: Invalid MultiAddress, must start with `/`]'
2026-03-18 09:13:48.915 DEBUG [tests.store.test_api_flags] Running test with wrong_peer_addr /ip4/172.18.136.187/tcp/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE
2026-03-18 09:13:48.915 DEBUG [src.steps.store] Checking that peer harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0 can find the stored messages
2026-03-18 09:13:48.915 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:48.918 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0. Response content: b'Failed parsing remote peer info: MultiAddress.init [multiaddress: Error encoding `p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE`]'
2026-03-18 09:13:48.919 DEBUG [tests.store.test_api_flags] Response with wrong peer id is Error: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2Ftcp%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0 with response: b'Failed parsing remote peer info: MultiAddress.init [multiaddress: Error encoding `p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkRE`]'
2026-03-18 09:13:48.919 DEBUG [tests.store.test_api_flags] logger is /ip4/172.18.136.187/40994/p2p/16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC
2026-03-18 09:13:48.919 DEBUG [src.steps.store] Checking that peer harbor.status.im/wakuorg/nwaku:v0.38.0-rc.0 can find the stored messages
2026-03-18 09:13:48.920 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0" -H "Content-Type: application/json" -d 'None'
2026-03-18 09:13:48.922 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0. Response content: b"Failed parsing remote peer info: MultiAddress.init [multiaddress: Unsupported protocol '40994']"
2026-03-18 09:13:48.923 DEBUG [tests.store.test_api_flags] Response with wrong peer address is Error: 400 Client Error: Bad Request for url: http://127.0.0.1:17523/store/v3/messages?peerAddr=%2Fip4%2F172.18.136.187%2F40994%2Fp2p%2F16Uiu2HAkupXXjvRWnjrAFwtfdeoHGEyQmeJj7CXHLJE87jjQkREC&pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0 with response: b"Failed parsing remote peer info: MultiAddress.init [multiaddress: Unsupported protocol '40994']"
2026-03-18 09:13:48.925 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-03-18 09:13:48.926 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-03-18 09:13:48.926 DEBUG [src.node.waku_node] Stopping container with id ad75b83289a5
2026-03-18 09:13:49.535 DEBUG [src.node.waku_node] Container stopped.
2026-03-18 09:13:49.537 DEBUG [src.node.waku_node] Stopping container with id a41c9328d315
2026-03-18 09:13:50.116 DEBUG [src.node.waku_node] Container stopped.
2026-03-18 09:13:50.120 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-03-18 09:13:50.130 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-03-18 09:13:50.135 DEBUG [src.node.docker_mananger] No errors found in the waku logs.