Bug #15743

Too much log when using obfs4 in Tails

Added by sajolida 2018-07-19 16:40:56 . Updated 2018-12-16 13:26:11 .

Status:
Resolved
Priority:
Low
Assignee:
Category:
Tor configuration
Target version:
Start date:
2018-07-19
Due date:
% Done:

100%

Feature Branch:
bugfix/15743-tor-log-level-with-bridges+force-all-tests
Type of work:
Test
Blueprint:

Starter:
Affected tool:
Deliverable for:

Description

From Cybelle’s report: https://lists.torproject.org/pipermail/tor-project/2018-July/001871.html

Tails 3.7 Debug or a high level of logging still present in /var/log/tor/log - when using obf4 (or whatever) bridges. This is a reminder that this problem continues to exist in Tails 3.7 (and several versions prior). The logging is crazy and consumes several MB per session. “warn 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.

I think we should check that…


Subtasks


Related issues

Related to Tails - Bug #15548: Tails can't establish a connection with obfs4 bridges and a hardware clock too far away from UTC Confirmed 2018-05-09
Blocks Tails - Feature #15507: Core work 2019Q1: Foundations Team Resolved 2018-04-08

History

#1 Updated by sajolida 2018-07-19 16:41:20

  • Assignee set to intrigeri
  • QA Check set to Info Needed

intrigeri: Is that part of the Foundation Team’s work?

#2 Updated by intrigeri 2018-07-22 02:27:50

  • Assignee changed from intrigeri to sajolida

> I think we should check that…

Data points:

  • We temporarily set the log level to info and then set it back to notice once Tor has bootstrapped.
  • This has been the case since 2012.
  • This is a workaround to inconsistent (from our perspective) behaviour in tor. I don’t know if there’s a good reason behind this inconsistency. I don’t know if this inconsistent behaviour is still present nowadays.

I don’t really understand what’s the problem with this temporary higher level of logging. Could someone explain?

#3 Updated by intrigeri 2018-07-22 02:28:31

> intrigeri: Is that part of the Foundation Team’s work?

It could potentially fit in “if time allows, do whatever code task the project sees as top-priority, such as fixing Holes in the Roof, important bugs, or implementing a feature that is needed to keep Tails relevant”. I personally don’t see this as top-priority at all.

#4 Updated by sajolida 2018-07-29 11:14:16

  • Assignee changed from sajolida to intrigeri
  • QA Check deleted (Info Needed)

> I don’t really understand what’s the problem with this temporary higher level of logging. Could someone explain?
I think that the problem is that people are scared by:

[warn] 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.

But I’ll let you decide on the priority.

#5 Updated by Anonymous 2018-08-16 10:33:52

  • Status changed from New to Confirmed
  • QA Check set to Info Needed

Info needed for the priority of this task.

#6 Updated by Anonymous 2018-08-18 12:02:04

  • related to Bug #9268: obfs4 bridges often don't work (maybe MTU?) added

#7 Updated by intrigeri 2018-08-20 09:33:48

  • related to deleted (Bug #9268: obfs4 bridges often don't work (maybe MTU?))

#8 Updated by intrigeri 2018-08-20 09:39:28

  • Target version set to Tails_3.12
  • QA Check deleted (Info Needed)

sajolida wrote:
> > I don’t really understand what’s the problem with this temporary higher level of logging. Could someone explain?
> I think that the problem is that people are scared by:

OK, I understand how that message can be scary. So what I’ll do as part of my FT work is: check if our “hack that increases tor’s logging level”: is still needed. If it is, file a ticket on the Tor bug tracker to check whether the tor behaviour that made us add this hack is on purpose and justified. If it is not, then remove it.

I think that’s the most FT time/energy I can justify spending on this and most likely I’ll need months before I get there.

#9 Updated by intrigeri 2018-08-20 09:39:58

#10 Updated by sajolida 2018-08-21 10:57:20

  • Priority changed from Normal to Low

Ah, and it’s definitely low prio :)

#11 Updated by letthemeatpie 2018-09-11 02:52:27

>I don’t really understand what’s the problem with this temporary higher level of logging. Could someone explain?

>>I think that the problem is that people are scared by:
>>[warn] 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.

IMO, it’s not that simple. The verbose logging should not be there to begin with, especially if you’re using bridges! It’s sensitive, real time information with
overly detailed data about the Tor session. There are many logical reasons as to why this is not a good thing - and the warning is there for a reason. Please fix.

#12 Updated by intrigeri 2018-09-19 15:12:15

letthemeatpie wrote:
> Please fix.

See Bug #15743#note-8. Help is welcome if you want to see this happen faster :)

#13 Updated by intrigeri 2018-11-17 20:48:06

  • Status changed from Confirmed to In Progress

Applied in changeset commit:tails|5b2ad40ff3186831fadedc5fce044c2dc6de0a84.

#14 Updated by intrigeri 2018-11-17 20:48:33

  • Feature Branch set to bugfix/15743-tor-log-level-with-bridges+force-all-tests

Let’s see how things work without our hack.

#15 Updated by intrigeri 2018-11-18 07:50:29

  • % Done changed from 0 to 10

Our does not seem necessary anymore when using regular bridges: I’ve dropped the hack on the topic branch and the “Clock is one day in the future in bridge mode” automated test that I’ve (re)introduced there passes. Will now test with obfs4.

#16 Updated by intrigeri 2018-11-18 08:29:04

I’ve manually traced the differing log levels in the tor source code (release-0.3.4 branch at commit 8517e2d6e9cf1500a1cb531c3bcf49004045989e) and it boils down to:

<code class="c">
  int severity;
  /* Note that this warns more loudly about time and validity if we were
   * _trying_ to connect to an authority, not necessarily if we _did_ connect
   * to one. */
  if (started_here &&
      router_digest_is_trusted_dir(TLS_CHAN_TO_BASE(chan)->identity_digest))
    severity = LOG_WARN;
  else
    severity = LOG_PROTOCOL_WARN;

  const ed25519_public_key_t *checked_ed_id = NULL;
  const common_digests_t *checked_rsa_id = NULL;
  or_handshake_certs_check_both(severity,
</code>

… in src/or/channeltls.c.

We’ve introduced our own hack in commit:4b11d7c71b522418bfc2cf4fa3e3a14eea5e350e (Nov 2012). Since then, this part of the tor code has seen a few refactoring passes.

#17 Updated by intrigeri 2018-11-20 12:34:39

  • related to Bug #15548: Tails can't establish a connection with obfs4 bridges and a hardware clock too far away from UTC added

#18 Updated by intrigeri 2018-11-20 12:35:48

intrigeri wrote:
> Our does not seem necessary anymore when using regular bridges: I’ve dropped the hack on the topic branch and the “Clock is one day in the future in bridge mode” automated test that I’ve (re)introduced there passes. Will now test with obfs4.

With obfs4, as reported today on Bug #15548, there’s nothing 20-time.sh can do to fix things up when the RTC is incorrect, regardless of whether our hack is applied or not. So I’ll drop the hack.

#19 Updated by intrigeri 2018-11-20 12:41:29

  • Assignee changed from intrigeri to segfault
  • Target version changed from Tails_3.12 to Tails_3.11
  • % Done changed from 10 to 50
  • QA Check set to Ready for QA

I’ve (re-)introduced a test to ensure our dirty hack (“tordate” aka. 20-time.sh) still works for regular bridges even without raising the log level. This makes me confident enough that this can go into 3.11, but if you prefer, feel free to merge into devel instead of stable.

#20 Updated by segfault 2018-11-21 21:26:58

  • Assignee deleted (segfault)
  • QA Check changed from Ready for QA to Pass

LGTM

I didn’t know about the obfs4 issues. obfs4 is the recommended pluggable transport, so this seems like an important issue to me. I’m glad about your progress on Bug #15168, it seems promising that this can be fixed soonish.

#21 Updated by segfault 2018-11-21 21:28:32

  • Status changed from In Progress to Fix committed
  • % Done changed from 50 to 100

Applied in changeset commit:tails|0a6d80f5824a933f73d763beb7a3ff2af1f3159c.

#22 Updated by CyrilBrulebois 2018-12-16 13:26:11

  • Status changed from Fix committed to Resolved