Bug: Bridge obfs4 0.4.5.0-alpha-dev rebuilding descriptor (source: METHOD=NONE) | Don't know my address while generating descriptor
syslog: Self-testing indicates your ORPort xxxxxxx:443 is reachable from the outside. Excellent. Publishing server descriptor. THEN: Our IP Address has changed from xxxxxxx to ???; rebuilding descriptor (source: METHOD=NONE).
Hello. After update alpha dev:
log: "Don't know my address while generating descriptor" https://metrics.torproject.org/rs.html#search/agileresearchlab but from the same location stable relay runs normally
I have 2 relays alpha/stable in the same location / 1 fix IP.
This happened after the update, only alpha bridge, stable bridge running normally.
Until then, everything was normal > 1 IP == 2x bridge obfs4.
OS: Debian
I provide alpha just for development research primarily..
Activity
added Backlog Regression + 1 deleted label
assigned to @nickm
changed milestone to %Tor: 0.4.5.x-freeze
Are those two log sections from the same torrc? Are they from different times, or at the same time?
Can you say more about which options you have set in the torrc? Of course, please feel free to replace all explicit IPs with
x.x.x.x.Would it be possible to try this again at info-level logging, and see what messages happen right before the one about
METHOD=NONE?(Also, if you want to try an alpha that is less "exciting", the 0.4.4.x series is currently in alpha and more stable than 0.4.5.x, which is just a development trunk.)
added Needs Information label
Hello @nickm
1. Yes. From the same torrc.
2. Screens are from different times. Respectively: first they both took turns, then only "Don't know my address while generating descriptor"
3. Torrc conf:
RunAsDaemon 1 User debian-tor BridgeRelay 1 ControlPort 9051 CookieAuthentication 1 ORPort 443 ServerTransportPlugin obfs4 exec /usr/bin/obfs4proxy ServerTransportListenAddr obfs4 0.0.0.0:55102 ExtORPort auto ExitRelay 0 ExitPolicy reject *:* Nickname AgileResearchLab ContactInfo Dev'agilelab AT pm DOT me [xdevproject.net]' DisableDebuggerAttachment 04. "what messages happen right before the one about METHOD=NONE"
50% Yes, I attached a 0.4.5.0-alpha BACKLOG!
- my last debug Tor log is from 31. July, and there is nothing here, becouse I switched to stable 0.4.3.6 for these moments.
- my last syslog is from 28. July, and there is only "Don't know my address while generating descriptor" message
However, from my head memory: The message "(source: METHOD=NONE)" was right after: "Bootstrapped 100% (done): Done"
becouse I log in to tmpfs, and they are automatically deleted, after a while ..
Jul 28 06:29:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:30:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:31:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:32:01 antix Tor[1469]: Received reload signal (hup). Reloading config and resetting internal state. Jul 28 06:32:01 antix Tor[1469]: Read configuration file "/usr/share/tor/tor-service-defaults-torrc". Jul 28 06:32:01 antix Tor[1469]: Read configuration file "/etc/tor/torrc". Jul 28 06:32:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:33:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:34:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:35:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:36:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:37:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:38:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:39:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:40:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:41:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:42:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:43:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:44:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:45:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:46:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:47:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:48:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:49:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:50:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:51:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:52:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:52:52 antix Tor[1469]: This version of Tor (0.4.5.0-alpha-dev) is newer than any recommended version, according to the directory authorities. Recommended versions are: 0.3.5.10,0.3.5.11,0.4.2.7,0.4.2.8,0.4.3.3-alpha,0.4.3.4-rc,0.4.3.5,0.4.3.6,0.4.4.1-alpha,0.4.4.2-alpha,0.4.4.3-alpha Jul 28 06:53:51 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:54:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:55:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:56:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:57:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:58:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 06:59:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:00:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:01:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:02:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:03:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:04:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:05:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:25:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:26:50 antix Tor[1469]: Don't know my address while generating descriptor Jul 28 07:27:07 antix Tor[1469]: Interrupt: we have stopped accepting new connections, and will shut down in 30 seconds. Interrupt again to exit now. Jul 28 07:27:08 antix Tor[1469]: Delaying directory fetches: We are hibernating or shutting down. Jul 28 07:27:37 antix Tor[1469]: Clean shutdown finished. Exiting. Jul 28 07:28:41 antix Tor[30707]: Your log may contain sensitive information - you're logging more than "notice". Don't log unless it serves an important reason. Overwrite the log afterwards. Jul 28 07:28:41 antix Tor[30707]: Not disabling debugger attaching for unprivileged users. Jul 28 07:28:48 antix Tor[30707]: Parsing GEOIP IPv4 file /usr/share/tor/geoip. Jul 28 07:28:49 antix Tor[30707]: Parsing GEOIP IPv6 file /usr/share/tor/geoip6. Jul 28 07:28:49 antix Tor[30707]: Configured to measure statistics. Look for the *-stats files that will first be written to the data directory in 24 hours from now. Jul 28 07:28:50 antix Tor[30707]: Your Tor server's identity key fingerprint is 'AgileResearchLab BAC7207742FFD48F01E91C983B3101C5C215AC2A' Jul 28 07:28:50 antix Tor[30707]: Your Tor bridge's hashed identity key fingerprint is 'AgileResearchLab D418E3928D215D2FFBB152DF012BA836CAEC5469' Jul 28 07:28:50 antix Tor[30707]: Your Tor server's identity key ed25519 fingerprint is 'AgileResearchLab abrXRIFrrGNBXtT8JFk2oPmxWSThtF+HiNBFhAK6WoU' Jul 28 07:28:50 antix Tor[30707]: Bootstrapped 0% (starting): Starting Jul 28 07:28:53 antix Tor[30707]: This version of Tor (0.4.5.0-alpha-dev) is newer than any recommended version, according to the directory authorities. Recommended versions are: 0.3.5.10,0.3.5.11,0.4.2.7,0.4.2.8,0.4.3.3-alpha,0.4.3.4-rc,0.4.3.5,0.4.3.6,0.4.4.1-alpha,0.4.4.2-alpha,0.4.4.3-alpha Jul 28 07:31:16 antix Tor[30707]: Starting with guard context "default" Jul 28 07:31:16 antix Tor[30707]: Registered server transport 'obfs4' at '[::]:55102' Jul 28 07:31:17 antix Tor[30707]: Bootstrapped 5% (conn): Connecting to a relay Jul 28 07:31:17 antix Tor[30707]: Opening Socks listener on /run/tor/socks Jul 28 07:31:17 antix Tor[30707]: Opened Socks listener connection (ready) on /run/tor/socks Jul 28 07:31:17 antix Tor[30707]: Opening Control listener on /run/tor/control Jul 28 07:31:17 antix Tor[30707]: Opened Control listener connection (ready) on /run/tor/control Jul 28 07:31:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 10% (conn_done): Connected to a relay Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 14% (handshake): Handshaking with a relay Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 15% (handshake_done): Handshake with a relay done Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits Jul 28 07:31:18 antix Tor[30707]: Bootstrapped 95% (circuit_create): Establishing a Tor circuit Jul 28 07:31:19 antix Tor[30707]: Bootstrapped 100% (done): Done Jul 28 07:32:17 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 07:33:17 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 07:34:17 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 07:35:17 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 07:36:17 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:48:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:49:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:50:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:51:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:52:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:53:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:54:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 10:55:18 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 12:00:01 antix CRON[2406]: (root) CMD (/root/flush.sh) Jul 28 12:00:01 antix root: SYNC:CRON FLUSH Jul 28 12:00:01 antix kernel: [925527.350685] flush.sh (2407): drop_caches: 3 Jul 28 12:00:04 antix kernel: [925530.215309] Adding 2097148k swap on /dev/sda2. Priority:-1 extents:1 across:2097148k FS Jul 28 13:29:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 13:30:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 13:31:17 antix Tor[30707]: Heartbeat: Tor's uptime is 6:00 hours, with 0 circuits open. I've sent 1.20 MB and received 4.78 MB. Jul 28 13:31:17 antix Tor[30707]: While bootstrapping, fetched this many bytes: Jul 28 13:31:17 antix Tor[30707]: 1804 (server descriptor fetch) Jul 28 13:31:17 antix Tor[30707]: While not bootstrapping, fetched this many bytes: Jul 28 13:31:17 antix Tor[30707]: 2832532 (server descriptor fetch) Jul 28 13:31:17 antix Tor[30707]: 403321 (consensus network-status fetch) Jul 28 13:31:17 antix Tor[30707]: 20365 (microdescriptor fetch) Jul 28 13:31:17 antix Tor[30707]: Heartbeat: In the last 6 hours, I have seen 4 unique clients. Jul 28 13:31:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 13:32:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 13:33:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 13:34:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:46:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:47:40 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:48:40 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:48:50 antix Tor[30707]: No circuits are opened. Relaxed timeout for circuit 138 (a General-purpose client 1-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. Jul 28 18:49:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:50:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:51:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 18:52:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:27:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:28:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:29:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:30:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:31:17 antix Tor[30707]: Heartbeat: Tor's uptime is 12:00 hours, with 1 circuits open. I've sent 1.69 MB and received 9.03 MB. Jul 28 19:31:17 antix Tor[30707]: While bootstrapping, fetched this many bytes: Jul 28 19:31:17 antix Tor[30707]: 1804 (server descriptor fetch) Jul 28 19:31:17 antix Tor[30707]: While not bootstrapping, fetched this many bytes: Jul 28 19:31:17 antix Tor[30707]: 6255361 (server descriptor fetch) Jul 28 19:31:17 antix Tor[30707]: 788076 (consensus network-status fetch) Jul 28 19:31:17 antix Tor[30707]: 35128 (microdescriptor fetch) Jul 28 19:31:17 antix Tor[30707]: Heartbeat: In the last 6 hours, I have seen 1 unique clients. Jul 28 19:31:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:32:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 28 19:33:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 29 01:29:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 29 01:30:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 29 01:31:17 antix Tor[30707]: Heartbeat: Tor's uptime is 18:00 hours, with 1 circuits open. I've sent 2.09 MB and received 12.46 MB. Jul 29 01:31:17 antix Tor[30707]: While bootstrapping, fetched this many bytes: Jul 29 01:31:17 antix Tor[30707]: 1804 (server descriptor fetch) Jul 29 01:31:17 antix Tor[30707]: While not bootstrapping, fetched this many bytes: Jul 29 01:31:17 antix Tor[30707]: 8878226 (server descriptor fetch) Jul 29 01:31:17 antix Tor[30707]: 1178110 (consensus network-status fetch) Jul 29 01:31:17 antix Tor[30707]: 69455 (microdescriptor fetch) Jul 29 01:31:17 antix Tor[30707]: Heartbeat: In the last 6 hours, I have seen 2 unique clients. Jul 29 01:31:20 antix Tor[30707]: Don't know my address while generating descriptor Jul 29 01:32:20 antix Tor[30707]: Don't know my address while generating descriptor tix Tor[30707]: Don't know my address while generating descriptor Jul 29 06:41:21 antix Tor[30707]: Don't know my address while generating descriptor Jul 29 06:42:07 antix liblogging-stdlog: [origin software="rsyslogd" swVersion="8.24.0" x-pid="529" x-info="http://www.rsyslog.com"] rsyslogd was HUPed--
I love new and exciting development things! I'm happy that I can contribute.
I am in a successful shift, the establishment of a non-profit organization, and the operation of high-speed exit relays.
Note: I have a spec monitor, only for Tor logs. Someone has an aquarium.., but I have logs, I follow the Tor logs etc instead of fish.
-
Hello @nickm
I did the research, for more information, about bug:
previous logs were from Debian 9.
I upgraded research machine to latest Debian Unstable/Sid now
Unpacking tor (0.4.5.0-alpha-dev-20200811T144847Z-1)deb http://ftp.nl.debian.org/debian/ unstable main contrib non-free deb https://deb.torproject.org/torproject.org sid main deb-src https://deb.torproject.org/torproject.org sid main deb https://deb.torproject.org/torproject.org tor-nightly-master-sid main deb-src https://deb.torproject.org/torproject.org tor-nightly-master-sid mainand ha get bug again with loop "rebuilding descriptor (source: METHOD=NONE)"
Aug 11 23:07:35 antix Tor[30814]: Bootstrapped 0% (starting): Starting Aug 11 23:07:38 antix Tor[30814]: This version of Tor (0.4.5.0-alpha-dev) is newer than any recommended version, according to the directory authorities. Recommended versions are: 0.3.5.10,0.3.5.11,0.4.2.7,0.4.2.8,0.4.3.3-alpha,0.4.3.4-rc,0.4.3.5,0.4.3.6,0.4.4.1-alpha,0.4.4 .2-alpha,0.4.4.3-alpha,0.4.4.4-rc Aug 11 23:09:27 antix Tor[30814]: Starting with guard context "default" Aug 11 23:09:28 antix Tor[30814]: Registered server transport 'obfs4' at '[::]:55102' Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 5% (conn): Connecting to a relay Aug 11 23:09:29 antix Tor[30814]: Opening Socks listener on /run/tor/socks Aug 11 23:09:29 antix Tor[30814]: Opened Socks listener connection (ready) on /run/tor/socks Aug 11 23:09:29 antix Tor[30814]: Opening Control listener on /run/tor/control Aug 11 23:09:29 antix Tor[30814]: Opened Control listener connection (ready) on /run/tor/control Aug 11 23:09:29 antix Tor[30814]: Don't know my address while generating descriptor Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 10% (conn_done): Connected to a relay Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 14% (handshake): Handshaking with a relay Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 15% (handshake_done): Handshake with a relay done Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits Aug 11 23:09:29 antix Tor[30814]: Bootstrapped 95% (circuit_create): Establishing a Tor circuit Aug 11 23:09:30 antix Tor[30814]: Bootstrapped 100% (done): Done Aug 11 23:10:29 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:29 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:31 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). Aug 11 23:10:31 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:31 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:31 antix Tor[30814]: Performing bandwidth self-test...done. Aug 11 23:10:32 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). Aug 11 23:10:33 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:35 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:36 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). Aug 11 23:10:36 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:37 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:38 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). Aug 11 23:10:38 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:39 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:40 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). Aug 11 23:10:40 antix Tor[30814]: Now checking whether IPv4 ORPort x.x.x.x:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Aug 11 23:10:41 antix Tor[30814]: Self-testing indicates your ORPort x.x.x.x:443 is reachable from the outside. Excellent. Publishing server descriptor. Aug 11 23:10:42 antix Tor[30814]: Our IP Address has changed from x.x.x.x to ???; rebuilding descriptor (source: METHOD=NONE). -
Sorry, I haven't been able to figure this one out. I tried running the same configuration, and didn't see that error. Maybe it requires me to open external ports? In any case, I'm hoping that David will be able to figure it out when he's back on Monday, since he wrote this version of the code.
added Bug label
-
(Sponsor 55 triage: this shouldn't be closed or deprioritized; it is an actual Bug resulting from our Sponsor 55 work.)
removed Needs Information label
Ok this is a fun one... first, thanks for the report! Lets try to narrow this down.
In 0.4.5.x, we've changed radically (as in the entire code has changed) how we discover addresses so you might have hit a bug there!
For relays, 4 methods are used in order to discover: Config (
Address), OR Port (ORPort), network interface lookup and finally local hostname resolution.Now, if none of them worked, we should see an
infolog:[info] find_my_address(): Unable to find our IP address.
If you are able to get the debug level logs and confirm that we can then proceed to understand why it found nothing. If you know how great, else simply add this to your torrc to get those logs:
Log debug file /tmp/info.log(Don't hesitate to post the whole thing here but just make sure to remove any private information from it like your IP or bridge fingerprint.)
We can already zone out options. The torrc you posted does not have
Addressand theORPort 443does not have an explicit address configured. Thus, the only way Tor can discover its public address is through the network interface or local hostname. And maybe that failed somehow... Logging will tell us more.It is weird though that the self testing can find an address but then we are unable to find it the second later through the other mechanism... Debug logs here are really instrumental to understand what is happening.
Thanks!
added Needs Information label
-
Hello @dgoulet,
OK let's debug
"already zone out options"
this torrc config worked (and on my others bridge machines(64-bit)) for more than a year and this alpha bug appeared at the end of July
Go: that is, the steps now(today) taken:
- I switched back to alpha, from running functional latest stable version(0.4.3.6-1):
.deb versions:
Get:1 https://deb.torproject.org/torproject.org tor-nightly-master-sid/main i386 tor-geoipdb all 0.4.5.0-alpha-dev-20200820T114133Z-1 [1,488 kB]
Get:2 https://deb.torproject.org/torproject.org tor-nightly-master-sid/main i386 tor i386 0.4.5.0-alpha-dev-20200820T114133Z-1 [2,056 kB]
- I created a new clean debug log with only alpha since startup
see attachment file debug.log.tar.gz
- Syslog grep Tor
# tail -F /var/log/syslog | grep Tor Aug 20 19:19:27 antix Tor[10904]: This version of Tor (0.4.5.0-alpha-dev) is newer than any recommended version, according to the directory authorities. Recommended versions are: 0.3.5.10,0.3.5.11,0.4.2.7,0.4.2.8,0.4.3.3-alpha,0.4.3.4-rc,0.4.3.5,0.4.3.6,0.4.4.1-alpha,0.4.4 .2-alpha,0.4.4.3-alpha,0.4.4.4-rc Aug 20 19:24:51 antix Tor[10904]: Starting with guard context "default" Aug 20 19:24:51 antix Tor[10904]: Registered server transport 'obfs4' at '[::]:55102' Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 5% (conn): Connecting to a relay Aug 20 19:24:53 antix Tor[10904]: Opening Socks listener on /run/tor/socks Aug 20 19:24:53 antix Tor[10904]: Opened Socks listener connection (ready) on /run/tor/socks Aug 20 19:24:53 antix Tor[10904]: Opening Control listener on /run/tor/control Aug 20 19:24:53 antix Tor[10904]: Opened Control listener connection (ready) on /run/tor/control Aug 20 19:24:53 antix Tor[10904]: Don't know my address while generating descriptor Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 10% (conn_done): Connected to a relay Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 14% (handshake): Handshaking with a relay Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 15% (handshake_done): Handshake with a relay done Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits Aug 20 19:24:53 antix Tor[10904]: Bootstrapped 95% (circuit_create): Establishing a Tor circuit Aug 20 19:25:00 antix Tor[10904]: Bootstrapped 100% (done): Done Aug 20 19:25:53 antix Tor[10904]: Don't know my address while generating descriptor Aug 20 19:26:53 antix Tor[10904]: Don't know my address while generating descriptor- and got bug loop
Aug 20 19:26:53 antix Tor[10904]: Don't know my address while generating descriptor
-
Awesome, debug logs, very useful! Here it is:
- Configuration
Aug 20 19:24:53.000 [debug] get_address_from_config(): Attempting to get address from configuration Aug 20 19:24:53.000 [info] get_address_from_config(): No Address option found in configuration.- ORPort
Aug 20 19:24:53.000 [debug] get_address_from_orport(): Attempting to get address from ORPort Aug 20 19:24:53.000 [info] address_can_be_used(): Address '0.0.0.0' is a private IP address. Tor relays that use the default DirAuthorities must have public IP addresses.- Network Interface
Aug 20 19:24:53.000 [debug] get_address_from_interface(): Attempting to get address from network interface Aug 20 19:24:53.000 [debug] get_interface_address6(): Found internal interface address 'xxx.xxx.xxx.xxx' Aug 20 19:24:53.000 [info] address_can_be_used(): Address 'xxx.xxx.xxx.xxx' is a private IP address. Tor relays that use the default DirAuthorities must have public IP addresses.- Local hostname
Aug 20 19:24:53.000 [debug] get_address_from_hostname(): Attempting to get address from local hostname Aug 20 19:24:53.000 [info] tor_getaddrinfo(): (Sandbox) getaddrinfo succeeded. Aug 20 19:24:53.000 [info] address_can_be_used(): Address '127.0.0.1' is a private IP address. Tor relays that use the default DirAuthorities must have public IP addresses.No methods were able to find your address. For some reasons, the address on the interface it only got a local IPv4? Was the xxx.xxx.xxx.xxx really local (RFC1918) ?
Now, there is a last resort method that relay use is that they learn their address from a directory authority when downloading directory data. HOWEVER, bridges don't do that, they act as client I believe so they don't leak to the authorities that they are in fact a relay (I might be wrong on the details but the debug logs suggest that since the directory fetch was done on a fallbackdir, relay don't poke them).
Thus your bridge has no way of finding its address. We ought to find the mystery of the network interface address first that is if really private address. Else, you will have to set
Addressin your torrc orOPPort address:port. -
Hey intersting.
- "Was the xxx.xxx.xxx.xxx really local (RFC1918)"
Yes 192.168.x.xxx
if I switch to stable (0.4.3.6-1), with the same torrc config, no bug, relay runs
it means from July alpha, they have new config? - more accurate time location: at the end of June I left state, and everything was fine, and at the end of July after the return, I discovered this bug.
- "We ought to find the mystery of the network interface address first that is if really private address"
This network is corporate. I built everything, so I know the exact structure.
Edited by LX1 -
Test 1 aka SCIFI log voice
"Else, you will have to set
Addressin your torrc orORPort address:port"new torrc for alpha
ORPort 443 NoAdvertise ORPort xx.xxx.xx.xxx:443 NoListentail -F /var/log/syslog | grep Tor Aug 22 04:05:53 antix Tor[3464]: Configuration port ORPort 443 superseded by ORPort xx.xxx.xx.xxx:443 Aug 22 04:06:01 antix Tor[3464]: Parsing GEOIP IPv4 file /usr/share/tor/geoip. Aug 22 04:06:02 antix Tor[3464]: Parsing GEOIP IPv6 file /usr/share/tor/geoip6. Aug 22 04:06:02 antix Tor[3464]: Configured to measure statistics. Look for the *-stats files that will first be written to the data directory in 24 hours from now. Aug 22 04:06:05 antix Tor[3464]: Your Tor server's identity key fingerprint is 'AgileResearchLab' Aug 22 04:06:05 antix Tor[3464]: Your Tor bridge's hashed identity key fingerprint is 'AgileResearchLab' Aug 22 04:06:05 antix Tor[3464]: Your Tor server's identity key ed25519 fingerprint is 'AgileResearchLab' Aug 22 04:06:05 antix Tor[3464]: Bootstrapped 0% (starting): Starting Aug 22 04:06:07 antix Tor[3464]: This version of Tor (0.4.5.0-alpha-dev) is newer than any recommended version, according to the directory authorities. Recommended versions are: 0.3.5.10,0.3.5.11,0.4.2.7,0.4.2.8,0.4.3.3-alpha,0.4.3.4-rc,0.4.3.5,0.4.3.6,0.4.4.1-alpha,0.4.4.2-alpha,0.4.4.3-alpha,0.4.4.4-rc Aug 22 04:08:09 antix Tor[3464]: Starting with guard context "default" Aug 22 04:08:09 antix Tor[3464]: Registered server transport 'obfs4' at '[::]:55102' Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 5% (conn): Connecting to a relay Aug 22 04:08:10 antix Tor[3464]: Opening Socks listener on /run/tor/socks Aug 22 04:08:10 antix Tor[3464]: Opened Socks listener connection (ready) on /run/tor/socks Aug 22 04:08:10 antix Tor[3464]: Opening Control listener on /run/tor/control Aug 22 04:08:10 antix Tor[3464]: Opened Control listener connection (ready) on /run/tor/control Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 10% (conn_done): Connected to a relay Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 14% (handshake): Handshaking with a relay Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 15% (handshake_done): Handshake with a relay done Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits Aug 22 04:08:10 antix Tor[3464]: Bootstrapped 95% (circuit_create): Establishing a Tor circuit Aug 22 04:08:11 antix Tor[3464]: Bootstrapped 100% (done): Done Aug 22 04:08:11 antix Tor[3464]: Now checking whether IPv4 ORPort xx.xxx.xx.xxx:443 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) roand now watch out for the SCIFI voice04:28:10 [WARN] Your server has not managed to confirm reachability for its ORPort(s) at xx.xxx.xx.xxx:443. Relays do not publish descriptors until their ORPort and DirPort are reachable. Please check your firewalls, ports, address, /etc/hosts file, etc.Nonsense! if I switch to the stable (0.4.3.6-1) version all runs, 443 is success reachable. See previous post.
Something had to happen in the alpha version in July. because until then everything was fine, and alpha worked for me over a year.
Let's go to test 2 - stable 0.4.3.6-1 - same new config
and this result is very interesting
The same new config as for alpha:
ORPort 443 NoAdvertise ORPort xx.xxx.xx.xxx:443 NoListeneeend voila:
Aug 22 04:57:26 antix Tor[5407]: Self-testing indicates your ORPort is reachable from the outside. Excellent. Publishing server descriptor. Aug 22 04:57:29 antix Tor[5407]: Performing bandwidth self-test...done.Which means that stable version (0.4.3.6-1) works with both the original torrc configuration and the new one,
alpha with neither since July.
-
Huh ... so hmmm, two possibilities, we introduced a bug or we fixed a bug :).
Now, I want to get that logic straighten out. The first
ORPort 443is in no advertise mode so basically you want tor to listen on0.0.0.0:443but not advertise its port + address in the descriptor.The second is that you want to advertise
xx.xxx.xx.xxx:443but not listen on it.Which means that the first
ORPortstatement will never be picked for the descriptor or reachability tests. What puzzles me is that the secondORPortis an internal address and 0.4.5 should never pick it as usable or even do reachability test. Again, can you provide the 0.4.5. debug logs if possible up to the reachability test onxx.xxx.xx.xxx:443?Tor, in theory, in all versions, should never allowed a private address to be tested on the network nor even published. Thanks!
-
I need the debug log to go further as I said previously:
Again, can you provide the 0.4.5. debug logs if possible up to the reachability test on xx.xxx.xx.xxx:443?
For some reasons, the 043 took that private address but in 045, which a lot of code touching that changed, we don't allow it (which should be the correct behavior).
Thus, we need to look at the tor logs here (ideally on both version) and understand why 1) reachability worked on 0.4.3 with a private address and 2) Why tor attempts to do a reachability check on a private address.
Just use the
ORPortyou showed us in #40071 (comment 2706761) and test it on 043 and 045. Thanks! -
ORPortsetupORPort 443 NoAdvertise ORPort xx.xxx.xx.xxx:443 NoListenDebug
-
it worked for me for years
ORPort 443RunAsDaemon 1 User debian-tor BridgeRelay 1 ControlPort 9051 CookieAuthentication 1 ORPort 443 ServerTransportPlugin obfs4 exec /usr/bin/obfs4proxy ServerTransportListenAddr obfs4 0.0.0.0:55102 ExtORPort auto ExitRelay 0 ExitPolicy reject *:* Nickname AgileResearchLab ContactInfo Dev'agilelab AT pm DOT me [xdevproject.net]' DisableDebuggerAttachment 0i have never added ip to the torrc file. and in July this conf stopped working for alpha 045
-
@dgoulet how can i help further?
added Mystery Bug label
-
-
I think I might have identified the issue here with this smaller debug log.
Basically, tor was not able to auto-discover an address because all methods failed. That is possible and expected behavior. No IP in the config, no usable IP on the interface and the local hostname resolved to an internal address.
What left is Tor discovering its IP from a directory authority. That is where it is failing. Bridge do not poke dirauth directly contrary to Relays and thus it never got a suggestion.
Remember that in July, with the S55 work and address discovery, we changed that behavior to ONLY allow dirauth to tell us our address.
Furthermore, the dummy descriptor fetch that tor has to speed up the address discovery uses the
DL_WANT_ANY_DIRSERVERparameter which will fail most of the time. We might want to change it toDL_WANT_AUTHORITYbut then we ought to make sure we are not adding more pressure on dirauth... -
@dgoulet Yes i tested both ways > with and without public IP (
Address,ORPort), and both don't work, starting in July. -
Found another bug. If you got your address from an authority, our periodic event
check_descriptor_ipaddress_changedwill trigger an address discovery and will fail to notice that we have not found one and instead will consider the address changed from the suggestion to "nothing" and trigger an event.This triggers logging, control event and rebuild of a descriptor which will use the right address. But it also resets all reachability tests so this is really not good because we will bounce back and forth non stop here from noticing a false IP change and resetting reachability...
Edited by David Goulet -
@agiteg so if you are able, can you try this branch that has a series of fixes:
ticket40071_045_01in https://git.torproject.org/user/dgoulet/tor.gitI'm currently unable to reproduce the reachability failure when only using
ORPortorAddressthat you are experiencing... so first I want to see if that branch help things on your side or not. Thanks! -
git clone --single-branch --branch ticket40071_045_01 https://git.torproject.org/user/dgoulet/tor.git
Tor 0.4.5.0-alpha-dev (git-33fec507310dfdb1)
CONF Test 1 NO IP in config
ORPort 443Log: debug.pureORPort443-without-ip.log.tar.gz
Result > SUCCESS !!
CONF Test 2 public address
ORPort 443 NoAdvertise ORPort xx.xxx.xx.xxx:443 NoListenLog: debug.xx.xxx.xx.xxxORPort443-with-public-ip.log.tar.gz
Result > FAULT ORPort NOT reachable
CONF Test 3 public address
Address: xx.xxx.xx.xxxLog: debug.Address_ORPort443-with-public-ip.log.tar.gz
Result > FAULT ORPort NOT reachable
-
@dgoulet 045 CONF Test 1 NO IP in config > so far it works fine https://metrics.torproject.org/rs.html#search/agileresearchlab