GitLab

Commit e67f4441eb2646368e3e7cb1bcee403667b786f0 introduced a safeguard in dirvote_get_next_valid_after_time() in order to recalculate the voting schedule if it is called before it was initialized.

Turns out that it is actually called very early for a directory authority with sr_init() thus the voting schedule is first initialized through that safeguard.

That made the following check in dirvote_act() not work so the voting schedule is never recalculated using the now that we are about to use to vote with:

  if (!voting_schedule.voting_starts) {
    ...
    dirvote_recalculate_timing(options, now);
  }

This lead to warnings such as (snipping some lines):

Nov 08 11:58:19.169 [info] Choosing expected valid-after time as 2017-11-08 16:58:20: consensus_set=0, interval=5
[...]
Nov 08 11:58:20.173 [notice] Time to vote.
[...]
Nov 08 11:58:20.175 [notice] Choosing valid-after time in vote as 2017-11-08 16:58:25: consensus_set=0, last_interval=5
Nov 08 11:58:20.181 [warn] Rejecting vote from 127.0.0.1 with valid-after time of 2017-11-08 16:58:25; we were expecting 2017-11-08 16:58:20
Nov 08 11:58:20.181 [warn] Couldn't store my own vote! (I told myself, 'Bad valid-after time'.)

Voting schedule object was set at "11:58:19" which made a valid_after time to "11:58:20" but we voted at "11:58:20" without updating that schedule so we ended up computing a valid_after = "11:58:25" in the vote but not in the voting schedule.

I think the fix here is to always recalculate our voting schedule when we are about to vote to use the "now" value maybe?