/qubes-issues

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

clock gets desynced #443

Closed
marmarek opened this Issue Mar 8, 2015 · 8 comments

Comments

Assignees

@marmarek marmarek

Labels
Projects
None yet
Milestone
  Release 1
2 participants
@marmarek @rootkovska
@marmarek
Member

marmarek commented Mar 8, 2015

Reported by joanna on 9 Feb 2012 08:47 UTC
It seems like the qvm-sync-clock (most likely run by a cron job) has desynced my time. After resume the time was correct, but a few moments later it got set incorrectly to roughly the time when the machine was suspended a few hours back.

It seems like the ntpdate in the netvm must have failed (e.g. due to networking problem), but the qvm-sync-clock script must have missed that, and used the incorrect time from the netvm anyway.

Here's a snippet of my messages log from Dom0:

Feb  9 09:27:25 dom0 kernel: [PM: resume of devices complete after 699.879 msecs
Feb  9 09:27:25 dom0 kernel: [229015.169306](229015.168850]) Restarting tasks ... done.
Feb  9 09:27:25 dom0 kernel: [video LNXVIDEO:00: Restoring backlight state
Feb  9 09:27:25 dom0 kernel: [229015.180839](229015.174246]) usb 2-1.1: USB disconnect, address 9
Feb  9 09:27:25 dom0 pulseaudio[ratelimit.c: 252 events suppressed
Feb  9 09:27:28 dom0 kernel: [229017.403431](3582]:) pciback 0000:00:19.0: get owner: 8 
Feb  9 09:27:28 dom0 kernel: [pciback 0000:00:19.0: get owner: 8 
Feb  9 09:27:28 dom0 kernel: [229017.457967](229017.403952]) pciback 0000:00:19.0: get owner: 8 
Feb  9 09:27:28 dom0 kernel: [pciback 0000:00:19.0: get owner: 8 
Feb  9 01:16:23 dom0 pulseaudio[3582](229017.458436]): ratelimit.c: 256 events suppressed
Feb  9 09:36:55 dom0 kernel: [229586.631896] usb 1-1.6: USB disconnect, address 6

Note how the time was correct, and then suddenly changed to 01:16:23. Later it was reverted back to the correct value after I manually run qvm-sync-clock...

Interestingly I made an experiment: 1) I disabled networking, and 2) run ntpdate restart in the netvm, and 3) checked the $?, thinking it might be 0, and so explaining this problem. But it was correctly set to 1, so this doesn't explain how qvm-sync-clock might got a wrong time from netvm...

Migrated-From: https://wiki.qubes-os.org/ticket/443
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by marmarek on 9 Feb 2012 09:37 UTC
Can you post also qrexec log (now in /var/log/messages) from netvm and some other VM?
Member

marmarek commented Mar 8, 2015

Comment by marmarek on 9 Feb 2012 09:37 UTC
Can you post also qrexec log (now in /var/log/messages) from netvm and some other VM?

@marmarek marmarek assigned rootkovska Mar 8, 2015

@marmarek marmarek added this to the Release 1 milestone Mar 8, 2015

@marmarek marmarek added bug C: core P: major labels Mar 8, 2015

@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by joanna on 9 Feb 2012 09:41 UTC
qrexec logs from netvm:

Feb  9 00:15:44 netvm qrexec_agent[send exit code for client_id 7 pid 7187
Feb  9 00:15:44 netvm qrexec_agent[398](398]:): executed user:date -u pid 7275
Feb  9 00:15:44 netvm qrexec_agent[eintr
Feb  9 00:15:44 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7275
Feb  9 01:15:18 netvm qrexec_agent[executed root:service NetworkManager stop; for if in `ls /sys/class/net|grep -v "lo\|vif"`; do ip l s $if down; done; modprobe -r uhci_hcd ehci_hcd pid 7297
Feb  9 01:15:19 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7297
Feb  9 01:15:24 netvm qrexec_agent[executed user:nm-online -x pid 7333
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): executed root:modprobe ehci_hcd; modprobe uhci_hcd; [ -x /bin/systemctl ] && systemctl start NetworkManager.service || service qubes_core_netvm start pid 7353
Feb  9 01:15:25 netvm qrexec_agent[eintr
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7353
Feb  9 01:15:25 netvm qrexec_agent[send exit code for client_id 7 pid 7333
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): executed root:/etc/init.d/ntpdate restart pid 7368
Feb  9 01:15:33 netvm qrexec_agent[executed root:service NetworkManager stop; for if in `ls /sys/class/net|grep -v "lo\|vif"`; do ip l s $if down; done; modprobe -r uhci_hcd ehci_hcd pid 7401
Feb  9 01:15:33 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7401
Feb  9 01:15:39 netvm qrexec_agent[executed user:nm-online -x pid 7430
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): executed root:modprobe ehci_hcd; modprobe uhci_hcd; [ -x /bin/systemctl ] && systemctl start NetworkManager.service || service qubes_core_netvm start pid 7450
Feb  9 01:15:40 netvm qrexec_agent[send exit code for client_id 9 pid 7450
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7430
Feb  9 01:15:40 netvm qrexec_agent[executed root:/etc/init.d/ntpdate restart pid 7468
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): eintr
Feb  9 01:15:40 netvm qrexec_agent[send exit code for client_id 7 pid 7368
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): executed user:date -u pid 7482
Feb  9 01:15:40 netvm qrexec_agent[eintr
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7482
Feb  9 01:15:58 netvm qrexec_agent[eintr
Feb  9 01:15:58 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7468
Feb  9 01:23:48 netvm qrexec_agent[executed user:nm-online -x pid 7555
Feb  9 01:23:48 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7555
Feb  9 01:23:48 netvm qrexec_agent[executed root:/etc/init.d/ntpdate restart pid 7567
Feb  9 09:35:39 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7567
Feb  9 09:35:39 netvm qrexec_agent[executed user:date -u pid 7597
Feb  9 09:35:39 netvm qrexec_agent[398](398]:): eintr
Feb  9 09:35:39 netvm qrexec_agent[send exit code for client_id 7 pid 7597
Feb  9 10:38:58 netvm qrexec_agent[398](398]:): executed (nowait) user:gnome-terminal pid 7778
Member

marmarek commented Mar 8, 2015

Comment by joanna on 9 Feb 2012 09:41 UTC
qrexec logs from netvm:

Feb  9 00:15:44 netvm qrexec_agent[send exit code for client_id 7 pid 7187
Feb  9 00:15:44 netvm qrexec_agent[398](398]:): executed user:date -u pid 7275
Feb  9 00:15:44 netvm qrexec_agent[eintr
Feb  9 00:15:44 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7275
Feb  9 01:15:18 netvm qrexec_agent[executed root:service NetworkManager stop; for if in `ls /sys/class/net|grep -v "lo\|vif"`; do ip l s $if down; done; modprobe -r uhci_hcd ehci_hcd pid 7297
Feb  9 01:15:19 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7297
Feb  9 01:15:24 netvm qrexec_agent[executed user:nm-online -x pid 7333
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): executed root:modprobe ehci_hcd; modprobe uhci_hcd; [ -x /bin/systemctl ] && systemctl start NetworkManager.service || service qubes_core_netvm start pid 7353
Feb  9 01:15:25 netvm qrexec_agent[eintr
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7353
Feb  9 01:15:25 netvm qrexec_agent[send exit code for client_id 7 pid 7333
Feb  9 01:15:25 netvm qrexec_agent[398](398]:): executed root:/etc/init.d/ntpdate restart pid 7368
Feb  9 01:15:33 netvm qrexec_agent[executed root:service NetworkManager stop; for if in `ls /sys/class/net|grep -v "lo\|vif"`; do ip l s $if down; done; modprobe -r uhci_hcd ehci_hcd pid 7401
Feb  9 01:15:33 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7401
Feb  9 01:15:39 netvm qrexec_agent[executed user:nm-online -x pid 7430
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): executed root:modprobe ehci_hcd; modprobe uhci_hcd; [ -x /bin/systemctl ] && systemctl start NetworkManager.service || service qubes_core_netvm start pid 7450
Feb  9 01:15:40 netvm qrexec_agent[send exit code for client_id 9 pid 7450
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7430
Feb  9 01:15:40 netvm qrexec_agent[executed root:/etc/init.d/ntpdate restart pid 7468
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): eintr
Feb  9 01:15:40 netvm qrexec_agent[send exit code for client_id 7 pid 7368
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): executed user:date -u pid 7482
Feb  9 01:15:40 netvm qrexec_agent[eintr
Feb  9 01:15:40 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7482
Feb  9 01:15:58 netvm qrexec_agent[eintr
Feb  9 01:15:58 netvm qrexec_agent[398](398]:): send exit code for client_id 8 pid 7468
Feb  9 01:23:48 netvm qrexec_agent[executed user:nm-online -x pid 7555
Feb  9 01:23:48 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7555
Feb  9 01:23:48 netvm qrexec_agent[executed root:/etc/init.d/ntpdate restart pid 7567
Feb  9 09:35:39 netvm qrexec_agent[398](398]:): send exit code for client_id 7 pid 7567
Feb  9 09:35:39 netvm qrexec_agent[executed user:date -u pid 7597
Feb  9 09:35:39 netvm qrexec_agent[398](398]:): eintr
Feb  9 09:35:39 netvm qrexec_agent[send exit code for client_id 7 pid 7597
Feb  9 10:38:58 netvm qrexec_agent[398](398]:): executed (nowait) user:gnome-terminal pid 7778
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by joanna on 9 Feb 2012 09:42 UTC
And from some other AppVM:

Feb  9 01:15:22 work qrexec_agent[executed (nowait) root:date -s "Thu Feb  9 01:28:16 CET 2012" pid 5545
Feb  9 01:28:16 work qrexec_agent[499](499]:): eintr
Feb  9 01:28:30 work qrexec_agent[executed (nowait) root:date -s "Thu Feb  9 09:27:26 CET 2012" pid 5554
Feb  9 09:27:26 work qrexec_agent[499](499]:): eintr
Feb  9 09:27:27 work qrexec_agent[executed (nowait) root:date -u -s "Thu Feb  9 00:15:40 UTC 2012
Feb  9 09:27:27 work qrexec_agent[499](499]:): " pid 5563
Feb  9 01:15:40 work qrexec_agent[eintr
Feb  9 01:23:52 work qrexec_agent[499](499]:): executed (nowait) root:date -u -s "Thu Feb  9 08:35:39 UTC 2012
Feb  9 01:23:52 work qrexec_agent[" pid 5583
Feb  9 09:35:39 work qrexec_agent[499](499]:): eintr
Feb  9 09:39:22 work qrexec_agent[executed (nowait) user:gnome-terminal pid 5595
Feb  9 10:42:20 work qrexec_agent[499](499]:): executed (nowait) user:gnome-terminal pid 5765
Feb  9 10:42:20 work qrexec_agent[499]: eintr
Member

marmarek commented Mar 8, 2015

Comment by joanna on 9 Feb 2012 09:42 UTC
And from some other AppVM:

Feb  9 01:15:22 work qrexec_agent[executed (nowait) root:date -s "Thu Feb  9 01:28:16 CET 2012" pid 5545
Feb  9 01:28:16 work qrexec_agent[499](499]:): eintr
Feb  9 01:28:30 work qrexec_agent[executed (nowait) root:date -s "Thu Feb  9 09:27:26 CET 2012" pid 5554
Feb  9 09:27:26 work qrexec_agent[499](499]:): eintr
Feb  9 09:27:27 work qrexec_agent[executed (nowait) root:date -u -s "Thu Feb  9 00:15:40 UTC 2012
Feb  9 09:27:27 work qrexec_agent[499](499]:): " pid 5563
Feb  9 01:15:40 work qrexec_agent[eintr
Feb  9 01:23:52 work qrexec_agent[499](499]:): executed (nowait) root:date -u -s "Thu Feb  9 08:35:39 UTC 2012
Feb  9 01:23:52 work qrexec_agent[" pid 5583
Feb  9 09:35:39 work qrexec_agent[499](499]:): eintr
Feb  9 09:39:22 work qrexec_agent[executed (nowait) user:gnome-terminal pid 5595
Feb  9 10:42:20 work qrexec_agent[499](499]:): executed (nowait) user:gnome-terminal pid 5765
Feb  9 10:42:20 work qrexec_agent[499]: eintr
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by marmarek on 9 Feb 2012 09:52 UTC
Looks like the first /etc/init.d/ntpdate restart did not synced the time. Tested manually and it also sets correct exit code (!= 0 if failed). But the other thing is interesting:
qvm-sync-clock calls in netvm (in order):

  1. nm-online -x (to wait for the network)
  2. /etc/init.d/ntpdate restart (to sync time)

Here I see that NetworkManager is started by pm-scripts AFTER calling nm-online -x (which exists immediately when no NetworkManager is running). So the order of pm-scripts need to be fixed.
Member

marmarek commented Mar 8, 2015

Comment by marmarek on 9 Feb 2012 09:52 UTC
Looks like the first /etc/init.d/ntpdate restart did not synced the time. Tested manually and it also sets correct exit code (!= 0 if failed). But the other thing is interesting:
qvm-sync-clock calls in netvm (in order):

  1. nm-online -x (to wait for the network)
  2. /etc/init.d/ntpdate restart (to sync time)

Here I see that NetworkManager is started by pm-scripts AFTER calling nm-online -x (which exists immediately when no NetworkManager is running). So the order of pm-scripts need to be fixed.
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by marmarek on 9 Feb 2012 09:54 UTC
BTW have you some messages about time sync in /var/log/pm-suspend.log (dom0)?
Member

marmarek commented Mar 8, 2015

Comment by marmarek on 9 Feb 2012 09:54 UTC
BTW have you some messages about time sync in /var/log/pm-suspend.log (dom0)?
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Comment by joanna on 9 Feb 2012 10:10 UTC
pm-susped.log:


Initial commandline parameters: --quirk-dpms-suspend
--quirk-dpms-on
--quirk-vbestate-restore
--quirk-vbemode-restore
--quirk-vga-mode3
--quirk-vbe-post
Thu Feb  9 01:28:24 CET 2012: Running hooks for suspend.
/usr/lib64/pm-utils/sleep.d/00auto-quirk suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/00logging suspend suspend: Linux dom0 2.6.38.3-10.xenlinux.qubes.x86_64 #1 SMP Sat Dec 24 18:09:56 EST 2011 x86_64 x86_64 x86_64 GNU/Linux
Module                  Size  Used by
usbhid                 48251  0 
hid                    88836  1 usbhid
xt_tcpudp               3772  7 
xt_physdev              1827  28 
bridge                 90456  2 
stp                     2291  1 bridge
llc                     6008  2 bridge,stp
af_packet              23787  0 
iptable_nat             5839  0 
nf_nat                 23604  1 iptable_nat
nf_conntrack_ipv4      10128  3 iptable_nat,nf_nat
nf_conntrack           86772  3 iptable_nat,nf_nat,nf_conntrack_ipv4
nf_defrag_ipv4          1761  1 nf_conntrack_ipv4
iptable_filter          1938  1 
ip_tables              21605  2 iptable_nat,iptable_filter
x_tables               26769  5 xt_tcpudp,xt_physdev,iptable_nat,iptable_filter,ip_tables
sha256_generic         10351  0 
dm_snapshot            33663  4 
binfmt_misc             8370  1 
dm_mirror              15828  0 
dm_region_hash         13123  1 dm_mirror
dm_log                 10726  2 dm_mirror,dm_region_hash
blktap                125515  0 [                 41641  0 [permanent](permanent]
netbk)
gntdev                  8325  78 
evtchn                  5882  70 
blkbk                  26381  0 [        2862  1 blkbk
snd_hda_codec_realtek   352799  1 
snd_hda_intel          28786  5 
snd_hda_codec         106767  2 snd_hda_codec_realtek,snd_hda_intel
snd_hwdep               7474  1 snd_hda_codec
snd_seq                64803  0 
snd_seq_device          7578  1 snd_seq
pcspkr                  2182  0 
snd_pcm               103509  3 snd_hda_intel,snd_hda_codec
btusb                  17481  0 
bluetooth             110684  1 btusb
uvcvideo               67698  0 
videodev               77490  1 uvcvideo
v4l2_compat_ioctl32     7335  1 videodev
sg                     31705  0 
qcserial                4700  0 
usb_wwan               14023  1 qcserial
usbserial              41181  2 qcserial,usb_wwan
snd_timer              26285  2 snd_seq,snd_pcm
sony_laptop            35275  0 
joydev                 12165  0 
iTCO_wdt               12668  0 
snd                    80657  17 snd_hda_codec_realtek,snd_hda_intel,snd_hda_codec,snd_hwdep,snd_seq,snd_seq_device,snd_pcm,snd_timer
iTCO_vendor_support     3110  1 iTCO_wdt
sdhci_pci              10165  0 
sdhci                  23685  1 sdhci_pci
mmc_core               94899  1 sdhci
i2c_i801               10840  0 
rfkill                 21079  2 bluetooth,sony_laptop
intel_ips              13084  0 
battery                12413  0 
ac                      4089  0 
wmi                    11148  0 
thermal                14639  0 
soundcore               8212  1 snd
snd_page_alloc          9100  2 snd_hda_intel,snd_pcm
tpm_infineon            8827  0 
processor              34247  0 
fpu                     2638  4 
aesni_intel            46320  12 
cryptd                 11340  5 aesni_intel
aes_x86_64              8064  1 aesni_intel
aes_generic            27727  2 aesni_intel,aes_x86_64
xts                     2903  4 
gf128mul                8399  1 xts
dm_crypt               18824  1 
ext4                  399882  1 
jbd2                   90056  1 ext4
crc16                   1739  1 ext4
uas                     9779  0 
usb_storage            52735  0 
raid0                   8913  1 
sr_mod                 15340  0 
sd_mod                 38418  2 
cdrom                  42564  1 sr_mod
ahci                   22146  4 
libahci                24983  1 ahci
libata                223474  2 ahci,libahci
scsi_mod              224115  6 sg,uas,usb_storage,sr_mod,sd_mod,libata
ehci_hcd               60797  0 
usbcore               209562  10 usbhid,btusb,uvcvideo,qcserial,usb_wwan,usbserial,uas,usb_storage,ehci_hcd
tpm_tis                11938  1 
tpm                    17299  2 tpm_infineon,tpm_tis
tpm_bios                6260  1 tpm
i915                  537703  2 
drm_kms_helper         37272  1 i915
drm                   232588  3 i915,drm_kms_helper
intel_agp              12418  1 i915
i2c_algo_bit            6408  1 i915
button                  6658  1 i915
intel_gtt              18872  3 i915,intel_agp
agpgart                39754  3 drm,intel_agp,intel_gtt
i2c_core               31494  6 videodev,i2c_i801,i915,drm_kms_helper,drm,i2c_algo_bit
video                  15058  1 i915
thermal_sys            18262  3 thermal,processor,video
hwmon                   2688  1 thermal_sys
pciback                48941  0 
xenbus_be               4125  4 blktap,netbk,blkbk,pciback
             total       used       free     shared    buffers     cached
Mem:       1674288    1600964      73324          0      15492     903452
-/+ buffers/cache:     682020     992268
Swap:      4161532      98368    4063164
success.
/usr/lib64/pm-utils/sleep.d/00powersave suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/00sony-vaio-audio suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/01grub suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/01qubes-suspend-netvm suspend suspend: (null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
Redirecting to /bin/systemctl  stop NetworkManager.service
success.
/usr/lib64/pm-utils/sleep.d/01qubes-sync-vms-clock suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/02qubes-pause-vms suspend suspend: 
Pausing VM: 'netvm'...
Pausing VM: 'firewallvm'...
Pausing VM: 'work-pub'...
Pausing VM: 'work'...
Pausing VM: 'bank'...
Pausing VM: 'personal'...
Pausing VM: 'vault'...
Pausing VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/49bluetooth suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/55NetworkManager suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/56atd suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/56dhclient suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/75modules suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/90clock suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/94cpufreq suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/95led suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/95packagekit suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/98smart-kernel-video suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/99hd-apm-restore.hook suspend suspend: saving level 255 for device sdb
saving level 255 for device sda
success.
/usr/lib64/pm-utils/sleep.d/99sony-vaio-audio suspend suspend: Thu Feb  9 01:28:26 CET 2012
Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 0 [0%](permanent]
blkback_pagemap) [[on](-64.00dB])
success.
/usr/lib64/pm-utils/sleep.d/99video suspend suspend: error: "kernel.acpi_video_flags" is an unknown key
success.
Thu Feb  9 01:28:26 CET 2012: performing suspend
Thu Feb  9 09:27:25 CET 2012: Awake.
Thu Feb  9 09:27:25 CET 2012: Running hooks for resume
/usr/lib64/pm-utils/sleep.d/99video resume suspend: success.
/usr/lib64/pm-utils/sleep.d/99sony-vaio-audio resume suspend: Thu Feb  9 09:27:25 CET 2012
Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 0 [[-64.00dB](0%]) [resume suspend: restoring level 255 for device sdb

/dev/sdb:
 setting Advanced Power Management level to disabled
 APM_level  = off
restoring level 255 for device sda

/dev/sda:
 setting Advanced Power Management level to disabled
 APM_level  = off
success.
/usr/lib64/pm-utils/sleep.d/98smart-kernel-video resume suspend: success.
/usr/lib64/pm-utils/sleep.d/95packagekit resume suspend: method return sender=:1.1261 -> dest=:1.1296 reply_serial=2
success.
/usr/lib64/pm-utils/sleep.d/95led resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/94cpufreq resume suspend: success.
/usr/lib64/pm-utils/sleep.d/90clock resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/75modules resume suspend: success.
/usr/lib64/pm-utils/sleep.d/56dhclient resume suspend: success.
/usr/lib64/pm-utils/sleep.d/56atd resume suspend: success.
/usr/lib64/pm-utils/sleep.d/55NetworkManager resume suspend: success.
/usr/lib64/pm-utils/sleep.d/49bluetooth resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/02qubes-pause-vms resume suspend: 
UnPausing VM: 'netvm'...
UnPausing VM: 'firewallvm'...
UnPausing VM: 'work-pub'...
UnPausing VM: 'work'...
UnPausing VM: 'bank'...
UnPausing VM: 'personal'...
UnPausing VM: 'vault'...
UnPausing VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/01qubes-sync-vms-clock resume suspend: 
Syncing VMs clock to: Thu Feb  9 09:27:26 CET 2012
Running command on VM: 'firewallvm'...
Running command on VM: 'work-pub'...
Running command on VM: 'work'...
Running command on VM: 'bank'...
Running command on VM: 'personal'...
Running command on VM: 'vault'...
Running command on VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/01qubes-suspend-netvm resume suspend: (null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
success.
/usr/lib64/pm-utils/sleep.d/01grub resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/00sony-vaio-audio resume suspend: Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 64 [100%](on]
success.
/usr/lib64/pm-utils/sleep.d/99hd-apm-restore.hook) [[on](0.00dB])
success.
/usr/lib64/pm-utils/sleep.d/00powersave resume suspend: success.
/usr/lib64/pm-utils/sleep.d/00logging resume suspend: success.
/usr/lib64/pm-utils/sleep.d/00auto-quirk resume suspend: succes[  OK  ]
Thu Feb  9 00:15:40 UTC 2012
ed.
Restarting ntpdate (via systemctl):  [FAILED]
Job failed. See system logs and 'systemctl status' for details.

Time sync failed, aborting!
Member

marmarek commented Mar 8, 2015

Comment by joanna on 9 Feb 2012 10:10 UTC
pm-susped.log:


Initial commandline parameters: --quirk-dpms-suspend
--quirk-dpms-on
--quirk-vbestate-restore
--quirk-vbemode-restore
--quirk-vga-mode3
--quirk-vbe-post
Thu Feb  9 01:28:24 CET 2012: Running hooks for suspend.
/usr/lib64/pm-utils/sleep.d/00auto-quirk suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/00logging suspend suspend: Linux dom0 2.6.38.3-10.xenlinux.qubes.x86_64 #1 SMP Sat Dec 24 18:09:56 EST 2011 x86_64 x86_64 x86_64 GNU/Linux
Module                  Size  Used by
usbhid                 48251  0 
hid                    88836  1 usbhid
xt_tcpudp               3772  7 
xt_physdev              1827  28 
bridge                 90456  2 
stp                     2291  1 bridge
llc                     6008  2 bridge,stp
af_packet              23787  0 
iptable_nat             5839  0 
nf_nat                 23604  1 iptable_nat
nf_conntrack_ipv4      10128  3 iptable_nat,nf_nat
nf_conntrack           86772  3 iptable_nat,nf_nat,nf_conntrack_ipv4
nf_defrag_ipv4          1761  1 nf_conntrack_ipv4
iptable_filter          1938  1 
ip_tables              21605  2 iptable_nat,iptable_filter
x_tables               26769  5 xt_tcpudp,xt_physdev,iptable_nat,iptable_filter,ip_tables
sha256_generic         10351  0 
dm_snapshot            33663  4 
binfmt_misc             8370  1 
dm_mirror              15828  0 
dm_region_hash         13123  1 dm_mirror
dm_log                 10726  2 dm_mirror,dm_region_hash
blktap                125515  0 [                 41641  0 [permanent](permanent]
netbk)
gntdev                  8325  78 
evtchn                  5882  70 
blkbk                  26381  0 [        2862  1 blkbk
snd_hda_codec_realtek   352799  1 
snd_hda_intel          28786  5 
snd_hda_codec         106767  2 snd_hda_codec_realtek,snd_hda_intel
snd_hwdep               7474  1 snd_hda_codec
snd_seq                64803  0 
snd_seq_device          7578  1 snd_seq
pcspkr                  2182  0 
snd_pcm               103509  3 snd_hda_intel,snd_hda_codec
btusb                  17481  0 
bluetooth             110684  1 btusb
uvcvideo               67698  0 
videodev               77490  1 uvcvideo
v4l2_compat_ioctl32     7335  1 videodev
sg                     31705  0 
qcserial                4700  0 
usb_wwan               14023  1 qcserial
usbserial              41181  2 qcserial,usb_wwan
snd_timer              26285  2 snd_seq,snd_pcm
sony_laptop            35275  0 
joydev                 12165  0 
iTCO_wdt               12668  0 
snd                    80657  17 snd_hda_codec_realtek,snd_hda_intel,snd_hda_codec,snd_hwdep,snd_seq,snd_seq_device,snd_pcm,snd_timer
iTCO_vendor_support     3110  1 iTCO_wdt
sdhci_pci              10165  0 
sdhci                  23685  1 sdhci_pci
mmc_core               94899  1 sdhci
i2c_i801               10840  0 
rfkill                 21079  2 bluetooth,sony_laptop
intel_ips              13084  0 
battery                12413  0 
ac                      4089  0 
wmi                    11148  0 
thermal                14639  0 
soundcore               8212  1 snd
snd_page_alloc          9100  2 snd_hda_intel,snd_pcm
tpm_infineon            8827  0 
processor              34247  0 
fpu                     2638  4 
aesni_intel            46320  12 
cryptd                 11340  5 aesni_intel
aes_x86_64              8064  1 aesni_intel
aes_generic            27727  2 aesni_intel,aes_x86_64
xts                     2903  4 
gf128mul                8399  1 xts
dm_crypt               18824  1 
ext4                  399882  1 
jbd2                   90056  1 ext4
crc16                   1739  1 ext4
uas                     9779  0 
usb_storage            52735  0 
raid0                   8913  1 
sr_mod                 15340  0 
sd_mod                 38418  2 
cdrom                  42564  1 sr_mod
ahci                   22146  4 
libahci                24983  1 ahci
libata                223474  2 ahci,libahci
scsi_mod              224115  6 sg,uas,usb_storage,sr_mod,sd_mod,libata
ehci_hcd               60797  0 
usbcore               209562  10 usbhid,btusb,uvcvideo,qcserial,usb_wwan,usbserial,uas,usb_storage,ehci_hcd
tpm_tis                11938  1 
tpm                    17299  2 tpm_infineon,tpm_tis
tpm_bios                6260  1 tpm
i915                  537703  2 
drm_kms_helper         37272  1 i915
drm                   232588  3 i915,drm_kms_helper
intel_agp              12418  1 i915
i2c_algo_bit            6408  1 i915
button                  6658  1 i915
intel_gtt              18872  3 i915,intel_agp
agpgart                39754  3 drm,intel_agp,intel_gtt
i2c_core               31494  6 videodev,i2c_i801,i915,drm_kms_helper,drm,i2c_algo_bit
video                  15058  1 i915
thermal_sys            18262  3 thermal,processor,video
hwmon                   2688  1 thermal_sys
pciback                48941  0 
xenbus_be               4125  4 blktap,netbk,blkbk,pciback
             total       used       free     shared    buffers     cached
Mem:       1674288    1600964      73324          0      15492     903452
-/+ buffers/cache:     682020     992268
Swap:      4161532      98368    4063164
success.
/usr/lib64/pm-utils/sleep.d/00powersave suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/00sony-vaio-audio suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/01grub suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/01qubes-suspend-netvm suspend suspend: (null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
Redirecting to /bin/systemctl  stop NetworkManager.service
success.
/usr/lib64/pm-utils/sleep.d/01qubes-sync-vms-clock suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/02qubes-pause-vms suspend suspend: 
Pausing VM: 'netvm'...
Pausing VM: 'firewallvm'...
Pausing VM: 'work-pub'...
Pausing VM: 'work'...
Pausing VM: 'bank'...
Pausing VM: 'personal'...
Pausing VM: 'vault'...
Pausing VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/49bluetooth suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/55NetworkManager suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/56atd suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/56dhclient suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/75modules suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/90clock suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/94cpufreq suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/95led suspend suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/95packagekit suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/98smart-kernel-video suspend suspend: success.
/usr/lib64/pm-utils/sleep.d/99hd-apm-restore.hook suspend suspend: saving level 255 for device sdb
saving level 255 for device sda
success.
/usr/lib64/pm-utils/sleep.d/99sony-vaio-audio suspend suspend: Thu Feb  9 01:28:26 CET 2012
Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 0 [0%](permanent]
blkback_pagemap) [[on](-64.00dB])
success.
/usr/lib64/pm-utils/sleep.d/99video suspend suspend: error: "kernel.acpi_video_flags" is an unknown key
success.
Thu Feb  9 01:28:26 CET 2012: performing suspend
Thu Feb  9 09:27:25 CET 2012: Awake.
Thu Feb  9 09:27:25 CET 2012: Running hooks for resume
/usr/lib64/pm-utils/sleep.d/99video resume suspend: success.
/usr/lib64/pm-utils/sleep.d/99sony-vaio-audio resume suspend: Thu Feb  9 09:27:25 CET 2012
Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 0 [[-64.00dB](0%]) [resume suspend: restoring level 255 for device sdb

/dev/sdb:
 setting Advanced Power Management level to disabled
 APM_level  = off
restoring level 255 for device sda

/dev/sda:
 setting Advanced Power Management level to disabled
 APM_level  = off
success.
/usr/lib64/pm-utils/sleep.d/98smart-kernel-video resume suspend: success.
/usr/lib64/pm-utils/sleep.d/95packagekit resume suspend: method return sender=:1.1261 -> dest=:1.1296 reply_serial=2
success.
/usr/lib64/pm-utils/sleep.d/95led resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/94cpufreq resume suspend: success.
/usr/lib64/pm-utils/sleep.d/90clock resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/75modules resume suspend: success.
/usr/lib64/pm-utils/sleep.d/56dhclient resume suspend: success.
/usr/lib64/pm-utils/sleep.d/56atd resume suspend: success.
/usr/lib64/pm-utils/sleep.d/55NetworkManager resume suspend: success.
/usr/lib64/pm-utils/sleep.d/49bluetooth resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/02qubes-pause-vms resume suspend: 
UnPausing VM: 'netvm'...
UnPausing VM: 'firewallvm'...
UnPausing VM: 'work-pub'...
UnPausing VM: 'work'...
UnPausing VM: 'bank'...
UnPausing VM: 'personal'...
UnPausing VM: 'vault'...
UnPausing VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/01qubes-sync-vms-clock resume suspend: 
Syncing VMs clock to: Thu Feb  9 09:27:26 CET 2012
Running command on VM: 'firewallvm'...
Running command on VM: 'work-pub'...
Running command on VM: 'work'...
Running command on VM: 'bank'...
Running command on VM: 'personal'...
Running command on VM: 'vault'...
Running command on VM: 'qubes'...
success.
/usr/lib64/pm-utils/sleep.d/01qubes-suspend-netvm resume suspend: (null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
(null) is an invalid domain identifier (rc=-6)
success.
/usr/lib64/pm-utils/sleep.d/01grub resume suspend: not applicable.
/usr/lib64/pm-utils/sleep.d/00sony-vaio-audio resume suspend: Simple mixer control 'Master',0
  Capabilities: pvolume pvolume-joined pswitch pswitch-joined penum
  Playback channels: Mono
  Limits: Playback 0 - 64
  Mono: Playback 64 [100%](on]
success.
/usr/lib64/pm-utils/sleep.d/99hd-apm-restore.hook) [[on](0.00dB])
success.
/usr/lib64/pm-utils/sleep.d/00powersave resume suspend: success.
/usr/lib64/pm-utils/sleep.d/00logging resume suspend: success.
/usr/lib64/pm-utils/sleep.d/00auto-quirk resume suspend: succes[  OK  ]
Thu Feb  9 00:15:40 UTC 2012
ed.
Restarting ntpdate (via systemctl):  [FAILED]
Job failed. See system logs and 'systemctl status' for details.

Time sync failed, aborting!
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Mar 8, 2015

Member

Modified by marmarek on 9 Feb 2012 12:39 UTC
Member

marmarek commented Mar 8, 2015

Modified by marmarek on 9 Feb 2012 12:39 UTC

@marmarek marmarek assigned marmarek and unassigned rootkovska Mar 8, 2015

@marmarek

@marmarek marmarek closed this Mar 8, 2015

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment