Can't parse networkstatus consensus time

changed milestone to %Tor: 0.4.0.x-final

added 040-backport 040-must 040-rc-must component::core tor/tor milestone::Tor: 0.4.0.x-final owner::nickm postfreeze-ok priority::high regression reporter::Vort resolution::fixed reviewer::ahf severity::normal sponsor::8 status::closed tbb-needs type::defect version::tor 0.4.0.1-alpha labels

Hm. Does this happen with older versions of Tor, or is it a regression with this one?

To me it sounds like the issue is with the \r at the end of the line -- like the consensus file was saved in a windows text format, but it's being interpreted as a unix-style text format.

Trac:
Milestone: N/A to Tor: 0.4.0.x-final

Never seen this with 0.3.4.9.

Trac:
Username: Vort

I was about to file this bug, too. This happens on Windows as well when testing in a Tor Browser context. I think this prevents Tor Browser starting up properly as I've seen numerous instances where Tor Browser "hangs" for 20 minutes after those messages. But that's "only" happening with a clean, new bundle on first start. Luckily, 0.3.5.5-alpha is fine, though.

Trac:
Version: Tor: 0.3.5.5-alpha to N/A

Trac:
Keywords: N/A deleted, 040-rc-must, regression added

Is there a way to reproduce this easily? Is there a Tor version where it always happens, and one where it never happens?

I wonder if the mmap-related changes of #27244 (moved) could be responsible here.

Trac:
Username: Vort

Screenshot

Trac:
Username: Vort

Reproduction is simple: just run tor.exe.

Trac:
Username: Vort

Stack trace

Trac:
Username: Vort

Yes, it may be related to mmap. Here is additional info: tor_mmap.png|tor_mmap.png.

Trac:
Username: Vort

Replying to gk:

I was about to file this bug, too. This happens on Windows as well when testing in a Tor Browser context. I think this prevents Tor Browser starting up properly as I've seen numerous instances where Tor Browser "hangs" for 20 minutes after those messages. But that's "only" happening with a clean, new bundle on first start. Luckily, 0.3.5.5-alpha is fine, though.

I think I am wrong. This just happens with testing Tor Browser 8.0.4 which ships 0.3.4.9. The result is that bootstrapping is delayed for several minutes (assuming that delay is actually caused by that parsing issue). I wonder, though, while this seems to be a new bug...

Replying to gk:

Replying to gk:

I was about to file this bug, too. This happens on Windows as well when testing in a Tor Browser context. I think this prevents Tor Browser starting up properly as I've seen numerous instances where Tor Browser "hangs" for 20 minutes after those messages. But that's "only" happening with a clean, new bundle on first start. Luckily, 0.3.5.5-alpha is fine, though.

I think I am wrong. This just happens with testing Tor Browser 8.0.4 which ships 0.3.4.9. The result is that bootstrapping is delayed for several minutes (assuming that delay is actually caused by that parsing issue). I wonder, though, while this seems to be a new bug...

Wait, scratch that. I think I took the wrong bundle to test. Sorry for the noise.

Note: #28405 (moved) seems highly related (but does have a different milestone and keywords).

Mark some tickets as postfreeze-ok, to indicate that I think they are okay to accept in 0.4.0 post-freeze. Does not indicate that they are all necessary to do postfreeze.

Trac:
Keywords: N/A deleted, postfreeze-ok added

Trac:
Keywords: N/A deleted, tbb-needs added

Hint: in maint-0.3.5's src/feature/nodelist/networkstatus.c's networkstatus_read_cached_consensus_impl(), we call

  char *result = read_file_to_str(filename, RFTS_IGNORE_MISSING, NULL);

Note that we don't pass it the RFTS_BIN flag, which means tor_open_cloexec()'s open() ultimately uses O_TEXT rather than O_BINARY for its flags.

But 0.4.0's networkstatus_map_cached_consensus_impl()'s tor_mmap_file() doesn't have the same Windows notion of O_TEXT.

And on Linux, open() doesn't care if it's binary or text because they're the same thing, so Linux (and really everything other than Windows) continued to work when we shifted from text to binary in 0.4.0.

Of course, for extra fun notice that we seem to have a Windows-specific mmap implementation: see the #elif _WIN32 version of tor_mmap_file().

Or maybe I am looking at this bug the wrong way around: how did it come to have \r's in it on disk? I assume it's because we wrote it with Windows-style O_TEXT which added the \r's. So if we want it to not have \r's in it when we read it, we need to write it in O_BINARY mode too? And then there will still be the edge case where we try to load a legacy file which has \r's in it, and we should teach ourselves to handle that case better (e.g. discard it and fetch another right then)?

So we need to do two things here:

always write a consensus in binary mode
on windows, when we encounter a consensus with CRLF in it, strip the CRs.

Trac:
Status: new to accepted
Owner: N/A to nickm

Proposed fix in bug28614_040, PR at https://github.com/torproject/tor/pull/671

Trac:
Status: accepted to needs_review

Trac:
Priority: Medium to High

- When reading a consensus fiel from disk, detect whether it FILE

Could we avoid that and just ask users to clear the old file if it's wrong?

Trac:
Username: watt

Trac:
Reviewer: N/A to ahf

Could we avoid that and just ask users to clear the old file if it's wrong?

We could, but that would be inconvenience to the users, and it's best not to inconvenience users for a problem that we can fix.

Not everybody is comfortable navigating inside folders and deleting stuff.

Replying to nickm:

Could we avoid that and just ask users to clear the old file if it's wrong?

We could, but that would be inconvenience to the users, and it's best not to inconvenience users for a problem that we can fix.

Not everybody is comfortable navigating inside folders and deleting stuff. No user intervention then. But adding more code to core tor just for transition to a new file format is not the best option. Will you remove it when tor is upgraded?

Trac:
Username: watt

Closed #29302 (moved) as a duplicate

Trac:
Cc: N/A to cypherpunks2

Replying to watt:

Replying to nickm:

Could we avoid that and just ask users to clear the old file if it's wrong?

We could, but that would be inconvenience to the users, and it's best not to inconvenience users for a problem that we can fix.

Not everybody is comfortable navigating inside folders and deleting stuff. No user intervention then. But adding more code to core tor just for transition to a new file format is not the best option. Will you remove it when tor is upgraded?

Probably; would you like to open a ticket for that? This code will be relevant until all earlier versions of Tor are obsolete, since people have any time between now and then to update. Since 0.3.5.x is supported till 2022, we shouldn't remove it before then.

Tested this on Windows. Looks like it makes the 'ISO time "...\r" was unparseable' go away.

Code looks good.

Trac:
Status: needs_review to merge_ready

Replying to nickm:

Replying to watt:

Replying to nickm:

Could we avoid that and just ask users to clear the old file if it's wrong?

We could, but that would be inconvenience to the users, and it's best not to inconvenience users for a problem that we can fix.

Not everybody is comfortable navigating inside folders and deleting stuff. No user intervention then. But adding more code to core tor just for transition to a new file format is not the best option. Will you remove it when tor is upgraded?

Probably; would you like to open a ticket for that? This code will be relevant until all earlier versions of Tor are obsolete, since people have any time between now and then to update. Since 0.3.5.x is supported till 2022, we shouldn't remove it before then. Usually such tickets are buried in the Tor: unspecified milestone. And it's almost impossible that somebody will remind us about it in 2022 :( The main drawback is that tor should do additional parsing again and again at runtime instead of one time deletion during update.

Trac:
Username: watt

Merged.

Trac:
Resolution: N/A to fixed
Status: merge_ready to closed

The problem is half-fixed. Fresh installation have no such messages anymore. But updating from 0.3.5.8 is still broken - same message pops out. Tested version: 0.4.0.3-alpha.

Trac:
Username: Vort

We need to check for \r\n before we try to parse the consensus, because tor logs warnings when it fails. I left some comments on the pull request.

Replying to Vort:

The problem is half-fixed. Fresh installation have no such messages anymore. But updating from 0.3.5.8 is still broken - same message pops out. Tested version: 0.4.0.3-alpha.

Yes, we should fix that message. But does Tor successfully parse the consensus, after it logs the message?

Trac:
Resolution: fixed to N/A
Version: N/A to Tor: 0.4.0.1-alpha
Keywords: N/A deleted, 040-must added
Status: closed to reopened

Trac:
Keywords: N/A deleted, 040-backport added

Replying to teor:

But does Tor successfully parse the consensus, after it logs the message?

I am not sure how to check it. Log says Mar 28 08:23:58.000 [notice] Bootstrapped 100% (done): Done

BTW, clean start of 0.4.0.3-alpha brings another problem: Mar 28 08:26:00.000 [warn] Failed to unlink C:\Users\Vort\AppData\Roaming\tor\unverified-microdesc-consensus: Permission denied Maybe it is related.

Trac:
Username: Vort

Replying to Vort:

Replying to teor:

But does Tor successfully parse the consensus, after it logs the message?

I am not sure how to check it. Log says Mar 28 08:23:58.000 [notice] Bootstrapped 100% (done): Done

Please send us a full copy of your logs. Please delete any guard fingerprints or names.

We should be able to tell from the bootstrap progress and times if you needed a new consensus or not.

BTW, clean start of 0.4.0.3-alpha brings another problem: Mar 28 08:26:00.000 [warn] Failed to unlink C:\Users\Vort\AppData\Roaming\tor\unverified-microdesc-consensus: Permission denied Maybe it is related.

I don't think it is, but I opened #29930 (moved) for it.

Trac:
Username: Vort

0358.txt

Trac:
Username: Vort

0403.txt

Trac:
Username: Vort

Replying to teor:

Please delete any guard fingerprints or names.

Nothing interesting there. It's a clean start inside VM.

Please send us a full copy of your logs.

Test sequence:

Manually remove C:\Users\Vort\AppData\Roaming\tor.
Start 0.3.5.8. Close it: [0358.txt]
Start 0.4.0.3-alpha. Close it: [0403.txt]

We should be able to tell from the bootstrap progress and times if you needed a new consensus or not.

My relay is fine. I was able to fix this problem by removing of some files in data directory.

Trac:
Username: Vort

Looks like the main issue here is mainly logging -- we're logging the failures at 'warning', but we're only logging the message about retrying at 'info'.

Opening a child ticket for that...

The issue was fixed, but the logs were misleading. Opened #30004 (moved) to improve the logging.

Trac:
Status: reopened to closed
Resolution: N/A to fixed

Related to #27244 (moved).

Trac:
Sponsor: N/A to Sponsor8

closed

mentioned in issue #28733 (moved)

mentioned in issue #28874 (moved)

mentioned in issue #29302 (moved)

Can't parse networkstatus consensus time

Child items 0

Activity