Closed Bug 1035794 Opened 6 years ago Closed 6 years ago

Make talos pageloader addon logs more readable/informative for humans

Categories

(Testing :: Talos, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: avih, Unassigned)

References

()

Details

(Keywords: ateam-talos-task)

Attachments

(1 file, 2 obsolete files)

Here's a sample from tscrollx log as it appears on the talos run logs (this is from a local run though with 5 tppagecycles):

> |0;tiled.html;3.201242916540756;3.1733981526987423;3.2949227673317596;3.170702278660242;3.0418815561999755
> |1;tiled-fixed.html;3.631526622740206;3.5975789293263722;4.051485202254075;3.7941154711936895;3.608586884756151
> |2;tiled-downscale.html;3.4860675611220735;3.334567000891805;4.0740232762709585;3.4918798749999995;3.4095411244586074
> |3;tiled-fixed-downscale.html;3.679511290442154;3.554806442280809;3.699679547052711;3.59577144147409;3.666771454495091
> |4;iframe.svg;5.270385247143827;5.121561659118311;4.921048208736382;5.2655628857199845;5.098445835630378
> |5;reader.htm;4.516483122186724;4.485920536404889;4.514902479503446;4.646722628796783;4.58047399474249

As you can tell, it's not easy to real this. What I think could help read and analyze the output:
1. Pretty print of the results (spacing, 1-2 decimal points, etc).
2. Some stats (e.g. average and stddev)

3. Optionally and arguably, replicate the graph server "score" formula and DataZilla "datapoint" formula and display them too at the log. This will be duplicating formulas which are defined elsewhere, but since both should be rather simple formulas, and neither of those change frequently (or at all), I think it's not a big burden to make sure they match, and even if they don't match for a while, it's not the end of the world. Also, we could display it as "Estimated GS/DZ score: ...".


One potential issue we could have, is that the place where the above log outputs (and where it's probably the easiest to add the extra outputs) is being parsed further, so we can't interrupt that parsing with more prints. We have two possible approaches for this, depending on how hard/easy they would be to implement once we start looking at the code:

1. Output the pretty print + extra info outside of the parsed section.
2. Allow the parser to ignore some lines, e.g. which start with '#', and use this prefix for our extra output.
Attached patch bug1035794.v1.patch (obsolete) — Splinter Review
Sample output, the original report outputs as is, the humane report follows:

> __start_tp_report
> _x_x_mozilla_page_load
> _x_x_mozilla_page_load_details
> |i|pagename|runs|
> |0;tiled.html;3.3815091755057654;3.577835266553349;3.508966494191598;3.447223707058441;3.314750318531658;3.140813430410517;3.3392423486641514;3.233077927484977;3.3050938524742106;3.3540684618304053
> |1;tiled-fixed.html;3.624484952346899;3.6518098923895654;3.935018187955001;3.6616317493508603;3.621640228800737;3.7637559070217796;3.865235040167698;3.6840445795492816;3.628697694940594;3.794672192405117
> |2;tiled-downscale.html;3.4552876949845635;3.654456146851113;3.528451905391933;3.539169235961196;3.528513336299076;3.7372342942263685;3.730273699901622;3.5353865097175032;3.5594225335008196;3.6757584952665634
> |3;tiled-fixed-downscale.html;3.7185663866364753;4.112555872325603;3.681714930532242;3.901207561754347;3.7640417970127147;3.7446414439915;3.9544020018858292;4.115511644050064;3.6725380980959486;3.6779581942877244
> |4;iframe.svg;5.528177095596724;5.347954855713156;5.014351267798297;5.487206753127875;5.174338738897633;5.40450642030757;5.539734997455123;5.115851478957898;5.144999449564771;5.100771061732723
> |5;reader.htm;4.571843632628734;4.760853955860159;4.755946420904359;4.659921411854664;4.548349935811288;4.478935883074669;4.768172283297449;4.459165288385159;4.457156993431014;4.505733413762401
> __end_tp_report
> __start_cc_report
> _x_x_mozilla_cycle_collect,3903
> __end_cc_report
> __startTimestamp1405123632973__endTimestamp
> 
> ------- Summary: start -------
> Number of tests: 6
> 
> [#0] tiled.html  Cycles:10  Average:3.36  Median:3.37  stddev:0.13, stddev-sans-first: 0.14
> Values: 3.4  3.6  3.5  3.4  3.3  3.1  3.3  3.2  3.3  3.4
> 
> [#1] tiled-fixed.html  Cycles:10  Average:3.72  Median:3.72  stddev:0.11, stddev-sans-first: 0.11
> Values: 3.6  3.7  3.9  3.7  3.6  3.8  3.9  3.7  3.6  3.8
> 
> [#2] tiled-downscale.html  Cycles:10  Average:3.59  Median:3.61  stddev:0.10, stddev-sans-first: 0.09
> Values: 3.5  3.7  3.5  3.5  3.5  3.7  3.7  3.5  3.6  3.7> 
> 
> [#3] tiled-fixed-downscale.html  Cycles:10  Average:3.83  Median:3.83  stddev:0.18, stddev-sans-first: 0.18
> Values: 3.7  4.1  3.7  3.9  3.8  3.7  4.0  4.1  3.7  3.7
> 
> [#4] iframe.svg  Cycles:10  Average:5.29  Median:5.38  stddev:0.20, stddev-sans-first: 0.19
> Values: 5.5  5.3  5.0  5.5  5.2  5.4  5.5  5.1  5.1  5.1
> 
> [#5] reader.htm  Cycles:10  Average:4.60  Median:4.62  stddev:0.13, stddev-sans-first: 0.14
> Values: 4.6  4.8  4.8  4.7  4.5  4.5  4.8  4.5  4.5  4.5
> -------- Summary: end --------
Attachment #8454816 - Flags: review?(jmaher)
This adds percentage (of the average) to the stddev value. E.g.:
> stddev:0.15 (3.8%)

Which allows quicker evaluation of the consistency of the values.
Attachment #8454816 - Attachment is obsolete: true
Attachment #8454816 - Flags: review?(jmaher)
Attachment #8454823 - Flags: review?(jmaher)
(In reply to Avi Halachmi (:avih) from comment #2)
> This adds percentage (of the average) to the stddev value. E.g.:

^ typo - it's actually percentage of the median. Since we usually/always use medians, I've used it also as a base for the percentage value.
Comment on attachment 8454823 [details] [diff] [review]
bug1035794.v2.patch - add stddev percentage

Review of attachment 8454823 [details] [diff] [review]:
-----------------------------------------------------------------

this looks great.  I would change getReportHumane to getReportSummary
Attachment #8454823 - Flags: review?(jmaher) → review+
shall we close this?
Yeah, it works well.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.