(I set reply-to to thunderbird developers list, but this is relevant to
dev-platform, too.)
I develop local patches for TB locally under Debign GNU/Linux.
I need to check the sanity of patches when they are applied to Windows
and MacOS version.
For that I trust tryserver to run the tests for these binaries.
A few years ago, it was possible to look at the log of debug version
to see what went wrong with my patches on systems I did not have on
tryserver. It was not easy, mind you, but not impossible.
By "what went wrong", I mean I could see a test failed and not only
that could focus on the cause of the failure with additional debug
logging using the existing warning/error messages as clue.
Unfortunately, for the last 12+ months, the debug log got way too
verbose for me to cull essential information from the log.
And this has hampered my attempt to merge my patches against the
latest C-C tree (M-C tree) and get the tests going.
I simply cannot easily spot where my patches screws up internal
processing easily.
Cause of too verbose message problems:
The problems of too verbose log files I see are caused by many
factors, but my taken on the state of affairs is as follows.
Item 1. C++/C sources suffer from the lack of a proper INFORMATIONAL
logging.
Those of you who are familiar with syslog/rsyslog logging know the
LEVEL of messages: this is related to the notion of urgency or
priority of messages to be logged.
We can specify a level and only log the messages with that priority
and above.
Problem with C++/C macros is that most of the macros for debugging
purposes lack the notion of INFORMATIONAL messages. The macros are
about something went wrong, so abort with messages.: NS_ABORT, NS_ASSERTION,
MOZ_ASSERT, etc.
something went wrong, so print an error message, but go on.
something seems fishy, so print a warning message, and go on.:
NS_WARNING, etc.
There are legitimate cases where the developers would like to know if
certain situation arises or not or how frequently they occur, but
currently the developers simply use NS_WARNING type macros and so we
have so many warnings which may not be WARNING at all, and actually
only INFORMATIONAL.
This adds to the messages that are actually of information nature, but
printed as warnings.
Item 2. I raised a few issues regarding the verbose warnings lately when
I found
the current state of verbose debug log file is getting out of hands
even for someone who has waded through it for the last several years or
more.
https://bugzilla.mozilla.org/show_bug.cgi?id=1695139
(actually many more in the past.)
It seems that the particular messages turn out to be of no concern to
mere mortals
So they could actually be turned into INFORMATIONAL category as noted
in Item 1.
Also, my take on the issue is that not many people look at the debug
log on tryserver. I have tough time to search for other people
submitting debug build and test on tryserver.
( I suspect only when the patch breaks, people use it?
A comprehensive patch set of mine to introduce buffered output to TB
(e.g. Bug 1242042 )
is rather sweeping changes that have known to break Windows versions in
the past, and MacOS version once. So I need to run debug build often.
Most of the time I run tests locally under linux before submitting
tryserver jobs.
Occasionally I have to make sure Windows and MacOS version at least run! )
ITEM 3. FYI, JS scripts at least have a notion of a crude level.
error, warn, debug, log for console messages and prefix them
with console.error, console.warn, console.debug, console.log.
I think this is in the right direction.
I would add console.info as logical next step.
Well, what I want to see to improve the state of affairs concerning
debug log is this:
Suggestion (a) I would suggest that we implement INFORMATIONAL logging
macros for
C++/C, that prefix the message with "INFO:".
This helps us to weed out INFORMATIONAL messages from the debug log to focus
on essential warnings and errors.
Suggestion (b) Filtering of log files
With macros for informational messages, we can institute a filtering
of debug log files by eliminating a few offending verbose messages and
informational messages to home in on the essential errors and
warnings.
We leave the original debug log file intact and provide it, of course,
but tryserver should
produce the filtered sanitized version that is easy for ordinary
developers to inspect.
Yes, (b) can be implemented locally by each developer to satisfy their
tastes for the local debug test runs, BUT I believe tryserver ought to
create a debug log file that would be meaningful for someone who sees
it for the first time.
(Well, I may be the only person in the world who regularly checks the
content of debug log file at least locally. Ugh...)
I am not sure what should the filtering be like. I would like to know
input from those in the know.
My initial consideration which I would implement locally first is,
- INFORMATIONAL messages be removed from the sanitized
version. (Remember the original debug log file will be provided, too.)
- Too many verbose messages should be considered first as candidate of
filtering and announced when the filtering rule changes.
"Too many" is rather subjective, let's call it more than 1000 times.
There ARE messages that appear more than 1000 times, mind you during
the whole test run.
These steps should clean up the cluttered debug log files hopefully.
At least, filtering of messages should motivate those responsible for
the code that creates the messages to either modify the message to
INFORMATIONAL category if they are not WARNING/ERROR category.
Or look at the nature of the issues in more detail.
I am hoping that there are people with similar sentiment regarding
debug log files.
Of course, warnings ARE important.
For example, I spotted a missed case handling lately due to a warning I
had not seen before.
https://bugzilla.mozilla.org/show_bug.cgi?id=1762161
The problem with today's debug log is that "noise" is burying essential
messages. :-(
Chiaki
PS: FYI, these are the most frequent warnings and errors from a run on
April 5th.
(That are recorded by an old script I have been using.
I am adding some more rules to extract different warnings/errors each
month, and so WEBRENDER warnings and some
which I mentioned above are not in this list.
Unfortunately, I have found out that the RAW local debug log file and
tryserver debug log files have different format. So, I cannot use the
filtering shell script to analyze the tyrserver log file easily.
I have been analyzing the local debug log file reasonably
well. Without automated summary, I cannot really do anything with
debug log file very well.
The numbers are crude indicators.
There are tests that are not executed due to the early failures, or
outright crashes, etc.
10 top most warnings coming from /libeditor/ during local mochitest
run of debug version of TB.
(TB has to create messages and editing is done actually to underlying HTML
document, BTW.)
========================================
Firstly, warnings under /libeditor/
========================================
4982: Main Thread] WARNING:
HTMLEditor::GetAbsolutelyPositionedSelectionContainer() reached <html>
element: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/HTMLAbsPositionEditor.cpp:95
525: Main Thread] WARNING: mozInlineSpellChecker::Cleanup() failed, but
ignored: 'NS_SUCCEEDED(rvIgnored)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/EditorBase.cpp:609
396: Main Thread] WARNING: '!aNode', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/EditorBase.cpp:3268
48: Main Thread] WARNING: Perhaps, <br> element position has been moved
to different point by mutation observer: 'currentPoint ==
pointToInsert', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/HTMLEditSubActionHandler.cpp:1252
41: Main Thread] WARNING: '!mSelection', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/EditorBase.cpp:6052
40: Main Thread] WARNING: '!editableContent', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/HTMLEditUtils.h:764
15: Main Thread] WARNING:
TopLevelEditSubActionData::AddRangeToChangedRange() failed:
'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/EditorBase.cpp:6412
15: Main Thread] WARNING:
TopLevelEditSubActionData::AddNodeToChangedRange() failed, but ignored:
'NS_SUCCEEDED(rvIgnored)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/EditorBase.cpp:6541
15: Main Thread] WARNING: HTMLEditor::DeleteNodeWithTransaction()
failed: 'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/editor/libeditor/HTMLEditSubActionHandler.cpp:963
10 most frequent warnings outside /libeditor/
(They are all above 1000 times threshold incidently.)
========================================
Other than /libeditor/
========================================
2947: Main Thread] WARNING: Scrolled rect smaller than scrollport?: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/layout/generic/nsGfxScrollFrame.cpp:7154
2164: Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/base/nsGlobalWindowOuter.cpp:4147
2074: Main Thread] WARNING: Failed to retarget HTML data delivery to the
parser thread.: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/parser/html/nsHtml5StreamParser.cpp:1198
1659: Main Thread] WARNING: XPCOM object nsStringBuffer released from
static ctor/dtor: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsTraceRefcnt.cpp:206
1564: Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC'
discarded: actor cannot send: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/ipc/glue/ProtocolUtils.cpp:504
1563: Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC'
discarded: actor cannot send: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/ipc/glue/ProtocolUtils.cpp:504
1402: Main Thread] WARNING: '!inner', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/ipc/jsactor/JSWindowActorProtocol.cpp:184
1168: Compositor] WARNING: Possibly dropping task posted to updater
thread: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/gfx/layers/apz/src/APZUpdater.cpp:365
1076: Main Thread] WARNING:
'!ClientIsValidPrincipalInfo(mClientInfo.PrincipalInfo())', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/clients/manager/ClientSource.cpp:183
1011: Main Thread] WARNING: no request to cancel: file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/base/src/nsMsgProtocol.cpp:763
[end of memo]
--
You received this message because you are subscribed to the Google Groups
"[email protected]" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/a/mozilla.org/d/msgid/dev-platform/d879234f-8920-40ce-8a88-6310272ed1d9%40yk.rim.or.jp.