sdwdate and sdwdate-gui development thread

Patrick · October 17, 2015, 9:40pm

[quote=“troubadour, post:199, topic:1137”]Makes the python code easier to read.

Something strange. When calling “/usr/lib/anon-shared-helper-scripts/settings_echo” from a terminal in Workstation, it returns

TOR_CONTROL_HOST="127.0.0.1".
When called from the python script, we get the correct value “10.152.152.10”.

In Gateway, it returns “127.0.0.1”, as expected.[/quote]
It’s because the env var TOR_CONTROL_HOST is already set in Whonix konsole. (by package anon-ws-disable-stacked-tor)
It will not be the case when run by systemd, because that cleans up the env vars.

Patrick · October 17, 2015, 9:41pm

“sudo” also cleans up the environment, unless you are using “sudo -E”. So you could try “sudo” or “sudo -u user” to emulate this.

Patrick · October 17, 2015, 9:43pm

Makes the python code easier to read. :)

Glad you like it!

https://github.com/troubadoour/sdwdate/commit/064f27675ff44396d2911ae3c265f5a7cc9ed445

It should search for the actual variable name TOR_CONTROL_HOST. Not just any IP address. Otherwise when the output of the script is extended, it may match the wrong variable.

troubadour · October 17, 2015, 10:17pm

The new key (troubadour, used in my last mail) is on hkp://qdigse2yzvuglcix.onion (created today).

Patrick · October 17, 2015, 11:12pm

Didn’t work.

gpg --keyserver hkp://qdigse2yzvuglcix.onion --search-keys trobador@riseup.net gpg: searching for "trobador@riseup.net" from hkp server qdigse2yzvuglcix.onion ?: qdigse2yzvuglcix.onion: Host not found gpgkeys: HTTP search error 7: couldn't connect: Success gpg: key "trobador@riseup.net" not found on keyserver gpg: keyserver internal error gpg: keyserver search failed: keyserver error

But the following worked.

gpg --search-keys trobador@riseup.net gpg: searching for "trobador@riseup.net" from hkp server keys.gnupg.net (1) troubadour <trobador@riseup.net> 4096 bit RSA key CDFFEA3E, created: 2015-10-17, expires: 2020-10-15 (2) troubadour <trobador@riseup.net> 4096 bit RSA key 547687FE, created: 2014-10-15, expires: 2015-10-15 (expired) (3) troubadour <trobador@riseup.net> 4096 bit RSA key 848861F1, created: 2014-10-15, expires: 2015-10-15 (expired) (4) troubadour <trobador@riseup.net> 4096 bit RSA key D9A2B7A5, created: 2014-04-27, expires: 2015-04-27 (revoked) (expired) Keys 1-4 of 4 for "trobador@riseup.net". Enter number(s), N)ext, or Q)uit > 1 gpg: requesting key CDFFEA3E from hkp server keys.gnupg.net gpg: key CDFFEA3E: public key "troubadour <trobador@riseup.net>" imported gpg: Total number processed: 1 gpg: imported: 1 (RSA: 1)

Normally you sign your new key with your old one but in this case I am sure it’s legit.

troubadour · October 20, 2015, 10:02pm

Pushed a batch of cosmetic commits.

The custom .d configuration files setup is tested OK.

Added a unit test. It requests time from all the servers, prints out and writes the results to a file with unixtime in the file name. Modified config.py with production and test modes in order to get all the url including multiple url from the same site.

It should search for the actual variable name TOR_CONTROL_HOST. Not just any IP address. Otherwise when the output of the script is extended, it may match the wrong variable.

Done. https://github.com/troubadoour/sdwdate/commit/09b21f2dbb4bdf091943c5e38b7f777bd9173e40

Patrick · October 21, 2015, 2:58pm

Please add proxy IP / port to the log output on startup. I guess this could be a real time safer later during support work.

Patrick · October 21, 2015, 3:18pm

Maximum number of allowed failures reached in pool 3 (8)

When we read this later during log analysis we need some more information.

Total number of pool members.
allowed_failure_ratio

Maybe something like this. Not sure about a good wording.

“Maximum number (Y of XX) of allowed failures reached in pool 3. Giving up.”

Patrick · October 21, 2015, 3:47pm

Works good so far. Anything else we require before it should replace the master branch?

I plan on reading this whole thread again to make sure nothing is forgotten, but I guess now sdwdate-python is doing everything sdwdate-bash is doing?

troubadour · October 21, 2015, 8:08pm

I have read through the thread, did not find anything essential.

A couple of things left:

kill sclockadj in sdwdate without calling sclockadj_kill_helper
remove unused files in /usr/lib/sdwdate
remove files in usr/share/test_d_files, as they were for development only.

Wondering about allowed_failure_ratio. At the moment It’s hardcoded. If a pool begin to deteriorate too much, we could give a mean to the user to modify it in the configuration file before the updates to the pool members are ready.

Patrick · October 21, 2015, 8:31pm

- kill sclockadj in sdwdate without calling sclockadj_kill_helper

sclockadj runs as root. sdwdate runs as user sdwdate. sdwdate is allowed to run sclockadj and sclockadj_kill_helper as root by an /etc/sudoers.d exception. Therefore, I think external calling would be required so or so.

sclockadj_kill_helper does some sanity checks. It expects, that the calling one (sdwdate) could be malicious. It lets one only kill sclockadj. Not any arbitrary process.

Now, you could rewrite sclockadj_kill_helper in python, but I don’t really think it’s necessary. That script is well tested, well working and has very little maintenance effort.

- remove unused files in /usr/lib/sdwdate

Yes.

- remove files in usr/share/test_d_files, as they were for development only.

Yes.

Wondering about allowed_failure_ratio. At the moment It's hardcoded. If a pool begin to deteriorate too much, we could give a mean to the user to modify it in the configuration file before the updates to the pool members are ready.

Yes. Good idea. We never know when we may need this. Or for custom configuration, sounds useful.

troubadour · October 22, 2015, 6:47am

There is an issue with sleeping time. Will look into it.

troubadour · October 23, 2015, 7:39am

Fixed.

The problem seems to stem from from python’s time.sleep() using the system clock to measure its inactive state time. When sclockadj is running, it starts behaving [very] erratically. Replaced with sh sleep, which works in sdwdate bash, most likely because it’s using a timer/counter.

A logging bug, start and end fetching times were identical.

Is sdwdate-gui popup message, increased timer period (for signal handling) to reduce cpu usage.

troubadour · October 23, 2015, 9:16pm

Three commits:

logging proxy settings
logging proxy settings · troubadoour/sdwdate@112d21e · GitHub
expanded max_pool_failures message
expanded max_pool_failures message · troubadoour/sdwdate@d442166 · GitHub
MAX_FAILURE_RATIO in /etc/sdwdate.d/30_default.conf (modifies max_pool_failures message too)
MAX_FAILURE_RATIO in /etc/sdwdate.d/30_default.conf · troubadoour/sdwdate@8c028f1 · GitHub

An extra commit for a typo in /etc/sdwdate.d/30_default.conf.

Seen from this side, the python branch can replace the master.

Patrick · October 24, 2015, 10:51am

Works good.

Tor control host: 127.0.0.1 Tor control port: 9050

Tor socks ...

(Control is for ControlPort. sdwdate does not directly use it. [Only the external connection check does.])

[hr]

I’ve set DisableNetwork 1 in torrc outside of Whonix.

2015-10-24 10:47:25,616 - sdwdate.log - INFO - Signal SIGTERM received. sdwdate stopped by user. 
2015-10-24 10:47:25,903 - sdwdate.log - INFO - sdwdate started. PID 16709
2015-10-24 10:47:25,926 - sdwdate.log - INFO - Tor control host:  127.0.0.1  Tor control port:  9050
2015-10-24 10:47:25,933 - sdwdate.log - INFO - Fetching remote times, start Sat Oct 24 10:47:25 UTC 2015 (unixtime 1445683645.93)
2015-10-24 10:47:25,935 - sdwdate.log - INFO - The clock is sane
 Current time Sat Oct 24 10:47:25 UTC 2015
2015-10-24 10:47:25,935 - sdwdate.log - INFO - Fetching remote times...
2015-10-24 10:47:25,935 - sdwdate.log - INFO - Running sdwdate loop, iteration 1
2015-10-24 10:47:25,935 - sdwdate.log - INFO - Requested urls ['gawker5oxtsc6fa7.onion', '5r4bjnjug3apqdii.onion', 'fncuwbiisyh6ak3i.onion']
2015-10-24 10:47:25,990 - sdwdate.log - INFO - Returned urls "['gawker5oxtsc6fa7.onion', '5r4bjnjug3apqdii.onion', 'fncuwbiisyh6ak3i.onion']"
2015-10-24 10:47:25,990 - sdwdate.log - INFO - Remote status "gawker5oxtsc6fa7.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:25,991 - sdwdate.log - INFO - Remote status "5r4bjnjug3apqdii.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:25,991 - sdwdate.log - INFO - Remote status "fncuwbiisyh6ak3i.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:25,991 - sdwdate.log - INFO - Running sdwdate loop, iteration 2
2015-10-24 10:47:25,991 - sdwdate.log - INFO - Requested urls ['swdi5ymnwmrqhycl.onion', '6iolddfbfinntq2b.onion', 'cwoiopiifrlzcuos.onion']
2015-10-24 10:47:26,035 - sdwdate.log - INFO - Returned urls "['swdi5ymnwmrqhycl.onion', '6iolddfbfinntq2b.onion', 'cwoiopiifrlzcuos.onion']"
2015-10-24 10:47:26,036 - sdwdate.log - INFO - Remote status "swdi5ymnwmrqhycl.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,036 - sdwdate.log - INFO - Remote status "6iolddfbfinntq2b.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,036 - sdwdate.log - INFO - Remote status "cwoiopiifrlzcuos.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,037 - sdwdate.log - INFO - Running sdwdate loop, iteration 3
2015-10-24 10:47:26,037 - sdwdate.log - INFO - Requested urls ['vtjkwwcq5osuo6uq.onion', '5r4bjnjug3apqdii.onion', '344c6kbnjnljjzlz.onion']
2015-10-24 10:47:26,078 - sdwdate.log - INFO - Returned urls "['vtjkwwcq5osuo6uq.onion', '5r4bjnjug3apqdii.onion', '344c6kbnjnljjzlz.onion']"
2015-10-24 10:47:26,078 - sdwdate.log - INFO - Remote status "vtjkwwcq5osuo6uq.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,079 - sdwdate.log - INFO - Remote status "5r4bjnjug3apqdii.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,079 - sdwdate.log - INFO - Remote status "344c6kbnjnljjzlz.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,079 - sdwdate.log - INFO - Running sdwdate loop, iteration 4
2015-10-24 10:47:26,080 - sdwdate.log - INFO - Requested urls ['vbmwh445kf3fs2v4.onion', 'w6csjytbrl273che.onion', 'msydqstlz2kzerdg.onion:80']
2015-10-24 10:47:26,118 - sdwdate.log - INFO - Returned urls "['vbmwh445kf3fs2v4.onion', 'w6csjytbrl273che.onion', 'msydqstlz2kzerdg.onion:80']"
2015-10-24 10:47:26,119 - sdwdate.log - INFO - Remote status "vbmwh445kf3fs2v4.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,119 - sdwdate.log - INFO - Remote status "w6csjytbrl273che.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,119 - sdwdate.log - INFO - Remote status "msydqstlz2kzerdg.onion:80", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,120 - sdwdate.log - INFO - Running sdwdate loop, iteration 5
2015-10-24 10:47:26,120 - sdwdate.log - INFO - Requested urls ['33y6fjyhs3phzfjj.onion', '5r4bjnjug3apqdii.onion', 'fncuwbiisyh6ak3i.onion']
2015-10-24 10:47:26,159 - sdwdate.log - INFO - Returned urls "['33y6fjyhs3phzfjj.onion', '5r4bjnjug3apqdii.onion', 'fncuwbiisyh6ak3i.onion']"
2015-10-24 10:47:26,159 - sdwdate.log - INFO - Remote status "33y6fjyhs3phzfjj.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,159 - sdwdate.log - INFO - Remote status "5r4bjnjug3apqdii.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,160 - sdwdate.log - INFO - Remote status "fncuwbiisyh6ak3i.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,160 - sdwdate.log - INFO - Running sdwdate loop, iteration 6
2015-10-24 10:47:26,160 - sdwdate.log - INFO - Requested urls ['y6xjgkgwj47us5ca.onion', 'abkjckdgoabr7bmm.onion', 'uj3wazyk5u4hnvtk.onion']
2015-10-24 10:47:26,202 - sdwdate.log - INFO - Returned urls "['y6xjgkgwj47us5ca.onion', 'abkjckdgoabr7bmm.onion', 'uj3wazyk5u4hnvtk.onion']"
2015-10-24 10:47:26,203 - sdwdate.log - INFO - Remote status "y6xjgkgwj47us5ca.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,203 - sdwdate.log - INFO - Remote status "abkjckdgoabr7bmm.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,204 - sdwdate.log - INFO - Remote status "uj3wazyk5u4hnvtk.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,204 - sdwdate.log - INFO - Running sdwdate loop, iteration 7
2015-10-24 10:47:26,204 - sdwdate.log - INFO - Requested urls ['udrciweihl4qe63p.onion', 'ppdz5djzpo3w5k2z.onion', '3g2upl4pq6kufc4m.onion:80']
2015-10-24 10:47:26,251 - sdwdate.log - INFO - Returned urls "['udrciweihl4qe63p.onion', 'ppdz5djzpo3w5k2z.onion', '3g2upl4pq6kufc4m.onion:80']"
2015-10-24 10:47:26,252 - sdwdate.log - INFO - Remote status "udrciweihl4qe63p.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,252 - sdwdate.log - INFO - Remote status "ppdz5djzpo3w5k2z.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,253 - sdwdate.log - INFO - Remote status "3g2upl4pq6kufc4m.onion:80", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,253 - sdwdate.log - INFO - Running sdwdate loop, iteration 8
2015-10-24 10:47:26,253 - sdwdate.log - INFO - Requested urls ['v6gdwmm7ed4oifvd.onion', 'pltloztihmfrg2sw.onion', 'wi7qkxyrdpu5cmvr.onion']
2015-10-24 10:47:26,292 - sdwdate.log - INFO - Returned urls "['v6gdwmm7ed4oifvd.onion', 'pltloztihmfrg2sw.onion', 'wi7qkxyrdpu5cmvr.onion']"
2015-10-24 10:47:26,293 - sdwdate.log - INFO - Remote status "v6gdwmm7ed4oifvd.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,293 - sdwdate.log - INFO - Remote status "pltloztihmfrg2sw.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,294 - sdwdate.log - INFO - Remote status "wi7qkxyrdpu5cmvr.onion", False: connect error: Error connecting to SOCKS5 proxy  127.0.0.1:9050: [Errno 111] Connection refused
2015-10-24 10:47:26,294 - sdwdate.log - WARNING - Maximum allowed number of failures reached in pool 3 (8 of 26). Giving up.
 If the problem occurs too frequently, please report it.
 You may increase MAX_FAILURE_RATIO (see /etc/sdwdate.d/30_default.conf).

 Sleeping for 10 minutes.

The last message is not good. The problem is that it would be the most frequent message in case of issues.
“You may increase MAX_FAILURE_RATIO (see /etc/sdwdate.d/30_default.conf).” leads to wrong track, a dead end.
Not sure its good to encourage everyone to do that. Then they ask how to do that, which is not trivial. (Open with root rights, user 50_… rather than 30_…, restart sdwdate, etc.)
Maybe we not care about this, since the connection checker should deal with it in Whonix.

troubadour · October 24, 2015, 6:26pm

Tor socks …[/quote]
Corrected.

The last message is not good. The problem is that it would be the most frequent message in case of issues.

Yes, it can happen for different reasons, so it was removed. I left the part asking to report if it becomes frequent.

Added some HTML in te_pe_tb_check (bootstrap status and Tor disabled).

troubadour · November 19, 2015, 9:29pm

Even if could be superseded in the future, there are some issues auto-starting sdwdate-gui in Qubes-Whonix.

1 - it looks like “/etc/xdg/autostart” in not honored in the Qubes vms (which probably makes sense).

2 - if started as user sdwdate, a d-bus error pops up.

Client failed to connect to the D-BUS daemon: Failed to connect to socket /tmp/dbus-xxxxxxxxx: Connection refused

Added a file in “/etc/X11/Xsession.d” running sdwdate-gui as root if Qubes is detected. commit e9f10493

Left “/etc/xdg/autostart/sdwdate-gui.desktop” because it’s still required in VirtualBox (calling sdwdate-gui from Xsession.d will crash KDE, with or without /etc/xdg/autostart).

3 - a remark more than an issue. sdwdate-gui can be run as user, not requesting a password when restarting sdwdate instantly adjusting the time (which implies deleting a file in /var/run/)

Patrick · November 19, 2015, 10:00pm

It works. See qubes-whonix/etc/xdg/autostart/qubes-whonixsetup.desktop at master · Whonix/qubes-whonix · GitHub which works. Must use kdesudo. On Debian, using sudo for gui applications will lead to issues.

Please undo.

troubadour · November 19, 2015, 10:37pm

Done.

Using kdesudo in /etc/xdg/autostart without “xhost +local:root”.
dd4236ca

Patrick · November 20, 2015, 4:27pm

https://github.com/Whonix/Whonix/commit/37bebac1bb7a4b2eebbcaf5840c985fb7fc58277