Closed
Bug 1074952
Opened 10 years ago
Closed 10 years ago
Consolidate graphics error/warning logging story
Categories
(Core :: Graphics, defect)
Tracking
()
RESOLVED
FIXED
mozilla36
People
(Reporter: milan, Assigned: milan)
References
Details
Attachments
(7 files, 18 obsolete files)
(deleted),
patch
|
milan
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
bas.schouten
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
bas.schouten
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
bas.schouten
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
milan
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
milan
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
milan
:
review+
|
Details | Diff | Splinter Review |
From the recent work week:
gfxCriticalError - in both release and debug, logged into a circular buffer and into the crash log - always keep the first one, but otherwise keep the last N (driven by gfx.logging.length preference) messages.
gfxWarning - in both release and debug, logged into a circular buffer. Keep the last N (driven by gfx.logging.length preference) messages.
gfxDebug - in debug only.
gfx.logging.level preference set to 1 gives us the above behaviour. Set to 2, it stops all gfxDebug messages. Set to 3, it stops all gfxWarning messages as well. The default is 1.
Assignee | ||
Comment 1•10 years ago
|
||
Attachment #8497597 -
Flags: feedback?(bas)
Comment 2•10 years ago
|
||
Comment on attachment 8497597 [details] [diff] [review]
Initial patch, a potential way to expose the Moz2D values to prefs.
Review of attachment 8497597 [details] [diff] [review]:
-----------------------------------------------------------------
r+'ed this patch in bug 1069620.
Attachment #8497597 -
Flags: feedback?(bas)
Comment 3•10 years ago
|
||
(In reply to Milan Sreckovic [:milan] from comment #0)
> gfx.logging.level preference set to 1 gives us the above behaviour. Set to
> 2, it stops all gfxDebug messages. Set to 3, it stops all gfxWarning
> messages as well. The default is 1.
Drive-by comment: to my mind it seems counter-intuitive that a higher value for gfx.logging.level should result in less logging. I'd expect "higher" logging levels to record/report more stuff, not less...
Assignee | ||
Comment 4•10 years ago
|
||
(In reply to Jonathan Kew (:jfkthame) from comment #3)
> (In reply to Milan Sreckovic [:milan] from comment #0)
> > gfx.logging.level preference set to 1 gives us the above behaviour. Set to
> > 2, it stops all gfxDebug messages. Set to 3, it stops all gfxWarning
> > messages as well. The default is 1.
>
> Drive-by comment: to my mind it seems counter-intuitive that a higher value
> for gfx.logging.level should result in less logging. I'd expect "higher"
> logging levels to record/report more stuff, not less...
That's a valid point. This behaviour is inherited from prlog that is used under the covers (see definition of PR_LOG_TEST in prlog.h), where the approach is "you need to be this tall to get on this ride (log)".
Assignee | ||
Comment 5•10 years ago
|
||
See https://bugzilla.mozilla.org/show_bug.cgi?id=1069620#c3 for r+.
https://tbpl.mozilla.org/?tree=Try&rev=7aac3cbc642d
Attachment #8497597 -
Attachment is obsolete: true
Attachment #8497653 -
Flags: review+
Assignee | ||
Comment 6•10 years ago
|
||
(In reply to Milan Sreckovic [:milan] from comment #4)
> (In reply to Jonathan Kew (:jfkthame) from comment #3)
> > (In reply to Milan Sreckovic [:milan] from comment #0)
> > > gfx.logging.level preference set to 1 gives us the above behaviour. Set to
> > > 2, it stops all gfxDebug messages. Set to 3, it stops all gfxWarning
> > > messages as well. The default is 1.
> >
> > Drive-by comment: to my mind it seems counter-intuitive that a higher value
> > for gfx.logging.level should result in less logging. I'd expect "higher"
> > logging levels to record/report more stuff, not less...
>
> That's a valid point. This behaviour is inherited from prlog that is used
> under the covers (see definition of PR_LOG_TEST in prlog.h), where the
> approach is "you need to be this tall to get on this ride (log)".
I'll take some of this back. We have our levels as "1 is debug, 3 is critical", but prlog goes the other way "1 is always logged, 2 is critical, 4 is debug", so I'll look at changing our side in the subsequent patches to match. "Larger number means more messages" does make sense.
Comment 7•10 years ago
|
||
(In reply to Milan Sreckovic [:milan] from comment #0)
> gfxDebug - in debug only.
I think the use of "debug" is not really great here. I think this is really "verbose" logging more than "debug" logging. There's also the problem of knowing whether that means "is only enabled for debug builds" or not. I realize PR_LOG is similar but if we're going to come up with something new why not use terminology that's a little more reflective of what the logging is actually doing.
Assignee | ||
Comment 8•10 years ago
|
||
We expect (what we currently call) gfxDebug to be compiled out in the release build, and only doing something in the #ifdef DEBUG - we want to use it often enough not to worry about increasing the size of the release build. gfxDebugLog or gfxLogDebug or gfxTraceDebug or something like that is an option? I'm not sure how "new" we want things to be, it was more to be consistent, but I'm sure we'll take any suggestions on what would make things more understandable and easier to maintain. So:
1. Something that is #ifdef DEBUG only, gets compiled out in the release builds and that is just for tracing the code.
2. Something that is run time governed by a pref, available in both debug and release builds, and constitutes a warning that things are not quite normal, but it isn't necessarily a sign of a bug in our code. For example, failing to get back a large canvas. Off by default in non-debug build, on by default in debug build. Actually, perhaps on by default in the nightly.
3. Something that is telling us that we have a bug in our code. Critical error, logged into the crash report as well. On by default. Will probably crash soon, but it depends. Basically, the way we'd use an assert in the debug build.
What would be the good names?
Assignee | ||
Comment 9•10 years ago
|
||
The story is evolving so let me record some thoughts.
First, the simple stuff - naming: gfxDebug - maybe use gfxLog instead. Basically, gfxWarning is for something mildly disturbing, and gfxLog is just for making a lot of noise when you're debugging something in particular (which is where gfxDebug probably came from before.)
Second, some kind of filtering when it comes to logging. Sometimes you want to see all the logging, but sometimes you just want to see apz or tiling or layers or whatever. So, combine what we'd have with logging, with what comes from prlog (so, this would be limited to those platforms alone to start), and use gfxLog("gfx-whatever") << ... syntax instead. One of the overall gfx.logging.level options would be "show me all logs", but one, just below it, would be "show me only the logs enabled by prlog (again, that would only work for the platforms where prlog does anything.)
Assignee: nobody → milan
Assignee | ||
Comment 10•10 years ago
|
||
Assignee | ||
Comment 11•10 years ago
|
||
Assignee | ||
Comment 12•10 years ago
|
||
Attachment #8497653 -
Attachment is obsolete: true
Attachment #8500550 -
Flags: review+
Assignee | ||
Comment 13•10 years ago
|
||
Assignee | ||
Comment 14•10 years ago
|
||
For the non-main thread logging - one option is to save them and pick them up if/when we crash, the other is to keep sending them across. Probably the later.
Assignee | ||
Comment 15•10 years ago
|
||
Attachment #8500550 -
Attachment is obsolete: true
Attachment #8511232 -
Flags: review+
Assignee | ||
Comment 16•10 years ago
|
||
Attachment #8500547 -
Attachment is obsolete: true
Attachment #8511233 -
Flags: review?(bas)
Assignee | ||
Comment 17•10 years ago
|
||
Attachment #8500549 -
Attachment is obsolete: true
Attachment #8511236 -
Flags: review?(bas)
Assignee | ||
Comment 18•10 years ago
|
||
Attachment #8500551 -
Attachment is obsolete: true
Attachment #8511237 -
Flags: review?(bas)
Assignee | ||
Updated•10 years ago
|
Attachment #8511233 -
Attachment description: Part 2. gfxWarning() should be available in both debug and release builds. (WIP) → Part 2. gfxWarning() should be available in both debug and release builds.
Updated•10 years ago
|
Attachment #8511233 -
Flags: review?(bas) → review+
Assignee | ||
Comment 19•10 years ago
|
||
Attachment #8511237 -
Attachment is obsolete: true
Attachment #8511237 -
Flags: review?(bas)
Attachment #8512836 -
Flags: review?(bas)
Assignee | ||
Comment 20•10 years ago
|
||
Note that the CrashReporter currently rejects the not-default-process-and-not-main-thread scenario, but the other combinations should be OK. Certainly the non-e10s OMTC scenario is covered.
Attachment #8512984 -
Flags: review?(nical.bugzilla)
Updated•10 years ago
|
Attachment #8512984 -
Flags: review?(nical.bugzilla) → review+
Assignee | ||
Comment 21•10 years ago
|
||
Assignee | ||
Comment 22•10 years ago
|
||
Attachment #8515114 -
Flags: review?(botond)
Comment 23•10 years ago
|
||
Comment on attachment 8511236 [details] [diff] [review]
Part 3. Redo the const values and optimize for the case where we run time don't log messages.
Review of attachment 8511236 [details] [diff] [review]:
-----------------------------------------------------------------
::: gfx/2d/Logging.h
@@ +93,5 @@
>
> // Used to choose the level of logging we get. The higher the number,
> + // the more logging we get. Value of zero will give you no logging,
> + // 1 will give you everything, 2 just errors, 3 adds warnings and
> + // 5 adds logging/debug (so, 1 behaves the same as 5.) The missing value
Drive-by observation: "1" giving you everything while "2" only gives you errors seems to contradict "the higher the number, the more logging we get".
Comment 24•10 years ago
|
||
Comment on attachment 8515114 [details] [diff] [review]
Part 6. Fully qualify the appropriate logs in the logging macros. r=botond
Review of attachment 8515114 [details] [diff] [review]:
-----------------------------------------------------------------
::: gfx/2d/Logging.h
@@ +367,5 @@
> typedef Log<LOG_WARNING> WarningLog;
> typedef Log<LOG_CRITICAL, CriticalLogger> CriticalLog;
>
> #ifdef GFX_LOG_DEBUG
> +#define gfxDebug gfx::DebugLog
Is there any harm in going the whole hog and qualifying them with mozilla::gfx::?
Attachment #8515114 -
Flags: review?(botond) → review+
Assignee | ||
Updated•10 years ago
|
Updated•10 years ago
|
Comment 25•10 years ago
|
||
Is this duplicating machinery elsewhere, such as in bug 881389 or its dependents?
Assignee | ||
Comment 26•10 years ago
|
||
It's more that completing bug 881389 may give us a unified way to implement one function in here, the one that actually delivers the logs to the user (BasicLogger::OutputMessage in Logging.h, which is today a combination of printf, printf_stderr, PR_LogPrint and OutputDebugStringA.) Most of the work here is one level higher, for us to consistently use the logging capabilities...
Assignee | ||
Comment 27•10 years ago
|
||
Assignee | ||
Comment 28•10 years ago
|
||
Update the docs and fully quality with mozilla::gfx:: instead of just gfx:: based on the feedback.
Attachment #8515114 -
Attachment is obsolete: true
Attachment #8517671 -
Flags: review+
Assignee | ||
Updated•10 years ago
|
Attachment #8517671 -
Attachment is patch: true
Assignee | ||
Updated•10 years ago
|
Attachment #8517666 -
Attachment description: Add logging support for a couple of common Moz2d enums and use them. → Part 7. Add logging support for a couple of common Moz2d enums and use them.
Comment 29•10 years ago
|
||
Comment on attachment 8511236 [details] [diff] [review]
Part 3. Redo the const values and optimize for the case where we run time don't log messages.
Review of attachment 8511236 [details] [diff] [review]:
-----------------------------------------------------------------
::: gfx/2d/Logging.h
@@ +360,4 @@
> }
>
> std::stringstream mMessage;
> + int mOptions;
I'm wondering out loud whether LogIt should be separate bool field instead of a bitflag. Both to avoid the bitwise-AND when checking it and to make it impossible for people to shove it into their LogOptions.
Attachment #8511236 -
Flags: review?(bas) → review+
Updated•10 years ago
|
Attachment #8512836 -
Flags: review?(bas)
Assignee | ||
Comment 30•10 years ago
|
||
Made enough changes that I won't carry the r+.
Attachment #8511236 -
Attachment is obsolete: true
Attachment #8520942 -
Flags: review?(bas)
Assignee | ||
Comment 31•10 years ago
|
||
Attachment #8512836 -
Attachment is obsolete: true
Attachment #8520943 -
Flags: review?(bas)
Assignee | ||
Comment 32•10 years ago
|
||
Attachment #8520944 -
Flags: review+
Assignee | ||
Updated•10 years ago
|
Attachment #8512984 -
Attachment is obsolete: true
Assignee | ||
Comment 33•10 years ago
|
||
Attachment #8517671 -
Attachment is obsolete: true
Attachment #8520945 -
Flags: review+
Assignee | ||
Comment 34•10 years ago
|
||
The code that uses these enums belongs to a different bug.
Attachment #8517666 -
Attachment is obsolete: true
Attachment #8520948 -
Flags: review?(bas)
Assignee | ||
Comment 35•10 years ago
|
||
Comment on attachment 8520943 [details] [diff] [review]
Part 4. For the critical log, save the first, then circular buffer the rest into the crash annotations.
Review of attachment 8520943 [details] [diff] [review]:
-----------------------------------------------------------------
::: gfx/thebes/gfxPlatform.cpp
@@ +174,5 @@
> + uint32_t mMaxCapacity;
> + int32_t mIndex;
> +};
> +
> +nsCString CrashStatsLogForwarder::kCrashCriticalKey("GraphicsCriticalError");
This shows up as a leak, so I'll change it to const char* instead.
Assignee | ||
Comment 36•10 years ago
|
||
Don't use the static for the key. Nicer code, and no worries about leaking statics.
Attachment #8520943 -
Attachment is obsolete: true
Attachment #8520943 -
Flags: review?(bas)
Attachment #8522435 -
Flags: review?(bas)
Assignee | ||
Comment 37•10 years ago
|
||
Just a merge to modified Part 4.
Attachment #8520944 -
Attachment is obsolete: true
Attachment #8522439 -
Flags: review+
Comment 38•10 years ago
|
||
Comment on attachment 8522435 [details] [diff] [review]
Part 4. For the critical log, save the first, then circular buffer the rest into the crash annotations. r=bschouten
Review of attachment 8522435 [details] [diff] [review]:
-----------------------------------------------------------------
::: gfx/thebes/gfxPlatform.cpp
@@ +176,5 @@
> + int32_t mIndex;
> +};
> +
> +CrashStatsLogForwarder::CrashStatsLogForwarder(const char* aKey)
> +: mBuffer()
nit: whitespace
@@ +190,5 @@
> + mBuffer.reserve(static_cast<size_t>(aCapacity));
> +}
> +
> +bool
> +CrashStatsLogForwarder::UpdateStringsVector(const std::string& aString)
personally I'd prefer just adding using namespace std and dropping all the std::
@@ +605,5 @@
> mozilla::gl::GLContextProviderEGL::Shutdown();
> #endif
>
> + // This is a bit iffy - we're assuming that we were the ones that set the
> + // log forwarder in the Factory, so that it's our responsibility to
Yeah, I thought about this, and I considered storing mLogForwarder on the gfxPlatform class. But I felt that was sort of needless.
Attachment #8522435 -
Flags: review?(bas) → review+
Updated•10 years ago
|
Attachment #8520942 -
Flags: review?(bas) → review+
Updated•10 years ago
|
Attachment #8520948 -
Flags: review?(bas) → review+
Assignee | ||
Comment 39•10 years ago
|
||
Fix the white space.
Attachment #8522435 -
Attachment is obsolete: true
Attachment #8524128 -
Flags: review+
Assignee | ||
Comment 40•10 years ago
|
||
Assignee | ||
Comment 41•10 years ago
|
||
Rebasing.
Attachment #8520945 -
Attachment is obsolete: true
Attachment #8524132 -
Flags: review+
Assignee | ||
Updated•10 years ago
|
Keywords: checkin-needed
Comment 42•10 years ago
|
||
Hi Milan, part 6 failed to apply:
1 out of 2 hunks FAILED -- saving rejects to file gfx/layers/d3d11/TextureD3D11.cpp.rej
patch failed, unable to continue (try -v)
patch failed, rejects left in working dir
errors during apply, please fix and refresh 1074952.6.p4
could you take a look ?
Flags: needinfo?(milan)
Updated•10 years ago
|
Keywords: checkin-needed
Assignee | ||
Comment 43•10 years ago
|
||
Hmm, applies cleanly for me - did you take it from the try run, or from the bug? Because the bug has an up to date Part 6, and the try run has a merge conflict. I'll check against inbound, in case it's different there, I was checking against central.
Flags: needinfo?(milan) → needinfo?(cbook)
Assignee | ||
Comment 44•10 years ago
|
||
OK, I see, it doesn't apply cleanly on inbound.
Assignee | ||
Comment 45•10 years ago
|
||
This should merge cleanly on inbound.
Attachment #8524132 -
Attachment is obsolete: true
Flags: needinfo?(cbook)
Attachment #8524655 -
Flags: review+
Assignee | ||
Updated•10 years ago
|
Keywords: checkin-needed
Comment 46•10 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/89b4de44d7b4
https://hg.mozilla.org/integration/mozilla-inbound/rev/eb7db60e6743
https://hg.mozilla.org/integration/mozilla-inbound/rev/b6c7ff735357
https://hg.mozilla.org/integration/mozilla-inbound/rev/4597d80c2b70
https://hg.mozilla.org/integration/mozilla-inbound/rev/d5d6c4693703
https://hg.mozilla.org/integration/mozilla-inbound/rev/864722a0c24a
https://hg.mozilla.org/integration/mozilla-inbound/rev/35b83e418c21
Keywords: checkin-needed
Comment 47•10 years ago
|
||
https://hg.mozilla.org/mozilla-central/rev/89b4de44d7b4
https://hg.mozilla.org/mozilla-central/rev/eb7db60e6743
https://hg.mozilla.org/mozilla-central/rev/b6c7ff735357
https://hg.mozilla.org/mozilla-central/rev/4597d80c2b70
https://hg.mozilla.org/mozilla-central/rev/d5d6c4693703
https://hg.mozilla.org/mozilla-central/rev/864722a0c24a
https://hg.mozilla.org/mozilla-central/rev/35b83e418c21
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
Assignee | ||
Comment 48•10 years ago
|
||
Any follow up enhancement and changes in bug 1101685.
You need to log in
before you can comment on or make changes to this bug.
Description
•