Firefox OS/Performance/Bisecting Regressions
Contents
Bisecting Regressions
This page will walk you through finding and bisecting performance regressions in Firefox OS.
Datazilla
Datazilla makes it easy to spot performance regressions in Firefox OS apps. The page that shows the performance test numbers is here: [1].
Performance regressions show up as spikes in the graphs like so (circled in red):
When you find a regression, you need to get the "regression range" for the regression. The regression range is the last known good revision to the first known bad revision for both Gecko and Gaia. To get the last known good revision IDs for both, click on the data point in the graph right before the spike. You will see something like this:
The Gaia and Gecko revisions used in the build and test that generated that data point are shown, circled in red. Write these down. You only need the first 7 characters of the IDs. So in this case you would write down d4655e7 for Gaia and a9f77f8 for Gecko.
To get the first know bad revision, click on the first data point after the spike. You will see something like this:
Again, you need to write down the revision IDs for both Gecko and Gaia, circled in red. So you would write down 9da1b9c for Gaia and b31f92b for Gecko.
The regression ranges are:
Gecko a9f77f8..b31f92b
Gaia d4655e7..9da1b9c
False Regressions
Sometimes we have false regressions either due to the test infrastructure or an error in datazilla. For each regression, if you cannot reproduce, please check the actual builds. For b2gperf, the link for builds are here - http://selenium.qa.mtv2.mozilla.com:8080/view/B2G%20Perf/. You need VPN access to get the builds. If you need access, ping stephend.
You have to manually dig through the logs to match the build id and gaia / gecko revision. These are usually found by looking at the console output, and searching for "gecko_revision" and "gaia_revision" and make sure they match up with datazilla.
One big signal that it is a datazilla issue is if the histogram of runs on datazilla show large sways and is not a consistent number. If this is the case, investigate datazilla before investigating the actual bisection.
Other Methods for Getting Revision ID Ranges
If all you have is a rough date range for a regression, you can still get revision ID ranges fairly easily. For gecko you'll be using mercurial to do this. However, the easiest way to get revision IDs is to use the web based pushlog and enter your date range in the "From:" and "To:" fields in the upper right and click "Search".
For Gaia, you will be using git on the command line. You will need a local clone of gaia. You then use git to list revisions between your dates:
$ git log --since="[branch@]DD-MM-YYYY" --until="[branch@]DD-MM-YYYY"
For example, if I want the revisions for the v1.2 branch between 10 January, 2014 and 15 January, 2014, I would run the following command:
$ git log --reverse --pretty="format:%h %aD" --since="v1.2@10-01-2014" --until="v1.2@15-01-2014"
The "pretty" format rule reduces the output to just the abbreviated revision ID and the date of the revision. The "reverse" just puts them in ascending order from oldest to newest. The output for the above command looks like this:
b93b2b2 Thu, 9 Jan 2014 11:42:28 -0800 e78d263 Fri, 10 Jan 2014 12:47:48 -0800 1e41341 Thu, 9 Jan 2014 12:31:14 -0500 b60845d Tue, 7 Jan 2014 19:26:32 -0200 b709981 Fri, 10 Jan 2014 15:14:48 -0800 15c5f8f Fri, 10 Jan 2014 14:49:13 -0800 4776e90 Fri, 10 Jan 2014 15:36:23 -0800 a3e966e Fri, 10 Jan 2014 16:23:38 -0800 ⋮ 2a8c898 Wed, 15 Jan 2014 10:41:04 -0800 c49a8f1 Wed, 15 Jan 2014 10:45:11 -0800 6b5ab7b Wed, 15 Jan 2014 17:57:03 +0000 f7cd69b Thu, 9 Jan 2014 11:33:42 -0500 70ba726 Wed, 15 Jan 2014 17:11:32 -0200 696fb30 Wed, 15 Jan 2014 11:35:04 -0800
One thing to notice is that they aren't in strict chronological order. That's because git lists a revisions's parents before the revision itself. Some commits have parent revisions are much older than a given revision and may not be the parent of any other revisions. This leads to logs with a much older revision being listed amongst newer revisions. You'll have to look at the log and think about if you need to include a given revision in your revision range for the git bisect command.
Setting up for Bisecting
You typically start off by creating a build of the latest master branch code for your device. I'm using the hamachi device in this tutorial because it is the device that Datazilla runs its tests on. To build master, do the following:
$ ENABLE_MARIONETTE=1 ./config.sh hamachi $ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh
Confirm that it builds, flashes, and the device reboots successfully.
Running b2gperf
This tutorial assumes that you have the b2gperf utility correctly set up on your host PC. If not, follow the instructions.
In our example, we are looking at the Contacts app. To run the tests that datazilla runs, you would execute b2gperf like so:
$ b2gperf --delay=10 --iterations=30 Contacts
These tests sometimes take a while to complete, so be patient. After it is done running, it will print out the results for you to compare to datazilla's numbers. I usually use the median value rather than the average value because it is influenced less by outliers in the gathered data.
Running the Correct Version of b2gperf
In some cases, you may have to bisect an old regression in gecko/gaia and the latest version of b2gperf won't work. Don't worry, way to make this work is to run the version of b2gperf that was current during the date range for the regression. To get the right version of b2gperf and its dependencies, you must use the pip python installer tool with a "requirements file". A requirements file explicitly specifies the modules and the exact version you want it to install. The contents of a requirements file looks something like this:
yoctopuce==1.01.12553 manifestdestiny==0.6 mozhttpd==0.7 mozprocess==0.18 mozrunner==5.35 mozdevice==0.33 moznetwork==0.24 mozcrash==0.12 mozprofile==0.21 moztest==0.3 marionette-client==0.6.2 datazilla==1.4 gaiatest==0.21.2 b2gperf==0.14
Building this file can be time consuming. You use start with the b2gperf pypi module page and you change the version number in the URL and look at the "Uploaded on" date to find the version that was current during the dates of your revision range. Luckily, we've already done the work for the last 6 months. Here's a list of b2gperf versions since December 2013:
https://pypi.python.org/pypi/b2gperf/0.26 -- 2014-05-01 https://pypi.python.org/pypi/b2gperf/0.25 -- 2014-04-09 https://pypi.python.org/pypi/b2gperf/0.24 -- 2014-03-31 https://pypi.python.org/pypi/b2gperf/0.23 -- 2014-03-27 https://pypi.python.org/pypi/b2gperf/0.22 -- 2014-03-25 https://pypi.python.org/pypi/b2gperf/0.21 -- 2014-03-25 https://pypi.python.org/pypi/b2gperf/0.20 -- 2014-03-06 https://pypi.python.org/pypi/b2gperf/0.19 -- 2014-02-28 https://pypi.python.org/pypi/b2gperf/0.18 -- 2014-02-18 https://pypi.python.org/pypi/b2gperf/0.17 -- 2014-02-18 https://pypi.python.org/pypi/b2gperf/0.16 -- 2014-02-07 https://pypi.python.org/pypi/b2gperf/0.15 -- 2014-01-29 https://pypi.python.org/pypi/b2gperf/0.14 -- 2013-12-13 https://pypi.python.org/pypi/b2gperf/0.13 -- 2013-12-12
Once you have found the correct b2gperf version, you must download the source tarball from the pypi page, decompress it, and then look at the contents of the setup.py file to find the dependencies and their versions. Here's what the contents of the b2gperf v0.18 setup.py file looks like:
# This Source Code Form is subject to the terms of the Mozilla Public
# License, v. 2.0. If a copy of the MPL was not distributed with this
# file, You can obtain one at http://mozilla.org/MPL/2.0/.
import os
from setuptools import setup, find_packages
version = '0.18'
# get documentation from the README
try:
here = os.path.dirname(os.path.abspath(__file__))
description = file(os.path.join(here, 'README.md')).read()
except (OSError, IOError):
description = ''
# dependencies
deps = ['b2gpopulate==0.17',
'datazilla>=1.2',
'gaiatest==0.21.7',
'mozdevice>=0.30',
'mozlog>=1.5',
'mozversion>=0.1',
'numpy==1.7.1']
setup(name='b2gperf',
version=version,
description="App startup tests for B2G",
long_description=description,
classifiers=[], # Get strings from http://pypi.python.org/pypi?%3Aaction=list_classifiers
keywords='mozilla',
author='Mozilla Automation and Testing Team',
author_email='tools@lists.mozilla.org',
url='https://github.com/davehunt/b2gperf',
license='MPL',
packages=find_packages(exclude=['ez_setup', 'examples', 'tests']),
package_data={'b2gperf': ['launchapp.js', 'scrollapp.js']},
include_package_data=True,
zip_safe=False,
entry_points="""
[console_scripts]
b2gperf = b2gperf.b2gperf:cli
""",
install_requires=deps,
)
The part that you care about is this:
# dependencies
deps = ['b2gpopulate==0.17',
'datazilla>=1.2',
'gaiatest==0.21.7',
'mozdevice>=0.30',
'mozlog>=1.5',
'mozversion>=0.1',
'numpy==1.7.1']
Those are the dependencies of b2gperf and their versions. Now you have to look those modules up on pypi, download the specified versions and look at their setup.py files to find their dependencies. You do this until you have built a comprehensive list of all dependencies for b2gperf. You then create a requirements file with those dependencies and their versions listed and you can then run pip with the requirements file to install everything:
$ pip install -r requirements.txt
Now you have the correct version of b2gperf installed and can continue bisecting the regression range.
Is it in Gecko or Gaia?
The first step in bisecting is to determine if the regression is in Gecko or Gaia. To do this, you have to test all four combinations of Gecko and Gaia revisions from the regression range. You need to test:
- Gecko a9f77f8 + Gaia d4655e7
- Gecko a9f77f8 + Gaia 9da1b9c
- Gecko b31f92b + Gaia 9da1b9c
- Gecko b31f92b + Gaia d4655e7
You use git to check out the last known good revisions of Gecko and Gaia:
$ cd gecko $ git checkout a9f77f8 $ cd ../gaia $ git checkout d4655e7 $ cd ..
Now that you have the correct revisions, time to do another build.
$ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh
Now, run b2gperf to see if the numbers match those on Datazilla:
$ adb forward tcp:2828 tcp:2828 $ b2gperf --delay=10 --iterations=30 Contacts mozversion.mozversion.RemoteB2GVersion INFO | Unable to find system/sources.xml 2014-04-16 19:26:57,244 B2GPerfRunner WARNING | Missing required DataZilla field: build revision 2014-04-16 19:26:57,244 B2GPerfRunner WARNING | Missing required DataZilla field: device name 2014-04-16 19:26:57,244 B2GPerfRunner WARNING | Missing required DataZilla field: oauth key 2014-04-16 19:26:57,245 B2GPerfRunner WARNING | Missing required DataZilla field: project 2014-04-16 19:26:57,245 B2GPerfRunner WARNING | Missing required DataZilla field: gecko revision 2014-04-16 19:26:57,245 B2GPerfRunner WARNING | Missing required DataZilla field: oauth secret 2014-04-16 19:26:57,245 B2GPerfRunner WARNING | Missing required DataZilla field: machine name 2014-04-16 19:26:57,245 B2GPerfRunner WARNING | Missing required DataZilla field: branch 2014-04-16 19:26:57,245 B2GPerfRunner INFO | Reports will not be submitted to DataZilla 2014-04-16 19:26:58,097 B2GPerfRunner INFO | Running B2GPerfLaunchContactsTest 2014-04-16 19:26:58,397 B2GPopulate INFO | Populating 200 contacts 2014-04-16 19:28:28,570 B2GPerfRunner INFO | Contacts [1/30] 2014-04-16 19:28:40,865 B2GPerfRunner INFO | Contacts [2/30] 2014-04-16 19:28:52,123 B2GPerfRunner INFO | Contacts [3/30] 2014-04-16 19:29:03,385 B2GPerfRunner INFO | Contacts [4/30] 2014-04-16 19:29:14,700 B2GPerfRunner INFO | Contacts [5/30] 2014-04-16 19:29:26,002 B2GPerfRunner INFO | Contacts [6/30] 2014-04-16 19:29:37,328 B2GPerfRunner INFO | Contacts [7/30] 2014-04-16 19:29:48,592 B2GPerfRunner INFO | Contacts [8/30] 2014-04-16 19:29:59,823 B2GPerfRunner INFO | Contacts [9/30] 2014-04-16 19:30:11,109 B2GPerfRunner INFO | Contacts [10/30] 2014-04-16 19:30:22,466 B2GPerfRunner INFO | Contacts [11/30] 2014-04-16 19:30:33,767 B2GPerfRunner INFO | Contacts [12/30] 2014-04-16 19:30:45,062 B2GPerfRunner INFO | Contacts [13/30] 2014-04-16 19:30:56,369 B2GPerfRunner INFO | Contacts [14/30] 2014-04-16 19:31:07,664 B2GPerfRunner INFO | Contacts [15/30] 2014-04-16 19:31:18,976 B2GPerfRunner INFO | Contacts [16/30] 2014-04-16 19:31:30,280 B2GPerfRunner INFO | Contacts [17/30] 2014-04-16 19:31:41,583 B2GPerfRunner INFO | Contacts [18/30] 2014-04-16 19:31:52,900 B2GPerfRunner INFO | Contacts [19/30] 2014-04-16 19:32:04,212 B2GPerfRunner INFO | Contacts [20/30] 2014-04-16 19:32:15,524 B2GPerfRunner INFO | Contacts [21/30] 2014-04-16 19:32:26,824 B2GPerfRunner INFO | Contacts [22/30] 2014-04-16 19:32:38,122 B2GPerfRunner INFO | Contacts [23/30] 2014-04-16 19:32:49,445 B2GPerfRunner INFO | Contacts [24/30] 2014-04-16 19:33:00,803 B2GPerfRunner INFO | Contacts [25/30] 2014-04-16 19:33:12,114 B2GPerfRunner INFO | Contacts [26/30] 2014-04-16 19:33:23,431 B2GPerfRunner INFO | Contacts [27/30] 2014-04-16 19:33:34,747 B2GPerfRunner INFO | Contacts [28/30] 2014-04-16 19:33:46,057 B2GPerfRunner INFO | Contacts [29/30] 2014-04-16 19:33:57,374 B2GPerfRunner INFO | Contacts [30/30] 2014-04-16 19:33:57,376 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:910, mean:935, std: 148, max:1732, min:877, all:923,1732,890,898,915,911,913,896,877,917,886,908,904,909,910,911,904,902,909,916,919,910,909,918,942,910,916,902,914,908
So in this example the median value is 910, in Datazilla it is 885. They are within 5% of each other so I consider that a match. Now let's change the Gaia revision to the first known bad revision and re-run the tests to see what we get:
$ cd gaia $ git checkout 9da1b9c $ cd .. $ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh $ adb forward tcp:2828 tcp:2828 $ b2gperf --delay=10 --iterations=30 Contacts ⋮ 2014-04-16 19:53:03,381 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1306, mean:1332, std: 95, max:1818, min:1282, all:1326,1818,1312,1306,1303,1303,1305,1295,1312,1303,1294,1292,1306,1286,1320,1297,1282,1307,1310,1323,1304,1312,1325,1292,1379,1334,1311,1365,1440,1305
The median value has jumped up significantly. This certainly looks like the regression was caused by Gaia. Let's make sure by now updating Gecko to its first known bad revision and re-running b2gperf:
$ cd gecko $ git checkout b31f92b $ cd .. $ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh $ adb forward tcp:2828 tcp:2828 $ b2gperf --delay=10 --iterations=30 Contacts ⋮ 2014-04-16 20:30:27,323 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1304, mean:1318, std: 84, max:1752, min:1208, all:1323,1752,1305,1308,1296,1271,1302,1273,1271,1300,1282,1323,1299,1208,1295,1317,1313,1330,1326,1297,1318,1287,1308,1307,1343,1323,1304,1358,1300,1302
You can see that the median value is 1304, which is nearly identical to the median of the previous result. This tells you that the regression is definitely in Gaia and you don't need to test the fourth possible combination of Gecko and Gaia.
Bisecting Gecko/Gaia
To bisect the Gaia code, you will use the git bisect command to automate the selection of revisions to test. It does a binary search for the revision that caused the regression. Before you start your own bisect, I need to point out that the "git bisect start" command takes the revision IDs of your regression range in BAD then GOOD order like so:
$ git bisect start <first know bad> <last known good>
So to kick off the bisect of Gaia, I run:
$ cd gaia $ git bisect start 9da1b9c d4655e7 Bisecting: 33 revisions left to test after this (roughly 5 steps) [9e90675d3486ad7494e7333fcf2871c8510e4736] Merge pull request #15833 from gitmai/bug-965512-costcontrol-jshint-fix $ cd ..
Git has chosen revision 9e90675 as the next revision of Gaia to test. It is roughly halfway between the regression range revisions. So now, we need to make a build and test it:
$ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh $ adb forward tcp:2828 tcp:2828 $ b2gperf --delay=10 --iterations=30 Contacts ⋮ 2014-04-16 22:27:23,370 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1315, mean:1332, std: 88, max:1792, min:1262, all:1342,1792,1309,1293,1303,1302,1291,1290,1298,1311,1313,1331,1319,1316,1346,1354,1315,1320,1341,1324,1361,1318,1350,1262,1326,1300,1310,1296,1308,1321
The median of 1315 means that this revision is bad. Let's tell git that by running git bisect bad:
$ cd gaia $ git bisect bad Bisecting: 15 revisions left to test after this (roughly 4 steps) [f7700e69a1bc2fbbabb80bf3aebcc77498a5647a] Bug 951670 - Contacts list edit mode: Update layout $ cd ..
Now we test the next revision, f7700e6:
$ ENABLE_MARIONETTE=1 ./build.sh -j $ ENABLE_MARIONETTE=1 ./flash.sh $ adb forward tcp:2828 tcp:2828 $ b2gperf --delay=10 --iterations=30 Contacts ⋮ 2014-04-16 22:47:14,481 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1316, mean:1339, std: 102, max:1876, min:1269, all:1329,1876,1314,1300,1322,1286,1299,1320,1308,1333,1324,1323,1307,1269,1307,1316,1381,1314,1317,1312,1340,1313,1365,1290,1354,1316,1364,1306,1325,1357
Again, the test revision is bad:
$ cd gaia $ git bisect bad Bisecting: 8 revisions left to test after this (roughly 3 steps) [80af23f8c74d9d2e9388d8ed3c204040b5c528ec] Revert "Bug 974253 - Set preferred network type on startup based on the user preference" $ cd ..
And so the bisecting goes. The rest of the bisect process looks like this:
$ ENABLE_MARIONETTE=1 ./build.sh -j
$ ENABLE_MARIONETTE=1 ./flash.sh
$ adb forward tcp:2828 tcp:2828
$ b2gperf --delay=10 --iterations=30 Contacts
⋮
2014-04-16 23:06:16,509 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1302, mean:1321, std: 87, max:1789, min:1281,
all:1351,1789,1300,1301,1281,1302,1292,1296,1311,1292,1301,1313,1291,1299,1330,1316,1305,1295,1299,1303,1321,1312,1316,1307,1317,1281,1298,1301,1321,1313
$ cd gaia
$ git bisect bad
Bisecting: 2 revisions left to test after this (roughly 2 steps)
[befb78cce80144ba6c0783aefcf6b98439d0a8e9] Merge pull request #16477 from crh0716/974253
$ cd ..
$ ENABLE_MARIONETTE=1 ./build.sh -j
$ ENABLE_MARIONETTE=1 ./flash.sh
$ adb forward tcp:2828 tcp:2828
$ b2gperf --delay=10 --iterations=30 Contacts
⋮
2014-04-16 23:17:43,499 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:908, mean:935, std: 131, max:1635, min:885,
all:945,1635,885,891,953,918,933,895,899,886,899,950,908,907,904,916,886,908,916,910,928,920,909,917,913,907,914,908,896,902
$ cd gaia
$ git bisect good
Bisecting: 0 revisions left to test after this (roughly 1 step)
[5c0b52751c7cf9f73d44126916a822baf65e2547] Merge pull request #17514 from alivedise/bugzilla/961800_master_merging/child-window-factory
$ cd ..
$ ENABLE_MARIONETTE=1 ./build.sh -j
$ ENABLE_MARIONETTE=1 ./flash.sh
$ adb forward tcp:2828 tcp:2828
$ b2gperf --delay=10 --iterations=30 Contacts
⋮
2014-04-16 23:31:51,981 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1308, mean:1323, std: 93, max:1819, min:1278,
all:1337,1819,1287,1308,1310,1283,1278,1284,1293,1289,1290,1311,1324,1289,1313,1290,1309,1322,1296,1337,1352,1317,1308,1305,1312,1304,1299,1309,1341,1279
$ cd gaia
$ git bisect bad
Bisecting: 0 revisions left to test after this (roughly 0 steps)
[439e40ef0e79393f94ca102b9fbd0785355e4b34] Bug 961800 - Implement Child Window Factory.
$ cd ..
$ ENABLE_MARIONETTE=1 ./build.sh -j
$ ENABLE_MARIONETTE=1 ./flash.sh
$ adb forward tcp:2828 tcp:2828
$ b2gperf --delay=10 --iterations=30 Contacts
⋮
2014-04-16 23:44:55,905 B2GPerfRunner INFO | Results for Contacts, cold_load_time: median:1304, mean:1325, std: 96, max:1822, min:1251,
all:1334,1822,1293,1278,1319,1267,1278,1281,1290,1338,1313,1301,1306,1301,1326,1291,1251,1299,1307,1338,1314,1319,1287,1329,1302,1299,1277,1374,1363,1377
$ cd gaia
$ git bisect bad
439e40ef0e79393f94ca102b9fbd0785355e4b34 is the first bad commit
commit 439e40ef0e79393f94ca102b9fbd0785355e4b34
Author: Alive Kuo <alegnadise@gmail.com>
Date: Mon Feb 3 11:49:44 2014 +0100
Bug 961800 - Implement Child Window Factory.
Conflicts:
apps/system/js/app_transition_controller.js
apps/system/js/app_window.js
apps/system/js/app_window_manager.js
apps/system/js/cards_view.js
apps/system/style/window.css
:100644 100644 635b6e3f784982c7c3944ba50a05a3259b8a8fab 11c79904ce42b229c18a28d24c9bd20ed718dda8 M Makefile
:040000 040000 e3b5cbb0db28d2a6e75962207f44dc2a630d7e10 d3cc2b91fe4a8ae471ab9e2f3ee3eb7c0f246305 M apps
:040000 040000 c787ffbabb879c3fc111407aefdefa257f68b019 b27d5e19622014e8f61747a18627aa521d5a890b M build
:040000 040000 4ca18cee8ccb928feb6bd18f06d287330d8bf5ee eef9f32e75e5581c3561fcb17cd2dc21085761e6 M test_apps
:040000 040000 ae9d9dfa93d8af9eb44623fd2b4466036a5f4cbb 154ad42f68f34472427c9bf1b6a07ff7f199882d M tests
