[24.0rc4] `--torcontrol` without `--onion` connects to wrong Tor proxy #26478

schildbach commented at 1:16 PM on November 10, 2022: contributor

Actual behavior

I'm using --torcontrol without --onion, which should be possible in 24.0. I get these errors in the log, repeated every couple of secs: connect() to 127.0.0.1:9050 failed after wait: Connection refused (111) If I use --onion=tor:9050, it works. tor is the hostname of my Tor proxy.

Expected behavior

Bitcoind to fetch the correct tor proxy address/port from the control port and use it.

System information

bitcoind 24.0rc4 (self-built Docker image), tor 0.4.7.10 (Docker image from docker.io), Docker 20.10.12 (from Ubuntu 22.04.1)

My startup log until the error occurs (Tor hidden service addresses redacted):

bitcoind_1          | Bitcoin Core version v24.0rc4 (release build)
bitcoind_1          | Using the 'x86_shani(1way,2way)' SHA256 implementation
bitcoind_1          | Using RdSeed as an additional entropy source
bitcoind_1          | Using RdRand as an additional entropy source
bitcoind_1          | Startup time: 2022-11-10T13:13:48Z
bitcoind_1          | Default data directory /home/bitcoin/.bitcoin
bitcoind_1          | Using data directory /home/bitcoin/.bitcoin
bitcoind_1          | Config file: /home/bitcoin/.bitcoin/bitcoin.conf (not found, skipping)
bitcoind_1          | Command-line arg: bind="[::]:8333"
bitcoind_1          | Command-line arg: bind="0.0.0.0:8333"
bitcoind_1          | Command-line arg: bind="[::]:8334=onion"
bitcoind_1          | Command-line arg: bind="0.0.0.0:8334=onion"
bitcoind_1          | Command-line arg: connect="redacted:8333"
bitcoind_1          | Command-line arg: debug="rpc"
bitcoind_1          | Command-line arg: debug="tor"
bitcoind_1          | Command-line arg: disablewallet="1"
bitcoind_1          | Command-line arg: discover="1"
bitcoind_1          | Command-line arg: dnsseed="0"
bitcoind_1          | Command-line arg: listen="1"
bitcoind_1          | Command-line arg: listenonion="1"
bitcoind_1          | Command-line arg: logtimestamps="0"
bitcoind_1          | Command-line arg: maxconnections="32"
bitcoind_1          | Command-line arg: mempoolexpiry="8760"
bitcoind_1          | Command-line arg: onlynet="onion"
bitcoind_1          | Command-line arg: par="2"
bitcoind_1          | Command-line arg: prune="1024"
bitcoind_1          | Command-line arg: rpcallowip="0.0.0.0"
bitcoind_1          | Command-line arg: rpcallowip="[::]"
bitcoind_1          | Command-line arg: rpcbind=****
bitcoind_1          | Command-line arg: rpcthreads="2"
bitcoind_1          | Command-line arg: server="1"
bitcoind_1          | Command-line arg: torcontrol="tor:9051"
bitcoind_1          | Command-line arg: torpassword=****
bitcoind_1          | Using at most 32 automatic connections (1048576 file descriptors available)
bitcoind_1          | Using 16 MiB out of 16 MiB requested for signature cache, able to store 524288 elements
bitcoind_1          | Using 16 MiB out of 16 MiB requested for script execution cache, able to store 524288 elements
bitcoind_1          | Script verification uses 1 additional threads
bitcoind_1          | No wallet support compiled in!
bitcoind_1          | scheduler thread start
bitcoind_1          | WARNING: the RPC server is not safe to expose to untrusted networks such as the public internet
bitcoind_1          | [http] creating work queue of depth 16
bitcoind_1          | [rpc] Starting RPC
bitcoind_1          | [rpc] Starting HTTP RPC server
bitcoind_1          | Using random cookie authentication.
bitcoind_1          | Generated RPC authentication cookie /home/bitcoin/.bitcoin/.cookie
bitcoind_1          | [http] starting 2 worker threads
bitcoind_1          | Using /16 prefix for IP bucketing
bitcoind_1          | init message: Loading P2P addresses…
bitcoind_1          | Loaded 14239 addresses from peers.dat  27ms
bitcoind_1          | init message: Loading banlist…
bitcoind_1          | SetNetworkActive: true
bitcoind_1          | Cache configuration:
bitcoind_1          | * Using 2.0 MiB for block index database
bitcoind_1          | * Using 8.0 MiB for chain state database
bitcoind_1          | * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
bitcoind_1          | init message: Loading block index…
bitcoind_1          | Assuming ancestors of block 00000000000000000009c97098b5295f7e5f183ac811fb5d1534040adb93cabd have valid signatures.
bitcoind_1          | Setting nMinimumChainWork=00000000000000000000000000000000000000003404ba0801921119f903495e
bitcoind_1          | Prune configured to target 1024 MiB on disk for block and undo files.
bitcoind_1          | Switching active chainstate to Chainstate [ibd] @ height -1 (null)
bitcoind_1          | Opening LevelDB in /home/bitcoin/.bitcoin/blocks/index
bitcoind_1          | Opened LevelDB successfully
bitcoind_1          | Using obfuscation key for /home/bitcoin/.bitcoin/blocks/index: 0000000000000000
bitcoind_1          | LoadBlockIndexDB: last block file = 3267
bitcoind_1          | LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=102, size=124550955, heights=762330...762431, time=2022-11-08...2022-11-09)
bitcoind_1          | Checking all blk files are present...
bitcoind_1          | LoadBlockIndexDB(): Block files have previously been pruned
bitcoind_1          | Opening LevelDB in /home/bitcoin/.bitcoin/chainstate
bitcoind_1          | Opened LevelDB successfully
bitcoind_1          | Using obfuscation key for /home/bitcoin/.bitcoin/chainstate: cec422b42319b403
bitcoind_1          | Loaded best chain: hashBestChain=0000000000000000000380536903d286f9010f25b6582c80a892c3e95bf80d06 height=762431 date=2022-11-09T14:14:43Z progress=0.999689
bitcoind_1          | init message: Verifying blocks…
bitcoind_1          | Verifying last 6 blocks at level 3
bitcoind_1          | [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
bitcoind_1          | No coin database inconsistencies in last 6 blocks (11634 transactions)
bitcoind_1          |  block index            3243ms
bitcoind_1          | init message: Pruning blockstore…
bitcoind_1          | Leaving InitialBlockDownload (latching to false)
bitcoind_1          | block tree size = 762433
bitcoind_1          | nBestHeight = 762431
bitcoind_1          | Warning: More than one onion bind address is provided. Using [::]:8334 for the automatically created Tor onion service.
bitcoind_1          | Warning: More than one onion bind address is provided. Using [::]:8334 for the automatically created Tor onion service.
bitcoind_1          | Bound to [::]:8333
bitcoind_1          | Bound to 0.0.0.0:8333
bitcoind_1          | Bound to [::]:8334
bitcoind_1          | Bound to 0.0.0.0:8334
bitcoind_1          | init message: Starting network threads…
bitcoind_1          | loadblk thread start
bitcoind_1          | DNS seeding disabled
bitcoind_1          | torcontrol thread start
bitcoind_1          | Imported mempool transactions from disk: 0 succeeded, 0 failed, 0 expired, 0 already there, 0 waiting for initial broadcast
bitcoind_1          | loadblk thread exit
bitcoind_1          | init message: Done loading
bitcoind_1          | msghand thread start
bitcoind_1          | addcon thread start
bitcoind_1          | opencon thread start
bitcoind_1          | Cannot create socket for redacted.onion:8333: unsupported network
bitcoind_1          | net thread start
bitcoind_1          | [tor] Reading cached private key from /home/bitcoin/.bitcoin/onion_v3_private_key
bitcoind_1          | [tor] Successfully connected!
bitcoind_1          | [tor] Connected to Tor version 0.4.7.10
bitcoind_1          | [tor] Supported authentication method: HASHEDPASSWORD
bitcoind_1          | [tor] Using HASHEDPASSWORD authentication
bitcoind_1          | [tor] Authentication successful
bitcoind_1          | [tor] Get SOCKS port command yielded [::]:9050
bitcoind_1          | [tor] Configuring onion proxy for 127.0.0.1:9050
bitcoind_1          | [tor] ADD_ONION successful
bitcoind_1          | [tor] Got service ID redacted, advertising service redacted.onion:8333
bitcoind_1          | [tor] Cached service private key to /home/bitcoin/.bitcoin/onion_v3_private_key
bitcoind_1          | AddLocal(redacted.onion:8333,4)
bitcoind_1          | connect() to 127.0.0.1:9050 failed after wait: Connection refused (111)
bitcoind_1          | connect() to 127.0.0.1:9050 failed after wait: Connection refused (111)

schildbach added the label Bug on Nov 10, 2022

schildbach commented at 1:20 PM on November 10, 2022: contributor

For reference, the issue that was reportedly fixed in 24.0 is:

#24980 (via https://github.com/bitcoin-core/gui/commit/2d0b4e4ff66e60c85f86c526a53f8fb242ebb7d0)

maflcko added this to the milestone 24.0 on Nov 10, 2022

maflcko added the label P2P on Nov 10, 2022

schildbach commented at 1:58 PM on November 10, 2022: contributor

Ok, I must admit I overlooked the line Get SOCKS port command yielded [::]:9050 in the log. Seems like bitcoind is getting the wrong proxy IP from the control port.

Investigating, I'll report back…

schildbach commented at 3:43 PM on November 10, 2022: contributor

I fixed this in my Tor config. I replaced my previous SocksPort configuration

SocksPort 0.0.0.0:${TOR_SOCKS_PORT} SocksPort [::]:${TOR_SOCKS_PORT}

with

SocksPort tor:${TOR_SOCKS_PORT}

(again, tor being the hostname of my tor container)

It would be nice if Tor would allow to bind the proxy to any network (like in my previous config), but still yielded a non-localhost address via control port, especially if the request comes from non-localhost (maybe aided by another configuration option). I'll probably open a feature request there.

Anyway, I'll close this as it's clearly not an issue with bitcoind.

schildbach closed this on Nov 10, 2022

vasild commented at 6:19 PM on November 10, 2022: contributor

[tor] Get SOCKS port command yielded [::]:9050 [tor] Configuring onion proxy for 127.0.0.1:9050

A bit unrelated, but how come [::]:9050 got converted to 127.0.0.1:9050? This means that here:

https://github.com/bitcoin/bitcoin/blob/9dce30194bc07463d634072251a8bf83e1b10ff9/src/torcontrol.cpp#L361-L383

LookupNumeric("[::]:9050") must have returned an invalid result, but it should not and there is a test for that:

https://github.com/bitcoin/bitcoin/blob/9dce30194bc07463d634072251a8bf83e1b10ff9/src/test/netbase_tests.cpp#L143

Anyway, if you have more than one SocksPort in torrc does the tor daemon deterministically return always the first or the last one? If yes, then maybe a workaround is to use something like:

SOCKSPort 0.0.0.0:9050
SOCKSPort 10.0.0.1:9050

schildbach commented at 8:13 PM on November 10, 2022: contributor

@vasild Good idea with the workaround, but get this error with tor if I try:

[warn] Failed to parse/validate config: Failed to bind one of the listener ports.

This is probably expected, as in your example 10.0.0.1 is a subset of 0.0.0.0.

I can't tell about your other finding, it's probably a bug? I'd expect bitcoind to manage the proxy address fully automatic if I use a control port.

schildbach commented at 8:26 PM on November 10, 2022: contributor

Shall we open a new issue about the wrong [::] conversion?

vasild commented at 10:13 AM on November 11, 2022: contributor

Yes, listing both 0.0.0.0 and 10.0.0.1 is too naive :( looks like the only option is to list all addresses explicitly instead of 0.0.0.0 and figure out if it deterministically returns e.g. the first one.

I see now how [::]:9050 gets flipped to 127.0.0.1 - on line 377 above, [::] is considered an invalid address by IsValid(), so // Fallback to old behaviour happens. This is actually ok, because we wouldn't be able to connect to [::]:9050. Tor shouldn't really be returning that.

schildbach commented at 12:00 PM on November 11, 2022: contributor

I'm glad you found out what caused the replacement to 127.0.0.1.

I've opened an issue with tor about an additional option to return a more sensible result in such case:

https://gitlab.torproject.org/tpo/core/tor/-/issues/40714

bitcoin locked this on Nov 11, 2023