Skip to content
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

Improvements for notify services (including #4212) #4745

Merged
merged 5 commits into from Nov 30, 2016

Conversation

joukewitteveen
Copy link
Contributor

Three improvements for services of type notify.

  1. A more correct condition of failure when the main process exits: only in the SERVICE_START state have we not received a ready notification.
  2. Disallow control processes from registering as the main process through a MAINPID= notification. The conditional on the process state in src/core/service.c:service_sigchld_event assumes a process is the main process or the control process, but not both.
  3. Introduce NotifyAccess=exec as a solution to Set $NOTIFY_SOCKET for ExecStop= processes, and process notify messages from them #4212. From a source code perspective, the NotifyAccess=control would be better, but this would be very confusing given all the contexts in which the word 'control' occurs in systemd. The current choice is based on the fact that it allows notifications from processes started from tall he Exec*= commands ({Start,Stop}{Pre,,Post}, Reload).

@evverx
Copy link
Member

evverx commented Nov 28, 2016

@joukewitteveen , I'd like to postpone this PR.
#4259 introduced the regression: #4752
I think we should fix #4752 first

@joukewitteveen
Copy link
Contributor Author

I'll take a look at #4752 later this week when I have time, but skimming the report I noticed the phrase 'race condition'. The second commit of this PR (only fail [...] during start) might solve this problem.

Also: failing exit.service with a protocol error is correct, since the READY=1 message never makes it.

@evverx
Copy link
Member

evverx commented Nov 28, 2016

I'll take a look at #4752 later this week when I have time

Sure

Also: failing exit.service with a protocol error is correct, since the READY=1 message never makes it

Hm, not sure I understand

[Service]
Type=notify
NotifyAccess=all
# ExecStart=/bin/sh -x -c 'systemd-notify --ready <- FAILS
ExecStart=/bin/sh -x -c 'systemd-notify --ready; sleep 100'

doesn't fail. Is it correct?
Anyway, let's move this discussion to the #4752. Thanks!

@arvidjaar
Copy link
Contributor

@evverx

Is it correct?

I'd say yes - in the first case you have race condition between main process termination and receiving of READY=1. Exiting of main PID before receiving READY=1 is treated as failure to start service.

@evverx
Copy link
Member

evverx commented Nov 28, 2016

in the first case you have race condition between main process termination and receiving of READY=1

I don't have race condition: sd_notify is not async. But, yes, systemd has a race condition.

@evverx
Copy link
Member

evverx commented Nov 28, 2016

Hm,

init.scope: Got notification message "READY=1", ignoring.

And

[Service]
Type=notify
NotifyAccess=all
ExecStart=/bin/sh -x -c 'systemd-notify --ready --pid=$$$$'

works fine.
This looks like a bash "tail" optimization.

But fails sometimes of course (if User != 0)

Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Trying to enqueue job exit.service/start/replace
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Installed new job exit.service/start as 958
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Enqueued job exit.service/start as 958
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Failed to reset devices.list: No such file or directory
Nov 28 09:38:29 systemd-testsuite sh[174]: + systemd-notify --ready --pid=174
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Failed to set pids.max: No such file or directory
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Passing 0 fds to service
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: About to execute: /bin/sh -x -c 'systemd-notify --ready --pid=$$$$'
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Forked /bin/sh as 174
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Changed dead -> start
Nov 28 09:38:29 systemd-testsuite systemd[1]: Starting exit.service...
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: User lookup succeeded: uid=1001 gid=1001
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Child 174 belongs to exit.service
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Main process exited, code=exited, status=0/SUCCESS
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Changed start -> failed
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Job exit.service/start finished, result=failed
Nov 28 09:38:29 systemd-testsuite systemd[1]: Failed to start exit.service.
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Unit entered failed state.
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: Failed with result 'protocol'.
Nov 28 09:38:29 systemd-testsuite systemd[1]: exit.service: cgroup is empty
Nov 28 09:38:53 systemd-testsuite systemd[1]: exit.service: Changed dead -> failed

@joukewitteveen
Copy link
Contributor Author

Added a section to NEWS.
CI appears unrelated.

@martinpitt
Copy link
Contributor

I restarted the semaphore run

Copy link
Member

@poettering poettering left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks pretty good, just some minor changes!

if (s->type == SERVICE_NOTIFY)
/* No chance of getting a ready notification anymore */
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_PROTOCOL);
else if (s->pid_file_pathspec) {
else /* Fall through */
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

uh, dropping into the next case as "else" statement looks strange. Quite franky, I am surprised this works at all...

Can you rewrite this and make the first if branch end in a "break", so that we don't need the "else" here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No problem.
Do we want this change at all? It is clear that the test should apply only to SERVICE_START, yet as far as I can tell it is impossible for Type=notify services to end up here while in a SERVICE_START_POST state. The main reason for this change is, I think, that it is more 'correct'.

@@ -1252,7 +1252,8 @@ static int service_spawn(
if (!our_env)
return -ENOMEM;

if ((flags & EXEC_IS_CONTROL) ? s->notify_access == NOTIFY_ALL : s->notify_access != NOTIFY_NONE)
if ((flags & EXEC_IS_CONTROL) ? IN_SET(s->notify_access, NOTIFY_ALL, NOTIFY_EXEC)
: s->notify_access != NOTIFY_NONE)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i figure this check got complex enough to deserve its function. service_exec_needs_notify_sockets(Service *s, flags) or so, with some explanatory comments owuld be great!

pid, s->main_pid, s->control_pid);
else if (s->main_pid != 0 || s->control_pid != 0)
log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception only permitted for %s PID "PID_FMT,
pid, s->main_pid ? "main" : "control", s->main_pid | s->control_pid);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That binary OR here is evil as fuck! ;-)

I think this would be better with a ternary operator, after all you generate the "main" and "control" string already that way...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I assume s->main_pid ?: s->control_pid (?: is a GCC extension) is out of the question?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we use ?: pretty frequently... but in this case I'd actually avoid it, as we try to get people to do numeric != 0 checks by spelling out != 0, instead of relying on C's degrade-to-bool feature (we use that only for ptr and bool-like objects, but not for numeric variables)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, but then the ternary operator for "main" vs. "control" has to be changed too and the part becomes
s->main_pid != 0 ? "main" : "control", s->main_pid != 0 ? s->main_pid : s->control_pid
This almost warrants a separate if block.

The alternative
s->main_pid ? "main" : "control", s->main_pid ?: s->control_pid
looks pretty neat if you ask me.

In the end I can see the appeal in either. Shall I add a clause to the if block?

                if (s->main_pid != 0 && s->control_pid != 0)
                        log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception only permitted for main PID "PID_FMT" and control PID "PID_FMT,
                                         pid, s->main_pid, s->control_pid);
                else if (s->main_pid != 0)
                        log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception only permitted for main PID "PID_FMT, pid, s->main_pid);
                else if (s->control_pid != 0)
                        log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception only permitted for control PID "PID_FMT, pid, s->control_pid);
                else
                        log_unit_debug(u, "Got notification message from PID "PID_FMT", but reception only permitted for main PID and control PID which are currently not known", pid);
                return;

P.S. Do we really want the last case to be a debug message?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah, the version with 4 branches indeed looks nicer. I think making all of them warnings would make sense.

@@ -17,6 +17,9 @@ CHANGES WITH 233 in spe
The 'n' choice for the confirmation spawn prompt has been removed,
because its meaning was confusing.

* Services of type notify require a READY=1 notification to be sent
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please write that as "Services of Type=notify require…"...

@@ -17,6 +17,9 @@ CHANGES WITH 233 in spe
The 'n' choice for the confirmation spawn prompt has been removed,
because its meaning was confusing.

* Services of type notify require a READY=1 notification to be sent
during startup. If no such message is sent, the service now fails.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe also say: "…, even if the process exited with a zero exit code." or so?

@poettering poettering added pid1 reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks labels Nov 28, 2016
@evverx
Copy link
Member

evverx commented Nov 28, 2016

systemctl doesn't print the explanation:

-bash-4.3# systemctl cat a --no-pager
# /etc/systemd/system/a.service
[Service]
Type=notify
ExecStart=/bin/sh -x -c 'exit 0'

-bash-4.3# systemctl start a
Job for a.service failed.
See "systemctl status a.service" and "journalctl -xe" for details.

Shouldn't we update the explanations-table?

-bash-4.3# systemctl cat b --no-pager
# /etc/systemd/system/b.service
[Service]
Type=notify
ExecStart=/bin/sh -x -c 'exit 1'

-bash-4.3# systemctl start b
Job for b.service failed because the control process exited with error code.
See "systemctl status b.service" and "journalctl -xe" for details.

Why not the protocol-error? "a service did not take the steps required by its configuration"

@evverx
Copy link
Member

evverx commented Nov 28, 2016

Why not the protocol-error? "a service did not take the steps required by its configuration"

That's matter for Restart=on-abnormal
BTW: https://www.freedesktop.org/software/systemd/man/systemd.service.html#Restart= says nothing about protocol

@joukewitteveen
Copy link
Contributor Author

joukewitteveen commented Nov 28, 2016

I need some help with this one.

For the explanations table I am not sure what the right values are. We only raise the error type through service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_PROTOCOL);.

For the Restart= part I am not even sure what we want and if it is only documentation that has to be updated.

BTW: Documentation of error types is quite scattered. I am sorry for not covering it all in the commit that introduced the new error type. There is also another table under https://www.freedesktop.org/software/systemd/man/systemd.exec#$EXIT_CODE ...

Edit: In the above message, I mixed up the explanations table and the Summary of possible service result variable values table in the systemd.service manpage. The explanations table is easy to fix. Time for some sleep.

@evverx
Copy link
Member

evverx commented Nov 28, 2016

For the Restart= part I am not even sure what we want and if it is only documentation that has to be updated

@joukewitteveen , that's a good point. But I think Restart=on-protocol is the overkill

Also, I think we should return the first meaningful error: signal, exit-code, ..., protocol, resources. So, actually, the current behaviour looks good to me. Sorry for the noise.

@martinpitt
Copy link
Contributor

CI failure is issue #4753 again and unrelated. As this is "changes requested" anyway, there is going to be a new run anyway, so not restarting. @joukewitteveen, it would be great if you could rebase against master so that we get some useful debugging out of that failure. Thanks!

We stay in the SERVICE_START while no READY=1 notification message has
been received. When we are in the SERVICE_START_POST state, we have
already received a ready notification. Hence we should not fail when the
cgroup becomes empty in that state.
We assume a process can be only one of the two in service_sigchld_event.
@joukewitteveen
Copy link
Contributor Author

Processed the requested changes and added an entry to the explanation table.

Copy link
Member

@poettering poettering left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

looks great, one minor string issue

@@ -764,6 +764,7 @@ static const struct {
const char *result, *explanation;
} explanations [] = {
{ "resources", "of unavailable resources or another system error" },
{ "protocol", "the service did not take the steps required by its configuration" },
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hmm "configuration" might be misleading. most people would probably look into the daemon's own configuratoin when debugging this when they read this. Maybe simply add in a "unit" there, so that it becomes "… required by its unit configuration"...

@poettering
Copy link
Member

so the Restart= table in the docs is incomplete currently. I am not entirely sure it needs to list all result codes however (but if somebody preps a patch I'd happily merge it!), hence I think your PR is actually good as it is right now in this regard.

The restart code should require no updates for the new result code, the existing restart modes should cover this well enough already.

Hence, please do the minor string fix, then it's good to merge. And if you want to update the restart docs, that'd be welcome too, but I think not necessary.

@joukewitteveen
Copy link
Contributor Author

Cool! Updated.
Thanks for all the reviewing.

@evverx
Copy link
Member

evverx commented Nov 29, 2016

so the Restart= table in the docs is incomplete currently. I am not entirely sure it needs to list all result codes however

What about https://www.freedesktop.org/software/systemd/man/systemd.exec#$EXIT_CODE ?

hmm "configuration" might be misleading. most people would probably look into the daemon's own configuratoin when debugging this when they read this. Maybe simply add in a "unit" there, so that it becomes "… required by its unit configuration"...

What about https://github.com/systemd/systemd/pull/4724/files ?

if a service did not take the steps required by its configuration

@poettering
Copy link
Member

What about https://www.freedesktop.org/software/systemd/man/systemd.exec#$EXIT_CODE ?

True, that table should indeed be updated. @joukewitteveen can you add that please? (and I figure a quick comment next to the enum referencing that man page and suggesting to update it when when adding a new enum might be great)

@poettering
Copy link
Member

What about https://github.com/systemd/systemd/pull/4724/files ?

Yupp, that should be updated to match the message string. @joukewitteveen can you fix that too, please?

@joukewitteveen
Copy link
Contributor Author

What would the values be for the https://www.freedesktop.org/software/systemd/man/systemd.exec#$EXIT_CODE table?

@poettering
Copy link
Member

@joukewitteveen well, for "protocol" the exit status would be clean, right, hence $EXIT_STATUS would be "exited", and $EXIT_STATUS would be "0", in the typical case, right?

@joukewitteveen
Copy link
Contributor Author

That also depends on what future uses of the error there may be. It is currently used for Type=notify services that never send READY=1 and for services that promise to write a pid file but don't.

@evverx
Copy link
Member

evverx commented Nov 29, 2016

Hm, we don't trigger the ExecStopPost=. So, I have no idea how to extract $SERVICE_RESULT == protocol

-bash-4.3# systemctl cat a --no-pager
# /etc/systemd/system/a.service
[Service]
Type=notify
ExecStart=/bin/sh -x -c 'exit 0'
ExecStopPost=/bin/sh -x -c 'set'

-bash-4.3# systemctl start a

...
Nov 28 20:58:03 sh[48]: + exit 0
Nov 28 20:58:03 systemd[1]: a.service: Child 48 belongs to a.service
Nov 28 20:58:03 systemd[1]: a.service: Main process exited, code=exited, status=0/SUCCESS
Nov 28 20:58:03 systemd[1]: a.service: Changed start -> failed
Nov 28 20:58:03 systemd[1]: a.service: Job a.service/start finished, result=failed
Nov 28 20:58:03 systemd[1]: Failed to start a.service.
Nov 28 20:58:03 systemd[1]: a.service: Unit entered failed state.
Nov 28 20:58:03 systemd[1]: a.service: Failed with result 'protocol'.
Nov 28 20:58:03 systemd[1]: a.service: cgroup is empty

@poettering
Copy link
Member

@joukewitteveen well, there's always he option to chicken out and just say "any of the above" in the table, like the "resources" line already does... ;-)

@joukewitteveen
Copy link
Contributor Author

@evverx We do here and here.
@poettering that would hardly be better than not documenting it. I would like to get this right. Is it true that we only anticipate to use FAILURE_PROTOCOL when no other error occurred, yet we are not in a good state to continue? In that case we are probably safe to write down "exited" and "0".

@poettering
Copy link
Member

@joukewitteveen will, the table isn't totally honest anyway, as you can fiddle with the clean exit statuses anyway with SuccessExitStatus=, and if you do, the table isn't entirely right anyway. I am not sure that's worth mentioning though...

So, the table at best shows only "typical" results... So adding the line with exited/0 sounds OK to me.

@evverx
Copy link
Member

evverx commented Nov 29, 2016

@evverx We do here and here.

@joukewitteveen , well, I start this unit

[Service]
Type=notify
ExecStart=/bin/sh -x -c 'exit 0'
ExecStopPost=/bin/sh -x -c 'set'

And ExecStopPost is not working. Am I missing something?

@joukewitteveen
Copy link
Contributor Author

@evverx for Type=notify services, we never go through ExecStop{,Post}. For the pid file situation we sometimes do.
@poettering thanks for the heads-up. I'll send an update tonight.

@evverx
Copy link
Member

evverx commented Nov 29, 2016

@evverx for Type=notify services, we never go through ExecStop{,Post}. For the pid file situation we sometimes do.

So

ExecStopPost ... It is recommended to use this setting for clean-up operations that shall be executed even when the service failed to start up correctly.

and

Even though this variable is available in both ExecStop= and ExecStopPost=, it is usually a better choice to place monitoring tools in the latter, as the former is only invoked for services that managed to start up correctly, and the latter covers both services that failed during their start-up and those which failed during their runtime.

doesn't make sense. Right?

@joukewitteveen
Copy link
Contributor Author

Ok, so I only fixed the phrasing in the systemd.exec manpage and did not address the table and failure behavior.

Here is a way to trigger STOP_POST with a protocol error:

[Service]
Type=forking
RemainAfterExit=yes
PIDFile=/var/run/pidfile
ExecStart=/bin/sh -x -c 'sleep 1 &'
ExecStartPost=/bin/sh -x -c 'sleep 2'
ExecStopPost=/bin/sh -x -c 'printenv'

Resulting in

Starting minimal unit...
+ sleep 1
+ sleep 2
minimal.service: PID file /var/run/pidfile not readable (yet?) after start-post: No such file or directory
+ printenv
LANG=***
SERVICE_RESULT=protocol
MANAGERPID=***
DISPLAY=***
INVOCATION_ID=***
USER=***
PWD=***
HOME=***
JOURNAL_STREAM=***
SHELL=/bin/bash
SHLVL=1
LOGNAME=***
DBUS_SESSION_BUS_ADDRESS=unix:path=***
XDG_RUNTIME_DIR=***
PATH=***
_=/usr/sbin/printenv
Failed to start minimal unit.
minimal.service: Unit entered failed state.
minimal.service: Failed with result 'protocol'.

Note the absence of both EXIT_STATUS and EXIT_CODE.
So we do not go through STOP_POST on service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_PROTOCOL) and for the situations where we do, we do not set the variables we say we will.
Indeed, this is a divergence from the documentation. However, this divergence was not introduced by the addition of the protocol error type and was already present with the resources error type. I think we should merge this PR as it currently is and start a new issue for the discrepancy between the manpage and the actual fail behavior. This new issue should also address the lack of a line for SERVICE_RESULT=protocol in the table at https://www.freedesktop.org/software/systemd/man/systemd.exec#$EXIT_CODE.

@poettering poettering added good-to-merge/waiting-for-ci 👍 PR is good to merge, but CI hasn't passed at time of review. Please merge if you see CI has passed and removed reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks labels Nov 29, 2016
@poettering
Copy link
Member

lgtm!

<option>all</option>. If <option>none</option>, no daemon status
updates are accepted from the service processes, all status
update messages are ignored. If <option>main</option>, only
service updates sent from the main process of the service are
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm, we should fix the main-description too. Actually, root can send "fake"-ucred data, i.e.

User=0
NotifyAccess=main
ExecStart=/bin/sh -x -c 'sleep 2; systemd-notify --ready; sleep 10'

works fine

But this unrelated to this PR, of course

Copy link
Member

@evverx evverx left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@joukewitteveen , thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
good-to-merge/waiting-for-ci 👍 PR is good to merge, but CI hasn't passed at time of review. Please merge if you see CI has passed pid1
Development

Successfully merging this pull request may close these issues.

None yet

5 participants