#!/usr/bin/python

# koji-shadow: a tool to shadow builds between koji instances
# Copyright (c) 2007-2016 Red Hat, Inc.
#
#    Koji is free software; you can redistribute it and/or
#    modify it under the terms of the GNU Lesser General Public
#    License as published by the Free Software Foundation;
#    version 2.1 of the License.
#
#    This software 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
#    Lesser General Public License for more details.
#
#    You should have received a copy of the GNU Lesser General Public
#    License along with this software; if not, write to the Free Software
#    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
#
# Authors:
#       Mike McLean <mikem@redhat.com>
#       Dennis Gilmore <dennis@ausil.us>
#       Karsten Hopp <karsten@redhat.com>

try:
    import krbV
except ImportError:  # pragma: no cover
    pass
import koji
import ConfigParser
import fnmatch
import optparse
import os
import pprint
import random
import shutil
import socket   # for socket.error and socket.setdefaulttimeout
import string
import sys
import time
import urllib2
import urlgrabber.grabber as grabber
import xmlrpclib  # for ProtocolError and Fault
import rpm

# koji.fp.o keeps stalling, probably network errors...
# better to time out than to stall
socket.setdefaulttimeout(180)  #XXX - too short?

logfile = None

OptionParser = optparse.OptionParser
if optparse.__version__ == "1.4.1+":
    def _op_error(self, msg):
        self.print_usage(sys.stderr)
        msg = "%s: error: %s\n" % (self._get_prog_name(), msg)
        if msg:
            sys.stderr.write(msg)
        sys.exit(2)
    OptionParser.error = _op_error


def _(args):
    """Stub function for translation"""
    return args

def log(str):
    global logfile
    print("%s" % str)
    if logfile is not None:
        os.write(logfile, "%s\n" % str)

class SubOption(object):
    """A simple container to help with tracking ConfigParser data"""
    pass

def get_options():
    """process options from command line and config file"""

    usage = _("%prog [options]")
    parser = OptionParser(usage=usage)
    parser.add_option("-c", "--config-file", metavar="FILE",
                      help=_("use alternate configuration file"))
    parser.add_option("--keytab", help=_("specify a Kerberos keytab to use"))
    parser.add_option("--principal", help=_("specify a Kerberos principal to use"))
    parser.add_option("--krbservice", help=_("the service name of the"
                                             " principal being used by the hub"))
    parser.add_option("--runas", metavar="USER",
             help=_("run as the specified user (requires special privileges)"))
    parser.add_option("--user", help=_("specify user"))
    parser.add_option("--password", help=_("specify password"))
    parser.add_option("--krb-rdns", action="store_true", default=False,
                      help=_("get reverse dns FQDN for krb target"))
    parser.add_option("--noauth", action="store_true", default=False,
                      help=_("do not authenticate"))
    parser.add_option("-n", "--test", action="store_true", default=False,
                      help=_("test mode"))
    parser.add_option("-d", "--debug", action="store_true", default=False,
                      help=_("show debug output"))
    parser.add_option("--first-one", action="store_true", default=False,
                      help=_("stop after scanning first build -- debugging"))
    parser.add_option("--debug-xmlrpc", action="store_true", default=False,
                      help=_("show xmlrpc debug output"))
    parser.add_option("--skip-main", action="store_true", default=False,
                      help=_("don't actually run main"))
#    parser.add_option("--tag-filter", metavar="PATTERN",
#                      help=_("limit tags for pruning"))
#    parser.add_option("--pkg-filter", metavar="PATTERN",
#                      help=_("limit packages for pruning"))
    parser.add_option("--max-jobs", type="int", default=0,
                      help=_("limit number of tasks"))
    parser.add_option("--build",
                      help=_("scan just this build"))
    parser.add_option("-s", "--server",
                      help=_("url of local XMLRPC server"))
    parser.add_option("-r", "--remote",
                      help=_("url of remote XMLRPC server"))
    parser.add_option("--prefer-new", action="store_true", default=False,
                      help=_("if there is a newer build locally prefer it for deps"))
    parser.add_option("--import-noarch-only", action="store_true", default=False,
                      help=_("Only import missing noarch builds"))
    parser.add_option("--import-noarch", action="store_true",
                      help=_("import missing noarch builds rather than rebuilding"))
    parser.add_option("--link-imports", action="store_true",
                      help=_("use 'import --link' functionality"))
    parser.add_option("--remote-topurl",
                      help=_("topurl for remote server"))
    parser.add_option("--workpath", default="/var/tmp/koji-shadow",
                      help=_("location to store work files"))
    parser.add_option("--auth-cert",
                      help=_("Certificate for authentication"))
    parser.add_option("--auth-ca",  # DEPRECATED and ignored
                      help=optparse.SUPPRESS_HELP)
    parser.add_option("--serverca",
                      help=_("Server CA certificate"))
    parser.add_option("--rules",
                      help=_("rules"))
    parser.add_option("--rules-greylist",
                      help=_("greylist rules"))
    parser.add_option("--rules-blacklist",
                      help=_("blacklist rules"))
    parser.add_option("--rules-ignorelist",
                      help=_("Rules: list of packages to ignore"))
    parser.add_option("--rules-excludelist",
                      help=_("Rules: list of packages to are excluded using ExcludeArch or ExclusiveArch"))
    parser.add_option("--rules-includelist",
                      help=_("Rules: list of packages to always include"))
    parser.add_option("--rules-protectlist",
                      help=_("Rules: list of package names to never replace"))
    parser.add_option("--tag-build", action="store_true", default=False,
                      help=_("tag sucessful builds into the tag we are building, default is to not tag"))
    parser.add_option("--logfile",
                      help=_("file where everything gets logged"))
    parser.add_option("--arches",
                      help=_("arches to use when creating tags"))
    parser.add_option("--priority", type="int", default=5,
                      help=_("priority to set for submitted builds"))

    #parse once to get the config file
    (options, args) = parser.parse_args()

    defaults = parser.get_default_values()
    config = ConfigParser.ConfigParser()
    cf = getattr(options, 'config_file', None)
    if cf:
        if not os.access(cf, os.F_OK):
            parser.error(_("No such file: %s") % cf)
            assert False  # pragma: no cover
    else:
        cf = '/etc/koji-shadow/koji-shadow.conf'
        if not os.access(cf, os.F_OK):
            cf = None
    if not cf:
        log("no config file")
        config = None
    else:
        config.read(cf)
        #allow config file to update defaults
        for opt in parser.option_list:
            if not opt.dest:
                continue
            name = opt.dest
            alias = ('main', name)
            if config.has_option(*alias):
                log("Using option %s from config file" % (alias,))
                if opt.action in ('store_true', 'store_false'):
                    setattr(defaults, name, config.getboolean(*alias))
                elif opt.action != 'store':
                    pass
                elif opt.type in ('int', 'long'):
                    setattr(defaults, name, config.getint(*alias))
                elif opt.type in ('float'):
                    setattr(defaults, name, config.getfloat(*alias))
                else:
                    log(config.get(*alias))
                    setattr(defaults, name, config.get(*alias))
        #config file options without a cmdline equivalent
        otheropts = [
            #name, type, default
            ['keytab', None, 'string'],
            ['principal', None, 'string'],
            ['runas', None, 'string'],
            ['user', None, 'string'],
            ['password', None, 'string'],
            ['noauth', None, 'boolean'],
            ['server', None, 'string'],
            ['remote', None, 'string'],
            ['max_jobs', None, 'int'],
            ['serverca', None, 'string'],
            ['auth_cert', None, 'string'],
            ['arches', None, 'string'],
            ]


    #parse again with updated defaults
    (options, args) = parser.parse_args(values=defaults)
    options.config = config

    return options, args

time_units = {
    'second' : 1,
    'minute' : 60,
    'hour' : 3600,
    'day' : 86400,
    'week' : 604800,
}
time_unit_aliases = [
    #[unit, alias, alias, ...]
    ['week', 'weeks', 'wk', 'wks'],
    ['hour', 'hours', 'hr', 'hrs'],
    ['day', 'days'],
    ['minute', 'minutes', 'min', 'mins'],
    ['second', 'seconds', 'sec', 'secs', 's'],
]
def parse_duration(str):
    """Parse time duration from string, returns duration in seconds"""
    ret = 0
    n = None
    unit = None
    def parse_num(s):
        try:
            return int(s)
        except ValueError:
            pass
        try:
            return float(s)
        except ValueError:
            pass
        return None
    for x in str.split():
        if n is None:
            n = parse_num(x)
            if n is not None:
                continue
            #perhaps the unit is appended w/o a space
            for names in time_unit_aliases:
                for name in names:
                    if x.endswith(name):
                        n = parse_num(x[:-len(name)])
                        if n is None:
                            continue
                        unit = names[0]
                        # combined at end
                        break
                if unit:
                    break
            else:
                raise ValueError("Invalid time interval: %s" % str)
        if unit is None:
            x = x.lower()
            for names in time_unit_aliases:
                for name in names:
                    if x == name:
                        unit = names[0]
                        break
                if unit:
                    break
            else:
                raise ValueError("Invalid time interval: %s" % str)
        ret += n * time_units[unit]
        n = None
        unit = None
    return ret

def error(msg=None, code=1):
    if msg:
        sys.stderr.write(msg + "\n")
        sys.stderr.flush()
    sys.exit(code)

def warn(msg):
    sys.stderr.write(msg + "\n")
    sys.stderr.flush()

def ensure_connection(session):
    try:
        ret = session.getAPIVersion()
    except xmlrpclib.ProtocolError:
        error(_("Error: Unable to connect to server"))
    if ret != koji.API_VERSION:
        warn(_("WARNING: The server is at API version %d and the client is at "
               "%d" % (ret, koji.API_VERSION)))

def activate_session(session):
    """Test and login the session is applicable"""
    global options

    if options.noauth:
        #skip authentication
        pass
    elif options.auth_cert and options.serverca:
        # convert to absolute paths
        options.auth_cert  = os.path.expanduser(options.auth_cert)
        options.serverca  = os.path.expanduser(options.serverca)

        if os.path.isfile(options.auth_cert):
            # authenticate using SSL client cert
            session.ssl_login(cert=options.auth_cert, serverca=options.serverca, proxyuser=options.runas)
    elif options.user:
        #authenticate using user/password
        session.login()
    elif 'krbV' in sys.modules:
        try:
            if options.keytab and options.principal:
                session.krb_login(principal=options.principal, keytab=options.keytab, proxyuser=options.runas)
            else:
                session.krb_login(proxyuser=options.runas)
        except krbV.Krb5Error, e:
            error(_("Kerberos authentication failed: '%s' (%s)") % (e.args[1], e.args[0]))
        except socket.error, e:
            warn(_("Could not connect to Kerberos authentication service: '%s'") % e.args[1])
    if not options.noauth and not session.logged_in:
        error(_("Error: unable to log in"))
    ensure_connection(session)
    if options.debug:
        log("successfully connected to hub")

def _unique_path(prefix):
    """Create a unique path fragment by appending a path component
    to prefix.  The path component will consist of a string of letter and numbers
    that is unlikely to be a duplicate, but is not guaranteed to be unique."""
    # Use time() in the dirname to provide a little more information when
    # browsing the filesystem.
    # For some reason repr(time.time()) includes 4 or 5
    # more digits of precision than str(time.time())
    return '%s/%r.%s' % (prefix, time.time(),
                      ''.join([random.choice(string.ascii_letters) for i in range(8)]))


class LocalBuild(object):
    """A stand-in for substitute deps that are only available locally"""

    def __init__(self, info, tracker=None):
        self.info = info
        self.id = info['id']
        self.nvr = "%(name)s-%(version)s-%(release)s" % self.info
        self.state = 'local'


class TrackedBuild(object):

    def __init__(self, build_id, child=None, tracker=None):
        self.id = build_id
        self.tracker = tracker
        self.info = remote.getBuild(build_id)
        self.nvr = "%(name)s-%(version)s-%(release)s" % self.info
        self.name = "%(name)s" % self.info
        self.epoch = "%(epoch)s" % self.info
        self.version = "%(version)s" % self.info
        self.release = "%(release)s" % self.info
        self.srpm = None
        self.rpms = None
        self.children = {}
        self.state = None
        self.order = 0
        self.substitute = None
        if child is not None:
            #children tracks the builds that were built using this one
            self.children[child] = 1
        #see if we have it
        self.rebuilt = False
        self.updateState()
        if self.state == 'missing':
            self.rpms = remote.listRPMs(self.id)
            for rinfo in self.rpms:
                if rinfo['arch'] == 'src':
                    self.srpm = rinfo
            self.getExtraArches()
            self.getDeps() #sets deps, br_tag, base, order, (maybe state)

    def updateState(self):
        """Update state from local hub

        This is intended to be called at initialization and after a missing
        build has been rebuilt"""
        ours = session.getBuild(self.nvr)
        if ours is not None:
            state = koji.BUILD_STATES[ours['state']]
            if state == 'COMPLETE':
                self.setState("common")
                if ours['task_id']:
                    self.rebuilt = True
                return
            elif state in ('FAILED', 'CANCELED'):
                #treat these as having no build
                pass
            elif state == 'BUILDING' and ours['task_id']:
                self.setState("pending")
                self.task_id = ours['task_id']
                return
            else:
                # DELETED or BUILDING(no task)
                self.setState("broken")
                return
        self.setState("missing")

    def isNoarch(self):
        if not self.rpms:
            return False
        noarch = False
        for rpminfo in self.rpms:
            if rpminfo['arch'] == 'noarch':
                #note that we've seen a noarch rpm
                noarch = True
            elif rpminfo['arch'] != 'src':
                return False
        return noarch

    def setState(self, state):
        #log("%s -> %s" % (self.nvr, state))
        if state == self.state:
            return
        if self.state is not None and self.tracker:
            del self.tracker.state_idx[self.state][self.id]
        self.state = state
        if self.tracker:
            self.tracker.state_idx.setdefault(self.state, {})[self.id] = self

    def getSource(self):
        """Get source from remote"""
        if options.remote_topurl and self.srpm:
            #download srpm from remote
            pathinfo = koji.PathInfo(options.remote_topurl)
            url = "%s/%s" % (pathinfo.build(self.info), pathinfo.rpm(self.srpm))
            log("Downloading %s" % url)
            #XXX - this is not really the right place for this
            fsrc = urllib2.urlopen(url)
            fn = "%s/%s.src.rpm" % (options.workpath, self.nvr)
            koji.ensuredir(os.path.dirname(fn))
            fdst = file(fn, 'w')
            shutil.copyfileobj(fsrc, fdst)
            fsrc.close()
            fdst.close()
            serverdir = _unique_path('koji-shadow')
            session.uploadWrapper(fn, serverdir, blocksize=65536)
            src = "%s/%s" % (serverdir, os.path.basename(fn))
            return src
        #otherwise use SCM url
        task_id = self.info['task_id']
        if task_id:
            tinfo = remote.getTaskInfo(task_id)
            if tinfo['method'] == 'build':
                try:
                    request = remote.getTaskRequest(task_id)
                    src = request[0]
                    #XXX - Move SCM class out of kojid and use it to check for scm url
                    if src.startswith('cvs:'):
                        return src
                except:
                    pass
        #otherwise fail
        return None

    def addChild(self, child):
        self.children[child] = 1

    def getExtraArches(self):
        arches = {}
        for rpminfo in self.rpms:
            arches.setdefault(rpminfo['arch'], 1)
        self.extraArches = [a for a in arches if koji.canonArch(a) != a]

    def getBuildroots(self):
        """Return a list of buildroots for remote build"""
        brs = {}
        bad = []
        for rinfo in self.rpms:
            br_id = rinfo.get('buildroot_id')
            if not br_id:
                bad.append(rinfo)
                continue
            brs[br_id] = 1
        if brs and bad:
            log("Warning: some rpms for %s lacked buildroots:" % self.nvr)
            for rinfo in bad:
                log("    %(name)s-%(version)s-%(release)s.%(arch)s" % rinfo)
        return brs.keys()

    def getDeps(self):
        buildroots = self.getBuildroots()
        if not buildroots:
            self.setState("noroot")
            return
        buildroots.sort()
        self.order = buildroots[-1]
        seen = {}       #used to avoid scanning the same buildroot twice
        builds = {}     #track which builds we need for a rebuild
        bases = {}      #track base install for buildroots
        tags = {}       #track buildroot tag(s)
        remote.multicall = True
        unpack = []
        for br_id in buildroots:
            if br_id in seen:
                continue
            seen[br_id] = 1
            #br_info = remote.getBuildroot(br_id, strict=True)
            remote.getBuildroot(br_id, strict=True)
            unpack.append(('br_info', br_id))
            #tags.setdefault(br_info['tag_name'], 0)
            #tags[br_info['tag_name']] += 1
            #print(".")
            remote.listRPMs(componentBuildrootID=br_id)
            unpack.append(('rpmlist', br_id))
            #for rinfo in remote.listRPMs(componentBuildrootID=br_id):
            #    builds[rinfo['build_id']] = 1
            #    if not rinfo['is_update']:
            #        bases.setdefault(rinfo['name'], {})[br_id] = 1
        for (dtype, br_id), data in zip(unpack, remote.multiCall()):
            if dtype == 'br_info':
                [br_info] = data
                tags.setdefault(br_info['tag_name'], 0)
                tags[br_info['tag_name']] += 1
            elif dtype == 'rpmlist':
                [rpmlist] = data
                for rinfo in rpmlist:
                    builds[rinfo['build_id']] = 1
                    if not rinfo['is_update']:
                        bases.setdefault(rinfo['name'], {})[br_id] = 1
        # we want to record the intersection of the base sets
        # XXX - this makes some assumptions about homogeneity that, while reasonable,
        #       are not strictly required of the db.
        #       The only way I can think of to break this is if some significant tag/target
        #        changes happened during the build startup and some subtasks got the old
        #        repo and others the new one.
        base = []
        for name, brlist in bases.iteritems():
            #We want to determine for each name if that package was present
            #in /all/ the buildroots or just some.
            #Because brlist is constructed only from elements of buildroots, we
            #can simply check the length
            assert len(brlist) <= len(buildroots)
            if len(brlist) == len(buildroots):
                #each buildroot had this as a base package
                base.append(name)
        if len(tags) > 1:
            log("Warning: found multiple buildroot tags for %s: %s" % (self.nvr, tags.keys()))
            counts = [(n, tag) for tag, n in tags.iteritems()]
            sort(counts)
            tag = counts[-1][1]
        else:
            tag = tags.keys()[0]
        # due bugs in used tools mainline koji instance could store empty buildroot infos for builds
        if len(builds) == 0:
            self.setState("noroot")
        self.deps = builds
        self.revised_deps = None #BuildTracker will set this later
        self.br_tag = tag
        self.base = base


class BuildTracker(object):

    def __init__(self):
        self.rebuild_order = 0
        self.builds = {}
        self.state_idx = {}
        self.nvr_idx = {}
        for state in ('common', 'pending', 'missing', 'broken', 'brokendeps',
                     'noroot', 'blocked', 'grey'):
            self.state_idx.setdefault(state, {})
        self.scanRules()

    def scanRules(self):
        """Reads/parses rules data from the config

        This data consists mainly of
            white/black/greylist data
            substitution data
        """
        self.blacklist = None
        self.whitelist = None
        self.greylist = None
        self.ignorelist = []
        self.excludelist = []
        self.includelist = []
        self.protectlist = []
        self.substitute_idx = {}
        self.substitutions = {}
        if options.config.has_option('rules', 'whitelist'):
            self.whitelist = options.config.get('rules', 'whitelist').split()
        if options.config.has_option('rules', 'blacklist'):
            self.blacklist = options.config.get('rules', 'blacklist').split()
        if options.config.has_option('rules', 'greylist'):
            self.greylist = options.config.get('rules', 'greylist').split()
        if options.config.has_option('rules', 'ignorelist'):
            self.ignorelist = options.config.get('rules', 'ignorelist').split()
        if options.config.has_option('rules', 'excludelist'):
            self.excludelist = options.config.get('rules', 'excludelist').split()
        if options.config.has_option('rules', 'includelist'):
            self.includelist = options.config.get('rules', 'includelist').split()
        if options.config.has_option('rules', 'protectlist'):
            self.protectlist = options.config.get('rules', 'protectlist').split()

        # merge the excludelist (script generated) to the ignorelist (manually maintained)
        self.ignorelist = self.ignorelist + self.excludelist

        if options.config.has_option('rules', 'substitutions'):
            #At present this is a simple multi-line format
            #one substitution per line
            #format:
            #  missing-build  build-to-substitute
            #TODO: allow more robust substitutions
            for line in options.config.get('rules', 'substitutions').splitlines():
                line = line.strip()
                if line[:1] == "#":
                    #skip comment
                    continue
                if not line:
                    #blank
                    continue
                data = line.split()
                if len(data) != 2:
                    raise Exception("Bad substitution: %s" % line)
                match, replace = data
                self.substitutions[match] = replace

    def checkFilter(self, build, grey=None, default=True):
        """Check build against white/black/grey lists

        Whitelisting takes precedence over blacklisting. In our case, the whitelist
        is a list of exceptions to black/greylisting.

        If the build is greylisted, returns the value specified by the 'grey' parameter

        If the build matches nothing, returns the value specified in the 'default' parameter
        """
        if self.whitelist:
            for pattern in self.whitelist:
                if fnmatch.fnmatch(build.nvr, pattern):
                    return True
        if self.blacklist:
            for pattern in self.blacklist:
                if fnmatch.fnmatch(build.nvr, pattern):
                    return False
        if self.greylist:
            for pattern in self.greylist:
                if fnmatch.fnmatch(build.nvr, pattern):
                    return grey
        return default

    def rpmvercmp(self, (e1, v1, r1), (e2, v2, r2)):
        """find out which build is newer"""
        rc = rpm.labelCompare((e1, v1, r1), (e2, v2, r2))
        if rc == 1:
            #first evr wins
            return 1
        elif rc == 0:
            #same evr
            return 0
        else:
            #second evr wins
            return -1

    def newerBuild(self, build, tag):
        #XXX:  secondary arches need a policy to say if we have newer build localy it will be the substitute
        localBuilds = session.listTagged(tag, inherit=True, package=str(build.name))
        newer = None
        parentevr = (str(build.epoch), build.version, build.release)
        parentnvr = (str(build.name), build.version, build.release)
        for b in localBuilds:
            latestevr = (str(b['epoch']), b['version'], b['release'])
            newestRPM = self.rpmvercmp(parentevr, latestevr)
            if options.debug:
                log("remote evr: %s  \nlocal evr: %s \nResult: %s" % (parentevr, latestevr, newestRPM))
            if newestRPM == -1:
                newer = b
            else:
                break
        #the local is newer
        if newer is not None:
            info = session.getBuild("%s-%s-%s" % (str(newer['name']), newer['version'], newer['release']))
            if info:
                build = LocalBuild(info)
                self.substitute_idx[parentnvr] = build
                return build
        return None

    def getSubstitute(self, nvr):
        build = self.substitute_idx.get(nvr)
        if not build:
            #see if remote has it
            info = remote.getBuild(nvr)
            if info:
                #see if we're already tracking it
                build = self.builds.get(info['id'])
                if not build:
                    build = TrackedBuild(info['id'], tracker=self)
            else:
                #remote doesn't have it
                #see if we have it locally
                info = session.getBuild(nvr)
                if info:
                    build = LocalBuild(info)
                else:
                    build = None
            self.substitute_idx[nvr] = build
        return build

    def scanBuild(self, build_id, from_build=None, depth=0, tag=None):
        """Recursively scan a build and its dependencies"""
        #print build_id
        build = self.builds.get(build_id)
        if build:
            #already scanned
            if from_build:
                build.addChild(from_build.id)
            #There are situations where, we'll need to go forward anyway:
            # - if we were greylisted before, and depth > 0 now
            # - if we're being substituted and depth is 0
            if not (depth > 0 and build.state == 'grey') \
                    and not (depth == 0 and build.substitute):
                return build
        else:
            child_id = None
            if from_build:
                child_id = from_build.id
            build = TrackedBuild(build_id, child=child_id, tracker=self)
            self.builds[build_id] = build
        if from_build:
            tail = " (from %s)" % from_build.nvr
        else:
            tail = ""
        head = " " * depth
        for ignored in self.ignorelist:
            if (build.name == ignored) or fnmatch.fnmatch(build.name, ignored):
                log ("%sIgnored Build: %s%s" % (head, build.nvr, tail))
                build.setState('ignore')
                return build
        check = self.checkFilter(build, grey=None)
        if check is None:
            #greylisted builds are ok as deps, but not primary builds
            if depth == 0:
                log ("%sGreylisted build %s%s" % (head, build.nvr, tail))
                build.setState('grey')
                return build
            #get rid of 'grey' state (filter will not be checked again)
            build.updateState()
        elif not check:
            log ("%sBlocked build %s%s" % (head, build.nvr, tail))
            build.setState('blocked')
            return build
        #make sure we dont have the build name protected
        if build.name not in self.protectlist:
            #check to see if a substition applies
            replace = self.substitutions.get(build.nvr)
            if replace:
                build.substitute = replace
                if depth > 0:
                    log ("%sDep replaced: %s->%s" % (head, build.nvr, replace))
                    return build
            if options.prefer_new and (depth > 0) and (tag is not None) and not (build.state == "common"):
                latestBuild = self.newerBuild(build, tag)
                if latestBuild != None:
                    build.substitute = latestBuild.nvr
                    log ("%sNewer build replaced: %s->%s" % (head, build.nvr, latestBuild.nvr))
                    return build
        else:
            log ("%sProtected Build: %s" % (head, build.nvr))
        if build.state == "common":
            #we're good
            if build.rebuilt:
                log ("%sCommon build (rebuilt) %s%s" % (head, build.nvr, tail))
            else:
                log ("%sCommon build %s%s" % (head, build.nvr, tail))
        elif build.state == 'pending':
            log ("%sRebuild in progress: %s%s" % (head, build.nvr, tail))
        elif build.state == "broken":
            #The build already exists locally, but is somehow invalid.
            #We should not replace it automatically. An admin can reset it
            #if that is the correct thing. A substitution might also be in order
            log ("%sWarning: build exists, but is invalid: %s%s" % (head, build.nvr, tail))
        #
        #  !! Cases where importing a noarch is /not/ ok must occur
        #     before this point
        #
        elif (options.import_noarch or options.import_noarch_only) and build.isNoarch():
            self.importBuild(build, tag)
        elif options.import_noarch_only and not build.isNoarch():
            log ("%sSkipping archful build: %s" % (head, build.nvr))
        elif build.state == "noroot":
            #Can't rebuild it, this is what substitutions are for
            log ("%sWarning: no buildroot data for %s%s" % (head, build.nvr, tail))
        elif build.state == 'brokendeps':
            #should not be possible at this point
            log ("Error: build reports brokendeps state before dep scan")
        elif build.state == "missing":
            #scan its deps
            log ("%sMissing build %s%s. Scanning deps..." % (head, build.nvr, tail))
            newdeps = []
            # include extra local builds as deps.
            if self.includelist:
                for dep in self.includelist:
                    info = session.getBuild(dep)
                    if info:
                        log ("%s Adding local Dep %s%s" % (head, dep, tail))
                        extradep = LocalBuild(info)
                        newdeps.append(extradep)
                    else:
                        log ("%s Warning: could not find build for %s" % (head, dep))
            #don't actually set build.revised_deps until we finish the dep scan
            for dep_id in build.deps:
                dep = self.scanBuild(dep_id, from_build=build, depth=depth+1, tag=tag)
                if dep.name in self.ignorelist:
                    # we are not done dep solving yet.  but we dont want this dep in our buildroot
                    continue
                else:
                    if dep.substitute:
                        dep2 = self.getSubstitute(dep.substitute)
                        if isinstance(dep2, TrackedBuild):
                            self.scanBuild(dep2.id, from_build=build, depth=depth+1, tag=tag)
                        elif dep2 is None:
                            #dep is missing on both local and remote
                            log ("%sSubstitute dep unavailable: %s" % (head, dep2.nvr))
                            #no point in continuing
                            break
                        #otherwise dep2 should be LocalBuild instance
                        newdeps.append(dep2)
                    elif dep.state in ('broken', 'brokendeps', 'noroot', 'blocked'):
                        #no point in continuing
                        build.setState('brokendeps')
                        log ("%sCan't rebuild %s, %s is %s" % (head, build.nvr, dep.nvr, dep.state))
                        newdeps = None
                        break
                    else:
                        newdeps.append(dep)
                    # set rebuild order as we go
                    # we do this /after/ the recursion, so our deps have a lower order number
                    self.rebuild_order += 1
                    build.order = self.rebuild_order
            build.revised_deps = newdeps
        #scanning takes a long time, might as well start builds if we can
        self.checkJobs(tag)
        self.rebuildMissing()
        if len(self.builds) % 50 == 0:
            self.report()
        return build

    def scanTag(self, tag):
        """Scan the latest builds in a remote tag"""
        taginfo = remote.getTag(tag)
        builds = remote.listTagged(taginfo['id'], latest=True)
        for build in builds:
            for retry in xrange(10):
                try:
                    self.scanBuild(build['id'], tag=tag)
                    if options.first_one:
                        return
                except (socket.timeout, socket.error):
                    log ("retry")
                    continue
                break
            else:
                log ("Error: unable to scan %(name)s-%(version)s-%(release)s" % build)
                continue

    def _importURL(self, url, fn):
        """Import an rpm directly from a url"""
        serverdir = _unique_path('koji-shadow')
        if options.link_imports:
            #bit of a hack, but faster than uploading
            dst = "%s/%s/%s" % (koji.pathinfo.work(), serverdir, fn)
            old_umask = os.umask(002)
            try:
                koji.ensuredir(os.path.dirname(dst))
                os.chown(os.path.dirname(dst), 48, 48) #XXX - hack
                log ("Downloading %s to %s" % (url, dst))
                fsrc = urllib2.urlopen(url)
                fdst = file(fn, 'w')
                shutil.copyfileobj(fsrc, fdst)
                fsrc.close()
                fdst.close()
            finally:
                os.umask(old_umask)
        else:
            #TODO - would be possible, using uploadFile directly, to upload without writing locally.
            #for now, though, just use uploadWrapper
            koji.ensuredir(options.workpath)
            dst = "%s/%s" % (options.workpath, fn)
            log ("Downloading %s to %s..." % (url, dst))
            fsrc = urllib2.urlopen(url)
            fdst = file(dst, 'w')
            shutil.copyfileobj(fsrc, fdst)
            fsrc.close()
            fdst.close()
            log ("Uploading %s..." % dst)
            session.uploadWrapper(dst, serverdir, blocksize=65536)
        session.importRPM(serverdir, fn)

    def importBuild(self, build, tag=None):
        '''import a build from remote hub'''
        if not build.srpm:
            log ("No srpm for build %s, skipping import" % build.nvr)
            #TODO - support no-src imports here
            return False
        if not options.remote_topurl:
            log ("Skipping import of %s, remote_topurl not specified" % build.nvr)
            return False
        pathinfo = koji.PathInfo(options.remote_topurl)
        build_url = pathinfo.build(build.info)
        url = "%s/%s" % (pathinfo.build(build.info), pathinfo.rpm(build.srpm))
        fname = "%s.src.rpm" % build.nvr
        self._importURL(url, fname)
        for rpminfo in build.rpms:
            if rpminfo['arch'] == 'src':
                #already imported above
                continue
            relpath = pathinfo.rpm(rpminfo)
            url = "%s/%s" % (build_url, relpath)
            fname = os.path.basename(relpath)
            self._importURL(url, fname)
        build.updateState()
        if options.tag_build and not tag == None:
            self.tagSuccessful(build.nvr, tag)
        return True

    def scan(self):
        """Scan based on config file"""
        to_scan = []
        alltags = remote.listTags()

    def rebuild(self, build):
        """Rebuild a remote build using closest possible buildroot"""
        #first check that we can
        if build.state != 'missing':
            log ("Can't rebuild %s. state=%s" % (build.nvr, build.state))
            return
        #deps = []
        #for build_id in build.deps:
        #    dep = self.builds.get(build_id)
        #    if not dep:
        #        log ("Missing dependency %i for %s. Not scanned?" % (build_id, build.nvr))
        #        return
        #    if dep.state != 'common':
        #        log ("Dependency missing for %s: %s (%s)" % (build.nvr, dep.nvr, dep.state))
        #        return
        #    deps.append(dep)
        deps = build.revised_deps
        if deps is None:
            log ("Can't rebuild %s" % build.nvr)
            return
        if options.test:
            log ("Skipping rebuild of %s (test mode)" % build.nvr)
            return
        #check/create tag
        our_tag = "SHADOWBUILD-%s" % build.br_tag
        taginfo = session.getTag(our_tag)
        parents = None
        if not taginfo:
            #XXX - not sure what is best here
            #how do we pick arches?  for now just hardcoded
            #XXX this call for perms is stupid, but it's all we've got
            perm_id = None
            for data in session.getAllPerms():
                if data['name'] == 'admin':
                    perm_id = data['id']
                    break
            session.createTag(our_tag, perm=perm_id, arches=options.arches)
            taginfo = session.getTag(our_tag, strict=True)
            #we don't need a target, we trigger our own repo creation and
            #pass that repo_id to the build call
            #session.createBuildTarget(taginfo['name'], taginfo['id'], taginfo['id'])
            # duplicate also extra information for a tag (eg. packagemanager setting)
            rtaginfo = remote.getTag(build.br_tag)
            if 'extra' in rtaginfo:
                opts = {}
                opts['extra'] = rtaginfo['extra']
                session.editTag2(our_tag, **opts)
        else:
            parents = session.getInheritanceData(taginfo['id'])
            if parents:
                log ("Warning: shadow build tag has inheritance")
        #check package list
        pkgs = {}
        for pkg in session.listPackages(tagID=taginfo['id']):
            pkgs[pkg['package_name']] = pkg
        missing_pkgs = []
        for dep in deps:
            name = dep.info['name']
            if name not in pkgs:
                #guess owner
                owners = {}
                for pkg in session.listPackages(pkgID=name):
                    owners.setdefault(pkg['owner_id'], []).append(pkg)
                if owners:
                    order = [(len(v), k) for k, v in owners.iteritems()]
                    order.sort()
                    owner = order[-1][1]
                else:
                    #just use ourselves
                    owner = session.getLoggedInUser()['id']
                missing_pkgs.append((name, owner))
        #check build list
        cur_builds = {}
        for binfo in session.listTagged(taginfo['id']):
            #index by name in tagging order (latest first)
            cur_builds.setdefault(binfo['name'], []).append(binfo)
        to_untag = []
        to_tag = []
        for dep in deps:
            #XXX - assuming here that there is only one dep per 'name'
            #      may want to check that this is true
            cur_order = cur_builds.get(dep.info['name'], [])
            tagged = False
            for binfo in cur_order:
                if binfo['nvr'] == dep.nvr:
                    tagged = True
                    #may not be latest now, but it will be after we do all the untagging
                else:
                    # note that the untagging keeps older builds from piling up. In a sense
                    # we're gc-pruning this tag ourselves every pass.
                    to_untag.append(binfo)
            if not tagged:
                to_tag.append(dep)
        #TODO - "add-on" packages
        #       for handling arch-specific deps that may not show up on remote
        #       e.g. elilo or similar
        #       these extra packages should be added to tag, but not the build group
        #TODO - local extra builds
        #       a configurable mechanism to add specific local builds to the buildroot
        drop_groups = []
        build_group = None
        for group in session.getTagGroups(taginfo['id']):
            if group['name'] == 'build':
                build_group = group
            else:
                # we should have no other groups but build
                log ("Warning: found stray group: %s" % group)
                drop_groups.append(group['name'])
        if build_group:
            #fix build group package list based on base of build to shadow
            needed = dict([(n, 1) for n in build.base])
            current = dict([(p['package'], 1) for p in build_group['packagelist']])
            add_pkgs = [n for n in needed if n not in current]
            drop_pkgs = [n for n in current if n not in needed]
            #no group deps needed/allowed
            drop_deps = [(g['name'], 1) for g in build_group['grouplist']]
            if drop_deps:
                log ("Warning: build group had deps: %r" % build_group)
        else:
            add_pkgs = build.base
            drop_pkgs = []
            drop_deps = []
        #update package list, tagged packages, and groups in one multicall/transaction
        #(avoid useless repo regens)
        session.multicall = True
        for name, owner in missing_pkgs:
            session.packageListAdd(taginfo['id'], name, owner=owner)
        for binfo in to_untag:
            session.untagBuildBypass(taginfo['id'], binfo['id'])
        for dep in to_tag:
            session.tagBuildBypass(taginfo['id'], dep.nvr)
            #shouldn't need force here
        #set groups data
        if not build_group:
            # build group not present. add it
            session.groupListAdd(taginfo['id'], 'build', force=True)
            #using force in case group is blocked. This shouldn't be the case, but...
        for pkg_name in drop_pkgs:
            #in principal, our tag should not have inheritance, so the remove call is the right thing
            session.groupPackageListRemove(taginfo['id'], 'build', pkg_name)
        for pkg_name in add_pkgs:
            session.groupPackageListAdd(taginfo['id'], 'build', pkg_name)
            #we never add any blocks, so forcing shouldn't be required
        #TODO - adjust extra_arches for package to build
        #get event id to facilitate waiting on repo
        #       not sure if getLastEvent is good enough
        #       short of adding a new call, perhaps use getLastEvent together with event of
        #       current latest repo for tag
        session.getLastEvent()
        results = session.multiCall(strict=True)
        event_id = results[-1][0]['id']
        #TODO - verify / check results ?
        task_id = session.newRepo(our_tag, event=event_id)
        #TODO - upload src
        #       [?] use remote SCM url (if avail)?
        src = build.getSource()
        if not src:
            log ("Couldn't get source for %s" % build.nvr)
            return None
        #wait for repo task
        log ("Waiting on newRepo task %i" % task_id)
        while True:
            tinfo = session.getTaskInfo(task_id)
            tstate = koji.TASK_STATES[tinfo['state']]
            if tstate == 'CLOSED':
                break
            elif tstate in ('CANCELED', 'FAILED'):
                log ("Error: failed to generate repo")
                return None
            #add a timeout?
        #TODO       ...and verify repo
        repo_id, event_id = session.getTaskResult(task_id)
        #kick off build
        task_id = session.build(src, None, opts={'repo_id': repo_id}, priority=options.priority)
        return task_id

    def report(self):
        log("-- %s --" % time.asctime())
        self.report_brief()
        for state in ('broken', 'noroot', 'blocked'):
            builds = self.state_idx[state].values()
            not_replaced = [b for b in builds if not b.substitute]
            n_replaced = len(builds) - len(not_replaced)
            log("%s: %i (+%i replaced)" % (state, len(not_replaced), n_replaced))
            if not_replaced and len(not_replaced) < 8:
                log(' '.join([b.nvr for b in not_replaced]))
        #generate a report of the most frequent problem deps
        problem_counts = {}
        for build in self.state_idx['brokendeps'].values():
            for dep_id in build.deps:
                dep = self.builds.get(dep_id)
                if not dep:
                    #unscanned
                    #possible because we short circuit the earlier scan on problems
                    #we don't really know if this one is a problem or not, so just
                    #skip it.
                    continue
                if dep.state in ('common', 'pending', 'missing'):
                    #not a problem
                    continue
                nvr = dep.nvr
                if dep.substitute:
                    dep2 = self.getSubstitute(dep.substitute)
                    if dep2:
                        #we have a substitution, so not a problem
                        continue
                    #otherwise the substitution is the problem
                    nvr = dep.substitute
                problem_counts.setdefault(nvr, 0)
                problem_counts[nvr] += 1
        order = [(c, nvr) for (nvr, c) in problem_counts.iteritems()]
        if order:
            order.sort()
            order.reverse()
            #print top 5 problems
            log("-- top problems --")
            for (c, nvr) in order[:5]:
                log(" %s (%i)" % (nvr, c))

    def report_brief(self):
        N = len(self.builds)
        states = self.state_idx.keys()
        states.sort()
        parts = ["%s: %i" % (s, len(self.state_idx[s])) for s in states]
        parts.append("total: %i" % N)
        log (' '.join(parts))

    def _print_builds(self, mylist):
        """small helper function for output"""
        for build in mylist:
            log ("    %s (%s)" % (build.nvr, build.state))

    def checkJobs(self, tag=None):
        """Check outstanding jobs. Return true if anything changes"""
        ret = False
        for build_id, build in self.state_idx['pending'].items():
            #check pending builds
            if not build.task_id:
                log ("No task id recorded for %s" % build.nvr)
                build.updateState()
                ret = True
            info = session.getTaskInfo(build.task_id)
            if not info:
                log ("No such task: %i (build %s)" % (build.task_id, build.nvr))
                build.updateState()
                ret = True
                continue
            state = koji.TASK_STATES[info['state']]
            if state in ('CANCELED', 'FAILED'):
                log ("Task %i is %s (build %s)" % (build.task_id, state, build.nvr))
                #we have to set the state to broken manually (updateState will mark
                #a failed build as missing)
                build.setState('broken')
                ret = True
            elif state == 'CLOSED':
                log ("Task %i complete (build %s)" % (build.task_id, build.nvr))
                if options.tag_build and not tag == None:
                    self.tagSuccessful(build.nvr, tag)
                build.updateState()
                ret = True
                if build.state != 'common':
                    log ("Task %i finished, but %s still missing" \
                            % (build.task_id, build.nvr))
        return ret

    def checkBuildDeps(self, build):
        #check deps
        if build.revised_deps is None:
            #log ("No revised deplist yet for %s" % build.nvr)
            return False
        problem = [x for x in build.revised_deps
                         if x.state in ('broken', 'brokendeps', 'noroot', 'blocked')]
        if problem:
            log ("Can't rebuild %s, missing %i deps" % (build.nvr, len(problem)))
            build.setState('brokendeps')
            self._print_builds(problem)
            return False
        not_common = [x for x in build.revised_deps
                         if x.state not in ('common', 'local')]
        if not_common:
            #could be missing or still building or whatever
            #log ("Still missing %i revised deps for %s" % (len(not_common), build.nvr))
            return False
        #otherwise, we should be good to rebuild
        return True

    def rebuildMissing(self):
        """Initiate rebuilds for missing builds, if possible.

        Returns True if any builds were attempted"""
        ret = False
        if options.max_jobs and len(self.state_idx['pending']) >= options.max_jobs:
            return ret
        missing = [(b.order, b.id, b) for b in self.state_idx['missing'].itervalues()]
        missing.sort()
        for order, build_id, build in missing:
            if not self.checkBuildDeps(build):
                continue
            #otherwise, we should be good to rebuild
            log ("rebuild: %s" % build.nvr)
            task_id = self.rebuild(build)
            ret = True
            if options.test:
                #pretend build is available
                build.setState('common')
            elif not task_id:
                #something went wrong setting up the rebuild
                log ("Did not get a task for %s" % build.nvr)
                build.setState('broken')
            else:
                # build might not show up as 'BUILDING' immediately, so we
                # set this state manually rather than by updateState
                build.task_id = task_id
                build.setState('pending')
            if options.max_jobs and len(self.state_idx['pending']) >= options.max_jobs:
                if options.debug:
                    log ("Maximum number of jobs reached.")
                break
        return ret

    def runRebuilds(self, tag=None):
        """Rebuild missing builds"""
        log ("Determining rebuild order")
        #using self.state_idx to track build states
        #make sure state_idx has at least these states
        initial_avail = len(self.state_idx['common'])
        self.report_brief()
        while True:
            if (not self.state_idx['missing'] and not self.state_idx['pending']) or \
               (options.prefer_new and not self.state_idx['pending']):
                #we're done
                break
            changed1 = self.checkJobs(tag)
            changed2 = self.rebuildMissing()
            if not changed1 and not changed2:
                time.sleep(30)
                continue
            self.report_brief()
        log ("Rebuilt %i builds" % (len(self.state_idx['common']) - initial_avail))

    def tagSuccessful(self, nvr, tag):
        """tag completed builds into final tags"""
        #TODO: check if there are other reasons why tagging may fail and handle them
        try:
            session.tagBuildBypass(tag, nvr)
            log ("tagged %s to %s" % (nvr, tag))
        except koji.TagError:
            log ("NOTICE: %s already tagged in %s" % (nvr, tag))


def main(args):
    global logfile
    tracker = BuildTracker()
    try:
        tag = args[0]
    except IndexError:
        tag = None

    if options.logfile:
        filename = options.logfile
        try:
            logfile = os.open(filename,os.O_CREAT|os.O_RDWR|os.O_APPEND, 0777)
        except:
            logfile = None
    if logfile is not None:
        log ("logging to %s" % filename)
        os.write(logfile, "\n\n========================================================================\n")

    if options.build:
        binfo = remote.getBuild(options.build, strict=True)
        tracker.scanBuild(binfo['id'], tag=tag)
    else:
        if tag is None:
            log ("Tag is required")
            return
        else:
            log ("Working on tag %s" % (tag))
            tracker.scanTag(tag)
    tracker.report()
    tracker.runRebuilds(tag)
    if logfile is not None:
        os.close(logfile)


if __name__ == "__main__":

    options, args = get_options()

    session_opts = koji.grab_session_options(options)
    session = koji.ClientSession(options.server, session_opts)
    if not options.noauth:
        activate_session(session)
    #XXX - sane auth
    #XXX - config!
    remote_opts = {'anon_retry': True}
    for k in ('debug_xmlrpc', 'debug'):
        remote_opts[k] = getattr(options, k)
    remote = koji.ClientSession(options.remote, remote_opts)
    rv = 0
    try:
        rv = main(args)
        if not rv:
            rv = 0
    except KeyboardInterrupt:
        pass
    except SystemExit:
        rv = 1
    #except:
    #    if options.debug:
    #        raise
    #    else:
    #        exctype, value = sys.exc_info()[:2]
    #        rv = 1
    #        log ("%s: %s" % (exctype, value))
    try:
        session.logout()
    except:
        pass
    sys.exit(rv)
