manager: print status text of the service when waiting for a job

This does two semi-independent but interleaved things: firstly, the manager now prints the status text (if available) of a service when we have a job running for that service and it is slow. Because it's hard to fit enough info on the line, we only do this if the output mode uses unit names. The format of the line "… job is running for …" is changed to be shorter. This way we can somewhat reasonably fit two status messages on one line. Secondly, the manager now sends more information using sd_notify. This mostly matters for in case of the user manager. In particular, we notify when starting one of the special units. Without this, when the system manager would display a line about waiting for the user manager, it would show status like "Ready.", which is confusing. Now it'll either show something like "Started special unit shutdown.target", or the line about waiting for a user job. Also, the timeouts for the user manager are lowered: the user manager usually (always?) has status disabled, so we would wait for 25 seconds before showing job progress. Normally we don't expect to have any jobs that take more than a second. So let's start the progress output fairly quickly, like we would if status showing was enabled. This obviously makes the output in the system manager about the user manager more useful. The timeouts are "desynchronized" by a fraction so if there are multiple jobs running, we'll cycle through showing all combinations. Example output: Stopping user@1000.service... [ OK ] Stopped dracut-shutdown.service. [ OK ] Stopped systemd-logind.service. [ OK ] Stopped systemd-logind.service - User Login Management. [* ] Job user@1000.service/stop running (2s / 2min): (1 of 2) User job slowstop.service/stop running (1s / 1min 30s)... [*** ] Job user@1000.service/stop running (3s / 2min): (2 of 2) User job slowstop2.service/stop running (2s / 1min 30s)... [ ***] Job user@1000.service/stop running (4s / 2min): (1 of 2) User job slowstop.service/stop running (4s / 1min 30s)... [ *] Job user@1000.service/stop running (5s / 2min): (1 of 2) User job slowstop.service/stop running (5s / 1min 30s)... [ ***] Job user@1000.service/stop running (6s / 2min): (2 of 2) User job slowstop2.service/stop running (6s / 1min 30s)... [*** ] Job user@1000.service/stop running (8s / 2min): (1 of 2) User job slowstop.service/stop running (7s / 1min 30s)... [*** ] Job user@1000.service/stop running (10s / 2min): (2 of 2) User job slowstop2.service/stop running (9s / 1min 30s)... [ *** ] Job user@1000.service/stop running (11s / 2min): (1 of 2) User job slowstop.service/stop running (10s / 1min 30s)... [ *] Job user@1000.service/stop running (12s / 2min): (2 of 2) User job slowstop2.service/stop running (12s / 1min 30s)... [ ***] Job user@1000.service/stop running (13s / 2min): (1 of 2) User job slowstop.service/stop running (13s / 1min 30s)... [*** ] Job user@1000.service/stop running (15s / 2min): (2 of 2) User job slowstop2.service/stop running (14s / 1min 30s)... [* ] Job user@1000.service/stop running (15s / 2min): (2 of 2) User job slowstop2.service/stop running (14s / 1min 30s)... [*** ] Job user@1000.service/stop running (16s / 2min): User job slowstop.service/stop running (16s / 1min 30s)... [ ***] Job user@1000.service/stop running (18s / 2min): User job slowstop.service/stop running (17s / 1min 30s)... [ *] Job user@1000.service/stop running (19s / 2min): User job slowstop.service/stop running (18s / 1min 30s)... [ ***] Job user@1000.service/stop running (20s / 2min): User job slowstop.service/stop running (19s / 1min 30s)... [* ] Job user@1000.service/stop running (22s / 2min): User job slowstop.service/stop running (22s / 1min 30s)... [** ] Job user@1000.service/stop running (30s / 2min): User job slowstop.service/stop running (29s / 1min 30s)... [ ***] Job user@1000.service/stop running (32s / 2min): User job slowstop.service/stop running (31s / 1min 30s)... [ *] Job user@1000.service/stop running (33s / 2min): User job slowstop.service/stop running (32s / 1min 30s)... [ ***] Job user@1000.service/stop running (34s / 2min): User job slowstop.service/stop running (33s / 1min 30s)... [** ] Job user@1000.service/stop running (37s / 2min): User job slowstop.service/stop running (36s / 1min 30s)... [ *** ] Job user@1000.service/stop running (41s / 2min): User job slowstop.service/stop running (41s / 1min 30s)... [ OK ] Stopped user@1000.service - User Manager for UID 1000. Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... [ OK ] Unmounted run-user-1000.mount - /run/user/1000. [ OK ] Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. If the output width is lower than approximately 100 columns, the output stops being very useful. No idea what to do about that.
2024-09-16 06:43:18 +00:00 · 2021-07-02 18:28:11 +02:00 · 2021-07-02 18:28:11 +02:00 · 3889fc6fc3
parent 6d93265955
commit 3889fc6fc3
1 changed files with 52 additions and 13 deletions
--- a/src/core/manager.c
+++ b/src/core/manager.c
@ -117,9 +117,19 @@ static int manager_run_generators(Manager *m);
 static void manager_vacuum(Manager *m);

 static usec_t manager_watch_jobs_next_time(Manager *m) {
-        return usec_add(now(CLOCK_MONOTONIC),
-                        show_status_on(m->show_status) ? JOBS_IN_PROGRESS_WAIT_USEC :
-                                                         JOBS_IN_PROGRESS_QUIET_WAIT_USEC);
+        usec_t timeout;
+
+        if (MANAGER_IS_USER(m))
+                /* Let the user manager without a timeout show status quickly, so the system manager can make
+                 * use of it, if it wants to. */
+                timeout = JOBS_IN_PROGRESS_WAIT_USEC * 2 / 3;
+        else if (show_status_on(m->show_status))
+                /* When status is on, just use the usual timeout. */
+                timeout = JOBS_IN_PROGRESS_WAIT_USEC;
+        else
+                timeout = JOBS_IN_PROGRESS_QUIET_WAIT_USEC;
+
+        return usec_add(now(CLOCK_MONOTONIC), timeout);
 }

 static void manager_watch_jobs_in_progress(Manager *m) {
@ -199,7 +209,6 @@ static void manager_flip_auto_status(Manager *m, bool enable, const char *reason
 }

 static void manager_print_jobs_in_progress(Manager *m) {
-        _cleanup_free_ char *job_of_n = NULL;
        Job *j;
        unsigned counter = 0, print_nr;
        char cylon[6 + CYLON_BUFFER_EXTRA + 1];
@ -229,25 +238,51 @@ static void manager_print_jobs_in_progress(Manager *m) {

        m->jobs_in_progress_iteration++;

+        char job_of_n[STRLEN("( of ) ") + DECIMAL_STR_MAX(unsigned)*2] = "";
        if (m->n_running_jobs > 1)
-                (void) asprintf(&job_of_n, "(%u of %u) ", counter, m->n_running_jobs);
+                xsprintf(job_of_n, "(%u of %u) ", counter, m->n_running_jobs);

        bool have_timeout = job_get_timeout(j, &x) > 0;

        /* We want to use enough information for the user to identify previous lines talking about the same
         * unit, but keep the message as short as possible. So if 'Starting foo.service' or 'Starting
-         * foo.service (Description)' were used, 'foo.service' is enough here. On the other hand, if we used
+         * foo.service - Description' were used, 'foo.service' is enough here. On the other hand, if we used
         * 'Starting Description' before, then we shall also use 'Description' here. So we pass NULL as the
         * second argument to unit_status_string(). */
        const char *ident = unit_status_string(j->unit, NULL);

-        manager_status_printf(m, STATUS_TYPE_EPHEMERAL, cylon,
-                              "%sA %s job is running for %s (%s / %s)",
-                              strempty(job_of_n),
-                              job_type_to_string(j->type),
-                              ident,
-                              FORMAT_TIMESPAN(now(CLOCK_MONOTONIC) - j->begin_usec, 1*USEC_PER_SEC),
-                              have_timeout ? FORMAT_TIMESPAN(x - j->begin_usec, 1*USEC_PER_SEC) : "no limit");
+        const char *time = FORMAT_TIMESPAN(now(CLOCK_MONOTONIC) - j->begin_usec, 1*USEC_PER_SEC);
+        const char *limit = have_timeout ? FORMAT_TIMESPAN(x - j->begin_usec, 1*USEC_PER_SEC) : "no limit";
+
+        if (m->status_unit_format == STATUS_UNIT_FORMAT_DESCRIPTION)
+                /* When using 'Description', we effectively don't have enough space to show the nested status
+                 * without ellipsization, so let's not even try. */
+                manager_status_printf(m, STATUS_TYPE_EPHEMERAL, cylon,
+                                      "%sA %s job is running for %s (%s / %s)",
+                                      job_of_n,
+                                      job_type_to_string(j->type),
+                                      ident,
+                                      time, limit);
+        else {
+                const char *status_text = unit_status_text(j->unit);
+
+                manager_status_printf(m, STATUS_TYPE_EPHEMERAL, cylon,
+                                      "%sJob %s/%s running (%s / %s)%s%s",
+                                      job_of_n,
+                                      ident,
+                                      job_type_to_string(j->type),
+                                      time, limit,
+                                      status_text ? ": " : "",
+                                      strempty(status_text));
+        }
+
+        sd_notifyf(false,
+                   "STATUS=%sUser job %s/%s running (%s / %s)...",
+                   job_of_n,
+                   ident,
+                   job_type_to_string(j->type),
+                   time, limit);
+        m->status_ready = false;
 }

 static int have_ask_password(void) {
@ -2621,6 +2656,10 @@ static void manager_start_special(Manager *m, const char *name, JobMode mode) {
        const char *s = unit_status_string(job->unit, NULL);

        log_info("Activating special unit %s...", s);
+
+        sd_notifyf(false,
+                   "STATUS=Activating special unit %s...", s);
+        m->status_ready = false;
 }

 static void manager_handle_ctrl_alt_del(Manager *m) {