Use dbus to tell when systemd has completed an action for us #3805
Conversation
| */ | ||
| pcmk__set_result(&(cmd->result), PCMK_OCF_UNKNOWN_ERROR, | ||
| PCMK_EXEC_ERROR, NULL); | ||
| } |
There was a problem hiding this comment.
Note the FIXME here. There's several other possibilities systemd could give us - canceled, failed, dependency, and skipped are all documented. These could be broken out into separate errors.
| if (!pcmk__str_eq(op->action, PCMK_ACTION_START, pcmk__str_casei)) { | ||
| services__finalize_async_op(op); | ||
| } | ||
|
|
There was a problem hiding this comment.
I hate this because it moves a critical part of handling a resource out of the library and into the callers (see handle_systemd_job_complete). But, it's necessary to not call services__finalize_async_op right here because that function will remove the operation from the list of inflight ops and then free it, and it's called before handle_systemd_job_complete so we'll have no op to handle anymore.
There was a problem hiding this comment.
I'll give this some more thought tomorrow night. I'm thinking perhaps we can design the callback differently, but I haven't thought through the specifics. Something involving one of the following:
- One message filter per unit that we care about, instead of a global message filter. We can use the
user_datafield where we're currently passingNULL, to give a unit name. D-Bus runs all message filters until it gets aDBUS_HANDLER_RESULT_HANDLEDcode. We can remove a unit's handler when we're done with it. - Similar, but by using a hash table or list more cleverly within the services library.
There was a problem hiding this comment.
I haven't really gotten back to this yet.
Even if we keep this basic setup, we should finalize the action if there is no callback registered.
There was a problem hiding this comment.
What do you think of this? Disclaimer: I'm pretty exhausted while writing it. Forgive me if there is an egregious oversight.
- Have
filter_systemd_signals()take asvc_action_tasuser_data. - DON'T add the filter in
subscribe_to_signals(). - DO add the filter within
invoke_unit_by_path(), right before or right afterservices_set_op_pending(), passingopasuser_data:dbus_connection_add_filter(systemd_proxy, filter_systemd_signals, op, NULL). - DON'T call
services__finalize_async_op()withinhandle_systemd_job_complete(). - In
filter_systemd_signals(), if we make it to the end, calldbus_connection_remove_filter(systemd_proxy, filter_systemd_signals, user_data). This removes the filter for the given action. This should happen AFTER callingsystemd_callback(). - Either call
services__finalize_async_op(user_data)immediately after callingdbus_connection_remove_filter(). Or alternatively, passservices__finalize_async_opas thefree_data_functionargument (4th argument position) when adding the filter.
Other implications:
- No need for
services__systemd_get_inflight_op(). Instead, pass the op directly tosystemd_callback()asuser_data, and havehandle_systemd_job_complete()use it as-is. Or alternatively, passop->cb_dataasuser_data, since that's the only part thathandle_systemd_job_complete()cares about. - No need to expose
services__finalize_async_op(). - No need to pass
unit_nametosystemd_callback().
There may be still others, but at some point I think we do have to have a callback function within the executor, because there are lrmd* objects involved (like cmd).
This approach assumes that we end up receiving a JobRemoved signal for each op, so that we remove the filter that we added for that op. Otherwise, the list of filters would accumulate in the D-Bus connection object. I think we can (and in fact, we have to) assume that we'll get a JobRemoved signal for each unit start/stop that we call.
| crm_trace("Checking DBus message %s.%s() on %s", | ||
| dbus_message_get_interface(message), | ||
| dbus_message_get_member(message), | ||
| dbus_message_get_path(message)); |
There was a problem hiding this comment.
I might remove this message - it's kind of a lot, even at trace level, since it will be triggered for every single thing systemd ever does after pacemaker has started.
There was a problem hiding this comment.
If it catches even things unrelated to the systemd units that we're managing as resources, then that would be a lot. One could argue that all information is good information, since tracing has to be enabled at a fairly granular level... but I'd vote against this.
It looks like signal messages get broadcast, so this is probably at least getting all signals.
That might not be a huge deal, depending on what all events generate a signal... if there are no recurring events happening within systemd, then it might be fine.
We had a mechanism for ridiculously granular XML logging for a while, separate from tracing (I think it had to be enabled at build time). We dropped that probably last year.
There was a problem hiding this comment.
What makes it a lot is that it's before the filter (dbus_message_is_signal), so it's everything that systemd ever does, regardless of whether we care about it or not. It's a ton of UnitNew() and UnitRemoved() messages, at least. I'm not sure we care about the unfiltered firehose. Here's what happens if you just start up the cluster:
[root@rhel9-scratch-1 ~]# grep "Checking DBus" /var/log/pacemaker/pacemaker.log | wc -l
1459
|
@HideoYamauchi As part of this PR, I was hoping to get rid of all the polling code in |
|
The monitor-related portion is starting to take on a life of its own, so I think what we should do is get this PR in first (it's big enough already), and then after that I can work on getting the monitor portion done separately. That way, if that part doesn't work out, I think we've still addressed the actual bug here. |
We will check and get back to you. Best Regards, I haven't checked the details of running it on Probe. Does this answer answer your question? Best Regards, |
|
The builds failed on BSD due to: It's guarded by |
Most importantly, replace a tab with spaces so the else blocks line up.
If you scroll up far enough, you'll see that the #endif closes out the same #ifdef that is immediately used again.
First, invert the test to see if this is a systemd resource. If it's not, there's no way goagain was set so we can just bail out to the end of the function. Then having done that, everything that was in the block can be unindented. No other code changes.
If goagain is not set, just bail to the end of the function. Having done that, everything that was in the previous block can be unindented. I think this is a little more legible. No other code changes.
Internally, pacemaker uses a shorter resource-based name when referring to systemd actions. However, systemd itself wants a real unit name so we append ".service" or whatever to the name at exec time. Because we do this at the last minute and don't save it anywhere, there's no way to figure out what action a systemd unit is associated with later. So, add that to the opaque data. This also requires an accessor function since the opaque data is supposed to be private.
At the moment, all this does is log a trace message for all recieved signals. We'll add some filtering on this later.
These are the ones that allow us to know whether a service has finished or not. In the future, we could perhaps open this filter up to other systemd signals if there's a need to do so.
This will get called when we receive a systemd message from dbus and it makes it through the filter in filter_systemd_signals. At the moment, this is only the JobRemoved signal which can be used to determine if a start action we initiated has started. This could be expanded to other signals in the future, if that would be useful.
We'll be handling this through talking to systemd over dbus. systemd has its own concept of timeouts, so we don't need to add an additional timer on top of that.
The action_complete function is called when a systemd action finishes. Unfortunately, StartUnit actions finish and return a value immediately, not when the unit we asked it to start is actually up and running. For this reason, action_complete handles start actions by then scheduling a follow-up monitor action to poll the service and see if it's actually up and running yet. It then takes the appropriate action when this happens. Since we're moving towards waiting for systemd to tells us a service is running, we don't need to do any of this anymore. However, stop actions and monitors still need this code. For the moment, it's easiest to just bail out for start actions.
An inflight operation is one that is currently being executed - either by us (in the case of something that we forked and execed), or systemd (in the case of something we told it to start up). Here, we add a function that just get a systemd inflight op that matches a given unit name.
Instead of being private to libcrmservices, this should now just be an internal-only use function. We'll need to do this to call it from elsewhere.
The executor just has to register a callback that gets called when JobRemoved signals are received from systemd. This callback then takes the data it's given and finds a matching svc_action_t. If there's a match, it can then finalize the action and remove it from the table of actions we're watching for. At the moment this only handles start actions, which is not sufficient to close T25, but it's a good start and should be easy enough to build on to handle stop actions and perhaps also monitors. Related T25
This is just like starting resources, but a lot easier because there's almost no extra code. Related T25
The comment should explain this pretty well. What was happening was that an executor regression test was failing because the operation never gets finalized. Essentially, services__finalize_async_op never gets called for a unit that doesn't exist. We typically want this to happen as part of the systemd callback that's registered in the executor, but this callback will never get called in this case because there's no systemd message that will make it through our filter and trigger the callback. JobRemoved won't get sent because there's no job to remove. It seems like we could look for a failure from LoadUnit for units that don't exist, but pacemaker always writes an override unit file which means the unit will always exist.
Thanks, I was just sitting down to sort these build errors out. Fixed. |
@HideoYamauchi Thanks for getting back to me. I'm going to address the monitor/probe stuff in a separate PR. I'll read through that thread in preparation for working on the monitor PR and let you know. This PR shouldn't have any effects for monitors or probes (aside from the follow-up monitors we were spawning for start/stop actions - those will be removed, but I don't think that will affect anyone). |
Okay! Many thanks, |
daemons/execd/execd_commands.c
Outdated
| @@ -917,8 +917,8 @@ action_complete(svc_action_t * action) | |||
| } | |||
| } | |||
| } | |||
| } else if (pcmk__str_any_of(cmd->action, PCMK_ACTION_MONITOR, PCMK_ACTION_STATUS, NULL) && | |||
| (cmd->interval_ms > 0)) { | |||
| } else if (pcmk__str_any_of(cmd->action, PCMK_ACTION_MONITOR, PCMK_ACTION_STATUS, NULL) && | |||
There was a problem hiding this comment.
While we're here, we prefer to have && at the beginning of the next line instead of the end of the line.
| free(name); | ||
|
|
||
| if (op != NULL) { | ||
| op->opaque->unit_name = name; |
There was a problem hiding this comment.
I think this function can only be called once for a given op, but for future-proofing we could be paranoid and free op->opaque->unit_name first.
lib/services/systemd.c
Outdated
| @@ -1222,8 +1222,11 @@ services__execute_systemd(svc_action_t *op) | |||
| "Bug in service library"); | |||
|
|
|||
| if (invoke_unit_by_name(op->agent, op, NULL) == pcmk_rc_ok) { | |||
| op->opaque->timerid = pcmk__create_timer(op->timeout + 5000, | |||
| systemd_timeout_callback, op); | |||
| if (!pcmk__str_eq(op->action, PCMK_ACTION_START, pcmk__str_casei)) { | |||
There was a problem hiding this comment.
As much as I like small, atomic commits, I'd rather see this merged into the "Use dbus to detect systemd resource startup". It's not atomic (it belongs with the other changes), and it's small enough that it doesn't need its own commit to avoid confusion. For me it initially caused confusion haha.
systemd has its own concept of timeouts, so we don't need to add an additional timer on top of that.
Can you elaborate on this? I'm having difficulty tracing where else we use op->timeout in a way that it gets actually passed to systemd. I see it getting used for other Pacemaker timers and for dbus calls. Neither of those (in the places that I've checked) are actually sending the timeout to systemd. Rather, they're used internally within Pacemaker and the dbus library.
The code is hard to trace and I could be missing something. However, I want to feel confident that we're not going to lose a start or stop operation timeout that the user has configured.
There was a problem hiding this comment.
Looking again at the systemd D-Bus doc, it does look like the job timeout would be determined by the unit configuration, with a global default. I don't see where they even expose a way to set the timeout per-job. Which would be required in order to use our user-configured resource action timeout.
I'll wait to hear what you have to say. This timer still may or may not be necessary. We do use op->timeout in a few other places for internal and D-Bus timers (but not as data passed to systemd).
There was a problem hiding this comment.
Looking over this again, I think I assumed we were doing something that we were not. In systemd.c, you'll notice that we create override unit files for any service that pacemaker manages (just search for override). As I was skimming through the code, I saw that timeouts were mentioned where SYSTEMD_OVERRIDE_TEMPLATE is defined. However, now that I look again, I see that it was mentioned in the context of a TODO.
So I guess what I want to do is either (1) reinstate the timeouts and make them work, or (2) take care of the TODO and hopefully remove more timeout-related code. There's... a lot of it.
There was a problem hiding this comment.
If you feel the need or inclination to do anything too complex, it might be worth doing another PR first. This one already has a lot going on (even though there isn't that much code), and I'm not even quite finished reviewing it.
That TODO should probably mention stop timeouts too.
I haven't looked at the monitor code, but the way you've described us using a poll to hack the monitor operation probably renders any timeout in the unit configuration irrelevant.
There was a problem hiding this comment.
hopefully remove more timeout-related code
Yeah... obviously be careful. Some of it is timeouts for more generic things like D-Bus operations. Our current use of the op->timeout in some of those places may be incorrect or arbitrary in the first place. Really, the op->timeout should start counting down when the operation begins. But IIRC we're using the same timeout value for multiple steps along the way (without subtracting anything, which might be painful to do) -- and then the timeout + 5000 for the timer to check whether the "real" part of the start/stop action timed out.
We might be using it for things like reloading systemd, loading the unit, waiting for a response to enqueuing the start job, etc. (I'm going from memory here.) If we add the configured timeout to a unit override, then the full configured timeout will be available to systemd for the meat of the operation, in addition to using the timeout for all the setup/bookkeeping steps.
It's complicated (again, obviously) and we may have to settle for "good enough."
There was a problem hiding this comment.
it might be worth doing another PR first
I see #3816
| if (!pcmk__str_eq(op->action, PCMK_ACTION_START, pcmk__str_casei)) { | ||
| services__finalize_async_op(op); | ||
| } | ||
|
|
There was a problem hiding this comment.
I'll give this some more thought tomorrow night. I'm thinking perhaps we can design the callback differently, but I haven't thought through the specifics. Something involving one of the following:
- One message filter per unit that we care about, instead of a global message filter. We can use the
user_datafield where we're currently passingNULL, to give a unit name. D-Bus runs all message filters until it gets aDBUS_HANDLER_RESULT_HANDLEDcode. We can remove a unit's handler when we're done with it. - Similar, but by using a hash table or list more cleverly within the services library.
| // Determine result and finalize action | ||
| /* Determine result and finalize action. | ||
| * | ||
| * Start and stop actions must be finalized by the registerd systemd callback |
At the moment, this just handles start and stop actions. I still need to deal with monitors before I can remove a bunch of code and consider the upstream issue closed. But I expect the code to handle monitors to look very similar to what's already here, so people might as well take a look.