logos-messaging-interop-tests/nim/1069/data/attachments/a2dcf120a77abd71.txt

2026-02-04 17:15:01.349 DEBUG [tests.conftest] Running fixture setup: test_id
2026-02-04 17:15:01.350 DEBUG [tests.conftest] Running test: test_store_with_non_hex_characters_in_hash with id: 2026-02-04_17-15-01__adbdf658-0b04-4c0a-a4ed-1ca86921f9fd
2026-02-04 17:15:01.350 DEBUG [src.steps.common] Running fixture setup: common_setup
2026-02-04 17:15:01.350 DEBUG [src.steps.store] Running fixture setup: store_setup
2026-02-04 17:15:01.350 DEBUG [src.steps.store] Running fixture setup: node_setup
2026-02-04 17:15:01.357 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-02-04 17:15:01.357 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/publishing_node1_2026-02-04_17-15-01__adbdf658-0b04-4c0a-a4ed-1ca86921f9fd__wakuorg_nwaku:latest.log
2026-02-04 17:15:01.358 DEBUG [src.node.waku_node] Starting Node...
2026-02-04 17:15:01.358 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-02-04 17:15:01.359 DEBUG [src.node.docker_mananger] Network waku already exists
2026-02-04 17:15:01.359 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.214.15
2026-02-04 17:15:01.359 DEBUG [src.node.docker_mananger] Generated ports ['65189', '65190', '65191', '65192', '65193']
2026-02-04 17:15:01.359 DEBUG [src.node.waku_node] RLN credentials were not set
2026-02-04 17:15:01.360 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-02-04 17:15:01.360 DEBUG [src.node.waku_node] Using volumes []
2026-02-04 17:15:01.360 DEBUG [src.node.docker_mananger] docker run -i -t -p 65189:65189 -p 65190:65190 -p 65191:65191 -p 65192:65192 -p 65193:65193 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=65191 --rest-port=65189 --tcp-port=65190 --discv5-udp-port=65192 --rest-address=0.0.0.0 --nat=extip:172.18.214.15 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=9a9bdddf5aba5fab4df158b9ebcffbdbbab5a8af513ee9e3d9baf1c9d104f530 --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=65193 --metrics-logging=true --store=true --relay=true
2026-02-04 17:15:01.540 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.214.15 waku ada556c677085209939b015f6ffa1a4d92f670ffa68a49b0b6206f06d58d42c7
2026-02-04 17:15:01.572 DEBUG [src.node.docker_mananger] Container started with ID ada556c67708. Setting up logs at ./log/docker/publishing_node1_2026-02-04_17-15-01__adbdf658-0b04-4c0a-a4ed-1ca86921f9fd__wakuorg_nwaku:latest.log
2026-02-04 17:15:01.573 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 65189
2026-02-04 17:15:01.574 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-02-04 17:15:01.612 ERROR [src.node.docker_mananger] Max retries reached for container 23ac6b30dc81. Exiting log stream.
2026-02-04 17:15:02.152 ERROR [src.node.docker_mananger] Max retries reached for container dab8191d3728. Exiting log stream.
2026-02-04 17:15:02.576 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:65189/health" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:02.579 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":"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"}]}'
2026-02-04 17:15:02.579 INFO [src.node.waku_node] Node protocols are initialized !!
2026-02-04 17:15:02.580 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:65189/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:02.582 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.214.15/tcp/65190/p2p/16Uiu2HAmHw4c3izh3xCVQAxhaLRE2H9WjMaVNpFBSuqx5CVR4PxP","/ip4/172.18.214.15/tcp/65191/ws/p2p/16Uiu2HAmHw4c3izh3xCVQAxhaLRE2H9WjMaVNpFBSuqx5CVR4PxP"],"enrUri":"enr:-L24QI_0g4z15J-kagdFPknPGZjdGPWu84ESyXe0Pf9zh5cWISK6PMzSe2616C34B0BJnmq6I9XVEgzkFZyxwPANXakCgmlkgnY0gmlwhKwS1g-KbXVsdGlhZGRyc5YACASsEtYPBv6mAAoErBLWDwb-p90DgnJzhQADAQAAiXNlY3AyNTZrMaEDTmiJwJp4y9CoatE_wZSfpjOhcAInroeWf3U8U0QT0NyDdGNwgv6mg3VkcIL-qIV3YWt1MgM"}'
2026-02-04 17:15:02.582 INFO [src.node.waku_node] REST service is ready !!
2026-02-04 17:15:02.589 DEBUG [src.node.docker_mananger] Docker client initialized with image wakuorg/nwaku:latest
2026-02-04 17:15:02.589 DEBUG [src.node.waku_node] WakuNode instance initialized with log path ./log/docker/store_node1_2026-02-04_17-15-01__adbdf658-0b04-4c0a-a4ed-1ca86921f9fd__wakuorg_nwaku:latest.log
2026-02-04 17:15:02.589 DEBUG [src.node.waku_node] Starting Node...
2026-02-04 17:15:02.589 DEBUG [src.node.docker_mananger] Attempting to create or retrieve network waku
2026-02-04 17:15:02.591 DEBUG [src.node.docker_mananger] Network waku already exists
2026-02-04 17:15:02.591 DEBUG [src.node.docker_mananger] Generated random external IP 172.18.56.136
2026-02-04 17:15:02.591 DEBUG [src.node.docker_mananger] Generated ports ['39204', '39205', '39206', '39207', '39208']
2026-02-04 17:15:02.591 DEBUG [src.node.waku_node] RLN credentials were not set
2026-02-04 17:15:02.591 INFO [src.node.waku_node] RLN credentials not set or credential store not available, starting without RLN
2026-02-04 17:15:02.591 DEBUG [src.node.waku_node] Using volumes []
2026-02-04 17:15:02.592 DEBUG [src.node.docker_mananger] docker run -i -t -p 39204:39204 -p 39205:39205 -p 39206:39206 -p 39207:39207 -p 39208:39208 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=39206 --rest-port=39204 --tcp-port=39205 --discv5-udp-port=39207 --rest-address=0.0.0.0 --nat=extip:172.18.56.136 --peer-exchange=true --discv5-discovery=true --cluster-id=3 --nodekey=0a1fc6b0888cacafd1feada8715c93ccdc74b9dbbb1be91ff665237213ad68bb --shard=0 --metrics-server=true --metrics-server-address=0.0.0.0 --metrics-server-port=39208 --metrics-logging=true --discv5-bootstrap-node=enr:-L24QI_0g4z15J-kagdFPknPGZjdGPWu84ESyXe0Pf9zh5cWISK6PMzSe2616C34B0BJnmq6I9XVEgzkFZyxwPANXakCgmlkgnY0gmlwhKwS1g-KbXVsdGlhZGRyc5YACASsEtYPBv6mAAoErBLWDwb-p90DgnJzhQADAQAAiXNlY3AyNTZrMaEDTmiJwJp4y9CoatE_wZSfpjOhcAInroeWf3U8U0QT0NyDdGNwgv6mg3VkcIL-qIV3YWt1MgM --storenode=/ip4/172.18.214.15/tcp/65190/p2p/16Uiu2HAmHw4c3izh3xCVQAxhaLRE2H9WjMaVNpFBSuqx5CVR4PxP --store=true --relay=true
2026-02-04 17:15:02.778 DEBUG [src.node.docker_mananger] docker network connect --ip 172.18.56.136 waku 9dd65765f2030cd2fe475fcc90abe9bc831d9cc8cd586dcb726b09753e751679
2026-02-04 17:15:02.811 DEBUG [src.node.docker_mananger] Container started with ID 9dd65765f203. Setting up logs at ./log/docker/store_node1_2026-02-04_17-15-01__adbdf658-0b04-4c0a-a4ed-1ca86921f9fd__wakuorg_nwaku:latest.log
2026-02-04 17:15:02.812 DEBUG [src.node.waku_node] Started container from image wakuorg/nwaku:latest. REST: 39204
2026-02-04 17:15:02.813 DEBUG [src.libs.common] Sleeping for 1 seconds
2026-02-04 17:15:03.813 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:39204/health" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:03.818 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"nodeHealth":"READY","protocolsHealth":[{"Relay":"READY"},{"Rln Relay":"NOT_MOUNTED"},{"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":"READY"},{"Filter Client":"NOT_READY","desc":"No Filter service peer available yet"}]}'
2026-02-04 17:15:03.818 INFO [src.node.waku_node] Node protocols are initialized !!
2026-02-04 17:15:03.818 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:39204/debug/v1/info" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:03.821 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'{"listenAddresses":["/ip4/172.18.56.136/tcp/39205/p2p/16Uiu2HAmUT9bgGx4BVYQFE6KC3ytQD6VvKV4PQg8wXJXxCruxg7f","/ip4/172.18.56.136/tcp/39206/ws/p2p/16Uiu2HAmUT9bgGx4BVYQFE6KC3ytQD6VvKV4PQg8wXJXxCruxg7f"],"enrUri":"enr:-L24QBMJYiWGLdGODvWQe7aHy8RAd-i0WDcarKHO8Pn_GwQ0Mb-CL_8Azxe3cqG1VfTxIpFsnlu_XnTd-UbNtjEZ2IACgmlkgnY0gmlwhKwSOIiKbXVsdGlhZGRyc5YACASsEjiIBpklAAoErBI4iAaZJt0DgnJzhQADAQAAiXNlY3AyNTZrMaED6rJ6Wj5rv66QO1xVwMPj83KXpnwOmbHnGaeYVIL7obaDdGNwgpklg3VkcIKZJ4V3YWt1MgM"}'
2026-02-04 17:15:03.821 INFO [src.node.waku_node] REST service is ready !!
2026-02-04 17:15:03.821 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:39204/admin/v1/peers" -H "Content-Type: application/json" -d '["/ip4/172.18.214.15/tcp/65190/p2p/16Uiu2HAmHw4c3izh3xCVQAxhaLRE2H9WjMaVNpFBSuqx5CVR4PxP"]'
2026-02-04 17:15:03.824 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:03.824 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:65189/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2026-02-04 17:15:03.827 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:03.827 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:39204/relay/v1/subscriptions" -H "Content-Type: application/json" -d '["/waku/2/rs/3/0"]'
2026-02-04 17:15:03.829 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:03.830 DEBUG [src.steps.store] Relaying message
2026-02-04 17:15:03.830 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:65189/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "TWVzc2FnZV8w", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2026-02-04 17:15:03.835 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:03.836 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-02-04 17:15:04.037 DEBUG [src.steps.store] Relaying message
2026-02-04 17:15:04.038 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:65189/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "TWVzc2FnZV8x", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2026-02-04 17:15:04.044 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:04.044 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-02-04 17:15:04.245 DEBUG [src.steps.store] Relaying message
2026-02-04 17:15:04.245 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:65189/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "TWVzc2FnZV8y", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2026-02-04 17:15:04.251 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:04.251 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-02-04 17:15:04.452 DEBUG [src.steps.store] Relaying message
2026-02-04 17:15:04.453 INFO [src.node.api_clients.base_client] curl -v -X POST "http://127.0.0.1:65189/relay/v1/messages/%2Fwaku%2F2%2Frs%2F3%2F0" -H "Content-Type: application/json" -d '{"payload": "TWVzc2FnZV8z", "contentTopic": "/myapp/1/latest/proto", "timestamp": '$(date +%s%N)'}'
2026-02-04 17:15:04.459 INFO [src.node.api_clients.base_client] Response status code: 200. Response content: b'OK'
2026-02-04 17:15:04.459 DEBUG [src.libs.common] Sleeping for 0.2 seconds
2026-02-04 17:15:04.660 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:65189/store/v3/messages?hashes=%23%23%23%20INVALID%20HASH%20%23%23%23&pageSize=50&ascending=true" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:04.663 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:65189/store/v3/messages?hashes=%23%23%23%20INVALID%20HASH%20%23%23%23&pageSize=50&ascending=true. Response content: b'Exception converting hex string to bytes: # is not a hexadecimal character'
2026-02-04 17:15:04.663 INFO [src.node.api_clients.base_client] curl -v -X GET "http://127.0.0.1:39204/store/v3/messages?hashes=%23%23%23%20INVALID%20HASH%20%23%23%23&pageSize=50&ascending=true" -H "Content-Type: application/json" -d 'None'
2026-02-04 17:15:04.665 ERROR [src.node.api_clients.base_client] HTTP error occurred: 400 Client Error: Bad Request for url: http://127.0.0.1:39204/store/v3/messages?hashes=%23%23%23%20INVALID%20HASH%20%23%23%23&pageSize=50&ascending=true. Response content: b'Exception converting hex string to bytes: # is not a hexadecimal character'
2026-02-04 17:15:04.667 DEBUG [tests.conftest] Running fixture teardown: test_setup
2026-02-04 17:15:04.669 DEBUG [tests.conftest] Running fixture teardown: close_open_nodes
2026-02-04 17:15:04.669 DEBUG [src.node.waku_node] Stopping container with id ada556c67708
2026-02-04 17:15:05.220 DEBUG [src.node.waku_node] Container stopped.
2026-02-04 17:15:05.222 DEBUG [src.node.waku_node] Stopping container with id 9dd65765f203
2026-02-04 17:15:05.783 DEBUG [src.node.waku_node] Container stopped.
2026-02-04 17:15:05.784 DEBUG [tests.conftest] Running fixture teardown: check_waku_log_errors
2026-02-04 17:15:05.798 DEBUG [src.node.docker_mananger] No errors found in the waku logs.
2026-02-04 17:15:05.804 DEBUG [src.node.docker_mananger] No errors found in the waku logs.