{"id":722,"date":"2011-03-02T07:59:56","date_gmt":"2011-03-02T15:59:56","guid":{"rendered":"http:\/\/www.visophyte.org\/blog\/?p=722"},"modified":"2011-03-02T07:59:56","modified_gmt":"2011-03-02T15:59:56","slug":"teaser-rich-contextual-information-for-thunderbird-mozmill-failures","status":"publish","type":"post","link":"https:\/\/www.visophyte.org\/blog\/2011\/03\/02\/teaser-rich-contextual-information-for-thunderbird-mozmill-failures\/","title":{"rendered":"teaser: Rich contextual information for Thunderbird mozmill failures"},"content":{"rendered":"<p><img loading=\"lazy\" decoding=\"async\" class=\"size-full wp-image-724 alignnone\" title=\"unhappy-popups-screenshot-from-bad-wm\" src=\"http:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-screenshot-from-bad-wm.png\" alt=\"\" width=\"503\" height=\"444\" srcset=\"https:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-screenshot-from-bad-wm.png 503w, https:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-screenshot-from-bad-wm-300x264.png 300w\" sizes=\"auto, (max-width: 503px) 100vw, 503px\" \/><\/p>\n<p>Sometimes <a href=\"https:\/\/developer.mozilla.org\/en\/Thunderbird\/Thunderbird_MozMill_Testing\">Thunderbird mozmill<\/a> unit tests fail. \u00a0When they do, it&#8217;s frequently a mystery. \u00a0My <a href=\"http:\/\/www.visophyte.org\/blog\/2011\/01\/14\/logsploder-circa-a-year-ago\/\">logsploder<\/a> work helped reduce the mystery for my local mozmill test runs, but did nothing for tinderbox runs or developers without tool fever. \u00a0Thanks to recent renewed activity on the Thunderbird front-end, this has become more of a problem and so it was time for another round of amortized tool building towards a platonic ideal.<\/p>\n<p>The exciting pipeline that leads to screenshots like you see in this post:<\/p>\n<p><a href=\"http:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-from-bad-wm.png\"><img loading=\"lazy\" decoding=\"async\" class=\"alignnone size-thumbnail wp-image-725\" title=\"unhappy-popups-from-bad-wm\" src=\"http:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-from-bad-wm-600x258.png\" alt=\"\" width=\"600\" height=\"258\" srcset=\"https:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-from-bad-wm-600x258.png 600w, https:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-from-bad-wm-300x129.png 300w, https:\/\/www.visophyte.org\/blog\/wp-content\/uploads\/2011\/03\/unhappy-popups-from-bad-wm.png 907w\" sizes=\"auto, (max-width: 600px) 100vw, 600px\" \/><\/a><\/p>\n<ul>\n<li>Thunderbird Mozmill tests run with the testing framework set to log semi-rich object representations to in-memory per-test buckets.<\/li>\n<li>In the event of a test failure, the in-Thunderbird test framework:\n<ul>\n<li>Gathers information about the state of the system now that we know there is a failure and emit it. \u00a0This takes the form of canvas-based screenshots (using chrome privileges) of all open windows in the application, plus the currently focused element in the window.<\/li>\n<li>Emits (up to) the last 10 seconds of log events from the previous test.<\/li>\n<li>Emits all of the log events from the current test.<\/li>\n<\/ul>\n<\/li>\n<li>The python test driver receives the emitted data and dumps it to stdout in a series of JSON blobs that are surrounded by magical annotations.<\/li>\n<li>A node.js daemon doing the database-based tinderboxpushlog thing (like my <a href=\"http:\/\/www.visophyte.org\/blog\/2010\/03\/03\/tinderbox-results-in-bugzilla-jetpack-times-2-couchdb-review-board\/\">previous Jetpack\/CouchDB work<\/a> that <a href=\"http:\/\/www.visophyte.org\/blog\/2010\/08\/08\/clicky-visophyte-org-hosted-couchdb-services-offline\/\">found CouchDB to not be a great thing to directly expose to users and died<\/a>, but now with node and hbase) processes the tinderbox logs for the delicious JSON blobs.\n<ul>\n<li>It also processes xpcshell runs and creates an MD5 hash that attempts to characterize the specific fingerprint of the run. \u00a0Namely, xpcshell emits lines prefixed with &#8220;TEST-&#8221; that have a regular form to describe when the pending test count changes or when specific comparison operations or failures occur. \u00a0It is assumed that tests will not comparison check values that are effectively random values, that the comparisons will tend to be deterministic (even if there are random orderings in the test) or notable when not deterministic, and thus that the trace derived from this filtering and hashing will be sufficiently consistent that similar failures should result in identical hashes.<\/li>\n<li>Nothing is done with mochitests because: Thunderbird does not have them, they don&#8217;t appear to emit any context about their failures, and as far as I can tell, frequently the source of a mochitest failure is the fault of an earlier test that claimed it had completed but still had some kind of ripples happening that broke a later test.<\/li>\n<\/ul>\n<li>A wmsy-based UI does the UI thing.<\/li>\n<ul><\/ul>\n<\/li>\n<\/ul>\n<p>The particular failure shown here is an interesting one where the exception is telling us that a popup we expected to open never opened. \u00a0But when we look at the events from the log, we can see that what happened is the popup opened and then immediately closed itself. \u00a0Given that this happened (locally) on linux, this made me suspect that the window manager didn&#8217;t let the popup acquire focus and perform a capture. \u00a0It turns out that I forgot to install the xfwm4 window manager on my new machine which my xvnc session&#8217;s xstartup script was trying to run in order to get a window manager that plays nicely with mozmill and our focus needs. \u00a0(Many window managers have configurable focus protection that converts a window trying to grab focus into an attention-requested notification.)<\/p>\n<p>This is a teaser because it will probably be a few more days before the required patch lands on comm-central, I use <a href=\"http:\/\/requirejs.org\/\">RequireJS<\/a>&#8216; fancy new <a href=\"http:\/\/requirejs.org\/docs\/optimization.html\">optimizer<\/a> to make the client load process more efficient, and I am happy that the server daemons can keep going for long stretches of time without messing up. \u00a0The server and client code is available <a href=\"https:\/\/github.com\/asutherland\/arbitrarypushlog\">on github<\/a>, and the <a href=\"http:\/\/hg.mozilla.org\/users\/bugmail_asutherland.org\/comm-central-patches\/file\/97ef5f6b655e\/mozmill-dump-useful-data-on-failure\">comm-central patch from hg<\/a>.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Sometimes Thunderbird mozmill unit tests fail. \u00a0When they do, it&#8217;s frequently a mystery. \u00a0My logsploder work helped reduce the mystery for my local mozmill test runs, but did nothing for tinderbox runs or developers without tool fever. \u00a0Thanks to recent &hellip; <a href=\"https:\/\/www.visophyte.org\/blog\/2011\/03\/02\/teaser-rich-contextual-information-for-thunderbird-mozmill-failures\/\">Continue reading <span class=\"meta-nav\">&rarr;<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"inline_featured_image":false,"footnotes":""},"categories":[7,6],"tags":[106,52,55,105,104],"class_list":["post-722","post","type-post","status-publish","format-standard","hentry","category-debugging","category-thunderbird","tag-arbpl","tag-logging","tag-logsploder","tag-mozmill","tag-node-js"],"_links":{"self":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/722","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/comments?post=722"}],"version-history":[{"count":7,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/722\/revisions"}],"predecessor-version":[{"id":731,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/722\/revisions\/731"}],"wp:attachment":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/media?parent=722"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/categories?post=722"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/tags?post=722"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}