Re: Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-22 Thread ishikawa
On (2014年04月22日 08:11), Zack Weinberg wrote:
> On 2014-04-21 1:07 PM, Steve Fink wrote:
>> On Sat 19 Apr 2014 08:36:22 AM PDT, ISHIKAWA,chiaki wrote:
>>> egrep  "^(\\[[0-9]*\\] |)WARNING" $1 | egrep NS_ENSURE | grep -v "sort
>>> operation has occurred for the SQL statement" | sort | uniq -f1 -c |
>>> sort -n -r
>>
>> It'd be easier if you threw in a *little* bit of perl:
>>
>>perl -lne 'print $1 if /WARNING: (NS_ENSURE.*)/' | sort | uniq -c |
>> sort -nr
> 
> If you're going to use perl, you might as well use perl:
> 
> perl -e 'my %hits;
>   while (<>) { $hits{$1}++ if /WARNING: (NS_ENSURE.*)/ }
>   printf("%d\t%s\n", $hits{$_}, $_)
>  for sort { $hits{$b} <=> $hits{$a} } keys %hits;'
> 
> Untested but, I believe, equivalent.  Could perhaps be further optimized by
> use of each() instead of keys() but I have forgotten too much to do it myself.
> 
> zw

Thank you for the suggestions.

My original intent was to avoid script programming as much as possible
and yet gain reasonably good summary.

I guess the time is over for a simple shell scripting to
produce a meaningful summary from ever evolving log record.
(Yes, my script goes over the log many times and in that sense it is not
very efficient, but
it can handle 100+MiB |mach mochitest-plain| of debug build of FF in several
seconds on my local PC and not too bad for my purpose of obtaining a
meaningful summary without investing too much in programming.)

When I have a time to re-engineer my script, I will post a prototype for
review by people who may be interested in such a script.

TIA
___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform


Re: Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-21 Thread Zack Weinberg

On 2014-04-21 1:07 PM, Steve Fink wrote:

On Sat 19 Apr 2014 08:36:22 AM PDT, ISHIKAWA,chiaki wrote:

egrep  "^(\\[[0-9]*\\] |)WARNING" $1 | egrep NS_ENSURE | grep -v "sort
operation has occurred for the SQL statement" | sort | uniq -f1 -c |
sort -n -r


It'd be easier if you threw in a *little* bit of perl:

   perl -lne 'print $1 if /WARNING: (NS_ENSURE.*)/' | sort | uniq -c |
sort -nr


If you're going to use perl, you might as well use perl:

perl -e 'my %hits;
  while (<>) { $hits{$1}++ if /WARNING: (NS_ENSURE.*)/ }
  printf("%d\t%s\n", $hits{$_}, $_)
 for sort { $hits{$b} <=> $hits{$a} } keys %hits;'

Untested but, I believe, equivalent.  Could perhaps be further optimized 
by use of each() instead of keys() but I have forgotten too much to do 
it myself.


zw
___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform


Re: Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-21 Thread Steve Fink
On Sat 19 Apr 2014 08:36:22 AM PDT, ISHIKAWA,chiaki wrote:
> egrep  "^(\\[[0-9]*\\] |)WARNING" $1 | egrep NS_ENSURE | grep -v "sort
> operation has occurred for the SQL statement" | sort | uniq -f1 -c |
> sort -n -r

It'd be easier if you threw in a *little* bit of perl:

  perl -lne 'print $1 if /WARNING: (NS_ENSURE.*)/' | sort | uniq -c | 
sort -nr

But you must be ignoring the SQL statement warning because it has 
varying text? I don't have an example line in my log, but if it matches 
https://bugzilla.mozilla.org/show_bug.cgi?id=933456 then you could use 
something like

  perl -lne 'next unless s/.*?WARNING: (NS_ENSURE.*)/$1/; 
s/0x[\da-f]+/0x/i; print' | sort | uniq -c | sort -nr

___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform


Re: Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-19 Thread ISHIKAWA,chiaki

(2014/04/19 22:54), Benjamin Smedberg wrote:

On 4/18/2014 7:07 PM, ISHIKAWA,chiaki wrote:

Does anyone know how to disable this prefixing short of modifying the
source code?


Why can't you just accept this in your parsing regex?

There is no runtime control for this behavior. It was made non-optional
so that we could which process an assertion was coming from when child
processes are present (plugins, content, eventually sandboxed media
decoders).

http://hg.mozilla.org/mozilla-central/annotate/db431ea44a1a/xpcom/base/nsDebugImpl.cpp#l311


--BDS


Thank you for the clarification.

Actually, my regex used in the summary creation script did try to 
accommodate this change.
But the simple-minded sum, etc. using shell and commands no longer works 
after the change, thus I was curious about restoring the

old behavior.

I created the shell scripts long time ago without
bothering to use anything more powerful (awk, perl, etc.) for
scanning through the TB test log quickly.

When I notice that a particular error/warning occurs very frequently or
shows up in the list for the first time, that is where I devote my
debug time.

I am debugging the summary creation shell script now, but I am afraid 
that has become very error-prone :-(


The shell script without trying to use advanced tools such as awk and 
perl is very simple-minded.
Say, for summary of WARNING lines coming from |make mozmill| and |make 
xpcshell-tests| of full debug version of TB (comm-central),

I used to use a simple-minded shell script as follows:

e.g.: the following line printed out how many times
a particular WARNING with NS_ENSURE was produced during the run.

egrep  "WARNING" $1 | egrep NS_ENSURE | grep -v "sort operation has 
occurred for the SQL statement" | sort | uniq -c | sort -n -r


Now, I am struggling with the following change, but still not producing 
the desired result yet:


egrep  "^(\\[[0-9]*\\] |)WARNING" $1 | egrep NS_ENSURE | grep -v "sort 
operation has occurred for the SQL statement" | sort | uniq -f1 -c | 
sort -n -r


As I write this, I realized I am missing a field selection for the "| 
sort |" portion in the pipeline.  I guess that is why I don't seem to 
get desired summary.

(But, of course, I have to figure out if I may be missing
WARNING lines without "[PID] " prefix if such lines exist. I hope not.)

Anyway, I have about a dozen lines of shell pipeline commands in the
summarizing script which broke due to the change,
and so was interesting in how to shut up the
PID prefix selectively. I will look into the above source code (maybe a 
local patch to change behavior based on environment variable.)


I agree that the new prefix is indeed useful for tracking down
issues to figure out which message is coming from which process when a
parallel testing (of running many tests at once) is done.
When a nasty bug appears, it is rather difficult to correlate the 
message to which process, I agree.


|make xpcshell-tests| runs many tests in parallel, and so will benefit 
from the change.


OTOH, |make mozmill|, the main TB test suite runs test more or less in 
serialized manner: after all testing mail client requires the simulation 
of mail creation, sending, or mail receiving, etc. using a shared local 
mail DB for a user and you can't run user interaction in parallel, and 
thus "[PID ]" prefix is not that useful there.


So it is a matter of what is sought.

I hope the build infrastructure can use the "[PID] " prefix to
track down and co-relate the messages with tests with more exactness so 
that debug/test can proceed more efficiently.

We need tryserver runs to catch more errors in a meaningful manner.
Currently, the so called "tests" simply pass individual tests that 
produce dubious error/warning lines during execution as long as

the sought criteria is met, but I think that ought to change.

TIA

Thank you for clarifying the






___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform


Re: Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-19 Thread Benjamin Smedberg

On 4/18/2014 7:07 PM, ISHIKAWA,chiaki wrote:

Does anyone know how to disable this prefixing short of modifying the
source code?


Why can't you just accept this in your parsing regex?

There is no runtime control for this behavior. It was made non-optional 
so that we could which process an assertion was coming from when child 
processes are present (plugins, content, eventually sandboxed media 
decoders).


http://hg.mozilla.org/mozilla-central/annotate/db431ea44a1a/xpcom/base/nsDebugImpl.cpp#l311

--BDS
___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform


Removing "[PID]" prefix from |make mozmill| warning/error/assertion lines?

2014-04-18 Thread ISHIKAWA,chiaki
Hi,

I have been analyzing warning/error/assertion lines produced
by full debug version of TB (comm-central).
To facilitate the analysis I created a few scripts to
process the error statistically.

Staring 1Q of 2014, I think such lines are prefixed with "[pid] ".
Now that probably is very good, but
unfortunately, this makes it very difficult to
use a simple-minded script to gather statistical information from the
log.

Does anyone know how to disable this prefixing short of modifying the
source code?

I have found that |mach| has a command for disabling timestamp (not
tested yet) "--log-no-timestamp".

If |make mozmill| has a similar run-time option to suppress "[pid' "
prefix, that is great.

TIA

PS: the lines look as follows. Note "[pid] "
Random sampling.

[17085] WARNING: not an nsIRDFRemoteDataSource: 'remote != nullptr',
file
/REF-COMM-CENTRAL/comm-central/mozilla/rdf/datasource/src/nsLocalStore.cpp,
line 279

[19427] WARNING: Leaking the RDF Service.: file
/REF-COMM-CENTRAL/comm-central/mozilla/rdf/build/nsRDFModule.cpp, line 165

[19427] ###!!! ASSERTION: Component Manager being held past XPCOM
shutdown.: 'cnt == 0', file
/REF-COMM-CENTRAL/comm-central/mozilla/xpcom/build/nsXPComInit.cpp, line
1020

[18458] WARNING: NS_ENSURE_TRUE(parentObject) failed: file
/REF-COMM-CENTRAL/comm-central/mozilla/accessible/src/atk/AccessibleWrap.cpp,
line 1295


etc.



___
dev-platform mailing list
dev-platform@lists.mozilla.org
https://lists.mozilla.org/listinfo/dev-platform