Opened 6 years ago

Last modified 15 months ago

#7077 new defect

Recover from junk in cached-descriptors

Reported by: jackhill Owned by:
Priority: Medium Milestone: Tor: unspecified
Component: Core Tor/Tor Version:
Severity: Normal Keywords: tor-relay tor-client parsing descriptors
Cc: jackhill@… Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I am running tor 2.2.39 on Debian Squeeze (on sparc). My node had been running for weeks, but I noticed that it had gone down and found this is syslog 'descriptor at 0xf76ecd08 begins with unexpected string "". Is another process running in our data directory? Exiting.' I'm not sure where else to find interesting information. I have kept copied of all the cached-* files.

Child Tickets

Attachments (4)

log (410 bytes) - added by jackhill 6 years ago.
Tor messages in syslog
torrc (335 bytes) - added by jackhill 6 years ago.
torrc
tor (4.5 KB) - added by jackhill 6 years ago.
Debian init script
unparseable-desc (910 bytes) - added by webmeister 6 years ago.

Download all attachments as: .zip

Change History (20)

Changed 6 years ago by jackhill

Attachment: log added

Tor messages in syslog

Changed 6 years ago by jackhill

Attachment: torrc added

torrc

comment:1 Changed 6 years ago by jackhill

Cc: jackhill@… added

comment:2 Changed 6 years ago by arma

Exciting! How do you start tor on this system?

Was it running for a while and then logged this and exited?

What happens when you start it again? (If you haven't tried yet, please cp -a /var/lib/tor to somewhere else in case it has any juicy bug-triggering files in it.)

comment:3 Changed 6 years ago by jackhill

I start tor with the Debian provided init script.

Yes, it had been running for about a month.

I have copied /var/lib/tor to a safe place. I have restarted tor (without cleaning /var/lib/tor) and everything seems to be working properly.

Changed 6 years ago by jackhill

Attachment: tor added

Debian init script

comment:4 Changed 6 years ago by nickm

Keywords: tor-relay added

comment:5 Changed 6 years ago by nickm

Milestone: Tor: 0.2.2.x-final

comment:6 Changed 6 years ago by webmeister

My relay TaurNuFuin (Tor 0.2.3.25) shows the same problem. Currently I have four such messages in my logs:

Dec 20 18:27:12.000 [err] descriptor at 0x2c05d1c8 begins with unexpected string "".  Is another process running in our data directory?  Exiting.
Dec 29 02:54:53.000 [err] descriptor at 0x2aa7d520 begins with unexpected string "".  Is another process running in our data directory?  Exiting.
Jan 03 03:30:43.000 [err] descriptor at 0x2bd2a750 begins with unexpected string "".  Is another process running in our data directory?  Exiting.
Jan 05 21:09:26.000 [err] descriptor at 0x2bdfda68 begins with unexpected string "".  Is another process running in our data directory?  Exiting.

Each time I restarted Tor several hours later and it continued to run fine. Three of these four times after restarting different warnings appeared in the log (right after the "Reloaded microdescriptor cache." notice):

Dec 20 23:28:41.000 [warn] Error reading router descriptor: signature does not match.

Dec 29 02:56:25.000 [warn] crypto error while reading public key from string: bad end line (in PEM routines:PEM_read_bio)
Dec 29 02:56:25.000 [warn] parse error: Couldn't parse public key.
Dec 29 02:56:25.000 [warn] Error tokenizing router descriptor.
Dec 29 02:56:29.000 [warn] Parse error: missing onion-key element.
Dec 29 02:56:29.000 [warn] Error tokenizing router descriptor.

Jan 05 22:46:02.000 [warn] parse error: Malformed object: mismatched end tag SIGNATURE
Jan 05 22:46:02.000 [warn] Error tokenizing router descriptor.

The relay is the only service running on a Pogoplug POGO-P24 V3 using Arch Linux ARM. Its file system is located on an USB flash drive. The error occurred for the first time after I had exchanged the flash drive with a different model. Can this be simply a faulty flash drive? Then again the system was only running for four days on the first flash drive, so this might be completely unrelated.

Another idea: The kernel on this device is rather old. Due to the special hardware 2.6.31.6 is the newest version available. Might this influence the behaviour?

comment:7 Changed 6 years ago by nickm

Hm. Is this host running with a very small HD? Are you nearly out-of-space on it?

It would help to have the (compressed!) contents of cached-*desc* from the /var/lib/tor directory.

comment:8 in reply to:  7 Changed 6 years ago by webmeister

Hm. Is this host running with a very small HD? Are you nearly out-of-space on it?

It is a small disk, but there is plenty of free space:

Filesystem      Size  Used Avail Use% Mounted on
rootfs           15G  685M   14G   5% /

It would help to have the (compressed!) contents of cached-*desc* from the /var/lib/tor directory.

I'll wait for the error to occur again and then collect the files. In the meantime I can at least provide the file /var/lib/tor/unparseable-desc that has been created the last time I restarted Tor after the error. The log messages in this case read:

Jan 11 20:31:19.000 [notice] Reloaded microdescriptor cache.  Found 9004 descriptors.
Jan 11 20:31:35.000 [warn] crypto error while reading public key from string: bad end line (in PEM routines:PEM_read_bio)
Jan 11 20:31:35.000 [warn] parse error: Couldn't parse public key.
Jan 11 20:31:35.000 [warn] Error tokenizing router descriptor.

Changed 6 years ago by webmeister

Attachment: unparseable-desc added

comment:9 Changed 6 years ago by webmeister

The problem occurred twice recently, so here are the two sets of cached descriptors:

http://ge.tt/api/1/files/7Xhrf4W/0/blob?download
http://ge.tt/api/1/files/7Xhrf4W/1/blob?download

comment:10 Changed 5 years ago by nickm

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

Putting this in 0.2.4 so it gets some attention. If we find a bug, it's backportable.

comment:11 Changed 5 years ago by nickm

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

So, the right way to prevent stuff like this might be to try parsing cached-descriptors.tmp before we replace cached-descriptors with it. Also we should check the code to make sure that a bogon in cached-descriptors can't make us exit on startup.

comment:12 Changed 4 years ago by nickm

Milestone: Tor: 0.2.5.x-finalTor: 0.2.???

comment:13 Changed 21 months ago by teor

Milestone: Tor: 0.2.???Tor: 0.3.???

Milestone renamed

comment:14 Changed 20 months ago by nickm

Keywords: tor-03-unspecified-201612 added
Milestone: Tor: 0.3.???Tor: unspecified

Finally admitting that 0.3.??? was a euphemism for Tor: unspecified all along.

comment:15 Changed 15 months ago by nickm

Keywords: tor-03-unspecified-201612 removed

Remove an old triaging keyword.

comment:16 Changed 15 months ago by nickm

Keywords: tor-client parsing descriptors added
Severity: Normal
Summary: Tor exits with 'descriptor at <address> begins with unexpected string ""'Recover from junk in cached-descriptors
Note: See TracTickets for help on using tickets.