Opened 9 years ago

Closed 8 years ago

Last modified 7 years ago

#1511 closed defect (fixed)

Accounting Resets when System Timezone Changes

Reported by: BarkerJr Owned by: nickm
Priority: High Milestone:
Component: Core Tor/Tor Version: Tor: 0.2.2.13-alpha
Severity: Keywords: tor-relay
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

If you have one timezone set and burn through your bandwidth, then change the system timezone and restart Tor, it will reset and burn through the bandwidth a second time. This causes double the intended bandwidth to get used.

Child Tickets

Change History (21)

comment:1 Changed 9 years ago by BarkerJr

Version: Tor: 0.2.2.13-alpha

comment:2 Changed 9 years ago by nickm

Hm. This is probably our fault for having the accounting code use local time instead of UTC. This will probably need some thinking to get right...

Are there any interesting messages in the log when Tor starts up in the new timezone? In particular, I'm wondering if you're seeing the warning, "Mismatched accounting interval; starting a fresh one."

comment:3 Changed 9 years ago by nickm

On further investigation, the culprit code is probably the logic in configure_accounting() that resets the accounting period if the start of the current accounting period is not the same as what it was before.

It's not totally clear what to do in this case. If the start of the accounting period moves _back_ in time, then it's probably okay to remember the bytes we already wrote. But what should we do if it moves forward in time, yet still overlaps with the previous accounting period? (Ignore for now the fact that we don't record when the old period was supposed to end.)

One easy fix would be to add some way to specify that accounting periods are to be taken relative to UTC rather than local time, but that leaves the major issue unaddressed.

comment:4 Changed 9 years ago by BarkerJr

The only real interesting log entry I got was this:
May 17 03:29:10.041 [warn] Mismatched accounting interval; starting a fresh one.

The state file had changed.
Old: AccountingIntervalStart 2010-05-01 04:00:00
New: AccountingIntervalStart 2010-05-01 00:00:00

I have a snapshot of the old /usr/local/var/lib/tor if needed.

comment:5 Changed 9 years ago by nickm

Milestone: Tor: 0.2.2.x-final
Owner: set to nickm
Status: newassigned

comment:6 Changed 9 years ago by nickm

So, here's the best revised behavior I can think of on changing an accounting period in progress:

  • If the period start moves backwards, remember the old bytes.
  • If the period start moves forwards, and there's more than 2% overlap, remember the old bytes.
  • Otherwise, if the period start moves forward and the old period overlaps the new one less than 2%, then don't remember the old bytes.

But before we implement this, we should figure out bug #1789, which might mean that accounting is broken in other ways.

comment:7 Changed 9 years ago by arma

Priority: normalmajor

Triage: if you're in a timezone that does daylight saving time, does this bug hit you? If so, it's a bug that should be resolved, perhaps in 0.2.1.x also.

Nick says "It's not too hard, either, if we do the hack suggested in my last comment."

Would be good to get solved for the rc.

comment:8 Changed 9 years ago by nickm

Status: assignedneeds_review

See branch "bug1511" in my public repository. It makes us tolerate 50% skew either way, which should be enough to tolerate DST shifts.

comment:9 Changed 9 years ago by arma

Looks fine to me. Green light to merge when you like.

(That being said, I hate time comparison calculations. :)

I will probably revise this to a 'major bugfix' when I'm making the changelog, on the assumption that this really is a bug that happens when a machine moves into or out of daylight saving time. If that's true, we should probably merge this into 0.2.1.x and then on to master. It's a serious bug.

All of that said, one question: you say "if it changes by up to 50% either way", but then your comment says "The start of the period is now a little later than we remembered." If the period has shifted forward, isn't the old time now in the previous interval, meaning

start_of_accounting_period_containing(interval_start_time)

would be like a month earlier?

comment:10 Changed 9 years ago by nickm

arg, I think you're right. In the case where the period shifts forward, we'll hit the first check in configure_accounting, which checks for

start_of_accounting_period_after(interval_start_time) <= now

and advances the accounting period.

Not quite sure what the right way to express the fix is. I'll take a crack at it... have a look at the latest patch on my bug1511 branch? If you like it, I'll backport to 0.2.1.x and do the merging

comment:11 Changed 9 years ago by nickm

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

Reviewing it myself 2 days later, I still believe in it. Merging it.

There is now also a "bug1511_on_021" branch on public. Moving this bug to 0.2.1.x-final.

comment:12 Changed 9 years ago by nickm

Still needs review.

comment:13 Changed 9 years ago by Sebastian

hrm. BarkerJr reported #2151 and #2146, might they be related? Or is it all #2003

comment:14 in reply to:  13 Changed 9 years ago by rransom

Replying to Sebastian:

hrm. BarkerJr reported #2151 and #2146, might they be related? Or is it all #2003

I think you mean #2152, not #2151.

comment:15 Changed 9 years ago by arma

Haven't reviewed patch yet, but since we think this triggers on DST, it is probably a good idea to backport in for 0.2.1.28.

That said, I think we should block the backport until we resolve #2146.

comment:16 Changed 9 years ago by nickm

Right now I'm thinking the best we can do for users here is _not_ to backport this (or #2146) to 0.2.1. Our chances of getting it wrong are high enough, and the workaround ("upgrade to 0.2.2.x") is simple enough that we should call this "won't fix" in the 0.2.1. series.

comment:17 Changed 9 years ago by BarkerJr

I got this error today on 0.2.2.22:

Mar 01 00:00:00.023 [warn] Mismatched accounting interval: moved by 90.32%. Starting a fresh one.
Mar 01 00:00:00.189 [info] reset_accounting(): Starting new accounting interval.

Not sure why, since DST has not changed.

comment:18 Changed 8 years ago by arma

Resolution: fixed
Status: needs_reviewclosed

Closing this one since we decided to abandon the backport to 0.2.1.

I opened #3020 for the new concern on 0.2.2 (but we need more details before we have a prayer of fixing it).

comment:19 Changed 7 years ago by nickm

Keywords: tor-relay added

comment:20 Changed 7 years ago by nickm

Component: Tor RelayTor

comment:21 Changed 7 years ago by nickm

Milestone: Tor: 0.2.1.x-final

Milestone Tor: 0.2.1.x-final deleted

Note: See TracTickets for help on using tickets.