search

0KnowledgeNetwork / opt

Zero Knowledge Network's mixnet server plugins and client apps
GNU Affero General Public License v3.0
2 stars 1 forks source link

Make it work with client2 #37

Closed david415 closed 1 month ago

xendarboh commented 2 months ago

walletshield clients do not get a response.

servicenode says:

19:43:48.335 DEBU provider: Dropping packet: 21 because recipient 2b77616c6c6574736869656c6400000000000000000000000000000000000000 is not found

mor logs... walletshield output: ``` 19:43:26.306 DEBU katzenpost/client2: Start daemon 19:43:26.307 INFO katzenpost/client2: Katzenpost is still pre-alpha. DO NOT DEPEND ON IT FOR STRONG SECURITY OR ANONYMITY. 19:43:26.306 DEBU client2/listener: Listener worker begin 19:43:26.307 DEBU client2/conn: newConnection 19:43:26.307 INFO client2/listener: Listening on: 127.0.0.1:64331 19:43:26.307 DEBU client2/pki: start 19:43:26.307 DEBU client2/conn: start 19:43:26.307 DEBU client2/conn: connectWorker begin 19:43:26.307 DEBU client2/conn: doConnect begin 19:43:26.307 DEBU client2/conn: getDescriptor 19:43:26.307 DEBU client2/pki: worker 19:43:26.307 DEBU client2/pki: getDocument 19:43:26.307 DEBU client2/pki: Fetching PKI doc for epoch 1911471 from Provider. 19:43:26.307 DEBU client2/pki: getDocument 19:43:26.307 DEBU client2/conn: getConsensus 19:43:26.307 DEBU client2/pki: Fetching PKI doc for epoch 1911471 from Provider. 19:43:26.307 DEBU client2/conn: getConsensus 19:43:26.307 INFO client2/pki: Failed to fetch PKI doc for epoch 1911471 from Provider: client/conn: not connected to the Gateway 19:43:26.307 WARN client2/pki: Failed to fetch PKI for epoch 1911471: client/conn: not connected to the Gateway 19:43:26.307 ERRO katzenpost/client2: WaitForCurrentDocument failed on updateDocument with err: client/conn: not connected to the Gateway 19:43:26.307 DEBU client2/conn: No PKI document for current epoch or cached PKI document provide. 19:43:26.307 INFO client2/pki: Failed to fetch PKI doc for epoch 1911471 from Provider: client/conn: not connected to the Gateway 19:43:26.307 WARN client2/pki: Failed to fetch PKI for epoch 1911471: client/conn: not connected to the Gateway 19:43:26.307 WARN client2/pki: Failed to fetch PKI for epoch 1911471: client/conn: not connected to the Gateway 19:43:26.307 DEBU client2/pki: getDocument 19:43:26.307 DEBU client2/pki: Fetching PKI doc for epoch 1911472 from Provider. 19:43:26.307 DEBU client2/conn: getConsensus 19:43:26.307 DEBU client2/conn: doConnect, got descriptor {gateway1 6e125fdbf611f6a1f8e49b77408d20e93eba5e905d623144313646c02ecfe67d map[http:[http://127.0.0.1:30004] tcp:[tcp://127.0.0.1:30005]]} 19:43:26.307 INFO client2/pki: Failed to fetch PKI doc for epoch 1911472 from Provider: client/conn: not connected to the Gateway 19:43:26.307 DEBU client2/conn: doConnect, before for loop 19:43:26.307 WARN client2/pki: Failed to fetch PKI for epoch 1911472: client/conn: not connected to the Gateway 19:43:26.307 WARN client2/pki: Failed to fetch PKI for epoch 1911472: client/conn: not connected to the Gateway 19:43:26.307 DEBU client2/conn: Dialing: tcp://127.0.0.1:30005 19:43:26.307 DEBU client2/conn: TCP connection established. 19:43:26.307 DEBU client2/conn: onNetConn begin 19:43:26.307 DEBU client2/conn: onNetConn: GenerateKeypair 19:43:26.308 DEBU client2/conn: onNetConn: NewSession 19:43:26.308 DEBU client2/conn: onTCPConn: before handshake 19:43:26.312 DEBU client2/conn: onTCPConn: Handshake completed. 19:43:26.312 DEBU client2/pki: New clock skew: 0 sec 19:43:26.312 DEBU client2/conn: onNetConn end 19:43:26.312 DEBU client2/conn: onWireConn 19:43:26.312 INFO client2/conn: onConnStatusChange 19:43:26.313 DEBU client2/pki: getDocument 19:43:26.313 DEBU client2/pki: Fetching PKI doc for epoch 1911471 from Provider. 19:43:26.313 DEBU client2/conn: getConsensus 19:43:26.313 DEBU client2/conn: Enqueued GetConsensus command for send. 19:43:26.313 DEBU client2/conn: Received Consensus: ErrorCode: 0, Payload 9066 bytes 19:43:26.314 DEBU client2/pki: getDocument 19:43:26.314 DEBU client2/pki: Fetching PKI doc for epoch 1911472 from Provider. 19:43:26.314 DEBU client2/conn: getConsensus 19:43:26.314 DEBU client2/conn: Enqueued GetConsensus command for send. 19:43:26.314 DEBU client2/conn: Received Consensus: ErrorCode: 0, Payload 9066 bytes 19:43:29.307 DEBU thinclient: Dial begin 19:43:29.308 DEBU thinclient: Waiting for a connection status message 19:43:29.308 DEBU client2/listener: Accepted new connection: 127.0.0.1:52078 19:43:29.308 DEBU client2/listener: onNewConn begin 19:43:29.308 DEBU client2/incomingConn: New incoming connection. Remote addr: 127.0.0.1:52078 assigned App ID: 486f1122fe9f7deb947ad8fe78fccb4b 19:43:29.308 DEBU client2/listener: get connection status 19:43:29.308 DEBU client2/listener: send connection status 19:43:29.308 DEBU client2/listener: getting current pki doc 19:43:29.308 DEBU client2/listener: send pki doc 19:43:29.308 DEBU client2/listener: onNewConn end 19:43:29.308 DEBU client2/incomingConn: STARTING incomingConn 19:43:29.308 DEBU client2/incomingConn: SEND TO THIN CLIENT THREAD 19:43:29.309 DEBU client2/incomingConn: sendResponse BEFORE conn.Write 19:43:29.308 DEBU client2/incomingConn: recvRequest TCP 19:43:29.309 DEBU client2/incomingConn: sendResponse AFTER conn.Write 19:43:29.309 DEBU client2/incomingConn: AFTER sendResponse 19:43:29.309 DEBU client2/incomingConn: SEND TO THIN CLIENT THREAD 19:43:29.309 DEBU client2/incomingConn: sendResponse BEFORE conn.Write 19:43:29.309 DEBU client2/incomingConn: sendResponse AFTER conn.Write 19:43:29.309 DEBU client2/incomingConn: AFTER sendResponse 19:43:29.309 DEBU thinclient: Waiting for a PKI doc message 19:43:29.309 DEBU thinclient: Dial end 19:43:29.310 DEBU thinclient: STARTING eventSinkDrain INFO walletshield:: Received HTTP request for /mina/devnet DEBU walletshield:: RAW HTTP REQUEST: POST /mina/devnet HTTP/1.1 Host: localhost:7070 User-Agent: curl/7.81.0 Content-Length: 108 Accept: */* Content-Type: application/json { "query": "query ChainId { daemonStatus { chainId } }", "variables": {}, "operationName": "ChainId" } 19:43:46.910 DEBU thinclient: STOPPING eventSinkDrain 19:43:46.910 DEBU client2/incomingConn: read length prefix 19:43:46.910 DEBU client2/incomingConn: length prefix is 473 19:43:46.910 DEBU client2/incomingConn: after blob read 19:43:46.910 DEBU client2/incomingConn: before Unmarshal 19:43:46.910 DEBU client2/incomingConn: after Unmarshal 19:43:46.910 DEBU client2/incomingConn: incomingConn received message 19:43:46.910 DEBU client2/incomingConn: recvRequest TCP 19:43:46.910 INFO client2/incomingConn: Received Request from peer application. 19:43:47.606 DEBU client2/incomingConn: sendResponse BEFORE conn.Write 19:43:47.606 DEBU client2/incomingConn: sendResponse AFTER conn.Write 19:43:47.606 DEBU thinclient: MessageSentEvent 19:43:47.606 INFO thinclient: MessageSentEvent ``` Running a test, like `./tests/e2e/walletshield/test.sh /mina/devnet` does not get a response from walletshield, it just waits for it indefinitely. It's request can be seen in the logs above, then where walletshield pauses. walletshield logs continue from there: ``` 19:44:03.820 DEBU client2/incomingConn: SEND TO THIN CLIENT THREAD 19:44:03.820 DEBU client2/incomingConn: sendResponse BEFORE conn.Write 19:44:03.820 DEBU client2/incomingConn: sendResponse AFTER conn.Write 19:44:03.820 DEBU client2/incomingConn: AFTER sendResponse 19:44:03.820 DEBU thinclient: NewPKIDocumentEvent 19:44:03.821 INFO thinclient: NewPKIDocumentEvent 19:45:26.326 DEBU client2/pki: getDocument 19:45:26.326 DEBU client2/pki: Fetching PKI doc for epoch 1911473 from Provider. 19:45:26.326 DEBU client2/conn: getConsensus 19:45:26.326 DEBU client2/conn: Enqueued GetConsensus command for send. 19:45:26.326 DEBU client2/conn: Received Consensus: ErrorCode: 0, Payload 9066 bytes 19:45:26.328 DEBU client2/pki: Discarding PKI for epoch: 1911471 19:47:26.338 DEBU client2/pki: getDocument 19:47:26.339 DEBU client2/pki: Fetching PKI doc for epoch 1911474 from Provider. 19:47:26.339 DEBU client2/conn: getConsensus 19:47:26.339 DEBU client2/conn: Enqueued GetConsensus command for send. 19:47:26.340 DEBU client2/conn: Received Consensus: ErrorCode: 0, Payload 9066 bytes 19:47:26.341 DEBU client2/pki: Discarding PKI for epoch: 1911472 ``` ``` $ cat voting_mixnet/servicenode1/http_proxy*.log 19:37:01.703 DEBU http_proxy: listening to unix domain socket file: /tmp/http_proxy2457061416/41.http_proxy.socket $ tail voting_mixnet/servicenode1/katzenpost.log 19:43:15.000 NOTI pki/voting/Client: Get(ctx, 1911472) 19:43:15.014 DEBU pki/voting/client/connector: sending getConsensus to auth3 19:43:15.018 NOTI pki/voting/Client: OK, received fully signed consensus document. 19:43:15.019 DEBU pki/voting/Client: voting/Client: Get() document: &{Epoch: 1911472 GenesisEpoch: 1911470 SendRatePerMinute: 100 Mu: 0.005 MuMaxDelay: 1000 LambdaP:0.001 LambdaPMaxDelay:1000 LambdaL:0.0005 LambdaLMaxDelay:1000 LambdaD:0.0005 LambdaDMaxDelay:3000 LambdaM: 0.0005 LambdaMMaxDelay: 100 SharedRandomValue: YQ7Bg/TYi/dTJOPEi2g8sIo/rqbktQEtRW1wE8T6b1w= PriorSharedRandom: [IDtE8XeXBvu+adgWhHq5xNPqZJJRcKJbOzNBoTLkY1E=, IDtE8XeXBvu+adgWhHq5xNPqZJJRcKJbOzNBoTLkY1E=] Topology: [0]{[{mix1 cffd780da5bffd45f288a1b36086d898c9d0ec4173ce6c790b9ff3cead40673a map[http:[http://127.0.0.1:30009]]}]} [1]{[{mix2 d379c42e702075a58ffb65e6e99b1dce2e372e490d9bede7cc3d737fcab91ac5 map[http:[http://127.0.0.1:30011]]}]} [2]{[{mix3 b0b052c9e12179a0f3ed80a7f71ed1ef0eb10eec43d1caab6f71deea9a4c643a map[http:[http://127.0.0.1:30013]]}]} } GatewayNodes:[]{[{gateway1 6e125fdbf611f6a1f8e49b77408d20e93eba5e905d623144313646c02ecfe67d map[http:[http://127.0.0.1:30004] tcp4:[tcp://127.0.0.1:30005]]tofu}]}}} } ServiceNodes:[]{[{servicenode1 271bee0af72a06fc734c900fa7a0391286d62810b73b55d2c182f8eeba15a1ed map[http:[http://127.0.0.1:30007]]map[echo:map[endpoint:+echo] http:map[endpoint:+http] http_proxy:map[endpoint:http_proxy] panda:map[endpoint:+panda] pigeonhole:map[endpoint:+pigeonhole] spool:map[endpoint:+spool] testdest:map[endpoint:+testdest]]}]}}} 19:43:15.019 DEBU pki: Skipping fetch for epoch 1911469: pki: requested epoch will never get a document 19:43:15.019 DEBU pki: pki woke 1m15.019697776s into epoch 1911471 with 44.980302224s remaining 19:43:15.019 DEBU pki: After deadline for next epoch publication 19:43:15.019 DEBU pki: document cached for 1911472, reset to 44.980302224s 19:43:16.247 DEBU outgoing:1: Connection closed by peer. 19:43:16.247 DEBU outgoing:1: TCP connection closed. (wasHalted: false) 19:43:16.247 DEBU outgoing:1: Connection terminated, will reconnect. 19:43:16.247 DEBU outgoing:1: Dialing: 127.0.0.1:30009 19:43:16.250 DEBU outgoing:1: http connection established. 19:43:16.255 DEBU outgoing:1: Handshake completed. 19:43:16.265 DEBU incoming:6: Failed to receive command: timeout: no recent network activity 19:43:16.265 DEBU incoming:6: Closing. 19:43:16.268 DEBU listener:0: Accepted new connection: 127.0.0.1:49785 19:43:16.269 DEBU incoming:7: New incoming connection: 127.0.0.1:49785 19:43:16.272 DEBU incoming:7: Handshake completed. 19:43:16.272 DEBU incoming:7: Peer: 'b0b052c9e12179a0f3ed80a7f71ed1ef0eb10eec43d1caab6f71deea9a4c643a' (021bc968a458f8b284b031171622e2bbc6dc4ee3392fe4076a77efef3bca6ec9) 19:43:46.255 DEBU outgoing:1: Connection closed by peer. 19:43:46.255 DEBU outgoing:1: TCP connection closed. (wasHalted: false) 19:43:46.255 DEBU outgoing:1: Connection terminated, will reconnect. 19:43:46.255 DEBU outgoing:1: Dialing: 127.0.0.1:30009 19:43:46.259 DEBU outgoing:1: http connection established. 19:43:46.264 DEBU outgoing:1: Handshake completed. 19:43:46.376 DEBU incoming:7: Failed to receive command: timeout: no recent network activity 19:43:46.377 DEBU incoming:7: Closing. 19:43:46.407 DEBU listener:0: Accepted new connection: 127.0.0.1:39920 19:43:46.407 DEBU incoming:8: New incoming connection: 127.0.0.1:39920 19:43:46.412 DEBU incoming:8: Handshake completed. 19:43:46.412 DEBU incoming:8: Peer: 'b0b052c9e12179a0f3ed80a7f71ed1ef0eb10eec43d1caab6f71deea9a4c643a' (021bc968a458f8b284b031171622e2bbc6dc4ee3392fe4076a77efef3bca6ec9) 19:43:48.334 DEBU incoming:8: Handing off packet: 21 19:43:48.334 DEBU crypto:9: Packet: 21 (Unwrap queue delay: 12.87µs) 19:43:48.334 DEBU crypto:9: Attempting to unwrap packet: 21 19:43:48.334 DEBU crypto:9: Packet: 21 (Unwrap took: 596.194µs) 19:43:48.335 DEBU crypto:9: Packet: 21 (IsReplay took: 112.898µs) 19:43:48.335 DEBU crypto:9: Packet: 21 (doUnwrap took: 766.201µs) 19:43:48.335 DEBU crypto:9: Handing off service destined packet: 21 19:43:48.335 DEBU provider: Dropping packet: 21 because recipient 2b77616c6c6574736869656c6400000000000000000000000000000000000000 is not found 19:44:00.000 DEBU pki: Within the publication time for epoch: 1911473 ```
mixmasala commented 2 months ago

I checked out opt branch use_client2 08efdb5a0748c87ba9e80579bc925e485408b3ed The error message about recipient "2b77616c6c6574736869656c6400000000000000000000000000000000000000" not found:

python3 -c 'print(bytes.fromhex("2b77616c6c6574736869656c6400000000000000000000000000000000000000"))'
b'+walletshield\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'

but there isn't a configuration generated with an endpoint by that name ("+walletshield").

diff --git a/docker/Makefile b/docker/Makefile
index 41d0e0e..80bee8c 100644
--- a/docker/Makefile
+++ b/docker/Makefile
@@ -32,8 +32,8 @@ export

 define SERVICENODE_PLUGINS
   [[ServiceNode.CBORPluginKaetzchen]]
-    Capability = "http_proxy"
-    Endpoint = "http_proxy"
+    Capability = "walletshield"
+    Endpoint = "+walletshield"
     Command = "/$(net_name)/http_proxy.$(distro)"
     MaxConcurrency = 1
     Disable = false

This might do what you want. Note that kaetzchen services should have a "+" prefix in their Endpoint.

xendarboh commented 2 months ago

Endpoint is now working, however does not currently have "+" prefix.

That python snippet is handy, thanks!

david415 commented 2 months ago

Endpoint is now working, however does not currently have "+" prefix.

That python snippet is handy, thanks!

let's just not put "+" in the name of anything. that was a historical thing. Yawning was being cute and making the configs look like a sendmail.cfg or something.