After my system was updated 3 days ago, I’ve been getting the weirdest pattern where it wakes up around 8 AM every morning:
- Day 1 - @ 8:00:03
- Day 2 - @ 8:01:03
- Day 3 - @ 8:02:03
I have not added any systemd timers, and none are configured to wake up to run. Here’s the list:
┬──[ajgringo619@dss-endeavouros]─[/etc]─[10:40:49]
╰─╼ $ ls-t
System timers
NEXT LEFT LAST PASSED UNIT ACTIVATES
Mon 2023-01-30 10:52:29 PST 8min left Mon 2023-01-30 09:52:29 PST 51min ago btrfsbk.timer btrfsbk.service
Mon 2023-01-30 16:44:07 PST 6h left Sat 2023-01-28 22:07:55 PST 1 day 12h ago systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
Tue 2023-01-31 00:00:00 PST 13h left Mon 2023-01-30 08:02:03 PST 2h 41min ago image-cleanup.timer image-cleanup.service
Tue 2023-01-31 00:00:00 PST 13h left Mon 2023-01-30 08:02:03 PST 2h 41min ago logrotate.timer logrotate.service
Tue 2023-01-31 00:00:00 PST 13h left Mon 2023-01-30 08:02:03 PST 2h 41min ago shadow.timer shadow.service
Tue 2023-01-31 04:09:05 PST 17h left Mon 2023-01-30 08:02:03 PST 2h 41min ago man-db.timer man-db.service
Tue 2023-01-31 11:04:55 PST 24h left Mon 2023-01-30 08:02:03 PST 2h 41min ago updatedb.timer updatedb.service
Wed 2023-02-01 00:00:00 PST 1 day 13h left Sun 2023-01-01 08:35:05 PST 4 weeks 1 day ago btrfs-balance.timer btrfs-balance.service
Wed 2023-02-01 00:00:00 PST 1 day 13h left Sun 2023-01-01 08:35:05 PST 4 weeks 1 day ago btrfs-scrub.timer btrfs-scrub.service
Fri 2023-02-03 16:28:05 PST 4 days left Wed 2023-01-18 08:34:17 PST 1 week 5 days ago archlinux-keyring-wkd-sync.timer archlinux-keyring-wkd-sync.service
Mon 2023-02-06 00:03:55 PST 6 days left Mon 2023-01-30 08:02:03 PST 2h 41min ago fstrim.timer fstrim.service
11 timers listed.
ajgringo619 timers
NEXT LEFT LAST PASSED UNIT ACTIVATES
Mon 2023-01-30 11:00:00 PST 16min left Sun 2023-01-29 11:00:41 PST 23h ago trash_empty.timer trash_empty.service
Tue 2023-01-31 00:04:51 PST 13h left Mon 2023-01-30 08:02:03 PST 2h 41min ago my_logs.timer my_logs.service
Tue 2023-01-31 10:00:00 PST 23h left Mon 2023-01-30 10:00:41 PST 43min ago cloud_sync.timer cloud_sync.service
Mon 2023-02-06 00:00:00 PST 6 days left Mon 2023-01-30 08:02:03 PST 2h 41min ago nix_cleanup.timer nix_cleanup.service
4 timers listed.
All of the timers that triggered when the system woke up are configured with either daily or weekly; these have not been changed in ages.
Here is the systemd journal from the wake up:
Jan 30 08:02:03 kernel: Freezing user space processes ... (elapsed 0.007 seconds) done.
Jan 30 08:02:03 kernel: OOM killer disabled.
Jan 30 08:02:03 kernel: Freezing remaining freezable tasks ... (elapsed 0.000 seconds) done.
Jan 30 08:02:03 kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Jan 30 08:02:03 kernel: sd 2:0:0:0: [sdb] Synchronizing SCSI cache
Jan 30 08:02:03 kernel: sd 2:0:0:0: [sdb] Stopping disk
Jan 30 08:02:03 kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Jan 30 08:02:03 kernel: sd 0:0:0:0: [sda] Stopping disk
Jan 30 08:02:03 kernel: ACPI: EC: interrupt blocked
Jan 30 08:02:03 kernel: ACPI: PM: Preparing to enter system sleep state S3
Jan 30 08:02:03 kernel: ACPI: EC: event blocked
Jan 30 08:02:03 kernel: ACPI: EC: EC stopped
Jan 30 08:02:03 kernel: ACPI: PM: Saving platform NVS memory
Jan 30 08:02:03 kernel: Disabling non-boot CPUs ...
Jan 30 08:02:03 kernel: smpboot: CPU 1 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 2 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 3 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 4 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 5 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 6 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 7 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 8 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 9 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 10 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 11 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 12 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 13 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 14 is now offline
Jan 30 08:02:03 kernel: smpboot: CPU 15 is now offline
Jan 30 08:02:03 kernel: ACPI: PM: Low-level resume complete
Jan 30 08:02:03 kernel: ACPI: EC: EC started
Jan 30 08:02:03 kernel: ACPI: PM: Restoring platform NVS memory
Jan 30 08:02:03 kernel: AMD-Vi: Virtual APIC enabled
Jan 30 08:02:03 kernel: AMD-Vi: Virtual APIC enabled
Jan 30 08:02:03 kernel: Enabling non-boot CPUs ...
Jan 30 08:02:03 kernel: x86: Booting SMP configuration:
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Jan 30 08:02:03 kernel: microcode: CPU1: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C002: Found 2 idle states
Jan 30 08:02:03 kernel: CPU1 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Jan 30 08:02:03 kernel: microcode: CPU2: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C004: Found 2 idle states
Jan 30 08:02:03 kernel: CPU2 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Jan 30 08:02:03 kernel: microcode: CPU3: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C006: Found 2 idle states
Jan 30 08:02:03 kernel: CPU3 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 4 APIC 0x8
Jan 30 08:02:03 kernel: microcode: CPU4: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C008: Found 2 idle states
Jan 30 08:02:03 kernel: CPU4 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 5 APIC 0xa
Jan 30 08:02:03 kernel: microcode: CPU5: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00A: Found 2 idle states
Jan 30 08:02:03 kernel: CPU5 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 6 APIC 0xc
Jan 30 08:02:03 kernel: microcode: CPU6: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00C: Found 2 idle states
Jan 30 08:02:03 kernel: CPU6 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 7 APIC 0xe
Jan 30 08:02:03 kernel: microcode: CPU7: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00E: Found 2 idle states
Jan 30 08:02:03 kernel: CPU7 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 8 APIC 0x1
Jan 30 08:02:03 kernel: microcode: CPU8: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C001: Found 2 idle states
Jan 30 08:02:03 kernel: CPU8 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 9 APIC 0x3
Jan 30 08:02:03 kernel: microcode: CPU9: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C003: Found 2 idle states
Jan 30 08:02:03 kernel: CPU9 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 10 APIC 0x5
Jan 30 08:02:03 kernel: microcode: CPU10: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C005: Found 2 idle states
Jan 30 08:02:03 kernel: CPU10 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 11 APIC 0x7
Jan 30 08:02:03 kernel: microcode: CPU11: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C007: Found 2 idle states
Jan 30 08:02:03 kernel: CPU11 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 12 APIC 0x9
Jan 30 08:02:03 kernel: microcode: CPU12: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C009: Found 2 idle states
Jan 30 08:02:03 kernel: CPU12 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 13 APIC 0xb
Jan 30 08:02:03 kernel: microcode: CPU13: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00B: Found 2 idle states
Jan 30 08:02:03 kernel: CPU13 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 14 APIC 0xd
Jan 30 08:02:03 kernel: microcode: CPU14: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00D: Found 2 idle states
Jan 30 08:02:03 kernel: CPU14 is up
Jan 30 08:02:03 kernel: smpboot: Booting Node 0 Processor 15 APIC 0xf
Jan 30 08:02:03 kernel: microcode: CPU15: patch_level=0x0800820d
Jan 30 08:02:03 kernel: ACPI: \_PR_.C00F: Found 2 idle states
Jan 30 08:02:03 kernel: CPU15 is up
Jan 30 08:02:03 kernel: ACPI: PM: Waking up from system sleep state S3
Jan 30 08:02:03 kernel: ACPI: EC: interrupt unblocked
Jan 30 08:02:03 kernel: ACPI: EC: event unblocked
Jan 30 08:02:03 kernel: xhci_hcd 0000:01:00.0: xHC error in resume, USBSTS 0x401, Reinit
Jan 30 08:02:03 kernel: usb usb1: root hub lost power or was reset
Jan 30 08:02:03 kernel: usb usb2: root hub lost power or was reset
Jan 30 08:02:03 kernel: xhci_hcd 0000:04:00.0: xHC error in resume, USBSTS 0x401, Reinit
Jan 30 08:02:03 kernel: usb usb3: root hub lost power or was reset
Jan 30 08:02:03 kernel: usb usb4: root hub lost power or was reset
Jan 30 08:02:03 kernel: sd 0:0:0:0: [sda] Starting disk
Jan 30 08:02:03 kernel: sd 2:0:0:0: [sdb] Starting disk
Jan 30 08:02:03 kernel: ata9: SATA link down (SStatus 0 SControl 300)
Jan 30 08:02:03 kernel: ata2: SATA link down (SStatus 0 SControl 300)
Jan 30 08:02:03 kernel: ata6: SATA link down (SStatus 0 SControl 330)
Jan 30 08:02:03 kernel: ata5: SATA link down (SStatus 0 SControl 330)
Jan 30 08:02:03 kernel: ata4: SATA link down (SStatus 0 SControl 300)
Jan 30 08:02:03 kernel: ata8: SATA link down (SStatus 0 SControl 330)
Jan 30 08:02:03 kernel: usb 1-14: reset full-speed USB device number 3 using xhci_hcd
Jan 30 08:02:03 kernel: ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jan 30 08:02:03 kernel: ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jan 30 08:02:03 kernel: ata1.00: configured for UDMA/133
Jan 30 08:02:03 kernel: ata3.00: configured for UDMA/133
Jan 30 08:02:03 kernel: usb 4-2: reset SuperSpeed USB device number 2 using xhci_hcd
Jan 30 08:02:03 kernel: usb 1-4: reset full-speed USB device number 2 using xhci_hcd
Jan 30 08:02:03 kernel: ata7: failed to resume link (SControl 0)
Jan 30 08:02:03 kernel: ata7: SATA link down (SStatus 0 SControl 0)
Jan 30 08:02:03 kernel: usb 2-3: reset SuperSpeed USB device number 2 using xhci_hcd
Jan 30 08:02:03 kernel: OOM killer enabled.
Jan 30 08:02:03 kernel: Restarting tasks ...
Jan 30 08:02:05 kernel: Bluetooth: hci0: CSR: Setting up dongle with HCI ver=6 rev=22bb; LMP ver=6 subver=22bb; manufacturer=10
Jan 30 08:02:05 kernel: done.
Jan 30 08:02:05 kernel: random: crng reseeded on system resumption
Jan 30 08:02:05 kernel: PM: suspend exit
Jan 30 08:02:05 kernel: audit: type=1130 audit(1675094523.323:925): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=image-cleanup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094523.326:926): prog-id=72 op=LOAD
Jan 30 08:02:05 kernel: Bluetooth: MGMT ver 1.22
Jan 30 08:02:05 kernel: igb 0000:06:00.0 enp6s0: igb: enp6s0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
Jan 30 08:02:03 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=image-cleanup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:03 audit: BPF prog-id=72 op=LOAD
Jan 30 08:02:03 systemd[1281]: Started Daily rotation of my user logs.
Jan 30 08:02:05 bash[159435]: reading config file /home/ajgringo619/.config/logrotate/unison.conf
Jan 30 08:02:05 bash[159435]: compress_prog is now /usr/bin/bzip2
Jan 30 08:02:05 bash[159435]: compress_ext was changed to .bz2
Jan 30 08:02:05 bash[159435]: uncompress_prog is now /usr/bin/bunzip2
Jan 30 08:02:05 bash[159435]: acquired lock on state file /home/ajgringo619/.config/logrotate/statusReading state from file: /home/ajgringo619/.config/logrotate/status
Jan 30 08:02:05 bash[159435]: Allocating hash table for state file, size 64 entries
Jan 30 08:02:05 bash[159435]: Creating new state
Jan 30 08:02:05 bash[159435]: Handling 1 logs
Jan 30 08:02:05 bash[159435]: rotating pattern: /home/ajgringo619/.unison/unison.log weekly (4 rotations)
Jan 30 08:02:05 bash[159435]: empty log files are not rotated, old logs are removed
Jan 30 08:02:05 bash[159435]: considering log /home/ajgringo619/.unison/unison.log
Jan 30 08:02:05 bash[159435]: Now: 2023-01-30 08:02
Jan 30 08:02:05 bash[159435]: Last rotated at 2023-01-29 08:01
Jan 30 08:02:05 bash[159435]: log does not need rotating (log has been rotated at 2023-01-29 08:01, which is less than a week ago)
Jan 30 08:02:03 systemd[1281]: Started Weekly cleanup of Nix package store.
Jan 30 08:02:03 systemd-sleep[159334]: System returned from sleep state.
Jan 30 08:02:03 systemd[1]: Starting Discard unused blocks on filesystems from /etc/fstab...
Jan 30 08:02:03 systemd[1]: Started Cleanup of system image backup files.
Jan 30 08:02:03 systemd[1]: Starting Load/Save RF Kill Switch Status...
Jan 30 08:02:04 systemd[1281]: Stopped target Bluetooth.
Jan 30 08:02:04 systemd[1281]: Reached target Bluetooth.
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.3385] device (enp6s0): carrier: link connected
Jan 30 08:02:05 systemd[1]: Starting Rotate log files...
Jan 30 08:02:05 audit: BPF prog-id=73 op=LOAD
Jan 30 08:02:05 systemd[1]: Starting Daily man-db regeneration...
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.411:927): prog-id=73 op=LOAD
Jan 30 08:02:05 audit: BPF prog-id=74 op=LOAD
Jan 30 08:02:05 audit: BPF prog-id=75 op=LOAD
Jan 30 08:02:05 audit: BPF prog-id=76 op=LOAD
Jan 30 08:02:05 audit: BPF prog-id=54 op=UNLOAD
Jan 30 08:02:05 audit: BPF prog-id=55 op=UNLOAD
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.412:928): prog-id=74 op=LOAD
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.412:929): prog-id=75 op=LOAD
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.412:930): prog-id=76 op=LOAD
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.412:931): prog-id=54 op=UNLOAD
Jan 30 08:02:05 kernel: audit: type=1334 audit(1675094525.412:932): prog-id=55 op=UNLOAD
Jan 30 08:02:05 systemd[1]: Started Verify integrity of password and group files.
Jan 30 08:02:05 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadow comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:05 audit: BPF prog-id=77 op=LOAD
Jan 30 08:02:05 systemd[1]: Starting Update locate database...
Jan 30 08:02:05 systemd[1]: Started Load/Save RF Kill Switch Status.
Jan 30 08:02:05 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:05 systemd[1]: systemd-suspend.service: Deactivated successfully.
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4259] manager: (0C:02:BD:35:52:B1): new Bluetooth device (/org/freedesktop/NetworkManager/Devices/15)
Jan 30 08:02:05 systemd[1]: Finished System Suspend.
Jan 30 08:02:05 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:05 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 30 08:02:05 systemd[1]: Stopped target Bluetooth Support.
Jan 30 08:02:05 systemd[1]: Stopped target Sleep.
Jan 30 08:02:05 systemd[1]: Reached target Suspend.
Jan 30 08:02:05 systemd-logind[930]: Operation 'sleep' finished.
Jan 30 08:02:05 systemd[1]: Starting NVIDIA system resume actions...
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4432] manager: sleep: wake requested (sleeping: yes enabled: yes)
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4432] device (enp6s0): state change: activated -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4433] dhcp6 (enp6s0): canceled DHCP transaction
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4433] dhcp6 (enp6s0): activation: beginning transaction (timeout in 45 seconds)
Jan 30 08:02:05 NetworkManager[936]: <info> [1675094525.4433] dhcp6 (enp6s0): state changed no lease
Jan 30 08:02:05 suspend[159481]: nvidia-resume.service
Jan 30 08:02:05 logger[159481]: <13>Jan 30 08:02:05 suspend: nvidia-resume.service
Jan 30 08:02:05 systemd[1]: Stopped target Suspend.
Jan 30 08:02:05 systemd[1]: nvidia-resume.service: Deactivated successfully.
Jan 30 08:02:05 dnsmasq[1111]: no servers found in /etc/resolv.conf, will retry
Jan 30 08:02:05 avahi-daemon[923]: Withdrawing address record for 192.168.0.15 on enp6s0.
Jan 30 08:02:05 avahi-daemon[923]: Leaving mDNS multicast group on interface enp6s0.IPv4 with address 192.168.0.15.
Jan 30 08:02:05 avahi-daemon[923]: Interface enp6s0.IPv4 no longer relevant for mDNS.
Jan 30 08:02:05 avahi-daemon[923]: Withdrawing address record for 2600:8801:fd01:3400::5c17 on enp6s0.
Jan 30 08:02:05 avahi-daemon[923]: Withdrawing address record for 2600:8801:fd01:3400:1ce0:c3e2:c853:e5ff on enp6s0.
Jan 30 08:02:05 avahi-daemon[923]: Leaving mDNS multicast group on interface enp6s0.IPv6 with address 2600:8801:fd01:3400:1ce0:c3e2:c853:e5ff.
Jan 30 08:02:05 avahi-daemon[923]: Joining mDNS multicast group on interface enp6s0.IPv6 with address fe80::f7b4:e68b:add3:2ab6.
Jan 30 08:02:05 avahi-daemon[923]: Registering new address record for fe80::f7b4:e68b:add3:2ab6 on enp6s0.*.
Jan 30 08:02:05 avahi-daemon[923]: Withdrawing address record for fe80::f7b4:e68b:add3:2ab6 on enp6s0.
Jan 30 08:02:05 avahi-daemon[923]: Leaving mDNS multicast group on interface enp6s0.IPv6 with address fe80::f7b4:e68b:add3:2ab6.
Jan 30 08:02:05 avahi-daemon[923]: Interface enp6s0.IPv6 no longer relevant for mDNS.
Jan 30 08:02:05 systemd[1]: Finished NVIDIA system resume actions.
This is not a high priority, as I’m normally up when this happens. But it’s so strange that I’d like to troubleshoot it…any ideas where to start?