Caffeine service keeps failing

[dschrempf]

The caffeine service keeps failing:

$ journalctl -b | grep caffeine
Feb 02 20:34:43 schwarzbaer systemd[1076]: Starting caffeine...
Feb 02 20:34:43 schwarzbaer systemd[1076]: Started caffeine.
Feb 02 20:34:43 schwarzbaer caffeine[1123]: CRITICAL:caffeine.main:Caffeine is already running
Feb 02 20:34:43 schwarzbaer systemd[1076]: caffeine.service: Main process exited, code=exited, status=253/n/a
Feb 02 20:34:43 schwarzbaer systemd[1076]: caffeine.service: Failed with result 'exit-code'.
Feb 02 20:34:44 schwarzbaer systemd[1076]: caffeine.service: Scheduled restart job, restart counter is at 1.
Feb 02 20:34:44 schwarzbaer systemd[1076]: Stopped caffeine.
...
Feb 02 20:34:47 schwarzbaer systemd[1076]: caffeine.service: Start request repeated too quickly.
Feb 02 20:34:47 schwarzbaer systemd[1076]: caffeine.service: Failed with result 'exit-code'.
Feb 02 20:34:47 schwarzbaer systemd[1076]: Failed to start caffeine.

I did not yet find out when the service fails. I think it is after suspend, or after display changes. In particular, it is not true that "Caffeine is already running." (I checked with ps).

I had a look at the created caffeine.service systemd service file:

[Install]
WantedBy=graphical-session.target

[Service]
ExecStart=/nix/store/jsrqn034clwarlgxp0zzdkmir85hb8gi-caffeine-ng-3.4.2/bin/caffeine
PrivateTmp=true
ProtectHome=yes
ProtectSystem=full
Restart=on-failure
Slice=session.slice
Type=exec

[Unit]
Description=caffeine

I did not know the PrivateTmp and ProtectHome keys, and I read in the systemd manual, that they are not to be used with user services, so this should probably be changed. Further, I don't understand the Slice key. But maybe, the problem is with caffeine itself, and not with the created systemd service. Do you have an idea?

EDIT: Executing /nix/store/jsrqn034clwarlgxp0zzdkmir85hb8gi-caffeine-ng-3.4.2/bin/caffeine from the terminal gives the "already running" error, but /nix/store/jsrqn034clwarlgxp0zzdkmir85hb8gi-caffeine-ng-3.4.2/bin/caffeine -k works.

[berbiche]

cc @uvNikita as the maintainer of the module

[uvNikita]

PrivateTmp, ProtectHome and ProtectSystem are ignored for user services. We should probably remove them not to confuse anyone, but they shouldn't matter when it comes to this issue.

Slice=session.slice part comes from this WIP document: https://systemd.io/DESKTOP_ENVIRONMENTS but can also be ignored for this issue I think.

Just to double-check, $ systemctl --user status caffeine doesn't list any running processes when this happens either?

It seems like the way caffeine checks that another process is running is by looking if the pid file is present:

https://github.com/caffeine-ng/caffeine-ng/blob/ed5e9e79d63d3c6dec6046e43741d24b1bf27382/caffeine/applicationinstance.py#L38

So my guess is that caffeine process is crashing and not removing its pid file. Looking at the service log files can help to figure out why this happens: $ journalctl --user -u caffeine

[dschrempf]

 + systemctl --user status caffeine.service
● caffeine.service - caffeine
     Loaded: loaded (/nix/store/lgimpqv8mnm14knmzzhk5q3km0zprsjq-home-manager-files/.config/systemd/user/caffeine.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Wed 2021-02-03 15:36:23 CET; 10min ago
   Main PID: 2195 (code=exited, status=253)
        CPU: 356ms

Feb 03 15:36:23 schwarzbaer systemd[1070]: caffeine.service: Scheduled restart job, restart counter is at 5.
Feb 03 15:36:23 schwarzbaer systemd[1070]: Stopped caffeine.
Feb 03 15:36:23 schwarzbaer systemd[1070]: caffeine.service: Start request repeated too quickly.
Feb 03 15:36:23 schwarzbaer systemd[1070]: caffeine.service: Failed with result 'exit-code'.
Feb 03 15:36:23 schwarzbaer systemd[1070]: Failed to start caffeine.

That's what I find with journalctl --user -u caffeine:

Feb 03 15:35:53 schwarzbaer c[1107]: .caffeine-wrapped: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
Feb 03 15:35:53 schwarzbaer systemd[1056]: caffeine.service: Main process exited, code=exited, status=1/FAILURE
Feb 03 15:35:53 schwarzbaer systemd[1056]: caffeine.service: Failed with result 'exit-code'.
Feb 03 15:35:53 schwarzbaer systemd[1056]: caffeine.service: Consumed 3.917s CPU time.

I guess this happened when I issued home-manager switch. Or maybe during boot? I don't know. I begin to expect that the service is started too early.

[uvNikita]

This seems to be a bug in caffeine ng and should probably be fixed there. The only workaround I can suggest here is to add something like this to a caffeine service file:

systemd.user.services.caffeine.Service.ExecStopPost = runCommand "rm /tmp/caffeine$(id -u).pid"

Note that I haven't tested the code above.

[stale[bot]]

Thank you for your contribution! I marked this issue as stale due to inactivity. If this remains inactive for another 7 days, I will close this issue. Please read the relevant sections below before commenting.

If you are the original author of the issue

* If this is resolved, please consider closing it so that the maintainers know not to focus on this. * If this might still be an issue, but you are not interested in promoting its resolution, please consider closing it while encouraging others to take over and reopen an issue if they care enough. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

If you are not the original author of the issue

* If you are also experiencing this issue, please add details of your situation to help with the debugging process. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

Memorandum on closing issues

If you have nothing of substance to add, please refrain from commenting and allow the bot close the issue. Also, don't be afraid to manually close an issue, even if it holds valuable information.

Closed issues stay in the system for people to search, read, cross-reference, or even reopen--nothing is lost! Closing obsolete issues is an important way to help maintainers focus their time and effort.

[berbiche]

@uvNikita would using PIDFile from https://www.freedesktop.org/software/systemd/man/systemd.service.html#PIDFile= resolve the issue? This setting allows systemd to automatically remove the pid file after the process is shutdown.

[uvNikita]

Yes, I guess it could help indeed. The only thing is that /tmp/caffeine$(uid).pid path is hard-coded, so we need to know UID in home-manager to be able to create correct service file.

[stale[bot]]

Thank you for your contribution! I marked this issue as stale due to inactivity. If this remains inactive for another 7 days, I will close this issue. Please read the relevant sections below before commenting.

If you are the original author of the issue

* If this is resolved, please consider closing it so that the maintainers know not to focus on this. * If this might still be an issue, but you are not interested in promoting its resolution, please consider closing it while encouraging others to take over and reopen an issue if they care enough. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

If you are not the original author of the issue

* If you are also experiencing this issue, please add details of your situation to help with the debugging process. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

Memorandum on closing issues

If you have nothing of substance to add, please refrain from commenting and allow the bot close the issue. Also, don't be afraid to manually close an issue, even if it holds valuable information.

Closed issues stay in the system for people to search, read, cross-reference, or even reopen--nothing is lost! Closing obsolete issues is an important way to help maintainers focus their time and effort.