Fix Linux unit test failure in the wipe tower temperature trace comparison (#15161)

## Problem

`Toolchange temperature commands are unchanged when the wipe tower wait
is off`
(added in #15144) fails on both Linux runners and passes on Windows and
macOS.
It is the only failing test in the suite, and it has been failing on
main since
that PR merged.

| Job | Result |
| --- | --- |
| Windows x64 / Unit Tests | pass |
| Windows arm64 / Unit Tests | pass |
| macOS arm64 / Unit Tests | pass |
| Linux x86_64 / Unit Tests | **fail** |
| Linux aarch64 / Unit Tests | **fail** |

From the merge commit
([Linux
x86_64](https://github.com/OrcaSlicer/OrcaSlicer/actions/runs/31072382258/job/92531704095),
[Linux
aarch64](https://github.com/OrcaSlicer/OrcaSlicer/actions/runs/31072382258/job/92531704075)),
still reproducing on current main:

```
first difference at trace entry 29
  main:   M104 S240 T0 ; preheat T0 time: 31s	lead 30.9s
  branch: M104 S240 T0 ; preheat T0 time: 30s	lead 30.3s
```

## Cause

Each preheat entry records the same quantity twice: `lead` at one
decimal, and
`time:` inside the command text as that value rounded to a whole second.

`split_lead` already compares `lead` with a 0.5s tolerance and explains
why the
estimate moves. `time:` sits in the exactly-compared command text, so it
never
got that tolerance — and being rounded, it flips on a drift far below
0.5s
(30.4 and 30.6 render as `30s` and `31s`). Entry 29 is the only entry in
the
163-entry golden whose lead rounds up; every other preheat sits at
30.0–30.4 and
rounds down, which is why it is the only one that fails.

The variation is per-toolchain, not run to run. Both Linux arches
produce
exactly `lead 30.3s`; Windows x64/arm64 and macOS arm64 all produce
exactly
`30.9s`. Repeated local runs are byte-identical. macOS arm64 passing
while Linux
aarch64 fails rules out the ISA — it is floating-point accumulation over
a few
thousand move durations under GCC vs Clang vs MSVC.

The mechanism makes it discrete rather than gradual: the backtrace parks
the
preheat at the first exported line at least `preheat_time` before the
tool
change, so `lead` is `preheat_time` plus the leftover of whichever move
that
landed on. A sub-tenth difference selects the neighbouring move and
`lead` steps
by that move's whole duration.

Entries 1–28 match exactly, including five earlier preheats whose leads
fall
inside the existing tolerance, so the toolpaths themselves are
identical. I also
reverted the two prime-tower commits that landed between the golden's
capture
point and now, rebuilt, and got a byte-identical trace — this is not
behavioural
drift.

That also rules out regenerating the golden: no single capture satisfies
all
three toolchains, and recapturing on Linux would turn the three
currently-green
runners red.

## Fix

Test-only.

- `lead` keeps a tolerance, widened to 1.5s (measured drift 0.6s; a
preheat
actually leaving its backtrace position would move by tens of seconds).
- `time:` is **not** compared across runs at all. Being a rounding of
`lead`, it
carries nothing the tolerance does not already cover, and comparing it
across
runs can only reproduce the flake. It is instead checked against its own
  entry's `lead` — a correct rounding keeps `|time - lead| <= 0.5`.

That second point matters: simply tolerating `time:` numerically would
have made
the test blind to a real change, because drift and a wrong rounding both
move it
by 1. The self-consistency check keeps that coverage. I verified it by
changing
`(int) std::round(time_diffs[0])` to `(int) time_diffs[0]` in
`GCodeProcessor::export_lines` — the test fails with
`"time:" is not its entry's "lead" rounded to a whole second`, where a
plain
tolerance would have passed silently.

Everything else is still compared exactly: all M104/M109 values, tool
ids,
block markers, ordering, entry count, and the annotation text including
its
trailing `s`. The other 138 entries remain byte-exact.

No production code, no golden regeneration. The golden file and these
helpers
are used by this one test and nothing else, and the tolerance only
widens, so
Windows and macOS keep passing unchanged. A note is added to the
golden's header
so the next mismatch in those fields is not "fixed" by recapturing.

## How to verify

Before, on Linux:

```bash
git checkout main && ./build_linux.sh -t
ctest --test-dir build/tests -R "Toolchange temperature commands are unchanged" --output-on-failure
# fails at trace entry 29
```

After:

```bash
cmake --build build --config Release --target fff_print_tests
ctest --test-dir build/tests --output-on-failure     # 463/463
```
This commit is contained in:
Clifford
2026-08-07 08:26:18 -04:00
committed by GitHub
parent b5412221b6
commit 8e243faa3a
2 changed files with 85 additions and 15 deletions

View File

@@ -2,6 +2,11 @@
# captured from the main branch at a10d9e77cf. Regeneration is described
# at the test that reads this file: "Toolchange temperature commands are unchanged
# when the wipe tower wait is off" in tests/fff_print/test_multifilament.cpp.
#
# The "time:" and "lead" values are toolchain-specific -- GCC, Clang and MSVC each produce
# slightly different estimates from an identical toolpath -- so they are compared with a
# tolerance, not exactly. Do not regenerate this file to resolve a mismatch in them: no single
# capture satisfies all three, and recapturing just moves the failure to other platforms.
M104 S215 T0 ; set nozzle temperature
M104 S215 T1 ; set nozzle temperature
; CP PRIMING START

View File

@@ -17,6 +17,7 @@
#include <set>
#include <sstream>
#include <string>
#include <string_view>
#include <utility>
#include <vector>
@@ -165,28 +166,82 @@ static std::vector<std::string> temperature_trace(const std::string& gcode)
return trace;
}
// Splits a trace entry into its command text and the lead time appended after a tab, if any.
static std::pair<std::string, std::optional<double>> split_lead(const std::string& entry)
// "M104 S240 T0 ; preheat T0 time: 31s<TAB>lead 30.9s" carries the same quantity twice, and both
// vary by toolchain: the backtrace picks the first line at least preheat_time out, so a sub-tenth
// difference in the estimate selects a neighbouring move and "lead" steps by that move's duration.
// Tolerate "lead", still far below the tens of seconds a displaced preheat would shift it. Check
// "time:" against its own entry's "lead" instead of across runs -- being a rounding of it, that
// still catches a change in how it is derived without tracking the absolute estimate.
static constexpr double TRACE_TIME_TOLERANCE_S = 1.5;
static constexpr double TRACE_ROUNDING_SLACK_S = 0.05; // correct rounding keeps |time - lead| <= 0.5
struct TraceEntry
{
const size_t tab = entry.find('\t');
if (tab == std::string::npos)
return { entry, std::nullopt };
const std::string tail = entry.substr(tab + 1); // "lead 30.2s"
return { entry.substr(0, tab), std::stod(tail.substr(tail.find(' ') + 1)) };
std::string text; // timing values replaced by a placeholder
std::optional<double> time_s;
std::optional<double> lead_s;
};
static TraceEntry parse_trace_entry(const std::string& entry)
{
TraceEntry out;
std::string text = entry;
// Split off the tail only when it really is a "lead <n>s", so an unexpected one still compares.
const size_t tab = text.find('\t');
if (tab != std::string::npos) {
const std::string tail = text.substr(tab + 1); // "lead 30.2s"
const size_t sp = tail.find(' ');
if (sp != std::string::npos && sp + 1 < tail.size()
&& std::isdigit(static_cast<unsigned char>(tail[sp + 1]))) {
out.lead_s = std::stod(tail.substr(sp + 1));
text.erase(tab);
}
}
static constexpr std::string_view k_time = "time: ";
const size_t at = text.find(k_time);
// Require a digit first: a dots-only run would otherwise reach std::stod and throw.
if (at != std::string::npos && at + k_time.size() < text.size()
&& std::isdigit(static_cast<unsigned char>(text[at + k_time.size()]))) {
const size_t first = at + k_time.size();
size_t last = first;
while (last < text.size() && (std::isdigit(static_cast<unsigned char>(text[last])) || text[last] == '.'))
++last;
out.time_s = std::stod(text.substr(first, last - first));
text.replace(first, last - first, "<n>"); // surrounding text, incl. the "s", still compared
}
out.text = std::move(text);
return out;
}
// Same command, and a lead time within half a second. The lead is an estimate summed over every
// move before it, so it drifts slightly with unrelated changes to travel or tower geometry; half a
// second is far below the tens of seconds a preheat leaving its backtrace position would shift it.
static bool timings_match(const std::optional<double>& a, const std::optional<double>& b)
{
if (a.has_value() != b.has_value())
return false;
return !a.has_value() || std::abs(*a - *b) <= TRACE_TIME_TOLERANCE_S;
}
// "time:" must be its own entry's "lead" rounded to a whole second.
static bool time_is_rounded_lead(const TraceEntry& e)
{
if (!e.time_s.has_value() || !e.lead_s.has_value())
return true; // nothing to cross-check
return std::abs(*e.time_s - *e.lead_s) <= 0.5 + TRACE_ROUNDING_SLACK_S;
}
// `a` is the slice under test, `b` the recorded golden.
static bool trace_entries_match(const std::string& a, const std::string& b)
{
const auto x = split_lead(a);
const auto y = split_lead(b);
if (x.first != y.first)
const auto x = parse_trace_entry(a);
const auto y = parse_trace_entry(b);
if (x.text != y.text)
return false;
if (x.second.has_value() != y.second.has_value())
// A field appearing or disappearing is a real change even though the values are tolerated.
if (x.time_s.has_value() != y.time_s.has_value())
return false;
return !x.second.has_value() || std::abs(*x.second - *y.second) <= 0.5;
return timings_match(x.lead_s, y.lead_s) && time_is_rounded_lead(x);
}
// Tool index = filament id - 1; brim and skirt follow the wall filament.
@@ -617,6 +672,16 @@ TEST_CASE("Toolchange temperature commands are unchanged when the wipe tower wai
}
REQUIRE(!golden.empty());
// Reported separately from the golden comparison below: it is a different failure.
for (size_t i = 0; i < trace.size(); ++i) {
const auto entry = parse_trace_entry(trace[i]);
if (time_is_rounded_lead(entry))
continue;
INFO("at trace entry " << i + 1);
INFO(" " << trace[i]);
FAIL("\"time:\" is not its entry's \"lead\" rounded to a whole second");
}
const size_t common = std::min(trace.size(), golden.size());
for (size_t i = 0; i < common; ++i) {
if (trace_entries_match(trace[i], golden[i]))