test: set -x in TEST-50-DISSECT test unit

Need to see what is actually being written down socat
to debug https://github.com/systemd/systemd/issues/37626

src/machine/machinectl.c

@@ -1236,10 +1236,10 @@ static int on_machine_removed(sd_bus_message *m, void *userdata, sd_bus_error *r
         /* Tell the forwarder to exit on the next vhangup(), so that we still flush out what might be queued
          * and exit then. */
 
-        r = pty_forward_set_ignore_vhangup(forward, false);
+        r = pty_forward_honor_vhangup(forward);
         if (r < 0) {
                 /* On error, quit immediately. */
-                log_error_errno(r, "Failed to set ignore_vhangup flag: %m");
+                log_error_errno(r, "Failed to make PTY forwarder honor vhangup(): %m");
                 (void) sd_event_exit(sd_bus_get_event(sd_bus_message_get_bus(m)), EXIT_FAILURE);
         }
 
@@ -1285,8 +1285,8 @@ static int process_forward(sd_event *event, sd_bus_slot *machine_removed_slot, i
                 return log_error_errno(r, "Failed to run event loop: %m");
 
         bool machine_died =
-                (flags & PTY_FORWARD_IGNORE_VHANGUP) &&
-                pty_forward_get_ignore_vhangup(forward) == 0;
+                FLAGS_SET(flags, PTY_FORWARD_IGNORE_VHANGUP) &&
+                !pty_forward_vhangup_honored(forward);
 
         if (!arg_quiet) {
                 if (machine_died)

src/run/run.c

@@ -1818,17 +1818,32 @@ static int run_context_check_started(RunContext *c) {
 }
 
 static void run_context_check_done(RunContext *c) {
+        int r;
+
         assert(c);
 
-        bool done = STRPTR_IN_SET(c->active_state, "inactive", "failed") &&
-                !c->start_job &&   /* our start job */
-                !c->job;           /* any other job */
+        if (!STRPTR_IN_SET(c->active_state, "inactive", "failed") ||
+            c->start_job ||   /* our start job */
+            c->job)           /* any other job */
+                return;
 
-        if (done && c->forward) /* If the service is gone, it's time to drain the output */
-                done = pty_forward_drain(c->forward);
+        if (!c->forward)
+                return (void) sd_event_exit(c->event, EXIT_SUCCESS);
 
-        if (done)
-                (void) sd_event_exit(c->event, EXIT_SUCCESS);
+        /* If the service is gone, it's time to drain the output */
+        r = pty_forward_drain(c->forward);
+        if (r < 0) {
+                log_error_errno(r, "Failed to drain PTY forwarder: %m");
+                return (void) sd_event_exit(c->event, EXIT_FAILURE);
+        }
+
+        /* Tell the forwarder to exit on the next vhangup(), so that we still flush out what might be queued
+         * and exit then. */
+        r = pty_forward_honor_vhangup(c->forward);
+        if (r < 0) {
+                log_error_errno(r, "Failed to make PTY forwarder honor vhangup(): %m");
+                return (void) sd_event_exit(c->event, EXIT_FAILURE);
+        }
 }
 
 static int map_job(sd_bus *bus, const char *member, sd_bus_message *m, sd_bus_error *error, void *userdata) {
@@ -1983,6 +1998,8 @@ static int pty_forward_handler(PTYForward *f, int rcode, void *userdata) {
                 return log_error_errno(rcode, "Error on PTY forwarding logic: %m");
         }
 
+        c->forward = pty_forward_free(c->forward);
+
         run_context_check_done(c);
         return 0;
 }

src/shared/ptyfwd.c

@@ -60,6 +60,7 @@ struct PTYForward {
         sd_event_source *master_event_source;
         sd_event_source *sigwinch_event_source;
         sd_event_source *exit_event_source;
+        sd_event_source *defer_event_source;
 
         struct termios saved_stdin_attr;
         struct termios saved_stdout_attr;
@@ -122,6 +123,7 @@ static void pty_forward_disconnect(PTYForward *f) {
         f->master_event_source = sd_event_source_unref(f->master_event_source);
         f->sigwinch_event_source = sd_event_source_unref(f->sigwinch_event_source);
         f->exit_event_source = sd_event_source_unref(f->exit_event_source);
+        f->defer_event_source = sd_event_source_unref(f->defer_event_source);
         f->event = sd_event_unref(f->event);
 
         if (f->output_fd >= 0) {
@@ -249,18 +251,6 @@ static RequestOperation look_for_escape(PTYForward *f, const char *buffer, size_
         return REQUEST_NOP;
 }
 
-static bool ignore_vhangup(PTYForward *f) {
-        assert(f);
-
-        if (f->flags & PTY_FORWARD_IGNORE_VHANGUP)
-                return true;
-
-        if ((f->flags & PTY_FORWARD_IGNORE_INITIAL_VHANGUP) && !f->read_from_master)
-                return true;
-
-        return false;
-}
-
 static bool drained(PTYForward *f) {
         int q = 0;
 
@@ -720,9 +710,9 @@ static int do_shovel(PTYForward *f) {
 
                                 /* Note that EIO on the master device might be caused by vhangup() or
                                  * temporary closing of everything on the other side, we treat it like EAGAIN
-                                 * here and try again, unless ignore_vhangup is off. */
+                                 * here and try again, unless vhangup() is honored. */
 
-                                if (errno == EAGAIN || (errno == EIO && ignore_vhangup(f)))
+                                if (errno == EAGAIN || (errno == EIO && !pty_forward_vhangup_honored(f)))
                                         f->master_readable = false;
                                 else if (IN_SET(errno, EPIPE, ECONNRESET, EIO)) {
                                         f->master_readable = f->master_writable = false;
@@ -786,6 +776,18 @@ static int do_shovel(PTYForward *f) {
                         break;
         }
 
+        return 0;
+}
+
+static int shovel(PTYForward *f) {
+        int r;
+
+        assert(f);
+
+        r = do_shovel(f);
+        if (r < 0)
+                return pty_forward_done(f, r);
+
         if (f->stdin_hangup || f->stdout_hangup || f->master_hangup) {
                 /* Exit the loop if any side hung up and if there's
                  * nothing more to write or nothing we could write. */
@@ -803,16 +805,17 @@ static int do_shovel(PTYForward *f) {
         return 0;
 }
 
-static int shovel(PTYForward *f) {
-        int r;
-
+static int shovel_force(PTYForward *f) {
         assert(f);
 
-        r = do_shovel(f);
-        if (r < 0)
-                return pty_forward_done(f, r);
+        if (!f->master_hangup)
+                f->master_writable = f->master_readable = true;
+        if (!f->stdin_hangup)
+                f->stdin_readable = true;
+        if (!f->stdout_hangup)
+                f->stdout_writable = true;
 
-        return r;
+        return shovel(f);
 }
 
 static int on_master_event(sd_event_source *e, int fd, uint32_t revents, void *userdata) {
@@ -883,15 +886,7 @@ static int on_exit_event(sd_event_source *e, void *userdata) {
 
         if (!pty_forward_drain(f)) {
                 /* If not drained, try to drain the buffer. */
-
-                if (!f->master_hangup)
-                        f->master_writable = f->master_readable = true;
-                if (!f->stdin_hangup)
-                        f->stdin_readable = true;
-                if (!f->stdout_hangup)
-                        f->stdout_writable = true;
-
-                r = shovel(f);
+                r = shovel_force(f);
                 if (r < 0)
                         return r;
         }
@@ -899,6 +894,23 @@ static int on_exit_event(sd_event_source *e, void *userdata) {
         return pty_forward_done(f, 0);
 }
 
+static int on_defer_event(sd_event_source *s, void *userdata) {
+        PTYForward *f = ASSERT_PTR(userdata);
+        return shovel_force(f);
+}
+
+static int pty_forward_add_defer(PTYForward *f) {
+        assert(f);
+
+        if (f->done)
+                return 0;
+
+        if (f->defer_event_source)
+                return sd_event_source_set_enabled(f->defer_event_source, SD_EVENT_ONESHOT);
+
+        return sd_event_add_defer(f->event, &f->defer_event_source, on_defer_event, f);
+}
+
 int pty_forward_new(
                 sd_event *event,
                 int master,
@@ -1082,33 +1094,31 @@ PTYForward* pty_forward_free(PTYForward *f) {
         return mfree(f);
 }
 
-int pty_forward_set_ignore_vhangup(PTYForward *f, bool b) {
-        int r;
-
+int pty_forward_honor_vhangup(PTYForward *f) {
         assert(f);
 
-        if (FLAGS_SET(f->flags, PTY_FORWARD_IGNORE_VHANGUP) == b)
+        if ((f->flags & (PTY_FORWARD_IGNORE_VHANGUP | PTY_FORWARD_IGNORE_INITIAL_VHANGUP)) == 0)
+                return 0; /* nothing changed. */
+
+        f->flags &= ~(PTY_FORWARD_IGNORE_VHANGUP | PTY_FORWARD_IGNORE_INITIAL_VHANGUP);
+
+        if (f->master_hangup)
                 return 0;
 
-        SET_FLAG(f->flags, PTY_FORWARD_IGNORE_VHANGUP, b);
-
-        if (!ignore_vhangup(f)) {
-
-                /* We shall now react to vhangup()s? Let's check immediately if we might be in one. */
-
-                f->master_readable = true;
-                r = shovel(f);
-                if (r < 0)
-                        return r;
+        /* We shall now react to vhangup()s? Let's check if we might be in one. */
+        return pty_forward_add_defer(f);
 }
 
-        return 0;
-}
-
-bool pty_forward_get_ignore_vhangup(PTYForward *f) {
+bool pty_forward_vhangup_honored(const PTYForward *f) {
         assert(f);
 
-        return FLAGS_SET(f->flags, PTY_FORWARD_IGNORE_VHANGUP);
+        if (FLAGS_SET(f->flags, PTY_FORWARD_IGNORE_VHANGUP))
+                return false;
+
+        if (FLAGS_SET(f->flags, PTY_FORWARD_IGNORE_INITIAL_VHANGUP) && !f->read_from_master)
+                return false;
+
+        return true;
 }
 
 void pty_forward_set_hangup_handler(PTYForward *f, PTYForwardHangupHandler cb, void *userdata) {
@@ -1125,18 +1135,14 @@ void pty_forward_set_hotkey_handler(PTYForward *f, PTYForwardHotkeyHandler cb, v
         f->hotkey_userdata = userdata;
 }
 
-bool pty_forward_drain(PTYForward *f) {
+int pty_forward_drain(PTYForward *f) {
         assert(f);
 
-        /* Starts draining the forwarder. Specifically:
-         *
-         * - Returns true if there are no unprocessed bytes from the pty, false otherwise
-         *
-         * - Makes sure the handler function is called the next time the number of unprocessed bytes hits zero
-         */
+        /* Starts draining the forwarder. This makes sure the handler function is called the next time the
+         * number of unprocessed bytes hits zero. */
 
         f->drain = true;
-        return drained(f);
+        return pty_forward_add_defer(f);
 }
 
 int pty_forward_set_priority(PTYForward *f, int64_t priority) {

src/shared/ptyfwd.h

@@ -28,13 +28,13 @@ extern const int pty_forward_signals[N_PTY_FORWARD_SIGNALS];
 int pty_forward_new(sd_event *event, int master, PTYForwardFlags flags, PTYForward **ret);
 PTYForward* pty_forward_free(PTYForward *f);
 
-int pty_forward_set_ignore_vhangup(PTYForward *f, bool ignore_vhangup);
-bool pty_forward_get_ignore_vhangup(PTYForward *f);
+int pty_forward_honor_vhangup(PTYForward *f);
+bool pty_forward_vhangup_honored(const PTYForward *f);
 
 void pty_forward_set_hangup_handler(PTYForward *f, PTYForwardHangupHandler handler, void *userdata);
 void pty_forward_set_hotkey_handler(PTYForward *f, PTYForwardHotkeyHandler handler, void *userdata);
 
-bool pty_forward_drain(PTYForward *f);
+int pty_forward_drain(PTYForward *f);
 
 int pty_forward_set_priority(PTYForward *f, int64_t priority);
 

test/integration-tests/TEST-07-PID1/TEST-07-PID1.units/defer-reactivation.service

@@ -0,0 +1,6 @@
+[Unit]
+Description=Test for DeferReactivation=yes (service)
+
+[Service]
+Type=simple
+ExecStart=sh -c 'date +%%s >>/tmp/defer-reactivation.log; sleep 5'

test/integration-tests/TEST-07-PID1/TEST-07-PID1.units/defer-reactivation.timer

@@ -0,0 +1,7 @@
+[Unit]
+Description=Test for DeferReactivation=yes (timer)
+
+[Timer]
+OnCalendar=*:*:0/5
+AccuracySec=1us
+DeferReactivation=yes

test/integration-tests/TEST-74-AUX-UTILS/TEST-74-AUX-UTILS.units/realtime-test.service

@@ -1,6 +0,0 @@
-[Unit]
-Description=Testing systemd timers
-
-[Service]
-Type=simple
-ExecStart=sh -c 'date +%%s >>/tmp/realtime-test.log ; sleep 5'

test/integration-tests/TEST-74-AUX-UTILS/TEST-74-AUX-UTILS.units/realtime-test.timer

@@ -1,10 +0,0 @@
-[Unit]
-Description=Testing systemd timers
-
-[Timer]
-OnCalendar=*:*:0/5
-AccuracySec=1us
-DeferReactivation=true
-
-[Install]
-WantedBy=timers.target

test/meson.build

@@ -357,7 +357,6 @@ if install_tests
                 'integration-tests/TEST-30-ONCLOCKCHANGE/TEST-30-ONCLOCKCHANGE.units',
                 'integration-tests/TEST-52-HONORFIRSTSHUTDOWN/TEST-52-HONORFIRSTSHUTDOWN.units',
                 'integration-tests/TEST-63-PATH/TEST-63-PATH.units',
-                'integration-tests/TEST-74-AUX-UTILS/TEST-74-AUX-UTILS.units',
                 'integration-tests/TEST-80-NOTIFYACCESS/TEST-80-NOTIFYACCESS.units',
         ]
 

test/units/TEST-07-PID1.DeferReactivation.sh

@@ -0,0 +1,30 @@
+#!/usr/bin/env bash
+# SPDX-License-Identifier: LGPL-2.1-or-later
+# shellcheck disable=SC2016
+set -eux
+set -o pipefail
+
+systemctl start defer-reactivation.timer
+
+timeout 20 bash -c 'until [[ -e /tmp/defer-reactivation.log ]]; do sleep .5; done'
+timeout 60 bash -c 'until (( $(cat /tmp/defer-reactivation.log | wc -l) >= 3 )); do sleep 5; done'
+
+systemctl stop defer-reactivation.timer
+
+# If the 'date' command is the service called instantaneously when the timer is triggered, each time delta
+# must be 10 seconds. But in a realistic situation, the command is slightly delayed after the timer is
+# triggered, and the delay has some fluctuations. If a trigger event calls the command at 00:00:01.01, and
+# the next event does at 00:00:10.99, the delta is calculated as 9 seconds. So, let's accept 9 here.
+mindelta=9
+
+last=
+while read -r time; do
+    if [[ -n "$last" ]]; then
+        delta=$(( time - last ))
+        if (( delta < mindelta )); then
+            echo "Timer fired too early: $delta < $mindelta" >/failed
+            exit 1
+        fi
+    fi
+    last=$time
+done </tmp/defer-reactivation.log

test/units/TEST-50-DISSECT.dissect.sh

@@ -571,7 +571,7 @@ EnvironmentFile=-/usr/lib/systemd/systemd-asan-env
 PrivateTmp=disconnected
 BindPaths=/tmp/markers/
 ExtensionDirectories=-${VDIR}
-ExecStart=bash -c ' \\
+ExecStart=bash -x -c ' \\
     trap "{ \\
         systemd-notify --reloading; \\
         (ls /etc | grep marker || echo no-marker) >/tmp/markers/50g; \\
@@ -612,7 +612,7 @@ EnvironmentFile=-/usr/lib/systemd/systemd-asan-env
 PrivateTmp=disconnected
 BindPaths=/tmp/markers/
 ExtensionImages=-$VDIR2
-ExecStart=bash -c ' \\
+ExecStart=bash -x -c ' \\
     trap "{ \\
         systemd-notify --reloading; \\
         (ls /etc | grep marker || echo no-marker) >/tmp/markers/50h; \\
@@ -650,7 +650,7 @@ BindPaths=/tmp/markers/
 RootImage=$MINIMAL_IMAGE.raw
 ExtensionDirectories=-${VDIR}
 NotifyAccess=all
-ExecStart=bash -c ' \
+ExecStart=bash -x -c ' \
     trap '"'"' \
         now=\$\$(grep "^now" /proc/timer_list | cut -d" " -f3 | rev | cut -c 4- | rev); \
         printf "RELOADING=1\\nMONOTONIC_USEC=\$\${now}" | socat -t 5 - UNIX-SENDTO:\$\$NOTIFY_SOCKET; \
@@ -685,7 +685,7 @@ BindPaths=/tmp/markers/
 RootDirectory=/tmp/vpickminimg
 ExtensionDirectories=-${VDIR}
 NotifyAccess=all
-ExecStart=bash -c ' \
+ExecStart=bash -x -c ' \
     trap '"'"' \
         now=\$\$(grep "^now" /proc/timer_list | cut -d" " -f3 | rev | cut -c 4- | rev); \
         printf "RELOADING=1\\nMONOTONIC_USEC=\$\${now}" | socat -t 5 - UNIX-SENDTO:\$\$NOTIFY_SOCKET; \
@@ -715,7 +715,7 @@ RootImage=$MINIMAL_IMAGE.raw
 ExtensionImages=-$VDIR2 /tmp/app0.raw
 PrivateUsers=yes
 NotifyAccess=all
-ExecStart=bash -c ' \
+ExecStart=bash -x -c ' \
     trap '"'"' \
         now=\$\$(grep "^now" /proc/timer_list | cut -d" " -f3 | rev | cut -c 4- | rev); \
         printf "RELOADING=1\\nMONOTONIC_USEC=\$\${now}" | socat -t 5 - UNIX-SENDTO:\$\$NOTIFY_SOCKET; \

test/units/TEST-74-AUX-UTILS.defer_reactivation.sh

@@ -1,23 +0,0 @@
-#!/usr/bin/env bash
-# SPDX-License-Identifier: LGPL-2.1-or-later
-set -eux
-set -o pipefail
-
-systemctl start realtime-test.timer
-
-sleep 35
-mindelta=10
-
-last=
-while read -r time; do
-    if [ -n "$last" ]; then
-        delta=$((time - last))
-        if [ "$delta" -lt $mindelta ]; then
-            echo "Timer fired too early: $delta < $mindelta" >/failed
-            break
-        fi
-    fi
-    last=$time
-done </tmp/realtime-test.log
-
-test ! -s /failed