Opened 11 years ago

Last modified 7 years ago

#813 closed defect (Fixed)

Tor is unable to find my DNS and exits on startup

Reported by: knappo Owned by: nickm
Priority: High Milestone: 0.2.1.x-final
Component: Core Tor/Tor Version: 0.2.1.4-alpha
Severity: Keywords:
Cc: knappo, nickm, arma, coderman Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Version 2.1.5 is unable to start on my german WinXP SP3. The log looks this way:

Sep 08 21:28:44.411 [Hinweis] Tor v0.2.1.5-alpha (r16710). This is experimental software. Do not rely on it for strong anonymity. (Running on Windows XP Service Pack 3 [workstation] {terminal services, single user})
Sep 08 21:28:44.411 [Warnung] You have requested constrained socket buffers while also serving directory entries via DirPort. It is strongly suggested that you disable serving directory requests when system TCP buffer resources are scarce.
Sep 08 21:28:44.411 [Hinweis] Initialized libevent version 1.4.7-stable using method win32. Good.
Sep 08 21:28:44.411 [Hinweis] Opening OR listener on 0.0.0.0:443
Sep 08 21:28:44.411 [Hinweis] Opening Directory listener on 0.0.0.0:80
Sep 08 21:28:44.411 [Hinweis] Opening Socks listener on 127.0.0.1:9050
Sep 08 21:28:44.411 [Hinweis] Opening Control listener on 127.0.0.1:9051
Sep 08 21:28:44.645 [Warnung] eventdns: Didn't find any nameservers.
Sep 08 21:28:44.645 [Warnung] Could not config nameservers.
Sep 08 21:28:44.645 [Fehler] Error initializing dns subsystem; exiting

Version 2.1.4 (or earlier) do start up normally. As far as I can see there is no other
programm that has any issues with my DNS, everything works fine.

I will upload the
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip
from my registry shortly.

[Automatically added by flyspray2trac: Operating System: Windows 2k/XP]

Child Tickets

Attachments (2)

tcpip.reg (31.3 KB) - added by knappo 11 years ago.
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip
0.2.1.7-alpha-dev-log.zip (159.8 KB) - added by knappo 10 years ago.
2 logs on [Debug] and the corresponding torrc

Download all attachments as: .zip

Change History (22)

Changed 11 years ago by knappo

Attachment: tcpip.reg added

HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip

comment:1 Changed 11 years ago by knappo

The upload is there, a .reg file is just normal txt.

My nameservers are set up in:
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip\Parameters\Interfaces\{1F010631-9F90-4FA0-A034-9D30ED9AB900}\Nameservers

comment:2 Changed 11 years ago by nickm

Apparently the value of this is "194.25.2.131,204.152.184.76,195.85.254.254,194.150.168.168,192.168.0.1".

comment:3 Changed 11 years ago by knappo

The output of "Log debug" looks this way:

Sep 10 10:06:05.839 [Hinweis] Tor v0.2.1.5-alpha (r16710). This is experimental software. Do not rely on it for strong anonymity. (Running on Windows XP Service Pack 3 [workstation] {terminal services, single user})
Sep 10 10:06:05.839 [Warnung] You have requested constrained socket buffers while also serving directory entries via DirPort. It is strongly suggested that you disable serving directory requests when system TCP buffer resources are scarce.
Sep 10 10:06:05.839 [Hinweis] Initialized libevent version 1.4.7-stable using method win32. Good.
Sep 10 10:06:05.839 [Hinweis] Opening OR listener on 0.0.0.0:443
Sep 10 10:06:05.839 [Hinweis] Opening Directory listener on 0.0.0.0:80
Sep 10 10:06:05.839 [Hinweis] Opening Socks listener on 127.0.0.1:9050
Sep 10 10:06:05.839 [Hinweis] Opening Control listener on 127.0.0.1:9051
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 15 dirserver at 128.31.0.34:9031 (FFCB)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 11 dirserver at 128.31.0.34:9032 (719B)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 15 dirserver at 86.59.21.38:80 (847B)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 2 dirserver at 140.247.60.64:80 (38D4)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 6 dirserver at 194.109.206.212:80 (7EA6)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 16 dirserver at 82.94.251.206:80 (4A0C)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 4 dirserver at 216.224.124.114:9030 (F397)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 4 dirserver at 88.198.7.215:80 (6833)
Sep 10 10:06:05.839 [Debug] parse_dir_server_line(): Trusted 4 dirserver at 213.73.91.31:80 (7BE6)
Sep 10 10:06:05.839 [Info] or_state_load(): Loaded state from "C:\Dokumente und Einstellungen\Oliver Knapp\Anwendungsdaten\tor\state"
Sep 10 10:06:05.839 [Info] read_file_to_str(): Could not open "C:\Dokumente und Einstellungen\Oliver Knapp\Anwendungsdaten\tor\router-stability": No such file or directory
Sep 10 10:06:05.839 [Info] addressmap_register(): Addressmap: (re)mapped '[scrubbed]' to '[scrubbed]'
Sep 10 10:06:05.839 [Info] geoip_load_file(): Failed to open GEOIP file C:\Dokumente und Einstellungen\Oliver Knapp\Anwendungsdaten\tor\geoip.
Sep 10 10:06:06.042 [Info] eventdns: Added nameserver 131.2.25.194
Sep 10 10:06:06.042 [Info] eventdns: Succesfully added 194.25.2.131 as nameserver
Sep 10 10:06:06.042 [Info] eventdns: Could not add nameserver 204.152.184.76 to list,error: 0
Sep 10 10:06:06.042 [Info] eventdns: Didn't find nameservers in nt_key/"NameServer"
Sep 10 10:06:06.042 [Info] eventdns: Didn't find nameservers in nt_key/"DhcpNameServer"
Sep 10 10:06:06.042 [Info] eventdns: Didn't find nameservers in interfaces_key/"NameServer"
Sep 10 10:06:06.042 [Info] eventdns: Didn't find nameservers in interfaces_key/"DhcpNameServer"
Sep 10 10:06:06.042 [Warnung] eventdns: Didn't find any nameservers.
Sep 10 10:06:06.042 [Warnung] Could not config nameservers.
Sep 10 10:06:06.042 [Fehler] Error initializing dns subsystem; exiting
Sep 10 10:06:06.042 [Info] or_state_save(): Saved state to "C:\Dokumente und Einstellungen\Oliver Knapp\Anwendungsdaten\tor\state"
Sep 10 10:06:06.042 [Debug] _connection_free(): closing fd 1940.
Sep 10 10:06:06.042 [Debug] _connection_free(): closing fd 1880.
Sep 10 10:06:06.042 [Debug] _connection_free(): closing fd 1868.
Sep 10 10:06:06.042 [Debug] _connection_free(): closing fd 1860.
Sep 10 10:06:06.042 [Info] buf_shrink_freelists(): Cleaning freelist for 4096-byte chunks: keeping 0, dropping 0.
Sep 10 10:06:06.042 [Info] buf_shrink_freelists(): Cleaning freelist for 8192-byte chunks: keeping 0, dropping 0.
Sep 10 10:06:06.042 [Info] buf_shrink_freelists(): Cleaning freelist for 16384-byte chunks: keeping 0, dropping 0.
Sep 10 10:06:06.042 [Info] buf_shrink_freelists(): Cleaning freelist for 32768-byte chunks: keeping 0, dropping 0.

comment:4 Changed 11 years ago by nickm

13:32 < nickm> well, here's a bug. If evdns_nameserver_add_ip_line() finds any

errors, it says "I failed", even if it foudn some nameservers
too.

13:32 < nickm> *found
13:33 < trunp> this is not nice
13:33 < trunp> but there has to be another bug
13:33 < trunp> which triggers the error the first time
13:33 < nickm> Right. Why would 204.152.184.76 fail?
13:33 < trunp> error: 0
13:34 < trunp> always number your return codes :)
13:34 < trunp> I am open for experiments if you want to test anything
13:35 < trunp> but unfortunately I need a windows build for all the fun

comment:5 Changed 10 years ago by knappo

The problem vanished with installing Tor 0.2.1.6

Therefore I recommend the closure of this bug. Thanks for your work.

comment:6 Changed 10 years ago by nickm

False alarm; the bug vanished with installing 0.2.1.6 *and* with disabling ORPort. (reports Unicorn on IRC.)

Bug 868 may be another version of that.

comment:7 Changed 10 years ago by nickm

The code currently in svn should generate better messages for the nameservers that fail, and tolerate partial success
better. It would be good to figure out _why_ the failing ones are failing, though.

comment:8 Changed 10 years ago by phobos

Try the win32 packages at:

http://moria.seul.org/~phobos/tor-0.2.1.7-alpha-dev-win32.exe and
http://moria.seul.org/~phobos/tor-0.2.1.7-alpha-dev-win32.exe.asc

These are based on r17477 and include Nick's code to generate better messages during nameserver failures.

comment:9 Changed 10 years ago by knappo

I have tried your posted version but was not able to reproduce the error. This version runs smoothly as a normal version (but not this one...) should. I've attached 2 logs on [Debug] verbosity, one where Tor had a "normal" data directory and one where Tor was started with an empty one.

Changed 10 years ago by knappo

Attachment: 0.2.1.7-alpha-dev-log.zip added

2 logs on [Debug] and the corresponding torrc

comment:10 Changed 10 years ago by phobos

Here is 0.2.1.7-alpha release (r17216) with eventdns.c from r17368:

http://interloper.org/tmp/tor/tor-0.2.1.7-eventdns-alpha-win32.exe and
http://interloper.org/tmp/tor/tor-0.2.1.7-eventdns-alpha-win32.exe.asc

Nick and a Unicorn asked for this binary. These executables are also not stripped, as I usually do to the .exes.

comment:11 Changed 10 years ago by nickm

So, the last log doesn't actually have _any_ nameserver-related messages. Time to add more logging code, I guess.

comment:12 Changed 10 years ago by nickm

Also of interest: some other log messages could be missing. What about the message from or_state_load() ?

comment:13 Changed 10 years ago by nickm

r17569 may fix an error in the code introduced around 0.2.1.5-alpha that caused all nameservers but the first to
be bogusly detected as duplicates.

comment:14 Changed 10 years ago by knappo

I've did a complete clean install of the Tor Bundle and magically the logging returned to be sensefull...

Dez 11 00:11:40.000 [Info] eventdns: Trying to add nameserver <194.25.2.131>
Dez 11 00:11:40.000 [Info] eventdns: Added nameserver 131.2.25.194
Dez 11 00:11:40.000 [Info] eventdns: Successfully added 194.25.2.131 as nameserver
Dez 11 00:11:40.000 [Info] eventdns: Trying to add nameserver <204.152.184.76>
Dez 11 00:11:40.015 [Info] eventdns: Duplicate nameserver.
Dez 11 00:11:40.015 [Info] eventdns: Could not add nameserver 204.152.184.76 to list, error: 0; status: 3
Dez 11 00:11:40.015 [Info] eventdns: Trying to add nameserver <195.85.254.254>
Dez 11 00:11:40.015 [Info] eventdns: Duplicate nameserver.
Dez 11 00:11:40.015 [Info] eventdns: Could not add nameserver 195.85.254.254 to list, error: 0; status: 3
Dez 11 00:11:40.015 [Info] eventdns: Trying to add nameserver <194.150.168.168>
Dez 11 00:11:40.015 [Info] eventdns: Duplicate nameserver.
Dez 11 00:11:40.015 [Info] eventdns: Could not add nameserver 194.150.168.168 to list, error: 0; status: 3
Dez 11 00:11:40.015 [Info] eventdns: Trying to add nameserver <192.168.0.1>
Dez 11 00:11:40.015 [Info] eventdns: Duplicate nameserver.
Dez 11 00:11:40.015 [Info] eventdns: Could not add nameserver 192.168.0.1 to list, error: 0; status: 3
Dez 11 00:11:40.015 [Info] eventdns: Setting maximum allowed timeouts to 16
Dez 11 00:11:40.015 [Info] eventdns: Setting timeout to 10

comment:15 Changed 10 years ago by knappo

(The log was done with 0.2.1.8-alpha)

comment:16 Changed 10 years ago by nickm

Duplicate nameserver! oho!

Yes, I am pretty sure that r17569 will have fixed this. Nice job, coderman!

comment:17 Changed 10 years ago by nickm

knappo: does this still happen? is it better now?

comment:18 Changed 10 years ago by knappo

The problem is no longer reproducible and therefore (probably) solved. Thank You.

comment:19 Changed 10 years ago by nickm

flyspray2trac: bug closed.

comment:20 Changed 7 years ago by nickm

Component: Tor ClientTor
Note: See TracTickets for help on using tickets.