fwt_software/tests/test_thermalguard.cpp

484 lines
19 KiB
C++

#include <doctest/doctest.h>
#include "fgc/ChannelTopics.h"
#include "fgc/Config.h"
#include "fgc/HostMetrics.h"
#include "fgc/OperatingMode.h"
#include "fgc/ThermalGuard.h"
#include <filesystem>
#include <fstream>
#include <string>
#include <vector>
#include <unistd.h>
using namespace fgc;
namespace fs = std::filesystem;
namespace {
// A host at `c` degrees, 2.8 of 3.6 GHz, 30% busy, counters at `count`.
HostReading at(long long t_s, double c, long long count = 0) {
HostReading r;
r.now_ms = t_s * 1000;
r.temp_ok = true;
r.cpu_c = c;
r.zone = "x86_pkg_temp";
r.clock_ok = true;
r.mhz = 2800;
r.hw_max_mhz = 3600;
r.count_ok = true;
r.throttle_count = count;
r.busy_pct = 30;
return r;
}
bool logged(const std::vector<GuardLog>& log, const std::string& part) {
for (const auto& l : log)
if (l.second.find(part) != std::string::npos) return true;
return false;
}
// Feed a reading every 2 s from t0 to t1 (inclusive), collecting the log.
std::vector<GuardLog> run(ThermalGuard& g, long long t0, long long t1, double c,
long long count = 0) {
std::vector<GuardLog> all;
for (long long t = t0; t <= t1; t += 2) {
auto l = g.update(at(t, c, count));
all.insert(all.end(), l.begin(), l.end());
}
return all;
}
struct FakeSys {
fs::path root;
FakeSys() {
root = fs::temp_directory_path() / ("fgc_fakesys_" + std::to_string(::getpid()));
fs::remove_all(root);
}
~FakeSys() { fs::remove_all(root); }
void put(const std::string& rel, const std::string& text) {
fs::path p = root / rel;
fs::create_directories(p.parent_path());
std::ofstream(p) << text;
}
};
} // namespace
TEST_CASE("a cool, idle CPU stays at the normal pace") {
ThermalGuard g;
auto log = run(g, 0, 600, 60.0);
CHECK(g.state() == GuardState::Normal);
CHECK(g.intervalScale() == doctest::Approx(1.0));
CHECK_FALSE(g.pauseCapture());
CHECK(log.empty());
}
TEST_CASE("a hot CPU slows the scan, and the slow-down lifts only after it has been calm") {
ThermalParams p;
ThermalGuard g(p);
run(g, 0, 10, 70.0);
auto log = g.update(at(12, 86.0));
CHECK(g.state() == GuardState::Slowed);
CHECK(g.intervalScale() == doctest::Approx(p.slow_factor));
CHECK(logged(log, "CPU at 86 \xC2\xB0""C"));
CHECK(logged(log, "2x further apart"));
// Below slow_c but inside the hysteresis band: stays slowed.
run(g, 14, 400, 82.0);
CHECK(g.state() == GuardState::Slowed);
// Below slow_c - hysteresis, but not yet for calm_s.
run(g, 402, 402 + p.calm_s - 4, 78.0);
CHECK(g.state() == GuardState::Slowed);
// A hot blip restarts the calm clock.
g.update(at(402 + p.calm_s - 2, 81.0));
run(g, 402 + p.calm_s, 402 + 2 * p.calm_s - 2, 78.0);
CHECK(g.state() == GuardState::Slowed);
log = run(g, 402 + 2 * p.calm_s, 402 + 2 * p.calm_s + 4, 78.0);
CHECK(g.state() == GuardState::Normal);
CHECK(logged(log, "back to the normal picture pace"));
}
TEST_CASE("a CPU that stays very hot pauses pictures, and resumes once cool and the pause is served") {
ThermalParams p;
ThermalGuard g(p);
// One hot sample is not enough: pause_after_s of it is.
g.update(at(0, 93.0));
CHECK(g.state() == GuardState::Slowed);
auto log = run(g, 2, p.pause_after_s, 93.0);
CHECK(g.state() == GuardState::Paused);
CHECK(g.pauseCapture());
CHECK(logged(log, "pausing pictures"));
// Cooled quickly, but the pause runs its minimum.
const long long paused_at = p.pause_after_s;
run(g, paused_at + 2, paused_at + p.min_pause_s - 2, 70.0);
CHECK(g.state() == GuardState::Paused);
log = run(g, paused_at + p.min_pause_s, paused_at + p.min_pause_s + 2, 70.0);
CHECK(g.state() == GuardState::Slowed); // resumes slowed, not straight to full pace
CHECK(logged(log, "pictures resume"));
}
TEST_CASE("a pause lasts while the CPU is above resume_c, or saving has not caught up") {
ThermalParams p;
ThermalGuard g(p);
run(g, 0, p.pause_after_s + 2, 95.0);
REQUIRE(g.state() == GuardState::Paused);
run(g, 30, 30 + 2 * p.min_pause_s, p.resume_c + 3);
CHECK(g.state() == GuardState::Paused); // served its time, still too warm
HostReading r = at(1000, 70.0);
r.save_pending = 1;
g.update(r);
CHECK(g.state() == GuardState::Paused); // cool, but a frame is still saving
g.update(at(1002, 70.0));
CHECK(g.state() == GuardState::Slowed);
}
TEST_CASE("saving that keeps the scan waiting slows it, then pauses it") {
ThermalParams p;
ThermalGuard g(p);
auto held = [](long long t) {
HostReading r = at(t, 60.0);
r.held_for_save = true;
r.save_pending = 4;
return r;
};
// Brief holds are normal.
for (long long t = 0; t < p.held_slow_s; t += 2) g.update(held(t));
CHECK(g.state() == GuardState::Normal);
g.update(at(p.held_slow_s, 60.0)); // caught up: the clock restarts
for (long long t = p.held_slow_s + 2; t < 2 * p.held_slow_s; t += 2) g.update(held(t));
CHECK(g.state() == GuardState::Normal);
std::vector<GuardLog> log;
long long t = 100;
for (; t <= 100 + p.held_slow_s; t += 2) {
auto l = g.update(held(t));
log.insert(log.end(), l.begin(), l.end());
}
CHECK(g.state() == GuardState::Slowed);
CHECK(logged(log, "Saving has kept the scan waiting"));
for (; t <= 100 + p.held_pause_s; t += 2) g.update(held(t));
CHECK(g.state() == GuardState::Paused);
}
// A saver too slow for the interval: the scan waits `wait_s` out of every
// `cycle_s`, never long in one go - the overload the desk run with a CPU quota
// showed (save 4.6 s against a 2 s interval). Feeds samples every 2 s from t0
// to t1, keeping the running waiting total in `held`.
std::vector<GuardLog> runSlowSaver(ThermalGuard& g, long long t0, long long t1, double wait_frac,
long long& held, double save_ms = 4600.0) {
std::vector<GuardLog> all;
for (long long t = t0; t <= t1; t += 2) {
HostReading r = at(t, 60.0);
held += static_cast<long long>(2000 * wait_frac);
r.held_total_ms = held;
r.held_for_save = (t / 2) % 2 == 0 && wait_frac > 0.0; // short waits, on and off
r.save_pending = 2;
r.base_interval_ms = 2000;
r.save_ms_mean = save_ms;
r.save_workers = 1;
auto l = g.update(r);
all.insert(all.end(), l.begin(), l.end());
}
return all;
}
TEST_CASE("a saver that holds the scan briefly but often slows it, to a pace saving can keep") {
ThermalParams p;
ThermalGuard g(p);
long long held = 0;
// 10% of the time waiting: a saver with headroom; nothing to do.
runSlowSaver(g, 0, 120, 0.10, held);
CHECK(g.state() == GuardState::Normal);
// 50%: the bottleneck. Judged on half a minute at least, then slowed.
auto log = runSlowSaver(g, 122, 200, 0.50, held);
CHECK(g.state() == GuardState::Slowed);
CHECK(logged(log, "of the last minute"));
// The pace follows what saving takes: 1.5 x 4.6 s = 6.9 s, not 2 x 2 s.
CHECK(g.intervalScale() == doctest::Approx(1.5 * 4600.0 / 2000.0));
CHECK(logged(log, "one picture every 6.9 s instead of 2.0"));
}
TEST_CASE("slowed, but saving still the bottleneck: paused; with headroom: back to normal") {
ThermalParams p;
{
ThermalGuard g(p);
long long held = 0;
long long s = 0; // when it slowed
while (g.state() == GuardState::Normal && s < 120) {
s += 2;
runSlowSaver(g, s, s, 0.5, held);
}
REQUIRE(g.state() == GuardState::Slowed);
// Judged only once a minute of slowed pictures is in the window, then
// held_pause_s of it.
runSlowSaver(g, s + 2, s + 60 + p.held_pause_s - 4, 0.5, held);
CHECK(g.state() == GuardState::Slowed);
auto log = runSlowSaver(g, s + 60 + p.held_pause_s - 2, s + 60 + p.held_pause_s + 4,
0.5, held);
CHECK(g.state() == GuardState::Paused);
CHECK(logged(log, "even slowed"));
}
{
ThermalGuard g(p);
long long held = 0;
runSlowSaver(g, 0, 60, 0.5, held);
REQUIRE(g.state() == GuardState::Slowed);
// The slower pace gave saving its headroom: no waiting at all. But a
// save still 4.6 s long does not fit the 2 s pace, so going back would
// only overload again: it stays slowed, at a pace it can hold, no flapping.
runSlowSaver(g, 62, 62 + 60 + p.calm_s, 0.0, held);
CHECK(g.state() == GuardState::Slowed);
// Saving fast again (the CPU cooled, the load went): back to normal.
long long t = 62 + 60 + p.calm_s + 2;
runSlowSaver(g, t, t + p.calm_s + 4, 0.0, held, 1000.0);
CHECK(g.state() == GuardState::Normal);
}
}
TEST_CASE("the slowed pace never goes past 10x, and remembers the save time through a pause") {
ThermalGuard g;
long long held = 0;
runSlowSaver(g, 0, 60, 0.5, held, 60000.0); // a minute per picture
REQUIRE(g.state() == GuardState::Slowed);
CHECK(g.intervalScale() == doctest::Approx(10.0));
}
TEST_CASE("missing readings are left out of the rules, not taken as zero or as hot") {
ThermalGuard g;
for (long long t = 0; t < 600; t += 2) {
HostReading r;
r.now_ms = t * 1000;
auto log = g.update(r);
CHECK(log.empty());
}
CHECK(g.state() == GuardState::Normal);
}
TEST_CASE("thermal off keeps full pace; thermal resume clears a pause") {
ThermalParams p;
ThermalGuard g(p);
run(g, 0, p.pause_after_s + 2, 95.0);
REQUIRE(g.state() == GuardState::Paused);
auto log = g.forceResume(30000);
CHECK(g.state() == GuardState::Normal);
CHECK_FALSE(log.empty());
// Still hot: the rules apply afresh - slowed at once, paused after pause_after_s.
g.update(at(32, 95.0));
CHECK(g.state() == GuardState::Slowed);
run(g, 34, 32 + p.pause_after_s, 95.0);
CHECK(g.state() == GuardState::Paused);
g.setEnabled(false, 100000);
CHECK_FALSE(g.enabled());
CHECK(g.state() == GuardState::Normal);
run(g, 100, 1000, 99.0);
CHECK(g.state() == GuardState::Normal);
g.setEnabled(true, 1002000);
g.update(at(1004, 99.0));
CHECK(g.state() == GuardState::Slowed);
}
TEST_CASE("throttling is logged when it starts, summarised once a minute, and when it ends") {
ThermalGuard g;
// Counters still: nothing.
auto log = run(g, 0, 10, 80.0, 100);
CHECK_FALSE(g.throttle().throttling());
CHECK(log.empty());
// The counter rises: one start line, with the temperature and clock.
log = g.update(at(12, 90.0, 103));
CHECK(g.throttle().throttling());
CHECK(logged(log, "CPU is slowing itself to stay cool: 90 \xC2\xB0""C, running at 2.8 GHz of 3.6 GHz"));
CHECK(g.state() == GuardState::Slowed);
// Rising every sample for 70 s: exactly one summary.
int summaries = 0;
long long count = 103;
for (long long t = 14; t <= 82; t += 2) {
count += 2;
for (const auto& l : g.update(at(t, 90.0, count)))
if (l.second.find("CPU still slowed") != std::string::npos) ++summaries;
}
CHECK(summaries == 1);
CHECK(g.throttle().eventsLastMinute() > 0);
// Counter stops: the end line comes after a quiet minute, not before.
log = run(g, 84, 140, 80.0, count);
CHECK(g.throttle().throttling());
CHECK_FALSE(logged(log, "no longer slowed"));
log = run(g, 142, 146, 80.0, count);
CHECK_FALSE(g.throttle().throttling());
CHECK(logged(log, "CPU no longer slowed: 80 \xC2\xB0""C"));
}
TEST_CASE("throttling is inferred from a low clock while busy, as a capped or power-limited CPU shows") {
ThermalGuard g;
auto slow = [](long long t, double busy) {
HostReading r = at(t, 70.0);
r.count_ok = false; // no kernel counters on this host
r.mhz = 800;
r.busy_pct = busy;
return r;
};
// Low clock while idle is just an idle CPU.
for (long long t = 0; t < 20; t += 2) g.update(slow(t, 5));
CHECK_FALSE(g.throttle().throttling());
// One busy sample may be the governor catching up; two are not.
auto log = g.update(slow(20, 90));
CHECK_FALSE(g.throttle().throttling());
log = g.update(slow(22, 90));
CHECK(g.throttle().throttling());
CHECK(g.throttle().cause() == "clock");
CHECK(logged(log, "judged from its clock"));
}
TEST_CASE("a throttle counter that goes backwards is a fresh start, not throttling") {
ThermalGuard g;
g.update(at(0, 70.0, 500));
auto log = g.update(at(2, 70.0, 3));
CHECK_FALSE(g.throttle().throttling());
CHECK(log.empty());
}
TEST_CASE("host readers on a fake sysfs tree") {
FakeSys s;
s.put("sys/class/thermal/thermal_zone0/temp", "48000\n");
s.put("sys/class/thermal/thermal_zone0/type", "acpitz\n");
s.put("sys/class/thermal/thermal_zone1/temp", "91500\n");
s.put("sys/class/thermal/thermal_zone1/type", "x86_pkg_temp\n");
for (int c = 0; c < 4; ++c) {
const std::string cpu = "sys/devices/system/cpu/cpu" + std::to_string(c) + "/";
s.put(cpu + "cpufreq/scaling_cur_freq", std::to_string(1000000 + c * 200000) + "\n");
s.put(cpu + "cpufreq/cpuinfo_max_freq", "3600000\n");
s.put(cpu + "cpufreq/scaling_max_freq", c == 2 ? "1600000\n" : "3600000\n");
s.put(cpu + "thermal_throttle/package_throttle_count", "7\n");
s.put(cpu + "thermal_throttle/core_throttle_count", "1\n");
}
s.put("sys/devices/system/cpu/cpufreq/policy0/scaling_cur_freq", "999\n"); // not a core
s.put("proc/stat", "cpu 100 0 50 800 50 0 0 0 0 0\ncpu0 1 2 3 4\n");
const std::string root = s.root.string();
auto th = hostmetrics::readThermal(root);
REQUIRE(th.ok);
CHECK(th.max_temp_c == doctest::Approx(91.5));
CHECK(th.hottest_zone == "x86_pkg_temp");
CHECK(th.cpu_temp_c == doctest::Approx(91.5));
// A Wi-Fi card hotter than the CPU (the towers list iwlwifi_1): the hottest
// zone is the card, but the CPU guard still reads the CPU package.
s.put("sys/class/thermal/thermal_zone2/temp", "97000\n");
s.put("sys/class/thermal/thermal_zone2/type", "iwlwifi_1\n");
th = hostmetrics::readThermal(root);
CHECK(th.hottest_zone == "iwlwifi_1");
CHECK(th.cpu_zone == "x86_pkg_temp");
CHECK(th.cpu_temp_c == doctest::Approx(91.5));
auto f = hostmetrics::readCpuFreq(root);
REQUIRE(f.ok);
CHECK(f.core_mhz.size() == 4);
CHECK(f.core_mhz[0] == doctest::Approx(1000.0));
CHECK(f.mean_mhz == doctest::Approx(1300.0));
CHECK(f.hw_max_mhz == doctest::Approx(3600.0));
CHECK(f.cap_mhz == doctest::Approx(1600.0));
auto c = hostmetrics::readThrottleCount(root);
REQUIRE(c.ok);
CHECK(c.events == 7 + 4); // the package once, every core
auto t = hostmetrics::readCpuTimes(root);
REQUIRE(t.ok);
CHECK(t.total == 1000);
CHECK(t.busy == 150);
// A tree without proc/stat reads the real one: busy % stays real in a simulation.
fs::remove(s.root / "proc/stat");
CHECK(hostmetrics::readCpuTimes(root).ok);
// Nothing there: not ok, no throw.
CHECK_FALSE(hostmetrics::readCpuFreq("/nonexistent-fgc").ok);
CHECK_FALSE(hostmetrics::readThrottleCount("/nonexistent-fgc").ok);
CHECK(hostmetrics::readCpuTimes("/nonexistent-fgc").ok); // the real /proc/stat
CHECK_FALSE(hostmetrics::readThermal("/nonexistent-fgc").ok);
}
TEST_CASE("[Thermal] config: defaults, overrides and the order of the limits") {
AppConfig d = ConfigLoader::fromMap({});
CHECK(d.thermal.enabled);
CHECK(d.thermal.sysfs_root == "/");
CHECK(d.thermal.slow_c == doctest::Approx(85.0));
CHECK(d.thermal.pause_c == doctest::Approx(92.0));
CHECK(d.thermal.resume_c == doctest::Approx(75.0));
CHECK_FALSE(d.features.mock_camera_full);
AppConfig c = ConfigLoader::fromMap({{"Thermal.slow_c", "80"},
{"Thermal.pause_c", "88"},
{"Thermal.resume_c", "70"},
{"Thermal.slow_factor", "3"},
{"Thermal.sysfs_root", "/tmp/fake"},
{"Thermal.enabled", "false"},
{"Features.mock_camera_size", "full"}});
CHECK_FALSE(c.thermal.enabled);
CHECK(c.thermal.slow_c == doctest::Approx(80.0));
CHECK(c.thermal.slow_factor == doctest::Approx(3.0));
CHECK(c.thermal.sysfs_root == "/tmp/fake");
CHECK(c.features.mock_camera_full);
CHECK_THROWS(ConfigLoader::fromMap({{"Thermal.slow_c", "95"}})); // above pause_c
CHECK_THROWS(ConfigLoader::fromMap({{"Thermal.resume_c", "90"}})); // above slow_c
CHECK_THROWS(ConfigLoader::fromMap({{"Thermal.slow_factor", "0.5"}}));
CHECK_THROWS(ConfigLoader::fromMap({{"Thermal.held_pause_s", "10"}})); // under held_slow_s
CHECK_THROWS(ConfigLoader::fromMap({{"Thermal.sample_ms", "10"}}));
CHECK_THROWS(ConfigLoader::fromMap({{"Features.mock_camera_size", "huge"}}));
}
TEST_CASE("Health payload: unknown readings are null, numbers rounded") {
HealthReport h;
h.tower = "t121";
h.state = "paused";
h.reason = "CPU at 93 \xC2\xB0""C for 20 s";
h.cpu_c_ok = true;
h.cpu_c = 93.04;
h.cpu_mhz_ok = true;
h.cpu_mhz = 1187.6;
h.throttling = true;
h.throttle_events_last_min = 14;
h.interval_s = 10.0;
h.held_s = 3;
h.timestamp_ms = 1700000000000;
const std::string j = healthJson(h);
CHECK(j.find("\"state\":\"paused\"") != std::string::npos);
CHECK(j.find("\"cpu_c\":93.0") != std::string::npos);
CHECK(j.find("\"cpu_mhz\":1188") != std::string::npos);
CHECK(j.find("\"cpu_busy_pct\":null") != std::string::npos);
CHECK(j.find("\"enclosure_c\":null") != std::string::npos);
CHECK(j.find("\"save_ms_mean\":null") != std::string::npos);
CHECK(j.find("\"throttling\":true") != std::string::npos);
CHECK(j.find("\"throttle_events_last_min\":14") != std::string::npos);
CHECK(j.find("\"interval_s\":10.0") != std::string::npos);
CHECK(j.find("\"time\":1700000000000") != std::string::npos);
CHECK(j.front() == '{');
CHECK(j.back() == '}');
}
TEST_CASE("the CPU guard's commands work in every mode") {
CHECK(allowedIn(Mode::Auto, "thermal"));
CHECK(allowedIn(Mode::Pan, "thermal resume"));
CHECK(allowedIn(Mode::Auto, "thermal off"));
}
TEST_CASE("busy percent between two /proc/stat reads") {
auto a = hostmetrics::parseProcStatCpu("cpu 100 0 100 700 100 0 0 0\n");
auto b = hostmetrics::parseProcStatCpu("cpu 400 0 100 1000 100 0 0 0\n");
CHECK(hostmetrics::busyPercent(a, b) == doctest::Approx(50.0));
CHECK(hostmetrics::busyPercent(a, a) == doctest::Approx(-1.0));
CHECK(hostmetrics::busyPercent({}, b) == doctest::Approx(-1.0));
CHECK_FALSE(hostmetrics::parseProcStatCpu("intr 1 2 3\n").ok);
}