Log more information on exec failure.

Log failure stage as well as error-from-errno.

diff --git a/src/includes/proc-service.h b/src/includes/proc-service.h
index e7faf57c51a6264276acfc2627e974916f402b7c..085026bc5f7ae533ddd015c8181aa5cccab5e2a6 100644 (file)
--- a/src/includes/proc-service.h
+++ b/src/includes/proc-service.h
@@ -52,6 +52,20 @@ struct run_proc_params
     { }
 };
 
+enum class exec_stage {
+    ARRANGE_FDS, READ_ENV_FILE, SET_NOTIFYFD_VAR, SETUP_ACTIVATION_SOCKET, SETUP_CONTROL_SOCKET,
+    CHDIR, SETUP_STDINOUTERR, SET_RLIMITS, SET_UIDGID, /* must be last: */ DO_EXEC
+};
+
+extern const char * const exec_stage_descriptions[static_cast<int>(exec_stage::DO_EXEC) + 1];
+
+// Error information from process execution transferred via this struct
+struct run_proc_err
+{
+    exec_stage stage;
+    int st_errno;
+};
+
 class base_process_service;
 
 // A timer for process restarting. Used to ensure a minimum delay between process restarts (and
@@ -198,7 +212,7 @@ class base_process_service : public service_record
     virtual void handle_exit_status(bp_sys::exit_status exit_status) noexcept = 0;
 
     // Called if an exec fails.
-    virtual void exec_failed(int errcode) noexcept = 0;
+    virtual void exec_failed(run_proc_err errcode) noexcept = 0;
 
     // Called if exec succeeds.
     virtual void exec_succeeded() noexcept { };
@@ -346,7 +360,7 @@ class base_process_service : public service_record
 class process_service : public base_process_service
 {
     virtual void handle_exit_status(bp_sys::exit_status exit_status) noexcept override;
-    virtual void exec_failed(int errcode) noexcept override;
+    virtual void exec_failed(run_proc_err errcode) noexcept override;
     virtual void exec_succeeded() noexcept override;
     virtual void bring_down() noexcept override;
 
@@ -407,7 +421,7 @@ class process_service : public base_process_service
 class bgproc_service : public base_process_service
 {
     virtual void handle_exit_status(bp_sys::exit_status exit_status) noexcept override;
-    virtual void exec_failed(int errcode) noexcept override;
+    virtual void exec_failed(run_proc_err errcode) noexcept override;
     virtual void bring_down() noexcept override;
 
     enum class pid_result_t {
@@ -438,7 +452,7 @@ class scripted_service : public base_process_service
 {
     virtual void handle_exit_status(bp_sys::exit_status exit_status) noexcept override;
     virtual void exec_succeeded() noexcept override;
-    virtual void exec_failed(int errcode) noexcept override;
+    virtual void exec_failed(run_proc_err errcode) noexcept override;
     virtual void bring_down() noexcept override;
 
     virtual bool interrupt_start() noexcept override

diff --git a/src/proc-service.cc b/src/proc-service.cc
index f21aa20ba429ae4cdb556a377113fe21de9e828f..2f12b205755c12dd29dfca81e9e5354df72c4279 100644 (file)
--- a/src/proc-service.cc
+++ b/src/proc-service.cc
@@ -15,6 +15,20 @@
  * See proc-service.h header for interface details.
  */
 
+// Strings describing the execution stages (failure points).
+const char * const exec_stage_descriptions[static_cast<int>(exec_stage::DO_EXEC) + 1] = {
+        "arranging file descriptors",   // ARRANGE_FDS
+        "reading environment file",     // READ_ENV_FILE
+        "setting environment variable", // SET_NOTIFYFD_VAR
+        "setting up activation socket", // SETUP_ACTIVATION_SOCKET
+        "setting up control socket",    // SETUP_CONTROL_SOCKET
+        "changing directory",           // CHDIR
+        "setting up standard input/output descriptors", // SETUP_STDINOUTERR
+        "setting resource limits",      // SET_RLIMITS
+        "setting user/group ID",        // SET_UIDGID
+        "executing command"             // DO_EXEC
+};
+
 // Given a string and a list of pairs of (start,end) indices for each argument in that string,
 // store a null terminator for the argument. Return a `char *` vector containing the beginning
 // of each argument and a trailing nullptr. (The returned array is invalidated if the string is
@@ -76,8 +90,8 @@ rearm exec_status_pipe_watcher::fd_event(eventloop_t &loop, int fd, int flags) n
     base_process_service *sr = service;
     sr->waiting_for_execstat = false;
 
-    int exec_status;
-    int r = read(get_watched_fd(), &exec_status, sizeof(int));
+    run_proc_err exec_status;
+    int r = read(get_watched_fd(), &exec_status, sizeof(exec_status));
     deregister(loop);
     close(get_watched_fd());
 
@@ -224,9 +238,10 @@ void process_service::handle_exit_status(bp_sys::exit_status exit_status) noexce
     services->process_queues();
 }
 
-void process_service::exec_failed(int errcode) noexcept
+void process_service::exec_failed(run_proc_err errcode) noexcept
 {
-    log(loglevel_t::ERROR, get_name(), ": execution failed: ", strerror(errcode));
+    log(loglevel_t::ERROR, get_name(), ": execution failed - ",
+            exec_stage_descriptions[static_cast<int>(errcode.stage)], strerror(errcode.st_errno));
 
     if (notification_fd != -1) {
         readiness_watcher.deregister(event_loop);
@@ -347,9 +362,11 @@ void bgproc_service::handle_exit_status(bp_sys::exit_status exit_status) noexcep
     services->process_queues();
 }
 
-void bgproc_service::exec_failed(int errcode) noexcept
+void bgproc_service::exec_failed(run_proc_err errcode) noexcept
 {
-    log(loglevel_t::ERROR, get_name(), ": execution failed: ", strerror(errcode));
+    log(loglevel_t::ERROR, get_name(), ": execution failed - ",
+            exec_stage_descriptions[static_cast<int>(errcode.stage)], strerror(errcode.st_errno));
+
     // Only time we execute is for startup:
     stop_reason = stopped_reason_t::EXECFAILED;
     failed_to_start();
@@ -439,9 +456,10 @@ void scripted_service::handle_exit_status(bp_sys::exit_status exit_status) noexc
     }
 }
 
-void scripted_service::exec_failed(int errcode) noexcept
+void scripted_service::exec_failed(run_proc_err errcode) noexcept
 {
-    log(loglevel_t::ERROR, get_name(), ": execution failed: ", strerror(errcode));
+    log(loglevel_t::ERROR, get_name(), ": execution failed - ",
+            exec_stage_descriptions[static_cast<int>(errcode.stage)], strerror(errcode.st_errno));
     auto service_state = get_state();
     if (service_state == service_state_t::STARTING) {
         stop_reason = stopped_reason_t::EXECFAILED;

diff --git a/src/run-child-proc.cc b/src/run-child-proc.cc
index f387d9204b29591f8efabe5e469894bcff4bf3d5..ba54ab275e001bf0baf59b17dc31db168c2f5755 100644 (file)
--- a/src/run-child-proc.cc
+++ b/src/run-child-proc.cc
@@ -82,6 +82,9 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
     constexpr int csenvbufsz = 12 + ((CHAR_BIT * sizeof(int) - 1 + 2) / 3) + 1;
     char csenvbuf[csenvbufsz];
 
+    run_proc_err err;
+    err.stage = exec_stage::ARRANGE_FDS;
+
     int minfd = (socket_fd == -1) ? 3 : 4;
 
     if (force_notify_fd != -1) {
@@ -129,6 +132,8 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
         if (notify_fd == -1) goto failure_out;
     }
 
+    err.stage = exec_stage::READ_ENV_FILE;
+
     // Read environment from file
     if (params.env_file != nullptr) {
         try {
@@ -144,6 +149,7 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
 
     // Set up notify-fd variable:
     if (notify_var != nullptr && *notify_var != 0) {
+        err.stage = exec_stage::SET_NOTIFYFD_VAR;
         // We need to do an allocation: the variable name length, '=', and space for the value,
         // and nul terminator:
         int notify_var_len = strlen(notify_var);
@@ -156,6 +162,8 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
 
     // Set up Systemd-style socket activation:
     if (socket_fd != -1) {
+        err.stage = exec_stage::SETUP_ACTIVATION_SOCKET;
+
         // If we passing a pre-opened socket, it has to be fd number 3. (Thanks, Systemd).
         if (dup2(socket_fd, 3) == -1) goto failure_out;
         if (socket_fd != 3) close(socket_fd);
@@ -166,11 +174,13 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
     }
 
     if (csfd != -1) {
+        err.stage = exec_stage::SETUP_CONTROL_SOCKET;
         snprintf(csenvbuf, csenvbufsz, "DINIT_CS_FD=%d", csfd);
         if (putenv(csenvbuf)) goto failure_out;
     }
 
     if (working_dir != nullptr && *working_dir != 0) {
+        err.stage = exec_stage::CHDIR;
         if (chdir(working_dir) == -1) {
             goto failure_out;
         }
@@ -182,6 +192,7 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
             if (i != force_notify_fd) close(i);
         }
 
+        err.stage = exec_stage::SETUP_STDINOUTERR;
         if (notify_fd == 0 || move_fd(open("/dev/null", O_RDONLY), 0) == 0) {
             // stdin = 0. That's what we should have; proceed with opening stdout and stderr. We have to
             // take care not to clobber the notify_fd.
@@ -233,6 +244,7 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
     }
 
     // Resource limits
+    err.stage = exec_stage::SET_RLIMITS;
     for (auto &limit : rlimits) {
         rlimit setlimits;
         if (!limit.hard_set || !limit.soft_set) {
@@ -245,17 +257,19 @@ void base_process_service::run_child_proc(run_proc_params params) noexcept
     }
 
     if (uid != uid_t(-1)) {
+        err.stage = exec_stage::SET_UIDGID;
         if (setreuid(uid, uid) != 0) goto failure_out;
         if (setregid(gid, gid) != 0) goto failure_out;
     }
 
     sigprocmask(SIG_SETMASK, &sigwait_set, nullptr);
 
+    err.stage = exec_stage::DO_EXEC;
     execvp(args[0], const_cast<char **>(args));
 
     // If we got here, the exec failed:
     failure_out:
-    int exec_status = errno;
-    write(wpipefd, &exec_status, sizeof(int));
+    err.st_errno = errno;
+    write(wpipefd, &err, sizeof(err));
     _exit(0);
 }

diff --git a/src/tests/proctests.cc b/src/tests/proctests.cc
index 12c9abd8f8eb5b56feace5226416720650e9a322..cb36ede26d01363c5fbd4a218ce4d44ac4115648 100644 (file)
--- a/src/tests/proctests.cc
+++ b/src/tests/proctests.cc
@@ -29,8 +29,11 @@ class base_process_service_test
 
     static void exec_failed(base_process_service *bsp, int errcode)
     {
+        run_proc_err err;
+        err.stage = exec_stage::DO_EXEC;
+        err.st_errno = errcode;
        bsp->waiting_for_execstat = false;
-       bsp->exec_failed(errcode);
+       bsp->exec_failed(err);
     }
 
     static void handle_exit(base_process_service *bsp, int exit_status)