[tor-relays] [WARN] Your system clock just jumped 100 seconds forward; assuming established circuits no longer work.

Thu Feb 20 13:28:31 UTC 2014

On 2/20/14, grarpamp <grarpamp at gmail.com> wrote:
>>> - configure tor to syslog
>>
>> added
>
> 'Log syslog'

The example in etc/torrc is 'Log notice syslog' which I uncommented.

>>> - send an ntpdate -q pool to syslog every 5min,
>>>  remove when solved.
>>
>> Do you mean disable ntpd daemon, and run this instead? Sounds easy
>> enough, I imagine:
>> service ntp stop; while true; do ntpd -gqn -l /var/log/syslog; sleep 5m;
>> done
>> service ntp start
>
> I meant remove it when solved so you don't forget
> and you're banging on the pool every 5 for eternity.
>
> -l /var/log/syslog - this is potentially overwriting or blocking this file
> which
> is managed by syslogd in syslog.conf, pick another new file, or just
> better to use ntp.conf logconfig option.
>
> if you were running ntpd during problems, and ntpd was not working
> right, then ntpdate would be just a tool to separately query and
> print external pool time without impact to running system, for
> comparing with system time.

Thank you. Restarted ntpd, installed ntpdate, running this script:
while true; do sleep 5m; ntpdate -qsv 3.debian.pool.ntp.org; echo "---"; done

...
> ntpd disciplines kernel clock by calculating drift from the net
> and feeds back small rate deltas to kernel.
> no ntpd -> no discipline -> lots of drift... then these manual slews
> and jumpsets happen for people setting time manually, which is non
> ideal, get the daemon running right on its own.
> Tor said 100sec forward, so it maybe sees what look like
> the forward jumps above as accumulated.
> ntpd would not do that if running right, so check for some
> ntp thing in crontab maybe making your jump.

# cd etc; # grep -in ntp cron*/*
cron.daily/ntp:3:# The default Debian ntp.conf enables logging of
various statistics to
cron.daily/ntp:4:# the /var/log/ntpstats directory.  The daemon
automatically changes
cron.daily/ntp:9:statsdir=$(cat /etc/ntp.conf | grep -v '^#' | sed -n
's/statsdir $[^ ][^ ]*$/\1/p')

Nothing special at all - just standard debian ntp install.

I've now gone and added some ntp servers from telstra, iinet and ntp.org.

>> So it seems that the slew is somehow not being set properly, or
>> rather, now that ntpd is being run every 5 minutes, it gets to add
>> about .2 of a second pretty regularly (I'll continue to watch of
>> course), so something definitely seems amiss. I'm not loading the
>> system default ntpd config file.
>>
>> It looks like time could be running slow and being _not_ updated,
>> except a few times a day, resulting in the 2-3minute jump.
>
> Maybe ntpd is not working/running and cron is maybe doing manual sets.

I've restarted ntpd and running the above script as mentioned. Will
post some output soon.

# service ntp status
NTP server is running.

>>> - send *.* to /var/log/all
>>
>> intended to be a torrc config? It sounds like a good idea to send
>> everything to one log file for a while, till I debug this.
>
> man syslog.conf

Thanks. Looks like debian defaults to rsyslog. Anyway, I know what you
are referring to now, thanks (I'm a bit green, although have been
reported to have at least 1.5 brain cells - though some dispute this
as being biased sample).

>> interesting repeating lines all over daemon.log re ntpd (but not
>> nothing similar in today's daemon.log though.
>
> ntp automatically chooses who it thinks is best to listen to
> among given peers.

Good. Well now I have a number of ntp servers listed, hopefully it
shall improve the situation.

>>> If [system ntp]date
>>> is set, then under ntpd running for 15min+,
>>> if ntpq -np does not show one asterisk(*) in front
>
> Only one of ntpd or ntpdate should be doing the actual timing.
> For most people that means 'ntpd -g' starting as daemon
> at boot, with 'ntpdate -q' and 'ntpq -np' as just cli checks.

Thanks. That's what I'm doing now.

TOR relay docs should perhaps include, for debian "add your isp's ntp
servers, and possibly a few from ntp.org, to your /etc/ntpd.conf (and
check this file is sane)".

OK, grepping logs time...:
Feb 20 23:51:35 lt8 ntpdate[29233]: adjust time server 130.102.2.123
offset -0.024247 sec
Feb 20 23:57:31 lt8 ntpdate[29289]: adjust time server 54.252.129.186
offset 0.018113 sec
Feb 21 00:02:38 lt8 ntpdate[29329]: adjust time server 59.167.170.228
offset 0.025050 sec
Feb 21 00:07:46 lt8 ntpdate[29377]: adjust time server 121.0.0.41
offset 0.017704 sec
Feb 21 00:12:53 lt8 ntpdate[29380]: adjust time server 203.206.205.83
offset 0.004626 sec
Feb 21 00:18:00 lt8 ntpdate[29395]: adjust time server 27.116.36.44
offset -0.003997 sec
Feb 21 00:23:08 lt8 ntpdate[29411]: adjust time server 118.88.20.194
offset -0.003071 sec

Looking very hopeful - convergence of time offset on the way. I guess
something I did to ntpd.conf (probably adding servers above the
default debian entries which are:
server 0.debian.pool.ntp.org iburst
server 1.debian.pool.ntp.org iburst
server 2.debian.pool.ntp.org iburst
server 3.debian.pool.ntp.org iburst

I'll check it again in the morning. Next stop, looking into the cgnat
issue (occasionally the IP change appears to cause all clients to
disconnect, but only sometimes - I'll start another thread if I get
back to checking this issue).

Thank you so much, hopefully this TOR relay be stable and add to the
security of the internet,
Zenaan