def __init__(self, worker_num, ipaddr, tests, phone_cfg, user_cfg,
autophone_queue, logfile_prefix, loglevel, mailer,
build_cache_port):
self.phone_cfg = phone_cfg
self.user_cfg = user_cfg
self.worker_num = worker_num
self.ipaddr = ipaddr
self.last_status_msg = None
self.first_status_of_type = None
self.last_status_of_previous_type = None
self.crashes = Crashes(crash_window=user_cfg[PHONE_CRASH_WINDOW],
crash_limit=user_cfg[PHONE_CRASH_LIMIT])
self.cmd_queue = multiprocessing.Queue()
self.lock = multiprocessing.Lock()
self.subprocess = PhoneWorkerSubProcess(self.worker_num, self.ipaddr,
tests, phone_cfg, user_cfg,
autophone_queue,
self.cmd_queue, logfile_prefix,
loglevel, mailer,
build_cache_port)
self.logger = logging.getLogger('autophone.worker')
self.loggerdeco = LogDecorator(self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip']
}, '%(phoneid)s|%(phoneip)s|%(message)s')
def __init__(self, worker_num, ipaddr, tests, phone_cfg, user_cfg,
autophone_queue, cmd_queue, logfile_prefix, loglevel, mailer,
build_cache_port):
self.worker_num = worker_num
self.ipaddr = ipaddr
self.tests = tests
self.phone_cfg = phone_cfg
self.user_cfg = user_cfg
self.autophone_queue = autophone_queue
self.cmd_queue = cmd_queue
self.logfile = logfile_prefix + '.log'
self.outfile = logfile_prefix + '.out'
self.loglevel = loglevel
self.mailer = mailer
self.build_cache_port = build_cache_port
self._stop = False
self.p = None
self.jobs = jobs.Jobs(self.mailer, self.phone_cfg['phoneid'])
self.current_build = None
self.last_ping = None
self._dm = None
self.status = None
self.logger = logging.getLogger('autophone.worker.subprocess')
self.loggerdeco = LogDecorator(self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip']
}, '%(phoneid)s|%(phoneip)s|%(message)s')
def setup_job(self):
# Truncate the current log to prevent log bleed over. See the
# main process log for all of the mising bits. Log the current
# full contents of logcat, then clear the logcat buffers to
# help prevent the device's buffer from over flowing during
# the test.
self.worker_subprocess.filehandler.stream.truncate(0)
self.worker_subprocess.log_step('Setup Test')
self.start_time = datetime.datetime.utcnow()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
try:
self.worker_subprocess.logcat.reset()
except:
self.loggerdeco.exception('Exception resetting logcat before test')
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision,
self.build.type,
self.build.abi,
self.build.platform,
self.build.sdk,
self.build.builder_type,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
logger = utils.getLogger()
self.loggerdeco = LogDecorator(logger,
{
'repo': self.build.tree,
'buildid': self.build.id,
'buildtype': self.build.type,
'sdk': self.phone.sdk,
'platform': self.build.platform,
'testname': self.name
},
'PhoneTestJob %(repo)s %(buildid)s %(buildtype)s %(sdk)s %(platform)s %(testname)s '
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.info('PhoneTest starting job')
if self.unittest_logpath:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
self.upload_dir = tempfile.mkdtemp()
self.crash_processor = AutophoneCrashProcessor(self.dm,
self.profile_path,
self.upload_dir,
self.build.app_name)
self.crash_processor.clear()
self.reset_result()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def setup_job(self):
# Log the current full contents of logcat, then clear the
# logcat buffers to help prevent the device's buffer from
# over flowing during the test.
self.loggerdeco.debug('PhoneTest.teardown_job')
self.start_time = datetime.datetime.utcnow()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
self.loggerdeco.debug('full logcat before job:')
try:
self.loggerdeco.debug('\n'.join(
self.worker_subprocess.logcat.get(full=True)))
except:
self.loggerdeco.exception('Exception getting logcat')
try:
self.worker_subprocess.logcat.reset()
except:
self.loggerdeco.exception('Exception resetting logcat')
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision,
self.build.type,
self.build.abi,
self.build.platform,
self.build.sdk,
self.build.builder_type,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
logger = logging.getLogger()
self.loggerdeco = LogDecorator(
logger, {
'phoneid': self.phone.id,
'buildid': self.build.id,
'test': self.name
}, 'PhoneTestJob|%(phoneid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.info('PhoneTest starting job')
if self.unittest_logpath:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
self.upload_dir = tempfile.mkdtemp()
self.crash_processor = AutophoneCrashProcessor(self.dm,
self.profile_path,
self.upload_dir,
self.build.app_name)
self.crash_processor.clear()
self.reset_result()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def set_worker_subprocess(self, worker_subprocess):
logger = utils.getLogger()
self.loggerdeco = LogDecorator(logger,
{},
'%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.worker_subprocess = worker_subprocess
self.dm = worker_subprocess.dm
self.update_status_cb = worker_subprocess.update_status
def set_worker_subprocess(self, worker_subprocess):
logger = logging.getLogger()
self.loggerdeco = LogDecorator(
logger, {'phoneid': self.phone.id},
'PhoneTestSubProcess|%(phoneid)s|%(message)s')
self.loggerdeco.info('PhoneTest.set_worker_subprocess')
self.loggerdeco_original = None
self.dm_logger_original = None
self.worker_subprocess = worker_subprocess
self.dm = worker_subprocess.dm
self.update_status_cb = worker_subprocess.update_status
def runtest(self):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'buildid': self.parms['buildid'],
'testname': self.parms['test_name']},
'%(phoneid)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in self.parms.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, self.parms[key]))
self.update_status(message='Starting test %s' % self.parms['test_name'])
if self.parms['test_name'] == 'robocoptest':
try:
self.dm.uninstall_app('org.mozilla.roboexample.test')
robocop_apk_path = os.path.join(self.parms['build_dir'], 'robocop.apk')
self.dm.install_app(robocop_apk_path)
except Exception, e:
self.loggerdeco.exception('runtestsremote.py:runtest: Exception running test.')
self.test_result.status = PhoneTestResult.EXCEPTION
self.message = 'Exception installing robocop.apk: %s' % e
with open(self._log, "w") as logfilehandle:
logfilehandle.write('%s\n' % self.message)
return
def setup_job(self):
self.logger_original = self.logger
self.loggerdeco_original = self.loggerdeco
self.dm_logger_original = self.dm._logger
# Clear the log file if we are submitting logs to Treeherder.
if (self.worker_subprocess.options.treeherder_url and
self.worker_subprocess.build.revision_hash and
self.worker_subprocess.s3_bucket):
self.worker_subprocess.initialize_log_filehandler()
self.worker_subprocess.treeherder.submit_running(tests=[self])
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'pid': os.getpid(),
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(pid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self._log:
os.unlink(self._log)
self._log = None
self.upload_dir = tempfile.mkdtemp()
self.test_result = PhoneTestResult()
def setup_job(self):
self.start_time = datetime.datetime.now()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self._log:
os.unlink(self._log)
self._log = None
self.upload_dir = tempfile.mkdtemp()
self.test_result = PhoneTestResult()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
try:
self.setup_and_runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id},
'%(phoneid)s|%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self.repos = repos
self._log = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
self.loggerdeco.info('PhoneTest: Connected.')
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(buildid)s|%(message)s')
try:
self.setup_and_runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def __init__(self, phone, options, config_file=None,
enable_unittests=False, test_devices_repos={},
chunk=1):
self.config_file = config_file
self.cfg = ConfigParser.RawConfigParser()
self.cfg.read(self.config_file)
self.enable_unittests = enable_unittests
self.test_devices_repos = test_devices_repos
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.phone = phone
self.worker_subprocess = None
self.options = options
self.logger = logging.getLogger('autophone.phonetest')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'pid': os.getpid()},
'%(phoneid)s|%(pid)s|%(message)s')
self.logger_original = None
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self._dm = None
self._repos = None
self._log = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
def setup_job(self):
# Log the current full contents of logcat, then clear the
# logcat buffers to help prevent the device's buffer from
# over flowing during the test.
self.start_time = datetime.datetime.now()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
self.loggerdeco.debug('phonetest.setup_job: full logcat before job:')
try:
self.loggerdeco.debug('\n'.join(self.logcat.get(full=True)))
except:
self.loggerdeco.exception('Exception getting logcat')
try:
self.logcat.reset()
except:
self.loggerdeco.exception('Exception resetting logcat')
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
# Create a test run specific logger which will propagate to
# the root logger in the worker which runs in the same
# process. This log will be uploaded to Treeherder if
# Treeherder submission is enabled and will be cleared at the
# beginning of each test run.
sensitive_data_filter = SensitiveDataFilter(self.options.sensitive_data)
logger = logging.getLogger('phonetest')
logger.addFilter(sensitive_data_filter)
logger.propagate = True
logger.setLevel(self.worker_subprocess.loglevel)
self.test_logfile = (self.worker_subprocess.logfile_prefix +
'-' + self.name + '.log')
self.test_logfilehandler = logging.FileHandler(
self.test_logfile, mode='w')
fileformatstring = ('%(asctime)s|%(process)d|%(threadName)s|%(name)s|'
'%(levelname)s|%(message)s')
fileformatter = logging.Formatter(fileformatstring)
self.test_logfilehandler.setFormatter(fileformatter)
logger.addHandler(self.test_logfilehandler)
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self.unittest_logpath:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
self.upload_dir = tempfile.mkdtemp()
self.crash_processor = AutophoneCrashProcessor(self.dm,
self.profile_path,
self.upload_dir,
self.build.app_name)
self.crash_processor.clear()
self.test_result = PhoneTestResult()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
class S1S2Test(PerfTest):
def __init__(self, dm=None, phone=None, options=None,
config_file=None, chunk=1, repos=[]):
PerfTest.__init__(self, dm=dm, phone=phone, options=options,
config_file=config_file, chunk=chunk, repos=repos)
# [paths]
autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['dest'] = posixpath.join(self.base_device_path, 's1s2test/')
try:
sources = self.cfg.get('paths', 'sources').split()
self._paths['sources'] = []
for source in sources:
if not source.endswith('/'):
source += '/'
self._paths['sources'].append(source)
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['sources'] = [
os.path.join(autophone_directory, 'files/base/'),
os.path.join(autophone_directory, 'files/s1s2/')]
try:
self._paths['dest'] = self.cfg.get('paths', 'dest')
if not self._paths['dest'].endswith('/'):
self._paths['dest'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
try:
self._paths['profile'] = self.cfg.get('paths', 'profile')
if not self._paths['profile'].endswith('/'):
self._paths['profile'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for source in self._paths['sources']:
for push in glob.glob(source + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'], os.path.basename(push))
self._pushes[push] = push_dest
# [tests]
self._tests = {}
try:
for t in self.cfg.items('tests'):
self._tests[t[0]] = t[1]
except ConfigParser.NoSectionError:
self._tests['blank'] = 'blank.html'
# Map URLS - {urlname: url} - urlname serves as testname
self._urls = {}
config_vars = {'webserver_url': options.webserver_url}
try:
location_items = self.cfg.items('locations', False, config_vars)
except ConfigParser.NoSectionError:
location_items = [('local', None)]
for test_location, test_path in location_items:
if test_location in config_vars:
# Ignore the pseudo-options which result from passing
# the config_vars for interpolation.
continue
for test_name in self._tests:
if test_path:
test_url = urlparse.urljoin(test_path, self._tests[test_name])
else:
test_url = os.path.join('file://', self._paths['dest'],
self._tests[test_name])
self.loggerdeco.debug(
'test_location: %s, test_name: %s, test_path: %s, '
'test: %s, test_url: %s' %
(test_location, test_name, test_path,
self._tests[test_name], test_url))
self._urls["%s-%s" % (test_location, test_name)] = test_url
self._initialize_url = os.path.join('file://', self._paths['dest'],
'initialize_profile.html')
@property
def name(self):
return 'autophone-s1s2%s' % self.name_suffix
@property
def phonedash_url(self):
# For s1s2test, there are 4 different test names due to historical design.
# We pick local-blank as the default.
return self._phonedash_url('local-blank')
def setup_job(self):
PerfTest.setup_job(self)
def run_job(self):
if not self.install_local_pages():
self.test_failure(
self.name, 'TEST_UNEXPECTED_FAIL',
'Aborting test - Could not install local pages on phone.',
PhoneTestResult.EXCEPTION)
return
if not self.create_profile():
self.test_failure(
self.name, 'TEST_UNEXPECTED_FAIL',
'Aborting test - Could not run Fennec.',
PhoneTestResult.BUSTED)
return
testcount = len(self._urls.keys())
for testnum,(testname,url) in enumerate(self._urls.iteritems(), 1):
if self.fennec_crashed:
break
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'testname': testname},
'%(phoneid)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
# success == False indicates that none of the attempts
# were successful in getting any measurement. This is
# typically due to a regression in the brower which should
# be reported.
success = False
command = None
for attempt in range(1, self.stderrp_attempts+1):
if self.fennec_crashed:
break
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(1, self._iterations+1):
command = self.worker_subprocess.process_autophone_cmd(self)
if command['interrupt']:
self.handle_test_interrupt(command['reason'])
break
if self.fennec_crashed:
break
self.update_status(message='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt, self.stderrp_attempts,
testnum, testcount, iteration, url))
dataset.append({})
if not self.create_profile():
self.test_failure(url,
'TEST_UNEXPECTED_FAIL',
'Failed to create profile',
PhoneTestResult.TESTFAILED)
continue
measurement = self.runtest(url)
if measurement:
self.test_pass(url)
else:
self.test_failure(
url,
'TEST_UNEXPECTED_FAIL',
'Failed to get uncached measurement.',
PhoneTestResult.TESTFAILED)
continue
dataset[-1]['uncached'] = measurement
success = True
measurement = self.runtest(url)
if measurement:
self.test_pass(url)
else:
self.test_failure(
url,
'TEST_UNEXPECTED_FAIL',
'Failed to get cached measurement.',
PhoneTestResult.TESTFAILED)
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(
('throbberstart',
'throbberstop'),
dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration, self._iterations))
break
if command and command['interrupt']:
break
if not success:
# If we have not gotten a single measurement at this point,
# just bail and report the failure rather than wasting time
# continuing more attempts.
self.loggerdeco.info(
'Failed to get measurements for test %s after %d/%d attempt '
'of %d iterations' % (testname, attempt,
self.stderrp_attempts,
self._iterations))
self.worker_subprocess.mailer.send(
'S1S2Test %s failed for Build %s %s on Phone %s' %
(testname, self.build.tree, self.build.id,
self.phone.id),
'No measurements were detected for test %s.\n\n'
'Repository: %s\n'
'Build Id: %s\n'
'Revision: %s\n' %
(testname, self.build.tree, self.build.id, self.build.revision))
self.test_failure(self.name, 'TEST_UNEXPECTED_FAIL',
'No measurements detected.',
PhoneTestResult.BUSTED)
break
if self.is_stderr_below_threshold(
('throbberstart',
'throbberstop'),
dataset,
self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration, self._iterations))
self.loggerdeco.debug('publishing results')
for datapoint in dataset:
for cachekey in datapoint:
self.report_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
testname=testname,
cache_enabled=(cachekey=='cached'),
rejected=rejected)
if not rejected:
break
if command and command['interrupt']:
break
elif not success:
break
def runtest(self, url):
# Clear logcat
self.logcat.clear()
# Run test
self.run_fennec_with_profile(self.build.app_name, url)
# Get results - do this now so we don't have as much to
# parse in logcat.
starttime, throbberstart, throbberstop = self.analyze_logcat()
self.wait_for_fennec()
# Ensure we succeeded - no 0's reported
datapoint = {}
if (throbberstart and throbberstop):
datapoint['starttime'] = starttime
datapoint['throbberstart'] = throbberstart
datapoint['throbberstop'] = throbberstop
datapoint['throbbertime'] = throbberstop - throbberstart
return datapoint
def wait_for_fennec(self, max_wait_time=60, wait_time=5,
kill_wait_time=20, root=True):
# Wait for up to a max_wait_time seconds for fennec to close
# itself in response to the quitter request. Check that fennec
# is still running every wait_time seconds. If fennec doesn't
# close on its own, attempt up to 3 times to kill fennec, waiting
# kill_wait_time seconds between attempts.
# Return True if fennec exits on its own, False if it needs to be killed.
# Re-raise the last exception if fennec can not be killed.
max_wait_attempts = max_wait_time / wait_time
for wait_attempt in range(1, max_wait_attempts+1):
if not self.dm.process_exist(self.build.app_name):
return True
sleep(wait_time)
self.loggerdeco.debug('killing fennec')
max_killattempts = 3
for kill_attempt in range(1, max_killattempts+1):
try:
self.dm.pkill(self.build.app_name, root=root)
break
except ADBError:
self.loggerdeco.exception('Attempt %d to kill fennec failed' %
kill_attempt)
if kill_attempt == max_killattempts:
raise
sleep(kill_wait_time)
return False
def create_profile(self, custom_prefs=None, root=True):
# Create, install and initialize the profile to be
# used in the test.
# make sure firefox isn't running when we try to
# install the profile.
self.dm.pkill(self.build.app_name, root=root)
telemetry_prompt = 999
if self.build.id < '20130103':
telemetry_prompt = 2
prefs = {
'app.update.auto': False,
'app.update.enabled': False,
'app.update.url': '',
'app.update.url.android': '',
'app.update.url.override': '',
'beacon.enabled': False,
'browser.EULA.override': True,
'browser.safebrowsing.enabled': False,
'browser.safebrowsing.malware.enabled': False,
'browser.search.countryCode': 'US',
'browser.search.isUS': True,
'browser.selfsupport.url': '',
'browser.sessionstore.resume_from_crash': False,
'browser.snippets.enabled': False,
'browser.snippets.firstrunHomepage.enabled': False,
'browser.snippets.syncPromo.enabled': False,
'browser.warnOnQuit': False,
'browser.webapps.checkForUpdates': 0,
'datareporting.healthreport.service.enabled': False,
'datareporting.policy.dataSubmissionPolicyBypassAcceptance': True,
'dom.ipc.plugins.flash.subprocess.crashreporter.enabled': False,
'extensions.blocklist.enabled': False,
'extensions.getAddons.cache.enabled': False,
'extensions.update.enabled': False,
'general.useragent.updates.enabled': False,
'media.autoplay.enabled': True,
'shell.checkDefaultClient': False,
'toolkit.telemetry.enabled': False,
'toolkit.telemetry.notifiedOptOut': telemetry_prompt,
'toolkit.telemetry.prompted': telemetry_prompt,
'urlclassifier.updateinterval': 172800,
'webapprt.app_update_interval': 86400,
'xpinstall.signatures.required': False,
}
if isinstance(custom_prefs, dict):
prefs = dict(prefs.items() + custom_prefs.items())
profile = FirefoxProfile(preferences=prefs, addons='%s/xpi/quitter.xpi' %
os.getcwd())
if not self.install_profile(profile):
return False
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Initializing profile' % attempt)
self.run_fennec_with_profile(self.build.app_name, self._initialize_url)
if self.wait_for_fennec():
success = True
break
sleep(self.options.phone_retry_wait)
if not success:
msg = 'Aborting Test - Failure initializing profile.'
self.loggerdeco.error(msg)
return success
def install_local_pages(self):
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Installing local pages' % attempt)
try:
self.dm.rm(self._paths['dest'], recursive=True, force=True)
self.dm.mkdir(self._paths['dest'], parents=True)
for push_source in self._pushes:
push_dest = self._pushes[push_source]
if os.path.isdir(push_source):
self.dm.push(push_source, push_dest)
else:
self.dm.push(push_source, push_dest)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d Installing local pages' % attempt)
sleep(self.options.phone_retry_wait)
if not success:
self.loggerdeco.error('Failure installing local pages')
return success
def is_fennec_running(self, appname):
for attempt in range(1, self.options.phone_retry_limit+1):
try:
return self.dm.process_exist(appname)
except ADBError:
self.loggerdeco.exception('Attempt %d is fennec running' % attempt)
if attempt == self.options.phone_retry_limit:
raise
sleep(self.options.phone_retry_wait)
def analyze_logcat(self):
self.loggerdeco.debug('analyzing logcat')
logcat_prefix = '(\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3})'
throbber_prefix = '..GeckoToolbarDisplayLayout.*zerdatime (\d+) - Throbber'
re_base_time = re.compile('%s' % logcat_prefix)
re_start_time = re.compile(
'%s .*(Gecko|Start proc %s for activity %s/.App)' % (
logcat_prefix, self.build.app_name, self.build.app_name))
re_throbber_start_time = re.compile('%s %s start' %
(logcat_prefix, throbber_prefix))
re_throbber_stop_time = re.compile('%s %s stop' %
(logcat_prefix, throbber_prefix))
base_time = 0
start_time = 0
throbber_start_time = 0
throbber_stop_time = 0
attempt = 1
max_time = 90 # maximum time to wait for throbbers
wait_time = 3 # time to wait between attempts
max_attempts = max_time / wait_time
while (attempt <= max_attempts and (throbber_start_time == 0 or
throbber_stop_time == 0)):
buf = self.logcat.get()
for line in buf:
self.loggerdeco.debug('analyze_logcat: %s' % line)
match = re_base_time.match(line)
if match and not base_time:
base_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: base_time: %s' % base_time)
# we want the first throbberstart and throbberstop.
match = re_start_time.match(line)
if match and not start_time:
start_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: start_time: %s' % start_time)
continue
match = re_throbber_start_time.match(line)
if match and not throbber_start_time:
throbber_start_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: throbber_start_time: %s' % throbber_start_time)
continue
match = re_throbber_stop_time.match(line)
if match and not throbber_stop_time:
throbber_stop_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: throbber_stop_time: %s' % throbber_stop_time)
continue
if start_time and throbber_start_time and throbber_stop_time:
break
if self.fennec_crashed:
# If fennec crashed, don't bother looking for the Throbbers
break
if (start_time == 0 or
throbber_start_time == 0 or
throbber_stop_time == 0):
sleep(wait_time)
attempt += 1
if throbber_start_time and throbber_stop_time == 0:
self.loggerdeco.info('Unable to find Throbber stop')
# The captured time from the logcat lines is in the format
# MM-DD HH:MM:SS.mmm. It is possible for the year to change
# between the different times, so we need to make adjustments
# if necessary. First, we assume the year does not change and
# parse the dates as if they are in the current year. If
# the dates violate the natural order start_time,
# throbber_start_time, throbber_stop_time, we can adjust the
# year.
if base_time and start_time and throbber_start_time and throbber_stop_time:
parse = lambda y, t: datetime.datetime.strptime('%4d-%s' % (y, t), '%Y-%m-%d %H:%M:%S.%f')
year = datetime.datetime.now().year
base_time = parse(year, base_time)
start_time = parse(year, start_time)
throbber_start_time = parse(year, throbber_start_time)
throbber_stop_time = parse(year, throbber_stop_time)
self.loggerdeco.debug('analyze_logcat: before year adjustment '
'base: %s, start: %s, '
'throbber start: %s' %
(base_time, start_time,
throbber_start_time))
if base_time > start_time:
base_time.replace(year=year-1)
elif start_time > throbber_start_time:
base_time.replace(year=year-1)
start_time.replace(year=year-1)
elif throbber_start_time > throbber_stop_time:
base_time.replace(year=year-1)
start_time.replace(year=year-1)
throbber_start_time.replace(year-1)
self.loggerdeco.debug('analyze_logcat: after year adjustment '
'base: %s, start: %s, '
'throbber start: %s' %
(base_time, start_time,
throbber_start_time))
# Convert the times to milliseconds from the base time.
convert = lambda t1, t2: round((t2 - t1).total_seconds() * 1000.0)
start_time = convert(base_time, start_time)
throbber_start_time = convert(base_time, throbber_start_time)
throbber_stop_time = convert(base_time, throbber_stop_time)
self.loggerdeco.debug('analyze_logcat: base: %s, start: %s, '
'throbber start: %s, throbber stop: %s, '
'throbber time: %s ' %
(base_time, start_time,
throbber_start_time, throbber_stop_time,
throbber_stop_time - throbber_start_time))
if (start_time > throbber_start_time or
start_time > throbber_stop_time or
throbber_start_time > throbber_stop_time):
self.loggerdeco.warning('analyze_logcat: inconsistent measurements: '
'start: %s, '
'throbber start: %s, throbber stop: %s ' %
(start_time,
throbber_start_time,
throbber_stop_time))
start_time = throbber_start_time = throbber_stop_time = 0
else:
self.loggerdeco.warning(
'analyze_logcat: failed to get measurements '
'start_time: %s, throbber start: %s, throbber stop: %s' % (
start_time, throbber_start_time, throbber_stop_time))
start_time = throbber_start_time = throbber_stop_time = 0
return (start_time, throbber_start_time, throbber_stop_time)
class UnitTest(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
try:
self.setup_and_runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def setup_and_runtest(self, build_metadata, worker_subprocess):
self.loggerdeco.debug('runtestsremote.py runjob start')
self.set_status(msg='runtestsremote.py runjob start')
self.worker_subprocess = worker_subprocess
self.worker_subprocess.check_sdcard()
host_ip_address = self.phone_cfg['ipaddr']
phone_ip_address = self.phone_cfg['ip']
device_port = self.phone_cfg['sutcmdport']
cache_build_dir = os.path.abspath(build_metadata["cache_build_dir"])
symbols_path = os.path.join(cache_build_dir, 'symbols')
if not os.path.exists(symbols_path):
symbols_path = None
androidprocname = build_metadata['androidprocname']
re_revision = re.compile(r'http.*/rev/(.*)')
match = re_revision.match(build_metadata['revision'])
if match:
revision = match.group(1)
else:
revision = build_metadata['revision']
buildid = build_metadata['buildid']
tree = build_metadata['tree']
if self.logger.getEffectiveLevel() == logging.DEBUG:
for prop in self.phone_cfg:
self.loggerdeco.debug('phone_cfg[%s] = %s' %
(prop, self.phone_cfg[prop]))
job_cfg = ConfigParser.RawConfigParser()
job_cfg.read(self.config_file)
if job_cfg.has_option('runtests', 'config_files'):
# job contains multiple unittests
config_files = job_cfg.get('runtests', 'config_files').split(' ')
elif job_cfg.has_option('runtests', 'test_name'):
# job contains a single unittest
config_files = [self.config_file]
else:
raise Exception('Job configuration %s does not specify a test' %
self.config_file)
missing_config_files = []
for config_file in config_files:
if not os.path.exists(config_file):
missing_config_files.append(config_file)
if missing_config_files:
raise Exception("Can not run tests with missing config files: %s" %
', '.join(missing_config_files))
for config_file in config_files:
try:
test_parameters = {
'host_ip_address': host_ip_address,
'phone_ip_address': phone_ip_address,
'device_port': device_port,
'androidprocname': androidprocname,
'cache_build_dir': cache_build_dir,
'symbols_path': symbols_path,
'revision': revision,
'buildid': buildid,
'tree': tree,
'config_file': config_file,
}
self.load_test_parameters(test_parameters, config_file)
self.runtest(test_parameters)
except:
# This exception handler deals with exceptions which occur outside
# of the actual test runner. Exceptions from the test runner
# are handled locally in runtest.
self.loggerdeco.exception(
'runtestsremote.py:runjob: Exception '
'running test')
self.set_status(msg='runtestsremote.py:runjob: Exception '
'running test')
# give the phone a minute to recover
time.sleep(60)
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runjob exit')
self.set_status(msg='runtestsremote.py runjob exit')
def load_test_parameters(self, test_parameters, config_file):
cfg = ConfigParser.RawConfigParser()
cfg.read(config_file)
test_parameters['test_name'] = cfg.get('runtests', 'test_name')
test_parameters['test_manifest'] = cfg.get('runtests', 'test_manifest')
try:
test_parameters['test_path'] = cfg.get('runtests', 'test_path')
except ConfigParser.NoOptionError:
test_parameters['test_path'] = None
unittest_config_file = cfg.get('runtests', 'unittest_defaults')
cfg.read(unittest_config_file)
self.loggerdeco.info('config_file = %s, unittest_config_file = %s' %
(config_file, unittest_config_file))
test_parameters['xre_path'] = cfg.get('runtests', 'xre_path')
test_parameters['utility_path'] = cfg.get('runtests', 'utility_path')
if test_parameters['symbols_path'] is not None and cfg.has_option(
'runtests', 'minidump_stackwalk'):
test_parameters['minidump_stackwalk'] = cfg.get(
'runtests', 'minidump_stackwalk')
os.environ['MINIDUMP_STACKWALK'] = test_parameters[
'minidump_stackwalk']
elif 'MINIDUMP_STACKWALK' in os.environ:
del os.environ['MINIDUMP_STACKWALK']
if cfg.has_option('runtests', 'androidprocname'):
test_parameters['androidprocname'] = cfg.get(
'runtests', 'androidprocname')
test_parameters['console_level'] = cfg.get('runtests', 'console_level')
test_parameters['file_level'] = cfg.get('runtests', 'file_level')
test_parameters['time_out'] = cfg.getint('runtests', 'time_out')
if cfg.has_option('runtests', 'iterations'):
test_parameters['iterations'] = cfg.getint('runtests',
'iterations')
else:
test_parameters['iterations'] = 1
if cfg.has_option('runtests', 'total_chunks'):
test_parameters['total_chunks'] = cfg.getint(
'runtests', 'total_chunks')
else:
test_parameters['total_chunks'] = 1
if cfg.has_option('runtests', 'prefs'):
test_parameters['prefs'] = cfg.get('runtests', 'prefs').split(',')
else:
test_parameters['prefs'] = []
test_parameters['es_server'] = cfg.get('autolog', 'es_server')
test_parameters['rest_server'] = cfg.get('autolog', 'rest_server')
test_parameters['index'] = cfg.get('autolog', 'index')
test_parameters['include_pass'] = cfg.getboolean(
'autolog', 'include_pass')
test_parameters['submit_log'] = cfg.getboolean('autolog', 'submit_log')
test_parameters['use_newparser'] = cfg.getboolean(
'autolog', 'use_newparser')
def create_test_args(self, test_parameters):
args = ['python']
test_name_lower = test_parameters['test_name'].lower()
if test_name_lower.startswith('robocoptest'):
test_args = [
'mochitest/runtestsremote.py',
'--robocop=%s' % test_parameters['test_manifest'],
'--robocop-ids=%s/fennec_ids.txt' %
test_parameters['cache_build_dir'],
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % test_parameters['console_level'],
'--file-level=%s' % test_parameters['file_level'],
'--repeat=%d' % test_parameters['iterations'],
]
elif test_name_lower.startswith('mochitest'):
test_args = [
'mochitest/runtestsremote.py',
'--test-manifest=%s' % test_parameters['test_manifest'],
'--test-path=%s' % test_parameters['test_path'],
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % test_parameters['console_level'],
'--file-level=%s' % test_parameters['file_level'],
'--repeat=%d' % test_parameters['iterations'],
]
elif test_name_lower.startswith('reftest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'%s' % test_parameters['test_manifest'],
]
elif test_name_lower.startswith('jsreftest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'--extra-profile-file=jsreftest/tests/user.js',
'%s' % test_parameters['test_manifest'],
]
elif test_name_lower.startswith('crashtest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'%s' % test_parameters['test_manifest'],
]
else:
self.loggerdeco.error('Unknown test_name %s' %
test_parameters['test_name'])
raise Exception('Unknown test_name %s' %
test_parameters['test_name'])
test_parameters['http_port'] = test_parameters['port_manager'].reserve(
)
test_parameters['ssl_port'] = test_parameters['port_manager'].reserve()
common_args = [
'--deviceIP=%s' % test_parameters['phone_ip_address'],
'--devicePort=%s' % test_parameters['device_port'],
'--app=%s' % test_parameters['androidprocname'],
'--xre-path=%s' % test_parameters['xre_path'],
'--utility-path=%s' % test_parameters['utility_path'],
'--timeout=%d' % test_parameters['time_out'],
'--http-port=%s' %
test_parameters['port_manager'].use(test_parameters['http_port']),
'--ssl-port=%s' %
test_parameters['port_manager'].use(test_parameters['ssl_port']),
'--total-chunks=%d' % test_parameters['total_chunks'],
'--this-chunk=%d' % test_parameters['this_chunk'],
'--log-file=%s-%s.log' % (test_parameters['test_name'],
test_parameters['phone_ip_address']),
'--pidfile=%s-%s.pid' % (test_parameters['test_name'],
test_parameters['phone_ip_address']),
]
for pref in test_parameters['prefs']:
common_args.append('--setpref=%s' % pref)
args.extend(test_args)
args.extend(common_args)
if test_parameters['symbols_path'] is not None:
args.append('--symbols-path=%s' % test_parameters['symbols_path'])
return args
def process_test_log(self, test_parameters, logfilehandle):
test_log = None
test_runs = []
if test_parameters['use_newparser']:
logfilehandle.close()
logfilehandle = open(logfilehandle.name)
try:
# Turn off verbose logging for the log parser
logger = logging.getLogger('logparser')
logger_effectiveLevel = logger.getEffectiveLevel()
logger.setLevel(logging.WARN)
test_log = newlogparser.parse_log(logfilehandle)
test_runs = test_log.convert(test_parameters['include_pass'])
finally:
logger.setLevel(logger_effectiveLevel)
logfilehandle.close()
else:
lp = LogParser([logfilehandle.name],
es=False,
es_server=None,
includePass=True,
output_dir=None,
logger=self.logger,
harnessType=test_parameters['harness_type'])
# Use logparser's parsers, but do not allow it to
# submit data directly to elasticsearch.
test_runs.append(lp.parseFiles())
if test_parameters['es_server'] is None or test_parameters[
'rest_server'] is None:
return
# testgroup must match entry in autolog/js/Config.js:testNames
# os must match entry in autolog/js/Config.js:OSNames
# platform must match entry in autolog/js/Config.js:OSNames
logfilename = None
if test_parameters['submit_log']:
logfilename = logfilehandle.name
chunk_descriptor = ''
if test_parameters['total_chunks'] > 1:
chunk_descriptor = 's-%d' % test_parameters['this_chunk']
testgroup_name = '%s%s' % (test_parameters['test_name'],
chunk_descriptor)
platform_name = self.phone_cfg['machinetype']
self.loggerdeco.debug('testgroup_name = %s' % testgroup_name)
testgroup = RESTfulAutologTestGroup(
index=test_parameters['index'],
testgroup=testgroup_name,
os='android',
platform=platform_name,
harness=test_parameters['harness_type'],
server=test_parameters['es_server'],
restserver=test_parameters['rest_server'],
machine=self.phone_cfg['phoneid'],
logfile=logfilename)
testgroup.set_primary_product(tree=test_parameters['tree'],
buildtype='opt',
buildid=test_parameters['buildid'],
revision=test_parameters['revision'])
for testdata in test_runs:
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('Begin testdata')
self.loggerdeco.debug(json.dumps(testdata, indent=4))
self.loggerdeco.debug('End testdata')
testgroup.add_test_suite(testsuite=testgroup_name,
cmdline=test_parameters['cmdline'],
passed=testdata.get('passed', None),
failed=testdata.get('failed', None),
todo=testdata.get('todo', None))
for t in testdata.get('failures', {}):
test = t["test"]
for f in t["failures"]:
text = f["text"]
status = f["status"]
testgroup.add_test_failure(test=test,
text=text,
status=status)
# Submitting passing tests not supported via REST API
if test_parameters['include_pass']:
for t in testdata.get('passes', {}):
test = t["test"]
duration = None
if "duration" in t:
duration = t["duration"]
testgroup.add_test_pass(test=test, duration=duration)
testgroup.submit()
def runtest(self, test_parameters):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': test_parameters['buildid'],
'testname': test_parameters['test_name']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in test_parameters.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, test_parameters[key]))
self.set_status(msg='Starting test %s' % test_parameters['test_name'])
test_parameters['harness_type'] = test_parameters['test_name']
if test_parameters['test_name'] == 'robocoptest':
test_parameters['harness_type'] = 'mochitest'
robocop_apk_path = posixpath.join(self.dm.getDeviceRoot(),
'robocop.apk')
# XXX: FIXME. When bug 792072 lands, change to have
# installApp() push the file
self.dm.pushFile(
os.path.join(test_parameters['cache_build_dir'],
'robocop.apk'), robocop_apk_path)
try:
self.dm.uninstallApp('org.mozilla.roboexample.test')
except DMError:
self.loggerdeco.exception(
'runtestsremote.py:runtest: Exception running test.')
self.dm.installApp(robocop_apk_path)
self.dm.removeFile(robocop_apk_path)
test_parameters['port_manager'] = PortManager(
test_parameters['host_ip_address'])
for this_chunk in range(1, test_parameters['total_chunks'] + 1):
test_parameters['this_chunk'] = this_chunk
try:
while True:
socket_collision = False
logfilehandle = tempfile.NamedTemporaryFile(delete=False)
self.loggerdeco.debug('logging to %s' % logfilehandle.name)
args = self.create_test_args(test_parameters)
test_parameters['cmdline'] = ' '.join(args)
self.loggerdeco.debug("cmdline = %s" %
test_parameters['cmdline'])
self.set_status(msg='Running test %s chunk %d of %d' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks']))
if self.dm.processExist(
test_parameters['androidprocname']):
max_kill_attempts = 3
for kill_attempt in range(max_kill_attempts):
self.loggerdeco.debug(
'Process %s exists. Attempt %d to kill.' %
(test_parameters['androidprocname'],
kill_attempt + 1))
self.dm.killProcess(
test_parameters['androidprocname'])
if not self.dm.processExist(
test_parameters['androidprocname']):
break
if kill_attempt == max_kill_attempts - 1 and \
self.dm.processExist(test_parameters['androidprocname']):
self.loggerdeco.warning(
'Could not kill process %s.' %
(test_parameters['androidprocname']))
proc = subprocess.Popen(
args,
cwd=os.path.join(test_parameters['cache_build_dir'],
'tests'),
preexec_fn=lambda: os.setpgid(0, 0),
stdout=logfilehandle,
stderr=subprocess.STDOUT,
close_fds=True)
proc.wait()
self.loggerdeco.debug('runtestsremote.py return code %d' %
proc.returncode)
logfilehandle.close()
reSocketError = re.compile('socket\.error:')
logfilehandle = open(logfilehandle.name)
for logline in logfilehandle:
if reSocketError.search(logline):
socket_collision = True
break
logfilehandle.close()
if not socket_collision:
break
self.set_status(msg='Completed test %s chunk %d of %d' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks']))
except:
error_message = (
'Exception during test %s chunk %d of %d: %s' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks'], traceback.format_exc()))
self.set_status(msg=error_message)
self.loggerdeco.error(error_message)
finally:
logfilehandle.close()
self.process_test_log(test_parameters, logfilehandle)
if self.logger.getEffectiveLevel() == logging.DEBUG:
logfilehandle = open(logfilehandle.name)
self.loggerdeco.debug(40 * '*')
self.loggerdeco.debug(logfilehandle.read())
self.loggerdeco.debug(40 * '-')
logfilehandle.close()
os.unlink(logfilehandle.name)
# wait for a minute to give the phone time to settle
time.sleep(60)
# Recover the phone in between tests/chunks.
self.loggerdeco.info('Rebooting device after test.')
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runtest exit')
return
class S1S2Test(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
try:
# Read our config file which gives us our number of
# iterations and urls that we will be testing
cfg = ConfigParser.RawConfigParser()
cfg.read(self.config_file)
# [signature]
self._signer = None
self._jwt = {'id': '', 'key': None}
for opt in self._jwt.keys():
try:
self._jwt[opt] = cfg.get('signature', opt)
except (ConfigParser.NoSectionError,
ConfigParser.NoOptionError):
break
# phonedash requires both an id and a key.
if self._jwt['id'] and self._jwt['key']:
self._signer = jwt.jws.HmacSha(key=self._jwt['key'],
key_id=self._jwt['id'])
# [paths]
autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['source'] = os.path.join(autophone_directory, 'files/')
self._paths['dest'] = posixpath.join(self.base_device_path, 's1test/')
self._paths['remote'] = 'http://phonedash.mozilla.org/'
try:
for opt in ('source', 'dest', 'profile', 'remote'):
try:
self._paths[opt] = cfg.get('paths', opt)
if not self._paths[opt].endswith('/'):
self._paths[opt] += '/'
except ConfigParser.NoOptionError:
pass
except ConfigParser.NoSectionError:
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for push in glob.glob(self._paths['source'] + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'], os.path.basename(push))
self._pushes[push] = push_dest
# [tests]
self._tests = {}
for t in cfg.items('tests'):
self._tests[t[0]] = t[1]
# Map URLS - {urlname: url} - urlname serves as testname
self._urls = {}
for test_location in ('local', 'remote'):
for test_name in self._tests:
if test_location == 'local':
test_url = 'file://' + self._paths['dest'] + self._tests[test_name]
else:
test_url = self._paths['remote'] + self._tests[test_name]
self._urls["%s-%s" % (test_location, test_name)] = test_url
# [settings]
self._iterations = cfg.getint('settings', 'iterations')
try:
self.stderrp_accept = cfg.getfloat('settings', 'stderrp_accept')
except ConfigParser.NoOptionError:
self.stderrp_accept = 0
try:
self.stderrp_reject = cfg.getfloat('settings', 'stderrp_reject')
except ConfigParser.NoOptionError:
self.stderrp_reject = 100
try:
self.stderrp_attempts = cfg.getint('settings', 'stderrp_attempts')
except ConfigParser.NoOptionError:
self.stderrp_attempts = 1
self._resulturl = cfg.get('settings', 'resulturl')
if not self._resulturl.endswith('/'):
self._resulturl += '/'
self._initialize_url = 'file://' + self._paths['dest'] + 'initialize_profile.html'
self.runtests(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
self.dm._logger = loggerdeco
def is_stderr_below_threshold(self, dataset, threshold):
"""Return True if all of the measurements in the dataset have
standard errors of the mean below the threshold.
Return False if at least one measurement is above the threshold
or if one or more datasets have only one value.
Return None if at least one measurement has no values.
"""
self.loggerdeco.debug("is_stderr_below_threshold: %s" % dataset)
for cachekey in ('uncached', 'cached'):
for measurement in ('throbberstart', 'throbberstop'):
data = [datapoint[cachekey][measurement] - datapoint[cachekey]['starttime']
for datapoint in dataset
if datapoint and cachekey in datapoint]
if not data:
return None
stats = get_stats(data)
self.loggerdeco.debug('%s %s count: %d, mean: %.2f, '
'stddev: %.2f, stderr: %.2f, '
'stderrp: %.2f' % (
cachekey, measurement,
stats['count'], stats['mean'],
stats['stddev'], stats['stderr'],
stats['stderrp']))
if stats['count'] == 1 or stats['stderrp'] >= threshold:
return False
return True
def runtests(self, build_metadata, worker_subprocess):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
appname = build_metadata['androidprocname']
if not self.install_local_pages():
self.set_status(msg='Could not install local pages on phone. '
'Aborting test for '
'build %s' % build_metadata['buildid'])
return
if not self.create_profile(build_metadata):
self.set_status(msg='Could not run Fennec. Aborting test for '
'build %s' % build_metadata['buildid'])
return
testcount = len(self._urls.keys())
for testnum,(testname,url) in enumerate(self._urls.iteritems(), 1):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid'],
'testname': testname},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
if self.check_results(build_metadata, testname):
# We already have good results for this test and build.
# No need to test it again.
self.loggerdeco.info('Skipping test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
continue
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
for attempt in range(self.stderrp_attempts):
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(self._iterations):
self.set_status(msg='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt+1, self.stderrp_attempts,
testnum, testcount, iteration+1, url))
dataset.append({})
if not self.create_profile(build_metadata):
continue
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['uncached'] = measurement
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration+1, self._iterations))
break
self.loggerdeco.debug('publishing results')
if self.is_stderr_below_threshold(dataset, self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration+1, self._iterations))
for datapoint in dataset:
for cachekey in datapoint:
self.publish_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
build_metadata=build_metadata,
testname=testname,
cache_enabled=(cachekey=='cached'),
rejected=rejected)
if not rejected:
break
def runtest(self, build_metadata, appname, url):
# Clear logcat
self.loggerdeco.debug('clearing logcat')
self.dm.recordLogcat()
self.loggerdeco.debug('logcat cleared')
self.loggerdeco.debug('running fennec')
# Run test
self.run_fennec_with_profile(appname, url)
# Get results - do this now so we don't have as much to
# parse in logcat.
starttime, throbberstart, throbberstop = self.analyze_logcat(
build_metadata)
self.wait_for_fennec(build_metadata)
# Ensure we succeeded - no 0's reported
datapoint = {}
if (throbberstart and throbberstop):
datapoint['starttime'] = starttime
datapoint['throbberstart'] = throbberstart
datapoint['throbberstop'] = throbberstop
datapoint['throbbertime'] = throbberstop - throbberstart
return datapoint
def wait_for_fennec(self, build_metadata, max_wait_time=60, wait_time=5,
kill_wait_time=20):
# Wait for up to a max_wait_time seconds for fennec to close
# itself in response to the quitter request. Check that fennec
# is still running every wait_time seconds. If fennec doesn't
# close on its own, attempt up to 3 times to kill fennec, waiting
# kill_wait_time seconds between attempts.
# Return True if fennec exits on its own, False if it needs to be killed.
# Re-raise the last exception if fennec can not be killed.
max_wait_attempts = max_wait_time / wait_time
for wait_attempt in range(max_wait_attempts):
if not self.dm.processExist(build_metadata['androidprocname']):
return True
sleep(wait_time)
self.loggerdeco.debug('killing fennec')
max_killattempts = 3
for kill_attempt in range(max_killattempts):
try:
self.dm.killProcess(build_metadata['androidprocname'])
break
except DMError:
self.loggerdeco.exception('Attempt %d to kill fennec failed' %
kill_attempt)
if kill_attempt == max_killattempts - 1:
raise
sleep(kill_wait_time)
return False
def create_profile(self, build_metadata, custom_prefs=None):
# Create, install and initialize the profile to be
# used in the test.
telemetry_prompt = 999
if build_metadata['blddate'] < '2013-01-03':
telemetry_prompt = 2
prefs = {
'browser.firstrun.show.localepicker': False,
'browser.sessionstore.resume_from_crash': False,
'dom.ipc.plugins.flash.subprocess.crashreporter.enabled': False,
'browser.firstrun.show.uidiscovery': False,
'shell.checkDefaultClient': False,
'browser.warnOnQuit': False,
'browser.EULA.override': True,
'toolkit.telemetry.prompted': telemetry_prompt,
'toolkit.telemetry.notifiedOptOut': telemetry_prompt,
'datareporting.healthreport.service.enabled': False,
}
if isinstance(custom_prefs, dict):
prefs = dict(prefs.items() + custom_prefs.items())
profile = FirefoxProfile(preferences=prefs, addons='%s/xpi/quitter.xpi' %
os.getcwd())
if not self.install_profile(profile):
return False
appname = build_metadata['androidprocname']
buildid = build_metadata['buildid']
success = False
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
self.loggerdeco.debug('Attempt %d Initializing profile' % attempt)
self.run_fennec_with_profile(appname, self._initialize_url)
if self.wait_for_fennec(build_metadata):
success = True
break
sleep(self.user_cfg[PHONE_RETRY_WAIT])
if not success:
msg = 'Failure initializing profile for build %s' % buildid
self.loggerdeco.error(msg)
self.set_status(msg=msg)
return success
def install_local_pages(self):
success = False
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
self.loggerdeco.debug('Attempt %d Installing local pages' % attempt)
try:
self.dm.mkDir(self._paths['dest'])
for push_source in self._pushes:
push_dest = self._pushes[push_source]
if os.path.isdir(push_source):
self.dm.pushDir(push_source, push_dest)
else:
self.dm.pushFile(push_source, push_dest)
success = True
break
except DMError:
self.loggerdeco.exception('Attempt %d Installing local pages' % attempt)
sleep(self.user_cfg[PHONE_RETRY_WAIT])
if not success:
self.loggerdeco.error('Failure installing local pages')
return success
def is_fennec_running(self, appname):
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
try:
return self.dm.processExist(appname)
except DMError:
self.loggerdeco.exception('Attempt %d is fennec running' % attempt)
if attempt == self.user_cfg[PHONE_RETRY_LIMIT] - 1:
raise
sleep(self.user_cfg[PHONE_RETRY_WAIT])
def get_logcat_throbbers(self):
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
try:
return [x.strip() for x in
self.dm.getLogcat(
filterSpecs=['GeckoToolbarDisplayLayout:*', 'SUTAgentAndroid:I', '*:S'])]
except DMError:
self.loggerdeco.exception('Attempt %d get logcat throbbers' % attempt)
if attempt == self.user_cfg[PHONE_RETRY_LIMIT] - 1:
raise
sleep(self.user_cfg[PHONE_RETRY_WAIT])
def analyze_logcat(self, build_metadata):
self.loggerdeco.debug('analyzing logcat')
app_name = build_metadata['androidprocname']
logcat_prefix = '(\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3})'
throbber_prefix = 'I/GeckoToolbarDisplayLayout.* zerdatime (\d+) - Throbber'
re_base_time = re.compile('%s' % logcat_prefix)
re_start_time = re.compile('%s I/SUTAgentAndroid.* '
'exec am start\s+.*-n %s/.App '
'-a android.intent.action.VIEW' %
(logcat_prefix, app_name))
re_throbber_start_time = re.compile('%s %s start' %
(logcat_prefix, throbber_prefix))
re_throbber_stop_time = re.compile('%s %s stop' %
(logcat_prefix, throbber_prefix))
self.loggerdeco.debug('analyze_logcat: re_base_time: %s' % re_base_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_start_time: %s' % re_start_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_throbber_start_time: %s' % re_throbber_start_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_throbber_stop_time: %s' % re_throbber_stop_time.pattern)
base_time = 0
start_time = 0
throbber_start_time = 0
throbber_stop_time = 0
attempt = 0
max_time = 90 # maximum time to wait for throbbers
wait_time = 3 # time to wait between attempts
max_attempts = max_time / wait_time
while (attempt < max_attempts and (throbber_start_time == 0 or
throbber_stop_time == 0)):
buf = self.get_logcat_throbbers()
for line in buf:
self.loggerdeco.debug('analyze_logcat: %s' % line)
match = re_base_time.match(line)
if match and not base_time:
base_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: base_time: %s' % base_time)
# we want the first throbberstart and throbberstop.
match = re_start_time.match(line)
if match:
start_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: start_time: %s' % start_time)
continue
match = re_throbber_start_time.match(line)
if match and not throbber_start_time:
throbber_start_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: throbber_start_time: %s' % throbber_start_time)
continue
match = re_throbber_stop_time.match(line)
if match and not throbber_stop_time:
throbber_stop_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: throbber_stop_time: %s' % throbber_stop_time)
continue
if throbber_start_time and throbber_stop_time:
break
if throbber_start_time == 0 or throbber_stop_time == 0:
sleep(wait_time)
attempt += 1
if self.check_for_crashes():
self.loggerdeco.info('fennec crashed')
fennec_crashed = True
else:
fennec_crashed = False
if throbber_start_time and throbber_stop_time == 0 and not fennec_crashed:
self.loggerdeco.info('Unable to find Throbber stop')
# The captured time from the logcat lines is in the format
# MM-DD HH:MM:SS.mmm. It is possible for the year to change
# between the different times, so we need to make adjustments
# if necessary. First, we assume the year does not change and
# parse the dates as if they are in the current year. If
# the dates violate the natural order start_time,
# throbber_start_time, throbber_stop_time, we can adjust the
# year.
if base_time and start_time and throbber_start_time and throbber_stop_time:
parse = lambda y, t: datetime.datetime.strptime('%4d-%s' % (y, t), '%Y-%m-%d %H:%M:%S.%f')
year = datetime.datetime.now().year
base_time = parse(year, base_time)
start_time = parse(year, start_time)
throbber_start_time = parse(year, throbber_start_time)
throbber_stop_time = parse(year, throbber_stop_time)
if base_time > start_time:
base_time.replace(year=year-1)
elif start_time > throbber_start_time:
base_time.replace(year=year-1)
start_time.replace(year=year-1)
elif throbber_start_time > throbber_stop_time:
base_time.replace(year=year-1)
start_time.replace(year=year-1)
throbber_start_time.replace(year-1)
# Convert the times to milliseconds from the base time.
convert = lambda t1, t2: round((t2 - t1).total_seconds() * 1000.0)
start_time = convert(base_time, start_time)
throbber_start_time = convert(base_time, throbber_start_time)
throbber_stop_time = convert(base_time, throbber_stop_time)
self.loggerdeco.debug('analyze_logcat: base: %s, start: %s, '
'throbber start: %s, throbber stop: %s, '
'throbber time: %s ' %
(base_time, start_time,
throbber_start_time, throbber_stop_time,
throbber_stop_time - throbber_start_time))
else:
self.loggerdeco.warning(
'analyze_logcat: failed to get throbbers '
'start_time: %s, throbber start: %s, throbber stop: %s' % (
start_time, throbber_start_time, throbber_stop_time))
start_time = throbber_start_time = throbber_stop_time = 0
return (start_time, throbber_start_time, throbber_stop_time)
def publish_results(self, starttime=0, tstrt=0, tstop=0,
build_metadata=None, testname='', cache_enabled=True,
rejected=False):
msg = ('Cached: %s Start Time: %s Throbber Start: %s Throbber Stop: %s '
'Total Throbber Time: %s Rejected: %s' % (
cache_enabled, starttime, tstrt, tstop, tstop - tstrt, rejected))
self.loggerdeco.info('RESULTS: %s' % msg)
# Create JSON to send to webserver
resultdata = {}
resultdata['phoneid'] = self.phone_cfg['phoneid']
resultdata['testname'] = testname
resultdata['starttime'] = starttime
resultdata['throbberstart'] = tstrt
resultdata['throbberstop'] = tstop
resultdata['blddate'] = build_metadata['blddate']
resultdata['cached'] = cache_enabled
resultdata['rejected'] = rejected
resultdata['revision'] = build_metadata['revision']
resultdata['productname'] = build_metadata['androidprocname']
resultdata['productversion'] = build_metadata['version']
resultdata['osver'] = self.phone_cfg['osver']
resultdata['bldtype'] = build_metadata['bldtype']
resultdata['machineid'] = self.phone_cfg['machinetype']
result = {'data': resultdata}
# Upload
if self._signer:
encoded_result = jwt.encode(result, signer=self._signer)
content_type = 'application/jwt'
else:
encoded_result = json.dumps(result)
content_type = 'application/json; charset=utf-8'
req = urllib2.Request(self._resulturl + 'add/', encoded_result,
{'Content-Type': content_type})
try:
f = urllib2.urlopen(req)
except urllib2.URLError, e:
self.loggerdeco.error('Could not send results to server: %s' % e)
else:
class PhoneWorker(object):
"""Runs tests on a single phone in a separate process.
This is the interface to the subprocess, accessible by the main
process."""
DEVICEMANAGER_RETRY_LIMIT = 8
DEVICEMANAGER_SETTLING_TIME = 60
PHONE_RETRY_LIMIT = 2
PHONE_RETRY_WAIT = 15
PHONE_MAX_REBOOTS = 3
PHONE_PING_INTERVAL = 15 * 60
PHONE_COMMAND_QUEUE_TIMEOUT = 10
def __init__(self, worker_num, ipaddr, tests, phone_cfg, user_cfg,
autophone_queue, logfile_prefix, loglevel, mailer,
build_cache_port):
self.phone_cfg = phone_cfg
self.user_cfg = user_cfg
self.worker_num = worker_num
self.ipaddr = ipaddr
self.last_status_msg = None
self.first_status_of_type = None
self.last_status_of_previous_type = None
self.crashes = Crashes(crash_window=user_cfg[PHONE_CRASH_WINDOW],
crash_limit=user_cfg[PHONE_CRASH_LIMIT])
self.cmd_queue = multiprocessing.Queue()
self.lock = multiprocessing.Lock()
self.subprocess = PhoneWorkerSubProcess(self.worker_num, self.ipaddr,
tests, phone_cfg, user_cfg,
autophone_queue,
self.cmd_queue, logfile_prefix,
loglevel, mailer,
build_cache_port)
self.logger = logging.getLogger('autophone.worker')
self.loggerdeco = LogDecorator(self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip']
}, '%(phoneid)s|%(phoneip)s|%(message)s')
def is_alive(self):
return self.subprocess.is_alive()
def start(self, status=phonetest.PhoneTestMessage.IDLE):
self.subprocess.start(status)
def stop(self):
self.subprocess.stop()
def new_job(self):
self.cmd_queue.put_nowait(('job', None))
def reboot(self):
self.cmd_queue.put_nowait(('reboot', None))
def disable(self):
self.cmd_queue.put_nowait(('disable', None))
def enable(self):
self.cmd_queue.put_nowait(('enable', None))
def debug(self, level):
try:
level = int(level)
except ValueError:
self.loggerdeco.error('Invalid argument for debug: %s' % level)
else:
self.user_cfg['debug'] = level
self.cmd_queue.put_nowait(('debug', level))
def ping(self):
self.cmd_queue.put_nowait(('ping', None))
def process_msg(self, msg):
"""These are status messages routed back from the autophone_queue
listener in the main AutoPhone class. There is probably a bit
clearer way to do this..."""
if not self.last_status_msg or msg.status != self.last_status_msg.status:
self.last_status_of_previous_type = self.last_status_msg
self.first_status_of_type = msg
self.last_status_msg = msg
class PhoneTest(object):
# Use instances keyed on phoneid+':'config_file+':'+str(chunk)
# to lookup tests.
instances = {}
has_run_if_changed = False
@classmethod
def lookup(cls, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
if key in PhoneTest.instances:
return PhoneTest.instances[key]
return None
@classmethod
def match(cls, tests=None, test_name=None, phoneid=None,
config_file=None, job_guid=None,
repo=None, platform=None, build_type=None, build_abi=None, build_sdk=None,
changeset_dirs=None):
logger = utils.getLogger()
logger.debug('PhoneTest.match(tests: %s, test_name: %s, phoneid: %s, '
'config_file: %s, job_guid: %s, '
'repo: %s, platform: %s, build_type: %s, '
'abi: %s, build_sdk: %s',
tests, test_name, phoneid,
config_file, job_guid,
repo, platform, build_type, build_abi, build_sdk)
matches = []
if not tests:
tests = [PhoneTest.instances[key] for key in PhoneTest.instances.keys()]
for test in tests:
# If changeset_dirs is empty, we will run the tests anyway.
# This is safer in terms of catching regressions and extra tests
# being run are more likely to be noticed and fixed than tests
# not being run that should have been.
if hasattr(test, 'run_if_changed') and test.run_if_changed and changeset_dirs:
matched = False
for cd in changeset_dirs:
if matched:
break
for td in test.run_if_changed:
if cd == "" or cd.startswith(td):
logger.debug('PhoneTest.match: test %s dir %s '
'matched changeset_dirs %s', test, td, cd)
matched = True
break
if not matched:
continue
if test_name and test_name != test.name and \
"%s%s" % (test_name, test.name_suffix) != test.name:
continue
if phoneid and phoneid != test.phone.id:
continue
if config_file and config_file != test.config_file:
continue
if job_guid and job_guid != test.job_guid:
continue
if repo and test.repos and repo not in test.repos:
continue
if build_type and build_type not in test.buildtypes:
continue
if platform and platform not in test.platforms:
continue
if build_abi and build_abi not in test.phone.abi:
# phone.abi may be of the form armeabi-v7a, arm64-v8a
# or some form of x86. Test for inclusion rather than
# exact matches to cover the possibilities.
continue
if build_sdk and build_sdk not in test.phone.supported_sdks:
# We have extended build_sdk and the
# phone.supported_sdks to be a comma-delimited list of
# sdk values for phones whose minimum support has
# changed as the builds have changed.
sdk_found = False
for sdk in build_sdk.split(','):
if sdk in test.phone.supported_sdks:
sdk_found = True
break
if not sdk_found:
continue
matches.append(test)
logger.debug('PhoneTest.match = %s', matches)
return matches
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# The PhoneTest constructor may raise exceptions due to issues with
# the device. Creators of PhoneTest objects are responsible
# for catching these exceptions and cleaning up any previously
# created tests for the device.
#
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
# The default preferences and environment for running fennec
# are set here in PhoneTest. Tests which subclass PhoneTest can
# add or override these preferences during their
# initialization.
self._preferences = None
self._environment = None
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
# Make the values in the config file case-sensitive
self.cfg.optionxform = str
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
logger = utils.getLogger(name=self.phone.id)
self.loggerdeco = LogDecorator(logger,
{},
'%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
# Test result
self.status = TreeherderStatus.SUCCESS
self.passed = 0
self.failed = 0
self.todo = 0
self.repos = repos
self.unittest_logpath = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
# Perform initial configuration. For tests which do not
# specify all config options, reasonable defaults will be
# chosen.
# [paths]
# base_device_path accesses the device to determine the
# appropriate path and can therefore fail and raise an
# exception which will not be caught in the PhoneTest
# constructor. Creators of PhoneTest objects are responsible
# for catching these exceptions and cleaning up any previously
# created tests for the device.
self._base_device_path = ''
self.profile_path = '/data/local/tests/autophone/profile'
if self.dm:
self.profile_path = '%s/profile' % self.base_device_path
self.autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
try:
sources = self.cfg.get('paths', 'sources').split()
self._paths['sources'] = []
for source in sources:
if not source.endswith('/'):
source += '/'
self._paths['sources'].append(source)
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['sources'] = ['files/base/']
try:
self._paths['dest'] = self.cfg.get('paths', 'dest')
if not self._paths['dest'].endswith('/'):
self._paths['dest'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['dest'] = os.path.join(self.base_device_path,
self.__class__.__name__)
try:
self._paths['profile'] = self.cfg.get('paths', 'profile')
if not self._paths['profile'].endswith('/'):
self._paths['profile'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
self.run_if_changed = set()
try:
dirs = self.cfg.get('runtests', 'run_if_changed')
self.run_if_changed = set([d.strip() for d in dirs.split(',')])
if self.run_if_changed:
PhoneTest.has_run_if_changed = True
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for source in self._paths['sources']:
for push in glob.glob(source + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_file_name = os.path.basename(push)
push_dest = posixpath.join(self._paths['dest'],
source,
push_file_name)
self._pushes[push] = push_dest
if push_file_name == 'initialize_profile.html':
self._initialize_url = 'file://' + push_dest
# [tests]
self._tests = {}
try:
for t in self.cfg.items('tests'):
self._tests[t[0]] = t[1]
except ConfigParser.NoSectionError:
self._tests['blank'] = 'blank.html'
# [builds]
self.buildtypes = []
try:
self.buildtypes = self.cfg.get('builds', 'buildtypes').split(' ')
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self.buildtypes = list(self.options.buildtypes)
self.platforms = []
try:
self.platforms = self.cfg.get('builds', 'platforms').split(' ')
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self.platforms = self.options.platforms
self.loggerdeco.info('PhoneTest: %s', self.__dict__)
def __str__(self):
return '%s(%s, config_file=%s, chunk=%s, buildtypes=%s)' % (
type(self).__name__,
self.phone,
self.config_file,
self.chunk,
self.buildtypes)
def __repr__(self):
return self.__str__()
def _add_instance(self, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
assert key not in PhoneTest.instances, 'Duplicate PhoneTest %s' % key
PhoneTest.instances[key] = self
def remove(self):
key = '%s:%s:%s' % (self.phone.id, self.config_file, self.chunk)
if key in PhoneTest.instances:
had_run_if_changed = hasattr(PhoneTest.instances[key], 'run_if_changed') and \
PhoneTest.instances[key].run_if_changed
del PhoneTest.instances[key]
if had_run_if_changed:
PhoneTest.has_run_if_changed = False
for key in PhoneTest.instances.keys():
if PhoneTest.instances[key].run_if_changed:
PhoneTest.has_run_if_changed = True
break
def set_worker_subprocess(self, worker_subprocess):
logger = utils.getLogger()
self.loggerdeco = LogDecorator(logger,
{},
'%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.worker_subprocess = worker_subprocess
self.dm = worker_subprocess.dm
self.update_status_cb = worker_subprocess.update_status
@property
def preferences(self):
# https://dxr.mozilla.org/mozilla-central/source/mobile/android/app/mobile.js
# https://dxr.mozilla.org/mozilla-central/source/browser/app/profile/firefox.js
# https://dxr.mozilla.org/mozilla-central/source/addon-sdk/source/test/preferences/no-connections.json
# https://dxr.mozilla.org/mozilla-central/source/testing/profiles/prefs_general.js
# https://dxr.mozilla.org/mozilla-central/source/testing/mozbase/mozprofile/mozprofile/profile.py
if not self._preferences:
self._preferences = {
'app.support.baseURL': 'http://localhost/support-dummy/',
'app.update.auto': False,
'app.update.certs.1.commonName': '',
'app.update.certs.2.commonName': '',
'app.update.enabled': False,
'app.update.staging.enabled': False,
'app.update.url': 'http://localhost/app-dummy/update',
'app.update.url.android': 'http://localhost/app-dummy/update',
'beacon.enabled': False,
'browser.EULA.override': True,
'browser.aboutHomeSnippets.updateUrl': '',
'browser.contentHandlers.types.0.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.1.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.2.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.3.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.4.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.5.uri': 'http://localhost/rss?url=%%s',
'browser.firstrun.show.localepicker': False,
'browser.firstrun.show.uidiscovery': False,
'browser.newtab.url': '',
'browser.newtabpage.directory.ping': '',
'browser.newtabpage.directory.source': 'data:application/json,{"dummy":1}',
'browser.newtabpage.remote': False,
'browser.push.warning.infoURL': 'http://localhost/alerts-dummy/infoURL',
'browser.push.warning.migrationURL': 'http://localhost/alerts-dummy/migrationURL',
'browser.safebrowsing.appRepURL': '',
'browser.safebrowsing.downloads.enabled': False,
'browser.safebrowsing.downloads.remote.enabled': False,
'browser.safebrowsing.downloads.remote.url': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.enabled': False,
'browser.safebrowsing.gethashURL': '',
'browser.safebrowsing.malware.enabled': False,
'browser.safebrowsing.malware.reportURL': '',
'browser.safebrowsing.provider.google.appRepURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.provider.google.gethashURL': 'http://localhost/safebrowsing-dummy/gethash',
'browser.safebrowsing.provider.google.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.provider.mozilla.gethashURL': 'http://localhost/safebrowsing-dummy/gethash',
'browser.safebrowsing.provider.mozilla.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.search.countryCode': 'US',
'browser.search.geoSpecificDefaults': False,
'browser.search.geoip.url': '',
'browser.search.isUS': True,
'browser.search.suggest.enabled': False,
'browser.search.update': False,
'browser.selfsupport.url': 'https://localhost/selfsupport-dummy/',
'browser.sessionstore.resume_from_crash': False,
'browser.shell.checkDefaultBrowser': False,
'browser.snippets.enabled': False,
'browser.snippets.firstrunHomepage.enabled': False,
'browser.snippets.syncPromo.enabled': False,
'browser.snippets.updateUrl': '',
'browser.tabs.warnOnClose': False,
'browser.tiles.reportURL': 'http://localhost/tests/robocop/robocop_tiles.sjs',
'browser.trackingprotection.gethashURL': '',
'browser.trackingprotection.updateURL': '',
'browser.translation.bing.authURL': 'http://localhost/browser/browser/components/translation/test/bing.sjs',
'browser.translation.bing.translateArrayURL': 'http://localhost/browser/browser/components/translation/test/bing.sjs',
'browser.translation.yandex.translateURLOverride': 'http://localhost/browser/browser/components/translation/test/yandex.sjs',
'browser.uitour.pinnedTabUrl': 'http://localhost/uitour-dummy/pinnedTab',
'browser.uitour.url': 'http://localhost/uitour-dummy/tour',
'browser.urlbar.suggest.searches': False,
'browser.urlbar.userMadeSearchSuggestionsChoice': True,
'browser.warnOnQuit': False,
'browser.webapps.apkFactoryUrl': '',
'browser.webapps.checkForUpdates': 0,
'browser.webapps.updateCheckUrl': '',
'datareporting.healthreport.about.reportUrl': 'http://localhost/abouthealthreport/',
'datareporting.healthreport.about.reportUrlUnified': 'http://localhost/abouthealthreport/v4/',
'datareporting.healthreport.documentServerURI': 'http://localhost/healthreport/',
'datareporting.healthreport.service.enabled': False,
'datareporting.healthreport.uploadEnabled': False,
'datareporting.policy.dataSubmissionEnabled': False,
'datareporting.policy.dataSubmissionPolicyBypassAcceptance': True,
'dom.ipc.plugins.flash.subprocess.crashreporter.enabled': False,
'experiments.manifest.uri': 'http://localhost/experiments-dummy/manifest',
'extensions.autoDisableScopes': 0, # By default don't disable add-ons from any scope
'extensions.blocklist.enabled': False,
'extensions.blocklist.interval': 172800,
'extensions.blocklist.url': 'http://localhost/extensions-dummy/blocklistURL',
'extensions.enabledScopes': 5, # By default only load extensions all scopes except temporary.
'extensions.getAddons.cache.enabled': False,
'extensions.getAddons.get.url': 'http://localhost/extensions-dummy/repositoryGetURL',
'extensions.getAddons.getWithPerformance.url': 'http://localhost/extensions-dummy/repositoryGetWithPerformanceURL',
'extensions.getAddons.search.browseURL': 'http://localhost/extensions-dummy/repositoryBrowseURL',
'extensions.getAddons.search.url': 'http://localhost/extensions-dummy/repositorySearchURL',
'extensions.hotfix.url': 'http://localhost/extensions-dummy/hotfixURL',
'extensions.installDistroAddons': False,
'extensions.showMismatchUI': False,
'extensions.startupScanScopes': 5, # And scan for changes at startup
'extensions.systemAddon.update.url': 'data:application/xml,<updates></updates>',
'extensions.update.autoUpdateDefault': False,
'extensions.update.background.url': 'http://localhost/extensions-dummy/updateBackgroundURL',
'extensions.update.enabled': False,
'extensions.update.interval': 172800,
'extensions.update.notifyUser': False,
'extensions.update.url': 'http://localhost/extensions-dummy/updateURL',
'extensions.webservice.discoverURL': 'http://localhost/extensions-dummy/discoveryURL',
'general.useragent.updates.enabled': False,
'geo.provider.testing': True,
'geo.wifi.scan': False,
'geo.wifi.uri': 'http://localhost/tests/dom/tests/mochitest/geolocation/network_geolocation.sjs',
'identity.fxaccounts.auth.uri': 'https://localhost/fxa-dummy/',
'identity.fxaccounts.remote.force_auth.uri': 'https://localhost/fxa-force-auth',
'identity.fxaccounts.remote.signin.uri': 'https://localhost/fxa-signin',
'identity.fxaccounts.remote.signup.uri': 'https://localhost/fxa-signup',
'identity.fxaccounts.remote.webchannel.uri': 'https://localhost/',
'identity.fxaccounts.settings.uri': 'https://localhost/fxa-settings',
'identity.fxaccounts.skipDeviceRegistration': True,
'media.autoplay.enabled': True,
'media.gmp-gmpopenh264.autoupdate': False,
'media.gmp-manager.cert.checkAttributes': False,
'media.gmp-manager.cert.requireBuiltIn': False,
'media.gmp-manager.certs.1.commonName': '',
'media.gmp-manager.certs.2.commonName': '',
'media.gmp-manager.secondsBetweenChecks': 172800,
'media.gmp-manager.url': 'http://localhost/media-dummy/gmpmanager',
'media.gmp-manager.url.override': 'data:application/xml,<updates></updates>',
'plugin.state.flash': 2,
'plugins.update.url': 'http://localhost/plugins-dummy/updateCheckURL',
'privacy.trackingprotection.introURL': 'http://localhost/trackingprotection/tour',
'security.notification_enable_delay': 0,
'security.ssl.errorReporting.url': 'https://localhost/browser/browser/base/content/test/general/pinning_reports.sjs?succeed',
'shell.checkDefaultClient': False,
'toolkit.startup.max_resumed_crashes': -1,
'toolkit.telemetry.cachedClientID': 'dddddddd-dddd-dddd-dddd-dddddddddddd', # https://dxr.mozilla.org/mozilla-central/source/toolkit/modules/ClientID.jsm#40
'toolkit.telemetry.enabled': False,
'toolkit.telemetry.notifiedOptOut': 999,
'toolkit.telemetry.prompted': 999,
'toolkit.telemetry.rejected': True,
'toolkit.telemetry.server': 'https://localhost/telemetry-dummy/',
'toolkit.telemetry.unified': False,
'urlclassifier.updateinterval': 172800,
'webapprt.app_update_interval': 172800,
'xpinstall.signatures.required': False,
}
if self.cfg.has_section('preferences'):
overrides = self.cfg.options('preferences')
for name in overrides:
value = self.cfg.get('preferences', name)
if value.lower() == 'true':
value = True
elif value.lower() == 'false':
value = False
elif re.match(r'\d+$', value):
value = int(value)
self._preferences[name] = value
return self._preferences
@property
def environment(self):
if not self._environment:
# https://developer.mozilla.org/en-US/docs/Environment_variables_affecting_crash_reporting
self._environment = {
'MOZ_CRASHREPORTER': '1',
'MOZ_CRASHREPORTER_NO_REPORT': '1',
'MOZ_CRASHREPORTER_SHUTDOWN': '1',
'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1',
'MOZ_IN_AUTOMATION': '1',
'NO_EM_RESTART': '1',
'MOZ_DISABLE_SWITCHBOARD': '1',
#'NSPR_LOG_MODULES': 'all:5',
}
if self.cfg.has_section('environment'):
overrides = self.cfg.options('environment')
for name in overrides:
value = self.cfg.get('environment', name)
if value.lower() == 'true':
value = True
elif value.lower() == 'false':
value = False
elif re.match(r'\d+$', value):
value = int(value)
self._environment[name] = value
return self._environment
@property
def name_suffix(self):
return '-%s' % self.chunk if self.chunks > 1 else ''
@property
def name(self):
return 'autophone-%s%s' % (self.__class__.__name__, self.name_suffix)
@property
def base_device_path(self):
if self._base_device_path:
return self._base_device_path
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
try:
self._base_device_path = self.dm.test_root + '/autophone'
if not self.dm.is_dir(self._base_device_path, root=True):
self.loggerdeco.debug('Attempt %d creating base device path %s',
attempt, self._base_device_path)
self.dm.mkdir(self._base_device_path, parents=True, root=True)
self.dm.chmod(self._base_device_path, recursive=True, root=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d creating base device '
'path %s',
attempt, self._base_device_path)
sleep(self.options.phone_retry_wait)
if not success:
raise Exception('Failed to determine base_device_path')
self.loggerdeco.debug('base_device_path is %s', self._base_device_path)
return self._base_device_path
@property
def job_url(self):
if not self.options.treeherder_url:
return None
job_url = ('%s/#/jobs?filter-searchStr=autophone&' +
'exclusion_profile=false&' +
'filter-tier=1&filter-tier=2&filter-tier=3&' +
'repo=%s&revision=%s')
return job_url % (self.options.treeherder_url,
self.build.tree,
self.build.revision[:12])
@property
def job_name(self):
if not self.options.treeherder_url:
return None
if not self._job_name:
self._job_name = self.cfg.get('treeherder', 'job_name')
return self._job_name
@property
def job_symbol(self):
if not self.options.treeherder_url:
return None
if not self._job_symbol:
self._job_symbol = self.cfg.get('treeherder', 'job_symbol')
if self.chunks > 1:
self._job_symbol = "%s%s" %(self._job_symbol, self.chunk)
return self._job_symbol
@property
def group_name(self):
if not self.options.treeherder_url:
return None
if not self._group_name:
self._group_name = self.cfg.get('treeherder', 'group_name')
return self._group_name
@property
def group_symbol(self):
if not self.options.treeherder_url:
return None
if not self._group_symbol:
self._group_symbol = self.cfg.get('treeherder', 'group_symbol')
return self._group_symbol
@property
def build(self):
return self.worker_subprocess.build
def get_test_package_names(self):
"""Return a set of test package names which need to be downloaded
along with the build in order to run the test. This set will
be passed to the BuildCache.get() method. Normally, this will
only need to be set for UnitTests.
See https://bugzilla.mozilla.org/show_bug.cgi?id=1158276
https://bugzilla.mozilla.org/show_bug.cgi?id=917999
"""
return set()
def generate_guid(self):
self.job_guid = utils.generate_guid()
def handle_test_interrupt(self, reason, test_result):
self.add_failure(self.name, TestStatus.TEST_UNEXPECTED_FAIL, reason, test_result)
def add_pass(self, testpath):
testpath = _normalize_testpath(testpath)
self.passed += 1
self.loggerdeco.info(' %s | %s | Ok.', TestStatus.TEST_PASS, testpath)
def add_failure(self, testpath, test_status, text, testresult_status):
"""Report a test failure.
:param testpath: A string identifying the test.
:param test_status: A string identifying the type of test failure.
:param text: A string decribing the failure.
:param testresult_status: Test status to be reported to Treeherder.
One of PhoneTest.{BUSTED,EXCEPTION,TESTFAILED,UNKNOWN,USERCANCEL}.
"""
self.message = text
self.update_status(message=text)
testpath = _normalize_testpath(testpath)
self.status = testresult_status
self.failed += 1
self.loggerdeco.info(' %s | %s | %s', test_status, testpath, text)
def reset_result(self):
self.status = TreeherderStatus.SUCCESS
self.passed = 0
self.failed = 0
self.todo = 0
def handle_crashes(self):
"""Detect if any crash dump files have been generated, process them and
produce Treeherder compatible error messages, then clean up the dump
files before returning True if a crash was found or False if there were
no crashes detected.
"""
if not self.crash_processor:
return False
errors = self.crash_processor.get_errors(self.build.symbols,
self.options.minidump_stackwalk,
clean=True)
for error in errors:
if error['reason'] == 'java-exception':
self.add_failure(
self.name, TestStatus.PROCESS_CRASH,
error['signature'],
TreeherderStatus.TESTFAILED)
elif error['reason'] == TestStatus.TEST_UNEXPECTED_FAIL:
self.add_failure(
self.name,
error['reason'],
error['signature'],
TreeherderStatus.TESTFAILED)
elif error['reason'] == TestStatus.PROCESS_CRASH:
self.add_failure(
self.name,
error['reason'],
'application crashed [%s]' % error['signature'],
TreeherderStatus.TESTFAILED)
self.loggerdeco.info(error['signature'])
self.loggerdeco.info(error['stackwalk_output'])
self.loggerdeco.info(error['stackwalk_errors'])
else:
self.loggerdeco.warning('Unknown error reason: %s', error['reason'])
return len(errors) > 0
def stop_application(self):
"""Stop the application cleanly.
Make the home screen active placing the application into the
background, then attempt to use am force-stop, am kill, or
shell kill to stop the package in that order.
Only requires a rooted device if am force-stop and am kill
both fail.
Returns True if the process no longer exists.
Raises ADBError, ADBRootErrro, ADBTimeoutError
"""
result = True
self.loggerdeco.debug('stop_application: display home screen')
self.dm.shell_output("am start "
"-a android.intent.action.MAIN "
"-c android.intent.category.HOME")
self.loggerdeco.debug('stop_application: am force-stop')
self.dm.shell_output("am force-stop %s" % self.build.app_name)
if self.dm.process_exist(self.build.app_name):
self.loggerdeco.debug('stop_application: am kill')
self.dm.shell_output("am kill %s" % self.build.app_name)
if self.dm.process_exist(self.build.app_name):
self.loggerdeco.debug('stop_application: kill')
self.dm.pkill(self.build.app_name, root=True)
result = not self.dm.process_exist(self.build.app_name)
return result
def create_profile(self, custom_addons=[], custom_prefs=None, root=True):
# Create, install and initialize the profile to be
# used in the test.
temp_addons = ['quitter.xpi']
temp_addons.extend(custom_addons)
addons = ['%s/xpi/%s' % (os.getcwd(), addon) for addon in temp_addons]
# make sure firefox isn't running when we try to
# install the profile.
self.dm.pkill(self.build.app_name, root=root)
if isinstance(custom_prefs, dict):
prefs = dict(self.preferences.items() + custom_prefs.items())
else:
prefs = self.preferences
profile = Profile(preferences=prefs, addons=addons)
if not self.install_profile(profile):
return False
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Initializing profile', attempt)
self.run_fennec_with_profile(self.build.app_name, self._initialize_url)
if self.wait_for_fennec():
success = True
break
sleep(self.options.phone_retry_wait)
if not success or self.handle_crashes():
self.add_failure(self.name, TestStatus.TEST_UNEXPECTED_FAIL,
'Failure initializing profile',
TreeherderStatus.TESTFAILED)
return success
def wait_for_fennec(self, max_wait_time=60, wait_time=5,
kill_wait_time=20, root=True):
# Wait for up to a max_wait_time seconds for fennec to close
# itself in response to the quitter request. Check that fennec
# is still running every wait_time seconds. If fennec doesn't
# close on its own, attempt up to 3 times to kill fennec, waiting
# kill_wait_time seconds between attempts.
# Return True if fennec exits on its own, False if it needs to be killed.
# Re-raise the last exception if fennec can not be killed.
max_wait_attempts = max_wait_time / wait_time
for wait_attempt in range(1, max_wait_attempts+1):
if not self.dm.process_exist(self.build.app_name):
return True
sleep(wait_time)
max_killattempts = 3
for kill_attempt in range(1, max_killattempts+1):
try:
self.loggerdeco.info('killing %s' % self.build.app_name)
self.stop_application()
break
except ADBError:
self.loggerdeco.exception('Attempt %d to kill fennec failed' %
kill_attempt)
if kill_attempt == max_killattempts:
raise
sleep(kill_wait_time)
return False
def install_local_pages(self):
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Installing local pages', attempt)
try:
self.dm.rm(self._paths['dest'], recursive=True, force=True, root=True)
self.dm.mkdir(self._paths['dest'], parents=True, root=True)
for push_source in self._pushes:
push_dest = self._pushes[push_source]
if os.path.isdir(push_source):
self.dm.push(push_source, push_dest)
else:
self.dm.push(push_source, push_dest)
self.dm.chmod(self._paths['dest'], recursive=True, root=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d Installing local pages', attempt)
sleep(self.options.phone_retry_wait)
if not success:
self.add_failure(self.name, TestStatus.TEST_UNEXPECTED_FAIL,
'Failure installing local pages',
TreeherderStatus.TESTFAILED)
return success
def is_fennec_running(self, appname):
for attempt in range(1, self.options.phone_retry_limit+1):
try:
return self.dm.process_exist(appname)
except ADBError:
self.loggerdeco.exception('Attempt %d is fennec running', attempt)
if attempt == self.options.phone_retry_limit:
raise
sleep(self.options.phone_retry_wait)
def setup_job(self):
# Truncate the current log to prevent log bleed over. See the
# main process log for all of the mising bits. Log the current
# full contents of logcat, then clear the logcat buffers to
# help prevent the device's buffer from over flowing during
# the test.
self.worker_subprocess.filehandler.stream.truncate(0)
self.worker_subprocess.log_step('Setup Test')
self.start_time = datetime.datetime.utcnow()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
try:
self.worker_subprocess.logcat.reset()
except:
self.loggerdeco.exception('Exception resetting logcat before test')
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision,
self.build.type,
self.build.abi,
self.build.platform,
self.build.sdk,
self.build.builder_type,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
logger = utils.getLogger()
self.loggerdeco = LogDecorator(logger,
{
'repo': self.build.tree,
'buildid': self.build.id,
'buildtype': self.build.type,
'sdk': self.phone.sdk,
'platform': self.build.platform,
'testname': self.name
},
'PhoneTestJob %(repo)s %(buildid)s %(buildtype)s %(sdk)s %(platform)s %(testname)s '
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.info('PhoneTest starting job')
if self.unittest_logpath:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
self.upload_dir = tempfile.mkdtemp()
self.crash_processor = AutophoneCrashProcessor(self.dm,
self.profile_path,
self.upload_dir,
self.build.app_name)
self.crash_processor.clear()
self.reset_result()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def run_job(self):
raise NotImplementedError
def teardown_job(self):
self.loggerdeco.debug('PhoneTest.teardown_job')
self.stop_time = datetime.datetime.utcnow()
if self.stop_time and self.start_time:
self.loggerdeco.info('Test %s elapsed time: %s',
self.name, self.stop_time - self.start_time)
try:
if self.worker_subprocess.is_ok():
# Do not attempt to process crashes if the device is
# in an error state.
self.handle_crashes()
except Exception, e:
self.loggerdeco.exception('Exception during crash processing')
self.add_failure(
self.name, TestStatus.TEST_UNEXPECTED_FAIL,
'Exception %s during crash processing' % e,
TreeherderStatus.EXCEPTION)
if self.unittest_logpath and os.path.exists(self.unittest_logpath):
self.worker_subprocess.log_step('Unittest Log')
try:
logfilehandle = open(self.unittest_logpath)
for logline in logfilehandle.read().splitlines():
self.loggerdeco.info(logline)
logfilehandle.close()
except:
self.loggerdeco.exception('Exception loading log %s', self.unittest_log)
finally:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
# Unit tests may include the logcat output already but not all of them do.
self.worker_subprocess.log_step('Logcat')
try:
for logcat_line in self.worker_subprocess.logcat.get(full=True):
self.loggerdeco.info("logcat: %s", logcat_line)
except:
self.loggerdeco.exception('Exception getting logcat')
try:
if self.worker_subprocess.is_disabled() and self.status != TreeherderStatus.USERCANCEL:
# The worker was disabled while running one test of a job.
# Record the cancellation on any remaining tests in that job.
self.add_failure(
self.name, TestStatus.TEST_UNEXPECTED_FAIL,
'The worker was disabled.',
TreeherderStatus.USERCANCEL)
self.loggerdeco.info('PhoneTest stopping job')
self.worker_subprocess.flush_log()
self.worker_subprocess.treeherder.submit_complete(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision,
self.build.type,
self.build.abi,
self.build.platform,
self.build.sdk,
self.build.builder_type,
tests=[self])
except:
self.loggerdeco.exception('Exception tearing down job')
finally:
if self.upload_dir and os.path.exists(self.upload_dir):
shutil.rmtree(self.upload_dir)
self.upload_dir = None
# Reset the tests' volatile members in order to prevent them
# from being reused after a test has completed.
self.message = None
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.upload_dir = None
self.start_time = None
self.stop_time = None
self.unittest_logpath = None
# Reset the logcat buffers to help prevent the device's buffer
# from over flowing after the test.
self.worker_subprocess.logcat.reset()
if self.loggerdeco_original:
self.loggerdeco = self.loggerdeco_original
self.loggerdeco_original = None
if self.dm_logger_original:
self.dm._logger = self.dm_logger_original
self.dm_logger_original = None
self.reset_result()
class PhoneTest(object):
# Use instances keyed on phoneid+':'config_file+':'+str(chunk)
# to lookup tests.
instances = {}
@classmethod
def lookup(cls, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
if key in PhoneTest.instances:
return PhoneTest.instances[key]
return None
@classmethod
def match(cls, tests=None, test_name=None, phoneid=None,
config_file=None, chunk=None, job_guid=None,
build_url=None):
logger.debug('PhoneTest.match(tests: %s, test_name: %s, phoneid: %s, '
'config_file: %s, chunk: %s, job_guid: %s, '
'build_url: %s' % (tests, test_name, phoneid,
config_file, chunk, job_guid,
build_url))
matches = []
if not tests:
tests = [PhoneTest.instances[key] for key in PhoneTest.instances.keys()]
for test in tests:
if test_name and test_name != test.name:
continue
if phoneid and phoneid != test.phone.id:
continue
if config_file and config_file != test.config_file:
continue
if chunk and chunk != test.chunk:
continue
if job_guid and job_guid != test.job_guid:
continue
if build_url:
abi = test.phone.abi
sdk = test.phone.sdk
# First assume the test and build are compatible.
incompatible_job = False
# x86 devices can only test x86 builds and non-x86
# devices can not test x86 builds.
if abi == 'x86':
if 'x86' not in build_url:
incompatible_job = True
else:
if 'x86' in build_url:
incompatible_job = True
# If the build_url does not contain an sdk level, then
# assume this is an build from before the split sdk
# builds were first created. Otherwise the build_url
# must match this device's supported sdk levels.
if ('api-9' not in build_url and 'api-10' not in build_url and
'api-11' not in build_url):
pass
elif sdk not in build_url:
incompatible_job = True
if incompatible_job:
continue
# The test may be defined for multiple repositories.
# We are interested if this particular build is
# supported by this test. First assume it is
# incompatible, and only accept it if the build_url is
# from one of the supported repositories.
if test.repos:
incompatible_job = True
for repo in test.repos:
if repo in build_url:
incompatible_job = False
break
if incompatible_job:
continue
matches.append(test)
logger.debug('PhoneTest.match = %s' % matches)
return matches
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
# The default preferences and environment for running fennec
# are set here in PhoneTest. Tests which subclass PhoneTest can
# add or override these preferences during their
# initialization.
self._preferences = None
self._environment = None
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
# Make the values in the config file case-sensitive
self.cfg.optionxform = str
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id},
'%(phoneid)s|%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
# test_logfilehandler is used by running tests to save log
# messages to a separate file which can be reset at the
# beginning of each test independently of the worker's log.
self.test_logfilehandler = None
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self.repos = repos
self.test_logfile = None
self.unittest_logpath = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self, self.loggerdeco)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
# Perform initial configuration. For tests which do not
# specify all config options, reasonable defaults will be
# chosen.
# [paths]
self.autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['dest'] = posixpath.join(self.base_device_path,
self.__class__.__name__)
try:
sources = self.cfg.get('paths', 'sources').split()
self._paths['sources'] = []
for source in sources:
if not source.endswith('/'):
source += '/'
self._paths['sources'].append(source)
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['sources'] = [
os.path.join(self.autophone_directory, 'files/base/')]
try:
self._paths['dest'] = self.cfg.get('paths', 'dest')
if not self._paths['dest'].endswith('/'):
self._paths['dest'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
try:
self._paths['profile'] = self.cfg.get('paths', 'profile')
if not self._paths['profile'].endswith('/'):
self._paths['profile'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for source in self._paths['sources']:
for push in glob.glob(source + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'],
os.path.basename(push))
self._pushes[push] = push_dest
self._initialize_url = os.path.join('file://', self._paths['dest'],
'initialize_profile.html')
# [tests]
self._tests = {}
try:
for t in self.cfg.items('tests'):
self._tests[t[0]] = t[1]
except ConfigParser.NoSectionError:
self._tests['blank'] = 'blank.html'
self.loggerdeco.info('PhoneTest: Connected.')
def __str__(self):
return '%s(%s, config_file=%s, chunk=%s)' % (type(self).__name__,
self.phone,
self.config_file,
self.chunk)
def __repr__(self):
return self.__str__()
def _add_instance(self, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
assert key not in PhoneTest.instances, 'Duplicate PhoneTest %s' % key
PhoneTest.instances[key] = self
def remove(self):
key = '%s:%s:%s' % (self.phone.id, self.config_file, self.chunk)
if key in PhoneTest.instances:
del PhoneTest.instances[key]
@property
def preferences(self):
# https://dxr.mozilla.org/mozilla-central/source/mobile/android/app/mobile.js
# https://dxr.mozilla.org/mozilla-central/source/browser/app/profile/firefox.js
# https://dxr.mozilla.org/mozilla-central/source/addon-sdk/source/test/preferences/no-connections.json
# https://dxr.mozilla.org/mozilla-central/source/testing/profiles/prefs_general.js
if not self._preferences:
self._preferences = {
'app.update.auto': False,
'app.update.certs.1.commonName': '',
'app.update.certs.2.commonName': '',
'app.update.enabled': False,
'app.update.staging.enabled': False,
'app.update.url': 'http://localhost/app-dummy/update',
'app.update.url.android': 'http://localhost/app-dummy/update',
'beacon.enabled': False,
'browser.EULA.override': True,
'browser.aboutHomeSnippets.updateUrl': '',
'browser.contentHandlers.types.0.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.1.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.2.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.3.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.4.uri': 'http://localhost/rss?url=%%s',
'browser.contentHandlers.types.5.uri': 'http://localhost/rss?url=%%s',
'browser.firstrun.show.localepicker': False,
'browser.firstrun.show.uidiscovery': False,
'browser.newtab.url': '',
'browser.newtabpage.directory.ping': '',
'browser.newtabpage.directory.source': 'data:application/json,{"dummy":1}',
'browser.safebrowsing.appRepURL': '',
'browser.safebrowsing.downloads.enabled': False,
'browser.safebrowsing.downloads.remote.enabled': False,
'browser.safebrowsing.enabled': False,
'browser.safebrowsing.gethashURL': '',
'browser.safebrowsing.malware.enabled': False,
'browser.safebrowsing.malware.reportURL': '',
'browser.safebrowsing.provider.google.appRepURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.provider.google.gethashURL': 'http://localhost/safebrowsing-dummy/gethash',
'browser.safebrowsing.provider.google.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.provider.mozilla.gethashURL': 'http://localhost/safebrowsing-dummy/gethash',
'browser.safebrowsing.provider.mozilla.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.safebrowsing.updateURL': 'http://localhost/safebrowsing-dummy/update',
'browser.search.countryCode': 'US',
'browser.search.geoSpecificDefaults': False,
'browser.search.geoip.url': '',
'browser.search.isUS': True,
'browser.search.suggest.enabled': False,
'browser.search.update': False,
'browser.selfsupport.url': 'https://localhost/selfsupport-dummy/',
'browser.sessionstore.resume_from_crash': False,
'browser.snippets.enabled': False,
'browser.snippets.firstrunHomepage.enabled': False,
'browser.snippets.syncPromo.enabled': False,
'browser.snippets.updateUrl': '',
'browser.tiles.reportURL': 'http://localhost/tests/robocop/robocop_tiles.sjs',
'browser.trackingprotection.gethashURL': '',
'browser.trackingprotection.updateURL': '',
'browser.translation.bing.authURL': 'http://localhost/browser/browser/components/translation/test/bing.sjs',
'browser.translation.bing.translateArrayURL': 'http://localhost/browser/browser/components/translation/test/bing.sjs',
'browser.translation.yandex.translateURLOverride': 'http://localhost/browser/browser/components/translation/test/yandex.sjs',
'browser.uitour.pinnedTabUrl': 'http://localhost/uitour-dummy/pinnedTab',
'browser.uitour.url': 'http://localhost/uitour-dummy/tour',
'browser.warnOnQuit': False,
'browser.webapps.apkFactoryUrl': '',
'browser.webapps.checkForUpdates': 0,
'browser.webapps.updateCheckUrl': '',
'datareporting.healthreport.about.reportUrl': 'http://localhost/abouthealthreport/',
'datareporting.healthreport.about.reportUrlUnified': 'http://localhost/abouthealthreport/v4/',
'datareporting.healthreport.documentServerURI': 'http://localhost/healthreport/',
'datareporting.healthreport.service.enabled': False,
'datareporting.healthreport.uploadEnabled': False,
'datareporting.policy.dataSubmissionEnabled': False,
'datareporting.policy.dataSubmissionPolicyBypassAcceptance': True,
'dom.ipc.plugins.flash.subprocess.crashreporter.enabled': False,
'experiments.manifest.uri': 'http://localhost/experiments-dummy/manifest',
'extensions.autoDisableScopes': 0,
'extensions.blocklist.enabled': False,
'extensions.blocklist.interval': 172800,
'extensions.blocklist.url': 'http://localhost/extensions-dummy/blocklistURL',
'extensions.enabledScopes': 5,
'extensions.getAddons.cache.enabled': False,
'extensions.getAddons.get.url': 'http://localhost/extensions-dummy/repositoryGetURL',
'extensions.getAddons.getWithPerformance.url': 'http://localhost/extensions-dummy/repositoryGetWithPerformanceURL',
'extensions.getAddons.search.browseURL': 'http://localhost/extensions-dummy/repositoryBrowseURL',
'extensions.getAddons.search.url': 'http://localhost/extensions-dummy/repositorySearchURL',
'extensions.hotfix.url': 'http://localhost/extensions-dummy/hotfixURL',
'extensions.update.autoUpdateDefault': False,
'extensions.update.background.url': 'http://localhost/extensions-dummy/updateBackgroundURL',
'extensions.update.enabled': False,
'extensions.update.interval': 172800,
'extensions.update.url': 'http://localhost/extensions-dummy/updateURL',
'extensions.webservice.discoverURL': 'http://localhost/extensions-dummy/discoveryURL',
'general.useragent.updates.enabled': False,
'geo.wifi.scan': False,
'geo.wifi.uri': 'http://localhost/tests/dom/tests/mochitest/geolocation/network_geolocation.sjs',
'identity.fxaccounts.auth.uri': 'https://localhost/fxa-dummy/',
'identity.fxaccounts.remote.force_auth.uri': 'https://localhost/fxa-force-auth',
'identity.fxaccounts.remote.signin.uri': 'https://localhost/fxa-signin',
'identity.fxaccounts.remote.signup.uri': 'https://localhost/fxa-signup',
'identity.fxaccounts.remote.webchannel.uri': 'https://localhost/',
'identity.fxaccounts.settings.uri': 'https://localhost/fxa-settings',
'media.autoplay.enabled': True,
'media.gmp-gmpopenh264.autoupdate': False,
'media.gmp-manager.cert.checkAttributes': False,
'media.gmp-manager.cert.requireBuiltIn': False,
'media.gmp-manager.certs.1.commonName': '',
'media.gmp-manager.certs.2.commonName': '',
'media.gmp-manager.secondsBetweenChecks': 172800,
'media.gmp-manager.url': 'http://localhost/media-dummy/gmpmanager',
'media.gmp-manager.url.override': 'data:application/xml,<updates></updates>',
'plugin.state.flash': 2,
'plugins.update.url': 'http://localhost/plugins-dummy/updateCheckURL',
'privacy.trackingprotection.introURL': 'http://localhost/trackingprotection/tour',
'security.ssl.errorReporting.url': 'https://localhost/browser/browser/base/content/test/general/pinning_reports.sjs?succeed',
'shell.checkDefaultClient': False,
'toolkit.telemetry.cachedClientID': 'dddddddd-dddd-dddd-dddd-dddddddddddd', # https://dxr.mozilla.org/mozilla-central/source/toolkit/modules/ClientID.jsm#40
'toolkit.telemetry.enabled': False,
'toolkit.telemetry.notifiedOptOut': 999,
'toolkit.telemetry.prompted': 999,
'toolkit.telemetry.rejected': True,
'toolkit.telemetry.server': 'https://localhost/telemetry-dummy/',
'toolkit.telemetry.unified': False,
'urlclassifier.updateinterval': 172800,
'webapprt.app_update_interval': 172800,
'xpinstall.signatures.required': False,
}
if self.cfg.has_section('preferences'):
overrides = self.cfg.options('preferences')
for name in overrides:
value = self.cfg.get('preferences', name)
if value.lower() == 'true':
value = True
elif value.lower() == 'false':
value = False
elif re.match('\d+$', value):
value = int(value)
self._preferences[name] = value
return self._preferences
@property
def environment(self):
if not self._environment:
# https://developer.mozilla.org/en-US/docs/Environment_variables_affecting_crash_reporting
self._environment = {
'MOZ_CRASHREPORTER': '1',
'MOZ_CRASHREPORTER_NO_REPORT': '1',
'MOZ_CRASHREPORTER_SHUTDOWN': '1',
'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1',
'NO_EM_RESTART': '1',
#'NSPR_LOG_MODULES': 'all:5',
}
if self.cfg.has_section('environment'):
overrides = self.cfg.options('environment')
for name in overrides:
value = self.cfg.get('environment', name)
if value.lower() == 'true':
value = True
elif value.lower() == 'false':
value = False
elif re.match('\d+$', value):
value = int(value)
self._environment[name] = value
return self._environment
@property
def name_suffix(self):
return '-%s' % self.chunk if self.chunks > 1 else ''
@property
def name(self):
return 'autophone-%s%s' % (self.__class__.__name__, self.name_suffix)
@property
def base_device_path(self):
if self._base_device_path:
return self._base_device_path
success = False
e = None
for attempt in range(1, self.options.phone_retry_limit+1):
self._base_device_path = self.dm.test_root + '/autophone'
self.loggerdeco.debug('Attempt %d creating base device path %s' % (
attempt, self._base_device_path))
try:
if not self.dm.is_dir(self._base_device_path):
self.dm.mkdir(self._base_device_path, parents=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d creating base device '
'path %s' % (
attempt, self._base_device_path))
sleep(self.options.phone_retry_wait)
if not success:
raise e
self.loggerdeco.debug('base_device_path is %s' % self._base_device_path)
return self._base_device_path
@property
def job_url(self):
if not self.options.treeherder_url:
return None
job_url = '%s/#/jobs?filter-searchStr=autophone&exclusion_profile=false&repo=%s&revision=%s'
return job_url % (self.options.treeherder_url,
self.build.tree,
os.path.basename(self.build.revision)[:12])
@property
def job_name(self):
if not self.options.treeherder_url:
return None
if not self._job_name:
self._job_name = self.cfg.get('treeherder', 'job_name')
return self._job_name
@property
def job_symbol(self):
if not self.options.treeherder_url:
return None
if not self._job_symbol:
self._job_symbol = self.cfg.get('treeherder', 'job_symbol')
if self.chunks > 1:
self._job_symbol = "%s%s" %(self._job_symbol, self.chunk)
return self._job_symbol
@property
def group_name(self):
if not self.options.treeherder_url:
return None
if not self._group_name:
self._group_name = self.cfg.get('treeherder', 'group_name')
return self._group_name
@property
def group_symbol(self):
if not self.options.treeherder_url:
return None
if not self._group_symbol:
self._group_symbol = self.cfg.get('treeherder', 'group_symbol')
return self._group_symbol
@property
def build(self):
return self.worker_subprocess.build
def get_test_package_names(self):
"""Return a set of test package names which need to be downloaded
along with the build in order to run the test. This set will
be passed to the BuildCache.get() method. Normally, this will
only need to be set for UnitTests.
See https://bugzilla.mozilla.org/show_bug.cgi?id=1158276
https://bugzilla.mozilla.org/show_bug.cgi?id=917999
"""
return set()
def generate_guid(self):
self.job_guid = utils.generate_guid()
def get_buildername(self, tree):
return "%s %s opt %s" % (
self.phone.platform, tree, self.name)
def handle_test_interrupt(self, reason, test_result):
self.test_failure(self.name, 'TEST-UNEXPECTED-FAIL', reason, test_result)
def test_pass(self, testpath):
self.test_result.add_pass(testpath)
def test_failure(self, testpath, status, message, testresult_status):
self.message = message
self.update_status(message=message)
self.test_result.add_failure(testpath, status, message, testresult_status)
def handle_crashes(self):
if not self.crash_processor:
return
for error in self.crash_processor.get_errors(self.build.symbols,
self.options.minidump_stackwalk,
clean=False):
if error['reason'] == 'java-exception':
self.test_failure(
self.name, 'PROCESS-CRASH',
error['signature'],
PhoneTestResult.EXCEPTION)
elif error['reason'] == 'PROFILE-ERROR':
self.test_failure(
self.name,
error['reason'],
error['signature'],
PhoneTestResult.TESTFAILED)
elif error['reason'] == 'PROCESS-CRASH':
self.loggerdeco.info("PROCESS-CRASH | %s | "
"application crashed [%s]" % (self.name,
error['signature']))
self.loggerdeco.info(error['stackwalk_output'])
self.loggerdeco.info(error['stackwalk_errors'])
self.test_failure(self.name,
error['reason'],
'application crashed [%s]' % error['signature'],
PhoneTestResult.TESTFAILED)
else:
self.loggerdeco.warning('Unknown error reason: %s' % error['reason'])
def create_profile(self, custom_addons=[], custom_prefs=None, root=True):
# Create, install and initialize the profile to be
# used in the test.
temp_addons = ['quitter.xpi']
temp_addons.extend(custom_addons)
addons = ['%s/xpi/%s' % (os.getcwd(), addon) for addon in temp_addons]
# make sure firefox isn't running when we try to
# install the profile.
self.dm.pkill(self.build.app_name, root=root)
if isinstance(custom_prefs, dict):
prefs = dict(self.preferences.items() + custom_prefs.items())
else:
prefs = self.preferences
profile = FirefoxProfile(preferences=prefs, addons=addons)
if not self.install_profile(profile):
return False
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Initializing profile' % attempt)
self.run_fennec_with_profile(self.build.app_name, self._initialize_url)
if self.wait_for_fennec():
success = True
break
sleep(self.options.phone_retry_wait)
if not success:
msg = 'Aborting Test - Failure initializing profile.'
self.loggerdeco.error(msg)
return success
def wait_for_fennec(self, max_wait_time=60, wait_time=5,
kill_wait_time=20, root=True):
# Wait for up to a max_wait_time seconds for fennec to close
# itself in response to the quitter request. Check that fennec
# is still running every wait_time seconds. If fennec doesn't
# close on its own, attempt up to 3 times to kill fennec, waiting
# kill_wait_time seconds between attempts.
# Return True if fennec exits on its own, False if it needs to be killed.
# Re-raise the last exception if fennec can not be killed.
max_wait_attempts = max_wait_time / wait_time
for wait_attempt in range(1, max_wait_attempts+1):
if not self.dm.process_exist(self.build.app_name):
return True
sleep(wait_time)
self.loggerdeco.debug('killing fennec')
max_killattempts = 3
for kill_attempt in range(1, max_killattempts+1):
try:
self.dm.pkill(self.build.app_name, root=root)
break
except ADBError:
self.loggerdeco.exception('Attempt %d to kill fennec failed' %
kill_attempt)
if kill_attempt == max_killattempts:
raise
sleep(kill_wait_time)
return False
def install_local_pages(self):
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
self.loggerdeco.debug('Attempt %d Installing local pages' % attempt)
try:
self.dm.rm(self._paths['dest'], recursive=True, force=True)
self.dm.mkdir(self._paths['dest'], parents=True)
for push_source in self._pushes:
push_dest = self._pushes[push_source]
if os.path.isdir(push_source):
self.dm.push(push_source, push_dest)
else:
self.dm.push(push_source, push_dest)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d Installing local pages' % attempt)
sleep(self.options.phone_retry_wait)
if not success:
self.loggerdeco.error('Failure installing local pages')
return success
def is_fennec_running(self, appname):
for attempt in range(1, self.options.phone_retry_limit+1):
try:
return self.dm.process_exist(appname)
except ADBError:
self.loggerdeco.exception('Attempt %d is fennec running' % attempt)
if attempt == self.options.phone_retry_limit:
raise
sleep(self.options.phone_retry_wait)
def setup_job(self):
# Log the current full contents of logcat, then clear the
# logcat buffers to help prevent the device's buffer from
# over flowing during the test.
self.start_time = datetime.datetime.now()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
self.loggerdeco.debug('phonetest.setup_job: full logcat before job:')
try:
self.loggerdeco.debug('\n'.join(self.logcat.get(full=True)))
except:
self.loggerdeco.exception('Exception getting logcat')
try:
self.logcat.reset()
except:
self.loggerdeco.exception('Exception resetting logcat')
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
# Create a test run specific logger which will propagate to
# the root logger in the worker which runs in the same
# process. This log will be uploaded to Treeherder if
# Treeherder submission is enabled and will be cleared at the
# beginning of each test run.
sensitive_data_filter = SensitiveDataFilter(self.options.sensitive_data)
logger = logging.getLogger('phonetest')
logger.addFilter(sensitive_data_filter)
logger.propagate = True
logger.setLevel(self.worker_subprocess.loglevel)
self.test_logfile = (self.worker_subprocess.logfile_prefix +
'-' + self.name + '.log')
self.test_logfilehandler = logging.FileHandler(
self.test_logfile, mode='w')
fileformatstring = ('%(asctime)s|%(process)d|%(threadName)s|%(name)s|'
'%(levelname)s|%(message)s')
fileformatter = logging.Formatter(fileformatstring)
self.test_logfilehandler.setFormatter(fileformatter)
logger.addHandler(self.test_logfilehandler)
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self.unittest_logpath:
os.unlink(self.unittest_logpath)
self.unittest_logpath = None
self.upload_dir = tempfile.mkdtemp()
self.crash_processor = AutophoneCrashProcessor(self.dm,
self.profile_path,
self.upload_dir,
self.build.app_name)
self.crash_processor.clear()
self.test_result = PhoneTestResult()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def run_job(self):
raise NotImplementedError
def teardown_job(self):
self.loggerdeco.debug('PhoneTest.teardown_job')
self.stop_time = datetime.datetime.now()
self.loggerdeco.info('Test %s elapsed time: %s' % (
self.name, self.stop_time - self.start_time))
try:
if self.worker_subprocess.is_ok():
# Do not attempt to process crashes if the device is
# in an error state.
self.handle_crashes()
except Exception, e:
self.loggerdeco.exception('Exception during crash processing')
self.test_failure(
self.name, 'TEST-UNEXPECTED-FAIL',
'Exception %s during crash processing' % e,
PhoneTestResult.EXCEPTION)
logger = logging.getLogger('phonetest')
if (logger.getEffectiveLevel() == logging.DEBUG and self.unittest_logpath and
os.path.exists(self.unittest_logpath)):
self.loggerdeco.debug(40 * '=')
try:
logfilehandle = open(self.unittest_logpath)
self.loggerdeco.debug(logfilehandle.read())
logfilehandle.close()
except Exception:
self.loggerdeco.exception('Exception %s loading log')
self.loggerdeco.debug(40 * '-')
# Log the current full contents of logcat, then reset the
# logcat buffers to help prevent the device's buffer from
# over flowing after the test.
self.loggerdeco.debug('phonetest.teardown_job full logcat after job:')
self.loggerdeco.debug('\n'.join(self.logcat.get(full=True)))
try:
if (self.worker_subprocess.is_disabled() and
self.test_result.status != PhoneTestResult.USERCANCEL):
# The worker was disabled while running one test of a job.
# Record the cancellation on any remaining tests in that job.
self.test_failure(self.name, 'TEST_UNEXPECTED_FAIL',
'The worker was disabled.',
PhoneTestResult.USERCANCEL)
self.worker_subprocess.treeherder.submit_complete(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
except:
self.loggerdeco.exception('Exception tearing down job')
finally:
if self.upload_dir and os.path.exists(self.upload_dir):
shutil.rmtree(self.upload_dir)
self.upload_dir = None
# Reset the tests' volatile members in order to prevent them
# from being reused after a test has completed.
self.test_result = PhoneTestResult()
self.message = None
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.upload_dir = None
self.start_time = None
self.stop_time = None
self.unittest_logpath = None
self.logcat.reset()
if self.loggerdeco_original:
self.loggerdeco = self.loggerdeco_original
self.loggerdeco_original = None
if self.dm_logger_original:
self.dm._logger = self.dm_logger_original
self.dm_logger_original = None
self.test_logfilehandler.close()
logger.removeHandler(self.test_logfilehandler)
self.test_logfilehandler = None
os.unlink(self.test_logfile)
self.test_logfile = None
def runtests(self, build_metadata, worker_subprocess):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
appname = build_metadata['androidprocname']
if not self.install_local_pages():
self.set_status(msg='Could not install local pages on phone. '
'Aborting test for '
'build %s' % build_metadata['buildid'])
return
if not self.create_profile(build_metadata):
self.set_status(msg='Could not run Fennec. Aborting test for '
'build %s' % build_metadata['buildid'])
return
testcount = len(self._urls.keys())
for testnum, (testname, url) in enumerate(self._urls.iteritems(), 1):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid'],
'testname': testname
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
if self.check_results(build_metadata, testname):
# We already have good results for this test and build.
# No need to test it again.
self.loggerdeco.info(
'Skipping test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
continue
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
for attempt in range(self.stderrp_attempts):
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(self._iterations):
self.set_status(msg='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt + 1, self.stderrp_attempts,
testnum, testcount, iteration + 1, url))
dataset.append({})
if not self.create_profile(build_metadata):
continue
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['uncached'] = measurement
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration + 1,
self._iterations))
break
self.loggerdeco.debug('publishing results')
if self.is_stderr_below_threshold(dataset,
self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration + 1, self._iterations))
for datapoint in dataset:
for cachekey in datapoint:
self.publish_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
build_metadata=build_metadata,
testname=testname,
cache_enabled=(cachekey == 'cached'),
rejected=rejected)
if not rejected:
break
class S1S2Test(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
try:
# Read our config file which gives us our number of
# iterations and urls that we will be testing
cfg = ConfigParser.RawConfigParser()
cfg.read(self.config_file)
# [signature]
self._signer = None
self._jwt = {'id': '', 'key': None}
for opt in self._jwt.keys():
try:
self._jwt[opt] = cfg.get('signature', opt)
except (ConfigParser.NoSectionError,
ConfigParser.NoOptionError):
break
# phonedash requires both an id and a key.
if self._jwt['id'] and self._jwt['key']:
self._signer = jwt.jws.HmacSha(key=self._jwt['key'],
key_id=self._jwt['id'])
# [paths]
autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['source'] = os.path.join(autophone_directory, 'files/')
self._paths['dest'] = posixpath.join(self.base_device_path,
's1test/')
self._paths['remote'] = 'http://phonedash.mozilla.org/'
try:
for opt in ('source', 'dest', 'profile', 'remote'):
try:
self._paths[opt] = cfg.get('paths', opt)
if not self._paths[opt].endswith('/'):
self._paths[opt] += '/'
except ConfigParser.NoOptionError:
pass
except ConfigParser.NoSectionError:
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for push in glob.glob(self._paths['source'] + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'],
os.path.basename(push))
self._pushes[push] = push_dest
# [tests]
self._tests = {}
for t in cfg.items('tests'):
self._tests[t[0]] = t[1]
# Map URLS - {urlname: url} - urlname serves as testname
self._urls = {}
for test_location in ('local', 'remote'):
for test_name in self._tests:
if test_location == 'local':
test_url = 'file://' + self._paths[
'dest'] + self._tests[test_name]
else:
test_url = self._paths['remote'] + self._tests[
test_name]
self._urls["%s-%s" % (test_location, test_name)] = test_url
# [settings]
self._iterations = cfg.getint('settings', 'iterations')
try:
self.stderrp_accept = cfg.getfloat('settings',
'stderrp_accept')
except ConfigParser.NoOptionError:
self.stderrp_accept = 0
try:
self.stderrp_reject = cfg.getfloat('settings',
'stderrp_reject')
except ConfigParser.NoOptionError:
self.stderrp_reject = 100
try:
self.stderrp_attempts = cfg.getint('settings',
'stderrp_attempts')
except ConfigParser.NoOptionError:
self.stderrp_attempts = 1
self._resulturl = cfg.get('settings', 'resulturl')
if not self._resulturl.endswith('/'):
self._resulturl += '/'
self._initialize_url = 'file://' + self._paths[
'dest'] + 'initialize_profile.html'
self.runtests(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
self.dm._logger = loggerdeco
def is_stderr_below_threshold(self, dataset, threshold):
"""Return True if all of the measurements in the dataset have
standard errors of the mean below the threshold.
Return False if at least one measurement is above the threshold
or if one or more datasets have only one value.
Return None if at least one measurement has no values.
"""
self.loggerdeco.debug("is_stderr_below_threshold: %s" % dataset)
for cachekey in ('uncached', 'cached'):
for measurement in ('throbberstart', 'throbberstop'):
data = [
datapoint[cachekey][measurement] -
datapoint[cachekey]['starttime'] for datapoint in dataset
if datapoint and cachekey in datapoint
]
if not data:
return None
stats = get_stats(data)
self.loggerdeco.debug(
'%s %s count: %d, mean: %.2f, '
'stddev: %.2f, stderr: %.2f, '
'stderrp: %.2f' %
(cachekey, measurement, stats['count'], stats['mean'],
stats['stddev'], stats['stderr'], stats['stderrp']))
if stats['count'] == 1 or stats['stderrp'] >= threshold:
return False
return True
def runtests(self, build_metadata, worker_subprocess):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
appname = build_metadata['androidprocname']
if not self.install_local_pages():
self.set_status(msg='Could not install local pages on phone. '
'Aborting test for '
'build %s' % build_metadata['buildid'])
return
if not self.create_profile(build_metadata):
self.set_status(msg='Could not run Fennec. Aborting test for '
'build %s' % build_metadata['buildid'])
return
testcount = len(self._urls.keys())
for testnum, (testname, url) in enumerate(self._urls.iteritems(), 1):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid'],
'testname': testname
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
if self.check_results(build_metadata, testname):
# We already have good results for this test and build.
# No need to test it again.
self.loggerdeco.info(
'Skipping test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
continue
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
for attempt in range(self.stderrp_attempts):
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(self._iterations):
self.set_status(msg='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt + 1, self.stderrp_attempts,
testnum, testcount, iteration + 1, url))
dataset.append({})
if not self.create_profile(build_metadata):
continue
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['uncached'] = measurement
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration + 1,
self._iterations))
break
self.loggerdeco.debug('publishing results')
if self.is_stderr_below_threshold(dataset,
self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration + 1, self._iterations))
for datapoint in dataset:
for cachekey in datapoint:
self.publish_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
build_metadata=build_metadata,
testname=testname,
cache_enabled=(cachekey == 'cached'),
rejected=rejected)
if not rejected:
break
def runtest(self, build_metadata, appname, url):
# Clear logcat
self.loggerdeco.debug('clearing logcat')
self.dm.recordLogcat()
self.loggerdeco.debug('logcat cleared')
self.loggerdeco.debug('running fennec')
# Run test
self.run_fennec_with_profile(appname, url)
# Get results - do this now so we don't have as much to
# parse in logcat.
starttime, throbberstart, throbberstop = self.analyze_logcat(
build_metadata)
self.wait_for_fennec(build_metadata)
# Ensure we succeeded - no 0's reported
datapoint = {}
if (throbberstart and throbberstop):
datapoint['starttime'] = starttime
datapoint['throbberstart'] = throbberstart
datapoint['throbberstop'] = throbberstop
datapoint['throbbertime'] = throbberstop - throbberstart
return datapoint
def wait_for_fennec(self,
build_metadata,
max_wait_time=60,
wait_time=5,
kill_wait_time=20):
# Wait for up to a max_wait_time seconds for fennec to close
# itself in response to the quitter request. Check that fennec
# is still running every wait_time seconds. If fennec doesn't
# close on its own, attempt up to 3 times to kill fennec, waiting
# kill_wait_time seconds between attempts.
# Return True if fennec exits on its own, False if it needs to be killed.
# Re-raise the last exception if fennec can not be killed.
max_wait_attempts = max_wait_time / wait_time
for wait_attempt in range(max_wait_attempts):
if not self.dm.processExist(build_metadata['androidprocname']):
return True
sleep(wait_time)
self.loggerdeco.debug('killing fennec')
max_killattempts = 3
for kill_attempt in range(max_killattempts):
try:
self.dm.killProcess(build_metadata['androidprocname'])
break
except DMError:
self.loggerdeco.exception('Attempt %d to kill fennec failed' %
kill_attempt)
if kill_attempt == max_killattempts - 1:
raise
sleep(kill_wait_time)
return False
def create_profile(self, build_metadata, custom_prefs=None):
# Create, install and initialize the profile to be
# used in the test.
telemetry_prompt = 999
if build_metadata['blddate'] < '2013-01-03':
telemetry_prompt = 2
prefs = {
'browser.firstrun.show.localepicker': False,
'browser.sessionstore.resume_from_crash': False,
'dom.ipc.plugins.flash.subprocess.crashreporter.enabled': False,
'browser.firstrun.show.uidiscovery': False,
'shell.checkDefaultClient': False,
'browser.warnOnQuit': False,
'browser.EULA.override': True,
'toolkit.telemetry.prompted': telemetry_prompt,
'toolkit.telemetry.notifiedOptOut': telemetry_prompt,
'datareporting.healthreport.service.enabled': False,
}
if isinstance(custom_prefs, dict):
prefs = dict(prefs.items() + custom_prefs.items())
profile = FirefoxProfile(preferences=prefs,
addons='%s/xpi/quitter.xpi' % os.getcwd())
if not self.install_profile(profile):
return False
appname = build_metadata['androidprocname']
buildid = build_metadata['buildid']
success = False
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
self.loggerdeco.debug('Attempt %d Initializing profile' % attempt)
self.run_fennec_with_profile(appname, self._initialize_url)
if self.wait_for_fennec(build_metadata):
success = True
break
sleep(self.user_cfg[PHONE_RETRY_WAIT])
if not success:
msg = 'Failure initializing profile for build %s' % buildid
self.loggerdeco.error(msg)
self.set_status(msg=msg)
return success
def install_local_pages(self):
success = False
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
self.loggerdeco.debug('Attempt %d Installing local pages' %
attempt)
try:
self.dm.mkDir(self._paths['dest'])
for push_source in self._pushes:
push_dest = self._pushes[push_source]
if os.path.isdir(push_source):
self.dm.pushDir(push_source, push_dest)
else:
self.dm.pushFile(push_source, push_dest)
success = True
break
except DMError:
self.loggerdeco.exception('Attempt %d Installing local pages' %
attempt)
sleep(self.user_cfg[PHONE_RETRY_WAIT])
if not success:
self.loggerdeco.error('Failure installing local pages')
return success
def is_fennec_running(self, appname):
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
try:
return self.dm.processExist(appname)
except DMError:
self.loggerdeco.exception('Attempt %d is fennec running' %
attempt)
if attempt == self.user_cfg[PHONE_RETRY_LIMIT] - 1:
raise
sleep(self.user_cfg[PHONE_RETRY_WAIT])
def get_logcat_throbbers(self):
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
try:
return [
x.strip() for x in self.dm.getLogcat(filterSpecs=[
'GeckoToolbarDisplayLayout:*', 'SUTAgentAndroid:I',
'*:S'
])
]
except DMError:
self.loggerdeco.exception('Attempt %d get logcat throbbers' %
attempt)
if attempt == self.user_cfg[PHONE_RETRY_LIMIT] - 1:
raise
sleep(self.user_cfg[PHONE_RETRY_WAIT])
def analyze_logcat(self, build_metadata):
self.loggerdeco.debug('analyzing logcat')
app_name = build_metadata['androidprocname']
logcat_prefix = '(\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3})'
throbber_prefix = 'I/GeckoToolbarDisplayLayout.* zerdatime (\d+) - Throbber'
re_base_time = re.compile('%s' % logcat_prefix)
re_start_time = re.compile('%s I/SUTAgentAndroid.* '
'exec am start\s+.*-n %s/.App '
'-a android.intent.action.VIEW' %
(logcat_prefix, app_name))
re_throbber_start_time = re.compile('%s %s start' %
(logcat_prefix, throbber_prefix))
re_throbber_stop_time = re.compile('%s %s stop' %
(logcat_prefix, throbber_prefix))
self.loggerdeco.debug('analyze_logcat: re_base_time: %s' %
re_base_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_start_time: %s' %
re_start_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_throbber_start_time: %s' %
re_throbber_start_time.pattern)
self.loggerdeco.debug('analyze_logcat: re_throbber_stop_time: %s' %
re_throbber_stop_time.pattern)
base_time = 0
start_time = 0
throbber_start_time = 0
throbber_stop_time = 0
attempt = 0
max_time = 90 # maximum time to wait for throbbers
wait_time = 3 # time to wait between attempts
max_attempts = max_time / wait_time
while (attempt < max_attempts
and (throbber_start_time == 0 or throbber_stop_time == 0)):
buf = self.get_logcat_throbbers()
for line in buf:
self.loggerdeco.debug('analyze_logcat: %s' % line)
match = re_base_time.match(line)
if match and not base_time:
base_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: base_time: %s' %
base_time)
# we want the first throbberstart and throbberstop.
match = re_start_time.match(line)
if match:
start_time = match.group(1)
self.loggerdeco.debug('analyze_logcat: start_time: %s' %
start_time)
continue
match = re_throbber_start_time.match(line)
if match and not throbber_start_time:
throbber_start_time = match.group(1)
self.loggerdeco.debug(
'analyze_logcat: throbber_start_time: %s' %
throbber_start_time)
continue
match = re_throbber_stop_time.match(line)
if match and not throbber_stop_time:
throbber_stop_time = match.group(1)
self.loggerdeco.debug(
'analyze_logcat: throbber_stop_time: %s' %
throbber_stop_time)
continue
if throbber_start_time and throbber_stop_time:
break
if throbber_start_time == 0 or throbber_stop_time == 0:
sleep(wait_time)
attempt += 1
if self.check_for_crashes():
self.loggerdeco.info('fennec crashed')
fennec_crashed = True
else:
fennec_crashed = False
if throbber_start_time and throbber_stop_time == 0 and not fennec_crashed:
self.loggerdeco.info('Unable to find Throbber stop')
# The captured time from the logcat lines is in the format
# MM-DD HH:MM:SS.mmm. It is possible for the year to change
# between the different times, so we need to make adjustments
# if necessary. First, we assume the year does not change and
# parse the dates as if they are in the current year. If
# the dates violate the natural order start_time,
# throbber_start_time, throbber_stop_time, we can adjust the
# year.
if base_time and start_time and throbber_start_time and throbber_stop_time:
parse = lambda y, t: datetime.datetime.strptime(
'%4d-%s' % (y, t), '%Y-%m-%d %H:%M:%S.%f')
year = datetime.datetime.now().year
base_time = parse(year, base_time)
start_time = parse(year, start_time)
throbber_start_time = parse(year, throbber_start_time)
throbber_stop_time = parse(year, throbber_stop_time)
if base_time > start_time:
base_time.replace(year=year - 1)
elif start_time > throbber_start_time:
base_time.replace(year=year - 1)
start_time.replace(year=year - 1)
elif throbber_start_time > throbber_stop_time:
base_time.replace(year=year - 1)
start_time.replace(year=year - 1)
throbber_start_time.replace(year - 1)
# Convert the times to milliseconds from the base time.
convert = lambda t1, t2: round((t2 - t1).total_seconds() * 1000.0)
start_time = convert(base_time, start_time)
throbber_start_time = convert(base_time, throbber_start_time)
throbber_stop_time = convert(base_time, throbber_stop_time)
self.loggerdeco.debug(
'analyze_logcat: base: %s, start: %s, '
'throbber start: %s, throbber stop: %s, '
'throbber time: %s ' %
(base_time, start_time, throbber_start_time,
throbber_stop_time, throbber_stop_time - throbber_start_time))
else:
self.loggerdeco.warning(
'analyze_logcat: failed to get throbbers '
'start_time: %s, throbber start: %s, throbber stop: %s' %
(start_time, throbber_start_time, throbber_stop_time))
start_time = throbber_start_time = throbber_stop_time = 0
return (start_time, throbber_start_time, throbber_stop_time)
def publish_results(self,
starttime=0,
tstrt=0,
tstop=0,
build_metadata=None,
testname='',
cache_enabled=True,
rejected=False):
msg = (
'Cached: %s Start Time: %s Throbber Start: %s Throbber Stop: %s '
'Total Throbber Time: %s Rejected: %s' %
(cache_enabled, starttime, tstrt, tstop, tstop - tstrt, rejected))
self.loggerdeco.info('RESULTS: %s' % msg)
# Create JSON to send to webserver
resultdata = {}
resultdata['phoneid'] = self.phone_cfg['phoneid']
resultdata['testname'] = testname
resultdata['starttime'] = starttime
resultdata['throbberstart'] = tstrt
resultdata['throbberstop'] = tstop
resultdata['blddate'] = build_metadata['blddate']
resultdata['cached'] = cache_enabled
resultdata['rejected'] = rejected
resultdata['revision'] = build_metadata['revision']
resultdata['productname'] = build_metadata['androidprocname']
resultdata['productversion'] = build_metadata['version']
resultdata['osver'] = self.phone_cfg['osver']
resultdata['bldtype'] = build_metadata['bldtype']
resultdata['machineid'] = self.phone_cfg['machinetype']
result = {'data': resultdata}
# Upload
if self._signer:
encoded_result = jwt.encode(result, signer=self._signer)
content_type = 'application/jwt'
else:
encoded_result = json.dumps(result)
content_type = 'application/json; charset=utf-8'
req = urllib2.Request(self._resulturl + 'add/', encoded_result,
{'Content-Type': content_type})
try:
f = urllib2.urlopen(req)
except urllib2.URLError, e:
self.loggerdeco.error('Could not send results to server: %s' % e)
else:
class SmokeTest(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
try:
self.runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def runtest(self, build_metadata, worker_subprocess):
try:
os.unlink('smoketest_pass')
except OSError:
pass
try:
os.unlink('smoketest_fail')
except OSError:
pass
# Read our config file which gives us our number of
# iterations and urls that we will be testing
self.prepare_phone(build_metadata)
appname = build_metadata['androidprocname']
# Clear logcat
self.dm.recordLogcat()
# Run test
self.loggerdeco.debug('running fennec')
self.run_fennec_with_profile(appname, 'about:fennec')
self.loggerdeco.debug('analyzing logcat...')
fennec_launched = self.analyze_logcat(build_metadata)
start = datetime.datetime.now()
while (not fennec_launched and (datetime.datetime.now() - start <=
datetime.timedelta(seconds=60))):
sleep(3)
fennec_launched = self.analyze_logcat(build_metadata)
if fennec_launched:
self.loggerdeco.info('fennec successfully launched')
file('smoketest_pass', 'w')
else:
self.loggerdeco.error('failed to launch fennec')
file('smoketest_fail', 'w')
self.loggerdeco.debug('killing fennec')
# Get rid of the browser and session store files
self.dm.killProcess(build_metadata['androidprocname'])
self.loggerdeco.debug('removing sessionstore files')
self.remove_sessionstore_files()
def prepare_phone(self, build_metadata):
prefs = {
'browser.firstrun.show.localepicker': False,
'browser.sessionstore.resume_from_crash': False,
'browser.firstrun.show.uidiscovery': False,
'shell.checkDefaultClient': False,
'browser.warnOnQuit': False,
'browser.EULA.override': True,
'toolkit.telemetry.prompted': 999,
'toolkit.telemetry.notifiedOptOut': 999
}
profile = FirefoxProfile(preferences=prefs)
self.install_profile(profile)
def analyze_logcat(self, build_metadata):
buf = self.dm.getLogcat()
got_start = False
got_end = False
for line in buf:
if not got_start and 'Start proc org.mozilla.fennec' in line:
got_start = True
if not got_end and 'Throbber stop' in line:
got_end = True
return got_start and got_end
class SmokeTest(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
try:
self.runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def runtest(self, build_metadata, worker_subprocess):
try:
os.unlink('smoketest_pass')
except OSError:
pass
try:
os.unlink('smoketest_fail')
except OSError:
pass
# Read our config file which gives us our number of
# iterations and urls that we will be testing
self.prepare_phone(build_metadata)
appname = build_metadata['androidprocname']
# Clear logcat
self.dm.recordLogcat()
# Run test
self.loggerdeco.debug('running fennec')
self.run_fennec_with_profile(appname, 'about:fennec')
self.loggerdeco.debug('analyzing logcat...')
fennec_launched = self.analyze_logcat(build_metadata)
start = datetime.datetime.now()
while (not fennec_launched and (datetime.datetime.now() - start
<= datetime.timedelta(seconds=60))):
sleep(3)
fennec_launched = self.analyze_logcat(build_metadata)
if fennec_launched:
self.loggerdeco.info('fennec successfully launched')
file('smoketest_pass', 'w')
else:
self.loggerdeco.error('failed to launch fennec')
file('smoketest_fail', 'w')
self.loggerdeco.debug('killing fennec')
# Get rid of the browser and session store files
self.dm.killProcess(build_metadata['androidprocname'])
self.loggerdeco.debug('removing sessionstore files')
self.remove_sessionstore_files()
def prepare_phone(self, build_metadata):
prefs = { 'browser.firstrun.show.localepicker': False,
'browser.sessionstore.resume_from_crash': False,
'browser.firstrun.show.uidiscovery': False,
'shell.checkDefaultClient': False,
'browser.warnOnQuit': False,
'browser.EULA.override': True,
'toolkit.telemetry.prompted': 999,
'toolkit.telemetry.notifiedOptOut': 999 }
profile = FirefoxProfile(preferences=prefs)
self.install_profile(profile)
def analyze_logcat(self, build_metadata):
buf = self.dm.getLogcat()
got_start = False
got_end = False
for line in buf:
if not got_start and 'Start proc org.mozilla.fennec' in line:
got_start = True
if not got_end and 'Throbber stop' in line:
got_end = True
return got_start and got_end
class PhoneTest(object):
def __init__(self, phone, options, config_file=None,
enable_unittests=False, test_devices_repos={},
chunk=1):
self.config_file = config_file
self.cfg = ConfigParser.RawConfigParser()
self.cfg.read(self.config_file)
self.enable_unittests = enable_unittests
self.test_devices_repos = test_devices_repos
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.phone = phone
self.worker_subprocess = None
self.options = options
self.logger = logging.getLogger('autophone.phonetest')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'pid': os.getpid()},
'%(phoneid)s|%(pid)s|%(message)s')
self.logger_original = None
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self._dm = None
self._repos = None
self._log = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
def _check_device(self):
for attempt in range(1, self.options.phone_retry_limit+1):
output = self._dm.get_state()
if output == 'device':
break
self.loggerdeco.warning(
'PhoneTest:_check_device Attempt: %d: %s' %
(attempt, output))
time.sleep(self.options.phone_retry_wait)
if output != 'device':
raise ADBError('PhoneTest:_check_device: Failed')
@property
def name_suffix(self):
return '-%s' % self.chunk if self.chunk > 1 else ''
@property
def name(self):
return 'autophone-%s%s' % (self.__class__.__name__, self.name_suffix)
@property
def dm(self):
if not self._dm:
self.loggerdeco.info('PhoneTest: Connecting to %s...' % self.phone.id)
self._dm = ADBDevice(device=self.phone.serial,
logger_name='autophone.phonetest.adb',
device_ready_retry_wait=self.options.device_ready_retry_wait,
device_ready_retry_attempts=self.options.device_ready_retry_attempts,
verbose=self.options.verbose)
# Override mozlog.logger
self._dm._logger = self.loggerdeco
self.loggerdeco.info('PhoneTest: Connected.')
self._check_device()
return self._dm
@property
def base_device_path(self):
if self._base_device_path:
return self._base_device_path
success = False
e = None
for attempt in range(1, self.options.phone_retry_limit+1):
self._base_device_path = self.dm.test_root + '/autophone'
self.loggerdeco.debug('Attempt %d creating base device path %s' % (
attempt, self._base_device_path))
try:
if not self.dm.is_dir(self._base_device_path):
self.dm.mkdir(self._base_device_path, parents=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d creating base device '
'path %s' % (
attempt, self._base_device_path))
time.sleep(self.options.phone_retry_wait)
if not success:
raise e
self.loggerdeco.debug('base_device_path is %s' % self._base_device_path)
return self._base_device_path
@property
def job_name(self):
if not self.options.treeherder_url:
return None
if not self._job_name:
self._job_name = self.cfg.get('treeherder', 'job_name')
return self._job_name
@property
def job_symbol(self):
if not self.options.treeherder_url:
return None
if not self._job_symbol:
self._job_symbol = self.cfg.get('treeherder', 'job_symbol')
if self.chunks > 1:
self._job_symbol = "%s%s" %(self._job_symbol, self.chunk)
return self._job_symbol
@property
def group_name(self):
if not self.options.treeherder_url:
return None
if not self._group_name:
self._group_name = self.cfg.get('treeherder', 'group_name')
return self._group_name
@property
def group_symbol(self):
if not self.options.treeherder_url:
return None
if not self._group_symbol:
self._group_symbol = self.cfg.get('treeherder', 'group_symbol')
return self._group_symbol
@property
def build(self):
return self.worker_subprocess.build
@property
def buildername(self):
return "%s %s opt test %s-%s" % (
self.phone.platform, self.build.tree, self.job_name, self.job_symbol)
def handle_crashes(self):
if not self.crash_processor:
return
for error in self.crash_processor.get_errors(self.build.symbols,
self.options.minidump_stackwalk,
clean=False):
if error['reason'] == 'java-exception':
self.test_result.add_failure(self.name,
'PROCESS-CRASH',
error['signature'])
elif error['reason'] == 'PROFILE-ERROR':
self.test_result.add_failure(self.name,
error['reason'],
error['signature'])
elif error['reason'] == 'PROCESS-CRASH':
self.loggerdeco.info("PROCESS-CRASH | %s | "
"application crashed [%s]" % (self.name,
error['signature']))
self.loggerdeco.info(error['stackwalk_output'])
self.loggerdeco.info(error['stackwalk_errors'])
self.test_result.add_failure(self.name,
error['reason'],
'application crashed [%s]' % error['signature'])
else:
self.loggerdeco.warning('Unknown error reason: %s' % error['reason'])
def setup_job(self):
self.logger_original = self.logger
self.loggerdeco_original = self.loggerdeco
self.dm_logger_original = self.dm._logger
# Clear the log file if we are submitting logs to Treeherder.
if (self.worker_subprocess.options.treeherder_url and
self.worker_subprocess.build.revision_hash and
self.worker_subprocess.s3_bucket):
self.worker_subprocess.initialize_log_filehandler()
self.worker_subprocess.treeherder.submit_running(tests=[self])
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'pid': os.getpid(),
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(pid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self._log:
os.unlink(self._log)
self._log = None
self.upload_dir = tempfile.mkdtemp()
self.test_result = PhoneTestResult()
def run_job(self):
raise NotImplementedError
def teardown_job(self):
self.loggerdeco.debug('PhoneTest.teardown_job')
try:
self.handle_crashes()
self.worker_subprocess.treeherder.submit_complete(test=self)
finally:
if self.upload_dir and os.path.exists(self.upload_dir):
shutil.rmtree(self.upload_dir)
self.upload_dir = None
if self.logger.getEffectiveLevel() == logging.DEBUG and self._log:
self.loggerdeco.debug(40 * '=')
logfilehandle = open(self._log)
self.loggerdeco.debug(logfilehandle.read())
logfilehandle.close()
self.loggerdeco.debug(40 * '-')
self._log = None
self.logcat = Logcat(self)
if self.logger_original:
self.logger = self.logger_original
if self.loggerdeco_original:
self.loggerdeco = self.loggerdeco_original
if self.dm_logger_original:
self.dm._logger = self.dm_logger_original
def set_dm_debug(self, level):
self.options.debug = level
if self._dm:
self._dm.log_level = level
def update_status(self, phone_status=PhoneStatus.WORKING, message=None):
if self.update_status_cb:
self.update_status_cb(phone_status=phone_status,
build=self.build,
message=message)
def install_profile(self, profile=None):
if not profile:
profile = FirefoxProfile()
profile_path_parent = os.path.split(self.profile_path)[0]
success = False
for attempt in range(1, self.options.phone_retry_limit+1):
try:
self.loggerdeco.debug('Attempt %d installing profile' % attempt)
if self.dm.is_dir(self.profile_path, root=True):
self.dm.rm(self.profile_path, recursive=True, root=True)
self.dm.chmod(profile_path_parent, root=True)
self.dm.mkdir(self.profile_path, root=True)
self.dm.chmod(self.profile_path, root=True)
self.dm.push(profile.profile, self.profile_path)
self.dm.chmod(self.profile_path, recursive=True, root=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d Exception installing '
'profile to %s' % (
attempt, self.profile_path))
time.sleep(self.options.phone_retry_wait)
if not success:
self.loggerdeco.error('Failure installing profile to %s' % self.profile_path)
return success
def run_fennec_with_profile(self, appname, url):
self.loggerdeco.debug('run_fennec_with_profile: %s %s' % (appname, url))
try:
self.dm.pkill(appname, root=True)
self.dm.launch_fennec(appname,
intent="android.intent.action.VIEW",
moz_env={'MOZ_CRASHREPORTER_NO_REPORT': '1',
'MOZ_CRASHREPORTER': '1'},
extra_args=['--profile', self.profile_path],
url=url,
wait=False,
fail_if_running=False)
except:
self.loggerdeco.exception('run_fennec_with_profile: Exception:')
raise
def remove_sessionstore_files(self):
self.dm.rm(self.profile_path + '/sessionstore.js', force=True)
self.dm.rm(self.profile_path + '/sessionstore.bak', force=True)
@property
def fennec_crashed(self):
"""
Perform a quick check for crashes by checking
self.profile_path/minidumps for dump files.
"""
if self.dm.exists(os.path.join(self.profile_path, 'minidumps', '*.dmp')):
self.loggerdeco.info('fennec crashed')
return True
return False
class PhoneTest(object):
# Use instances keyed on phoneid+':'config_file+':'+str(chunk)
# to lookup tests.
instances = {}
@classmethod
def lookup(cls, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
if key in PhoneTest.instances:
return PhoneTest.instances[key]
return None
@classmethod
def match(cls, tests=None, test_name=None, phoneid=None,
config_file=None, chunk=None, job_guid=None,
build_url=None):
logger.debug('PhoneTest.match(tests: %s, test_name: %s, phoneid: %s, '
'config_file: %s, chunk: %s, job_guid: %s, '
'build_url: %s' % (tests, test_name, phoneid,
config_file, chunk, job_guid,
build_url))
matches = []
if not tests:
tests = [PhoneTest.instances[key] for key in PhoneTest.instances.keys()]
for test in tests:
if test_name and test_name != test.name:
continue
if phoneid and phoneid != test.phone.id:
continue
if config_file and config_file != test.config_file:
continue
if chunk and chunk != test.chunk:
continue
if job_guid and job_guid != test.job_guid:
continue
if build_url:
abi = test.phone.abi
sdk = test.phone.sdk
# First assume the test and build are compatible.
incompatible_job = False
# x86 devices can only test x86 builds and non-x86
# devices can not test x86 builds.
if abi == 'x86':
if 'x86' not in build_url:
incompatible_job = True
else:
if 'x86' in build_url:
incompatible_job = True
# If the build_url does not contain an sdk level, then
# assume this is an build from before the split sdk
# builds were first created. Otherwise the build_url
# must match this device's supported sdk levels.
if ('api-9' not in build_url and 'api-10' not in build_url and
'api-11' not in build_url):
pass
elif sdk not in build_url:
incompatible_job = True
if incompatible_job:
continue
# The test may be defined for multiple repositories.
# We are interested if this particular build is
# supported by this test. First assume it is
# incompatible, and only accept it if the build_url is
# from one of the supported repositories.
if test.repos:
incompatible_job = True
for repo in test.repos:
if repo in build_url:
incompatible_job = False
break
if incompatible_job:
continue
matches.append(test)
logger.debug('PhoneTest.match = %s' % matches)
return matches
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id},
'%(phoneid)s|%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self.repos = repos
self._log = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
self.loggerdeco.info('PhoneTest: Connected.')
def __str__(self):
return '%s(%s, config_file=%s, chunk=%s)' % (type(self).__name__,
self.phone,
self.config_file,
self.chunk)
def __repr__(self):
return self.__str__()
def _add_instance(self, phoneid, config_file, chunk):
key = '%s:%s:%s' % (phoneid, config_file, chunk)
assert key not in PhoneTest.instances, 'Duplicate PhoneTest %s' % key
PhoneTest.instances[key] = self
def remove(self):
key = '%s:%s:%s' % (self.phone.id, self.config_file, self.chunk)
if key in PhoneTest.instances:
del PhoneTest.instances[key]
def _check_device(self):
for attempt in range(1, self.options.phone_retry_limit+1):
output = self.dm.get_state()
if output == 'device':
break
self.loggerdeco.warning(
'PhoneTest:_check_device Attempt: %d: %s' %
(attempt, output))
time.sleep(self.options.phone_retry_wait)
if output != 'device':
raise ADBError('PhoneTest:_check_device: Failed')
@property
def name_suffix(self):
return '-%s' % self.chunk if self.chunks > 1 else ''
@property
def name(self):
return 'autophone-%s%s' % (self.__class__.__name__, self.name_suffix)
@property
def base_device_path(self):
if self._base_device_path:
return self._base_device_path
success = False
e = None
for attempt in range(1, self.options.phone_retry_limit+1):
self._base_device_path = self.dm.test_root + '/autophone'
self.loggerdeco.debug('Attempt %d creating base device path %s' % (
attempt, self._base_device_path))
try:
if not self.dm.is_dir(self._base_device_path):
self.dm.mkdir(self._base_device_path, parents=True)
success = True
break
except ADBError:
self.loggerdeco.exception('Attempt %d creating base device '
'path %s' % (
attempt, self._base_device_path))
time.sleep(self.options.phone_retry_wait)
if not success:
raise e
self.loggerdeco.debug('base_device_path is %s' % self._base_device_path)
return self._base_device_path
@property
def job_name(self):
if not self.options.treeherder_url:
return None
if not self._job_name:
self._job_name = self.cfg.get('treeherder', 'job_name')
return self._job_name
@property
def job_symbol(self):
if not self.options.treeherder_url:
return None
if not self._job_symbol:
self._job_symbol = self.cfg.get('treeherder', 'job_symbol')
if self.chunks > 1:
self._job_symbol = "%s%s" %(self._job_symbol, self.chunk)
return self._job_symbol
@property
def group_name(self):
if not self.options.treeherder_url:
return None
if not self._group_name:
self._group_name = self.cfg.get('treeherder', 'group_name')
return self._group_name
@property
def group_symbol(self):
if not self.options.treeherder_url:
return None
if not self._group_symbol:
self._group_symbol = self.cfg.get('treeherder', 'group_symbol')
return self._group_symbol
@property
def build(self):
return self.worker_subprocess.build
def generate_guid(self):
self.job_guid = utils.generate_guid()
def get_buildername(self, tree):
return "%s %s opt %s" % (
self.phone.platform, tree, self.name)
def handle_test_interrupt(self, reason):
self.test_failure(self.name, 'TEST-UNEXPECTED-FAIL', reason,
PhoneTestResult.USERCANCEL)
def test_pass(self, testpath):
self.test_result.add_pass(testpath)
def test_failure(self, testpath, status, message, testresult_status):
self.message = message
self.update_status(message=message)
self.test_result.add_failure(testpath, status, message, testresult_status)
def handle_crashes(self):
if not self.crash_processor:
return
for error in self.crash_processor.get_errors(self.build.symbols,
self.options.minidump_stackwalk,
clean=False):
if error['reason'] == 'java-exception':
self.test_failure(
self.name, 'PROCESS-CRASH',
error['signature'],
PhoneTestResult.EXCEPTION)
elif error['reason'] == 'PROFILE-ERROR':
self.test_failure(
self.name,
error['reason'],
error['signature'],
PhoneTestResult.TESTFAILED)
elif error['reason'] == 'PROCESS-CRASH':
self.loggerdeco.info("PROCESS-CRASH | %s | "
"application crashed [%s]" % (self.name,
error['signature']))
self.loggerdeco.info(error['stackwalk_output'])
self.loggerdeco.info(error['stackwalk_errors'])
self.test_failure(self.name,
error['reason'],
'application crashed [%s]' % error['signature'],
PhoneTestResult.TESTFAILED)
else:
self.loggerdeco.warning('Unknown error reason: %s' % error['reason'])
def setup_job(self):
self.start_time = datetime.datetime.now()
self.stop_time = self.start_time
# Clear the Treeherder job details.
self.job_details = []
self.worker_subprocess.treeherder.submit_running(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
self.loggerdeco_original = self.loggerdeco
# self.dm._logger can raise ADBTimeoutError due to the
# property dm therefore place it after the initialization.
self.dm_logger_original = self.dm._logger
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'test': self.name},
'%(phoneid)s|%(buildid)s|%(test)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.debug('PhoneTest.setup_job')
if self._log:
os.unlink(self._log)
self._log = None
self.upload_dir = tempfile.mkdtemp()
self.test_result = PhoneTestResult()
if not self.worker_subprocess.is_disabled():
self.update_status(phone_status=PhoneStatus.WORKING,
message='Setting up %s' % self.name)
def run_job(self):
raise NotImplementedError
def teardown_job(self):
self.loggerdeco.debug('PhoneTest.teardown_job')
self.stop_time = datetime.datetime.now()
self.loggerdeco.info('Test %s elapsed time: %s' % (
self.name, self.stop_time - self.start_time))
try:
self.handle_crashes()
except Exception, e:
self.test_failure(
self.name, 'TEST-UNEXPECTED-FAIL',
'Exception %s during crash processing' % e,
PhoneTestResult.EXCEPTION)
try:
if (self.worker_subprocess.is_disabled() and
self.test_result.status != PhoneTestResult.USERCANCEL):
# The worker was disabled while running one test of a job.
# Record the cancellation on any remaining tests in that job.
self.test_failure(self.name, 'TEST_UNEXPECTED_FAIL',
'The worker was disabled.',
PhoneTestResult.USERCANCEL)
self.worker_subprocess.treeherder.submit_complete(
self.phone.id,
self.build.url,
self.build.tree,
self.build.revision_hash,
tests=[self])
except:
self.loggerdeco.exception('Exception tearing down job')
finally:
if self.upload_dir and os.path.exists(self.upload_dir):
shutil.rmtree(self.upload_dir)
self.upload_dir = None
if (logger.getEffectiveLevel() == logging.DEBUG and self._log and
os.path.exists(self._log)):
self.loggerdeco.debug(40 * '=')
try:
logfilehandle = open(self._log)
self.loggerdeco.debug(logfilehandle.read())
logfilehandle.close()
except Exception:
self.loggerdeco.exception('Exception %s loading log')
self.loggerdeco.debug(40 * '-')
# Reset the tests' volatile members in order to prevent them
# from being reused after a test has completed.
self.test_result = PhoneTestResult()
self.message = None
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.upload_dir = None
self.start_time = None
self.stop_time = None
self._log = None
self.logcat = Logcat(self)
if self.loggerdeco_original:
self.loggerdeco = self.loggerdeco_original
if self.dm_logger_original:
self.dm._logger = self.dm_logger_original
class PhoneWorkerSubProcess(object):
"""Worker subprocess.
FIXME: Would be nice to have test results uploaded outside of the
test objects, and to have them queued (and cached) if the results
server is unavailable for some reason. Might be best to communicate
this back to the main AutoPhone process.
"""
def __init__(self, worker_num, ipaddr, tests, phone_cfg, user_cfg,
autophone_queue, cmd_queue, logfile_prefix, loglevel, mailer,
build_cache_port):
self.worker_num = worker_num
self.ipaddr = ipaddr
self.tests = tests
self.phone_cfg = phone_cfg
self.user_cfg = user_cfg
self.autophone_queue = autophone_queue
self.cmd_queue = cmd_queue
self.logfile = logfile_prefix + '.log'
self.outfile = logfile_prefix + '.out'
self.loglevel = loglevel
self.mailer = mailer
self.build_cache_port = build_cache_port
self._stop = False
self.p = None
self.jobs = jobs.Jobs(self.mailer, self.phone_cfg['phoneid'])
self.current_build = None
self.last_ping = None
self._dm = None
self.status = None
self.logger = logging.getLogger('autophone.worker.subprocess')
self.loggerdeco = LogDecorator(self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip']
}, '%(phoneid)s|%(phoneip)s|%(message)s')
@property
def dm(self):
if not self._dm:
self.loggerdeco.info(
'Connecting to %s:%d...' %
(self.phone_cfg['ip'], self.phone_cfg['sutcmdport']))
# Droids and other slow phones can take a while to come back
# after a SUT crash or spontaneous reboot, so we up the
# default retrylimit.
self._dm = DroidSUT(
self.phone_cfg['ip'],
self.phone_cfg['sutcmdport'],
retryLimit=self.user_cfg[DEVICEMANAGER_RETRY_LIMIT],
logLevel=self.loglevel)
# Give slow devices chance to mount all devices.
# Give slow devices chance to mount all devices.
if self.user_cfg[DEVICEMANAGER_SETTLING_TIME] is not None:
self._dm.reboot_settling_time = self.user_cfg[
DEVICEMANAGER_SETTLING_TIME]
# Override mozlog.logger
self._dm._logger = self.loggerdeco
self.loggerdeco.info('Connected.')
return self._dm
def is_alive(self):
"""Call from main process."""
return self.p and self.p.is_alive()
def start(self, status):
"""Call from main process."""
if self.p:
if self.is_alive():
return
del self.p
self.status = status
self.p = multiprocessing.Process(target=self.run)
self.p.start()
def stop(self):
"""Call from main process."""
if self.is_alive():
self.cmd_queue.put_nowait(('stop', None))
self.p.join(self.user_cfg[PHONE_COMMAND_QUEUE_TIMEOUT] * 2)
def has_error(self):
return (self.status == phonetest.PhoneTestMessage.DISABLED
or self.status == phonetest.PhoneTestMessage.DISCONNECTED)
def disconnect_dm(self):
self._dm = None
def status_update(self, msg):
self.status = msg.status
self.loggerdeco.info(str(msg))
try:
self.autophone_queue.put_nowait(msg)
except Queue.Full:
self.loggerdeco.warning('Autophone queue is full!')
def check_sdcard(self):
self.loggerdeco.info('Checking SD card.')
success = True
try:
dev_root = self.dm.getDeviceRoot()
if dev_root:
d = posixpath.join(dev_root, 'autophonetest')
self.dm.removeDir(d)
self.dm.mkDir(d)
if self.dm.dirExists(d):
with tempfile.NamedTemporaryFile() as tmp:
tmp.write('autophone test\n')
tmp.flush()
self.dm.pushFile(tmp.name,
posixpath.join(d, 'sdcard_check'))
self.dm.removeDir(d)
else:
self.loggerdeco.error('Failed to create directory under '
'device root!')
success = False
else:
self.loggerdeco.error('Invalid device root.')
success = False
except DMError:
self.loggerdeco.exception('Exception while checking SD card!')
success = False
if not success:
# FIXME: Should this be called under more circumstances than just
# checking the SD card?
self.clear_test_base_paths()
return False
# reset status if there had previous been an error.
# FIXME: should send email that phone is back up.
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.IDLE))
return True
def clear_test_base_paths(self):
for t in self.tests:
t._base_device_path = ''
def recover_phone(self):
exc = None
reboots = 0
while reboots < self.user_cfg[PHONE_MAX_REBOOTS]:
self.loggerdeco.info('Rebooting phone...')
reboots += 1
# FIXME: reboot() no longer indicates success/failure; instead
# we just verify the device root.
try:
self.dm.reboot(ipAddr=self.ipaddr, wait=True)
if self.dm.getDeviceRoot():
self.loggerdeco.info('Phone is back up.')
if self.check_sdcard():
return
self.loggerdeco.info('Failed SD card check.')
else:
self.loggerdeco.info('Phone did not reboot successfully.')
except DMError:
self.loggerdeco.exception('Exception while checking SD card!')
# DM can be in a weird state if reboot failed.
self.disconnect_dm()
self.loggerdeco.info('Phone has been rebooted %d times; giving up.' %
reboots)
msg_body = 'Phone was rebooted %d times.' % reboots
if exc:
msg_body += '\n\n%s' % exc
self.phone_disconnected(msg_body)
def reboot(self):
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.REBOOTING))
self.recover_phone()
def phone_disconnected(self, msg_body):
"""Indicate that a phone has become unreachable or experienced a
error from which we might be able to recover."""
if self.has_error():
return
self.loggerdeco.info('Phone disconnected: %s.' % msg_body)
if msg_body and self.mailer:
self.loggerdeco.info('Sending notification...')
try:
self.mailer.send(
'Phone %s disconnected' % self.phone_cfg['phoneid'],
'''Hello, this is Autophone. Phone %s appears to be disconnected:
%s
I'll keep trying to ping it periodically in case it reappears.
''' % (self.phone_cfg['phoneid'], msg_body))
self.loggerdeco.info('Sent.')
except socket.error:
self.loggerdeco.exception('Failed to send disconnected-phone '
'notification.')
self.status_update(
phonetest.PhoneTestMessage(
self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.DISCONNECTED))
def disable_phone(self, errmsg, send_email=True):
"""Completely disable phone. No further attempts to recover it will
be performed unless initiated by the user."""
self.loggerdeco.info('Disabling phone: %s.' % errmsg)
if errmsg and send_email and self.mailer:
self.loggerdeco.info('Sending notification...')
try:
self.mailer.send(
'Phone %s disabled' % self.phone_cfg['phoneid'],
'''Hello, this is Autophone. Phone %s has been disabled:
%s
I gave up on it. Sorry about that. You can manually re-enable it with
the "enable" command.
''' % (self.phone_cfg['phoneid'], errmsg))
self.loggerdeco.info('Sent.')
except socket.error:
self.loggerdeco.exception('Failed to send disabled-phone '
'notification.')
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.DISABLED,
msg=errmsg))
def ping(self):
self.loggerdeco.info('Pinging phone')
# Verify that the phone is still responding.
# It should always be possible to get the device root, so use this
# command to ensure that the device is still reachable.
try:
if self.dm.getDeviceRoot():
self.loggerdeco.info('Pong!')
return True
except DMError:
self.loggerdeco.exception('Exception while pinging:')
self.loggerdeco.error('Got empty device root!')
return False
def run_tests(self, build_metadata):
if not self.has_error():
self.loggerdeco.info('Rebooting...')
self.reboot()
# may have gotten an error trying to reboot, so test again
if self.has_error():
self.loggerdeco.info('Phone is in error state; not running test.')
return False
repo = build_metadata['tree']
build_date = datetime.datetime.fromtimestamp(
float(build_metadata['blddate']))
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.INSTALLING,
build_metadata['blddate']))
self.loggerdeco.info('Installing build %s.' % build_date)
success = False
for attempt in range(self.user_cfg[PHONE_RETRY_LIMIT]):
try:
pathOnDevice = posixpath.join(self.dm.getDeviceRoot(),
'build.apk')
self.dm.pushFile(
os.path.join(build_metadata['cache_build_dir'],
'build.apk'), pathOnDevice)
self.dm.installApp(pathOnDevice)
self.dm.removeFile(pathOnDevice)
success = True
except DMError:
exc = 'Exception installing fennec attempt %d!\n\n%s' % (
attempt, traceback.format_exc())
self.loggerdeco.exception(
'Exception installing fennec attempt %d!' % attempt)
time.sleep(self.user_cfg[PHONE_RETRY_WAIT])
if not success:
self.phone_disconnected(exc)
return False
self.current_build = build_metadata['blddate']
self.loggerdeco.info('Running tests...')
for t in self.tests:
if self.has_error():
break
try:
repos = t.test_devices_repos[self.phone_cfg['phoneid']]
if repos and repo not in repos:
self.loggerdeco.debug('run_tests: ignoring build %s '
'repo %s not in '
'defined repos: %s' %
(build_date, repo, repos))
continue
except KeyError:
pass
t.current_build = build_metadata['blddate']
try:
t.runjob(build_metadata, self)
except DMError:
exc = 'Uncaught device error while running test!\n\n%s' % \
traceback.format_exc()
self.loggerdeco.exception('Uncaught device error while '
'running test!')
self.phone_disconnected(exc)
return False
return True
def handle_timeout(self):
if (self.status != phonetest.PhoneTestMessage.DISABLED and
(not self.last_ping or
(datetime.datetime.now() - self.last_ping > datetime.timedelta(
seconds=self.user_cfg[PHONE_PING_INTERVAL])))):
self.last_ping = datetime.datetime.now()
if self.ping():
if self.status == phonetest.PhoneTestMessage.DISCONNECTED:
self.recover_phone()
if not self.has_error():
self.status_update(
phonetest.PhoneTestMessage(
self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.IDLE,
self.current_build))
else:
self.loggerdeco.info('Ping unanswered.')
# No point in trying to recover, since we couldn't
# even perform a simple action.
if not self.has_error():
self.phone_disconnected('No response to ping.')
def handle_job(self, job):
phoneid = self.phone_cfg['phoneid']
abi = self.phone_cfg['abi']
build_url = job['build_url']
self.loggerdeco.debug('handle_job: job: %s, abi: %s' % (job, abi))
incompatible_job = False
if abi == 'x86':
if 'x86' not in build_url:
incompatible_job = True
elif abi == 'armeabi-v6':
if 'armv6' not in build_url:
incompatible_job = True
else:
if 'x86' in build_url or 'armv6' in build_url:
incompatible_job = True
if incompatible_job:
self.loggerdeco.debug('Ignoring incompatible job %s '
'for phone abi %s' % (build_url, abi))
self.jobs.job_completed(job['id'])
return
# Determine if we will test this build and if we need
# to enable unittests.
skip_build = True
enable_unittests = False
for test in self.tests:
test_devices_repos = test.test_devices_repos
if not test_devices_repos:
# We know we will test this build, but not yet
# if any of the other tests enable_unittests.
skip_build = False
elif not phoneid in test_devices_repos:
# This device will not run this test.
pass
else:
for repo in test_devices_repos[phoneid]:
if repo in build_url:
skip_build = False
enable_unittests = test.enable_unittests
break
if not skip_build:
break
if skip_build:
self.loggerdeco.debug('Ignoring job %s ' % build_url)
self.jobs.job_completed(job['id'])
return
self.loggerdeco.info('Checking job %s.' % build_url)
client = buildserver.BuildCacheClient(port=self.build_cache_port)
self.loggerdeco.info('Fetching build...')
cache_response = client.get(build_url,
enable_unittests=enable_unittests)
client.close()
if not cache_response['success']:
self.loggerdeco.warning('Errors occured getting build %s: %s' %
(build_url, cache_response['error']))
return
self.loggerdeco.info('Starting job %s.' % build_url)
starttime = datetime.datetime.now()
if self.run_tests(cache_response['metadata']):
self.loggerdeco.info('Job completed.')
self.jobs.job_completed(job['id'])
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.IDLE,
self.current_build))
else:
self.loggerdeco.error('Job failed.')
stoptime = datetime.datetime.now()
self.loggerdeco.info('Job elapsed time: %s' % (stoptime - starttime))
def handle_cmd(self, request):
if not request:
self.loggerdeco.debug('handle_cmd: No request')
pass
elif request[0] == 'stop':
self.loggerdeco.info('Stopping at user\'s request...')
self._stop = True
elif request[0] == 'job':
# This is just a notification that breaks us from waiting on the
# command queue; it's not essential, since jobs are stored in
# a db, but it allows the worker to react quickly to a request if
# it isn't doing anything else.
self.loggerdeco.debug('Received job command request...')
pass
elif request[0] == 'reboot':
self.loggerdeco.info('Rebooting at user\'s request...')
self.reboot()
elif request[0] == 'disable':
self.disable_phone('Disabled at user\'s request', False)
elif request[0] == 'enable':
self.loggerdeco.info('Enabling phone at user\'s request...')
if self.has_error():
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'],
phonetest.PhoneTestMessage.IDLE,
self.current_build))
self.last_ping = None
elif request[0] == 'debug':
self.loggerdeco.info(
'Setting debug level %d at user\'s request...' % request[1])
self.user_cfg['debug'] = request[1]
DroidSUT.debug = self.user_cfg['debug']
# update any existing DroidSUT objects
if self._dm:
self._dm.loglevel = self.user_cfg['debug']
for t in self.tests:
t.set_dm_debug(self.user_cfg['debug'])
elif request[0] == 'ping':
self.loggerdeco.info('Pinging at user\'s request...')
self.ping()
else:
self.loggerdeco.debug('handle_cmd: Unknown request %s' %
request[0])
def main_loop(self):
# Commands take higher priority than jobs, so we deal with all
# immediately available commands, then start the next job, if there is
# one. If neither a job nor a command is currently available,
# block on the command queue for PhoneWorker.PHONE_COMMAND_QUEUE_TIMEOUT seconds.
request = None
while True:
try:
if not request:
request = self.cmd_queue.get_nowait()
self.handle_cmd(request)
request = None
if self._stop:
return
except Queue.Empty:
request = None
if self.has_error():
self.recover_phone()
if not self.has_error():
job = self.jobs.get_next_job()
if job:
self.handle_job(job)
else:
try:
request = self.cmd_queue.get(
timeout=self.
user_cfg[PHONE_COMMAND_QUEUE_TIMEOUT])
except Queue.Empty:
request = None
self.handle_timeout()
def run(self):
sys.stdout = file(self.outfile, 'a', 0)
sys.stderr = sys.stdout
self.filehandler = MultiprocessingTimedRotatingFileHandler(
self.logfile, when='midnight', backupCount=7)
fileformatstring = ('%(asctime)s|%(levelname)s' '|%(message)s')
self.fileformatter = logging.Formatter(fileformatstring)
self.filehandler.setFormatter(self.fileformatter)
self.logger.addHandler(self.filehandler)
self.loggerdeco.info('PhoneWorker starting up.')
DroidSUT.loglevel = self.user_cfg.get('debug', 3)
for t in self.tests:
t.status_cb = self.status_update
self.status_update(
phonetest.PhoneTestMessage(self.phone_cfg['phoneid'], self.status))
if self.status != phonetest.PhoneTestMessage.DISABLED:
if not self.check_sdcard():
self.recover_phone()
if self.has_error():
self.loggerdeco.error('Initial SD card check failed.')
self.main_loop()
def runtest(self, test_parameters):
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': test_parameters['buildid'],
'testname': test_parameters['test_name']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in test_parameters.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, test_parameters[key]))
self.set_status(msg='Starting test %s' % test_parameters['test_name'])
test_parameters['harness_type'] = test_parameters['test_name']
if test_parameters['test_name'] == 'robocoptest':
test_parameters['harness_type'] = 'mochitest'
robocop_apk_path = posixpath.join(self.dm.getDeviceRoot(),
'robocop.apk')
# XXX: FIXME. When bug 792072 lands, change to have
# installApp() push the file
self.dm.pushFile(
os.path.join(test_parameters['cache_build_dir'],
'robocop.apk'), robocop_apk_path)
try:
self.dm.uninstallApp('org.mozilla.roboexample.test')
except DMError:
self.loggerdeco.exception(
'runtestsremote.py:runtest: Exception running test.')
self.dm.installApp(robocop_apk_path)
self.dm.removeFile(robocop_apk_path)
test_parameters['port_manager'] = PortManager(
test_parameters['host_ip_address'])
for this_chunk in range(1, test_parameters['total_chunks'] + 1):
test_parameters['this_chunk'] = this_chunk
try:
while True:
socket_collision = False
logfilehandle = tempfile.NamedTemporaryFile(delete=False)
self.loggerdeco.debug('logging to %s' % logfilehandle.name)
args = self.create_test_args(test_parameters)
test_parameters['cmdline'] = ' '.join(args)
self.loggerdeco.debug("cmdline = %s" %
test_parameters['cmdline'])
self.set_status(msg='Running test %s chunk %d of %d' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks']))
if self.dm.processExist(
test_parameters['androidprocname']):
max_kill_attempts = 3
for kill_attempt in range(max_kill_attempts):
self.loggerdeco.debug(
'Process %s exists. Attempt %d to kill.' %
(test_parameters['androidprocname'],
kill_attempt + 1))
self.dm.killProcess(
test_parameters['androidprocname'])
if not self.dm.processExist(
test_parameters['androidprocname']):
break
if kill_attempt == max_kill_attempts - 1 and \
self.dm.processExist(test_parameters['androidprocname']):
self.loggerdeco.warning(
'Could not kill process %s.' %
(test_parameters['androidprocname']))
proc = subprocess.Popen(
args,
cwd=os.path.join(test_parameters['cache_build_dir'],
'tests'),
preexec_fn=lambda: os.setpgid(0, 0),
stdout=logfilehandle,
stderr=subprocess.STDOUT,
close_fds=True)
proc.wait()
self.loggerdeco.debug('runtestsremote.py return code %d' %
proc.returncode)
logfilehandle.close()
reSocketError = re.compile('socket\.error:')
logfilehandle = open(logfilehandle.name)
for logline in logfilehandle:
if reSocketError.search(logline):
socket_collision = True
break
logfilehandle.close()
if not socket_collision:
break
self.set_status(msg='Completed test %s chunk %d of %d' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks']))
except:
error_message = (
'Exception during test %s chunk %d of %d: %s' %
(test_parameters['test_name'], this_chunk,
test_parameters['total_chunks'], traceback.format_exc()))
self.set_status(msg=error_message)
self.loggerdeco.error(error_message)
finally:
logfilehandle.close()
self.process_test_log(test_parameters, logfilehandle)
if self.logger.getEffectiveLevel() == logging.DEBUG:
logfilehandle = open(logfilehandle.name)
self.loggerdeco.debug(40 * '*')
self.loggerdeco.debug(logfilehandle.read())
self.loggerdeco.debug(40 * '-')
logfilehandle.close()
os.unlink(logfilehandle.name)
# wait for a minute to give the phone time to settle
time.sleep(60)
# Recover the phone in between tests/chunks.
self.loggerdeco.info('Rebooting device after test.')
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runtest exit')
return
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(
self.logger, {
'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']
}, '%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
try:
# Read our config file which gives us our number of
# iterations and urls that we will be testing
cfg = ConfigParser.RawConfigParser()
cfg.read(self.config_file)
# [signature]
self._signer = None
self._jwt = {'id': '', 'key': None}
for opt in self._jwt.keys():
try:
self._jwt[opt] = cfg.get('signature', opt)
except (ConfigParser.NoSectionError,
ConfigParser.NoOptionError):
break
# phonedash requires both an id and a key.
if self._jwt['id'] and self._jwt['key']:
self._signer = jwt.jws.HmacSha(key=self._jwt['key'],
key_id=self._jwt['id'])
# [paths]
autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['source'] = os.path.join(autophone_directory, 'files/')
self._paths['dest'] = posixpath.join(self.base_device_path,
's1test/')
self._paths['remote'] = 'http://phonedash.mozilla.org/'
try:
for opt in ('source', 'dest', 'profile', 'remote'):
try:
self._paths[opt] = cfg.get('paths', opt)
if not self._paths[opt].endswith('/'):
self._paths[opt] += '/'
except ConfigParser.NoOptionError:
pass
except ConfigParser.NoSectionError:
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for push in glob.glob(self._paths['source'] + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'],
os.path.basename(push))
self._pushes[push] = push_dest
# [tests]
self._tests = {}
for t in cfg.items('tests'):
self._tests[t[0]] = t[1]
# Map URLS - {urlname: url} - urlname serves as testname
self._urls = {}
for test_location in ('local', 'remote'):
for test_name in self._tests:
if test_location == 'local':
test_url = 'file://' + self._paths[
'dest'] + self._tests[test_name]
else:
test_url = self._paths['remote'] + self._tests[
test_name]
self._urls["%s-%s" % (test_location, test_name)] = test_url
# [settings]
self._iterations = cfg.getint('settings', 'iterations')
try:
self.stderrp_accept = cfg.getfloat('settings',
'stderrp_accept')
except ConfigParser.NoOptionError:
self.stderrp_accept = 0
try:
self.stderrp_reject = cfg.getfloat('settings',
'stderrp_reject')
except ConfigParser.NoOptionError:
self.stderrp_reject = 100
try:
self.stderrp_attempts = cfg.getint('settings',
'stderrp_attempts')
except ConfigParser.NoOptionError:
self.stderrp_attempts = 1
self._resulturl = cfg.get('settings', 'resulturl')
if not self._resulturl.endswith('/'):
self._resulturl += '/'
self._initialize_url = 'file://' + self._paths[
'dest'] + 'initialize_profile.html'
self.runtests(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
self.dm._logger = loggerdeco
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# The PhoneTest constructor may raise exceptions due to issues with
# the device. Creators of PhoneTest objects are responsible
# for catching these exceptions and cleaning up any previously
# created tests for the device.
#
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
# The default preferences and environment for running fennec
# are set here in PhoneTest. Tests which subclass PhoneTest can
# add or override these preferences during their
# initialization.
self._preferences = None
self._environment = None
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
# Make the values in the config file case-sensitive
self.cfg.optionxform = str
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
logger = utils.getLogger(name=self.phone.id)
self.loggerdeco = LogDecorator(logger,
{},
'%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
# Test result
self.status = TreeherderStatus.SUCCESS
self.passed = 0
self.failed = 0
self.todo = 0
self.repos = repos
self.unittest_logpath = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
# Perform initial configuration. For tests which do not
# specify all config options, reasonable defaults will be
# chosen.
# [paths]
# base_device_path accesses the device to determine the
# appropriate path and can therefore fail and raise an
# exception which will not be caught in the PhoneTest
# constructor. Creators of PhoneTest objects are responsible
# for catching these exceptions and cleaning up any previously
# created tests for the device.
self._base_device_path = ''
self.profile_path = '/data/local/tests/autophone/profile'
if self.dm:
self.profile_path = '%s/profile' % self.base_device_path
self.autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
try:
sources = self.cfg.get('paths', 'sources').split()
self._paths['sources'] = []
for source in sources:
if not source.endswith('/'):
source += '/'
self._paths['sources'].append(source)
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['sources'] = ['files/base/']
try:
self._paths['dest'] = self.cfg.get('paths', 'dest')
if not self._paths['dest'].endswith('/'):
self._paths['dest'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['dest'] = os.path.join(self.base_device_path,
self.__class__.__name__)
try:
self._paths['profile'] = self.cfg.get('paths', 'profile')
if not self._paths['profile'].endswith('/'):
self._paths['profile'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
self.run_if_changed = set()
try:
dirs = self.cfg.get('runtests', 'run_if_changed')
self.run_if_changed = set([d.strip() for d in dirs.split(',')])
if self.run_if_changed:
PhoneTest.has_run_if_changed = True
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for source in self._paths['sources']:
for push in glob.glob(source + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_file_name = os.path.basename(push)
push_dest = posixpath.join(self._paths['dest'],
source,
push_file_name)
self._pushes[push] = push_dest
if push_file_name == 'initialize_profile.html':
self._initialize_url = 'file://' + push_dest
# [tests]
self._tests = {}
try:
for t in self.cfg.items('tests'):
self._tests[t[0]] = t[1]
except ConfigParser.NoSectionError:
self._tests['blank'] = 'blank.html'
# [builds]
self.buildtypes = []
try:
self.buildtypes = self.cfg.get('builds', 'buildtypes').split(' ')
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self.buildtypes = list(self.options.buildtypes)
self.platforms = []
try:
self.platforms = self.cfg.get('builds', 'platforms').split(' ')
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self.platforms = self.options.platforms
self.loggerdeco.info('PhoneTest: %s', self.__dict__)
class UnitTest(PhoneTest):
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
try:
self.setup_and_runtest(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
def setup_and_runtest(self, build_metadata, worker_subprocess):
self.loggerdeco.debug('runtestsremote.py runjob start')
self.set_status(msg='runtestsremote.py runjob start')
self.worker_subprocess = worker_subprocess
self.worker_subprocess.check_sdcard()
host_ip_address = self.phone_cfg['ipaddr']
phone_ip_address = self.phone_cfg['ip']
device_port = self.phone_cfg['sutcmdport']
cache_build_dir = os.path.abspath(build_metadata["cache_build_dir"])
symbols_path = os.path.join(cache_build_dir, 'symbols')
if not os.path.exists(symbols_path):
symbols_path = None
androidprocname = build_metadata['androidprocname']
re_revision = re.compile(r'http.*/rev/(.*)')
match = re_revision.match(build_metadata['revision'])
if match:
revision = match.group(1)
else:
revision = build_metadata['revision']
buildid = build_metadata['buildid']
tree = build_metadata['tree']
if self.logger.getEffectiveLevel() == logging.DEBUG:
for prop in self.phone_cfg:
self.loggerdeco.debug('phone_cfg[%s] = %s' %
(prop, self.phone_cfg[prop]))
job_cfg = ConfigParser.RawConfigParser()
job_cfg.read(self.config_file)
if job_cfg.has_option('runtests', 'config_files'):
# job contains multiple unittests
config_files = job_cfg.get('runtests', 'config_files').split(' ')
elif job_cfg.has_option('runtests', 'test_name'):
# job contains a single unittest
config_files = [self.config_file]
else:
raise Exception('Job configuration %s does not specify a test' %
self.config_file)
missing_config_files = []
for config_file in config_files:
if not os.path.exists(config_file):
missing_config_files.append(config_file)
if missing_config_files:
raise Exception("Can not run tests with missing config files: %s" %
', '.join(missing_config_files))
for config_file in config_files:
try:
test_parameters = {
'host_ip_address': host_ip_address,
'phone_ip_address': phone_ip_address,
'device_port': device_port,
'androidprocname': androidprocname,
'cache_build_dir': cache_build_dir,
'symbols_path': symbols_path,
'revision': revision,
'buildid': buildid,
'tree': tree,
'config_file': config_file,
}
self.load_test_parameters(test_parameters, config_file)
self.runtest(test_parameters)
except:
# This exception handler deals with exceptions which occur outside
# of the actual test runner. Exceptions from the test runner
# are handled locally in runtest.
self.loggerdeco.exception('runtestsremote.py:runjob: Exception '
'running test')
self.set_status(msg='runtestsremote.py:runjob: Exception '
'running test')
# give the phone a minute to recover
time.sleep(60)
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runjob exit')
self.set_status(msg='runtestsremote.py runjob exit')
def load_test_parameters(self, test_parameters, config_file):
cfg = ConfigParser.RawConfigParser()
cfg.read(config_file)
test_parameters['test_name'] = cfg.get('runtests', 'test_name')
test_parameters['test_manifest'] = cfg.get('runtests', 'test_manifest')
try:
test_parameters['test_path'] = cfg.get('runtests', 'test_path')
except ConfigParser.NoOptionError:
test_parameters['test_path'] = None
unittest_config_file = cfg.get('runtests', 'unittest_defaults')
cfg.read(unittest_config_file)
self.loggerdeco.info('config_file = %s, unittest_config_file = %s' %
(config_file, unittest_config_file))
test_parameters['xre_path'] = cfg.get('runtests', 'xre_path')
test_parameters['utility_path'] = cfg.get('runtests', 'utility_path')
if test_parameters['symbols_path'] is not None and cfg.has_option('runtests',
'minidump_stackwalk'):
test_parameters['minidump_stackwalk'] = cfg.get('runtests', 'minidump_stackwalk')
os.environ['MINIDUMP_STACKWALK'] = test_parameters['minidump_stackwalk']
elif 'MINIDUMP_STACKWALK' in os.environ:
del os.environ['MINIDUMP_STACKWALK']
if cfg.has_option('runtests', 'androidprocname'):
test_parameters['androidprocname'] = cfg.get('runtests', 'androidprocname')
test_parameters['console_level'] = cfg.get('runtests', 'console_level')
test_parameters['file_level'] = cfg.get('runtests', 'file_level')
test_parameters['time_out'] = cfg.getint('runtests', 'time_out')
if cfg.has_option('runtests', 'iterations'):
test_parameters['iterations'] = cfg.getint('runtests', 'iterations')
else:
test_parameters['iterations'] = 1
if cfg.has_option('runtests', 'total_chunks'):
test_parameters['total_chunks'] = cfg.getint('runtests', 'total_chunks')
else:
test_parameters['total_chunks'] = 1
if cfg.has_option('runtests', 'prefs'):
test_parameters['prefs'] = cfg.get('runtests', 'prefs').split(',')
else:
test_parameters['prefs'] = []
test_parameters['es_server'] = cfg.get('autolog', 'es_server')
test_parameters['rest_server'] = cfg.get('autolog', 'rest_server')
test_parameters['index'] = cfg.get('autolog', 'index')
test_parameters['include_pass'] = cfg.getboolean('autolog', 'include_pass')
test_parameters['submit_log'] = cfg.getboolean('autolog', 'submit_log')
test_parameters['use_newparser'] = cfg.getboolean('autolog', 'use_newparser')
def create_test_args(self, test_parameters):
args = ['python']
test_name_lower = test_parameters['test_name'].lower()
if test_name_lower.startswith('robocoptest'):
test_args = [
'mochitest/runtestsremote.py',
'--robocop=%s' % test_parameters['test_manifest'],
'--robocop-ids=%s/fennec_ids.txt' % test_parameters['cache_build_dir'],
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % test_parameters['console_level'],
'--file-level=%s' % test_parameters['file_level'],
'--repeat=%d' % test_parameters['iterations'],
]
elif test_name_lower.startswith('mochitest'):
test_args = [
'mochitest/runtestsremote.py',
'--test-manifest=%s' % test_parameters['test_manifest'],
'--test-path=%s' % test_parameters['test_path'],
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % test_parameters['console_level'],
'--file-level=%s' % test_parameters['file_level'],
'--repeat=%d' % test_parameters['iterations'],
]
elif test_name_lower.startswith('reftest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'%s' % test_parameters['test_manifest'],
]
elif test_name_lower.startswith('jsreftest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'--extra-profile-file=jsreftest/tests/user.js',
'%s' % test_parameters['test_manifest'],
]
elif test_name_lower.startswith('crashtest'):
test_args = [
'reftest/remotereftest.py',
'--enable-privilege',
'--ignore-window-size',
'--bootstrap',
'%s' % test_parameters['test_manifest'],
]
else:
self.loggerdeco.error('Unknown test_name %s' % test_parameters['test_name'])
raise Exception('Unknown test_name %s' % test_parameters['test_name'])
test_parameters['http_port'] = test_parameters['port_manager'].reserve()
test_parameters['ssl_port'] = test_parameters['port_manager'].reserve()
common_args = [
'--deviceIP=%s' % test_parameters['phone_ip_address'],
'--devicePort=%s' % test_parameters['device_port'],
'--app=%s' % test_parameters['androidprocname'],
'--xre-path=%s' % test_parameters['xre_path'],
'--utility-path=%s' % test_parameters['utility_path'],
'--timeout=%d' % test_parameters['time_out'],
'--http-port=%s' % test_parameters['port_manager'].use(test_parameters['http_port']),
'--ssl-port=%s' % test_parameters['port_manager'].use(test_parameters['ssl_port']),
'--total-chunks=%d' % test_parameters['total_chunks'],
'--this-chunk=%d' % test_parameters['this_chunk'],
'--log-file=%s-%s.log' % (test_parameters['test_name'], test_parameters['phone_ip_address']),
'--pidfile=%s-%s.pid' % (test_parameters['test_name'], test_parameters['phone_ip_address']),
]
for pref in test_parameters['prefs']:
common_args.append('--setpref=%s' % pref)
args.extend(test_args)
args.extend(common_args)
if test_parameters['symbols_path'] is not None:
args.append('--symbols-path=%s' % test_parameters['symbols_path'])
return args
def process_test_log(self, test_parameters, logfilehandle):
test_log = None
test_runs = []
if test_parameters['use_newparser']:
logfilehandle.close()
logfilehandle = open(logfilehandle.name)
try:
# Turn off verbose logging for the log parser
logger = logging.getLogger('logparser')
logger_effectiveLevel = logger.getEffectiveLevel()
logger.setLevel(logging.WARN)
test_log = newlogparser.parse_log(logfilehandle)
test_runs = test_log.convert(test_parameters['include_pass'])
finally:
logger.setLevel(logger_effectiveLevel)
logfilehandle.close()
else:
lp = LogParser([logfilehandle.name],
es=False,
es_server=None,
includePass=True,
output_dir=None,
logger=self.logger,
harnessType=test_parameters['harness_type'])
# Use logparser's parsers, but do not allow it to
# submit data directly to elasticsearch.
test_runs.append(lp.parseFiles())
if test_parameters['es_server'] is None or test_parameters['rest_server'] is None:
return
# testgroup must match entry in autolog/js/Config.js:testNames
# os must match entry in autolog/js/Config.js:OSNames
# platform must match entry in autolog/js/Config.js:OSNames
logfilename = None
if test_parameters['submit_log']:
logfilename = logfilehandle.name
chunk_descriptor = ''
if test_parameters['total_chunks'] > 1:
chunk_descriptor = 's-%d' % test_parameters['this_chunk']
testgroup_name = '%s%s' % (test_parameters['test_name'],
chunk_descriptor)
platform_name = self.phone_cfg['machinetype']
self.loggerdeco.debug('testgroup_name = %s' % testgroup_name)
testgroup = RESTfulAutologTestGroup(
index=test_parameters['index'],
testgroup=testgroup_name,
os='android',
platform=platform_name,
harness=test_parameters['harness_type'],
server=test_parameters['es_server'],
restserver=test_parameters['rest_server'],
machine=self.phone_cfg['phoneid'],
logfile=logfilename)
testgroup.set_primary_product(
tree=test_parameters['tree'],
buildtype='opt',
buildid=test_parameters['buildid'],
revision=test_parameters['revision'])
for testdata in test_runs:
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('Begin testdata')
self.loggerdeco.debug(json.dumps(testdata, indent=4))
self.loggerdeco.debug('End testdata')
testgroup.add_test_suite(
testsuite=testgroup_name,
cmdline=test_parameters['cmdline'],
passed=testdata.get('passed', None),
failed=testdata.get('failed', None),
todo=testdata.get('todo', None))
for t in testdata.get('failures', {}):
test = t["test"]
for f in t["failures"]:
text = f["text"]
status = f["status"]
testgroup.add_test_failure(test=test,
text=text,
status=status)
# Submitting passing tests not supported via REST API
if test_parameters['include_pass']:
for t in testdata.get('passes', {}):
test = t["test"]
duration = None
if "duration" in t:
duration = t["duration"]
testgroup.add_test_pass(test=test,
duration=duration)
testgroup.submit()
def runtest(self, test_parameters):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': test_parameters['buildid'],
'testname': test_parameters['test_name']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in test_parameters.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, test_parameters[key]))
self.set_status(msg='Starting test %s' % test_parameters['test_name'])
test_parameters['harness_type'] = test_parameters['test_name']
if test_parameters['test_name'] == 'robocoptest':
test_parameters['harness_type'] = 'mochitest'
robocop_apk_path = posixpath.join(self.dm.getDeviceRoot(), 'robocop.apk')
# XXX: FIXME. When bug 792072 lands, change to have
# installApp() push the file
self.dm.pushFile(os.path.join(test_parameters['cache_build_dir'],
'robocop.apk'),
robocop_apk_path)
try:
self.dm.uninstallApp('org.mozilla.roboexample.test')
except DMError:
self.loggerdeco.exception('runtestsremote.py:runtest: Exception running test.')
self.dm.installApp(robocop_apk_path)
self.dm.removeFile(robocop_apk_path)
test_parameters['port_manager'] = PortManager(test_parameters['host_ip_address'])
for this_chunk in range(1, test_parameters['total_chunks'] + 1):
test_parameters['this_chunk'] = this_chunk
try:
while True:
socket_collision = False
logfilehandle = tempfile.NamedTemporaryFile(delete=False)
self.loggerdeco.debug('logging to %s' % logfilehandle.name)
args = self.create_test_args(test_parameters)
test_parameters['cmdline'] = ' '.join(args)
self.loggerdeco.debug("cmdline = %s" %
test_parameters['cmdline'])
self.set_status(msg='Running test %s chunk %d of %d' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks']))
if self.dm.processExist(test_parameters['androidprocname']):
max_kill_attempts = 3
for kill_attempt in range(max_kill_attempts):
self.loggerdeco.debug(
'Process %s exists. Attempt %d to kill.' % (
test_parameters['androidprocname'], kill_attempt + 1))
self.dm.killProcess(test_parameters['androidprocname'])
if not self.dm.processExist(test_parameters['androidprocname']):
break
if kill_attempt == max_kill_attempts - 1 and \
self.dm.processExist(test_parameters['androidprocname']):
self.loggerdeco.warning(
'Could not kill process %s.' % (
test_parameters['androidprocname']))
proc = subprocess.Popen(
args,
cwd=os.path.join(test_parameters['cache_build_dir'],
'tests'),
preexec_fn=lambda: os.setpgid(0, 0),
stdout=logfilehandle,
stderr=subprocess.STDOUT,
close_fds=True
)
proc.wait()
self.loggerdeco.debug('runtestsremote.py return code %d' %
proc.returncode)
logfilehandle.close()
reSocketError = re.compile('socket\.error:')
logfilehandle = open(logfilehandle.name)
for logline in logfilehandle:
if reSocketError.search(logline):
socket_collision = True
break
logfilehandle.close()
if not socket_collision:
break
self.set_status(msg='Completed test %s chunk %d of %d' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks']))
except:
error_message = ('Exception during test %s chunk %d of %d: %s' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks'],
traceback.format_exc()))
self.set_status(msg=error_message)
self.loggerdeco.error(error_message)
finally:
logfilehandle.close()
self.process_test_log(test_parameters, logfilehandle)
if self.logger.getEffectiveLevel() == logging.DEBUG:
logfilehandle = open(logfilehandle.name)
self.loggerdeco.debug(40 * '*')
self.loggerdeco.debug(logfilehandle.read())
self.loggerdeco.debug(40 * '-')
logfilehandle.close()
os.unlink(logfilehandle.name)
# wait for a minute to give the phone time to settle
time.sleep(60)
# Recover the phone in between tests/chunks.
self.loggerdeco.info('Rebooting device after test.')
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runtest exit')
return
def __init__(self, dm=None, phone=None, options=None, config_file=None, chunk=1, repos=[]):
# Ensure that repos is a list and that it is sorted in order
# for comparisons with the tests loaded from the jobs database
# to work.
assert type(repos) == list, 'PhoneTest repos argument must be a list'
repos.sort()
self._add_instance(phone.id, config_file, chunk)
# The default preferences and environment for running fennec
# are set here in PhoneTest. Tests which subclass PhoneTest can
# add or override these preferences during their
# initialization.
self._preferences = None
self._environment = None
self.config_file = config_file
self.cfg = ConfigParser.ConfigParser()
# Make the values in the config file case-sensitive
self.cfg.optionxform = str
self.cfg.read(self.config_file)
self.enable_unittests = False
self.chunk = chunk
self.chunks = 1
self.update_status_cb = None
self.dm = dm
self.phone = phone
self.worker_subprocess = None
self.options = options
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id},
'%(phoneid)s|%(message)s')
self.loggerdeco_original = None
self.dm_logger_original = None
self.loggerdeco.info('init autophone.phonetest')
# test_logfilehandler is used by running tests to save log
# messages to a separate file which can be reset at the
# beginning of each test independently of the worker's log.
self.test_logfilehandler = None
self._base_device_path = ''
self.profile_path = '/data/local/tmp/profile'
self.repos = repos
self.test_logfile = None
self.unittest_logpath = None
# Treeherder related items.
self._job_name = None
self._job_symbol = None
self._group_name = None
self._group_symbol = None
self.test_result = PhoneTestResult()
self.message = None
# A unique consistent guid is necessary for identifying the
# test job in treeherder. The test job_guid is updated when a
# test is added to the pending jobs/tests in the jobs
# database.
self.job_guid = None
self.job_details = []
self.submit_timestamp = None
self.start_timestamp = None
self.end_timestamp = None
self.logcat = Logcat(self, self.loggerdeco)
self.loggerdeco.debug('PhoneTest: %s, cfg sections: %s' % (self.__dict__, self.cfg.sections()))
if not self.cfg.sections():
self.loggerdeco.warning('Test configuration not found. '
'Will use defaults.')
# upload_dir will hold ANR traces, tombstones and other files
# pulled from the device.
self.upload_dir = None
# crash_processor is an instance of AutophoneCrashProcessor that
# is used by non-unittests to process device errors and crashes.
self.crash_processor = None
# Instrument running time
self.start_time = None
self.stop_time = None
# Perform initial configuration. For tests which do not
# specify all config options, reasonable defaults will be
# chosen.
# [paths]
self.autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['dest'] = posixpath.join(self.base_device_path,
self.__class__.__name__)
try:
sources = self.cfg.get('paths', 'sources').split()
self._paths['sources'] = []
for source in sources:
if not source.endswith('/'):
source += '/'
self._paths['sources'].append(source)
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
self._paths['sources'] = [
os.path.join(self.autophone_directory, 'files/base/')]
try:
self._paths['dest'] = self.cfg.get('paths', 'dest')
if not self._paths['dest'].endswith('/'):
self._paths['dest'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
try:
self._paths['profile'] = self.cfg.get('paths', 'profile')
if not self._paths['profile'].endswith('/'):
self._paths['profile'] += '/'
except (ConfigParser.NoSectionError, ConfigParser.NoOptionError):
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for source in self._paths['sources']:
for push in glob.glob(source + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'],
os.path.basename(push))
self._pushes[push] = push_dest
self._initialize_url = os.path.join('file://', self._paths['dest'],
'initialize_profile.html')
# [tests]
self._tests = {}
try:
for t in self.cfg.items('tests'):
self._tests[t[0]] = t[1]
except ConfigParser.NoSectionError:
self._tests['blank'] = 'blank.html'
self.loggerdeco.info('PhoneTest: Connected.')
def runtest(self, test_parameters):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': test_parameters['buildid'],
'testname': test_parameters['test_name']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in test_parameters.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, test_parameters[key]))
self.set_status(msg='Starting test %s' % test_parameters['test_name'])
test_parameters['harness_type'] = test_parameters['test_name']
if test_parameters['test_name'] == 'robocoptest':
test_parameters['harness_type'] = 'mochitest'
robocop_apk_path = posixpath.join(self.dm.getDeviceRoot(), 'robocop.apk')
# XXX: FIXME. When bug 792072 lands, change to have
# installApp() push the file
self.dm.pushFile(os.path.join(test_parameters['cache_build_dir'],
'robocop.apk'),
robocop_apk_path)
try:
self.dm.uninstallApp('org.mozilla.roboexample.test')
except DMError:
self.loggerdeco.exception('runtestsremote.py:runtest: Exception running test.')
self.dm.installApp(robocop_apk_path)
self.dm.removeFile(robocop_apk_path)
test_parameters['port_manager'] = PortManager(test_parameters['host_ip_address'])
for this_chunk in range(1, test_parameters['total_chunks'] + 1):
test_parameters['this_chunk'] = this_chunk
try:
while True:
socket_collision = False
logfilehandle = tempfile.NamedTemporaryFile(delete=False)
self.loggerdeco.debug('logging to %s' % logfilehandle.name)
args = self.create_test_args(test_parameters)
test_parameters['cmdline'] = ' '.join(args)
self.loggerdeco.debug("cmdline = %s" %
test_parameters['cmdline'])
self.set_status(msg='Running test %s chunk %d of %d' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks']))
if self.dm.processExist(test_parameters['androidprocname']):
max_kill_attempts = 3
for kill_attempt in range(max_kill_attempts):
self.loggerdeco.debug(
'Process %s exists. Attempt %d to kill.' % (
test_parameters['androidprocname'], kill_attempt + 1))
self.dm.killProcess(test_parameters['androidprocname'])
if not self.dm.processExist(test_parameters['androidprocname']):
break
if kill_attempt == max_kill_attempts - 1 and \
self.dm.processExist(test_parameters['androidprocname']):
self.loggerdeco.warning(
'Could not kill process %s.' % (
test_parameters['androidprocname']))
proc = subprocess.Popen(
args,
cwd=os.path.join(test_parameters['cache_build_dir'],
'tests'),
preexec_fn=lambda: os.setpgid(0, 0),
stdout=logfilehandle,
stderr=subprocess.STDOUT,
close_fds=True
)
proc.wait()
self.loggerdeco.debug('runtestsremote.py return code %d' %
proc.returncode)
logfilehandle.close()
reSocketError = re.compile('socket\.error:')
logfilehandle = open(logfilehandle.name)
for logline in logfilehandle:
if reSocketError.search(logline):
socket_collision = True
break
logfilehandle.close()
if not socket_collision:
break
self.set_status(msg='Completed test %s chunk %d of %d' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks']))
except:
error_message = ('Exception during test %s chunk %d of %d: %s' %
(test_parameters['test_name'],
this_chunk, test_parameters['total_chunks'],
traceback.format_exc()))
self.set_status(msg=error_message)
self.loggerdeco.error(error_message)
finally:
logfilehandle.close()
self.process_test_log(test_parameters, logfilehandle)
if self.logger.getEffectiveLevel() == logging.DEBUG:
logfilehandle = open(logfilehandle.name)
self.loggerdeco.debug(40 * '*')
self.loggerdeco.debug(logfilehandle.read())
self.loggerdeco.debug(40 * '-')
logfilehandle.close()
os.unlink(logfilehandle.name)
# wait for a minute to give the phone time to settle
time.sleep(60)
# Recover the phone in between tests/chunks.
self.loggerdeco.info('Rebooting device after test.')
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py runtest exit')
return
def runtests(self, build_metadata, worker_subprocess):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
appname = build_metadata['androidprocname']
if not self.install_local_pages():
self.set_status(msg='Could not install local pages on phone. '
'Aborting test for '
'build %s' % build_metadata['buildid'])
return
if not self.create_profile(build_metadata):
self.set_status(msg='Could not run Fennec. Aborting test for '
'build %s' % build_metadata['buildid'])
return
testcount = len(self._urls.keys())
for testnum,(testname,url) in enumerate(self._urls.iteritems(), 1):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid'],
'testname': testname},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
if self.check_results(build_metadata, testname):
# We already have good results for this test and build.
# No need to test it again.
self.loggerdeco.info('Skipping test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
continue
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
for attempt in range(self.stderrp_attempts):
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(self._iterations):
self.set_status(msg='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt+1, self.stderrp_attempts,
testnum, testcount, iteration+1, url))
dataset.append({})
if not self.create_profile(build_metadata):
continue
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['uncached'] = measurement
measurement = self.runtest(build_metadata, appname, url)
if not measurement:
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration+1, self._iterations))
break
self.loggerdeco.debug('publishing results')
if self.is_stderr_below_threshold(dataset, self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration+1, self._iterations))
for datapoint in dataset:
for cachekey in datapoint:
self.publish_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
build_metadata=build_metadata,
testname=testname,
cache_enabled=(cachekey=='cached'),
rejected=rejected)
if not rejected:
break
def run_job(self):
if not self.install_local_pages():
self.test_failure(
self.name, 'TEST_UNEXPECTED_FAIL',
'Aborting test - Could not install local pages on phone.',
PhoneTestResult.EXCEPTION)
return
if not self.create_profile():
self.test_failure(
self.name, 'TEST_UNEXPECTED_FAIL',
'Aborting test - Could not run Fennec.',
PhoneTestResult.BUSTED)
return
testcount = len(self._urls.keys())
for testnum,(testname,url) in enumerate(self._urls.iteritems(), 1):
if self.fennec_crashed:
break
self.loggerdeco = LogDecorator(logger,
{'phoneid': self.phone.id,
'buildid': self.build.id,
'testname': testname},
'%(phoneid)s|%(buildid)s|'
'%(testname)s|%(message)s')
self.dm._logger = self.loggerdeco
self.loggerdeco.info('Running test (%d/%d) for %d iterations' %
(testnum, testcount, self._iterations))
# success == False indicates that none of the attempts
# were successful in getting any measurement. This is
# typically due to a regression in the brower which should
# be reported.
success = False
command = None
for attempt in range(1, self.stderrp_attempts+1):
if self.fennec_crashed:
break
# dataset is a list of the measurements made for the
# iterations for this test.
#
# An empty item in the dataset list represents a
# failure to obtain any measurement for that
# iteration.
#
# It is possible for an item in the dataset to have an
# uncached value and not have a corresponding cached
# value if the cached test failed to record the
# values.
dataset = []
for iteration in range(1, self._iterations+1):
command = self.worker_subprocess.process_autophone_cmd(self)
if command['interrupt']:
self.handle_test_interrupt(command['reason'])
break
if self.fennec_crashed:
break
self.update_status(message='Attempt %d/%d for Test %d/%d, '
'run %d, for url %s' %
(attempt, self.stderrp_attempts,
testnum, testcount, iteration, url))
dataset.append({})
if not self.create_profile():
self.test_failure(url,
'TEST_UNEXPECTED_FAIL',
'Failed to create profile',
PhoneTestResult.TESTFAILED)
continue
measurement = self.runtest(url)
if measurement:
self.test_pass(url)
else:
self.test_failure(
url,
'TEST_UNEXPECTED_FAIL',
'Failed to get uncached measurement.',
PhoneTestResult.TESTFAILED)
continue
dataset[-1]['uncached'] = measurement
success = True
measurement = self.runtest(url)
if measurement:
self.test_pass(url)
else:
self.test_failure(
url,
'TEST_UNEXPECTED_FAIL',
'Failed to get cached measurement.',
PhoneTestResult.TESTFAILED)
continue
dataset[-1]['cached'] = measurement
if self.is_stderr_below_threshold(
('throbberstart',
'throbberstop'),
dataset,
self.stderrp_accept):
self.loggerdeco.info(
'Accepted test (%d/%d) after %d of %d iterations' %
(testnum, testcount, iteration, self._iterations))
break
if command and command['interrupt']:
break
if not success:
# If we have not gotten a single measurement at this point,
# just bail and report the failure rather than wasting time
# continuing more attempts.
self.loggerdeco.info(
'Failed to get measurements for test %s after %d/%d attempt '
'of %d iterations' % (testname, attempt,
self.stderrp_attempts,
self._iterations))
self.worker_subprocess.mailer.send(
'S1S2Test %s failed for Build %s %s on Phone %s' %
(testname, self.build.tree, self.build.id,
self.phone.id),
'No measurements were detected for test %s.\n\n'
'Repository: %s\n'
'Build Id: %s\n'
'Revision: %s\n' %
(testname, self.build.tree, self.build.id, self.build.revision))
self.test_failure(self.name, 'TEST_UNEXPECTED_FAIL',
'No measurements detected.',
PhoneTestResult.BUSTED)
break
if self.is_stderr_below_threshold(
('throbberstart',
'throbberstop'),
dataset,
self.stderrp_reject):
rejected = False
else:
rejected = True
self.loggerdeco.info(
'Rejected test (%d/%d) after %d/%d iterations' %
(testnum, testcount, iteration, self._iterations))
self.loggerdeco.debug('publishing results')
for datapoint in dataset:
for cachekey in datapoint:
self.report_results(
starttime=datapoint[cachekey]['starttime'],
tstrt=datapoint[cachekey]['throbberstart'],
tstop=datapoint[cachekey]['throbberstop'],
testname=testname,
cache_enabled=(cachekey=='cached'),
rejected=rejected)
if not rejected:
break
if command and command['interrupt']:
break
elif not success:
break
def runjob(self, build_metadata, worker_subprocess):
logger = self.logger
loggerdeco = self.loggerdeco
self.logger = logging.getLogger('autophone.worker.subprocess.test')
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone_cfg['phoneid'],
'phoneip': self.phone_cfg['ip'],
'buildid': build_metadata['buildid']},
'%(phoneid)s|%(phoneip)s|%(buildid)s|'
'%(message)s')
self.dm._logger = self.loggerdeco
try:
# Read our config file which gives us our number of
# iterations and urls that we will be testing
cfg = ConfigParser.RawConfigParser()
cfg.read(self.config_file)
# [signature]
self._signer = None
self._jwt = {'id': '', 'key': None}
for opt in self._jwt.keys():
try:
self._jwt[opt] = cfg.get('signature', opt)
except (ConfigParser.NoSectionError,
ConfigParser.NoOptionError):
break
# phonedash requires both an id and a key.
if self._jwt['id'] and self._jwt['key']:
self._signer = jwt.jws.HmacSha(key=self._jwt['key'],
key_id=self._jwt['id'])
# [paths]
autophone_directory = os.path.dirname(os.path.abspath(sys.argv[0]))
self._paths = {}
self._paths['source'] = os.path.join(autophone_directory, 'files/')
self._paths['dest'] = posixpath.join(self.base_device_path, 's1test/')
self._paths['remote'] = 'http://phonedash.mozilla.org/'
try:
for opt in ('source', 'dest', 'profile', 'remote'):
try:
self._paths[opt] = cfg.get('paths', opt)
if not self._paths[opt].endswith('/'):
self._paths[opt] += '/'
except ConfigParser.NoOptionError:
pass
except ConfigParser.NoSectionError:
pass
if 'profile' in self._paths:
self.profile_path = self._paths['profile']
# _pushes = {'sourcepath' : 'destpath', ...}
self._pushes = {}
for push in glob.glob(self._paths['source'] + '*'):
if push.endswith('~') or push.endswith('.bak'):
continue
push_dest = posixpath.join(self._paths['dest'], os.path.basename(push))
self._pushes[push] = push_dest
# [tests]
self._tests = {}
for t in cfg.items('tests'):
self._tests[t[0]] = t[1]
# Map URLS - {urlname: url} - urlname serves as testname
self._urls = {}
for test_location in ('local', 'remote'):
for test_name in self._tests:
if test_location == 'local':
test_url = 'file://' + self._paths['dest'] + self._tests[test_name]
else:
test_url = self._paths['remote'] + self._tests[test_name]
self._urls["%s-%s" % (test_location, test_name)] = test_url
# [settings]
self._iterations = cfg.getint('settings', 'iterations')
try:
self.stderrp_accept = cfg.getfloat('settings', 'stderrp_accept')
except ConfigParser.NoOptionError:
self.stderrp_accept = 0
try:
self.stderrp_reject = cfg.getfloat('settings', 'stderrp_reject')
except ConfigParser.NoOptionError:
self.stderrp_reject = 100
try:
self.stderrp_attempts = cfg.getint('settings', 'stderrp_attempts')
except ConfigParser.NoOptionError:
self.stderrp_attempts = 1
self._resulturl = cfg.get('settings', 'resulturl')
if not self._resulturl.endswith('/'):
self._resulturl += '/'
self._initialize_url = 'file://' + self._paths['dest'] + 'initialize_profile.html'
self.runtests(build_metadata, worker_subprocess)
finally:
self.logger = logger
self.loggerdeco = loggerdeco
self.dm._logger = loggerdeco
class UnitTest(PhoneTest):
def __init__(self, phone, options, config_file=None,
enable_unittests=False, test_devices_repos={},
chunk=1):
PhoneTest.__init__(self, phone, options,
config_file=config_file,
enable_unittests=enable_unittests,
test_devices_repos=test_devices_repos,
chunk=chunk)
self.unittest_cfg = ConfigParser.RawConfigParser()
unittest_config_file = self.cfg.get('runtests', 'unittest_defaults')
self.unittest_cfg.read(unittest_config_file)
self.loggerdeco.info('config_file = %s, unittest_config_file = %s' %
(config_file, unittest_config_file))
# Mochitests in particular are broken when run via adb. We must
# use the SUTAgent and will need the phone's ip address.
phone_ip_address = None
for attempt in range(1, self.options.phone_retry_limit+1):
phone_ip_address = self.dm.get_ip_address()
self.loggerdeco.debug(
'UnitTest: get phone ip address Attempt: %d: %s' %
(attempt, phone_ip_address))
if phone_ip_address:
break
time.sleep(self.options.phone_retry_wait)
if not phone_ip_address:
raise Exception('UnitTest: Failed to get phone %s ip address' % self.phone.id)
self.parms = {
'host_ip_address': self.phone.host_ip,
'phone_ip_address': phone_ip_address,
'phoneid': self.phone.id,
'config_file': config_file,
'test_name': self.cfg.get('runtests', 'test_name'),
'test_manifest': self.cfg.get('runtests', 'test_manifest'),
}
self.parms['xre_path'] = self.unittest_cfg.get('runtests', 'xre_path')
self.parms['utility_path'] = self.unittest_cfg.get('runtests', 'utility_path')
if self.unittest_cfg.has_option('runtests', 'include_pass'):
self.parms['include_pass'] = self.unittest_cfg.getboolean('runtests', 'include_pass')
else:
self.parms['include_pass'] = False
if self.cfg.has_option('runtests', 'app_name'):
self.parms['app_name'] = self.cfg.get('runtests', 'app_name')
self.parms['console_level'] = self.unittest_cfg.get('runtests', 'console_level')
self.parms['log_level'] = self.unittest_cfg.get('runtests', 'log_level')
self.parms['time_out'] = self.unittest_cfg.getint('runtests', 'time_out')
if self.cfg.has_option('runtests', 'iterations'):
self.parms['iterations'] = self.cfg.getint('runtests', 'iterations')
else:
self.parms['iterations'] = 1
if self.cfg.has_option('runtests', 'total_chunks'):
self.chunks = self.cfg.getint('runtests', 'total_chunks')
if self.cfg.has_option('runtests', 'prefs'):
self.parms['prefs'] = self.cfg.get('runtests', 'prefs').split(',')
else:
self.parms['prefs'] = []
@property
def name(self):
return 'autophone-%s%s' % (self.parms['test_name'], self.name_suffix)
def setup_job(self):
PhoneTest.setup_job(self)
build_dir = self.build.dir
symbols_path = self.build.symbols
if symbols_path and not os.path.exists(symbols_path):
symbols_path = None
re_revision = re.compile(r'http.*/rev/(.*)')
match = re_revision.match(self.build.revision)
if match:
revision = match.group(1)
else:
revision = self.build.revision
self.parms['app_name'] = self.build.app_name
self.parms['build_dir'] = build_dir
self.parms['symbols_path'] = symbols_path
self.parms['revision'] = revision
self.parms['buildid'] = self.build.id
self.parms['tree'] = self.build.tree
self._log = '%s/tests/%s-%s-%s.log' % (build_dir,
self.parms['test_name'],
self.chunk,
self.parms['phoneid'])
os.putenv('MINIDUMP_STACKWALK', self.options.minidump_stackwalk)
os.putenv('MINIDUMP_SAVE_PATH', self.upload_dir)
os.putenv('MOZ_UPLOAD_DIR', self.upload_dir)
def teardown_job(self):
os.unsetenv('MINIDUMP_STACKWALK')
os.unsetenv('MINIDUMP_SAVE_PATH')
os.unsetenv('MOZ_UPLOAD_DIR')
PhoneTest.teardown_job(self)
def run_job(self):
self.loggerdeco.debug('runtestsremote.py run_job start')
self.update_status(message='runtestsremote.py run_job start')
self.worker_subprocess.check_sdcard()
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('phone = %s' % self.phone)
if not self.cfg.has_option('runtests', 'test_name'):
raise Exception('Job configuration %s does not specify a test' %
self.config_file)
try:
self.runtest()
except:
# This exception handler deals with exceptions which occur outside
# of the actual test runner. Exceptions from the test runner
# are handled locally in runtest.
self.loggerdeco.exception('runtestsremote.py:run_job: Exception '
'running test')
self.update_status(message='runtestsremote.py:run_job: Exception '
'running test')
# give the phone a minute to recover
time.sleep(60)
self.worker_subprocess.recover_phone()
self.loggerdeco.debug('runtestsremote.py run_job exit')
self.update_status(message='runtestsremote.py run_job exit')
def create_test_args(self):
args = ['python', '-u']
test_name_lower = self.parms['test_name'].lower()
if test_name_lower.startswith('robocoptest'):
self.parms['harness_type'] = 'mochitest'
test_args = [
'mochitest/runtestsremote.py',
'--robocop=%s' % self.parms['test_manifest'],
'--robocop-ids=%s/fennec_ids.txt' % self.parms['build_dir'],
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % self.parms['console_level'],
'--log-raw=%s' % 'raw-log-' + os.path.basename(self._log),
]
elif test_name_lower.startswith('mochitest'):
self.parms['harness_type'] = 'mochitest'
test_args = [
'mochitest/runtestsremote.py',
'--manifest=%s' % self.parms['test_manifest'],
'--testrun-manifest-file=%s-%s-%s-tests.json' % (self.parms['test_name'],
self.chunk,
self.parms['phoneid']),
'--certificate-path=certs',
'--close-when-done',
'--autorun',
'--console-level=%s' % self.parms['console_level'],
'--log-raw=%s' % 'raw-log-' + os.path.basename(self._log),
]
elif test_name_lower.startswith('reftest'):
self.parms['harness_type'] = 'reftest'
test_args = [
'reftest/remotereftest.py',
'--ignore-window-size',
'--bootstrap',
'%s' % self.parms['test_manifest'],
]
elif test_name_lower.startswith('jsreftest'):
self.parms['harness_type'] = 'reftest'
test_args = [
'reftest/remotereftest.py',
'--ignore-window-size',
'--bootstrap',
'--extra-profile-file=jsreftest/tests/user.js',
'%s' % self.parms['test_manifest'],
]
elif test_name_lower.startswith('crashtest'):
self.parms['harness_type'] = 'reftest'
test_args = [
'reftest/remotereftest.py',
'--ignore-window-size',
'--bootstrap',
'%s' % self.parms['test_manifest'],
]
else:
self.loggerdeco.error('Unknown test_name %s' % self.parms['test_name'])
raise Exception('Unknown test_name %s' % self.parms['test_name'])
if self.parms['iterations'] > 1:
test_args.append('--repeat=%d' % (self.parms['iterations']-1))
self.parms['http_port'] = self.parms['port_manager'].reserve()
self.parms['ssl_port'] = self.parms['port_manager'].reserve()
common_args = [
'--dm_trans=sut',
'--deviceIP=%s' % self.parms['phone_ip_address'],
'--devicePort=20701',
'--app=%s' % self.parms['app_name'],
'--xre-path=%s' % self.parms['xre_path'],
'--utility-path=%s' % self.parms['utility_path'],
'--timeout=%d' % self.parms['time_out'],
'--remote-webserver=%s' % self.parms['host_ip_address'],
'--http-port=%s' % self.parms['port_manager'].use(self.parms['http_port']),
'--ssl-port=%s' % self.parms['port_manager'].use(self.parms['ssl_port']),
'--total-chunks=%d' % self.chunks,
'--this-chunk=%d' % self.chunk,
'--pidfile=%s-%s-%s.pid' % (self.parms['test_name'], self.chunk, self.parms['phoneid']),
]
for pref in self.parms['prefs']:
common_args.append('--setpref=%s' % pref)
args.extend(test_args)
args.extend(common_args)
if self.parms['symbols_path'] is not None:
args.append('--symbols-path=%s' % self.parms['symbols_path'])
return args
def process_test_log(self, logfilehandle):
logfilehandle.close()
# convert embedded \n into real newlines
logfilehandle = open(self._log)
self.loggerdeco.debug('process_test_log: name: %s, self._log: %s' % (
logfilehandle.name, self._log))
logcontents = logfilehandle.read()
logfilehandle.close()
logcontents = re.sub(r'\\n', '\n', logcontents)
logfilehandle = open(self._log, 'wb')
logfilehandle.write(logcontents)
logfilehandle.close()
self.loggerdeco.debug('process_test_log: raw log:\n%s\n' % logcontents)
lp = LogParser([logfilehandle.name],
includePass=True,
output_dir=None,
logger=self.logger,
harnessType=self.parms['harness_type'])
parsed_log = lp.parseFiles()
self.loggerdeco.debug('process_test_log: LogParser parsed log : %s' %
json.dumps(parsed_log, indent=2))
self.test_result.todo = parsed_log.get('todo', 0)
self.test_result.passes = parsed_log.get('passes', [])
failures = parsed_log.get('failures', [])
if failures:
self.test_result.status = PhoneTestResult.TESTFAILED
for failure in failures:
for test_failure in failure['failures']:
self.test_result.add_failure(failure['test'],
test_failure['status'],
test_failure['text'])
self.loggerdeco.debug('process_test_log: test_result: %s' %
json.dumps(self.test_result.__dict__, indent=2))
def runtest(self):
self.loggerdeco = LogDecorator(self.logger,
{'phoneid': self.phone.id,
'buildid': self.parms['buildid'],
'testname': self.parms['test_name']},
'%(phoneid)s|%(buildid)s|'
'%(testname)s|%(message)s')
if self.logger.getEffectiveLevel() == logging.DEBUG:
self.loggerdeco.debug('runtestsremote.py runtest start')
for key in self.parms.keys():
self.loggerdeco.debug('test parameters: %s = %s' %
(key, self.parms[key]))
self.update_status(message='Starting test %s' % self.parms['test_name'])
if self.parms['test_name'] == 'robocoptest':
try:
self.dm.uninstall_app('org.mozilla.roboexample.test')
robocop_apk_path = os.path.join(self.parms['build_dir'], 'robocop.apk')
self.dm.install_app(robocop_apk_path)
except Exception, e:
self.loggerdeco.exception('runtestsremote.py:runtest: Exception running test.')
self.test_result.status = PhoneTestResult.EXCEPTION
self.message = 'Exception installing robocop.apk: %s' % e
with open(self._log, "w") as logfilehandle:
logfilehandle.write('%s\n' % self.message)
return
self.parms['port_manager'] = PortManager(self.parms['host_ip_address'])
try:
while True:
socket_collision = False
logfilehandle = open(self._log, 'wb')
self.loggerdeco.debug('logging to %s' % logfilehandle.name)
args = self.create_test_args()
self.parms['cmdline'] = ' '.join(args)
self.loggerdeco.debug("cmdline = %s" %
self.parms['cmdline'])
self.update_status(message='Running test %s chunk %d of %d' %
(self.parms['test_name'],
self.chunk, self.chunks))
if self.dm.process_exist(self.parms['app_name']):
max_kill_attempts = 3
for kill_attempt in range(1, max_kill_attempts+1):
self.loggerdeco.debug(
'Process %s exists. Attempt %d to kill.' % (
self.parms['app_name'], kill_attempt + 1))
self.dm.pkill(self.parms['app_name'], root=True)
if not self.dm.process_exist(self.parms['app_name']):
break
if kill_attempt == max_kill_attempts and \
self.dm.process_exist(self.parms['app_name']):
self.loggerdeco.warning(
'Could not kill process %s.' % (
self.parms['app_name']))
proc = subprocess.Popen(
args,
cwd=os.path.join(self.parms['build_dir'],
'tests'),
preexec_fn=lambda: os.setpgid(0, 0),
stdout=logfilehandle,
stderr=subprocess.STDOUT,
close_fds=True
)
proc.wait()
if proc.returncode == 0:
self.test_result.status = PhoneTestResult.SUCCESS
else:
self.test_result.status = PhoneTestResult.EXCEPTION
self.message = 'Test exited with return code %d' % proc.returncode
self.loggerdeco.debug('runtestsremote.py return code %d' %
proc.returncode)
logfilehandle.close()
# XXX: investigate if this is still needed.
re_socket_error = re.compile('socket\.error:')
logfilehandle = open(self._log)
logcontents = logfilehandle.read()
logfilehandle.close()
if re_socket_error.search(logcontents):
socket_collision = True
if not socket_collision:
break
self.update_status(message='Completed test %s chunk %d of %d' %
(self.parms['test_name'],
self.chunk, self.chunks))
except:
logfilehandle.close()
error_message = ('Exception during test %s chunk %d of %d: %s' %
(self.parms['test_name'],
self.chunk, self.chunks,
traceback.format_exc()))
self.update_status(message=error_message)
self.loggerdeco.error(error_message)
self.test_result.status = PhoneTestResult.EXCEPTION
self.message = error_message
finally:
self.process_test_log(logfilehandle)
self.loggerdeco.debug('runtestsremote.py runtest exit')
return