Opened 7 years ago

Closed 6 years ago

#8846 closed defect (fixed)

Useless log message when using IPv6 address on SocksPort without IPv6

Reported by: kargig Owned by:
Priority: Medium Milestone: Tor: 0.2.4.x-final
Component: Core Tor/Tor Version: Tor: 0.2.4.11-alpha
Severity: Keywords: tor-client ipv6
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I'm using TBB but with custom built tor executable, actually from git.tpo/debian/tor.git, and the log shows the following errors upon trying to visit an IPv6 address in TBB.

May 08 19:28:06.684 [Notice] Tor v0.2.4.11-alpha (git-f4f37a8fed617ffd) running on Linux with Libevent 2.0.21-stable and OpenSSL 1.0.1e.
May 08 19:28:06.684 [Notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
May 08 19:28:06.684 [Notice] This version is not a stable Tor release. Expect more bugs than usual.
May 08 19:28:06.686 [Notice] Read configuration file "XXXXXX/tor-browser_en-US/App/../Data/Tor/torrc".
May 08 19:28:06.692 [Notice] We were compiled with headers from version 2.0.19-stable of Libevent, but we're using a Libevent library that says it's version 2.0.21-stable.
May 08 19:28:06.692 [Notice] Opening Socks listener on 127.0.0.1:9150
May 08 19:28:06.692 [Notice] Opening Socks listener on 127.0.0.1:9050
May 08 19:28:06.692 [Notice] Opening Control listener on 127.0.0.1:9151
May 08 19:28:06.709 [Notice] Parsing GEOIP IPv4 file ./Data/Tor/geoip.
May 08 19:28:08.199 [Notice] Bootstrapped 5%: Connecting to directory server.
May 08 19:28:08.199 [Warning] Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Network is unreachable; NOROUTE; count 1; recommendation warn)
May 08 19:28:08.270 [Notice] Bootstrapped 10%: Finishing handshake with directory server.
May 08 19:28:08.534 [Notice] Bootstrapped 15%: Establishing an encrypted directory connection.
May 08 19:28:08.932 [Notice] New control connection opened.
May 08 19:28:08.932 [Notice] Bootstrapped 20%: Asking for networkstatus consensus.
May 08 19:28:08.932 [Notice] Bootstrapped 25%: Loading networkstatus consensus.
May 08 19:28:10.586 [Notice] Bootstrapped 45%: Asking for relay descriptors.
May 08 19:28:10.586 [Notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 2187/3501, and can only build 27% of likely paths. (We have 65% of guards bw, 64% of midpoint bw, and 66% of exit bw.)
May 08 19:28:14.205 [Notice] We now have enough directory information to build circuits.
May 08 19:28:14.205 [Notice] Bootstrapped 80%: Connecting to the Tor network.
May 08 19:28:14.205 [Notice] Bootstrapped 90%: Establishing a Tor circuit.
May 08 19:28:14.683 [Notice] Tor has successfully opened a circuit. Looks like client functionality is working.
May 08 19:28:14.684 [Notice] Bootstrapped 100%: Done.
May 08 19:33:48.508 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:48.792 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:50.516 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:50.517 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:51.515 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:51.516 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:52.313 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:33:52.363 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:54.314 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:33:57.545 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:34:00.998 [Warning] connection_ap_get_begincell_flags(): Bug: Hey; I'm about to ask a node for a connection that I am telling it to fulfil with neither IPv4 nor IPv6. That's probably not going to work.
May 08 19:34:01.535 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:36:28.511 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:36:50.612 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:37:08.202 [Notice] We tried for 15 seconds to connect to '[scrubbed]' using exit $A59E1E7C7EAEE083D756EE1FF6EC31CA3D8651D7~chaoscomputerclub19 at 31.172.30.2. Retrying on a new circuit.
May 08 19:37:09.088 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:37:34.885 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:37:48.819 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:37:57.915 [Notice] Have tried resolving or connecting to address '[scrubbed]' at 3 different places. Giving up.
May 08 19:38:35.203 [Notice] We tried for 15 seconds to connect to '[scrubbed]' using exit $43691853EA556C21A77E006886A5DC579855F527~sofia at 109.163.233.202. Retrying on a new circuit.
May 08 19:38:50.204 [Notice] We tried for 15 seconds to connect to '[scrubbed]' using exit $4F8D80A0F768A2A29856A8F26B05D35DEAA39850~wannabe at 96.47.226.19. Retrying on a new circuit.
May 08 19:39:36.202 [Notice] Tor has not observed any network activity for the past 69 seconds. Disabling circuit build timeout recording.

My torrc:
# If non-zero, try to write to disk less frequently than we would otherwise.
AvoidDiskWrites 1
# Store working data, state, keys, and caches here.
DataDirectory ./Data/Tor
GeoIPFile ./Data/Tor/geoip
# Where to send logging messages. Format is minSeverity[-maxSeverity]
# (stderr|stdout|syslog|file FILENAME).
Log notice stdout
# Bind to this address to listen to connections from SOCKS-speaking
# applications.
SocksPort 9150
ControlPort 9151
ClientPreferIPv6ORPort 1
ClientUseIPv6 1
SocksPort 127.0.0.1:9050 IPv6Traffic

I used to be able to visit IPv6 addresses from TBB up until 0.2.4.10 (if I remember correctly) using the same method (custom built tor executable).

If I start a TBB session and I don't visit any IPv6 addresses then I got no problems and no 'connection_ap_get_begincell_flags(): Bug:' messages appear in the logfile.

Child Tickets

Change History (7)

comment:1 Changed 7 years ago by asn

Keywords: tor-client ipv6 added

comment:2 Changed 7 years ago by nickm

Milestone: Tor: 0.2.4.x-final

If you're building from source from git, and it's not too hard -- do you know how to use 'git bisect' to track down where it broke?

comment:3 Changed 7 years ago by nickm

Also, if you can double-check and confirm that it really did work in 0.2.4.10-alpha, that would be really helpful

comment:4 Changed 7 years ago by kargig

I'm lucky enough to keep my old TBB dirs. So I made some tests to find out which one used to work. Here are the results:

2.3.25-2-Linux | Tor 0.2.4.10 | Works
2.3.25-4-Linux | Tor 0.2.4.10 | Does not work, throws connection_ap_get_begincell_flags(): Bug
2.3.25-5-Linux | Tor 0.2.4.10 | Does not work, throws connection_ap_get_begincell_flags(): Bug
2.3.25-6-Linux | Tor 0.2.4.11 | Does not work, throws connection_ap_get_begincell_flags(): Bug

Then I compared my torrcs in every version and I found that in 2.3.25-2-Linux I only used one SocksPort with IPv6Traffic and my current torrc had 2 SocksPort defined. One with IPv6Traffic and one without. The problem appeared because TBB was using the one without IPv6 traffic: SocksPort 9150

As soon as I replaced it with: SocksPort 9150 IPv6Traffic
the error message got away.

So obviously it was a problem on my client's side. Maybe the error msg could have been a bit more descriptive though about the problem (e.g. "No IPv6 functionality enabled on the SocksPort")

thanks anyway

comment:5 Changed 7 years ago by nickm

Summary: 'connection_ap_get_begincell_flags Bug' with IPv6 addressUseless log message when using IPv6 address on SocksPort without IPv6

no problem -- thanks for figuring this out

comment:6 Changed 7 years ago by nickm

Milestone: Tor: 0.2.4.x-finalTor: 0.2.5.x-final

Log message updated in bc56918e5abb48f67f31012838c689e9572eec69.

We should catch this situation earlier in 0.2.5 though.

comment:7 Changed 6 years ago by nickm

Milestone: Tor: 0.2.5.x-finalTor: 0.2.4.x-final
Resolution: fixed
Status: newclosed
Note: See TracTickets for help on using tickets.