sys-whonix launch error

[mossy-nw]

Qubes OS version:

R4.0_rc3

Affected TemplateVMs:

whonix-gw

---

Steps to reproduce the behavior:

launch sys-whonix

Expected behavior:

sys-whonix should start without errors

Actual behavior:

whonix seems to be working normally, but gives a popup error:

ERROR: Systemd Clock Check Result: 
Unexpected results by timedatectl. 
timedatectl_output_pretty: 
Local time: Fri 2018-01-12 14:04:59 UTC
Universal time: Fri 2018-01-12 14:04:59 UTC
RTC time: Fri 2018-01-12 14:04:06
Time zone: Etc/UTC (UTC, +0000)
NTP enabled: yes 
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
It is generally recommended to keep the default as per Whonix Design. [1] If you did not change timezone related settings, please report this Whonix bug. If you know what you are doing and changed this on purpose, feel free to disable this check. [2] 

[1] https://www.whonix.org/wiki/Dev/Design-Shared#timezone 
[2] Create a file /etc/whonix.d/50_whonixcheck_user and add: 
whonixcheck_skip_functions+=" check_systemd_clock " 

General notes:

apologies if this is a bug that should be reported directly to Whonix devs instead of QubesOS

---

Related issues:

[marmarek]

@adrelanos which part of this output is unexpected?

[marmarek]

@adrelanos which part of this output is unexpected?

[adrelanos]

NTP enabled: yes

Should be disabled by:

https://github.com/Whonix/sdwdate/blob/master/debian/sdwdate.postinst

## Deletes /etc/systemd/system/sysinit.target.wants/systemd-timesyncd.service.
## Otherwise timedatectl still thinks systemd-timesyncd is enabled.
timedatectl set-ntp false >/dev/null 2>&1 || true
## Make sure it gets really deleted even if timedatectl does not work.
rm --force /etc/systemd/system/sysinit.target.wants/systemd-timesyncd.service

The question is what re-enabled it?

[adrelanos]

NTP enabled: yes

Should be disabled by:

https://github.com/Whonix/sdwdate/blob/master/debian/sdwdate.postinst

## Deletes /etc/systemd/system/sysinit.target.wants/systemd-timesyncd.service.
## Otherwise timedatectl still thinks systemd-timesyncd is enabled.
timedatectl set-ntp false >/dev/null 2>&1 || true
## Make sure it gets really deleted even if timedatectl does not work.
rm --force /etc/systemd/system/sysinit.target.wants/systemd-timesyncd.service

The question is what re-enabled it?

[marmarek]

I guess here: https://github.com/QubesOS/qubes-core-agent-linux/blob/master/vm-systemd/75-qubes-vm.preset#L97
| enable systemd-timesyncd.service
together with systemctl preset-all at the end of installation

But there is also https://github.com/QubesOS/qubes-core-agent-linux/blob/master/vm-systemd/systemd-timesyncd.service.d/30_qubes.conf, which should prevent starting the service everywhere but sys-net.

@mossy-nw can you check if the service is really running? systemctl status systemd-timesyncd.service

[marmarek]

I guess here: https://github.com/QubesOS/qubes-core-agent-linux/blob/master/vm-systemd/75-qubes-vm.preset#L97
| enable systemd-timesyncd.service
together with systemctl preset-all at the end of installation

But there is also https://github.com/QubesOS/qubes-core-agent-linux/blob/master/vm-systemd/systemd-timesyncd.service.d/30_qubes.conf, which should prevent starting the service everywhere but sys-net.

@mossy-nw can you check if the service is really running? systemctl status systemd-timesyncd.service

[mossy-nw]

Sure. In sys-whonix, correct?

user@host:~$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; enabled)
  Drop-In: /lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf, 40_sdwdate.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

So it's loaded (enabled) but inactive (dead)? I'm not sure if this means it's really running or no. Thanks!

[mossy-nw]

Sure. In sys-whonix, correct?

user@host:~$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; enabled)
  Drop-In: /lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf, 40_sdwdate.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

So it's loaded (enabled) but inactive (dead)? I'm not sure if this means it's really running or no. Thanks!

[mossy-nw]

FWIW it's running identically in sys-net:

[user@sys-net ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

also running in sys-usb:

[user@sys-usb ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
Condition: start condition failed at Tue 2018-01-16 22:18:41 PST; 40min ago
           └─ ConditionPathExists=/var/run/qubes-service/clocksync was not met
     Docs: man:systemd-timesyncd.service(8)

and in an offline (via qvm-prefs offlineVM netvm "") appVM:

[user@offlineVM ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

so looks like the service is starting everywhere.

[mossy-nw]

FWIW it's running identically in sys-net:

[user@sys-net ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

also running in sys-usb:

[user@sys-usb ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
Condition: start condition failed at Tue 2018-01-16 22:18:41 PST; 40min ago
           └─ ConditionPathExists=/var/run/qubes-service/clocksync was not met
     Docs: man:systemd-timesyncd.service(8)

and in an offline (via qvm-prefs offlineVM netvm "") appVM:

[user@offlineVM ~]$ systemctl status systemd-timesyncd.service 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; v
  Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
           └─30_qubes.conf
   Active: inactive (dead)
     Docs: man:systemd-timesyncd.service(8)

so looks like the service is starting everywhere.

[adrelanos]

timedatectl: caches NTP enablement state, better shouldn't:
systemd/systemd#1329

[adrelanos]

timedatectl: caches NTP enablement state, better shouldn't:
systemd/systemd#1329

[marmarek]

According to systemd/systemd#1329 (comment), sdwdate.service should have Conflicts=systemd-timesyncd.service

[marmarek]

According to systemd/systemd#1329 (comment), sdwdate.service should have Conflicts=systemd-timesyncd.service

[adrelanos]

Marek Marczykowski-Górecki:

According to systemd/systemd#1329 (comment), `sdwdate.service` should have `Conflicts=systemd-timesyncd.service`

It has. https://github.com/Whonix/sdwdate/blob/master/lib/systemd/system/sdwdate.service#L17 Conflicts=systemd-timesyncd.service

[adrelanos]

Marek Marczykowski-Górecki:

According to systemd/systemd#1329 (comment), `sdwdate.service` should have `Conflicts=systemd-timesyncd.service`

It has. https://github.com/Whonix/sdwdate/blob/master/lib/systemd/system/sdwdate.service#L17 Conflicts=systemd-timesyncd.service

[marmarek]

FWIW it's running identically in sys-net:

Should be really running there... As you can see, there is no "start condition failed", so it was prevented by something else. Can't find anything related in logs.

[marmarek]

FWIW it's running identically in sys-net:

Should be really running there... As you can see, there is no "start condition failed", so it was prevented by something else. Can't find anything related in logs.

[mossy-nw]

I don't see this issue anymore in R4.0_rc4, so is it OK to close this issue? Don't want to close it if you all are still wanting to follow up on this or related things. Thanks!

[mossy-nw]

I don't see this issue anymore in R4.0_rc4, so is it OK to close this issue? Don't want to close it if you all are still wanting to follow up on this or related things. Thanks!

[mossy-nw]

Sorry everyone @marmarek @andrewdavidwong @adrelanos it looks like on a fresh R4.0_rc4 install the original Unexpected results by timedatectl error message is still appearing. Apologies for not waiting to do more thorough testing before reporting it resolved.

[mossy-nw]

Sorry everyone @marmarek @andrewdavidwong @adrelanos it looks like on a fresh R4.0_rc4 install the original Unexpected results by timedatectl error message is still appearing. Apologies for not waiting to do more thorough testing before reporting it resolved.

[adrelanos]

There was no update. Will be fixed in Whonix 14.

[adrelanos]

There was no update. Will be fixed in Whonix 14.

[mossy-nw]

Wonderful. Thank you for all the work and care you take on this project!

[mossy-nw]

Wonderful. Thank you for all the work and care you take on this project!

[RefinedSoftwareLLC]

#3930 was closed as a duplicate of this issue. The problem is that I am also having the issue stated with #3930, but I guess this is the correct place to post that. #3469 or #3930 needs to be reopened, because the issue is still happening with R4.0.

[RefinedSoftwareLLC]

#3930 was closed as a duplicate of this issue. The problem is that I am also having the issue stated with #3930, but I guess this is the correct place to post that. #3469 or #3930 needs to be reopened, because the issue is still happening with R4.0.

[esote]

@adrelanos Another thing to note is that this commit hasn't made it to the current/stable repository. All of my Whonix VMs are up to date, and yet I was initially unable to hide the error because I was missing the .conf extension.

When will those changes make it to the stable repo, or equivalently, how far away is Whonix 14?

[esote]

@adrelanos Another thing to note is that this commit hasn't made it to the current/stable repository. All of my Whonix VMs are up to date, and yet I was initially unable to hide the error because I was missing the .conf extension.

When will those changes make it to the stable repo, or equivalently, how far away is Whonix 14?

[vladionescu]

What is the workaround here? I updated earlier today and now I can't start VMs, breaking my workflow.

[vladionescu]

What is the workaround here? I updated earlier today and now I can't start VMs, breaking my workflow.

[marmarek]

Just to clarify - is it sys-whonix not starting at all, or displaying "Unexpected results by timedatectl" error message after the startup? The latter looks scary, but is a false positive (see discussion above) and in fact shouldn't break anything.
Do you see any other problem?

[marmarek]

Just to clarify - is it sys-whonix not starting at all, or displaying "Unexpected results by timedatectl" error message after the startup? The latter looks scary, but is a false positive (see discussion above) and in fact shouldn't break anything.
Do you see any other problem?

[vladionescu]

It's displaying the error message and the VM starts, but connectivity in that VM appears to be broken:

• DispVMs based on whonix-ws-dvm have no outbound connectivity using Tor Browser
• Can't update whonix-gw template
• Can't update whonix-ws template

There's a chance this is a coincidence (saying this because I haven't had time to do a root cause and figure out whether the issues are related), but the issues started happening at the same time and I never had connectivity issues with whonix VMs prior. My other VMs/templates are unaffected.

[vladionescu]

It's displaying the error message and the VM starts, but connectivity in that VM appears to be broken:

• DispVMs based on whonix-ws-dvm have no outbound connectivity using Tor Browser
• Can't update whonix-gw template
• Can't update whonix-ws template

There's a chance this is a coincidence (saying this because I haven't had time to do a root cause and figure out whether the issues are related), but the issues started happening at the same time and I never had connectivity issues with whonix VMs prior. My other VMs/templates are unaffected.

[adrelanos]

This very issue #3469 certainly (and I say that seldom) is only a false positive graphical user interface message warning.

For everything else, please create new issues.

[adrelanos]

This very issue #3469 certainly (and I say that seldom) is only a false positive graphical user interface message warning.

For everything else, please create new issues.

[adrelanos]

status of Whonix 14 development:

Besides the known bugs on the Whonix and Qubes issue trackers, Whonix 14 should be ready as stable Whonix 14 release. Only waiting for new Qubes templates to be built and tested before the Whonix 14 release will be made. (#4016)

https://www.whonix.org/wiki/Upgrading_Whonix_13_to_Whonix_14

[adrelanos]

status of Whonix 14 development:

Besides the known bugs on the Whonix and Qubes issue trackers, Whonix 14 should be ready as stable Whonix 14 release. Only waiting for new Qubes templates to be built and tested before the Whonix 14 release will be made. (#4016)

https://www.whonix.org/wiki/Upgrading_Whonix_13_to_Whonix_14