Skip to content
This repository has been archived by the owner on Aug 14, 2020. It is now read-only.

Commit

Permalink
Bug 1227188 - Autophone - use new browser start logcat message to det…
Browse files Browse the repository at this point in the history 
…ermine start time, r=gbrown.
  • Loading branch information
@bclary
bclary committed Dec 18, 2015
1 parent ca98e2e commit 90a7885
Show file tree
Hide file tree
Showing 2 changed files with 98 additions and 22 deletions.
60 changes: 49 additions & 11 deletions tests/s1s2test.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -273,8 +273,11 @@ def analyze_logcat(self):
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_gecko_time = re.compile('%s .*([Gg]ecko)' % logcat_prefix)
re_start_time = re.compile(
'%s .*([Gg]ecko|Start proc %s for activity %s/.App)' % (
'%s .*('
'Start proc .*%s.* for activity %s|'
'Fennec application start)' % (
logcat_prefix, self.build.app_name, self.build.app_name))
re_throbber_start_time = re.compile('%s %s start' %
(logcat_prefix, throbber_prefix))
Expand All @@ -285,6 +288,8 @@ def analyze_logcat(self):
start_time = 0
throbber_start_time = 0
throbber_stop_time = 0
start_time_reason = ''
fennec_start = 'Fennec application start'

attempt = 1
max_time = 90 # maximum time to wait for throbbers
Expand All @@ -301,17 +306,50 @@ def analyze_logcat(self):
base_time = match.group(1)
self.loggerdeco.info('analyze_logcat: base_time: %s' %
base_time)
# We want the Start proc message or if that is not
# available, the first gecko related message in order
# to determine the start_time which will be used to
# convert the absolute time values into values
# relative to the start of fennec.
# We want the Fennec application start message, or the
# Start proc message or the first gecko related
# message in order to determine the start_time which
# will be used to convert the absolute time values
# into values relative to the start of fennec. See
# https://bugzilla.mozilla.org/show_bug.cgi?id=1214810
if not start_time:
match = re_gecko_time.match(line)
if match:
start_time = match.group(1)
start_time_reason = match.group(2)
self.loggerdeco.info(
'analyze_logcat: new start_time: %s %s' %
(start_time, start_time_reason))
match = re_start_time.match(line)
if match and (not start_time or
match.group(2).startswith('Start proc')):
start_time = match.group(1)
self.loggerdeco.info('analyze_logcat: start_time: %s %s' %
(start_time, match.group(2)))
if match:
group1 = match.group(1)
group2 = match.group(2)
if not start_time:
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: new start_time: %s %s' %
(start_time, start_time_reason))
elif (fennec_start in group2 and
fennec_start not in start_time_reason):
# Only use the first if there are multiple
# fennec_start messages.
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: updated start_time: %s %s' %
(start_time, start_time_reason))
elif (fennec_start not in start_time_reason and
group2.startswith('Start proc')):
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: updated start_time: %s %s' %
(start_time, start_time_reason))
else:
self.loggerdeco.info(
'analyze_logcat: ignoring start_time: %s %s' %
(group1, group2))
continue
# We want the first throbberstart and throbberstop
# after the start_time.
Expand Down
60 changes: 49 additions & 11 deletions tests/webappstartup.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -480,8 +480,11 @@ def analyze_logcat(self):
chrome_prefix = '..GeckoBrowser.*: zerdatime .* - browser chrome startup finished.'
webapp_prefix = '..GeckoConsole.*WEBAPP STARTUP COMPLETE'
re_base_time = re.compile('%s' % logcat_prefix)
re_gecko_time = re.compile('%s .*([Gg]ecko)' % logcat_prefix)
re_start_time = re.compile(
'%s .*([Gg]ecko|Start proc %s for activity %s)' % (
'%s .*('
'Start proc .*%s.* for activity %s|'
'Fennec application start)' % (
logcat_prefix, self.webappstartup_name, self.webappstartup_name))
re_chrome_time = re.compile('%s %s' %
(logcat_prefix, chrome_prefix))
Expand All @@ -492,6 +495,8 @@ def analyze_logcat(self):
start_time = 0
chrome_time = 0
startup_time = 0
start_time_reason = ''
fennec_start = 'Fennec application start'

attempt = 1
max_time = 90 # maximum time to wait for WEBAPP STARTUP COMPLETE
Expand All @@ -507,17 +512,50 @@ def analyze_logcat(self):
base_time = match.group(1)
self.loggerdeco.info('analyze_logcat: base_time: %s' %
base_time)
# We want the Start proc message or if that is not
# available, the first gecko related message in order
# to determine the start_time which will be used to
# convert the absolute time values into values
# relative to the start of fennec.
# We want the Fennec application start message, or the
# Start proc message or the first gecko related
# message in order to determine the start_time which
# will be used to convert the absolute time values
# into values relative to the start of fennec. See
# https://bugzilla.mozilla.org/show_bug.cgi?id=1214810
if not start_time:
match = re_gecko_time.match(line)
if match:
start_time = match.group(1)
start_time_reason = match.group(2)
self.loggerdeco.info(
'analyze_logcat: new start_time: %s %s' %
(start_time, start_time_reason))
match = re_start_time.match(line)
if match and (not start_time or
match.group(2).startswith('Start proc')):
start_time = match.group(1)
self.loggerdeco.info('analyze_logcat: start_time: %s %s' %
(start_time, match.group(2)))
if match:
group1 = match.group(1)
group2 = match.group(2)
if not start_time:
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: new start_time: %s %s' %
(start_time, start_time_reason))
elif (fennec_start in group2 and
fennec_start not in start_time_reason):
# Webapps emit two fennec_start messages. Only
# use the first.
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: updated start_time: %s %s' %
(start_time, start_time_reason))
elif (fennec_start not in start_time_reason and
group2.startswith('Start proc')):
start_time = group1
start_time_reason = group2
self.loggerdeco.info(
'analyze_logcat: updated start_time: %s %s' %
(start_time, start_time_reason))
else:
self.loggerdeco.info(
'analyze_logcat: ignoring start_time: %s %s' %
(group1, group2))
continue
# We want the first chrome time and WEBAPP STARTUP
# COMPLETE after the start_time.
Expand Down

0 comments on commit 90a7885

Please sign in to comment.