2026-04-22 15:08:14 +00:00

110 lines
18 KiB
Plaintext

2026-04-22 14:46:01.562 DEBUG [tests.conftest] Running fixture setup: test_id
2026-04-22 14:46:01.563 DEBUG [tests.conftest] Running test: test_sync_flags_node2_start_later with id: 2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d
2026-04-22 14:46:01.563 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-04-22 14:46:01.570 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 14:46:01.571 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node1_2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d__wakuorg_nwaku:latest.log
2026-04-22 14:46:01.576 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 14:46:01.576 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node2_2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d__wakuorg_nwaku:latest.log
2026-04-22 14:46:01.582 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-04-22 14:46:01.582 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/node3_2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d__wakuorg_nwaku:latest.log
2026-04-22 14:46:01.583 DEBUG [src.steps.store] Running fixture setup: store_setup
2026-04-22 14:46:01.583 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 14:46:01.583 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 14:46:01.585 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 14:46:01.585 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.154.113
2026-04-22 14:46:01.585 DEBUG [src.node.docker_mananger] Generated ports ['58166', '58167', '58168', '58169', '58170']
2026-04-22 14:46:01.585 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 14:46:01.585 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 14:46:01.585 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 14:46:01.586 DEBUG [src.node.docker_mananger] docker run -i -t -p 58166:58166 -p 58167:58167 -p 58168:58168 -p 58169:58169 -p 58170:58170 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=58168 --rest-port=58166 --tcp-port=58167 --discv5-udp-port=58169 --rest-address=0.0.0.0 --nat=extip:172.18.154.113 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=29ccef5967cb63ba23fa272dabf367d0fafbc53de10b2fdc42dd8f14a54a307b --store-sync=true --store=true --store-sync-range=45 --store-sync-interval=10 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=58170 --metrics-logging=true --store-sync-relay-jitter=0 --relay=true
2026-04-22 14:46:01.774 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.154.113 waku 90664dc3a59b6618e709a99e8d29ded11fa6e285657d1e351965c23ab1f0d925
2026-04-22 14:46:01.812 DEBUG [src.node.docker_mananger] Container started with ID 90664dc3a59b. Setting up logs at ./log/docker/node1_2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d__wakuorg_nwaku:latest.log
2026-04-22 14:46:01.812 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 58166
2026-04-22 14:46:01.813 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 14:46:01.859 ERROR [src.node.docker_mananger] Max retries reached for container d5ebb53b937f. Exiting log stream.
2026-04-22 14:46:02.355 ERROR [src.node.docker_mananger] Max retries reached for container 928d0f03bc34. Exiting log stream.
2026-04-22 14:46:02.813 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:58166/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 14:46:02.816 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"},{"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"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 14:46:02.816 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 14:46:02.817 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:58166/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 14:46:02.819 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.154.113/tcp/58167/p2p/16Uiu2HAm2DAiHYcrckBpcDqKsdQ9REb5SijNJRCsyWrjP3CW6Pv3","/ip4/172.18.154.113/tcp/58168/ws/p2p/16Uiu2HAm2DAiHYcrckBpcDqKsdQ9REb5SijNJRCsyWrjP3CW6Pv3"],"enrUri":"enr:-L24QMnk1wDwLY1G_460Gn-bgsOERjtKuMEgewhdQHLkrlbPUaANzZuP656LHx37LtveDOoc3xYRVASTuzMFOoNZm34CgmlkgnY0gmlwhKwSmnGKbXVsdGlhZGRyc5YACASsEppxBuM3AAoErBKacQbjON0DgnJzhQDGAQAAiXNlY3AyNTZrMaECZM2-_XlOm16bWCjxec6i0Sco47b5sU314KBjSsvKhBSDdGNwguM3g3VkcILjOYV3YWt1MhM"}'
2026-04-22 14:46:02.819 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 14:46:02.820 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/198/0"]'
2026-04-22 14:46:02.822 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:02.823 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:02.823 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:02.827 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:02.827 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:03.027 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:03.028 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:03.032 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:03.032 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:03.232 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:03.233 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:03.237 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:03.237 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:03.438 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:03.438 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:03.442 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:03.442 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:03.643 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:03.643 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:03.647 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:03.647 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:03.848 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:03.848 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:03.852 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:03.852 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:04.053 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:04.053 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:04.058 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:04.058 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:04.258 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:04.258 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:04.263 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:04.263 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:04.463 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:04.464 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:04.468 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:04.468 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:04.669 DEBUG [src.steps.store] Relaying message
2026-04-22 14:46:04.669 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:58166/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-04-22 14:46:04.673 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:04.674 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-04-22 14:46:04.874 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 14:46:05.874 DEBUG [src.node.waku_node] Starting Node...
2026-04-22 14:46:05.875 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-04-22 14:46:05.876 DEBUG [src.node.docker_mananger] Network waku already exists
2026-04-22 14:46:05.877 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.87.215
2026-04-22 14:46:05.877 DEBUG [src.node.docker_mananger] Generated ports ['33079', '33080', '33081', '33082', '33083']
2026-04-22 14:46:05.877 DEBUG [src.node.waku_node] RLN credentials were not set
2026-04-22 14:46:05.877 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-04-22 14:46:05.877 DEBUG [src.node.waku_node] Using volumes []
2026-04-22 14:46:05.877 DEBUG [src.node.docker_mananger] docker run -i -t -p 33079:33079 -p 33080:33080 -p 33081:33081 -p 33082:33082 -p 33083:33083 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=33081 --rest-port=33079 --tcp-port=33080 --discv5-udp-port=33082 --rest-address=0.0.0.0 --nat=extip:172.18.87.215 --peer-exchange=true --discv5-discovery=true --cluster-id=198 --nodekey=0e0d85bf730d0bf17c0bab8c45bd8e3fa41dd2d56d8ea4d7f80cf0ae5e0bcabc --store-sync=true --store=true --store-sync-range=45 --store-sync-interval=10 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=33083 --metrics-logging=true --store-sync-relay-jitter=0 --relay=false --discv5-bootstrap-node=enr:-L24QMnk1wDwLY1G_460Gn-bgsOERjtKuMEgewhdQHLkrlbPUaANzZuP656LHx37LtveDOoc3xYRVASTuzMFOoNZm34CgmlkgnY0gmlwhKwSmnGKbXVsdGlhZGRyc5YACASsEppxBuM3AAoErBKacQbjON0DgnJzhQDGAQAAiXNlY3AyNTZrMaECZM2-_XlOm16bWCjxec6i0Sco47b5sU314KBjSsvKhBSDdGNwguM3g3VkcILjOYV3YWt1MhM
2026-04-22 14:46:06.071 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.87.215 waku cd6d3f4ac5edb739be32492251cc5a7290baae40326b8cafa2d02fec92cf9c0d
2026-04-22 14:46:06.107 DEBUG [src.node.docker_mananger] Container started with ID cd6d3f4ac5ed. Setting up logs at ./log/docker/node2_2026-04-22_14-46-01__efbab7c4-4377-4f31-acab-8e97174ac51d__wakuorg_nwaku:latest.log
2026-04-22 14:46:06.107 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 33079
2026-04-22 14:46:06.107 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-04-22 14:46:07.108 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:33079/health" -H "Content-Type: application/json" -d 'None'
2026-04-22 14:46:07.111 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":"READY"},{"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"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"},{"Rln Relay":"NOT_MOUNTED"}]}'
2026-04-22 14:46:07.111 INFO [src.node.waku_node] Node protocols are initialized !!
2026-04-22 14:46:07.111 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:33079/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-04-22 14:46:07.114 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.87.215/tcp/33080/p2p/16Uiu2HAkx3rYxp4mYhh8BmES1bJ6qB9678F9J3qawJFhkw1JU3Lt","/ip4/172.18.87.215/tcp/33081/ws/p2p/16Uiu2HAkx3rYxp4mYhh8BmES1bJ6qB9678F9J3qawJFhkw1JU3Lt"],"enrUri":"enr:-L24QMOdF5d86aahvL_zH5EpmRiPTxf8uZ3D7DPngKmqfnTmeW4jIV4R94iCllpVZAmFw-yoyd94_7DK_r6oro99XfoCgmlkgnY0gmlwhKwSV9eKbXVsdGlhZGRyc5YACASsElfXBoE4AAoErBJX1waBOd0DgnJzhQDGAQAAiXNlY3AyNTZrMaECJvw8lUHePrd-0TIbkh0LVZw8xpCBUhmWaZBM0F2S7BGDdGNwgoE4g3VkcIKBOoV3YWt1MhI"}'
2026-04-22 14:46:07.114 INFO [src.node.waku_node] REST service is ready !!
2026-04-22 14:46:07.114 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:33079/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.154.113/tcp/58167/p2p/16Uiu2HAm2DAiHYcrckBpcDqKsdQ9REb5SijNJRCsyWrjP3CW6Pv3"]'
2026-04-22 14:46:07.117 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-04-22 14:46:07.117 DEBUG [src.libs.common] Sleeping for 65 seconds
2026-04-22 14:47:12.118 DEBUG [src.steps.store] Checking that peer wakuorg/nwaku:latest can find the stored messages
2026-04-22 14:47:12.119 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:33079/store/v3/messages?pubsubTopic=%2Fwaku%2F2%2Frs%2F198%2F0&pageSize=100&ascending=true" -H "Content-Type: application/json" -d 'None'
2026-04-22 14:47:12.123 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"requestId":"","statusCode":200,"statusDesc":"OK","messages":[{"messageHash":"0xf6f0595a93cca54cfcc58392513ad8ccb5a6bf019bebd083a05cbee3d30b9be5"},{"messageHash":"0xe29fe8a335ff3b1b0d313d9d0f79482d008df020a9257b1601f39868cc5c4a53"},{"messageHash":"0x7ae7653783af076461cb24f6c4b6d592454d2470e0eb484d349472a618ae534f"},{"messageHash":"0xb7f4fc6b1749b68daa0e32f46518644cf9f5ba8d49b9240139547b1854d9c2cc"},{"messageHash":"0x9099a2349a62c54d08f14ce55d00f4819556c74f217056cc33a817ae471be3a9"},{"messageHash":"0xe35cc9f1e12f8ab62d7fa1d1daf629495eb766ffa8abea4ccb2272a407be53e7"},{"messageHash":"0xfa3217f0c7d2a8a8fd2711c3b6ef98632ba2623c34662cef5d598193edbe1168"},{"messageHash":"0x78887c3ed8d18f936daadf72e865d77482c1a8c2a5233feced2cb3b9c58deadd"},{"messageHash":"0x58deb21a6a70e81170684e094f3688495f816a30fbedf6065f02c060e3a2d7ca"},{"messageHash":"0x79291fed42492517d7e992c7d9eac1392e83dff5599566fd6992474fb14c767a"}]}'
2026-04-22 14:47:12.123 DEBUG [src.steps.store] messages length is 10
2026-04-22 14:47:12.126 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-04-22 14:47:12.127 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-04-22 14:47:12.128 DEBUG [src.node.waku_node] Stopping container with id 90664dc3a59b
2026-04-22 14:47:12.633 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 14:47:12.634 DEBUG [src.node.waku_node] Stopping container with id cd6d3f4ac5ed
2026-04-22 14:47:13.130 DEBUG [src.node.waku_node] Container stopped.
2026-04-22 14:47:13.132 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-04-22 14:47:13.183 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-04-22 14:47:13.215 DEBUG [src.node.docker_mananger] No errors found in the waku logs.