diff --git a/cf-agent/verify_exec.c b/cf-agent/verify_exec.c index 15c74d5fee..53ec985a58 100644 --- a/cf-agent/verify_exec.c +++ b/cf-agent/verify_exec.c @@ -288,6 +288,9 @@ static ActionResult RepairExec(EvalContext *ctx, const Attributes *a, CommandPrefix(cmdline, comm); + /* Set once the command has been reaped, if its exec_timeout fired. */ + bool timed_out = false; + bool do_work_here = true; #ifndef __MINGW32__ @@ -448,7 +451,31 @@ static ActionResult RepairExec(EvalContext *ctx, const Attributes *a, { int ret = cf_pclose(pfp); - if (ret == -1) + /* Sample only now, and never earlier. The read loop above ends as + * soon as the command closes its output, which it can do long + * before it exits -- so the alarm may not fire until cf_pclose() + * is already waiting for the child. Reading the flag before that + * wait misses exactly the case this is here to catch. It is still + * read before the alarm is disarmed further down. */ + timed_out = (a->contain.timeout != CF_NOINT) && TimeOutHasFired(); + + if (timed_out) + { + /* The command exceeded exec_timeout and was signalled, so its + * exit status cannot be trusted to say so. A command killed + * after it has written its last output, or one that exits + * normally while only its children are killed, is reaped with a + * status VerifyCommandRetcode() reads as success -- and the + * promise is then reported kept or repaired even though the + * command never completed. Classify on the timeout instead. */ + cfPS(ctx, LOG_LEVEL_ERR, PROMISE_RESULT_TIMEOUT, pp, a, + TimeOutSignalledProcess() + ? "Command '%s' exceeded exec_timeout of %d seconds and was terminated" + : "Command '%s' exceeded exec_timeout of %d seconds; it was NOT terminated and ran to completion", + pp->promiser, a->contain.timeout); + *result = PromiseResultUpdate(*result, PROMISE_RESULT_TIMEOUT); + } + else if (ret == -1) { cfPS(ctx, LOG_LEVEL_ERR, PROMISE_RESULT_FAIL, pp, a, "Finished script '%s' - failed (abnormal termination)", pp->promiser); *result = PromiseResultUpdate(*result, PROMISE_RESULT_FAIL); @@ -492,7 +519,7 @@ static ActionResult RepairExec(EvalContext *ctx, const Attributes *a, } #endif /* !__MINGW32__ */ - return ACTION_RESULT_OK; + return timed_out ? ACTION_RESULT_TIMEOUT : ACTION_RESULT_OK; } /*************************************************************/ diff --git a/libpromises/timeout.c b/libpromises/timeout.c index 5ad63baf85..5033ceada1 100644 --- a/libpromises/timeout.c +++ b/libpromises/timeout.c @@ -26,21 +26,46 @@ #include #include +/* Set by TimeOut() when the alarm fires, so that the caller can tell "the + * command timed out" from "the command finished". Written from a signal + * handler, hence volatile sig_atomic_t. */ +static volatile sig_atomic_t TIMEOUT_FIRED = 0; /* GLOBAL_X */ + +/* Set only when TimeOut() actually had a process to signal. The alarm can fire + * with ALARM_PID already cleared -- cf_pclose() clears it before waiting -- in + * which case the command timed out but was never terminated, and saying + * otherwise would be a false statement in an error message. */ +static volatile sig_atomic_t TIMEOUT_SIGNALLED = 0; /* GLOBAL_X */ + void SetTimeOut(int timeout) { ALARM_PID = -1; + TIMEOUT_FIRED = 0; + TIMEOUT_SIGNALLED = 0; signal(SIGALRM, (void *) TimeOut); alarm(timeout); } +bool TimeOutHasFired(void) +{ + return TIMEOUT_FIRED != 0; +} + +bool TimeOutSignalledProcess(void) +{ + return TIMEOUT_SIGNALLED != 0; +} + /*************************************************************************/ void TimeOut() { alarm(0); + TIMEOUT_FIRED = 1; if (ALARM_PID != -1) { + TIMEOUT_SIGNALLED = 1; Log(LOG_LEVEL_VERBOSE, "Time out of process %jd", (intmax_t)ALARM_PID); GracefulTerminate(ALARM_PID, PROCESS_START_TIME_UNKNOWN); } diff --git a/libpromises/timeout.h b/libpromises/timeout.h index 33af0f7f05..7fee008f4a 100644 --- a/libpromises/timeout.h +++ b/libpromises/timeout.h @@ -26,6 +26,16 @@ #define CFENGINE_TIMEOUT_H void SetTimeOut(int timeout); + +/* True if the alarm armed by the last SetTimeOut() actually fired. Lets a + * caller report that a command was timed out even when the command's own exit + * status would otherwise read as success. Cleared by SetTimeOut(). */ +bool TimeOutHasFired(void); + +/* True if that alarm also had a process to signal. False means the command + * exceeded its timeout but was never terminated, which callers must not + * describe as a termination. */ +bool TimeOutSignalledProcess(void); void TimeOut(void); time_t SetReferenceTime(void); diff --git a/tests/acceptance/08_commands/04_exec_timeout/timeout_after_output_closed.cf b/tests/acceptance/08_commands/04_exec_timeout/timeout_after_output_closed.cf new file mode 100644 index 0000000000..bf679fbd5e --- /dev/null +++ b/tests/acceptance/08_commands/04_exec_timeout/timeout_after_output_closed.cf @@ -0,0 +1,61 @@ +####################################################### +# +# Test that exec_timeout is detected even when the command +# closes its output long before it exits. The agent's read +# loop ends at EOF, so it is already waiting for the child +# when the alarm fires; a timeout sampled while output was +# still open misses exactly this shape. The command then runs +# to completion and exits 0, and must still be reported as +# timed out. +# +# Deliberately slow: with its output already closed there is +# no process left registered for the alarm to signal, so the +# child's full 10 second sleep runs out before it is reaped. +# Expect around 12 seconds of wall clock. +# +####################################################### +body common control +{ + inputs => { "../../default.sub.cf" }; + bundlesequence => { default("$(this.promise_filename)") }; + version => "1.0"; +} + +####################################################### +bundle agent test +{ + meta: + "description" + string => "exec_timeout is detected when the command closes its output before it exits"; + + "test_skip_unsupported" + string => "windows", + comment => "Drives /bin/sh with a POSIX shell payload"; + + commands: + "/bin/sh" + arglist => { "-c", "exec 1>&- 2>&-; sleep 10; exit 0" }, + contain => exec_timeout_2, + classes => dcs_all_classes("output_closed"); +} + +body contain exec_timeout_2 +{ + exec_timeout => "2"; +} + +####################################################### +bundle agent check +{ + methods: + "any" + usebundle => dcs_passif_expected( + "output_closed_repair_timeout", + "output_closed_promise_kept,output_closed_promise_repaired", + $(this.promise_filename) + ), + inherit => "true"; +} + +### PROJECT_ID: core +### CATEGORY_ID: 26 diff --git a/tests/acceptance/08_commands/04_exec_timeout/timeout_does_not_leak_to_next_promise.cf b/tests/acceptance/08_commands/04_exec_timeout/timeout_does_not_leak_to_next_promise.cf new file mode 100644 index 0000000000..c38a4e0330 --- /dev/null +++ b/tests/acceptance/08_commands/04_exec_timeout/timeout_does_not_leak_to_next_promise.cf @@ -0,0 +1,66 @@ +####################################################### +# +# Test that a fired exec_timeout is charged to the promise +# whose command timed out, and only that promise: a +# subsequent commands: promise that finishes inside its own +# timeout must come out repaired, not timed out. +# +####################################################### +body common control +{ + inputs => { "../../default.sub.cf" }; + bundlesequence => { default("$(this.promise_filename)") }; + version => "1.0"; +} + +####################################################### +bundle agent test +{ + meta: + "description" + string => "A fired exec_timeout does not leak into the next commands promise"; + + "test_skip_unsupported" + string => "windows", + comment => "Drives /bin/sh with POSIX shell payloads"; + + commands: + "/bin/sh" + arglist => { "-c", "sleep 2.4; exit 0" }, + contain => exec_timeout_2, + classes => dcs_all_classes("leak_first"); + + # Runs after the first command has already timed out, armed with + # its own timeout so that a stale flag surviving from the first + # promise would be sampled here if it leaked. + "/bin/sh" + arglist => { "-c", "exit 0" }, + contain => exec_timeout_10, + classes => dcs_all_classes("leak_second"); +} + +body contain exec_timeout_2 +{ + exec_timeout => "2"; +} + +body contain exec_timeout_10 +{ + exec_timeout => "10"; +} + +####################################################### +bundle agent check +{ + methods: + "any" + usebundle => dcs_passif_expected( + "leak_first_repair_timeout,leak_second_promise_repaired", + "leak_first_promise_kept,leak_first_promise_repaired,leak_second_repair_timeout", + $(this.promise_filename) + ), + inherit => "true"; +} + +### PROJECT_ID: core +### CATEGORY_ID: 26 diff --git a/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_exit_zero.cf b/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_exit_zero.cf new file mode 100644 index 0000000000..c5022af938 --- /dev/null +++ b/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_exit_zero.cf @@ -0,0 +1,58 @@ +####################################################### +# +# Test that a commands: promise whose exec_timeout fires is +# reported as timed out even though the command exits 0. The +# exit status of a command that was signalled does not say +# whether it ran to completion, so a fired timeout must take +# precedence over a successful exit status. +# +####################################################### +body common control +{ + inputs => { "../../default.sub.cf" }; + bundlesequence => { default("$(this.promise_filename)") }; + version => "1.0"; +} + +####################################################### +bundle agent test +{ + meta: + "description" + string => "A fired exec_timeout takes precedence over a successful exit status"; + + "test_skip_unsupported" + string => "windows", + comment => "Drives /bin/sh with a POSIX shell payload"; + + commands: + # The sleep outlives the 2 second timeout by less than the + # termination ladder's grace period, so the signalled shell + # still reaps its child and exits 0 -- the shape in which the + # exit status used to win over the fired timeout. + "/bin/sh" + arglist => { "-c", "sleep 2.4; exit 0" }, + contain => exec_timeout_2, + classes => dcs_all_classes("timeout_exit0"); +} + +body contain exec_timeout_2 +{ + exec_timeout => "2"; +} + +####################################################### +bundle agent check +{ + methods: + "any" + usebundle => dcs_passif_expected( + "timeout_exit0_repair_timeout", + "timeout_exit0_promise_kept,timeout_exit0_promise_repaired", + $(this.promise_filename) + ), + inherit => "true"; +} + +### PROJECT_ID: core +### CATEGORY_ID: 26 diff --git a/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_kept_returncodes.cf b/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_kept_returncodes.cf new file mode 100644 index 0000000000..4f293fe0bb --- /dev/null +++ b/tests/acceptance/08_commands/04_exec_timeout/timeout_overrides_kept_returncodes.cf @@ -0,0 +1,66 @@ +####################################################### +# +# Test that kept_returncodes does not resurrect "kept" when +# exec_timeout fired: the timed-out command exits 0, and 0 is +# listed in kept_returncodes, but the promise must still be +# reported as timed out, not kept. +# +####################################################### +body common control +{ + inputs => { "../../default.sub.cf" }; + bundlesequence => { default("$(this.promise_filename)") }; + version => "1.0"; +} + +####################################################### +bundle agent test +{ + meta: + "description" + string => "kept_returncodes does not resurrect kept when exec_timeout fired"; + + "test_skip_unsupported" + string => "windows", + comment => "Drives /bin/sh with a POSIX shell payload"; + + commands: + "/bin/sh" + arglist => { "-c", "sleep 2.4; exit 0" }, + contain => exec_timeout_2, + classes => all_classes_kept_0("timeout_kept0"); +} + +body contain exec_timeout_2 +{ + exec_timeout => "2"; +} + +# dcs_all_classes (dcs.sub.cf) carries no returncode attributes and +# classes bodies do not compose, so this is dcs_all_classes plus +# kept_returncodes. +body classes all_classes_kept_0(prefix) +{ + promise_kept => { "$(prefix)_promise_kept" }; + promise_repaired => { "$(prefix)_promise_repaired" }; + repair_failed => { "$(prefix)_repair_failed" }; + repair_denied => { "$(prefix)_repair_denied" }; + repair_timeout => { "$(prefix)_repair_timeout" }; + kept_returncodes => { "0" }; +} + +####################################################### +bundle agent check +{ + methods: + "any" + usebundle => dcs_passif_expected( + "timeout_kept0_repair_timeout", + "timeout_kept0_promise_kept,timeout_kept0_promise_repaired", + $(this.promise_filename) + ), + inherit => "true"; +} + +### PROJECT_ID: core +### CATEGORY_ID: 26 diff --git a/tests/acceptance/08_commands/04_exec_timeout/within_timeout_normal_outcomes.cf b/tests/acceptance/08_commands/04_exec_timeout/within_timeout_normal_outcomes.cf new file mode 100644 index 0000000000..6ea7e32995 --- /dev/null +++ b/tests/acceptance/08_commands/04_exec_timeout/within_timeout_normal_outcomes.cf @@ -0,0 +1,59 @@ +####################################################### +# +# Test that an armed exec_timeout that does not fire leaves +# the outcome of a commands: promise to the exit status: 0 +# repairs the promise and non-zero fails it, exactly as if no +# timeout were set. Guards the normal path against +# regressions from the timed-out path. +# +####################################################### +body common control +{ + inputs => { "../../default.sub.cf" }; + bundlesequence => { default("$(this.promise_filename)") }; + version => "1.0"; +} + +####################################################### +bundle agent test +{ + meta: + "description" + string => "An exec_timeout that does not fire leaves the outcome to the exit status"; + + "test_skip_unsupported" + string => "windows", + comment => "Drives /bin/sh with POSIX shell payloads"; + + commands: + "/bin/sh" + arglist => { "-c", "sleep 1; exit 0" }, + contain => exec_timeout_10, + classes => dcs_all_classes("within_exit0"); + + "/bin/sh" + arglist => { "-c", "sleep 1; exit 3" }, + contain => exec_timeout_10, + classes => dcs_all_classes("within_exit3"); +} + +body contain exec_timeout_10 +{ + exec_timeout => "10"; +} + +####################################################### +bundle agent check +{ + methods: + "any" + usebundle => dcs_passif_expected( + "within_exit0_promise_repaired,within_exit3_repair_failed", + "within_exit0_repair_timeout,within_exit0_repair_failed,within_exit3_repair_timeout,within_exit3_promise_repaired", + $(this.promise_filename) + ), + inherit => "true"; +} + +### PROJECT_ID: core +### CATEGORY_ID: 26