From 7bc07eb6c9a31f2c26d0fe3e6d7a26a13cbb2369 Mon Sep 17 00:00:00 2001

From: Michal Schmidt <mschmidt@redhat.com>

Date: Thu, 16 Jul 2015 20:08:30 +0200

Subject: [PATCH] core: fix confusing logging of instantaneous jobs

For instantaneous jobs (e.g. starting of targets, sockets, slices, or

Type=simple services) the log shows the job completion

before starting:

        systemd[1]: Created slice -.slice.

        systemd[1]: Starting -.slice.

        systemd[1]: Created slice System Slice.

        systemd[1]: Starting System Slice.

        systemd[1]: Listening on Journal Audit Socket.

        systemd[1]: Starting Journal Audit Socket.

        systemd[1]: Reached target Timers.

        systemd[1]: Starting Timers.

        ...

The reason is that the job completes before the ->start() method returns

and only then does unit_start() print the "Starting ..." message.

The same thing happens when stopping units.

Rather than fixing the order of the messages, let's just not emit the

Starting/Stopping message at all when the job completes instantaneously.

The job completion message is sufficient in this case.

(cherry picked from commit d1a34ae9c20f1c02aab17884919eccef572b1d21)

Resolves: #1506256

---

 src/core/job.c  | 65 +++++++++++++++++++++++++++++++++++++++------------------

 src/core/unit.c | 36 +++++++++++---------------------

 src/core/unit.h |  1 +

 3 files changed, 58 insertions(+), 44 deletions(-)

diff --git a/src/core/job.c b/src/core/job.c

index c9a43a4cb..612caa604 100644

--- a/src/core/job.c

+++ b/src/core/job.c

@@ -504,10 +504,48 @@ static void job_change_type(Job *j, JobType newtype) {

         j->type = newtype;

 }

+static int job_perform_on_unit(Job **j) {

+        /* While we execute this operation the job might go away (for

+         * example: because it finishes immediately or is replaced by a new,

+         * conflicting job.) To make sure we don't access a freed job later on

+         * we store the id here, so that we can verify the job is still

+         * valid. */

+        Manager *m  = (*j)->manager;

+        Unit *u     = (*j)->unit;

+        JobType t   = (*j)->type;

+        uint32_t id = (*j)->id;

+        int r;

+

+        switch (t) {

+                case JOB_START:

+                        r = unit_start(u);

+                        break;

+

+                case JOB_RESTART:

+                        t = JOB_STOP;

+                case JOB_STOP:

+                        r = unit_stop(u);

+                        break;

+

+                case JOB_RELOAD:

+                        r = unit_reload(u);

+                        break;

+

+                default:

+                        assert_not_reached("Invalid job type");

+        }

+

+        /* Log if the job still exists and the start/stop/reload function

+         * actually did something. */

+        *j = manager_get_job(m, id);

+        if (*j && r > 0)

+                unit_status_emit_starting_stopping_reloading(u, t);

+

+        return r;

+}

+

 int job_run_and_invalidate(Job *j) {

         int r;

-        uint32_t id;

-        Manager *m = j->manager;

         assert(j);

         assert(j->installed);

@@ -526,23 +564,9 @@ int job_run_and_invalidate(Job *j) {

         job_set_state(j, JOB_RUNNING);

         job_add_to_dbus_queue(j);

-        /* While we execute this operation the job might go away (for

-         * example: because it is replaced by a new, conflicting

-         * job.) To make sure we don't access a freed job later on we

-         * store the id here, so that we can verify the job is still

-         * valid. */

-        id = j->id;

         switch (j->type) {

-                case JOB_START:

-                        r = unit_start(j->unit);

-

-                        /* If this unit cannot be started, then simply wait */

-                        if (r == -EBADR)

-                                r = 0;

-                        break;

-

                 case JOB_VERIFY_ACTIVE: {

                         UnitActiveState t = unit_active_state(j->unit);

                         if (UNIT_IS_ACTIVE_OR_RELOADING(t))

@@ -554,17 +578,19 @@ int job_run_and_invalidate(Job *j) {

                         break;

                 }

+                case JOB_START:

                 case JOB_STOP:

                 case JOB_RESTART:

-                        r = unit_stop(j->unit);

+                        r = job_perform_on_unit(&j);

-                        /* If this unit cannot stopped, then simply wait. */

+                        /* If the unit type does not support starting/stopping,

+                         * then simply wait. */

                         if (r == -EBADR)

                                 r = 0;

                         break;

                 case JOB_RELOAD:

-                        r = unit_reload(j->unit);

+                        r = job_perform_on_unit(&j);

                         break;

                 case JOB_NOP:

@@ -575,7 +601,6 @@ int job_run_and_invalidate(Job *j) {

                         assert_not_reached("Unknown job type");

         }

-        j = manager_get_job(m, id);

         if (j) {

                 if (r == -EALREADY)

                         r = job_finish_and_invalidate(j, JOB_DONE, true, true);

diff --git a/src/core/unit.c b/src/core/unit.c

index 6d535ae12..907a4bf7f 100644

--- a/src/core/unit.c

+++ b/src/core/unit.c

@@ -1417,6 +1417,15 @@ static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) {

                         NULL);

 }

+void unit_status_emit_starting_stopping_reloading(Unit *u, JobType t) {

+

+        unit_status_log_starting_stopping_reloading(u, t);

+

+        /* Reload status messages have traditionally not been printed to console. */

+        if (t != JOB_RELOAD)

+                unit_status_print_starting_stopping(u, t);

+}

+

 /* Errors:

  *         -EBADR:     This unit type does not support starting.

  *         -EALREADY:  Unit is already started.

@@ -1427,7 +1436,6 @@ static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) {

 int unit_start(Unit *u) {

         UnitActiveState state;

         Unit *following;

-        int r;

         assert(u);

@@ -1481,14 +1489,7 @@ int unit_start(Unit *u) {

         unit_add_to_dbus_queue(u);

-        r = UNIT_VTABLE(u)->start(u);

-        if (r <= 0)

-                return r;

-

-        /* Log if the start function actually did something */

-        unit_status_log_starting_stopping_reloading(u, JOB_START);

-        unit_status_print_starting_stopping(u, JOB_START);

-        return r;

+        return UNIT_VTABLE(u)->start(u);

 }

 bool unit_can_start(Unit *u) {

@@ -1512,7 +1513,6 @@ bool unit_can_isolate(Unit *u) {

 int unit_stop(Unit *u) {

         UnitActiveState state;

         Unit *following;

-        int r;

         assert(u);

@@ -1531,13 +1531,7 @@ int unit_stop(Unit *u) {

         unit_add_to_dbus_queue(u);

-        r = UNIT_VTABLE(u)->stop(u);

-        if (r <= 0)

-                return r;

-

-        unit_status_log_starting_stopping_reloading(u, JOB_STOP);

-        unit_status_print_starting_stopping(u, JOB_STOP);

-        return r;

+        return UNIT_VTABLE(u)->stop(u);

 }

 /* Errors:

@@ -1548,7 +1542,6 @@ int unit_stop(Unit *u) {

 int unit_reload(Unit *u) {

         UnitActiveState state;

         Unit *following;

-        int r;

         assert(u);

@@ -1575,12 +1568,7 @@ int unit_reload(Unit *u) {

         unit_add_to_dbus_queue(u);

-        r = UNIT_VTABLE(u)->reload(u);

-        if (r <= 0)

-                return r;

-

-        unit_status_log_starting_stopping_reloading(u, JOB_RELOAD);

-        return r;

+        return UNIT_VTABLE(u)->reload(u);

 }

 bool unit_can_reload(Unit *u) {

diff --git a/src/core/unit.h b/src/core/unit.h

index 85f52df18..480e2e95f 100644

--- a/src/core/unit.h

+++ b/src/core/unit.h

@@ -562,6 +562,7 @@ int unit_add_node_link(Unit *u, const char *what, bool wants, UnitDependency d);

 int unit_coldplug(Unit *u, Hashmap *deferred_work);

 void unit_status_printf(Unit *u, const char *status, const char *unit_status_msg_format) _printf_(3, 0);

+void unit_status_emit_starting_stopping_reloading(Unit *u, JobType t);

 bool unit_need_daemon_reload(Unit *u);