Hi,
I am running TB test suite (mochitest) locally and have an issue at the
format of the timestamp of the log lines.
I am not sure when the time stamp became this way.
(I don't think I had this issue several years ago. Something must have
changed a year or so ago? Maybe around the time, mochitest replaced
mozmill test.)
Can we modify the test suite run script so that the timestamp prepended
to the log line
always has a filled two digits leading number, 0-filled if necessary,
WITHOUT leading space character?
Currently: the log lines when the leading number of the timestamp is one
digit, they
look like the following. Note the space character at the beginning of
the line. This causes a problem for simple-minded log summarizer.
0:23.46 INFO runtests.py | Waiting for browser...
0:49.50 GECKO(735766) #01: NS_DebugBreak
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsDebugImpl.cpp:497)
0:49.50 GECKO(735766) #02: nsWindow::SetZIndex(int)
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/widget/gtk/nsWindow.cpp:2470)
0:49.50 GECKO(735766) #03: UpdateNativeWidgetZIndexes(nsView*, int)
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/view/nsView.cpp:505)
I would like it to be: Note there is no leading space character.
00:23.46 INFO runtests.py | Waiting for browser...
00:49.50 GECKO(735766) #01: NS_DebugBreak
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsDebugImpl.cpp:497)
00:49.50 GECKO(735766) #02: nsWindow::SetZIndex(int)
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/widget/gtk/nsWindow.cpp:2470)
00:49.50 GECKO(735766) #03: UpdateNativeWidgetZIndexes(nsView*, int)
(/NEW-SSD/NREF-COMM-CENTRAL/mozilla/view/nsView.cpp:505)
This formatting would make it much easier for me to create a script to
pick up interesting lines and calculate
the counts from the log.
Currently a simple command as follows fails to produce a uniq count for
interesting lines.
grep ASSERTION log1439-mochitest.txt | cut --delimiter=" " -f 6- | \
sort | uniq -c | sort -n -k 1 -r
E.g. Split summary
This is from a real log of TB mochitest.
947 Thread] ###!!! ASSERTION: Overwriting an existing document
channel!: '(loadFlags & nsIChannel::LOAD_REPLACE) ||
!(mDocumentRequest.get())', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/uriloader/base/nsDocLoader.cpp:467
359 Thread] ###!!! ASSERTION: Expected Mozilla child widget:
'!mContainer', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/widget/gtk/nsWindow.cpp:2434
321 Thread] ###!!! ASSERTION:
GetMsgDatabase(getter_AddRefs(database)) returned failure.:
'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/base/src/nsMsgDBFolder.cpp:4724
321 Thread] ###!!! ASSERTION: GetMessageHeader(msgKey, _retval)
returned failure: 'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/local/src/nsMailboxService.cpp:621
174 Main Thread] ###!!! ASSERTION:
GetMsgDatabase(getter_AddRefs(database)) returned failure.:
'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/base/src/nsMsgDBFolder.cpp:4724
174 Main Thread] ###!!! ASSERTION: GetMessageHeader(msgKey,
_retval) returned failure: 'NS_SUCCEEDED(rv)', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/local/src/nsMailboxService.cpp:621
97 Main Thread] ###!!! ASSERTION: Expected Mozilla child widget:
'!mContainer', file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/widget/gtk/nsWindow.cpp:2434
...
Note that the second and the seventh lines above are for the same
ASSERTION lines recorded at different times, but leading space character
at the beginning of the lines early in the log causes the early lines
counted separately.
Ditto for the third and the fifth lines, and the fourth and sixth lines.
(BTW, by counting the numbers it becomes obvious that the errors
recorded for GetMsgDatbase and GetMessageHeader are closely related.)
The counting discrepancy occurs because in later part of the log, the
leading number of the timestamp has two digits and there is no leading
space. This subtle difference fools a simple couting script.
E.g.
54:14.53 GECKO(769167) [Parent 769167, Main Thread] ###!!! ASSERTION:
GetMessageHeader(msgKey, _retval) returned failure: 'NS_SUCCEEDED(rv)',
file
/NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/local/src/nsMailboxService.cpp:621
Still later, it becomes three digits and there is no space character.
100:00.82 INFO *** Start BrowserChrome Test Results ***
100:00.83 INFO checking window state
It should be a simple fix.
Someone in the know can point at the problematic output code and maybe I
can proceed from there.
TIA
Chiaki
--
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/799a2574-8819-8f0a-2ede-2aeb7ac850c3%40yk.rim.or.jp.
