I thought I was measuring one thing, but I was actually measuring something else — I almost fixed something that didn’t need fixing

📝 Originally published (in Japanese) at forge.workstyle.tech.

A User Said

I tried it, and it didn't feel that bad, but are there any areas for improvement when looking at the logs?

I aggregated the conversation logs. The response time distribution was as follows:

Response time  Count: 16  Median: 3924ms  Max: 8294ms  Min: 1034ms
  Over 3 seconds: 9 cases / 16 cases

In order of slowness:
   8294ms  Explain this page
   8188ms  Can you explain the content?
   7523ms  Can you tell me more about that?

This product has a requirement to maintain a response time of 1.5-3 seconds. This was an explicit constraint stated by the user.
The median response time was 3.9 seconds, with 9 out of 16 cases exceeding 3 seconds, and a maximum response time of 8.3 seconds. This clearly violates the requirement.

I was about to report that "there are three bad points, especially the response time."

Verified the Contents of the Metrics

I started writing, but stopped. I hadn't verified what the numbers were measuring with code.

self._turn_started = time.monotonic()    # When the question was received
...
_elapsed = int((time.monotonic() - self._turn_started) * 1000)   # When the conversation log was recorded

The recorded value was the point at which one turn was completely finished. In other words, what was being measured was
"from receiving the question to generating and synthesizing the entire response".

The perceived responsiveness — from asking a question to hearing the first sound — is a completely different quantity.

Remasured

I took the difference between the time the question was received and the time the first speech synthesis started from the server logs.

Time from receiving the question to starting to speak  Count: 9  Median: 712ms  Max: 821ms  Min: 364ms
  Over 3 seconds: 0 cases / 9 cases

The median response time was 712ms, with no cases exceeding 3 seconds. This is well below the requirement.

The user's "not bad" was correct, and my interpretation was incorrect. The 8-second response time meant "speaking continuously for 8 seconds", not the waiting time.

If I had reported without verifying, I would have started unnecessary work to improve responsiveness. Moreover, I might have reduced other quality aspects by shortening the response or reducing processing.

Made Similar Mistakes Multiple Times on the Same Day

On this day, I made the same type of mistake four times.

What I thought I verified	What I actually verified
Response time	Time to finish speaking entirely
Effectiveness of self-echo countermeasures	Ability to process self-made frames
Ability to change VAD threshold	Ability to modify attributes of fake objects
Receipt of digging instructions	Presence of strings in prompts (which were actually being received)

All of these were "verified" in my mind. What I verified and what I wanted to verify were different.

Made Mistakes in the Opposite Direction on a Different Day

Something similar happened earlier. To verify if page transitions were occurring, I looked at the command issuance audit logs.

navigate  0 cases

I concluded that "no transitions were occurring" and started investigating the cause. This was a mistake.

The transition command was not being recorded in the audit logs at the time of issuance. Moreover, transitions leave the page, so the result reports are not received. In other words, even if successful, it is not recorded due to the design.

I was interpreting the lack of records as evidence that it was not happening. This was also a type of "verified in my mind", and I repeated it twice.

Generalizable Points

The name of a metric does not explain its contents.

elapsed_ms only says "elapsed time", without specifying what it measures from and to. In voice conversations, these two values can differ by several times.

Time from receiving the question to the first sound  712ms   ← Perceived responsiveness
Time from receiving the question to finishing speaking  3924ms   ← Value recorded in conversation logs

When the requirement says "1.5-3 seconds", it refers to the former. The latter is the length of the response, which can vary greatly.

Before making judgments based on metrics, verify what they measure with code. This is a task that can be completed in one minute, and in this case, it helped avoid unnecessary revisions.

Additionally, when seeing "0 cases", suspect observational gaps first. Is the target non-existent, or is it not being measured? On this day, I encountered both patterns.

Gate judgment log 0 cases  → It was not actually working (implementation defect)
Transition audit log  0 cases  → It was happening, but not being recorded (observational defect)

The method to distinguish between them was to measure again from a different axis. For the gate, I checked the frame type and found that "it was not being received", while for transitions, I added logs to the issuance side and found that "it was being issued".