Currently, "Unrecognized output format" is a very ambiguous error: http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l384 This literally means "None of our regexes matched". But why they didn't match could mean one of many things: - pageloader isn't loaded - buffers weren't flushed or other IO error - some pageloader internal error - the final timestamp didn't get written properly (or similar) - some other error Instead, we should parse for these delimeter pairs individually so that we can know exactly what the problem is: http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l74 Then we should raise a import informative error.

AnalyzeThis uses tokens for splicing input: http://k0s.org/mozilla/hg/AnalyzeThis/file/f2b4b13ffab1/analyzethis/utils.py I'd prefer to use something like this

I will also move the browser log parsing to results.py. There is no reason the already monolithic ttest.py file should do this

This actually doesn't do any of the error handling better at all; it just moves the logic out of ttest.py to results.py and adds some tests now that there is an API that is actually testable

effectively blocks https://bugzilla.mozilla.org/show_bug.cgi?id=687116

Comment on attachment 612740 [details] [diff] [review] WIP Review of attachment 612740 [details] [diff] [review]: ----------------------------------------------------------------- overall this looks good. Mostly a simple restructuring, but it really opens the gates for better code! ::: talos/ttest.py @@ +74,1 @@ > RESULTS_RESPONSIVENESS_REGEX = re.compile('MOZ_EVENT_TRACE\ssample\s\d*?\s(\d*?)$', re.DOTALL|re.MULTILINE) what about the responsiveness regex?

(In reply to Joel Maher (:jmaher) from comment #5) > Comment on attachment 612740 [details] [diff] [review] > WIP > > Review of attachment 612740 [details] [diff] [review]: > ----------------------------------------------------------------- > > overall this looks good. Mostly a simple restructuring, but it really opens > the gates for better code! Thanks. I actually meant to put for feedback and not review as I don't intend on landing until I fix the actual bug, but thanks for looking at it. > ::: talos/ttest.py > @@ +74,1 @@ > > RESULTS_RESPONSIVENESS_REGEX = re.compile('MOZ_EVENT_TRACE\ssample\s\d*?\s(\d*?)$', re.DOTALL|re.MULTILINE) > > what about the responsiveness regex? I'm not sure what to do here. this regex is used in a different place and in a different way than the previous regexes. I thought about moving it to results.py and just having it called here, but i'm not sure its a real advantage. What do you think?

ideally all stdout parsing should take place in the same area. Especially stuff that we end up reporting. Since we do report the responsiveness stuff and it is part of the stdout, I would like to get it in the same area. The other hitch here is the counters. RSS is collected from stdout now, so we need to resolve that as well.

Okay, I'll do that fore responsiveness. For counters, we should probably really rethink them a bit. They are, across the board, currently a bit magic.

So there is a current strangeness with responsiveness: we parse it for each cycle, but we actually only use the last one: http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l412 http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l423 I'm guessing something is wrong here and don't know A. what we want to do and B. whether we want to tie this to this bug

(In reply to Jeff Hammel [:jhammel] from comment #9) > So there is a current strangeness with responsiveness: we parse it for each > cycle, but we actually only use the last one: > > http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l412 > http://hg.mozilla.org/build/talos/file/a9f14a82860e/talos/ttest.py#l423 > > I'm guessing something is wrong here and don't know A. what we want to do > and B. whether we want to tie this to this bug I'm going to work under the assumption that we want to extend versus overwrite the results. Lemme know if I'm wrong here

This gives better failure messages and has tests for parsing. In this I just extend all responsiveness finds as per comments. I don't know if this is what we want to do but I'm guessing what we do currently is wrong (the solutions are equivalent to the production case of having a single browser cycle).

Try run for d2f7dc4482aa is complete. Detailed breakdown of the results available here: https://tbpl.mozilla.org/?tree=Try&rev=d2f7dc4482aa Results (out of 76 total builds): success: 7 warnings: 2 failure: 67 Builds (or logs if builds failed) available at: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jhammel@mozilla.com-d2f7dc4482aa

Comment on attachment 612995 [details] [diff] [review] exactly the same as the previous, just updated a docstring Beh forgot a colon. Will put up a new patch shortly

pushed to try, https://tbpl.mozilla.org/?tree=Try&rev=ac954657a3d9, but happened to coincide with mad infrastructure failures. I tried restarting jobs but its pretty hard to say what is/isn't broken here, so I'll repush after this set of results come in. FWIW, none of the failures seemed related to the patch

Comment on attachment 613327 [details] [diff] [review] final patch, i hope Review of attachment 613327 [details] [diff] [review]: ----------------------------------------------------------------- a lot of code to review here, but this is looking really good. I am unclear on the PageLoaderResults class in results.py, maybe that is something for raw results?

pushed to try again: https://tbpl.mozilla.org/?tree=Try&rev=abd6b0240375 Its green except ts on android, which fails because the browser log isn't appropriately removed: OISE: __startTimestamp1332535908581__endTimestamp NOISE: __start_report2511__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332535925633 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332535923753" line: 0}] NOISE: __startTimestamp1332535926322__endTimestamp NOISE: __start_report2574__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332535975149 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332535973199" line: 0}] NOISE: __startTimestamp1332535975817__endTimestamp NOISE: __start_report2471__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332535994108 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332535992223" line: 0}] NOISE: __startTimestamp1332535994760__endTimestamp NOISE: __start_report2626__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332536013254 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332536011205" line: 0}] NOISE: __startTimestamp1332536013877__endTimestamp NOISE: __start_report3270__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332536033143 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332536030440" line: 0}] NOISE: __startTimestamp1332536033760__endTimestamp NOISE: __start_report2728__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332536051836 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332536049703" line: 0}] NOISE: __startTimestamp1332536052488__endTimestamp NOISE: __start_report2333__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332536071575 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332536069801" line: 0}] NOISE: __startTimestamp1332536072184__endTimestamp NOISE: __start_report2677__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1332536122896 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1332536120792" line: 0}] NOISE: __startTimestamp1332536123523__endTimestamp NOISE: __metrics Screen width/height:1280/800 NOISE: colorDepth:16 NOISE: Browser inner width/height: 1280/696 NOISE: __metrics__start_report3140__end_report NOISE: NOISE: Could not read chrome manifest 'file:///data/data/org.mozilla.fennec/chrome.manifest'. NOISE: zerdatime 1334088311122 - browser chrome startup finished. NOISE: OpenGL LayerManager Initialized Succesfully. NOISE: Version: OpenGL ES 2.0 NOISE: Vendor: NVIDIA Corporation NOISE: Renderer: NVIDIA Tegra NOISE: FBO Texture Target: TEXTURE_2D NOISE: [JavaScript Warning: "Use of enablePrivilege is deprecated. Please use code that runs with the system principal (e.g. an extension) instead." {file: "http://10.251.27.101:15707/startup_test/startup_test.html?begin=1334088308584" line: 0}] NOISE: __startTimestamp1334088311778__endTimestamp NOISE: __startBeforeLaunchTimestamp1334088475258__endBeforeLaunchTimestamp NOISE: __startAfterTerminationTimestamp1334088481479__endAfterTerminationTimestamp getting files in '/mnt/sdcard/tests/profile/minidumps/' Failed ts: Stopped Tue, 10 Apr 2012 13:08:05 FAIL: Busted: ts FAIL: Multiple matches for __start_report,__end_report [browser_output.txt] Traceback (most recent call last): File "/home/jhammel/talos/bin/talos", line 8, in <module> load_entry_point('talos==0.0', 'console_scripts', 'talos')() File "/home/jhammel/talos/talos/run_tests.py", line 675, in main test_file(arg, options, parser.parsed) File "/home/jhammel/talos/talos/run_tests.py", line 616, in test_file raise e talos.utils.talosError: 'Multiple matches for __start_report,__end_report [browser_output.txt]' This gets removed here, http://hg.mozilla.org/build/talos/file/4343f5e91fae/talos/ttest.py#l262 , but since we copy over the file from the android device this does not suffice. We'll need a bug to remove this file on the device before we can re-test this.

Try run for abd6b0240375 is complete. Detailed breakdown of the results available here: https://tbpl.mozilla.org/?tree=Try&rev=abd6b0240375 Results (out of 75 total builds): success: 73 failure: 2 Builds (or logs if builds failed) available at: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jhammel@mozilla.com-abd6b0240375

carrying jmaher's r+ forward

Try run for 00268ef06c83 is complete. Detailed breakdown of the results available here: https://tbpl.mozilla.org/?tree=Try&rev=00268ef06c83 Results (out of 77 total builds): success: 76 failure: 1 Builds (or logs if builds failed) available at: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jhammel@mozilla.com-00268ef06c83

looks pretty good, pushing

pushed: https://bug742937.bugzilla.mozilla.org/attachment.cgi?id=615368