Closed Bug 1959141 Opened 1 year ago Closed 1 year ago

Increase in invalid_label metric errors for the `event.longtask` on Fenix

Categories

(Toolkit :: Telemetry, defect, P1)

defect
Points:
2

Tracking

()

RESOLVED FIXED
139 Branch
Tracking Status
firefox139 --- fixed

People

(Reporter: janerik, Assigned: chutten)

References

(Blocks 2 open bugs)

Details

Attachments

(1 file)

We're seeing an increase in invalid_label metric errors for the event.longtask metric.

Error: invalid_label
Channel: Nightly
Date range: 2025-04-04 to 2025-04-30
Graph: https://sql.telemetry.mozilla.org/queries/105105/source?p_appid=org_mozilla_fenix&p_channel=nightly&p_date_range=2025-04-04--2025-04-30&p_error_type=invalid_label&p_metric=event.longtask#258708

See also the error reporting docs.

Labels must not exceed 71 characters in length, and may comprise any printable ASCII characters.

This is a migrated metric (bug 1956726)
I'm surprised we hit this.

Code is here: https://searchfox.org/mozilla-central/rev/9c6e9ca72d4a59267d985fb35ba259fb937c8503/xpcom/threads/nsThread.cpp#1496

The label is the name of the long-running task. Tasks often have static names (the longest of which is "InitializeVirtualDesktopManagerTask" at 36 characters), but there are three situations where the name is dynamic:

  1. HelperThreadTaskHandler will get a JS HelperThreadTask's name instead, which, upon inspection can only be one of a set of literals the longest of which appears to be "CompleteTier2GeneratorTask" at 27 characters.
  2. IdleTaskRunnerTask will use the name of the IdleTaskRunner (if present). These too, upon inspection, appear to be literals the longest of which appears to be "nsHtml5TreeOpExecutor::BackgroundFlushCallback" at 47 characters.
  3. RunnableTask will use the name of the underlying runnable if it's an nsINamed. There are 104 references to nsINamed::GetName in tree, and that doesn't include all the runnables that set their name on construction. I did a quick scan, and there are only 5 that don't just assign and return a literal:
    1. WorkerRunnable which has a huge type tree, all of which appears to use literals of which "PropagateStorageAccessPermissionGrantedRunnable" appears to be the longest (48 chars)
    2. GCLockWeakCallback which only uses literals like "MLSFallbackTimerFired"
    3. nsMediaEventRunner which only uses literals like "nsResolveOrRejectPendingPlayPromisesRunner"
    4. WrappedJSNamed which reports the result of GetFunctionName. These strings are either literals of various cases (e.g. "anonymous", "error") or constructed from function and file names and are like "setTimeout() for promiseWaitOnTimeout/this._timer<[TelemetrySend.sys.mjs]" (74 chars, over the limit (found in legacy telemetry from Desktop))
    5. Runnable which (via DiscardableRunnable -> CancelableRunnable -> MessageChannel::MessageTask) can contain IPC message names like "PBackgroundIDBDatabase::Msg_PBackgroundIDBVersionChangeTransactionConstructor" (78 chars, over the limit (found in legacy telemetry from Desktop))

So we have at least two subtypes of message that can (and do) have labels over the limit. What should we do about them?

I can see some options:

  1. Do Nothing. Let these just be failures and ignore them for the purposes of monitoring. Pros: Easiest option. Cons: It'll weaken the usefulness of this data and make it easier for non-acceptable errors to hide in its shadow.
  2. Extend the label limit so there's no more errors. Pros: No more errors, full resolution data. Cons: We no longer catch cases where long labels are erroneous or risky. We don't actually know what a new length should be that would protect us in the future (what is the longest future JS function name and filename combo? What is the longest future IPC message type name?)
    • Could make this an "unsafety valve" in the metric definition (e.g. max_label_length_override: 150) which'd put control in the instrumentors' hands, allaying some of the cons.
  3. Adjust all these names to be shorter. Pros: No more errors. Cons: Given the spidery nature of Runnable and Task in the codebase, this will likely be annoying to fix in the current tree. And it could be fragile (new stuff could break it).
  4. Adjust the instrumentation call to truncate. Pros: No more errors, current-best resolution of data, readably communicates in the code that long names are okay but long labels are not. Cons: Lose some resolution (e.g. "setTimeout() for scheduleCheckForUnsubmittedCrashReports/this._checkTimeout<[ContentCrashHandlers.sys.mjs]" becomes "setTimeout() for scheduleCheckForUnsubmittedCrashReports/this._checkTi" or "setTimeout() for scheduleCheckForUnsubmittedCrashReports/this._checkT..." if we use \u2026)
    • An optional possibility would be to add a TruncatedGet to labeled_* metrics to make this "unsafety valve" (for "we hereby acknowledge that we're making it impossible for you to help us catch over-length label errors" purposes) "official".
  5. Make it so labeled_* metrics' Get() functions truncate instead of erroring. Pros: No more errors. Cons: No more catching of errors. Not in keeping with most of the rest of the metrics API's philosophy.

My leaning is towards 4 with a hidden suboption of a C++-only MaybeTruncateAndGet API on LabeledTimingDistributionMetric plus a follow-up bug for considering adding that functionality to all labeled_* in the SDK (and, eventually, FOG). Thoughts: Florian, Jan-Erik, Travis?

Flags: needinfo?(jrediger)
Flags: needinfo?(florian)
Flags: needinfo?(tlong)

Option 4 seems best/easiest, especially if there's a single metric where we encounter this issue. If we expect the problem to happen several times, a C++ helper would make sense. It could alternatively be an optional parameter to the Get method.

Flags: needinfo?(florian)

Option 4 sounds good to me.

Flags: needinfo?(jrediger)

I agree, Option 4 gives the calling code discretion on how to truncation should occur

Flags: needinfo?(tlong)

A sidelong note that bug 1959696 ups the label limit to 111 (because it needs to be at least as long as maxlen(metric_category) + maxlen(metric_name) + 1 (for the delimiter)) which might take care of the current crop of overages once it's released and vendored.

But for now (and for the future where even longer labels may show up) I'll write a quick MaybeTruncateAndGet for C++ that uses the current 71-char limit.

Assignee: nobody → chutten
Severity: -- → S4
Status: NEW → ASSIGNED
Points: --- → 2
Component: XPCOM → Telemetry
Priority: -- → P1
Product: Core → Toolkit
See Also: → 1959696
Blocks: 1959765

It is expected and allowed both that task names can be long and that analysis
can be performed on the truncated values.

Pushed by chutten@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/303fc19db920 Truncate event.longtask labels before use r=florian
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 139 Branch
QA Whiteboard: [qa-triage-done-c140/b139]
Blocks: 1956726
No longer depends on: 1956726
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: