Closed Bug 1771776 Opened 3 years ago Closed 3 years ago

Always add the script name to DOM Worker's thread names, and other labels

Categories

(Core :: Gecko Profiler, enhancement, P3)

enhancement

Tracking

()

RESOLVED FIXED
103 Branch
Tracking Status
firefox103 --- fixed

People

(Reporter: julienw, Assigned: mstange)

References

Details

Attachments

(1 file)

While looking at a profile, we found difficult to identify which JS file was running in a DOM Worker thread. It could be good to have this information in some way, possibly by appending it to its name. I don't know how to get this information so this may be difficult to get at that location.

The same worker thread can be re-used with different script files. That's why we put the script name in the profiler label and not in the thread name. But maybe it would be better to just rename the thread every time a new script uses it, and then you would just see the last script name that used that thread.

(In reply to Markus Stange [:mstange] from comment #1)

The same worker thread can be re-used with different script files. That's why we put the script name in the profiler label and not in the thread name. But maybe it would be better to just rename the thread every time a new script uses it, and then you would just see the last script name that used that thread.

Mmm I don't see this information in https://share.firefox.dev/3GvmVNz. In that case there's no JS frame, and so we don't have a filename. Am I missing something?

I also looked at another DOM Worker from chat.mozilla.org, I don't see a Profiler Labels, however because we have JS frames we can see their filenames this time, so it's probable OK in this case.

Hmm, interesting. This is the line that creates the label: https://searchfox.org/mozilla-central/rev/7751fef9eeb3db0a07ae4680daa2a62bd8f49882/dom/workers/RuntimeService.cpp#1984-1985
And I can see WorkerThreadPrimaryRunnable::Run on the stack in the profile. But the label frame is not there!

Based on comment #2 and comment #3, it seems we may have a real issue with missing labels. I'm changing the bug type from "Enhancement" to "Defect", and rewording the title accordingly. To be investigated...

Severity: -- → S3
Type: enhancement → defect
Priority: -- → P2
Summary: Add the script name to DOM Worker's thread names → DOM Worker's label (with script name) is not visible in stacks

(In reply to Julien Wajsberg [:julienw] from comment #5)

I see a profiler_is_active check when adding the label, is that expected?
https://searchfox.org/mozilla-central/rev/32ca4fc265150e7d3d7aa6c6abea088768cf024b/tools/profiler/public/ProfilerLabels.h#161

Good eye! It means that if the worker runnable started before the profiling session, there won't be a label there -- which seems to be the case in your profile https://share.firefox.dev/3GvmVNz .
This is done to avoid the overhead of getting+converting+storing the string. I'm not sure there would be a good way around that; maybe the AUTO_PROFILER_LABEL_DYNAMIC... call could be given a lambda, to only run this expensive operation if the profiler is already running, or when it starts running? 🤔

So let's go back at the various use cases.

Use case 1: a DOM Worker is created while the profiler is running => in that case we'd have a frame label with the file name with the current code.
Use case 2: a DOM Worker is created before the profiler is running, but ends before the profiler stops => in that case, we don't have a frame label, but maybe a RAII marker could help? Or can we add a frame label when going out of a scope?
Use case 3: a DOM Worker is created before the profiler is running, and ends after the profiler stops => in that case, a RAII marker wouldn't work. Then having the name of the (last?) file in the thread name would help.
Use case 4: while the profiler is running, the same DOM Worker thread is used for several actual DOM Workers => both 1 and 2 would work for this case.

Then a combination of all these changes would support all use cases, with the inconvenient of having very different behaviors for different use cases:

Frame label: works for use case 1, and use case 4 (except the first DOM worker if it was running before the start of the profile).
RAII marker: works for use cases 1, 2, 4.
Adding the file name to the thread name: works for use case 1, 2 (unless another DOM Worker uses the same thread), 3.

Thoughts?

Thank you Julien for the list.

Don't forget use case 0: DOM workers are created, but the profiler never runs => We want the minimal amount of CPU&memory usage.
I think it's important to keep that one in mind, while we try to improve the situation for those other use cases when the profiler runs.

As you noted, the possible solutions you propose are indeed different, which may be confusing (say, if we only get markers, which don't appear in stack traces), or would require more front-end work to make them look the same (e.g., inserting labels based on special markers).

I now think that this could be solved with more complex label code.
Basically, we want the label to always be present, but its dynamic text should only be created when necessary:

  • immediately if the profiler is already running,
  • otherwise, if&when the profiler starts.

Tech details:
This could be done with a new RAII label object, whose constructor would be given a function object (e.g., a lambda) used to create the dynamic string when needed.
The label object would store the function object, and register itself with profiler_add_state_change_callback. If the profiler is already running, or later if&when the profiler starts, it would invoke the label object's state-change callback, which would invoke the user-provided function object.
There may be some care needed to be fully thread-safe and sampling-safe, e.g.: The dynamic string may need to be pointed at through an atomic pointer, so that the sampler would either see a nullptr or a valid pointer to a valid string.


Aside: I've noticed a few uses of AUTO_PROFILER_LABEL_DYNAMIC_NSCSTRING that could probably be AUTO_PROFILER_LABEL_DYNAMIC_CSTR instead. E.g., in Element::Closest where the string is always live within the scope of that function.

Since the label code intentionally drops labels when the profiler is not running, it was not really a "defect", so I'm changing this bug back to "enhancement", tweaking the title.

Type: defect → enhancement
Priority: P2 → P3
Summary: DOM Worker's label (with script name) is not visible in stacks → Always add the script name to DOM Worker's thread names, and other labels
See Also: → 1772284

(In reply to Gerald Squelart [:gerald] (he/him) from comment #8)

Don't forget use case 0: DOM workers are created, but the profiler never runs => We want the minimal amount of CPU&memory usage.
I think it's important to keep that one in mind, while we try to improve the situation for those other use cases when the profiler runs.

Is the CPU and memory cost of converting the worker name from UTF16 to ascii really significant compared to the cost of creating a worker? If not, I don't think we need to block on fixing the general problem to reduce the pain of profiling workers.

Assignee: nobody → mstange.moz
Status: NEW → ASSIGNED

(In reply to Florian Quèze [:florian] from comment #10)

Is the CPU and memory cost of converting the worker name from UTF16 to ascii really significant compared to the cost of creating a worker?

Definitely not!

I wonder if we just want another macro that always does the string conversion, and rename the existing macro to something that conveys "only if profiler is active".

Pushed by mstange@themasta.com: https://hg.mozilla.org/integration/autoland/rev/3e77e0ed6e46 Use AUTO_PROFILER_LABEL_DYNAMIC_CSTR instead of AUTO_PROFILER_LABEL_DYNAMIC_CSTRING so that the dynamic string is captured even while the profiler is not running. r=florian
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 103 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: