[tor-relays] Issues with vidalia-obfsproxy-bridge-bundle-0.2.4.12-alpha-0.3.3-alpha on Windows

Sat Jun 1 13:43:09 UTC 2013

From: Asa Rossoff [mailto:asa at lovetour.info] 
Sent: Saturday, June 01, 2013 4:33 AM
To: 'tor-talk at lists.torproject.org'
Cc: 'tor-relays at lists.torproject.org'
Subject: Issues with
vidalia-obfsproxy-bridge-bundle-0.2.4.12-alpha-0.3.3-alpha on Windows

[A. R.] .

4) Now, things were better.  Next problem: periodically, usually after some
hours of running fine, the Tor log began showing errors re. the
cached-microdescs file.  First, a permission/file access error, and then
hundreds of other errors related to building the micro descriptor cache
would be generated every some minutes.  Actually---I also observed this
problem the first time, even running under Vidalia, that Tor ran without
crashing on startup.  My solution attempt: delete the file.  It was locked.
When I closed Tor --- the lock was released [Tor was tied to the file lock]
and I could delete the file.  I restarted Tor and it worked fine for some
hours before repeating this behavior.  Once this happens, my node goes down.
I think it has to do more bootstrapping work on restart when this file is
lost, if I understand correctly.

[A. R.] Another quick update that may offer some insight to programmers:

29 minutes after hitting the ESC key (as I reportd a bit ago in an email
update) woke Tor up starting with the message "Your system clock just jumped
64376 seconds forward.," etc., the micro descriptor cache problem described
in item 4 above occurred.  In the past, I have solved It by closing/kjilling
Tor, deleting the file, and restarting Tor, however this time I relied on
Empty Loop's Unlocker Windows Explorer add-in (which I always keep
installed) to check what process was locking the file, if any.  I know I
couldn't delete the file in Windows Explorer at that point.  Unlocker
reported "no locks found" and offered to help me deal with the file itself.
It was able to delete the file (it has elevated priveleges, for one thing,
and it may try unconventional means).

I am now leaving Tor running to see if it will recover without a restart,
probably within minutes if it does.

The logged (warn/info level only) messages upon issue #4 occurring begin
like this:

[warn] Error replacing "C:\.........\tor\cached-microdescs": Permission
denied

[warn] Error rebuilding microdescriptor cache: Permission denied

[warn] Couldn't dump microdescriptor (wrote 4294967295 out of 261): Invalid
argument

[warn] microdesc_cache_rebuild(): Bug: Discontinuity in position in
microdescriptor cache.By my count, I'm at 294, but I should be at 327

[warn] Couldn't dump microdescriptor (wrote 4294967295 out of 619): Invalid
argument

[warn] Couldn't dump microdescriptor (wrote 4294967295 out of 261): Invalid
argument

[warn] Couldn't dump microdescriptor (wrote 4294967295 out of 939): Invalid
argument

[warn] microdesc_cache_rebuild(): Bug: Discontinuity in position in
microdescriptor cache.By my count, I'm at 621, but I should be at 720

[warn] Couldn't dump microdescriptor (wrote 4294967295 out of 333): Invalid
argument

[warn] microdesc_cache_rebuild(): Bug: Discontinuity in position in
microdescriptor cache.By my count, I'm at 1357, but I should be at 1390

The pattern continues for many entries, culminating in the following:

[warn] microdesc_cache_rebuild(): Bug: Discontinuity in position in
microdescriptor cache.By my count, I'm at 1517569, but I should be at
1517701

[warn] Error replacing "C:\.........\tor\cached-microdescs": Permission
denied

[warn] Error rebuilding microdescriptor cache: Permission denied

UPDATE  -- - As I write this message, some timeout expired and Tor attempted
it's microsdescriptor business again.  The results were NOT good; obviously
deleting the file while Tor was running backfired.

Result: Tons of messages like "Couldn't dump microdescriptor," "Bug:
Discontinuity in position in microsdescriptor cache," etc.  I don't know
what the first of this new batch of entries was, but the last of them were
these:

[err] microdesc_cache_rebuild(): Bug: After rebuilding microdesc cache,
offsets seem wrong.  At offset 33, I expected to find a microdescriptor
starting  with "onion-key".  Instead I got "@last-listed 2013-05-30
03:29:37\nonion-key\n-----BEGIN RSA PUBLIC KEY-----\n[key
here....................]".

[err] microdesc_cache_rebuild(): Bug: microdesc.c:510:
microdesc_cache_rebuild: Assertion fast_memeq(md->body, "onion-key", 9)
failed; aborting.

microdesc.c:510 microdesc_cache_rebuild: Assertion fast_memeq(md->body,
"onion-key", 9) failed, aborting.

This application has requested the Runtime to terminate in an unusual way.

Please contact the application's support team for more information.

Those console messages were followed by the Tor console freezing and a
windows dialog "tor.exe has stopped working....... with a "Close the
program" button.

Thanks,

Asa

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.torproject.org/pipermail/tor-relays/attachments/20130601/d91b7ec5/attachment-0003.html>