Add some window event data to an about page for debugging
Categories
(Core :: Widget: Win32, task, P3)
Tracking
()
Tracking | Status | |
---|---|---|
firefox109 | --- | fixed |
People
(Reporter: handyman, Assigned: gstoll)
References
Details
(Whiteboard: [win:fullscreen],[win:multimonitors],[win:sizing])
Attachments
(11 files, 4 obsolete files)
757.22 KB,
image/png
|
Details | |
146.50 KB,
image/png
|
Details | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review | |
48 bytes,
text/x-phabricator-request
|
Details | Review |
In order to better debug window position and sizing and multi-monitor issues (and probably others), we need better window message logging. Some basic window message logging improvements are covered in bug 1788271. This bug is to go a step further and record some message "times" and payloads/responses, and display them in an about page or some similar mechanism.
For example, we can count messages as they come in to nsWindow::ProcessMessage
and store the count ID for the latest of a few message types, along with the payload and our response to the message. This would not be just the lParam
and wParam
but also any primitive payload data they might reference through pointers. E.g. the WINDOWPOS structure in the lParam for WM_WINDOWPOSCHANGING. Storing the message count ID with them allows us to order them -- many messages partially or completely overwrite the data from others so this is crucial. Also, we sometimes see bugs from messages that arrived in an unexpected order.
By storing a few types of messages this way, along with the display geometry information, we should be able to use it to reproduce window geometry calculations in the event that they lead to a bad state, like unresponsive window chrome or not-drawn pixels. This will not be much data and will be stored per-window.
We can display the information in an about page, which would require some window to be at least usable. That is fine for the kinds of bugs mentioned here.
Updated•2 years ago
|
Assignee | ||
Updated•2 years ago
|
Assignee | ||
Comment 1•2 years ago
|
||
Assignee | ||
Comment 2•2 years ago
|
||
Assignee | ||
Comment 3•2 years ago
|
||
Assignee | ||
Comment 4•2 years ago
|
||
This is helpful for the normal event log, and also necessary since we want to group the messages up by window in the about page.
Depends on D161148
Assignee | ||
Comment 5•2 years ago
|
||
This is the list of messages that handyman and rkraesig suggested.
Since we're recording WM_GETMINMAXINFO, we now have better logging for that message.
Depends on D161149
Assignee | ||
Comment 6•2 years ago
|
||
Depends on D161150
Assignee | ||
Comment 7•2 years ago
|
||
Depends on D161151
Assignee | ||
Comment 8•2 years ago
|
||
Depends on D161152
Assignee | ||
Comment 9•2 years ago
|
||
Depends on D161153
Assignee | ||
Comment 10•2 years ago
|
||
It seemed like a bad idea to hold on to entries forever after a window closes, even though we're not talking about a lot of memory per window. I went back and forth a bit on how to handle this; my first solution just removed the current window's messages when we got the "domwindowclosed" event, but the HWND would get a few more messages before it actually closed. This solution:
- doesn't add any extra overhead when we're logging messages (since this happens frequently, perf matters most here)
- prevents us from an unbounded memory leak; after a window closes it will keep a few extra messages around until the time the next window closes
- should be relatively quick; the 99th percentile of open windows is somewhere around 7, so this shouldn't take too long.
Depends on D161154
Assignee | ||
Comment 11•2 years ago
|
||
One thing to note is that if the user shrinks this number we won't reclaim any memory - this is because I wanted to avoid doing any more work than necessary when we're logging messages. Let me know if you think this is a problem!
Depends on D161155
Assignee | ||
Comment 12•2 years ago
|
||
Depends on D161156
Assignee | ||
Comment 13•2 years ago
|
||
Depends on D161157
Assignee | ||
Comment 14•2 years ago
|
||
Depends on D161158
Comment 15•2 years ago
|
||
This is a lot of patches. Can someone describe why we're going with Yet Another About Page, rather than reusing e.g. MOZ_LOG (via about:logging), which seems like it'd be appropriate for something like this and would also allow seeing it in connection/relation to other MOZ_LOG enabled functionality? Apologies if there's an obvious reason not to do that that I'm missing...
Comment 16•2 years ago
|
||
(In reply to :Gijs (he/him) from comment #15)
This is a lot of patches. Can someone describe why we're going with Yet Another About Page, rather than reusing e.g. MOZ_LOG
I almost wrote here a similar question yesterday, as the profiler has markers for WindowProc messages, probably less detailed than the logging considered here, but I wonder if it would be possible to improve them enough to fit the need here. MOZ_LOG is also visible in profiles.
After reading the comments here, my understanding of why something different has been implemented is that by keeping some information around all the time, it would be possible to troubleshoot what happened, after the fact, without knowing steps to reproduce.
Assignee | ||
Comment 17•2 years ago
|
||
(In reply to Florian Quèze [:florian] from comment #16)
After reading the comments here, my understanding of why something different has been implemented is that by keeping some information around all the time, it would be possible to troubleshoot what happened, after the fact, without knowing steps to reproduce.
Yes, this is the idea - often these bugs are hard to reproduce, and so when someone gets into this state we can ask them to load the about page and send in that data, as opposed to having to have logging turned on to begin with.
Also, my apologies for the number of patches; I'm new at mozilla and still getting used to the stack of patches concept.
Reporter | ||
Updated•2 years ago
|
Updated•2 years ago
|
Assignee | ||
Comment 18•2 years ago
|
||
Depends on D161152
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Comment 19•2 years ago
|
||
Comment 20•2 years ago
|
||
Backed out for causing mochitest failures on browser_preferences_usage.js
- Backout link
- Push with failures
- Failure Log
- Failure line: TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_preferences_usage.js | widget.windows.messages_to_log should not be accessed more than 40 times. - 60 <= 40 - JS frame :: chrome://mochitests/content/browser/browser/base/content/test/performance/browser_preferences_usage.js :: checkPrefGetters :: line 42
Comment 21•2 years ago
|
||
Comment 22•2 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/bfd6a2697b3b
https://hg.mozilla.org/mozilla-central/rev/3c2fd06bcfe8
https://hg.mozilla.org/mozilla-central/rev/9cb0638f941d
https://hg.mozilla.org/mozilla-central/rev/9dabd35bafe5
https://hg.mozilla.org/mozilla-central/rev/c55341738f3b
https://hg.mozilla.org/mozilla-central/rev/ce4be86b4c3f
https://hg.mozilla.org/mozilla-central/rev/c5c8cf87125d
https://hg.mozilla.org/mozilla-central/rev/9243bbde3d5e
https://hg.mozilla.org/mozilla-central/rev/ebcce528c4a9
Assignee | ||
Updated•2 years ago
|
Description
•