82 lines
15 KiB
Plaintext

2025-12-27 04:27:57.231 DEBUG [tests.conftest] Running fixture setup: test_id
2025-12-27 04:27:57.231 DEBUG [tests.conftest] Running test: test_subscribe_and_publish_on_another_content_topic_from_another_shard with id: 2025-12-27_04-27-57__41b55d03-4aaf-41fe-8528-35b17f0dd6c0
2025-12-27 04:27:57.232 DEBUG [src.steps.common] Running fixture setup: common_setup
2025-12-27 04:27:57.232 DEBUG [src.steps.relay] Running fixture setup: relay_setup
2025-12-27 04:27:57.232 DEBUG [src.steps.sharding] Running fixture setup: sharding_setup
2025-12-27 04:27:57.239 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-27 04:27:57.239 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2025-12-27_04-27-57__41b55d03-4aaf-41fe-8528-35b17f0dd6c0__wakuorg_nwaku:latest.log
2025-12-27 04:27:57.240 DEBUG [src.node.waku_node] Starting Node...
2025-12-27 04:27:57.240 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-27 04:27:57.241 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-27 04:27:57.241 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.85.192
2025-12-27 04:27:57.241 DEBUG [src.node.docker_mananger] Generated ports ['30006', '30007', '30008', '30009', '30010']
2025-12-27 04:27:57.241 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-27 04:27:57.242 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-27 04:27:57.242 DEBUG [src.node.waku_node] Using volumes []
2025-12-27 04:27:57.242 DEBUG [src.node.docker_mananger] docker run -i -t -p 30006:30006 -p 30007:30007 -p 30008:30008 -p 30009:30009 -p 30010:30010 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=30008 --rest-port=30006 --tcp-port=30007 --discv5-udp-port=30009 --rest-address=0.0.0.0 --nat=extip:172.18.85.192 --peer-exchange=true --discv5-discovery=true --cluster-id=2 --nodekey=25a788d7d89d58672f4c1fddb782a6abee3eba6aeba7b0d91c4fec0bf925b19f --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=30010 --metrics-logging=true --relay=true --filter=true --content-topic=/myapp/1/latest/proto --num-shards-in-network=8
2025-12-27 04:27:57.427 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.85.192 waku 6b2325aece380c808faca5bb7513a6c21a9fc5ab288901f719265eb3f1a78009
2025-12-27 04:27:57.458 DEBUG [src.node.docker_mananger] Container started with ID 6b2325aece38. Setting up logs at ./log/docker/node1_2025-12-27_04-27-57__41b55d03-4aaf-41fe-8528-35b17f0dd6c0__wakuorg_nwaku:latest.log
2025-12-27 04:27:57.460 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 30006
2025-12-27 04:27:57.460 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-27 04:27:58.038 ERROR [src.node.docker_mananger] Max retries reached for container 980e5b36dd40. Exiting log stream.
2025-12-27 04:27:58.460 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:30006/health" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:58.463 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-27 04:27:58.464 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-27 04:27:58.464 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:30006/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:58.466 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.85.192/tcp/30007/p2p/16Uiu2HAmGmkX9GJkeDWx3vozCWXPAEdBepD22r95JKYseRFd3idq","/ip4/172.18.85.192/tcp/30008/ws/p2p/16Uiu2HAmGmkX9GJkeDWx3vozCWXPAEdBepD22r95JKYseRFd3idq"],"enrUri":"enr:-L24QKConewYjFrDjm79jXneNex7QzwhEnxBjJiOIrWaQIzqWz4jWnTzPCK_8FgZnekPRhpYZ_QX_6Aa4G4wEck9cMYCgmlkgnY0gmlwhKwSVcCKbXVsdGlhZGRyc5YACASsElXABnU3AAoErBJVwAZ1ON0DgnJzhQACAQAAiXNlY3AyNTZrMaEDPSos9MQSLmowE1BchMCMQSt-dERKASmBVkMKmmU5_uyDdGNwgnU3g3VkcIJ1OYV3YWt1MgU"}'
2025-12-27 04:27:58.466 INFO [src.node.waku_node] REST service is ready !!
2025-12-27 04:27:58.473 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2025-12-27 04:27:58.473 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2025-12-27_04-27-57__41b55d03-4aaf-41fe-8528-35b17f0dd6c0__wakuorg_nwaku:latest.log
2025-12-27 04:27:58.473 DEBUG [src.node.waku_node] Starting Node...
2025-12-27 04:27:58.473 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2025-12-27 04:27:58.475 DEBUG [src.node.docker_mananger] Network waku already exists
2025-12-27 04:27:58.475 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.12.252
2025-12-27 04:27:58.475 DEBUG [src.node.docker_mananger] Generated ports ['32198', '32199', '32200', '32201', '32202']
2025-12-27 04:27:58.475 DEBUG [src.node.waku_node] RLN credentials were not set
2025-12-27 04:27:58.475 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2025-12-27 04:27:58.475 DEBUG [src.node.waku_node] Using volumes []
2025-12-27 04:27:58.476 DEBUG [src.node.docker_mananger] docker run -i -t -p 32198:32198 -p 32199:32199 -p 32200:32200 -p 32201:32201 -p 32202:32202 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=32200 --rest-port=32198 --tcp-port=32199 --discv5-udp-port=32201 --rest-address=0.0.0.0 --nat=extip:172.18.12.252 --peer-exchange=true --discv5-discovery=true --cluster-id=2 --nodekey=c3192f960b0b4dabdef534bfb8f7be4ccecde6f17cc0c3edfbb36f0c453120dc --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=32202 --metrics-logging=true --relay=true --discv5-bootstrap-node=enr:-L24QKConewYjFrDjm79jXneNex7QzwhEnxBjJiOIrWaQIzqWz4jWnTzPCK_8FgZnekPRhpYZ_QX_6Aa4G4wEck9cMYCgmlkgnY0gmlwhKwSVcCKbXVsdGlhZGRyc5YACASsElXABnU3AAoErBJVwAZ1ON0DgnJzhQACAQAAiXNlY3AyNTZrMaEDPSos9MQSLmowE1BchMCMQSt-dERKASmBVkMKmmU5_uyDdGNwgnU3g3VkcIJ1OYV3YWt1MgU --content-topic=/myapp/1/latest/proto --num-shards-in-network=8
2025-12-27 04:27:58.655 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.12.252 waku 61053006b3619525c9f0e910d6516281de88a5b4a55e7992514bbcc87e216c1a
2025-12-27 04:27:58.685 DEBUG [src.node.docker_mananger] Container started with ID 61053006b361. Setting up logs at ./log/docker/node2_2025-12-27_04-27-57__41b55d03-4aaf-41fe-8528-35b17f0dd6c0__wakuorg_nwaku:latest.log
2025-12-27 04:27:58.685 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 32198
2025-12-27 04:27:58.686 DEBUG [src.libs.common] Sleeping for 1 seconds
2025-12-27 04:27:59.686 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:32198/health" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.698 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":"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-27 04:27:59.699 INFO [src.node.waku_node] Node protocols are initialized !!
2025-12-27 04:27:59.699 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:32198/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.703 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.12.252/tcp/32199/p2p/16Uiu2HAmLNZXCR93WoGBJ7R5zpyruCNxW8yGj7WoFHbQsDzyiexi","/ip4/172.18.12.252/tcp/32200/ws/p2p/16Uiu2HAmLNZXCR93WoGBJ7R5zpyruCNxW8yGj7WoFHbQsDzyiexi"],"enrUri":"enr:-L24QDZu1MFh939lfhUCt6pRbQzTdmz_mZja3puriPkquO9IZBEbGGR1YsdBb8xuLWPE0x_Ds5YLTQQWJtpR4NyNr-QCgmlkgnY0gmlwhKwSDPyKbXVsdGlhZGRyc5YACASsEgz8Bn3HAAoErBIM_AZ9yN0DgnJzhQACAQAAiXNlY3AyNTZrMaEDcqggxlanznTyHF1MEPvvlLBfqLA_SgKufAJVacdMgluDdGNwgn3Hg3VkcIJ9yYV3YWt1MgE"}'
2025-12-27 04:27:59.705 INFO [src.node.waku_node] REST service is ready !!
2025-12-27 04:27:59.705 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:32198/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.85.192/tcp/30007/p2p/16Uiu2HAmGmkX9GJkeDWx3vozCWXPAEdBepD22r95JKYseRFd3idq"]'
2025-12-27 04:27:59.710 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-27 04:27:59.711 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:30006/relay/v1/auto/subscriptions" -H "Content-Type: application/json" -d '["/toychat/2/huilong/proto"]'
2025-12-27 04:27:59.715 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-27 04:27:59.715 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:32198/relay/v1/auto/subscriptions" -H "Content-Type: application/json" -d '["/toychat/2/huilong/proto"]'
2025-12-27 04:27:59.720 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-27 04:27:59.721 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:30006/relay/v1/auto/messages" -H "Content-Type: application/json" -d '{"payload": "U2hhcmRpbmcgd29ya3MhIQ==", "contentTopic": "/toychat/2/huilong/proto", "timestamp": '$(date +%s%N)'}'
2025-12-27 04:27:59.727 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-27 04:27:59.728 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-27 04:27:59.828 DEBUG [src.steps.sharding] Checking that peer NODE_1:wakuorg/nwaku:latest can find the published message
2025-12-27 04:27:59.829 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:30006/relay/v1/auto/messages/%2Ftoychat%2F2%2Fhuilong%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.831 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"U2hhcmRpbmcgd29ya3MhIQ==","contentTopic":"/toychat/2/huilong/proto","version":0,"timestamp":1766809679721570114,"ephemeral":false,"proof":""}]'
2025-12-27 04:27:59.833 DEBUG [src.steps.sharding] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2025-12-27 04:27:59.833 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:32198/relay/v1/auto/messages/%2Ftoychat%2F2%2Fhuilong%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.835 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"U2hhcmRpbmcgd29ya3MhIQ==","contentTopic":"/toychat/2/huilong/proto","version":0,"timestamp":1766809679721570114,"ephemeral":false,"proof":""}]'
2025-12-27 04:27:59.837 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:30006/relay/v1/auto/messages" -H "Content-Type: application/json" -d '{"payload": "U2hhcmRpbmcgd29ya3MhIQ==", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2025-12-27 04:27:59.841 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2025-12-27 04:27:59.842 DEBUG [src.libs.common] Sleeping for 0.1 seconds
2025-12-27 04:27:59.943 DEBUG [src.steps.sharding] Checking that peer NODE_1:wakuorg/nwaku:latest can find the published message
2025-12-27 04:27:59.943 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:30006/relay/v1/auto/messages/%2Fmyapp%2F1%2Flatest%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.946 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"U2hhcmRpbmcgd29ya3MhIQ==","contentTopic":"/myapp/1/latest/proto","version":0,"timestamp":1766809679837163118,"ephemeral":false,"proof":""}]'
2025-12-27 04:27:59.948 DEBUG [src.steps.sharding] Checking that peer NODE_2:wakuorg/nwaku:latest can find the published message
2025-12-27 04:27:59.948 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:32198/relay/v1/auto/messages/%2Fmyapp%2F1%2Flatest%2Fproto" -H "Content-Type: application/json" -d 'None'
2025-12-27 04:27:59.950 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'[{"payload":"U2hhcmRpbmcgd29ya3MhIQ==","contentTopic":"/myapp/1/latest/proto","version":0,"timestamp":1766809679837163118,"ephemeral":false,"proof":""}]'
2025-12-27 04:27:59.953 DEBUG [tests.conftest] Running fixture teardown: test_setup
2025-12-27 04:27:59.954 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2025-12-27 04:27:59.954 DEBUG [src.node.waku_node] Stopping container with id 6b2325aece38
2025-12-27 04:28:00.527 DEBUG [src.node.waku_node] Container stopped.
2025-12-27 04:28:00.528 DEBUG [src.node.waku_node] Stopping container with id 61053006b361
2025-12-27 04:28:01.062 DEBUG [src.node.waku_node] Container stopped.
2025-12-27 04:28:01.063 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2025-12-27 04:28:01.068 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2025-12-27 04:28:01.075 DEBUG [src.node.docker_mananger] No errors found in the waku logs.