Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Michael Biebl]

Am 19.01.2016 um 10:36 schrieb Christian Pernegger:
> Package: systemd
> Version: 215-17+deb8u2
> Severity: normal
> 
> 
> Hello,
> 
> I'm trying to do the following:
> 1) wake up the system every night at 3 am (using a timer unit with 
> WakeSystem=yes)
> 2) pull in backups (using a service triggered by the timer unit)
> 3) send it to sleep again (via logind idle timeout)
> 
> See attached files backup.timer and backup.service.

I've tried those example unit files (with v235) and got the following
error on wakeup:
Nov 08 22:43:15 pluto systemd[1]: backup.service: Main process exited,
code=exited, status=1/FAILURE
Nov 08 22:43:15 pluto systemd-inhibit[3709]: Failed to inhibit: The
operation inhibition has been requested for is already running
Nov 08 22:43:15 pluto systemd[1]: backup.service: Failed with result
'exit-code'.

I wonder if your problem is related to the usage of systemd-inhibit.

Can you try and run the shell script directly?

Btw, for a script/use case like yours, using Type=oneshot is probably
more suitable.

-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Michael Biebl]

Am 19.01.2016 um 10:36 schrieb Christian Pernegger:
> Package: systemd
> Version: 215-17+deb8u2
> Severity: normal
> 
> 
> Hello,
> 
> I'm trying to do the following:
> 1) wake up the system every night at 3 am (using a timer unit with 
> WakeSystem=yes)
> 2) pull in backups (using a service triggered by the timer unit)
> 3) send it to sleep again (via logind idle timeout)
> 
> See attached files backup.timer and backup.service.
> 
> Now, step 1 works, it'll always wake up at 3 am, and sometimes
> backup.service will then run as it should, sometimes it won't.
> 
> (For completeness' sake: starting backup.service manually always
> works, as does running it on a timer when the machine is already
> up. Same goes for suspend on idle.)
> 
> It might be some kind of timing issue but frankly I've no idea where
> to look. The journal doesn't show anything about the timer unit in any
> case, the service unit does get mentioned only because a sudo session
> is opened for it (only when it actually runs).
> 


Christian, can you show me the output of
systemctl status backup.service
after such a wakeup and failed attempt to start the service?
What would probably useful as well is to increase the log level of
systemd (systemd-analyze set-log-level debug) and get a journal log from
after the wakeup.

Michael

-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Michael Biebl]

Am 08.11.2017 um 20:21 schrieb Alberto Manzaneque García:
> I have the same problem too on version 234.
> Do you know if there is a systemd (not debian) bug open?
> 
> On Sat, 25 Feb 2017 16:35:20 +0200 (EET) Madis Janson  > wrote:
>>
>> I have exactly the same problem with Debian Stretch (testing) on amd64.
>> Package version is 232-15.
>>
>> $ systemctl --version
>> systemd 232
>> +PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP
>> +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN
>>
>> The system wakes, but the service unit won't be started. If the system
>> wasn't syspended then the timer service works as expected.
>>



Upstream only tracks the latest two upstream releases, but as Alberto
can apparently reproduce it with v234 it should be ok to file this
upstream at https://github.com/systemd/systemd

If you can verify it with v235, even better.

Once you have a bug number, please report back and will link the two bug
reports then.

Thanks,
Michael


-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Alberto Manzaneque García]

I have the same problem too on version 234.
Do you know if there is a systemd (not debian) bug open?

On Sat, 25 Feb 2017 16:35:20 +0200 (EET) Madis Janson 
wrote:
>
> I have exactly the same problem with Debian Stretch (testing) on amd64.
> Package version is 232-15.
>
> $ systemctl --version
> systemd 232
> +PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP
> +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN
>
> The system wakes, but the service unit won't be started. If the system
> wasn't syspended then the timer service works as expected.
>
>

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Madis Janson]

I have exactly the same problem with Debian Stretch (testing) on amd64.
Package version is 232-15.

$ systemctl --version
systemd 232
+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP 
+GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN


The system wakes, but the service unit won't be started. If the system 
wasn't syspended then the timer service works as expected.

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Christian Pernegger]

Alright, I'm giving up on this. A timer with "WakeSystem=yes" will
consistently wake this system from suspend, whether it will then execute
that same timer's payload is quite another matter.

I had it running for ~2 months, thought I'd cracked it, now it's stopped
working entirely (still wakes up every night but hasn't triggered for 3
days in a row). Nothing pertinent in the journal even at log-level debug.

Cheers,
C.

2016-01-29 15:54 GMT+01:00 Christian Pernegger :

> Hello,
>
> it seems like 216 has a change that might affect this, namely giving
> OnCalendar-timers an implicit After-dependency on time-sync.target. (The
> changelog and most documentation says timeR-sync.target, but Debian's 215
> at least doesn't have that.) Easy enough to add manually, but it would be
> nice if it were documented in README.Debian.
>
> Then I'd get a few failures because backup.service would be started before
> the resume from suspend was actually complete (suspend.target and/or
> sleep.target still active), preventing systemd-inhibit from getting a
> wake-lock. Now I have After-deps on the suspend, sleep and hybrid-sleep
> targets as a workaround.
>
> The band-aids seem to be holding, no missed backups for ~1 week.
>
> Regards,
> Christian Pernegger
>
> On 22 January 2016 at 10:39, Christian Pernegger 
> wrote:
>
>> Hello again,
>>
>> I just wanted to document a few further observations & things I tried:
>>
>> * A dummy timer that just sent me mail every hour (but otherwise
>> configured identically) managed to wake the system up 20 out of 20 times
>> and did send mail on 18 of these. Sadly, with the backup.service the track
>> record is more like fifty-fifty.
>> * replacing ntpdate with systemd-timesyncd (the whole guarantees
>> monotonic time thing) does not help
>>
>> Status after a failed run:
>> chris@mrmackey:~$ sudo systemctl status backup.service
>> ● backup.service - Pulls configured backups
>>Loaded: loaded (/etc/systemd/system/backup.service; static)
>>Active: inactive (dead)
>>
>> chris@mrmackey:~$ sudo systemctl status backup.timer
>> ● backup.timer - Wakes the system up once per day for backups
>>Loaded: loaded (/etc/systemd/system/backup.timer; enabled)
>>Active: active (waiting) since Don 2016-01-21 13:15:53 CET; 21h ago
>>
>> chris@mrmackey:~$ sudo systemctl list-timers
>> NEXT LEFT LAST
>> PASSED  UNIT ACTIVATES
>> Sam 2016-01-23 03:00:00 CET  16h left n/a
>> n/a backup.timer backup.service
>> Sam 2016-01-23 10:06:21 CET  23h left Don 2016-01-21 13:30:30 CET  20h
>> ago systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
>> [...]
>>
>> Workarounds galore, of course, but I'd still prefer this function to work
>> as documented.
>>
>> Regards,
>> Christian Pernegger
>>
>>
>>
>>
>> On 19 January 2016 at 10:36, Christian Pernegger 
>> wrote:
>>
>>> Package: systemd
>>> Version: 215-17+deb8u2
>>> Severity: normal
>>>
>>>
>>> Hello,
>>>
>>> I'm trying to do the following:
>>> 1) wake up the system every night at 3 am (using a timer unit with
>>> WakeSystem=yes)
>>> 2) pull in backups (using a service triggered by the timer unit)
>>> 3) send it to sleep again (via logind idle timeout)
>>>
>>> See attached files backup.timer and backup.service.
>>>
>>> Now, step 1 works, it'll always wake up at 3 am, and sometimes
>>> backup.service will then run as it should, sometimes it won't.
>>>
>>> (For completeness' sake: starting backup.service manually always
>>> works, as does running it on a timer when the machine is already
>>> up. Same goes for suspend on idle.)
>>>
>>> It might be some kind of timing issue but frankly I've no idea where
>>> to look. The journal doesn't show anything about the timer unit in any
>>> case, the service unit does get mentioned only because a sudo session
>>> is opened for it (only when it actually runs).
>>>
>>> Regards,
>>> Christian Pernegger
>>>
>>>
>>>
>>> -- Package-specific info:
>>>
>>> -- System Information:
>>> Debian Release: 8.2
>>>   APT prefers stable-updates
>>>   APT policy: (500, 'stable-updates'), (500, 'stable')
>>> Architecture: amd64 (x86_64)
>>>
>>> Kernel: Linux 3.16.0-4-amd64 (SMP w/2 CPU cores)
>>> Locale: LANG=de_AT.UTF-8, LC_CTYPE=de_AT.UTF-8 (charmap=UTF-8)
>>> Shell: /bin/sh linked to /bin/dash
>>> Init: systemd (via /run/systemd/system)
>>>
>>> Versions of packages systemd depends on:
>>> ii  acl 2.2.52-2
>>> ii  adduser 3.113+nmu3
>>> ii  initscripts 2.88dsf-59
>>> ii  libacl1 2.2.52-2
>>> ii  libaudit1   1:2.4-1+b1
>>> ii  libblkid1   2.25.2-6
>>> ii  libc6   2.19-18+deb8u1
>>> ii  libcap2 1:2.24-8
>>> ii  libcap2-bin 1:2.24-8
>>> ii  libcryptsetup4  2:1.6.6-5
>>> ii  libgcrypt20 1.6.3-2
>>> ii  libkmod218-3
>>> ii  liblzma55.1.1alpha+20120614-2+b3
>>> ii  libpam0g1.1.8-3.1
>>> ii  libselinux1 2.3-2
>>> ii  libsystemd0 215-17+deb8u2
>>> ii  mount   2.25.2-6

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Christian Pernegger]

Hello,

it seems like 216 has a change that might affect this, namely giving
OnCalendar-timers an implicit After-dependency on time-sync.target. (The
changelog and most documentation says timeR-sync.target, but Debian's 215
at least doesn't have that.) Easy enough to add manually, but it would be
nice if it were documented in README.Debian.

Then I'd get a few failures because backup.service would be started before
the resume from suspend was actually complete (suspend.target and/or
sleep.target still active), preventing systemd-inhibit from getting a
wake-lock. Now I have After-deps on the suspend, sleep and hybrid-sleep
targets as a workaround.

The band-aids seem to be holding, no missed backups for ~1 week.

Regards,
Christian Pernegger

On 22 January 2016 at 10:39, Christian Pernegger 
wrote:

> Hello again,
>
> I just wanted to document a few further observations & things I tried:
>
> * A dummy timer that just sent me mail every hour (but otherwise
> configured identically) managed to wake the system up 20 out of 20 times
> and did send mail on 18 of these. Sadly, with the backup.service the track
> record is more like fifty-fifty.
> * replacing ntpdate with systemd-timesyncd (the whole guarantees monotonic
> time thing) does not help
>
> Status after a failed run:
> chris@mrmackey:~$ sudo systemctl status backup.service
> ● backup.service - Pulls configured backups
>Loaded: loaded (/etc/systemd/system/backup.service; static)
>Active: inactive (dead)
>
> chris@mrmackey:~$ sudo systemctl status backup.timer
> ● backup.timer - Wakes the system up once per day for backups
>Loaded: loaded (/etc/systemd/system/backup.timer; enabled)
>Active: active (waiting) since Don 2016-01-21 13:15:53 CET; 21h ago
>
> chris@mrmackey:~$ sudo systemctl list-timers
> NEXT LEFT LAST PASSED
> UNIT ACTIVATES
> Sam 2016-01-23 03:00:00 CET  16h left n/a  n/a
> backup.timer backup.service
> Sam 2016-01-23 10:06:21 CET  23h left Don 2016-01-21 13:30:30 CET  20h ago
> systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
> [...]
>
> Workarounds galore, of course, but I'd still prefer this function to work
> as documented.
>
> Regards,
> Christian Pernegger
>
>
>
>
> On 19 January 2016 at 10:36, Christian Pernegger 
> wrote:
>
>> Package: systemd
>> Version: 215-17+deb8u2
>> Severity: normal
>>
>>
>> Hello,
>>
>> I'm trying to do the following:
>> 1) wake up the system every night at 3 am (using a timer unit with
>> WakeSystem=yes)
>> 2) pull in backups (using a service triggered by the timer unit)
>> 3) send it to sleep again (via logind idle timeout)
>>
>> See attached files backup.timer and backup.service.
>>
>> Now, step 1 works, it'll always wake up at 3 am, and sometimes
>> backup.service will then run as it should, sometimes it won't.
>>
>> (For completeness' sake: starting backup.service manually always
>> works, as does running it on a timer when the machine is already
>> up. Same goes for suspend on idle.)
>>
>> It might be some kind of timing issue but frankly I've no idea where
>> to look. The journal doesn't show anything about the timer unit in any
>> case, the service unit does get mentioned only because a sudo session
>> is opened for it (only when it actually runs).
>>
>> Regards,
>> Christian Pernegger
>>
>>
>>
>> -- Package-specific info:
>>
>> -- System Information:
>> Debian Release: 8.2
>>   APT prefers stable-updates
>>   APT policy: (500, 'stable-updates'), (500, 'stable')
>> Architecture: amd64 (x86_64)
>>
>> Kernel: Linux 3.16.0-4-amd64 (SMP w/2 CPU cores)
>> Locale: LANG=de_AT.UTF-8, LC_CTYPE=de_AT.UTF-8 (charmap=UTF-8)
>> Shell: /bin/sh linked to /bin/dash
>> Init: systemd (via /run/systemd/system)
>>
>> Versions of packages systemd depends on:
>> ii  acl 2.2.52-2
>> ii  adduser 3.113+nmu3
>> ii  initscripts 2.88dsf-59
>> ii  libacl1 2.2.52-2
>> ii  libaudit1   1:2.4-1+b1
>> ii  libblkid1   2.25.2-6
>> ii  libc6   2.19-18+deb8u1
>> ii  libcap2 1:2.24-8
>> ii  libcap2-bin 1:2.24-8
>> ii  libcryptsetup4  2:1.6.6-5
>> ii  libgcrypt20 1.6.3-2
>> ii  libkmod218-3
>> ii  liblzma55.1.1alpha+20120614-2+b3
>> ii  libpam0g1.1.8-3.1
>> ii  libselinux1 2.3-2
>> ii  libsystemd0 215-17+deb8u2
>> ii  mount   2.25.2-6
>> ii  sysv-rc 2.88dsf-59
>> ii  udev215-17+deb8u2
>> ii  util-linux  2.25.2-6
>>
>> Versions of packages systemd recommends:
>> ii  dbus1.8.20-0+deb8u1
>> ii  libpam-systemd  215-17+deb8u2
>>
>> Versions of packages systemd suggests:
>> pn  systemd-ui  
>>
>> -- Configuration Files:
>> /etc/systemd/journald.conf changed:
>> [Journal]
>> Storage=persistent
>> Compress=no
>>
>> /etc/systemd/logind.conf changed:
>> [Login]
>> IdleAction=suspend
>> IdleActionSec=30min
>>
>>
>> -- no debconf information
>>
>
>

Bug#811473: systemd: timer with WakeSystem=yes doesn't always start the service it's supposed to trigger

[Christian Pernegger]

Hello again,

I just wanted to document a few further observations & things I tried:

* A dummy timer that just sent me mail every hour (but otherwise configured
identically) managed to wake the system up 20 out of 20 times and did send
mail on 18 of these. Sadly, with the backup.service the track record is
more like fifty-fifty.
* replacing ntpdate with systemd-timesyncd (the whole guarantees monotonic
time thing) does not help

Status after a failed run:
chris@mrmackey:~$ sudo systemctl status backup.service
● backup.service - Pulls configured backups
   Loaded: loaded (/etc/systemd/system/backup.service; static)
   Active: inactive (dead)

chris@mrmackey:~$ sudo systemctl status backup.timer
● backup.timer - Wakes the system up once per day for backups
   Loaded: loaded (/etc/systemd/system/backup.timer; enabled)
   Active: active (waiting) since Don 2016-01-21 13:15:53 CET; 21h ago

chris@mrmackey:~$ sudo systemctl list-timers
NEXT LEFT LAST PASSED
UNIT ACTIVATES
Sam 2016-01-23 03:00:00 CET  16h left n/a  n/a
backup.timer backup.service
Sam 2016-01-23 10:06:21 CET  23h left Don 2016-01-21 13:30:30 CET  20h ago
systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
[...]

Workarounds galore, of course, but I'd still prefer this function to work
as documented.

Regards,
Christian Pernegger



On 19 January 2016 at 10:36, Christian Pernegger 
wrote:

> Package: systemd
> Version: 215-17+deb8u2
> Severity: normal
>
>
> Hello,
>
> I'm trying to do the following:
> 1) wake up the system every night at 3 am (using a timer unit with
> WakeSystem=yes)
> 2) pull in backups (using a service triggered by the timer unit)
> 3) send it to sleep again (via logind idle timeout)
>
> See attached files backup.timer and backup.service.
>
> Now, step 1 works, it'll always wake up at 3 am, and sometimes
> backup.service will then run as it should, sometimes it won't.
>
> (For completeness' sake: starting backup.service manually always
> works, as does running it on a timer when the machine is already
> up. Same goes for suspend on idle.)
>
> It might be some kind of timing issue but frankly I've no idea where
> to look. The journal doesn't show anything about the timer unit in any
> case, the service unit does get mentioned only because a sudo session
> is opened for it (only when it actually runs).
>
> Regards,
> Christian Pernegger
>
>
>
> -- Package-specific info:
>
> -- System Information:
> Debian Release: 8.2
>   APT prefers stable-updates
>   APT policy: (500, 'stable-updates'), (500, 'stable')
> Architecture: amd64 (x86_64)
>
> Kernel: Linux 3.16.0-4-amd64 (SMP w/2 CPU cores)
> Locale: LANG=de_AT.UTF-8, LC_CTYPE=de_AT.UTF-8 (charmap=UTF-8)
> Shell: /bin/sh linked to /bin/dash
> Init: systemd (via /run/systemd/system)
>
> Versions of packages systemd depends on:
> ii  acl 2.2.52-2
> ii  adduser 3.113+nmu3
> ii  initscripts 2.88dsf-59
> ii  libacl1 2.2.52-2
> ii  libaudit1   1:2.4-1+b1
> ii  libblkid1   2.25.2-6
> ii  libc6   2.19-18+deb8u1
> ii  libcap2 1:2.24-8
> ii  libcap2-bin 1:2.24-8
> ii  libcryptsetup4  2:1.6.6-5
> ii  libgcrypt20 1.6.3-2
> ii  libkmod218-3
> ii  liblzma55.1.1alpha+20120614-2+b3
> ii  libpam0g1.1.8-3.1
> ii  libselinux1 2.3-2
> ii  libsystemd0 215-17+deb8u2
> ii  mount   2.25.2-6
> ii  sysv-rc 2.88dsf-59
> ii  udev215-17+deb8u2
> ii  util-linux  2.25.2-6
>
> Versions of packages systemd recommends:
> ii  dbus1.8.20-0+deb8u1
> ii  libpam-systemd  215-17+deb8u2
>
> Versions of packages systemd suggests:
> pn  systemd-ui  
>
> -- Configuration Files:
> /etc/systemd/journald.conf changed:
> [Journal]
> Storage=persistent
> Compress=no
>
> /etc/systemd/logind.conf changed:
> [Login]
> IdleAction=suspend
> IdleActionSec=30min
>
>
> -- no debconf information
>