Index: commit-queue/tools/stats.py
|
===================================================================
|
--- commit-queue/tools/stats.py (revision 249146)
|
+++ commit-queue/tools/stats.py (working copy)
|
@@ -1,504 +0,0 @@
|
-#!/usr/bin/python
|
-# Copyright 2013 The Chromium Authors. All rights reserved.
|
-# Use of this source code is governed by a BSD-style license that can be
|
-# found in the LICENSE file.
|
-'''Generate stats of CQ usage.'''
|
-
|
-# sudo apt-get install pip; sudo pip install requests request_cache
|
-import argparse
|
-import collections
|
-from datetime import timedelta, datetime
|
-import itertools
|
-import numpy
|
-import operator
|
-import re
|
-import requests_cache
|
-import time
|
-import sys
|
-
|
-
|
-class Unbuffered:
|
- def __init__(self, stream):
|
- self.stream = stream
|
- def write(self, data):
|
- self.stream.write(data)
|
- self.stream.flush()
|
- def __getattr__(self, attr):
|
- return getattr(self.stream, attr)
|
-sys.stdout = Unbuffered(sys.stdout)
|
-
|
-
|
-CONFIG = {
|
- 'chrome': {
|
- 'target_base_url_regexps': [
|
- re.compile(r'^svn://svn\.chromium\.org/chrome/trunk/src'),
|
- # pylint: disable=C0301
|
- re.compile(r'^https://chromium\.googlesource\.com/chromium/chromium/src(?:\.git)?(?:@[\w\-]+)?$'),
|
- re.compile(r'^http://src\.chromium\.org/chrome/trunk/src'),
|
- ],
|
- },
|
- 'blink': {
|
- 'target_base_url_regexps': [
|
- re.compile(r'^svn://svn\.chromium\.org/blink/(?:trunk/?)?$'),
|
- # pylint: disable=C0301
|
- re.compile(r'^https://chromium\.googlesource\.com/chromium/blink(?:\.git)?(?:@[\w\-]+)?$'),
|
- re.compile(r'^http://src\.chromium\.org/blink/(?:trunk/?)?$'),
|
- ],
|
- },
|
- 'skia': {
|
- 'target_base_url_regexps': [
|
- re.compile(r'^http://skia.googlecode.com/svn/trunk'),
|
- re.compile(r'^https://skia.googlecode.com/svn/trunk'),
|
- ],
|
- },
|
-}
|
-config_name = None
|
-
|
-
|
-def make_throttle_hook(timeout=1.0):
|
- # pylint: disable=W0613
|
- def hook(response, *args, **kwargs):
|
- print response.url
|
- if not getattr(response, 'from_cache', False):
|
- print 'sleeping'
|
- time.sleep(timeout)
|
- return response
|
- return hook
|
-
|
-
|
-# It seems reasonable to expect that rietveld can handle 20 query-per-second
|
-# load from this script. Ask someone on the infra team before reducing this
|
-# value.
|
-seconds_between_requests = 0.05
|
-
|
-requests_cache.install_cache('cq')
|
-session = requests_cache.CachedSession()
|
-# if args.clear:
|
-# print 'Clearing cache...'
|
-# session.cache.clear()
|
-session.hooks = {'response': make_throttle_hook(seconds_between_requests)}
|
-
|
-
|
-def fetch_recent_issues(limit, args, cursor=None):
|
- search_url = ('https://codereview.chromium.org/search?format=json&'
|
- 'limit=%d') % limit
|
- if cursor:
|
- search_url += '&cursor=%s' % cursor
|
- if args.modified_after:
|
- search_url += '&modified_after=%s' % args.modified_after
|
- if args.modified_before:
|
- search_url += '&modified_before=%s' % args.modified_before
|
- response = session.get(search_url)
|
- return response.json()
|
-
|
-
|
-def get_target_base_url_regexps():
|
- return CONFIG[config_name]['target_base_url_regexps']
|
-
|
-
|
-def matches_target_base_url(url):
|
- for regexp in get_target_base_url_regexps():
|
- match = regexp.match(url)
|
- if match:
|
- return True
|
- return False
|
-
|
-
|
-def issue_patch_string(issue_id, patch_id):
|
- return '%s:%s' % (issue_id, patch_id)
|
-
|
-
|
-def issue_display_url(issue_id):
|
- return 'https://codereview.chromium.org/%s' % issue_id
|
-
|
-
|
-def issue_url(issue_id):
|
- return 'https://codereview.chromium.org/api/%s?messages=true' % issue_id
|
-
|
-
|
-def date_from_iso_str(iso_str):
|
- # Issues have one of two formats:
|
- # 2013-10-17 16:43:04.391480
|
- # 2013-10-17 16:43:04
|
- try:
|
- return datetime.strptime(iso_str, '%Y-%m-%d %H:%M:%S.%f')
|
- except ValueError:
|
- return datetime.strptime(iso_str, '%Y-%m-%d %H:%M:%S')
|
-
|
-
|
-def round_timedelta(delta):
|
- # We never care about the milliseconds when printing timedeltas:
|
- return timedelta(seconds=round(delta.total_seconds()))
|
-
|
-
|
-def fetch_issue(issue_id):
|
- url = issue_url(issue_id)
|
- this_json = session.get(url).json()
|
- # pylint: disable=W0212
|
- cache_key = session.cache._url_to_key(url)
|
- _, now = session.cache.get_response_and_time(cache_key)
|
- return this_json, now
|
-
|
-
|
-def format_line(values, aligns, widths):
|
- values = map(str, values)
|
- args = zip(values, aligns, widths)
|
- return ' '.join([apply(align, (value, width))
|
- for value, align, width in args])
|
-
|
-
|
-class CQAttempt(object):
|
- def __init__(self):
|
- self.result = None
|
- self.patch_id = None
|
- self.issue_id = None
|
- self.author = None
|
- self.start_time = None
|
- self.end_time = None
|
-
|
- @property
|
- def issue_patch_string(self):
|
- return issue_patch_string(self.issue_id, self.patch_id)
|
-
|
- @property
|
- def duration(self):
|
- return self.end_time - self.start_time
|
-
|
-
|
-class CQAnalyzer(object):
|
- def __init__(self):
|
- self.state = None
|
- self.issue = None
|
- self.issue_id = None
|
- self.author = None
|
- self.patch_id = None
|
- self.start_time = None
|
- self.attempts = []
|
- self.manual_commits = set()
|
- self.no_try_issues = set()
|
- self.now = None
|
- # issue_id -> time since CQ start
|
- self.in_progress = {}
|
-
|
- # pylint: disable=C0301
|
- start_regexp = re.compile('''CQ is trying da patch. Follow status at
|
-https://chromium-status.appspot.com/cq/(?P<author>.*)/(?P<issue_id>\d+)/(?P<patch_id>\d+)''')
|
- committed_regexp = re.compile('Change committed as (?P<revision>\d+)')
|
- # pylint: disable=C0301
|
- manual_commit_regexp = re.compile('Committed patchset #(?P<patch_id>\d+) manually as r(?P<revision>\d+)')
|
-
|
- def _reset(self):
|
- self.state = None
|
- self.author = None
|
- self.patch_id = None
|
- self.start_time = None
|
-
|
- def _start(self, patch_id, start_time, author=None):
|
- if self.state == 'START' and self.patch_id == patch_id:
|
- # print 'Restarted for patchset %s on %s' % (
|
- # patch_id, issue_display_url(self.issue_id))
|
- self._end('RESTART', start_time)
|
- self.state = 'START'
|
- self.patch_id = patch_id
|
- self.author = author
|
- assert start_time
|
- self.start_time = start_time
|
-
|
- def _end(self, result, end_time):
|
- if self.state != 'START':
|
- print 'ERROR: %s for %s without start??' % (
|
- result, issue_display_url(self.issue_id))
|
- self._reset()
|
- return
|
- attempt = CQAttempt()
|
- attempt.result = result
|
- attempt.patch_id = self.patch_id
|
- attempt.issue_id = self.issue_id
|
- attempt.start_time = self.start_time
|
- attempt.end_time = end_time
|
- self.attempts.append(attempt)
|
- self._reset()
|
-
|
- def _start_and_end(self, result, date):
|
- self._start(result, date)
|
- self._end(result, date)
|
-
|
- def _manual_commit(self, patch_id):
|
- self.manual_commits.add(issue_patch_string(self.issue_id, patch_id))
|
-
|
- def process_message(self, message):
|
- text = message['text']
|
- date = date_from_iso_str(message['date'])
|
-
|
- match = self.manual_commit_regexp.match(text)
|
- if match:
|
- if self.start_time:
|
- self._end('MANUAL_COMMIT',
|
- date_from_iso_str(self.issue['modified']))
|
- patch_number = int(match.group('patch_id'))
|
- # gcl dcommit talks in terms of patch numbers 1-5, we need to map
|
- # those to patchset ids:
|
- if len(self.issue['patchsets']) > (patch_number-1):
|
- patch_id = self.issue['patchsets'][patch_number-1]
|
- else:
|
- print '%s missing patch number %d' % (
|
- self.issue_id, patch_number)
|
- print self.issue['patchsets']
|
- print 'issue, now = fetch_issue(\'%s\')' % self.issue_id
|
- patch_id = self.issue['patchsets'][-1]
|
- self._manual_commit(patch_id)
|
- return
|
-
|
- if message['sender'] != 'commit-bot@chromium.org':
|
- return
|
-
|
- match = self.start_regexp.match(text)
|
- if match:
|
- self._start(match.group('patch_id'), date, match.group('author'))
|
- return
|
- match = self.committed_regexp.match(text)
|
- if match:
|
- self._end('SUCCESS', date)
|
- return
|
-
|
- cq_end_messages = {
|
- 'TRY': 'Retried try job',
|
- 'APPLY': 'Failed to apply patch',
|
- 'APPLY2': 'Failed to apply the patch',
|
- 'COMPILE': 'Sorry for I got bad news for ya',
|
- 'DESCRIPTION_CHANGED': ('Commit queue rejected this change because '
|
- 'the description'),
|
- # This is too conservative.
|
- 'REVIEWERS_CHANGED': 'List of reviewers changed.',
|
- # User caused.
|
- 'PATCH_CHANGED': 'Commit queue failed due to new patchset.',
|
- # FAILED_TO_TRIGGER is a very serious failure, unclear why it
|
- # happens!
|
- 'FAILED_TO_TRIGGER': 'Failed to trigger a try job on',
|
- # BINARY_FILE is just a bug in the CQ.
|
- 'BINARY_FILE': 'Can\'t process patch for file',
|
- 'BINARY_FILE2': 'Failed to request the patch to try',
|
- # Unclear why UPDATE_STEP happens. Likely broken bots, shouldn't
|
- # fail patches!
|
- 'UPDATE_STEP': 'Step "update" is always a major failure.',
|
- 'BERSERK': 'The commit queue went berserk',
|
- 'INTERNAL_ERROR': 'Commit queue had an internal error.',
|
- }
|
- for result, message_text in cq_end_messages.items():
|
- if text.startswith(message_text):
|
- self._end(result, date)
|
- return
|
-
|
- cq_fail_to_start_messsages = {
|
- 'FAILED_PATCHSET': 'Failed to get patchset properties',
|
- 'NO_COMMENTS': 'No comments yet.',
|
- 'NO_LGTM': 'No LGTM from a valid reviewer yet.',
|
- }
|
- for result, message_text in cq_fail_to_start_messsages.items():
|
- if text.startswith(message_text):
|
- self._start_and_end(result, date)
|
- return
|
-
|
- print 'Error %s has unknown message: %s' % (
|
- issue_display_url(self.issue_id), text)
|
- self._end('UNKNOWN', date)
|
-
|
- def start_issue(self, issue, now):
|
- # We may be dealing with cached data, so cache our concept of "now"
|
- self.now = now
|
- self.issue = issue
|
- self.issue_id = issue['issue']
|
-
|
- def end_issue(self, issue):
|
- issue_id = issue['issue']
|
- assert issue_id == self.issue_id
|
- if self.start_time:
|
- if self.issue['commit']:
|
- print '%s in progress? %s' % (
|
- round_timedelta(self.now - self.start_time),
|
- issue_display_url(self.issue_id))
|
- self._end('IN_PROGRESS', self.now)
|
- else:
|
- # There are various reasons why the commit box may have
|
- # been unchecked, including that the issue may be closed now.
|
- # If those are not from a user, then that's a bug in rietveld
|
- # and out of scope for this script. For now we're just ignoring
|
- # cases where the box was unchecked. We could log an _end()
|
- # event, but which time would we use? last_modified has at
|
- # best a weak corrolation with the issue close or CQ checkbox.
|
- self._reset()
|
- # _reset() shouldn't be needed, but just in case.
|
- self._reset()
|
- self.issue_id = None
|
- self.issue = None
|
-
|
- def process_issue(self, issue, now):
|
- issue_id = issue['issue']
|
-
|
- if re.search('^NOTRY=[tT][rR][uU][eE]$', issue['description'], re.M):
|
- self.no_try_issues.add(issue_id)
|
-
|
- self.start_issue(issue, now)
|
- for message in issue['messages']:
|
- self.process_message(message)
|
- # print '%(date)s: %(text)s' % message
|
- self.end_issue(issue)
|
-
|
- def print_attempts_table(self):
|
- result_getter = operator.attrgetter('result')
|
- attempts = sorted(self.attempts, key=result_getter)
|
-
|
- col_aligns = (str.rjust, str.ljust, str.rjust, str.rjust)
|
- col_widths = (5, 20, 16, 16)
|
- col_headers = ('count', 'result', 'mean duration', 'median duration')
|
- print
|
- print ('CQ Attempts by result (there can be more than '
|
- 'one attempt on the same patch)')
|
- print format_line(col_headers, col_aligns, col_widths)
|
- print '-' * (sum(col_widths) + len(col_widths) - 1)
|
- for result, group_itr in itertools.groupby(attempts, result_getter):
|
- group = list(group_itr)
|
- durations = map(operator.attrgetter('duration'), group)
|
- mean = sum(durations, timedelta()) / len(group)
|
- durations_seconds = map(timedelta.total_seconds, durations)
|
- median_seconds = numpy.median(durations_seconds)
|
- median = timedelta(seconds=round(median_seconds))
|
- values = (len(group), result, round_timedelta(mean), median)
|
- print format_line(values, col_aligns, col_widths)
|
- print
|
-
|
-
|
-def main():
|
- parser = argparse.ArgumentParser()
|
- parser.add_argument('--base-url-stats', action='store_true',
|
- help='print base_url matching stats')
|
- parser.add_argument('--chrome', action='store_true')
|
- parser.add_argument('--clear', action='store_true',
|
- help='clear the cache before starting')
|
- parser.add_argument('--count', type=int, default=None,
|
- help='number of issues to fetch')
|
- parser.add_argument('--modified-after', default=None,
|
- help=('search for issues modified after '
|
- 'this date YYYY-MM-DD'))
|
- parser.add_argument('--modified-before', default=None,
|
- help=('search for issues modified before '
|
- 'this date YYYY-MM-DD'))
|
- parser.add_argument('--progress', help='Show progress', action='store_true')
|
- parser.add_argument('--skia', action='store_true')
|
- args = parser.parse_args()
|
-
|
- # Rietveld allows up to 1000 results per search query. I don't know if
|
- # that's better for the server or not. We'll use 100 to be safe.
|
- per_request_search_limit = 100
|
- if args.count:
|
- per_request_search_limit = min(int(args.count/2), 100)
|
- # Currently looking at the last 2000 entries.
|
- target_count = args.count
|
- if args.clear:
|
- print 'Clearing cache...'
|
- session.cache.clear()
|
- global config_name
|
- if args.chrome:
|
- config_name = 'chrome'
|
- elif args.skia:
|
- config_name = 'skia'
|
- else:
|
- config_name = 'blink'
|
- print 'Fetching and analyzing most recent issues...'
|
- analyzer = CQAnalyzer()
|
-
|
- total_fetch_count = 0
|
- issue_count = 0
|
- cursor = None
|
- url_counts = collections.Counter()
|
- while True:
|
- search_results = fetch_recent_issues(per_request_search_limit, args,
|
- cursor)
|
- if len(search_results['results']) == 0:
|
- break
|
- cursor = search_results['cursor']
|
- total_fetch_count += per_request_search_limit
|
-
|
- if args.base_url_stats:
|
- url_counts.update([result['base_url']
|
- for result in search_results['results']])
|
-
|
- for result in search_results['results']:
|
- if not matches_target_base_url(result['base_url']):
|
- continue
|
- issue_count += 1
|
- if args.progress and (issue_count % 100 == 0):
|
- print issue_count,
|
- if target_count:
|
- print target_count
|
- issue, now = fetch_issue(result['issue'])
|
- analyzer.process_issue(issue, now)
|
- if target_count and issue_count >= target_count:
|
- break
|
-
|
- if args.base_url_stats:
|
- print
|
- for url, count in url_counts.most_common():
|
- matches_target = matches_target_base_url(url)
|
- print '%s %s %s' % (matches_target, count, url)
|
-
|
- print
|
- print 'Found %s issues (in the %s most recent issues).' % (
|
- issue_count, total_fetch_count)
|
- cq_issues = set([attempt.issue_id for attempt in analyzer.attempts])
|
- cq_issue_count = len(cq_issues)
|
- cq_patches = set([attempt.issue_patch_string
|
- for attempt in analyzer.attempts])
|
- cq_patch_count = len(cq_patches)
|
- print ('%s issues (%d%%) (%d patches) tried the CQ, '
|
- 'resulting in %d CQ attempts.') % (
|
- cq_issue_count, 100 * cq_issue_count / issue_count, cq_patch_count,
|
- len(analyzer.attempts))
|
-
|
- no_try_issues = len(cq_issues & analyzer.no_try_issues)
|
- gave_up_patches = len(cq_patches & analyzer.manual_commits)
|
- print ('%s of those (%d%%) were committed manually (gave up). '
|
- '%s (%d%%) were marked NOTRY.') % (
|
- gave_up_patches, 100 * gave_up_patches / cq_issue_count,
|
- no_try_issues, 100 * no_try_issues / cq_issue_count)
|
-
|
- analyzer.print_attempts_table()
|
-
|
- identifier_getter = operator.attrgetter('issue_patch_string')
|
- attempts = sorted(analyzer.attempts, key=identifier_getter)
|
- extra_user_clicks = 0
|
- eventually_success_durations = []
|
- eventually_success_attempts = []
|
-
|
- # pylint: disable=W0612
|
- for identifier, group_itr in itertools.groupby(attempts, identifier_getter):
|
- group = list(group_itr)
|
- if group[0].issue_id in analyzer.no_try_issues:
|
- continue
|
- results = map(operator.attrgetter('result'), group)
|
- # print '%s(%s): %s %s' % (identifier, len(group), total_time, results)
|
- if 'SUCCESS' in results:
|
- # 'RESTART' events may not require a user re-click?
|
- user_initiated = filter(lambda result: result != 'RESTART', results)
|
- extra_user_clicks += len(user_initiated) - 1
|
- durations = map(operator.attrgetter('duration'), group)
|
- eventually_success_durations.append(
|
- sum(durations, timedelta()).total_seconds())
|
- eventually_success_attempts.append(len(group))
|
-
|
- print ('%s CQ starts (%d%%) were due a previous false-negative '
|
- '(CQ landed a patch it previously rejected)') % (
|
- extra_user_clicks, 100 * extra_user_clicks / len(analyzer.attempts))
|
-
|
- print 'Patches which eventually land percentiles:'
|
- for i in [10, 25, 50, 75, 90, 95, 99]:
|
- eventually_success_durations_p = round(numpy.percentile(
|
- eventually_success_durations, i)/(60*60), 3)
|
- eventually_success_attempts_p = numpy.percentile(
|
- eventually_success_attempts, i)
|
- print '%d: %.3f hrs, %.3f attempts' % (
|
- i, eventually_success_durations_p, eventually_success_attempts_p)
|
-
|
-
|
-if __name__ == '__main__':
|
- sys.exit(main())
|
|