Sparrow seems unable to reliably(?) connect to Whirlpool servers for remixes

[stripey679]

What do I think is happening?
I think there's an issue with Tor in Sparrow, specifically related to Whirlpool servers under some circumstances

Why do I think this?
I am able to connect to my node just fine, but I see Tor-related warnings followed by Whirlpool errors in the log file. After an initial set of whirlpool mixes, it has taken a long time and there have been no remixes.

How do I know this is a bug and not just a feature of the way Whirlpool works, as discussed in #607?
I don't. But I'm seeing some warnings in my logs that I don't find in any other issues (except #296, which seems unrelated) when I search the repository for the phrase "no Tor ControlPort configured?". I have 95 instances of "no Tor ControlPort configured?" in my log file, and they began appearing when I first started mixing with Whirlpool. I'm also seeing 83 instances of "Failed to execute request to http://[onion_address].onion" in my logs, also beginning around the time I first started using Whirlpool in Sparrow.

Do I have stack traces to share?
Yes. I think this is a representative sample:
07:22:42,362 WARN [Whirlpool-HttpClient-COORDINATOR_WEBSOCKET-CENSORED_VALUE_1] c.s.s.w.t.SparrowTorClientService [null:-1] Error connecting to localhost:9051, no Tor ControlPort configured? 08:20:05,276 ERROR [Whirlpool-HttpClient-COORDINATOR_WEBSOCKET-CENSORED_VALUE_1] c.s.w.c.m.d.MixSession[CENSORED_VALUE_3] [null:-1] ! connexion lost, reconnecting for a new mix... 08:27:12,403 ERROR [Whirlpool-HttpClient-COORDINATOR_WEBSOCKET-CENSORED_VALUE_2] c.s.w.c.m.d.MixSession[CENSORED_VALUE_3] [null:-1] ! connexion lost, reconnecting for a new mix... 08:27:42,405 ERROR [Whirlpool-HttpClient-COORDINATOR_WEBSOCKET-CENSORED_VALUE_2] o.s.w.s.s.c.SockJsClient [null:-1] Initial SockJS "Info" request to server failed, url=ws://CENSORED_VALUE_4.onion/ws/connect org.springframework.web.socket.sockjs.SockJsTransportFailureException: Failed to execute request to http://CENSORED_VALUE_4.onion/ws/connect/info; nested exception is java.lang.InterruptedException at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.JettyXhrTransport.executeRequest(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.JettyXhrTransport.executeInfoRequestInternal(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.AbstractXhrTransport.executeInfoRequest(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.SockJsClient.getServerInfo(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.SockJsClient.doHandshake(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.messaging.WebSocketStompClient.connect(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.messaging.WebSocketStompClient.connect(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.sparrowwallet.nightjar.stomp.JavaStompClient.connect(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.samourai.stomp.client.StompTransport.connect(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.samourai.whirlpool.client.mix.dialog.MixSession.connect(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.samourai.whirlpool.client.mix.dialog.MixSession$3.onTransportDisconnected(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.samourai.stomp.client.StompTransport$1.onError(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.samourai.stomp.client.StompTransport$1.onError(Unknown Source) at com.sparrowwallet.nightjar@0.2.33/com.sparrowwallet.nightjar.stomp.JavaStompClient$1.handleTransportError(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.messaging.simp.stomp.DefaultStompSession.handleFailure(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.messaging.simp.stomp.DefaultStompSession.afterConnectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.messaging.WebSocketStompClient$WebSocketTcpConnectionHandlerAdapter.afterConnectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.handler.WebSocketHandlerDecorator.afterConnectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.handler.LoggingWebSocketHandlerDecorator.afterConnectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.AbstractClientSockJsSession.afterTransportClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.sockjs.client.WebSocketTransport$ClientSockJsWebSocketHandler.afterConnectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.springframework.web.socket.adapter.jetty.JettyWebSocketHandlerAdapter.onWebSocketClose(Unknown Source) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Unknown Source) at java.base/java.lang.reflect.Method.invoke(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onClose(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.WebSocketSession.callApplicationOnClose(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.disconnect(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.websocket.common.WebSocketSession.onClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.io.AbstractConnection.onClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.io.AbstractConnection.onClose(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.io.SelectorManager.connectionClosed(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.io.ManagedSelector$DestroyEndPoint.run(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(Unknown Source) at java.base/java.lang.Thread.run(Unknown Source) Caused by: java.lang.InterruptedException: null at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(Unknown Source) at java.base/java.util.concurrent.CountDownLatch.await(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.client.util.FutureResponseListener.get(Unknown Source) at com.sparrowwallet.merged.module@1.6.6/org.eclipse.jetty.client.HttpRequest.send(Unknown Source) ... 37 common frames omitted 08:27:42,405 WARN [Whirlpool-HttpClient-COORDINATOR_WEBSOCKET-CENSORED_VALUE_2] c.s.s.w.t.SparrowTorClientService [null:-1] Error connecting to localhost:9051, no Tor ControlPort configured? 08:30:15,454 WARN [Thread-7499] c.s.s.n.TcpTransport [null:-1] No response from server, setting read timeout to 8 secs

CENSORED_VALUE_1, CENSORED_VALUE_2 are 4-digit integers indicating a websocket number
CENSORED_VALUE_3 is a large number indicating a mix session Id
CENSORED_VALUE_4 is the part of a Tor onion address that appears before the ".onion" part

The value replaced by CENSORED_VALUE_X is the same for any given X.

How prevalent is this problem?
I'm looking at logs taken over a timespan of Day X 20:44:58 to Day X+2 at 08:30:15 in my timezone.
Over that span of time,
Instances of "Error connecting to localhost:9051, no Tor ControlPort configured?": 95
Instances of "connexion lost, reconnecting for a new mix...": 29
Instances of "Initial SockJS "Info" request to server failed, url=ws://CENSORED_VALUE_4.onion/ws/connect
": 83
Instances of "Failed to execute request to http://[CENSORED_VALUE_4].onion/ws/connect/info": 83

Do I have steps to reliably reproduce this problem?
Unfortunately, no. The only hint I have is that my computer went to sleep during the initial set of mixes, which succeeded. I've also started, and stopped mixing several times, and even rebooted my computer completely. I've opened and closed Sparrow several times. One time, it froze and I had to force quit it, but I think that was an environment issue. The error appears to continue to occur until I began debugging it this morning. In the time it took me to write this issue, it did not seem to occur again, even though I had Sparrow open for an extended period of time. Nothing new was written to the log file until I closed Sparrow, and then it was just a single line about "! connexion lost, reconnecting for a new mix...", probably since I was still in mixing mode when I closed it.

How do I know it isn't just an issue with Tor on my machine?
I can't actually rule this out, but I'm able to use the Tor browser just fine. I'm also able to connect to my node from Sparrow over Tor. I'm also able to use other software which also has Tor built-in, although that software did experience some issues initially. I'm not sure if there's a possibility of multiple programs with Tor embedded into them negatively interacting with each other if they are running at the same time. I wouldn't think so, but I just don't know.

What would I like to see in terms of a resolution?
Ultimately, I just want to understand if what I'm seeing in the logs represents an actual issue, and if so, I would like to be given guidance regarding a possible fix or workaround. I would be satisfied with an explanation of what is meant by "Error connecting to localhost:9051, no Tor ControlPort configured?". Bonus points for explaining what is happening when I see "Failed to execute request to http://CENSORED_VALUE_4.onion/ws/connect/info" in the logs.

It's possible this is completely normal and there's nothing I need to do but wait (more) patiently for remixes. I just didn't want to wait too long before opening up an actual bug report, mainly due to the Tor ControlPort warning "seeming" important.

[craigraw]

Thanks for this (very) detailed report!

To resolve the no Tor ControlPort configured message, just edit your torrc and add/uncomment

ControlPort 9051

The Tor control port is used by Sparrow to request new Tor circuits for greater anonymity.

With respect to the Tor connection issues, it is possible for certain parts of the Tor network to be reachable at a certain time, while others are not. So I don't think what you're seeing is particularly unusual, as Tor regularly suffers from DDos attacks. One way to avoid Tor is to use a VPN instead, which is a reasonably private approach. Alternatively, you can configure Sparrow to use an external Tor proxy, such as the one in Tor Browser. There should be no difference, but it may give a way to test things anyway (Tor in Sparrow uses the same client code as in Tor Browser). To do this, make sure Tor Browser is running, enable the proxy in the server preferences, and configure the URL to localhost with port 9150.

I'm closing this off as I don't believe there is an issue here, but please post any findings below.

[stripey679]

I have troubleshooted and tried various things for the past 5 days, and I cannot seem to achieve stability. The Tor Browser doesn't seem to respect the ControlPort configuration. I don't know enough about networking or how Tor works to troubleshoot further. I did seem to have better luck when running Tor from the command line instead, but that could be coincidental. It's confusing and frustrating to see so many warnings and errors in the logs and not knowing which ones indicate a problem and which ones are normal and expected.

Often Sparrow seems to be unable to connect to Tor on startup. Sometimes the Test Connection button is unresponsive. Recently I've found that mixing fully stops without explanation. Once I happened to be looking at the screen when an intended mix failed (that is, when the "Registered input" bar advanced almost all the way across before going back to zero).

I hope it is not the case that my client keeps appearing as a valid candidate for mixes and then failing to sign which causes mixes to fail, but I don't know how to troubleshoot that, especially given the random nature of mixes.

It might be nice to have a way to configure the log to only write events that are actually unexpected and problematic, especially with regards to whirlpool (i.e., hide expected whirlpool errors in "normal" logging, but show them in "verbose" mode).

In conclusion, I still don't know what's going on or if there's even actually a problem. It seems like there are Tor stability issues, but I can't say if that's an Sparrow issue or an environment issue, and I don't know how to troubleshoot it.

Sorry I can't be more help.

PS:
Since I don't have any new information, I don't see a reason to re-open this issue. However, if feasible, I would definitely appreciate a link to some kind of "tested and known to work with sparrow" Tor configuration guide. Most of my poor user experience comes from just not being able to tell if and when Sparrow is playing nicely with Tor.

[craigraw]

My suggestion is to try a hosted VPN service instead of Tor. The privacy tradeoffs are a little different, but I think to all practical purposes it's private enough if you use a service without KYC (like Mullvad).

It might be nice to have a way to configure the log to only write events that are actually unexpected and problematic,

It's difficult (read: basically impossible) to tell from the client side whether an error is temporary and recoverable, or more seriously problematic. So the Whirlpool client logs the connection errors it sees as they occur. The reality is Tor is under constant and serious DDos attack. That said, I (and many others) have been able to connect to the Whirlpool server over Tor fairly stably over the last while. Sometimes it is a matter of trying different approaches (such as the VPN suggestion) to isolate the cause of the issue.