Read the trustlet's own log, which on mainline means the response buffer

The matcher has been a black box that answers yes or no, and that is why "the
matcher saw a full-contact image of the enrolled finger and rejected it" went a
whole session with no explanation.

There is no tzdbg on mainline -- /sys/kernel/debug/tzdbg does not exist on this
kernel -- so the /proc/tzdbg/qsee_log route that captured the Android reference
log is unavailable, and the qcomtee qseelog ring is on record as wedging TZ. But
focal64 writes its log into the response buffer, which is how the research
harness printed it all along. --ta-log scans it, so the matcher's own verdicts
are readable on pmOS: auth success score, identify fail with the
FtVerifyByTemplate return, and the per-frame image quality, coverage and
humidity.

Turning it on taught three things, all of which are configuration rather than
code.

A log level is not enough. The trustlet answered "no key named
diagnosis.enable_algorithm_log, use default value" -- that switch and two
siblings are separate on/off gates that stock sets on and we had never sent at
all, so the algorithm log level was being applied to a stream that was off.

Lower is more verbose and 6 is off: level 0 produced 244 lines where 5 produced
far fewer. That settles a direction the config generator explicitly left open,
and it means the old verbose setting of 5 was very nearly a quiet one.

The ring is the scarce resource. It is about 150 lines per session and is never
reset, so the config dump alone overflows it: at framework level 0 the dump
produced 244 lines and UPDATE_TEMPLATE's own lines never arrived. The shipped
verbose config now leaves the framework log off and the algorithm log at 0,
which cut the init ring to 38 lines and reserves it for the matcher. Framework
tracing is a separate run and cannot also have the matcher's lines, and the
level cannot be raised later because 6 is unrecoverable by a runtime SYNC_CONFIG.
This commit is contained in:
Jorijn van der Graaf 2026-09-03 17:46:20 +02:00
commit 21d6aa448c

View file

@ -108,6 +108,9 @@ bool g_edgeWake = false;
// one binary without a rebuild, which is the only way the comparison is // one binary without a rebuild, which is the only way the comparison is
// single-variable. // single-variable.
bool g_learn = true; bool g_learn = true;
// Dump the trustlet's own log out of the response buffer after every command.
// See DumpTaLog: on pmOS this is the ONLY way to read it.
bool g_taLog = false;
// How many frames one press may contribute. Stock has no explicit bound -- it // How many frames one press may contribute. Stock has no explicit bound -- it
// harvests until the finger lifts -- but a finger left resting on the sensor // harvests until the finger lifts -- but a finger left resting on the sensor
// should not grow the template without limit, and the template body has a hard // should not grow the template without limit, and the template body has a hard
@ -948,6 +951,8 @@ struct CommandResult {
bool Ok() const { return invoked && result == 0 && rc == 0; } bool Ok() const { return invoked && result == 0 && rc == 0; }
}; };
void DumpTaLog(std::span<const std::byte> buf); // defined below, with Report
CommandResult SendCommand(qcomtee_object* app, fingerprintd::ta::Cmd cmd, CommandResult SendCommand(qcomtee_object* app, fingerprintd::ta::Cmd cmd,
std::span<const std::byte> payload) { std::span<const std::byte> payload) {
namespace ta = fingerprintd::ta; namespace ta = fingerprintd::ta;
@ -1031,9 +1036,44 @@ CommandResult SendCommand(qcomtee_object* app, fingerprintd::ta::Cmd cmd,
out.fid = ta::MatchedFid(reqOut); out.fid = ta::MatchedFid(reqOut);
out.samplesRemaining = ta::SamplesRemaining(reqOut); out.samplesRemaining = ta::SamplesRemaining(reqOut);
} }
if (g_taLog) DumpTaLog(rspOut);
return out; return out;
} }
// THE TRUSTLET'S OWN LOG, and on pmOS the only way to read it.
//
// focal64 writes its log lines into the RESPONSE buffer, which is how the
// research harness printed them (`scan_ascii` in utilities/fpta.c). It matters
// because mainline has no tzdbg: /sys/kernel/debug/tzdbg does not exist on this
// kernel, so the /proc/tzdbg/qsee_log route that captured the reference log on
// Android is unavailable here, and the qcomtee `qseelog=1` ring is recorded as
// wedging TZ. Without this the matcher is a black box that answers only yes or
// no -- which is exactly why "the matcher saw a full-contact image of the
// enrolled finger and rejected it" went a whole session with no explanation.
//
// What it surfaces, given diagnosis.algorithm_log_level: `auth success
// score:0x...`, `focal_IdentifyByImage...identify fail! FtVerifyByTemplate() =
// -2`, and the per-frame `image quality = N, coverage = N, humidity = N`.
//
// The ring is ~150 lines per session and is never reset, so it repeats itself
// across commands. A targeted instrument, not something to leave on.
void DumpTaLog(std::span<const std::byte> buf) {
std::size_t i = 0, n = buf.size();
while (i < n) {
std::size_t j = i;
while (j < n) {
auto c = std::to_integer<unsigned char>(buf[j]);
if (!(c == '\n' || (c >= 0x20 && c < 0x7f))) break;
j++;
}
if (j - i >= 12)
std::println(" ta: {}",
std::string_view(reinterpret_cast<const char*>(buf.data() + i),
j - i));
i = (j > i) ? j : i + 1;
}
}
void Report(fingerprintd::ta::Cmd cmd, const CommandResult& r) { void Report(fingerprintd::ta::Cmd cmd, const CommandResult& r) {
namespace ta = fingerprintd::ta; namespace ta = fingerprintd::ta;
if (!r.invoked) { if (!r.invoked) {
@ -2460,6 +2500,7 @@ int main(int argc, char** argv) {
if (a.starts_with("--group-path=")) g_groupPath = a.substr(13); if (a.starts_with("--group-path=")) g_groupPath = a.substr(13);
if (a.starts_with("--samples=")) { g_samples = std::stoi(std::string(a.substr(10))); g_samplesForced = true; } if (a.starts_with("--samples=")) { g_samples = std::stoi(std::string(a.substr(10))); g_samplesForced = true; }
if (a.starts_with("--learn=")) g_learn = a.substr(8) != "0"; if (a.starts_with("--learn=")) g_learn = a.substr(8) != "0";
if (a == "--ta-log") g_taLog = true;
if (a.starts_with("--learn-frames=")) g_learnMaxFrames = std::stoi(std::string(a.substr(15))); if (a.starts_with("--learn-frames=")) g_learnMaxFrames = std::stoi(std::string(a.substr(15)));
if (a.starts_with("--sfs-root=")) g_sfsRoot = a.substr(11); if (a.starts_with("--sfs-root=")) g_sfsRoot = a.substr(11);
if (a.starts_with("--gid=")) gid = static_cast<std::uint32_t>(std::stoul(std::string(a.substr(6)))); if (a.starts_with("--gid=")) gid = static_cast<std::uint32_t>(std::stoul(std::string(a.substr(6))));
@ -2476,6 +2517,7 @@ int main(int argc, char** argv) {
" --probe-ta-load=PATH load one TA image and report the loader result\n" " --probe-ta-load=PATH load one TA image and report the loader result\n"
" --auth | --enrol | --cal-save diagnostic loops (see README)\n" " --auth | --enrol | --cal-save diagnostic loops (see README)\n"
" --probe-learn send one UPDATE_TEMPLATE, no finger needed\n" " --probe-learn send one UPDATE_TEMPLATE, no finger needed\n"
" --ta-log print the trustlet's own log lines\n"
" --learn=0|1 [--learn-frames=N] fold a matched press back into the\n" " --learn=0|1 [--learn-frames=N] fold a matched press back into the\n"
" template, as stock does (default on, 8)\n" " template, as stock does (default on, 8)\n"
" --sfs-root=DIR --sfs-writable --rpmb-write storage policy", " --sfs-root=DIR --sfs-writable --rpmb-write storage policy",