Bug 89587

Summary: MSG: improve error message when dir specified in RuntimeDirectory= already exists but has differing access mode
Product: systemd Reporter: Fireball <ao>
Component: generalAssignee: systemd-bugs
Status: RESOLVED FIXED QA Contact: systemd-bugs
Severity: normal    
Priority: medium    
Version: unspecified   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: i915 features:

Description Fireball 2015-03-16 08:45:43 UTC
This is the unit I came up with called co2mon-log.service:

[Unit]
Description=Log Data From CO2Mon
PartOf=co2mon.service

[Service]
User=co2mon
Group=co2mon
RuntimeDirectory=co2mon
RuntimeDirectoryMode=0755
WorkingDirectory=/run/co2mon
StandardOutput=null
ExecStartPre=/usr/bin/rsync -a /var/lib/co2mon/ /run/co2mon
ExecStart=/bin/bash ./update_data.sh
ExecStopPost=-/bin/cp -p /run/co2mon/graph.rrd /var/lib/co2mon/

[Install]
WantedBy=multi-user.target

Starting it manually produces an error:

● co2mon-log.service - Log Data From CO2Mon
   Loaded: loaded (/usr/lib64/systemd/system/co2mon-log.service; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since 月 2015-03-16 11:36:02 MSK; 1s ago
  Process: 15105 ExecStopPost=/bin/cp -p /run/co2mon/graph.rrd /var/lib/co2mon/ (code=exited, status=233/RUNTIME_DIRECTORY)
  Process: 15104 ExecStart=/bin/bash ./update_data.sh (code=exited, status=233/RUNTIME_DIRECTORY)
  Process: 15098 ExecStartPre=/usr/bin/rsync -a /var/lib/co2mon/ /run/co2mon (code=exited, status=0/SUCCESS)
 Main PID: 15104 (code=exited, status=233/RUNTIME_DIRECTORY)

 3月 16 11:36:02 melforce systemd[1]: Starting Log Data From CO2Mon...
 3月 16 11:36:02 melforce systemd[1]: Started Log Data From CO2Mon.
 3月 16 11:36:02 melforce systemd[15104]: Failed at step RUNTIME_DIRECTORY spawning /bin/bash: File exists
 3月 16 11:36:02 melforce systemd[1]: co2mon-log.service: main process exited, code=exited, status=233/RUNTIME_DIRECTORY
 3月 16 11:36:02 melforce systemd[15105]: Failed at step RUNTIME_DIRECTORY spawning /bin/cp: File exists
 3月 16 11:36:02 melforce systemd[1]: Unit co2mon-log.service entered failed state.
 3月 16 11:36:02 melforce systemd[1]: co2mon-log.service failed.

If I commment out options RuntimeDirectory= and RuntimeDirectoryMode= and create directory /run/co2mon by hand giving it co2mon:co2mon ownership and mode 755, my unit starts successfully.

systemd version is 219.

I've read the manual systemd.exec and I think there are no problems with the unit itself.
Comment 1 Zbigniew Jedrzejewski-Szmek 2015-03-16 13:18:44 UTC
The directory is copied with rsync first. Then systemd tries to create it before executing ExecStart and fails. RuntimeDirectory applies to the main part of the service and systemd expects to be able to create it.

Replacing it with WorkingDirectory=%t/co2mon and ExecStartPost=/bin/rm -rf %t/co2mon (untested) might do what you want.
Comment 2 Fireball 2015-03-16 13:49:41 UTC
No, this does not seem to be the case.
I moved rsync to the main part:

[Unit]
Description=Log Data From CO2Mon
PartOf=co2mon.service

[Service]
User=co2mon
Group=co2mon
RuntimeDirectory=co2mon
RuntimeDirectoryMode=0755
WorkingDirectory=/run/co2mon
StandardOutput=null
ExecStart=/bin/bash -c "/usr/bin/rsync -a /var/lib/co2mon/ /run/co2mon ; ./update_data.sh"
ExecStopPost=-/bin/cp -p /run/co2mon/graph.rrd /var/lib/co2mon/

[Install]
WantedBy=multi-user.target

Check that the directory is not there before start:
# ls -ld /run/co2mon
ls: cannot access /run/co2mon: No such file or directory

Still fails:

# systemctl start co2mon-log
# systemctl status co2mon-log
● co2mon-log.service - Log Data From CO2Mon
   Loaded: loaded (/etc/systemd/system/co2mon-log.service; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since 月 2015-03-16 16:37:49 MSK; 3s ago
  Process: 9069 ExecStopPost=/bin/cp -p /run/co2mon/graph.rrd /var/lib/co2mon/ (code=exited, status=233/RUNTIME_DIRECTORY)
  Process: 9066 ExecStart=/bin/bash -c /usr/bin/rsync -a /var/lib/co2mon/ /run/co2mon ; ./update_data.sh (code=exited, status=233/RUNTIME_DIRECTORY)
 Main PID: 9066 (code=exited, status=233/RUNTIME_DIRECTORY)

 3月 16 16:37:49 melforce systemd[1]: Started Log Data From CO2Mon.
 3月 16 16:37:49 melforce systemd[1]: Starting Log Data From CO2Mon...
 3月 16 16:37:49 melforce systemd[1]: co2mon-log.service: main process exited, code=exited, status=233/RUNTIME_DIRECTORY
 3月 16 16:37:49 melforce systemd[1]: Unit co2mon-log.service entered failed state.
 3月 16 16:37:49 melforce systemd[1]: co2mon-log.service failed.

The other strange thing is that "cp" which is in ExecStopPost= (not the main part) also fails on runtime directory step and we see systemd's exit status 223, not cp's itself. cp is prefixed with minus sign. It can't fail. Doesn't this contradict what you said?
Comment 3 Fireball 2015-03-16 13:54:13 UTC
Oops, sorry, I was wrong, rsync has insufficient permissions.
Comment 4 Fireball 2015-03-16 13:59:06 UTC
Still, this behaviour is not documented.
man page says runtime directory is created when units starts and removed when it stops without the details.
Comment 5 Zbigniew Jedrzejewski-Szmek 2015-03-16 15:38:17 UTC
You're right, the directory is created before ExecStartPre commands are run.
I'll update the documentation to be more explicit.

Returning to your original unit: looking at the code, the failure is most likely caused by the permissions on the directory being too broad. What is the mode of of /var/lib/co2mon?
Comment 6 Fireball 2015-03-16 17:16:34 UTC
That wat right. 

drwxrwxr-x 1 root co2mon 132  3月 16 19:34 /var/lib/co2mon

Changing RuntimeDirectoryMode to 0775 fixed the error.

So I guess systemd's error message is not specific enough...
Comment 7 Zbigniew Jedrzejewski-Szmek 2018-06-11 14:42:30 UTC
Fixed in https://github.com/systemd/systemd/commit/37c1d5e97d.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.