Report placement time and decision time separately, because only one of them is ours
Jorijn: "response times this run tanked", and then, sharply, "are you sure its back? or has it always been like this." It has always been like this, and the number was never measuring the daemon. The client's wall clock starts when the verify request starts, so it includes however long the user takes to get a finger onto the sensor. In the run that prompted the question the slow presses spent two seconds and more watching an EMPTY sensor -- ten consecutive frames at metric 129 to 142 against a 133 idle floor -- and then matched on the very first frame that had contact in it. Every matched press in that run reads "press 1: 1 frames -> MATCH". Not one needed a retry. The presses that felt instant were the ones where a finger was already down when the request started, and the presses that felt slow were the ones where it was not. So the loop now times from first contact as well as from the start, and says so in as many words. A figure that silently includes human reaction time cannot be compared between runs, between people, or against a phone.
This commit is contained in:
parent
07dd7dd4d2
commit
eb50e5b6fb
1 changed files with 17 additions and 0 deletions
|
|
@ -1378,6 +1378,10 @@ public:
|
||||||
// spend a verdict on. A press made only of these is a "try again", not
|
// spend a verdict on. A press made only of these is a "try again", not
|
||||||
// a rejection.
|
// a rejection.
|
||||||
int skippedUnsettled = 0;
|
int skippedUnsettled = 0;
|
||||||
|
// Split the latency: everything before contact is the user placing a
|
||||||
|
// finger, everything after is this daemon.
|
||||||
|
int msToContact = 0;
|
||||||
|
int msFromContact = 0;
|
||||||
};
|
};
|
||||||
|
|
||||||
// `accept` is the set of fids that count as a match for THIS request. The
|
// `accept` is the set of fids that count as a match for THIS request. The
|
||||||
|
|
@ -1412,6 +1416,12 @@ public:
|
||||||
int pressFrames = 0, rescans = 0, skipped = 0;
|
int pressFrames = 0, rescans = 0, skipped = 0;
|
||||||
std::uint32_t pressFid = 0;
|
std::uint32_t pressFid = 0;
|
||||||
auto t0 = std::chrono::steady_clock::now();
|
auto t0 = std::chrono::steady_clock::now();
|
||||||
|
// When contact first appeared. The wall clock a client sees starts when
|
||||||
|
// the REQUEST starts, so it is dominated by how long the user takes to
|
||||||
|
// get a finger onto the sensor -- measured at 2 s and more, against a
|
||||||
|
// match that lands on the first contact frame. Timing from contact is
|
||||||
|
// the only figure that says anything about the daemon.
|
||||||
|
std::optional<std::chrono::steady_clock::time_point> tContact;
|
||||||
auto msSince = [&](auto t) {
|
auto msSince = [&](auto t) {
|
||||||
return std::chrono::duration_cast<std::chrono::milliseconds>(
|
return std::chrono::duration_cast<std::chrono::milliseconds>(
|
||||||
std::chrono::steady_clock::now() - t).count();
|
std::chrono::steady_clock::now() - t).count();
|
||||||
|
|
@ -1431,6 +1441,7 @@ public:
|
||||||
bool finger = baseline_.IsFinger(c.metric);
|
bool finger = baseline_.IsFinger(c.metric);
|
||||||
// A press begins only once contact is settled; see TouchTracker.
|
// A press begins only once contact is settled; see TouchTracker.
|
||||||
bool settled = baseline_.IsSettled(c.metric);
|
bool settled = baseline_.IsSettled(c.metric);
|
||||||
|
if (finger && !tContact) tContact = std::chrono::steady_clock::now();
|
||||||
fingerPresent_.store(finger);
|
fingerPresent_.store(finger);
|
||||||
out.frames++;
|
out.frames++;
|
||||||
if (finger && !settled && !tracker.FingerDown()) skipped++;
|
if (finger && !settled && !tracker.FingerDown()) skipped++;
|
||||||
|
|
@ -1533,6 +1544,12 @@ public:
|
||||||
out.frames, msSince(t0),
|
out.frames, msSince(t0),
|
||||||
out.frames ? msSince(t0) / out.frames : 0, g_frameGapMs,
|
out.frames ? msSince(t0) / out.frames : 0, g_frameGapMs,
|
||||||
skipped ? std::format(", {} unsettled frame(s) skipped", skipped) : "");
|
skipped ? std::format(", {} unsettled frame(s) skipped", skipped) : "");
|
||||||
|
if (tContact) {
|
||||||
|
out.msToContact = static_cast<int>(msSince(t0) - msSince(*tContact));
|
||||||
|
out.msFromContact = static_cast<int>(msSince(*tContact));
|
||||||
|
std::println(" timing: {} ms waiting for a finger, {} ms deciding once it was there",
|
||||||
|
out.msToContact, out.msFromContact);
|
||||||
|
}
|
||||||
out.skippedUnsettled = skipped;
|
out.skippedUnsettled = skipped;
|
||||||
if (cancel) {
|
if (cancel) {
|
||||||
SendCommand(app_, ta::Cmd::Cancel, {});
|
SendCommand(app_, ta::Cmd::Cancel, {});
|
||||||
|
|
|
||||||
Loading…
Reference in a new issue