Closed Bug 2066420 Opened 13 days ago Closed 5 days ago

update.status_error_code_*_startup has recorded no updater error code since bug 1928229

Categories

(Toolkit :: Application Update, defect)

defect

Tracking

()

RESOLVED FIXED
157 Branch
Tracking Status
firefox-esr115 --- wontfix
firefox-esr140 --- wontfix
firefox-esr153 --- affected
firefox154 --- wontfix
firefox155 --- wontfix
firefox156 --- wontfix
firefox157 --- fixed

People

(Reporter: jstutte, Assigned: jstutte)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: regression)

Attachments

(1 file)

update.status_error_code_complete_startup, ..._partial_startup and
..._unknown_startup only ever record the three codes that
UpdateService.sys.mjs synthesizes itself: 90 ERR_OLDER_VERSION_OR_SAME_BUILD,
91 ERR_UPDATE_STATE_NONE and 92 ERR_CHANNEL_CHANGE. No code coming from
updater.exe has been recorded since Firefox 136.

#asyncInit reads update.status and immediately discards everything after the
colon:

let statusParts = status.split(":");
status = statusParts[0];

https://searchfox.org/firefox-main/rev/2c35ff84ed7d1ca088a41f830bfab0be50868536/toolkit/mozapps/update/UpdateService.sys.mjs#2854

and that truncated string is what reaches pingStateAndStatusCodes():

https://searchfox.org/firefox-main/rev/2c35ff84ed7d1ca088a41f830bfab0be50868536/toolkit/mozapps/update/UpdateService.sys.mjs#3096

Inside, the error-code ping sits behind if (parts.length > 1), which is now
never true for a status read off disk, so AUSTLMY.pingStatusErrorCode() is
unreachable from there:

https://searchfox.org/firefox-main/rev/2c35ff84ed7d1ca088a41f830bfab0be50868536/toolkit/mozapps/update/UpdateService.sys.mjs#1938
https://searchfox.org/firefox-main/rev/2c35ff84ed7d1ca088a41f830bfab0be50868536/toolkit/mozapps/update/UpdateService.sys.mjs#1943

The only callers still passing a colon are the three that build the string
explicitly, e.g. STATE_FAILED + ": " + ERR_UPDATE_STATE_NONE, which is exactly
what the data shows.

The split was added by bug 1928229 (landed 2025-01-14, Firefox 136) to feed a new
switch (status). The code is still parsed a little later into
update.errorCode, so the information is available and never used for the
histogram. Passing the untruncated status to pingStateAndStatusCodes() should be
enough.

..._stage is unaffected: refreshUpdateStatus() passes the raw status, and
those probes do carry real updater codes.

Evidence from GLAM per-version aggregates
(mozdata.glam_etl.glam_fog_release_aggregates, Windows, build_id = '*') for
update_status_error_code_partial_startup. Counts are the 10% sample:

version   updater codes (1-79)   JS codes (>= 89)
137                          0             773046
145                          0             902309
150                          0            1069976
153                          0             446151
154                          0               1730

Zero updater codes on every release version GLAM still retains. Meanwhile
update_state_code_partial_startup on 153 shows the failures do reach this code
path: 8.38M STATE_SUCCEEDED, 2.67M STATE_DOWNLOADING, 2.23M STATE_FAILED.
Failure volume is observable, the reason never is.

Impact: the non-staged apply path has no error telemetry at all. That is exactly
the path the fixes under bug 2061897 change, since bug 2058860, bug 2060275 and
bug 1661556 are all explicit no-ops for staged updates. The ..._stage probes
that work cannot show their effect, and the probes that should are empty.

One thing to expect once this is fixed: WRITE_ERROR_DELETE_FILE (62) is
currently 0 in every probe and every version for an unrelated reason,
ensure_remove returning a raw errno rather than a status (bug 2063337, partly
addressed by the drive-by in bug 2058860). So 62 appearing will be a labelling
change, not a new failure mode.

Set release status flags based on info from the regressing bug 1928229

:bytesized, since you are the author of the regressor, bug 1928229, could you take a look? Also, could you set the severity field?

For more information, please visit BugBot documentation.

Confirmed against current mozilla-central; the analysis in comment 0 holds.

Root cause: toolkit/mozapps/update/UpdateService.sys.mjs splits the status file and reassigns status = statusParts[0] immediately after readStatusFile(), and that truncated value is what reaches pingStateAndStatusCodes(). Inside, the error-code ping is gated on parts.length > 1, so AUSTLMY.pingStatusErrorCode() is unreachable for any status read off disk — only the three call sites that build STATE_FAILED + ": " + … explicitly (1, 2, 3) still reach it, matching the GLAM data.

Regressor confirmed: changeset f8f9415606c005f4452b2d7c460fb81b911ff17d (bug 1928229, 2025-01-14, Firefox 136). It added the split at the top of #asyncInit and deleted the equivalent split that previously lived at what is now line 3210 — i.e. after the ping call — so the ping used to receive "failed: <code>" and now receives "failed". The staged path is unaffected because #refreshUpdateStatus() still pings before splitting.

Proposed fix:

  1. Keep the untruncated string in #asyncInit (e.g. const rawStatus = readStatusFile(readyUpdateDir); let status = rawStatus.split(":")[0];) and pass rawStatus at the :3096 call site. All the switch (status) / status == comparisons and statusParts[1] keep working unchanged.
  2. Optional hardening in the same patch: change the gate in pingStateAndStatusCodes() from parts.length > 1 to keying on parts[0] == STATE_FAILED, so a failed status with no code records INVALID_UPDATER_STATUS_CODE rather than recording nothing. That makes a future re-truncation visible in the data instead of silent, but it also changes the _stage probes, so it's a reviewer call whether to include it. UpdateTelemetry.sys.mjs itself needs no change.

Tests: nothing in the tree asserts update.status_error_code_* today. tests/unit_aus_update/updateFailureFallBack.js already writes a real "failed: 7" status and runs post-update processing, so it's the cheapest place to add a testGetValue() assertion on Glean.update.statusErrorCodePartialStartup; initialStateValidation.js is the parameterized alternative, and accessAndLockout.js has the existing pattern for asserting an update Glean metric on the startup path. Not built or run — this is from reading the code.


Suggested severity: S3
No direct user impact — the updater behaves the same and only telemetry is lost — but every non-staged apply failure has been unattributable since Firefox 136 on all platforms, which blocks measuring the fixes tracked under bug 2061897.


If you'd like to provide feedback on this comment, please use the 👍 or 👎 reaction.
If you want to categorize your feedback you can add one of the following tags: ai-triage-wrong-file, ai-triage-wrong-cause, ai-triage-hallucination, ai-triage-out-of-scope.

(In reply to BugBot [:suhaib / :marco] from comment #1)

Set release status flags based on info from the regressing bug 1928229

:bytesized, since you are the author of the regressor, bug 1928229, could you take a look? Also, could you set the severity field?

I'm afraid I don't work on Application Update anymore.

Flags: needinfo?(bytesized)

As hackbot agrees, I asked it also to provide the fix.

#asyncInit() split update.status and reassigned status = statusParts[0]
immediately after readStatusFile(), so the truncated state (ex. "failed"
instead of "failed: 7") was what reached pingStateAndStatusCodes(). There the
error-code ping was gated on parts.length > 1, which is never true for a status
read off disk, so AUSTLMY.pingStatusErrorCode() was unreachable and
update.status_error_code_{complete,partial,unknown}_startup only ever recorded
the three codes UpdateService.sys.mjs synthesizes itself (90, 91, 92).

Bug 1928229 introduced this by moving the split from after the ping call to the
top of #asyncInit. The staged path was unaffected because
#refreshUpdateStatus() still pings before splitting.

Keep the untruncated string as rawStatus and pass that at the ping call site.
All the switch (status) / status == comparisons and statusParts[1] uses are
unchanged.

Also key the error-code ping on parts[0] == STATE_FAILED rather than
parts.length > 1, so a failed status carrying no code records
INVALID_UPDATER_STATUS_CODE instead of recording nothing. That matches what
#refreshUpdateStatus() already does for update.errorCode, and it means a
future re-truncation shows up in the data instead of silently emptying the probe.

Adds statusErrorCodeTelemetry.js, which asserts the recorded samples for a
partial and a complete patch, for a failed status with no code, and for a
non-failed status. Nothing in the tree asserted these probes before.

Verified against an artifact build: the new test fails without the
UpdateService.sys.mjs change ({count:0,sum:0} instead of {count:1,sum:7}) and
passes with it (6/6 subtests). The rest of unit_aus_update is unchanged;
updateEnabledTelemetry.js crashes in my environment both with and without this
patch, so it is pre-existing and unrelated.

Assignee: nobody → jstutte
Status: NEW → ASSIGNED
See Also: → 2068198
Pushed by jstutte@mozilla.com: https://github.com/mozilla-firefox/firefox/commit/c5b820ff2995 https://hg.mozilla.org/integration/autoland/rev/46bf8c71ca4e Pass the untruncated update.status to pingStateAndStatusCodes() on the startup path. r=application-update-reviewers,cdupuis,yjuglaret
Status: ASSIGNED → RESOLVED
Closed: 5 days ago
Resolution: --- → FIXED
Target Milestone: --- → 157 Branch
See Also: → 2068687
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: