execute_process: Restore support for short timeouts

Since commit 5420639a8d (cmExecuteProcessCommand: Replace cmsysProcess
with cmUVProcessChain, 2023-06-01, v3.28.0-rc1~138^2~8) we've
occasionally observed immediate timeouts on processes that take longer
than the timeout to start, even though we only start the timer after the
child processes start.  The problem is that:

* `uv_loop_init` initializes `uv_loop_t`'s cached "now" time.
* Starting processes takes time but does not update the "now" time.
* `uv_timer_start` computes expiry relative the cached "now" time,
  so short timers may be expired as soon as they are started.
* `uv_run` invokes expired timer callbacks before polling for I/O
  or process completion, so we "timeout" immediately.

Fix this by updating the cached "now" time via `uv_update_time` just
before starting timers.  This is needed only for timers that start
before the `uv_run` event loop.  Update our `uv_timer_ptr` wrapper
to make all callers consider the choice when calling `start()`.
This commit is contained in:
Brad King
2025-11-09 09:07:01 -05:00
parent b4cdd8aab5
commit 6ec2c51f0c
10 changed files with 35 additions and 12 deletions

View File

@@ -840,7 +840,7 @@ bool cmCTestBuildHandler::RunMakeCommand(const std::string& command,
auto* timedOutPtr = static_cast<bool*>(t->data);
*timedOutPtr = true;
},
timeout * 1000, 0);
timeout * 1000, 0, cm::uv_update_time::yes);
}
// For every chunk of data

View File

@@ -733,7 +733,7 @@ void cmCTestMultiProcessHandler::StartNextTestsOnTimer()
auto* self = static_cast<cmCTestMultiProcessHandler*>(timer->data);
self->StartNextTests();
},
milliseconds, 0);
milliseconds, 0, cm::uv_update_time::no);
}
void cmCTestMultiProcessHandler::FinishTestProcess(

View File

@@ -156,7 +156,8 @@ void cmProcess::StartTimer()
auto msec =
std::chrono::duration_cast<std::chrono::milliseconds>(*this->Timeout);
this->Timer.start(&cmProcess::OnTimeoutCB,
static_cast<uint64_t>(msec.count()), 0);
static_cast<uint64_t>(msec.count()), 0,
cm::uv_update_time::no);
}
}

View File

@@ -3553,7 +3553,8 @@ bool cmCTest::RunCommand(std::vector<std::string> const& args,
auto* timedOutPtr = static_cast<bool*>(t->data);
*timedOutPtr = true;
},
static_cast<uint64_t>(timeout.count() * 1000.0), 0);
static_cast<uint64_t>(timeout.count() * 1000.0), 0,
cm::uv_update_time::yes);
}
std::vector<char> tempOutput;

View File

@@ -306,7 +306,7 @@ bool cmExecuteProcessCommand(std::vector<std::string> const& args,
auto* timeoutPtr = static_cast<bool*>(handle->data);
*timeoutPtr = true;
},
timeoutMillis, 0);
timeoutMillis, 0, cm::uv_update_time::yes);
}
// Read the process output.

View File

@@ -610,7 +610,8 @@ bool cmSystemTools::RunSingleCommand(std::vector<std::string> const& command,
auto* timedOutPtr = static_cast<bool*>(t->data);
*timedOutPtr = true;
},
static_cast<uint64_t>(timeout.count() * 1000.0), 0);
static_cast<uint64_t>(timeout.count() * 1000.0), 0,
cm::uv_update_time::yes);
}
std::vector<char> tempStdOut;
@@ -2343,7 +2344,8 @@ cmSystemTools::WaitForLineResult cmSystemTools::WaitForLine(
auto* timedOutPtr = static_cast<bool*>(handle->data);
*timedOutPtr = true;
},
static_cast<uint64_t>(timeout.count() * 1000.0), 0);
static_cast<uint64_t>(timeout.count() * 1000.0), 0,
cm::uv_update_time::no);
uv_run(loop, UV_RUN_ONCE);
if (timedOut) {

View File

@@ -243,9 +243,13 @@ int uv_timer_ptr::init(uv_loop_t& loop, void* data)
return uv_timer_init(&loop, *this);
}
int uv_timer_ptr::start(uv_timer_cb cb, uint64_t timeout, uint64_t repeat)
int uv_timer_ptr::start(uv_timer_cb cb, uint64_t timeout, uint64_t repeat,
uv_update_time update_time)
{
assert(this->handle);
if (update_time == uv_update_time::yes) {
::uv_update_time(this->handle->loop);
}
return uv_timer_start(*this, cb, timeout, repeat);
}

View File

@@ -30,6 +30,20 @@
namespace cm {
/** Whether to call uv_update_time before starting a timer.
*
* uv_loop_t caches a "now" time that uv_loop_init initializes and
* uv_run updates on each event loop iteration. uv_timer_start
* computes timer expiry relative to the loop's cached "now" time.
* For short timeouts started before the event loop, we may need to
* update the "now" time when starting the timer.
*/
enum class uv_update_time
{
no,
yes,
};
/***
* RAII class to simplify and ensure the safe usage of uv_loop_t. This includes
* making sure resources are properly freed.
@@ -251,7 +265,8 @@ struct uv_timer_ptr : public uv_handle_ptr_<uv_timer_t>
int init(uv_loop_t& loop, void* data = nullptr);
int start(uv_timer_cb cb, uint64_t timeout, uint64_t repeat);
int start(uv_timer_cb cb, uint64_t timeout, uint64_t repeat,
uv_update_time update_time);
void stop();
};

View File

@@ -439,7 +439,7 @@ bool cmUVProcessChain::Wait(uint64_t milliseconds)
auto* timeoutPtr = static_cast<bool*>(handle->data);
*timeoutPtr = true;
},
milliseconds, 0);
milliseconds, 0, cm::uv_update_time::yes);
}
while (!timeout &&

View File

@@ -74,7 +74,7 @@ static bool testTimer()
cm::uv_timer_ptr timer;
timer.init(*loop, &timed);
timer.start(cb, 10, 0);
timer.start(cb, 10, 0, cm::uv_update_time::no);
uv_run(loop, UV_RUN_DEFAULT);
if (!timed) {
@@ -83,7 +83,7 @@ static bool testTimer()
}
timed = false;
timer.start(cb, 10, 0);
timer.start(cb, 10, 0, cm::uv_update_time::no);
timer.stop();
uv_run(loop, UV_RUN_DEFAULT);