Merge lp:~brian-murray/ubuntu-archive-tools/phased-updater into lp:ubuntu-archive-tools

[Brian Murray]

This new tool, phased-updater, will be the glue between Launchpad (for setting the phased updater percentage) and the Ubuntu Error Tracker (for finding regressions in package from -updates).

In the event that no regressions (defined as errors about the version of the package in -updates that were not seen in the previous version, or an increased rate of crashes) are found about the package the phased-update-percentage for the package will be incremented by 10%. If regressions are found the phased-update-percentage for the package will be set to 0%. There is also a mechanism for indicating that individual buckets are not regressions in a particular version of the package.

In either case an html report (sample visible at http://people.canonical.com/~brian/tmp/phased-updates.html) will be generated that will display the phased update percentage for the package and any issues found with that package. This will also be useful for seeing which packages are currently undergoing phasing.

In the event that a regression is found about a package in -updates the uploader and signer (if different from the uploader) wil be emailed of the regression or regressions in that upload. There is a csv file used to keep track of email notifications sent to uploaders to ensure that we do not email them multiple times about the same issue.

Its possible to test this on dogfood by initially setting the phased update percentage to something less than one hundred percent and observe the script increment the phased update percentage. However, this needs to be done using quantal and a start date in early May as the database for dogfood is rather old.

[lp:~brian-murray/ubuntu-archive-tools/phased-updater]

758. By Brian Murray on 2013-06-24

log original phased update percentage

759. By Brian Murray on 2013-06-24

clarify last todo

[Steve Langasek (vorlon)]

+def set_pup(new_pup, suite, src_pkg):
+ import subprocess
+ with open(os.devnull, 'w') as fnull:
+ retcode = subprocess.call([
+ "%s/change-override" % os.getcwd(),
+ "--confirm-all",
+ "--percentage", '%s' % new_pup,
+ "--suite", suite,
+ "--source-and-binary", src_pkg,
+ "--launchpad", options.launchpad_instance],
+ stdout = fnull)
+ if retcode != 0:
+ logging.error("There was an error (%s) running change-override."
+ % retcode)
+ return retcode

os.getcwd() doesn't do what you want here in all cases. I, for example, have ubuntu-archive-tools on my path, so my getcwd() returns a location completely unrelated to where the tools are.

Instead, I think you want:

  os.path.dirname(sys.argv[0]) or "."

The other use of os.getcwd() seem fine, as they refer to the output directory and I think it's reasonable to use the current dir as the convention for that. But in production, I think we aren't going to be writing the report to the checkout dir.

Otherwise, this looks good to me and ready to merge.

review: Needs Fixing

[Colin Watson (cjwatson)]

On Mon, Jun 24, 2013 at 10:54:25PM -0000, Steve Langasek wrote:
> os.getcwd() doesn't do what you want here in all cases. I, for example, have ubuntu-archive-tools on my path, so my getcwd() returns a location completely unrelated to where the tools are.
>
> Instead, I think you want:
>
> os.path.dirname(sys.argv[0]) or "."

I would prefer doing the override change directly using API calls,
rather than shelling out to change-override.

[lp:~brian-murray/ubuntu-archive-tools/phased-updater]

760. By Brian Murray on 2013-06-27

directly call changeOverride in the Launchpad API rather than using subprocess to call change-override

[Brian Murray (brian-murray)]

I've switched to using the API directly instead of using change-override which I believe addresses both comments about the merge proposal.

[Colin Watson (cjwatson)]

OK, thanks for that fix. Let's give this a go ...

review: Approve

=== added file 'phased-updater'
--- phased-updater	1970-01-01 00:00:00 +0000
+++ phased-updater	2013-06-27 16:06:38 +0000
@@ -0,0 +1,518 @@
+#!/usr/bin/python
+
+# Copyright (C) 2013 Canonical Ltd.
+# Author: Brian Murray <[e-mail]>
+
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; version 3 of the License.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+'''Increment the Phased-Update-Percentage for a package
+
+Check to see whether or not there is a regression (new crash bucket or
+increase rate of errors about a package) using errors.ubuntu.com and if
+not increment the Phased-Update-Percentage for the package.
+Additionally, generate an html report regarding state of phasing of
+packages and email uploaders regarding issues with their uploads.
+'''
+
+from __future__ import print_function
+
+import apt
+import csv
+import datetime
+import logging
+import os
+import simplejson as json
+import time
+
+from collections import defaultdict, OrderedDict
+from optparse import OptionParser
+
+import lputils
+
+try:
+    from urllib.parse import quote
+    from urllib.request import urlopen
+except ImportError:
+    from urllib import quote, urlopen
+
+from launchpadlib.launchpad import Launchpad
+
+def get_primary_email(lp_user):
+    try:
+        lp_user_email = lp_user.preferred_email_address.email
+    except ValueError as e:
+        if 'server-side permission' in e.message:
+            logging.info("%s has hidden their email addresses" %
+                lp_user.web_link)
+            return ''
+        logging.info("Error accessing %s's preferred email address: %s" %
+            (lp_user.web_link, e.message))
+        return ''
+    return lp_user_email
+
+def set_pup(current_pup, new_pup, release, suite, src_pkg):
+    options.series = release
+    options.suite = suite
+    options.pocket = 'Updates'
+    options.version = None
+    source = lputils.find_latest_published_source(options, src_pkg)
+    publications = [binary for binary in source.getPublishedBinaries()]
+
+    for pub in publications:
+        pub.changeOverride(new_phased_update_percentage=new_pup)
+        if new_pup != 0:
+            logging.info('Incremented p-u-p for %s %s from %s%% to %s%%' %
+                (suite, pub.binary_package_name, current_pup, new_pup))
+        else:
+            logging.info('Set p-u-p to 0%% from %s%% for %s %s'
+                % (current_pup, suite, pub.binary_package_name))
+
+def generate_html_report(releases, buckets):
+    import tempfile
+    import shutil
+    with tempfile.NamedTemporaryFile() as report:
+        report.write('''<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
+ "http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
+<html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en">
+<head>
+  <meta http-equiv="Content-Type" content="text/html; charset=utf-8" />
+  <title>Released Ubuntu SRUs</title>
+  <style type="text/css">
+    body { background: #CCCCB0; color: black; }
+    a { text-decoration: none; }
+    table { border-collapse: collapse; border-style: solid none;
+            border-width: 3px; margin-bottom: 3ex; empty-cells: show; }
+    table th { text-align: left; border-style: none none dotted none;
+               border-width: 1px; padding-right: 10px; }
+    table td { text-align: left; border-style: none none dotted none;
+               border-width: 1px; padding-right: 10px; }
+    .noborder { border-style: none; }
+    a { color: blue; }
+    a:visited { color: black; }
+  </style>
+</head>
+<body>
+<h1>Phasing %sUbuntu Stable Release Updates</h1>
+''' % ('', 'and Released ')[options.fully_phased])
+        report.write('<p>Generated: %s by '
+          '<a href="http://bazaar.launchpad.net/'
+          '~ubuntu-archive/ubuntu-archive-tools/trunk/annotate/head%%3A/'
+          'phased-updater">phased-updater</a></p>' %
+          time.strftime('%x %X UTC', time.gmtime()))
+        report.write('''<p>A <a
+href="https://wiki.ubuntu.com/StableReleaseUpdates ">stable release
+update</a> has been created for the following packages, i. e.  they have
+a new version in -updates, and either an increased rate of crashes has
+been detected or an error has been found that only exists with the new
+version of the package.\n''')
+        for release in releases:
+            rname = release.name
+            if not buckets[rname]:
+                continue
+            report.write('''<h3>%s</h3>\n''' % rname)
+            report.write('''<table>\n''')
+            report.write('''<tr>
+      <th>Package</th>
+      <th>Version</th>
+      <th>Update Percentage</th>
+      <th>Rate Increase</th>
+      <th>Problems</th>
+      <th>Days</th>
+    </tr>''')
+            for pub_source in buckets[rname]:
+                pkg = pub_source.source_package_name
+                version = pub_source.source_package_version
+                age = (datetime.datetime.now() -
+                    pub_source.date_published.replace(tzinfo=None)).days
+                update_percentage = buckets[rname][pub_source].get('pup',
+                    100)
+                if not options.fully_phased and update_percentage == 100:
+                    continue
+                lpurl = '%s/ubuntu/+source/%s/' % (LP_BASE_URL, pkg)
+                report.write('''<tr>
+      <td><a href="%s">%s</a></td>
+      <td><a href="%s">%s</a></td>\n''' %
+                             (lpurl, pkg, lpurl + version, version))
+                report.write('  <td>')
+                if update_percentage == 0:
+                    binary_pub = pub_source.getPublishedBinaries()[0]
+                    arch = binary_pub.distro_arch_series.architecture_tag
+                    bpph_url = ('%s/ubuntu/%s/%s/%s'
+                        % (LP_BASE_URL, rname, arch,
+                           binary_pub.binary_package_name))
+                    report.write('<a href="%s">%s%% of users' %
+                        (bpph_url, update_percentage))
+                    previous_pup = \
+                        buckets[rname][pub_source]['previous_pup']
+                    if previous_pup != 0:
+                        report.write(' (was %s%%)</a>' % previous_pup)
+                    else:
+                        report.write('</a>')
+                else:
+                    report.write('%s%% of users' % update_percentage)
+                report.write('</td>\n')
+                if 'rate' in buckets[rname][pub_source]:
+                    data = buckets[rname][pub_source]['rate']
+                    report.write('  <td><a href="%s">+%s</a></td>\n' %
+                                 (data[1], data[0]))
+                else:
+                    report.write('  <td></td>\n')
+                report.write('  <td>')
+                if 'buckets' in buckets[rname][pub_source]:
+                    for bucket in buckets[rname][pub_source]['buckets']:
+                        if 'problem' in bucket:
+                            # create a short version of the problem's hash
+                            phash = bucket.replace(
+                                'https://errors.ubuntu.com/problem/', '')[0:6]
+                            report.write('<a href="%s">%s</a> ' % (bucket,
+                                phash))
+                        else:
+                            report.write('<a href="%s">problem</a> ' % bucket)
+                else:
+                    report.write('')
+                report.write('</td>\n')
+                report.write('  <td>%s</td>\n' % age)
+                report.write('</tr>\n')
+            report.write('''</table>\n''')
+        report.write('''</body>\n''')
+        report.write('''</html>''')
+        report.flush()
+        shutil.copy2(report.name, '%s/phased-updates.html' % os.getcwd())
+
+def create_email_notifications(releases, spph_buckets):
+    import smtplib
+    from email.mime.text import MIMEText
+    with open(NOTIFICATIONS, 'r') as notify_file:
+        notify_csv = csv.reader(notify_file)
+        notifications = defaultdict(list)
+        for row in notify_csv:
+            # LP name, problem, pkg_version
+            person = row[0].strip()
+            problem = row[1].strip()
+            pkg = row[2].strip()
+            pkg_version = row[3].strip()
+            notifications[person].append((problem, pkg, pkg_version))
+    b_body = ('Your upload of %s version %s to %s has resulted in %s'
+              'error%s that %s first reported about this version of the '
+              'package.  The error%s follow%s:\n\n'
+              '%s\n\n')
+    i_body = ('Your upload of %s version %s to %s has resulted in an '
+              'increased daily rate of errors for the package compared '
+              'to the previous two weeks. For problems currently being '
+              'reported about the package see:\n\n'
+              '%s\n\n')
+    remedy = ('Further phasing of this update has been stopped until the '
+              'errors have either been fixed or determined to not be a '
+              'result of this Stable Release Update.  In the event of '
+              'the latter please let a member of the Ubuntu Stable Release '
+              'Updates team (~ubuntu-sru) know so that phasing of the update '
+              'can proceed.')
+    for release in releases:
+        rname = release.name
+        for spph in spph_buckets[rname]:
+            signer = spph.package_signer
+            # not an active user of Launchpad
+            if not signer.is_valid:
+                logging.info('%s not mailed as they are not a valid LP user'
+                    % signer)
+                continue
+            signer_email = get_primary_email(signer)
+            if not signer_email:
+                continue
+            pkg = spph.source_package_name
+            version = spph.source_package_version
+            signer_name = signer.name
+            changer = spph.package_creator
+            if 'buckets' in spph_buckets[rname][spph]:
+                # see if they've been emailed about the bucket before
+                notices = []
+                if signer_name in notifications:
+                    notices = notifications[signer_name]
+                for notice, notified_pkg, notified_version in notices:
+                    if notice in spph_buckets[rname][spph]['buckets']:
+                        if (notified_pkg != pkg and
+                                notified_version != version):
+                            continue
+                        spph_buckets[rname][spph]['buckets'].remove(notice)
+                if len(spph_buckets[rname][spph]['buckets']) == 0:
+                    continue
+                receivers = []
+                quantity = len(spph_buckets[rname][spph]['buckets'])
+                msg = MIMEText(b_body % (pkg, version, rname,
+                    ('an ', '')[quantity != 1], ('', 's')[quantity != 1],
+                    ('was', 'were')[quantity != 1],
+                    ('', 's')[quantity != 1], ('s', '')[quantity != 1],
+                    '\n'.join(spph_buckets[rname][spph]['buckets'])) + remedy)
+                subject = '[%s/%s] Possible Regression' % (rname, pkg)
+                msg['Subject'] = subject
+                msg['From'] = EMAIL_SENDER
+                receivers.append(signer_email)
+                msg['To'] = signer_email
+                if changer != signer and changer.is_valid:
+                    changer_email = get_primary_email(changer)
+                    if changer_email:
+                       receivers.append(changer_email)
+                       msg['Cc'] = '%s' % changer_email
+                smtp = smtplib.SMTP('localhost')
+                smtp.sendmail(EMAIL_SENDER, receivers,
+                          msg.as_string())
+                logging.info('%s mailed about %s' % (receivers, subject))
+                smtp.quit()
+                # add signer, problem, pkg, version to notifications csv file
+                with open(NOTIFICATIONS, 'a') as notify_file:
+                    for bucket in spph_buckets[rname][spph]['buckets']:
+                        notify_file.write('%s, %s, %s, %s\n' % (signer.name,
+                            bucket, pkg, version))
+            if 'rate' in spph_buckets[rname][spph]:
+                # see if they have been emailed about the increased rate
+                # for this package version before
+                notices = []
+                if signer_name in notifications:
+                    notices = notifications[signer_name]
+                if ('increased-rate', pkg, version) in notices:
+                    continue
+                receivers = []
+                msg = MIMEText(i_body % (pkg, version, rname,
+                    spph_buckets[rname][spph]['rate'][1]) + remedy)
+                subject = '[%s/%s] Increase in crash rate' % (rname, pkg)
+                msg['Subject'] = subject
+                msg['From'] = EMAIL_SENDER
+                receivers.append(signer_email)
+                msg['To'] = signer_email
+                if changer != signer and changer.is_valid:
+                   changer_email = get_primary_email(changer)
+                   if changer_email:
+                        receivers.append(changer_email)
+                        msg['Cc'] = '%s' % changer_email
+                smtp = smtplib.SMTP('localhost')
+                smtp.sendmail(EMAIL_SENDER, receivers,
+                          msg.as_string())
+                logging.info('%s mailed about %s' % (receivers, subject))
+                # add signer, increased-rate, pkg, version to
+                # notifications csv
+                with open(NOTIFICATIONS, 'a') as notify_file:
+                    notify_file.write('%s, increased-rate, %s, %s\n' %
+                        (signer.name, pkg, version))
+                smtp.quit()
+
+def new_buckets(archive, release, src_pkg, version):
+    # can't use created_since here because it have may been uploaded
+    # before the release date
+    spph = archive.getPublishedSources(distro_series=release,
+        source_name=src_pkg, exact_match=True)
+    pubs = [(ph.date_published, ph.source_package_version) for ph in spph
+            if ph.status != 'Deleted' and ph.pocket != 'Backports'
+            and ph.pocket != 'Proposed'
+            and ph.date_published is not None]
+    pubs = sorted(pubs)
+    # it is possible for the same version to appear multiple times
+    numbers = set([pub[1] for pub in pubs])
+    versions = sorted(numbers, cmp=apt.apt_pkg.version_compare)
+    # it never appeared in release e.g. cedarview-drm-drivers in precise
+    try:
+        previous_version = versions[-2]
+    except IndexError:
+        return False
+    new_version = versions[-1]
+    new_buckets_url = '%spackage-version-new-buckets/?format=json&' % \
+        (BASE_ERRORS_URL) + \
+        'package=%s&previous_version=%s&new_version=%s' % \
+        (quote(src_pkg), quote(previous_version), quote(new_version))
+    new_buckets_file = urlopen(new_buckets_url)
+    # LP: #1193022 - 404 returned when a package version is not found
+    if new_buckets_file.getcode() == 404:
+        logging.error('404 with %s' % new_buckets_url)
+        return False
+    try:
+        new_buckets_data = json.load(new_buckets_file)
+    except json.decoder.JSONDecodeError:
+        logging.error("Error decoding %s" % new_buckets_url)
+        return False
+    if 'error_message' in new_buckets_data.keys():
+        logging.error('Error getting new buckets at %s' % new_buckets_url)
+        return False
+    if len(new_buckets_data['objects']) == 0:
+        return False
+    buckets = []
+    for bucket in new_buckets_data['objects']:
+        # In the event that package install failures are not useful
+        #if 'dpkg: error' in bucket['function']:
+        #    continue
+        # Skip failed buckets as they don't have useful tracebacks
+        if 'failed:' in bucket['function']:
+            logging.info('Skipped failed to retrace bucket %s' %
+                bucket['web_link'])
+            continue
+        buckets.append(bucket['web_link'])
+    return buckets
+
+def crash_rate_increase(release_version, src_pkg, version):
+    release = 'Ubuntu ' + release_version
+    # Is this not being package version specific a problem?
+    rate_url = BASE_ERRORS_URL + 'package-rate-of-crashes/?format=json' + \
+        '&release=%s&package=%s' % \
+        (quote(release), quote(src_pkg))
+    rate_file = urlopen(rate_url)
+    # LP: #1193022 - 404 returned when a package version is not found
+    if rate_file.getcode() == 404:
+        logging.error('404 with %s' % rate_url)
+        return False
+    rate_data = json.load(rate_file)
+    if 'error_message' in rate_data.keys():
+        logging.error('Error getting rate at %s' % rate_url)
+        return False
+    # this may not be useful if the buckets creating the increase have
+    # failed to retrace
+    for data in rate_data['objects']:
+        if data['increase']:
+            previous_amount = data['previous_average']
+            # appears in errors r439
+            if 'difference' in data:
+                increase = data['difference']
+            elif 'this_count' in data:
+            # 2013-06-17 this can be negative due to the portion of the
+            # day math (we take the average crashes and multiple them by
+            # the fraction of hours that have passed so far in the day)
+                current_amount = data['this_count']
+                increase = current_amount - previous_amount
+            # 2013-06-20 - Fix errors api to add this
+            link = data['web_link'] + '&version=%s' % version
+            return(increase, link)
+
+def main():
+    #  TODO: make email code less redundant
+    #  TODO: Determine how to override an increased rate
+    #  TODO: modify HTTP_USER_AGENT (both versions of urllib)
+    #  TODO: Open bugs for regressions when false positives reduced
+    #  TODO: determine if starting p-u-p over from 0% is an issue
+    ubuntu = launchpad.distributions['ubuntu']
+    archive = ubuntu.getArchive(name='primary')
+    options.archive = archive
+
+    overrides = defaultdict(list)
+    override_file = csv.reader(open(OVERRIDES, 'r'))
+    for row in override_file:
+        # package, version, problem
+        if row[0].startswith('#'):
+            continue
+        package = row[0].strip()
+        version = row[1].strip()
+        problem = row[2].strip()
+        overrides[(package, version)].append(problem)
+
+    releases = []
+    for series in ubuntu.series:
+        if series.active:
+            if series.status == 'Active Development':
+                continue
+            releases.append(series)
+    releases.reverse()
+    issues = {}
+    for release in releases:
+        rname = release.name
+        rvers = release.version
+        issues[rname] = OrderedDict()
+        # XXX - starting with raring
+        if rname != 'raring':
+            continue
+        # XXX - only look at updates since 21/06/2013
+        start_date = datetime.datetime(2013, 6, 21, 0, 0, 0, 0)
+        pub_sources = archive.getPublishedSources(
+            created_since_date=start_date,
+            pocket='Updates', status='Published', distro_series=release)
+        sorted_pub_sources = sorted([(ps.date_published, ps)
+            for ps in pub_sources if ps.date_published is not None])
+        for date, pub_source in sorted_pub_sources:
+            src_pkg = pub_source.source_package_name
+            version = pub_source.source_package_version
+            problems = new_buckets(archive, release, src_pkg, version)
+            if problems:
+                if (src_pkg, version) in overrides:
+                    not_overrode = set(problems).difference(
+                        set(overrides[(src_pkg, version)]))
+                    if len(not_overrode) > 0:
+                        issues[rname][pub_source] = {}
+                        issues[rname][pub_source]['buckets'] = not_overrode
+                else:
+                    issues[rname][pub_source] = {}
+                    issues[rname][pub_source]['buckets'] = problems
+            rate_increase = crash_rate_increase(rvers, src_pkg, version)
+            if rate_increase:
+                if pub_source not in issues[rname]:
+                    issues[rname][pub_source] = {}
+                issues[rname][pub_source]['rate'] = rate_increase
+            pups = [pb.phased_update_percentage
+                    for pb in pub_source.getPublishedBinaries()
+                    if pb.phased_update_percentage]
+            if pups:
+                if pub_source not in issues[rname]:
+                    issues[rname][pub_source] = {}
+                issues[rname][pub_source]['pup'] = pups[0]
+            suite = rname + '-updates'
+            if pub_source not in issues[rname]:
+                continue
+            elif ('rate' not in issues[rname][pub_source] and
+                  'buckets' not in issues[rname][pub_source] and
+                  pups):
+                # there is not an error so increment the phasing
+                current_pup =  issues[rname][pub_source]['pup']
+                new_pup = current_pup + PUP_INCREMENT
+                if not options.no_act:
+                    set_pup(current_pup, new_pup, release, suite, src_pkg)
+                issues[rname][pub_source]['pup'] = new_pup
+            elif pups:
+                # there is an error and pup is not None so stop the phasing
+                current_pup =  issues[rname][pub_source]['pup']
+                issues[rname][pub_source]['previous_pup'] = current_pup
+                new_pup = 0
+                if (not options.no_act and
+                        issues[rname][pub_source]['pup'] != 0):
+                    set_pup(current_pup, new_pup, release, suite, src_pkg)
+                issues[rname][pub_source]['pup'] = new_pup
+    generate_html_report(releases, issues)
+    if options.email:
+        create_email_notifications(releases, issues)
+
+if __name__ == '__main__':
+    start_time = time.time()
+    BASE_ERRORS_URL = 'https://errors.ubuntu.com/api/1.0/'
+    LOCAL_ERRORS_URL = 'http://10.0.3.182/api/1.0/'
+    LP_BASE_URL = 'https://launchpad.net'
+    OVERRIDES = 'phased-updates-overrides.txt'
+    NOTIFICATIONS = 'phased-updates-emails.txt'
+    EMAIL_SENDER = '[e-mail]'
+    PUP_INCREMENT = 10
+    parser = OptionParser(usage = "usage: %prog [options]")
+    parser.add_option(
+        "-l", "--launchpad", dest="launchpad_instance", default="production")
+    parser.add_option(
+        "-n", "--no-act", default=False, action="store_true",
+        help="do not modify phased update percentages")
+    parser.add_option(
+        "-e", "--email", default=False, action="store_true",
+        help="send email notifications to uploaders")
+    parser.add_option(
+        "-f", "--fully-phased", default=False, action="store_true",
+        help="show packages which have been fully phased")
+    options, args = parser.parse_args()
+    if options.launchpad_instance != 'production':
+        LP_BASE_URL = 'https://%s.launchpad.net' % options.launchpad_instance
+    launchpad = Launchpad.login_with(
+        'phased-updater', options.launchpad_instance, version='devel')
+    logging.basicConfig(filename='phased-updates.log',
+        format='%(asctime)s - %(levelname)s - %(message)s',
+        level=logging.INFO)
+    logging.info('Starting phased-updater')
+    main()
+    end_time = time.time()
+    logging.info("Elapsed time was %g seconds" % (end_time - start_time))