Help me understand sdwdate

[Ulrich Windl]

Hi!

I'm not a complete dummy regarding time synchronization, but I don't
understand what sdwdate is doing, or more specifically: I don't know
whether it's working as intended.

Let me present some logs:
2021-04-07 20:16:17 - sdwdate - INFO - Running sdwdate main loop.
iteration: 1 / 10000
2021-04-07 20:16:18 - sdwdate - INFO - The clock is sane.
Within build timestamp Fri 11 Oct 2019 12:55:17 AM UTC and expiration
timestamp Tue 17 May 2033 10:00:00 AM UTC.
2021-04-07 20:16:18 - sdwdate - WARNING - Tor is not yet fully
bootstrapped. 52 % done.
Tor reports: NOTICE BOOTSTRAP PROGRESS=52 TAG=loading_descriptors
SUMMARY="Loading relay descriptors"
2021-04-07 20:16:19 - sdwdate - INFO - The clock is sane.
Within build timestamp Fri 11 Oct 2019 12:55:17 AM UTC and expiration
timestamp Tue 17 May 2033 10:00:00 AM UTC.
2021-04-07 20:16:19 - sdwdate - WARNING - Tor is not yet fully
bootstrapped. 57 % done.
Tor reports: NOTICE BOOTSTRAP PROGRESS=57 TAG=loading_descriptors
SUMMARY="Loading relay descriptors"
2021-04-07 20:16:20 - sdwdate - INFO - The clock is sane.
Within build timestamp Fri 11 Oct 2019 12:55:17 AM UTC and expiration
timestamp Tue 17 May 2033 10:00:00 AM UTC.
2021-04-07 20:16:20 - sdwdate - WARNING - Tor is not yet fully
bootstrapped. 61 % done.
Tor reports: NOTICE BOOTSTRAP PROGRESS=61 TAG=loading_descriptors
SUMMARY="Loading relay descriptors"
2021-04-07 20:16:22 - sdwdate - INFO - Prerequisite check: The clock is
sane.
Within build timestamp Fri 11 Oct 2019 12:55:17 AM UTC and expiration
timestamp Tue 17 May 2033 10:00:00 AM UTC.
Clock within consensus parameters consensus/valid-after 2021-04-07
19:00:00 and consensus/valid-until 2021-04-07 22:00:00.
2021-04-07 20:16:22 - sdwdate - INFO - Prerequisite check: Tor fully
bootstrapped.
2021-04-07 20:16:22 - sdwdate - INFO - Start fetching remote times.
2021-04-07 20:16:22 - sdwdate - INFO - Initial time fetching in progress...
2021-04-07 20:16:22 - sdwdate - INFO - Running sdwdate fetch loop.
iteration: 1
2021-04-07 20:16:22 - sdwdate - INFO - Requested urls
['secrdrop5wyphb5x.onion', 'pgpkeysximvxiazm.onion',
'3kyl4i7bfdgwelmf.onion']
2021-04-07 20:17:12 - sdwdate - INFO - Returned urls
"['secrdrop5wyphb5x.onion', 'pgpkeysximvxiazm.onion',
'3kyl4i7bfdgwelmf.onion']"
2021-04-07 20:17:12 - sdwdate - INFO - remote 0: secrdrop5wyphb5x.onion
2021-04-07 20:17:12 - sdwdate - INFO - * comment: https://securedrop.org
https://web.archive.org/web/20170403043247/https://securedrop.org
2021-04-07 20:17:12 - sdwdate - INFO - * status: False
2021-04-07 20:17:12 - sdwdate - INFO - * value: Timeout
2021-04-07 20:17:12 - sdwdate - INFO - remote 1: pgpkeysximvxiazm.onion
2021-04-07 20:17:12 - sdwdate - INFO - * comment:
https://pgpkeys.urown.net
https://web.archive.org/web/20170421213557/https://pgpkeys.urown.net
2021-04-07 20:17:12 - sdwdate - INFO - * status: False
2021-04-07 20:17:12 - sdwdate - INFO - * value: Timeout
2021-04-07 20:17:12 - sdwdate - INFO - remote 2: 3kyl4i7bfdgwelmf.onion
2021-04-07 20:17:12 - sdwdate - INFO - * comment:
http://www.wefightcensorship.org https://archive.fo/GhgMU
2021-04-07 20:17:12 - sdwdate - INFO - * remote_unixtime: 1617826445
2021-04-07 20:17:12 - sdwdate - INFO - * consensus/valid-after:
2021-04-07 19:00:00
2021-04-07 20:17:12 - sdwdate - INFO - * remote_time :
2021-04-07 20:14:05
2021-04-07 20:17:12 - sdwdate - INFO - * consensus/valid-until:
2021-04-07 22:00:00
2021-04-07 20:17:12 - sdwdate - INFO - * time_diff: -187 second(s)
2021-04-07 20:17:12 - sdwdate - INFO - * timesanitycheck: sane
2021-04-07 20:17:12 - sdwdate - INFO - * time_consensus_sanity_check: sane
2021-04-07 20:17:12 - sdwdate - INFO - * remote_status: True
2021-04-07 20:17:12 - sdwdate - INFO - Pool 3: 3kyl4i7bfdgwelmf.onion,
web unixtime: 1617826445, web time: Wed Apr 07 20:14:05 UTC 2021, diff:
-187 seconds
2021-04-07 20:17:12 - sdwdate - INFO - Running sdwdate fetch loop.
iteration: 2
2021-04-07 20:17:12 - sdwdate - INFO - Requested urls
['mprt35sjunnxfa76.onion', 'zvldz46bbxqlw4od.onion']
2021-04-07 20:18:02 - sdwdate - INFO - Returned urls
"['mprt35sjunnxfa76.onion', 'zvldz46bbxqlw4od.onion']"
2021-04-07 20:18:02 - sdwdate - INFO - remote 0: mprt35sjunnxfa76.onion
2021-04-07 20:18:02 - sdwdate - INFO - * comment:
https://informant.taz.de
https://web.archive.org/web/20170329061908/https://informant.taz.de
2021-04-07 20:18:02 - sdwdate - INFO - * remote_unixtime: 1617826493
2021-04-07 20:18:02 - sdwdate - INFO - * consensus/valid-after:
2021-04-07 19:00:00
2021-04-07 20:18:02 - sdwdate - INFO - * remote_time :
2021-04-07 20:14:53
2021-04-07 20:18:02 - sdwdate - INFO - * consensus/valid-until:
2021-04-07 22:00:00
2021-04-07 20:18:02 - sdwdate - INFO - * time_diff: -189 second(s)
2021-04-07 20:18:02 - sdwdate - INFO - * timesanitycheck: sane
2021-04-07 20:18:02 - sdwdate - INFO - * time_consensus_sanity_check: sane
2021-04-07 20:18:02 - sdwdate - INFO - * remote_status: True
2021-04-07 20:18:02 - sdwdate - INFO - remote 1: zvldz46bbxqlw4od.onion
2021-04-07 20:18:02 - sdwdate - INFO - * comment: Transparencia
https://www.transparencia.click
2021-04-07 20:18:02 - sdwdate - INFO - * status: False
2021-04-07 20:18:02 - sdwdate - INFO - * value: Timeout
2021-04-07 20:18:02 - sdwdate - INFO - Pool 1: mprt35sjunnxfa76.onion,
web unixtime: 1617826493, web time: Wed Apr 07 20:14:53 UTC 2021, diff:
-189 seconds
2021-04-07 20:18:02 - sdwdate - INFO - Running sdwdate fetch loop.
iteration: 3
2021-04-07 20:18:02 - sdwdate - INFO - Requested urls
['ltcpool5brio2gaj.onion']
2021-04-07 20:18:06 - sdwdate - INFO - Returned urls
"['ltcpool5brio2gaj.onion']"
2021-04-07 20:18:06 - sdwdate - INFO - remote 0: ltcpool5brio2gaj.onion
2021-04-07 20:18:06 - sdwdate - INFO - * comment:
https://www.litecoinpool.org/help
https://web.archive.org/web/20161114095946/https://www.litecoinpool.org/help
2021-04-07 20:18:06 - sdwdate - INFO - * remote_unixtime: 1617826544
2021-04-07 20:18:06 - sdwdate - INFO - * consensus/valid-after:
2021-04-07 19:00:00
2021-04-07 20:18:06 - sdwdate - INFO - * remote_time :
2021-04-07 20:15:44
2021-04-07 20:18:06 - sdwdate - INFO - * consensus/valid-until:
2021-04-07 22:00:00
2021-04-07 20:18:06 - sdwdate - INFO - * time_diff: -142 second(s)
2021-04-07 20:18:06 - sdwdate - INFO - * timesanitycheck: sane
2021-04-07 20:18:06 - sdwdate - INFO - * time_consensus_sanity_check: sane
2021-04-07 20:18:06 - sdwdate - INFO - * remote_status: True
2021-04-07 20:18:06 - sdwdate - INFO - Pool 2: ltcpool5brio2gaj.onion,
web unixtime: 1617826544, web time: Wed Apr 07 20:15:44 UTC 2021, diff:
-142 seconds
2021-04-07 20:18:06 - sdwdate - INFO - End fetching remote times.
2021-04-07 20:18:06 - sdwdate - INFO - Pool differences, sorted: [-189,
-187, -142]
2021-04-07 20:18:06 - sdwdate - INFO - Median time difference:
-187.000000000
2021-04-07 20:18:06 - sdwdate - INFO - randomize : +0.611985016
2021-04-07 20:18:06 - sdwdate - INFO - New time difference :
-186.388014984
2021-04-07 20:18:06 - sdwdate - INFO - Old unixttime: 1617826686.715282679
2021-04-07 20:18:06 - sdwdate - INFO - New unixtime : 1617826500.327267647
2021-04-07 20:18:06 - sdwdate - INFO - Instantly setting the time by
using command: /bin/date --set "@1617826500.327267647"
2021-04-07 20:15:00 - sdwdate - INFO - /bin/date output: Wed 07 Apr 2021
08:15:00 PM UTC

What makes me wonder: My clock seems to be off by about 3 minutes (186
seconds), and sdwdate care to add a 0.6 second random offset.
That doesn't make sense to me.
I wonder: Is sdwdate setting the correct time at all here?
Or does it mean it took 3 minutes between requesting the sending the
time and receiving it?

Regards,
Ulrich

[Sven Semmler]

Hi Ulrich,

have you considered asking those questions over at forums.whonix.org?
swdate is part of Whonix which is packaged with Qubes OS but a separate
project.

Here is a thread that would probably connect you with the right people
to answer your questions:

https://forums.whonix.org/t/sdwdate-and-sdwdate-gui-development-thread/1137/140