1007220 - Add webapp startup test

Status: RESOLVED FIXED

(Testing Graveyard :: Autophone, defect)

Description

[James Willcox (:snorp) ([e-mail]) (he/him)]

We should add an autophone test that times webapp startup time. We should be able to write a basic webapp that just console.log()s something when it loads -- which should then be viewable in the logcat.

Comment 1

[Bob Clary [:bc] (inactive)]

snorp, thanks!

https://github.com/snorp/webapp-startup-test/blob/master/Makefile

Comment 2

[Bob Clary [:bc] (inactive)]

Attachment: bug-1007220.patch

This patch is a 'wip' that I have been testing. You can see the actual results at <http://phonedash-dev.allizom.org/#/org.mozilla.fennec/totalthrobber/webappstartup/norejected/2014-06-09/2014-06-09/notcached/errorbars/standarderror>.

mcote: There is some duplication of code between this and s1s2test but I'd rather not spend much (any) time at the moment trying to minimize it since I think our performance test approach will change quite a bit for treeherder and I expect we will be able to consolidate much of the common code for various performance tests into a single class.

There is also some remnant of the profile creating code which is not being used. I've tried using profiles but couldn't get them to work. I've left that in case we do come up with a profile management approach using webapps.

The real meat is in how the times are collected and reported. The test name is webappstartup and it reuses the throbber start, stop and total times in the phonedash db and ui. The actual values are obtained from logcat using:

'chrome startup time' aka Throbber Start:
D/GeckoBrowser.*: zerdatime .* - browser chrome startup finished.

'startup time' aka Throbber Stop:
E/GeckoConsole.*WEBAPP STARTUP COMPLETE

For each test:

For each iteration:

If necessary Fennec and the Webapp are uninstalled, then Fennec is installed, followed by the Webapp. The 'uncached' value is from a first run.  After the uncached value is detected, the webapp and fennec are killed. Then the webapp is started again to obtain the 'cached' values.

This is using the default webapp profile created inside of fennec's files/mozilla directory. There is no profile initialization since I don't have control over the profile being used. --es args '--profile /data/local/tmp/profile' does not appear to work. There is also no crash detection for the same reason.

Looking at phonedash-dev, you can see all of the values have fairly high variability. There are a number of measurements which were rejected on the first attempt due to their standard error exceeding the 10% cut off. The cached values are practically unusable. This doesn't quite agree with a local test I did on a few builds, so I will run them again locally to see if they reproduce the same variability.

I need the following:

1. are the chrome start and webapp start up measurement detections ok?

2. is there a better way to cleanly stop the webapp other than killing it and fennec?

3. is there a way to create and use a specific profile with a webapp?

4. is the cached measurement after killing fennec/webapp what you want or would you rather measure the times to reinvoke an already running webapp?

Comment 3

[Mark Côté [:mcote]]

Comment on attachment 8437716 [details] [diff] [review]
bug-1007220.patch

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

Hm yeah, that is quite a lot of duplicated code... makes me uneasy, but against my better judgement I'll f+ this knowing that we'll be refactoring everything soon, hopefully before we add more tests.

Comment 4

[James Willcox (:snorp) ([e-mail]) (he/him)]

Bob and I talked about this some. The measurements seem ok to me, though I was hoping it wouldn't be so noisy. We can try to solve the profile thing.

Comment 5

[Bob Clary [:bc] (inactive)]

Attachment: bug-1007220-webapp-startup.patch

Mark, this creates a base class PerfTest and subclasses it for WebappStartupTest and S1S2Test.

It also includes the adb.py and adb_android.py changes from bug 1012711 which you can ignore.

Comment 6

[Bob Clary [:bc] (inactive)]

Attachment: phonetest-proc-fix.patch

This fixes a warning where I reference an undefined proc. I'll bundle this with the previous patch when I land it.

Comment 7

[Mark Côté [:mcote]]

Comment on attachment 8445913 [details] [diff] [review]
bug-1007220-webapp-startup.patch

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

Looks good!  I think you may have gone overboard a bit with vertical spacing, particularly in docstrings, but nothing important.

::: adb.py
@@ +140,5 @@
> +        """Executes an adb command on the host.
> +
> +        :param cmds: list containing the command and its arguments to be
> +            executed.
> +        :param device_serial: optional string specifying the device'

device's

@@ +154,5 @@
> +        command() provides a low level interface for executing
> +        commands on the host via adb.
> +
> +        For commands targeting specific devices, ADBDevice.command is
> +        preferred. To execute shell commands on specific devices, 

Trailing space.

@@ +155,5 @@
> +        commands on the host via adb.
> +
> +        For commands targeting specific devices, ADBDevice.command is
> +        preferred. To execute shell commands on specific devices, 
> +        ADBDevice.shell is preferred.

This is a little confusing... I think a bit of clarification that command() is used for commands executed on the host and shell() for commands executed on the device.  Assuming that's accurate. :)

@@ +161,5 @@
> +        The caller provides a list containing commands, as well as a
> +        timeout period in seconds.
> +
> +        A subprocess is spawned to execute adb with stdout and stderr
> +        directed to named temporary files. If the process takes longer

According to ADBProcess, these are TemporaryFiles, not NamedTemporaryFiles.

@@ +178,5 @@
> +
> +        if timeout is None:
> +            timeout = self._timeout
> +
> +        timeout = int(timeout)

Are you expecting non-integers to be passed in?

@@ +200,5 @@
> +        """Executes an adb command on the host returning stdout.
> +
> +        :param cmds: list containing the command and its arguments to be
> +            executed.
> +        :param device_serial: optional string specifying the device'

device's

@@ +339,5 @@
> +                        self._logger.warning('devices: Unable to parse '
> +                                             'remainder for device %s' % line)
> +                devices.append(device)
> +        return devices
> +

Double space between classes.

::: autophone.ini.example
@@ +17,5 @@
>  
>  #build_cache_size = 20
>  #build_cache_expires = 7
> +# device_ready_retry_wait = 20
> +# device_ready_retry_attempts = 3

Why the extra space?

::: tests/webappstartup.py
@@ +295,5 @@
> +        max_time = 90 # maximum time to wait for WEBAPP STARTUP COMPLETE
> +        wait_time = 3 # time to wait between attempts
> +        max_attempts = max_time / wait_time
> +
> +        while (attempt < max_attempts and startup_time == 0):

Don't need parens.

@@ +383,5 @@
> +            self.loggerdeco.debug('analyze_logcat: base: %s, start: %s, '
> +                                  'chrome time: %s, startup_time: %s ' %
> +                                  (base_time, start_time, chrome_time, startup_time))
> +
> +            if (start_time > chrome_time):

No parents.

Comment 8

[Bob Clary [:bc] (inactive)]

(In reply to Mark Côté ( :mcote ) from comment #7)
> Comment on attachment 8445913 [details] [diff] [review]
> bug-1007220-webapp-startup.patch
> 
> Review of attachment 8445913 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> @@ +155,5 @@
> > +        commands on the host via adb.
> > +
> > +        For commands targeting specific devices, ADBDevice.command is
> > +        preferred. To execute shell commands on specific devices, 
> > +        ADBDevice.shell is preferred.
> 
> This is a little confusing... I think a bit of clarification that command()
> is used for commands executed on the host and shell() for commands executed
> on the device.  Assuming that's accurate. :)

Yeah, overloading the word command does make things a bit confusing. In the following I'll use an undecorated command when using the word in its normal sense and a quoted 'command' when using it to describe the methods.

The intended distinction between 'command' and 'shell' are that:

* 'command' executes on the host in such a fashion that stdout and stderr of the adb process are file handles on the host and the exit code is available as the exit code of the adb process. In general the usage could be for non-device specific commands such as 'devices' or device specific commands such as 'logcat' but I wanted to restrict it as described below.

* 'shell' executes on the host in such as fashion that stdout contains the stdout of the host abd process combined with the combined stdout/stderr of the shell command on the device while stderr is still the stderr of the adb process on the host. The exit code of 'shell' *should* be the exit code of the adb command if it was non-zero or the extracted exit code from the stdout/stderr of the shell command executed on the device. Currently, if the adb shell command terminates within the timeout period, the exit code of adb is ignored and only the exit code from the device's stdout+stderr is returned. I think this is a bug.

ADBCommand.command has the device_serial argument to target a specific device but that is only so we can use the inherited method in the ADBDevice class. I should have made it more clear that ADBCommand should never be used directly. Do you have a recommendation on how to make this programatically enforceable?

ADBHost should be used for non-device specific commands such as 'adb devices' or 'adb start-server' or 'adb kill-server' and the device_serial argument shouldn't be used. I could and probably should enforce this programatically by raising an exception if ADBHost.command is given a device_serial argument.

ADBDevice should be used for all device specific commands. This includes both 'command', such as adb -s <serial> logcat, and 'shell', such as adb -s <serial> shell 'ls /system/'.


> 
> @@ +178,5 @@
> > +
> > +        if timeout is None:
> > +            timeout = self._timeout
> > +
> > +        timeout = int(timeout)
> 
> Are you expecting non-integers to be passed in?
> 

No, I think this was just copied from DeviceManager.

Comment 9

[Bob Clary [:bc] (inactive)]

Attachment: bug-1007220-webapp-startup.patch v3

Mark, Will: I changed ADBCommand to a private class _ADBCommand and cleaned up ADBHost's docstring a bit. I've pushed updated mozdevice rest docs to http://people.mozilla.org/~bclary/mozdevice/mozdevice.html#adb-interface to show the updates more clearly.

If this passes muster, I'll file a bug to incorporate these changes to mozdevice in m-c.

Comment 10

[Mark Côté [:mcote]]

Hm this seems pretty non idiomatic, in that I don't think I've seen underscore-prefixed private classes before, and I think user-defined dunder methods (e.g. __foo__) isn't recommended, since they generally refer to special methods.

I was about to say that someone instantiating an ADBCommand directly is probably not worth worrying about, but then I remembered that we had a similar problem with people neglecting to use specific methods in DeviceManager and creating their own via shell() or whatever.  So there might be a real concern there... but I don't think this is the way to solve it.  Python does have an Abstract Base Class module; that might be a more idiomatic solution.

Leaving r? for now, as I'd like to hear wlach's feedback.

Comment 11

[Bob Clary [:bc] (inactive)]

I picked the _ADBCommand name since sphinx won't generate docs by default for items which have a _ prefix which seemed like a good first step in not having people use it directly.

I looked at the Abstract Base Class stuff a bit but it seemed really weird to me and didn't really address my concern that I didn't want _ADBCommand instantiated.

I could use something like _initialize or _initialize_ to signify the private nature of the method instead of the double __.

Or better yet, I could just use the normal __init__ and inside test  self.__class__ == _ADBCommand and raise a NotImplementedError. That way attempts to create an _ADBCommand would fail but child classes would not.

Comment 12

[Bob Clary [:bc] (inactive)]

Attachment: bug-1007220-webapp-startup.patch v4

Keep _ADBCommand but remove __initialize__, check self.__class__ in _ADBCommand.__init__ to raise NotImplementedError if _ADBCommand is instantiated directly.

Comment 13

[William Lachance (:wlach)]

Comment on attachment 8449957 [details] [diff] [review]
bug-1007220-webapp-startup.patch v4

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

Not that familiar with the guts of autophone, but this looks reasonable to me.

I wonder if we should consider converting some of this logging stuff to structured logging (for ease of integration with treeherder, among other things) and if so, how we would incorporate the "dictionary" of metadata into it.

I don't have a strong opinion on ABCCommand. I tend to think that using python's abstract base class here is the right thing to do, since it's more idiomatic. Or just not caring if people instantiate one standalone, honestly. I think this is a bit different than the abuse of DeviceManagerADB that we saw a year or so ago... I think in most cases here, people won't be using these classes directly. But I'm pretty much fine with whatever you choose. Seems like it's one of those things that could go either way.

::: tests/perftest.py
@@ +105,5 @@
> +                   cache_enabled, starttime, tstrt, tstop, tstop - tstrt, rejected))
> +        self.loggerdeco.debug('RESULTS: %s' % msg)
> +
> +        # Create JSON to send to webserver
> +        resultdata = {}

I think it would be clearer to do something like:

resultdata = { 'phoneid': self.phone_cfg['phoneid'], 
               'testname': testname,
                ... }

@@ +150,5 @@
> +        query = {}
> +        query['phoneid'] = self.phone_cfg['phoneid']
> +        query['test'] = testname
> +        query['revision'] = self.build_metadata['revision']
> +        query['product'] = self.fennec_appname

Likewise, I think it would be better to create the dictionary in one shot here.

Comment 14

[Mark Côté [:mcote]]

Comment on attachment 8449957 [details] [diff] [review]
bug-1007220-webapp-startup.patch v4

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

As discussed over vidyo, I think ADBCommand shouldn't be private, since it now can't be instantiated directly, and its inherited methods should be in the user documentation.

I also lean a bit towards using AbstractBaseClasses, but I have to admit that the official docs for the class really don't make the rationale for using it here particularly clear, even if it is in fact actually suitable.  bc's solution is pretty clean, so I'm fine with it.

Comment 15

[Bob Clary [:bc] (inactive)]

(In reply to William Lachance (:wlach) from comment #13)
> Comment on attachment 8449957 [details] [diff] [review]
> bug-1007220-webapp-startup.patch v4
> 
> Review of attachment 8449957 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Not that familiar with the guts of autophone, but this looks reasonable to
> me.
> 
> I wonder if we should consider converting some of this logging stuff to
> structured logging (for ease of integration with treeherder, among other
> things) and if so, how we would incorporate the "dictionary" of metadata
> into it.
> 

I'd rather leave that to when we actually start to talk to treeherder. I don't think a lot of the current logging would be appropriate for treeherder since it is currently really for debugging autophone's operation.

I would expect we could create/grab a different logger with formatter and handler to send the appropriate stuff to treeherder.

> I don't have a strong opinion on ABCCommand. I tend to think that using
> python's abstract base class here is the right thing to do, since it's more
> idiomatic. Or just not caring if people instantiate one standalone,
> honestly. I think this is a bit different than the abuse of DeviceManagerADB
> that we saw a year or so ago... I think in most cases here, people won't be
> using these classes directly. But I'm pretty much fine with whatever you
> choose. Seems like it's one of those things that could go either way.
> 

The Abstract Base Class stuff seems so orthogonal to the result I'd like to achieve. I guess my use case is kind of backwards in that I don't want the base class to be able to call the method but I do want the child class to. I'm open to other ideas. Let's work it out after this lands in Autophone and mozdevice.

> 
> I think it would be clearer to do something like:
> 
> resultdata = { 'phoneid': self.phone_cfg['phoneid'], 
>                'testname': testname,
>                 ... }
> 

done

> 
> Likewise, I think it would be better to create the dictionary in one shot
> here.

done

(In reply to Mark Côté ( :mcote ) from comment #14)
> Comment on attachment 8449957 [details] [diff] [review]
> bug-1007220-webapp-startup.patch v4
> 
> Review of attachment 8449957 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> As discussed over vidyo, I think ADBCommand shouldn't be private, since it
> now can't be instantiated directly, and its inherited methods should be in
> the user documentation.
> 

done

> I also lean a bit towards using AbstractBaseClasses, but I have to admit
> that the official docs for the class really don't make the rationale for
> using it here particularly clear, even if it is in fact actually suitable. 
> bc's solution is pretty clean, so I'm fine with it.

Yeah, I actually don't get it. I want to not allow instantiation of ADBCommand, but do want ADBHost and ADBDevice to call ADBCommand's __init__. Not sure how the abc really helps.

https://github.com/mozilla/autophone/commit/92416ceff7514e5210e1fe5f682cd1bc0bc94109

I had some tussles with git but I'm pretty sure I didn't lose or add anything.