sdwdate service stops upon resume from S3 state

anadahz commented 5 years ago

Qubes OS version:

Qubes release 4.0 (R4.0)

Affected component(s) or functionality:

Whonix workstation 14 AppVM
Whonix workstation 15 AppVM

Steps to reproduce the behavior:

Resuming upon system suspend to ram: [dom0 /]$ systemctl suspend

Expected or desired behavior:

The sdwdate (Secure Distributed Web Date) service should be running upon resume from system suspend to ram.

Actual behavior:

[whonix-ws ]$ systemctl -l status sdwdate

● sdwdate.service - Secure Distributed Web Date
   Loaded: loaded (/lib/systemd/system/sdwdate.service; enabled; vendor preset: enabled)
  Drop-In: /lib/systemd/system/sdwdate.service.d
           └─40_qubes.conf
   Active: inactive (dead) since Sun 2019-03-17 01:32:13 UTC; 58min ago
     Docs: https://www.whonix.org/wiki/sdwdate
  Process: 12211 ExecStart=/usr/bin/sdwdate (code=exited, status=143)
 Main PID: 12211 (code=exited, status=143)
   Status: "Shutting down..."

Mar 17 01:32:13 host systemd[1]: Stopping Secure Distributed Web Date...
Mar 17 01:32:13 host sdwdate[12211]: 2019-03-17 01:32:13 - sdwdate - INFO - delete temp_dir: /tmp/tmp.2231AFRGrq
Mar 17 01:32:13 host sdwdate[12211]: 2019-03-17 01:32:13 - sdwdate - INFO - Signal SIGTERM received. sdwdate stopped by user or system.
Mar 17 01:32:13 host systemd[1]: Stopped Secure Distributed Web Date.
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

General notes:

Whonix wiki: Network Time Synchronization

I have consulted the following relevant documentation:

Qubes User Documentation: Whonix for Privacy & Anonymity

Edit: Added Whonix 15 to the affected components

marmarek commented 5 years ago

cc @adrelanos

adrelanos commented 5 years ago

Can't reproduce. Works for me. Just now tested.

Watch in sys-whonix while systemctl suspend on host:

sudo journalctl -f

I saw both qubes.SuspendPreAll-dom0 and qubes.SuspendPostAll-dom0 correctly executed.

Could you provide the log please?

Could can redact the log, mostly qubes.SuspendPreAll-dom0 and qubes.SuspendPostAll-dom0 are interesting.

anadahz commented 5 years ago

[sys-whonix]

$ systemctl -l status systemd-suspend.service suspend.target

● systemd-suspend.service - Suspend
   Loaded: loaded (/lib/systemd/system/systemd-suspend.service; static; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:systemd-suspend.service(8)

● suspend.target - Suspend
   Loaded: loaded (/lib/systemd/system/suspend.target; static; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:systemd.special(7)

$ sudo journalctl -f

-- Logs begin at Thu 2019-03-28 08:29:55 UTC. --
Mar 29 12:15:22 host sudo[2091]: pam_unix(sudo:session): session opened for user root by user(uid=0)
Mar 29 12:15:22 host audit[2091]: USER_START pid=2091 uid=0 auid=2131232132 ses=2131232132 msg='op=PAM:session_open acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
Mar 29 12:15:24 host sudo[2091]: pam_unix(sudo:session): session closed for user root
Mar 29 12:15:24 host audit[2091]: USER_END pid=2091 uid=0 auid=2131232132 ses=2131232132 msg='op=PAM:session_close acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
Mar 29 12:15:24 host audit[2091]: CRED_DISP pid=2091 uid=0 auid=2131232132 ses=2131232132 msg='op=PAM:setcred acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
Mar 29 12:15:25 host sudo[2093]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/bin/journalctl -f
Mar 29 12:15:25 host audit[2093]: USER_CMD pid=2093 uid=1000 auid=2131232132 ses=2131232132 msg='cwd="/home/user" cmd=920183921839218D222221 terminal=pts/0 res=success'
Mar 29 12:15:25 host audit[2093]: CRED_REFR pid=2093 uid=0 auid=2131232132 ses=2131232132 msg='op=PAM:setcred acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
Mar 29 12:15:25 host sudo[2093]: pam_unix(sudo:session): session opened for user root by user(uid=0)
Mar 29 12:15:25 host audit[2093]: USER_START pid=2093 uid=0 auid=2131232132 ses=2131232132 msg='op=PAM:session_open acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'

I saw both qubes.SuspendPreAll-dom0 and qubes.SuspendPostAll-dom0 correctly executed. Could you provide the log please? Could can redact the log, mostly qubes.SuspendPreAll-dom0 and qubes.SuspendPostAll-dom0 are interesting.

I cannot find these systemd units in either sys-whonix or dom0:

[sys-whonix] user@host:~$ systemctl list-unit-files |grep -i suspend

systemd-suspend.service                        static   
suspend.target                                        static

[dom0] [user@dom0 ~]$ systemctl list-unit-files |grep -i suspend

qubes-suspend.service                           enabled
systemd-suspend.service                        static   
suspend.target                                        static

[user@dom0 ~]$ systemctl -l status qubes-suspend.service

● qubes-suspend.service - Qubes suspend hooks
   Loaded: loaded (/usr/lib/systemd/system/qubes-suspend.service; enabled; vendor preset: enab
   Active: inactive (dead)

Mar 28 12:38:44 dom0 systemd[1]: Stopping Qubes suspend hooks...
Mar 28 12:38:57 dom0 52qubes-pause-vms[18307]: 0
Mar 28 12:38:57 dom0 systemd[1]: Stopped Qubes suspend hooks.
Mar 28 14:50:51 dom0 systemd[1]: Starting Qubes suspend hooks...
Mar 28 14:50:55 dom0 52qubes-pause-vms[8348]: 0
Mar 28 14:50:55 dom0 systemd[1]: Started Qubes suspend hooks.
Mar 29 11:35:11 dom0 systemd[1]: qubes-suspend.service: Unit not needed anymore. Stopping.
Mar 29 11:35:11 dom0 systemd[1]: Stopping Qubes suspend hooks...
Mar 29 11:35:22 dom0 52qubes-pause-vms[8405]: 0
Mar 29 11:35:22 dom0 systemd[1]: Stopped Qubes suspend hooks.

[user@dom0 ~]$ systemctl -l status systemd-suspend.service

● systemd-suspend.service - Suspend
   Loaded: loaded (/usr/lib/systemd/system/systemd-suspend.service; static; vendor preset: dis
   Active: inactive (dead)
     Docs: man:systemd-suspend.service(8)

Mar 28 12:04:11 dom0 systemd[1]: Starting Suspend...
Mar 28 12:04:11 dom0 systemd-sleep[18070]: Suspending system...
Mar 28 12:10:03 dom0 systemd[1]: Started Suspend.
Mar 28 12:10:31 dom0 systemd[1]: Starting Suspend...
Mar 28 12:10:31 dom0 systemd-sleep[18293]: Suspending system...
Mar 28 12:38:44 dom0 systemd-sleep[18293]: System resumed.
Mar 28 12:38:44 dom0 systemd[1]: Started Suspend.
Mar 28 14:50:55 dom0 systemd[1]: Starting Suspend...
Mar 28 14:50:55 dom0 systemd-sleep[8377]: Suspending system...
Mar 29 11:35:11 dom0 systemd[1]: Started Suspend.

[user@dom0 ~]$ systemctl -l status suspend.target

● suspend.target - Suspend
   Loaded: loaded (/usr/lib/systemd/system/suspend.target; static; vendor preset: disabled)
   Active: inactive (dead)
     Docs: man:systemd.special(7)

Mar 28 12:03:42 dom0 systemd[1]: Stopped target Suspend.
Mar 28 12:10:03 dom0 systemd[1]: Reached target Suspend.
Mar 28 12:10:03 dom0 systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspen
Mar 28 12:10:03 dom0 systemd[1]: Stopped target Suspend.
Mar 28 12:38:44 dom0 systemd[1]: Reached target Suspend.
Mar 28 12:38:44 dom0 systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspen
Mar 28 12:38:44 dom0 systemd[1]: Stopped target Suspend.
Mar 29 11:35:11 dom0 systemd[1]: Reached target Suspend.
Mar 29 11:35:11 dom0 systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspen
Mar 29 11:35:11 dom0 systemd[1]: Stopped target Suspend.

adrelanos commented 5 years ago

Could be a general Qubes (non-Whonix) issue. Can you make any SuspendPreAll / SuspendPostAll work at all?

marmarek commented 5 years ago

Similar issue was fixed in #3489 , but according to the above the service is called...

adrelanos commented 5 years ago

Do you have that update / package version https://github.com/QubesOS/qubes-issues/issues/3489? @anadahz

anadahz commented 5 years ago

Do you have that update / package version #3489? @anadahz

$ dnf info qubes-core-dom0

Qubes OS Repository for Dom0                                   27 MB/s |  28 kB     00:00    
Installed Packages
Name        : qubes-core-dom0
Arch        : x86_64
Epoch       : 0
Version     : 4.0.42
Release     : 1.fc25
Size        : 4.4 M
Repo        : @System
From repo   : qubes-dom0-cached
Summary     : The Qubes core files (Dom0-side)
URL         : http://www.qubes-os.org
License     : GPL
Description : The Qubes core files for installation on Dom0.

anadahz commented 5 years ago

I can reproduce this issue in Whonix 15 AppVM.

adrelanos commented 4 years ago

Could you check dom0 log please? In dom0:

sudo journalctl -f

Do you also get

Mar 03 11:50:53 dom0 qubesd[6943]: future: <Task finished coro=<QubesVM.resume() done, defined at /usr/lib/python3.5/site-packages/qubes/vm/qubesvm.py:1277> exception=CalledProcessError(1, 'qubes.SuspendPost', b'', b'vchan connection timeout\n')>

?

Is this the same issue as https://github.com/QubesOS/qubes-issues/issues/5702?

anadahz commented 4 years ago

Could you check dom0 log please? In dom0:
sudo journalctl -f
Do you also get

Mar 03 11:50:53 dom0 qubesd[6943]: future: <Task finished coro=<QubesVM.resume() done, defined at /usr/lib/python3.5/site-packages/qubes/vm/qubesvm.py:1277> exception=CalledProcessError(1, 'qubes.SuspendPost', b'', b'vchan connection timeout\n')>

?

I do not get any vchan connection timeout errors in dom0 logs.

Is this the same issue as #5702?

I never had issues with USB devices or ethernet network connectivity upon resuming from suspend.

Few times though I had issues with the wireless network connectivity upon resuming from suspend as in: https://www.qubes-os.org/doc/wireless-troubleshooting/

github-actions[bot] commented 1 year ago

This issue is being closed because:

This issue is on the "Release 4.0 updates" milestone.
Qubes OS 4.0 reached EOL (end-of-life) over one year ago.
There has not been any activity on this issue in over one year.

If anyone believes that this issue should be reopened and reassigned to an active milestone, please leave a brief comment. (For example, if a bug still affects Qubes OS 4.1, then the comment "Affects 4.1" will suffice.)

QubesOS / qubes-issues