{"id":192,"date":"2013-08-01T16:49:18","date_gmt":"2013-08-01T20:49:18","guid":{"rendered":"http:\/\/blog.mozilla.org\/nfroyd\/?p=192"},"modified":"2013-08-01T16:49:18","modified_gmt":"2013-08-01T20:49:18","slug":"visual-event-tracing-on-android-and-eideticker","status":"publish","type":"post","link":"https:\/\/blog.mozilla.org\/nfroyd\/2013\/08\/01\/visual-event-tracing-on-android-and-eideticker\/","title":{"rendered":"visual event tracing on android and eideticker"},"content":{"rendered":"

Over the last couple of weeks, I’ve been working with Jan Bambas’s visual event tracer<\/a> and using it to analyze why we’re slower than the stock Android browser on Eideticker’s New York Times pageload test<\/a>.<\/p>\n

The first order of business was to add trace-saving capabilities to the tracer.\u00a0 With this change, I could capture traces on my Android device and view them on my desktop, which is much more convenient than looking at them on my phone.\u00a0 (Especially because Simile Timeline<\/a>, which the about:timeline extension uses, is difficult to use on mobile and slow in Firefox<\/a>, so it needs all the CPU power it can get.\u00a0 If any JS hackers out there have a replacement timeline widget recommendation, I am all ears!)<\/p>\n

The second order of business was to modify Firefox to start and stop tracing automatically, rather than requiring the user to push buttons in about:timeline.\u00a0 Pushing buttons works fine on desktop, not so much on automated tests on mobile devices.\u00a0 I experimented with way too many fully general solutions before settling on the straightforward path: modifying nsDocShell::LoadURI<\/a> to start and stop the tracer when certain URIs were fetched.<\/p>\n

Now the tracer would automatically record profiles, on to viewing them!\u00a0 I modified Jan’s about:timeline extension to function properly in a browser not built with event tracing support.\u00a0 I also added the ability to use a trace saved in a file, rather than recording one in a browser.\u00a0 You can see the changes I made in my about:timeline github repository<\/a>.<\/p>\n

With all those changes in hand, we can view pretty pictures of what’s going on when the browser runs Eideticker tests.\u00a0 First, a normal Firefox for Android.<\/p>\n

\"android-cached\"<\/a><\/p>\n

That almost-4-second delay you see there is the cache getting opened.\u00a0 Yes, that’s happening on the main thread and yes, it’s blocking everything else from moving forward.\u00a0 This is a great illustration of why we are rewriting the network cache<\/a>.\u00a0 If the cache is so slow, what happens if we disable the cache?<\/p>\n

\"android-uncached\"<\/a><\/p>\n

It’s hard to tell from the picture, but if you looked at the Eideticker log of network requests, you’d see that everything completes somewhere around a 0.5-1 second faster (!).\u00a0 Why doesn’t it speed up more than that, since we’ve removed all that cache blocking by disabling the cache?\u00a0 Not sure yet, although you can see that cache entries are still getting opened.\u00a0 Also, you can see highlighted in the picture that the first network request takes about 250ms to start executing from the time that it’s fired off.\u00a0 That also needs to be investigated (and fixed!).<\/p>\n

What about this new cache rewrite, how does it fare?\u00a0 Thought you’d never ask.<\/p>\n

\"android-newcache\"<\/a><\/p>\n

Again, you have to check out the HTTP request log, but this is still another 0.3 seconds or so faster than the uncached<\/strong> case that we see above.\u00a0 So the new network cache is a clear win in this instance.\u00a0 It’s worth pointing out that the network request delays are still present here and are taking slightly longer than the cache-disabled case.\u00a0 Variance in profiles?\u00a0 Effects of the new cache?\u00a0 Not sure yet!<\/p>\n

I’m still figuring out my way around the tracer, but it’s a useful tool to peer into the Firefox network stack.\u00a0 It would be great if other subsystems (images, CSS, layout) would hook into the event tracer so we could have visibility into what they’re doing, too.\u00a0 The API is pretty simple<\/a> and causes no runtime overhead in our usual release builds.<\/p>\n","protected":false},"excerpt":{"rendered":"

Over the last couple of weeks, I’ve been working with Jan Bambas’s visual event tracer and using it to analyze why we’re slower than the stock Android browser on Eideticker’s New York Times pageload test. The first order of business was to add trace-saving capabilities to the tracer.\u00a0 With this change, I could capture traces […]<\/p>\n","protected":false},"author":320,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"_links":{"self":[{"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/posts\/192"}],"collection":[{"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/users\/320"}],"replies":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/comments?post=192"}],"version-history":[{"count":0,"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/posts\/192\/revisions"}],"wp:attachment":[{"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/media?parent=192"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/categories?post=192"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blog.mozilla.org\/nfroyd\/wp-json\/wp\/v2\/tags?post=192"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}