From ca15aff82ba9c1baeeec6f729ea86d6482b230b6 Mon Sep 17 00:00:00 2001 From: Karsten Hopp Date: Tue, 5 Apr 2016 14:45:56 +0200 Subject: [PATCH] add --logfile parameter, no behaviour changes if omitted --- util/koji-shadow | 195 ++++++++++++++++++++++++++++++----------------- 1 file changed, 124 insertions(+), 71 deletions(-) diff --git a/util/koji-shadow b/util/koji-shadow index 06244413..cbc27f44 100755 --- a/util/koji-shadow +++ b/util/koji-shadow @@ -1,7 +1,7 @@ #!/usr/bin/python # koji-shadow: a tool to shadow builds between koji instances -# Copyright (c) 2007-2014 Red Hat, Inc. +# 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 @@ -20,6 +20,7 @@ # Authors: # Mike McLean # Dennis Gilmore +# Karsten Hopp try: import krbV @@ -46,6 +47,7 @@ import rpm # better to time out than to stall socket.setdefaulttimeout(180) #XXX - too short? +logfile = None OptionParser = optparse.OptionParser if optparse.__version__ == "1.4.1+": @@ -62,6 +64,11 @@ 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""" @@ -140,6 +147,8 @@ def get_options(): 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, @@ -734,20 +743,20 @@ class BuildTracker(object): head = " " * depth for ignored in self.ignorelist: if (build.name == ignored) or fnmatch.fnmatch(build.name, ignored): - print "%sIgnored Build: %s%s" % (head, build.nvr, tail) + 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: - print "%sGreylisted build %s%s" % (head, build.nvr, tail) + 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: - print "%sBlocked build %s%s" % (head, build.nvr, tail) + log ("%sBlocked build %s%s" % (head, build.nvr, tail)) build.setState('blocked') return build #make sure we dont have the build name protected @@ -757,29 +766,29 @@ class BuildTracker(object): if replace: build.substitute = replace if depth > 0: - print "%sDep replaced: %s->%s" % (head, build.nvr, replace) + 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 - print "%sNewer build replaced: %s->%s" % (head, build.nvr, latestBuild.nvr) + log ("%sNewer build replaced: %s->%s" % (head, build.nvr, latestBuild.nvr)) return build else: - print "%sProtected Build: %s" % (head, build.nvr) + log ("%sProtected Build: %s" % (head, build.nvr)) if build.state == "common": #we're good if build.rebuilt: - print "%sCommon build (rebuilt) %s%s" % (head, build.nvr, tail) + log ("%sCommon build (rebuilt) %s%s" % (head, build.nvr, tail)) else: - print "%sCommon build %s%s" % (head, build.nvr, tail) + log ("%sCommon build %s%s" % (head, build.nvr, tail)) elif build.state == 'pending': - print "%sRebuild in progress: %s%s" % (head, build.nvr, tail) + 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 - print "%sWarning: build exists, but is invalid: %s%s" % (head, build.nvr, tail) + 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 @@ -787,27 +796,27 @@ class BuildTracker(object): 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(): - print "%sSkipping archful build: %s" % (head, build.nvr) + log ("%sSkipping archful build: %s" % (head, build.nvr)) elif build.state == "noroot": #Can't rebuild it, this is what substitutions are for - print "%sWarning: no buildroot data for %s%s" % (head, build.nvr, tail) + log ("%sWarning: no buildroot data for %s%s" % (head, build.nvr, tail)) elif build.state == 'brokendeps': #should not be possible at this point - print "Error: build reports brokendeps state before dep scan" + log ("Error: build reports brokendeps state before dep scan") elif build.state == "missing": #scan its deps - print "%sMissing build %s%s. Scanning deps..." % (head, build.nvr, tail) + 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: - print "%s Adding local Dep %s%s" % (head, dep, tail) + log ("%s Adding local Dep %s%s" % (head, dep, tail)) extradep = LocalBuild(info) newdeps.append(extradep) else: - print "%s Warning: could not find build for %s" % (head, dep) + 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) @@ -821,7 +830,7 @@ class BuildTracker(object): self.scanBuild(dep2.id, from_build=build, depth=depth+1, tag=tag) elif dep2 is None: #dep is missing on both local and remote - print "%sSubstitute dep unavailable: %s" % (head, dep2.nvr) + log ("%sSubstitute dep unavailable: %s" % (head, dep2.nvr)) #no point in continuing break #otherwise dep2 should be LocalBuild instance @@ -829,7 +838,7 @@ class BuildTracker(object): elif dep.state in ('broken', 'brokendeps', 'noroot', 'blocked'): #no point in continuing build.setState('brokendeps') - print "%sCan't rebuild %s, %s is %s" % (head, build.nvr, dep.nvr, dep.state) + log ("%sCan't rebuild %s, %s is %s" % (head, build.nvr, dep.nvr, dep.state)) newdeps = None break else: @@ -857,11 +866,11 @@ class BuildTracker(object): if options.first_one: return except (socket.timeout, socket.error): - print "retry" + log ("retry") continue break else: - print "Error: unable to scan %(name)s-%(version)s-%(release)s" % build + log ("Error: unable to scan %(name)s-%(version)s-%(release)s" % build) continue def _importURL(self, url, fn): @@ -874,7 +883,7 @@ class BuildTracker(object): try: koji.ensuredir(os.path.dirname(dst)) os.chown(os.path.dirname(dst), 48, 48) #XXX - hack - print "Downloading %s to %s" % (url, dst) + log ("Downloading %s to %s" % (url, dst)) fsrc = urllib2.urlopen(url) fdst = file(fn, 'w') shutil.copyfileobj(fsrc, fdst) @@ -887,24 +896,24 @@ class BuildTracker(object): #for now, though, just use uploadWrapper koji.ensuredir(options.workpath) dst = "%s/%s" % (options.workpath, fn) - print "Downloading %s to %s..." % (url, dst) + log ("Downloading %s to %s..." % (url, dst)) fsrc = urllib2.urlopen(url) fdst = file(dst, 'w') shutil.copyfileobj(fsrc, fdst) fsrc.close() fdst.close() - print "Uploading %s..." % dst + 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: - print "No srpm for build %s, skipping import" % build.nvr + log ("No srpm for build %s, skipping import" % build.nvr) #TODO - support no-src imports here return False if not options.remote_topurl: - print "Skipping import of %s, remote_topurl not specified" % build.nvr + 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) @@ -933,24 +942,24 @@ class BuildTracker(object): """Rebuild a remote build using closest possible buildroot""" #first check that we can if build.state != 'missing': - print "Can't rebuild %s. state=%s" % (build.nvr, build.state) + 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: - # print "Missing dependency %i for %s. Not scanned?" % (build_id, build.nvr) + # log ("Missing dependency %i for %s. Not scanned?" % (build_id, build.nvr)) # return # if dep.state != 'common': - # print "Dependency missing for %s: %s (%s)" % (build.nvr, dep.nvr, dep.state) + # 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: - print "Can't rebuild %s" % build.nvr + log ("Can't rebuild %s" % build.nvr) return if options.test: - print "Skipping rebuild of %s (test mode)" % build.nvr + log ("Skipping rebuild of %s (test mode)" % build.nvr) return #check/create tag our_tag = "SHADOWBUILD-%s" % build.br_tag @@ -979,7 +988,7 @@ class BuildTracker(object): else: parents = session.getInheritanceData(taginfo['id']) if parents: - print "Warning: shadow build tag has inheritance" + log ("Warning: shadow build tag has inheritance") #check package list pkgs = {} for pkg in session.listPackages(tagID=taginfo['id']): @@ -1035,7 +1044,7 @@ class BuildTracker(object): build_group = group else: # we should have no other groups but build - print "Warning: found stray group: %s" % group + 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 @@ -1046,7 +1055,7 @@ class BuildTracker(object): #no group deps needed/allowed drop_deps = [(g['name'], 1) for g in build_group['grouplist']] if drop_deps: - print "Warning: build group had deps: %r" % build_group + log ("Warning: build group had deps: %r" % build_group) else: add_pkgs = build.base drop_pkgs = [] @@ -1086,17 +1095,17 @@ class BuildTracker(object): # [?] use remote SCM url (if avail)? src = build.getSource() if not src: - print "Couldn't get source for %s" % build.nvr + log ("Couldn't get source for %s" % build.nvr) return None #wait for repo task - print "Waiting on newRepo task %i" % task_id + 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'): - print "Error: failed to generate repo" + log ("Error: failed to generate repo") return None #add a timeout? #TODO ...and verify repo @@ -1106,17 +1115,18 @@ class BuildTracker(object): return task_id def report(self): - print "-- %s --" % time.asctime() + brokenpackage = {} + thispackageblocks = {} 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) - print "%s: %i (+%i replaced)" % (state, len(not_replaced), n_replaced) - if not_replaced and len(not_replaced) < 8: - print '', ' '.join([b.nvr for b in not_replaced]) - #generate a report of the most frequent problem deps - problem_counts = {} + for b in not_replaced: + if not b.nvr in brokenpackage: + brokenpackage.update({b.nvr:[b.nvr]}) + else: + brokenpackage[b.nvr].append(b.nvr) for build in self.state_idx['brokendeps'].values(): for dep_id in build.deps: dep = self.builds.get(dep_id) @@ -1137,16 +1147,46 @@ class BuildTracker(object): 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 dep.state == 'broken': + brokenpackage[dep.nvr].append(build.nvr) + elif dep.state == 'brokendeps': + found = 0; + for i in brokenpackage: + if dep.nvr in brokenpackage[i]: + brokenpackage[i] += [build.nvr] + found = 1 + if found == 0: + if not dep.nvr in thispackageblocks: + thispackageblocks.update({dep.nvr:[build.nvr]}) + else: + if len(thispackageblocks[dep.nvr]) > 100: + thispackageblocks[dep.nvr].append('') + else: + thispackageblocks[dep.nvr].append(build.nvr) + # group all brokendeps + for package in thispackageblocks: + for blockedpackage in thispackageblocks: + if package in thispackageblocks[blockedpackage]: + thispackageblocks[blockedpackage] += thispackageblocks[package] + #log("thispackageblocks: %s" % thispackageblocks) + for package in thispackageblocks: + for blockedpackage in brokenpackage: + if package in brokenpackage[blockedpackage]: + if len(brokenpackage[blockedpackage]) > 500: + continue + else: + brokenpackage[blockedpackage] += thispackageblocks[package] + for package in brokenpackage: +# Remove duplicates, use 'set' as order isn't important: + brokenpackage[package] = set(brokenpackage[package]) + log("brokenpackage: %s %s" % (package, brokenpackage[package])) + order = [(len(c), nvr) for (nvr, c) in brokenpackage.iteritems()] if order: order.sort() order.reverse() - #print top 5 problems - print "-- top problems --" - for (c, nvr) in order[:5]: - print " %s (%i)" % (nvr, c) + log("-- top broken packages --") + for (c, nvr) in order[:20]: + log(" %s (%i)" % (nvr, c)) def report_brief(self): N = len(self.builds) @@ -1154,12 +1194,12 @@ class BuildTracker(object): states.sort() parts = ["%s: %i" % (s, len(self.state_idx[s])) for s in states] parts.append("total: %i" % N) - print ' '.join(parts) + log (' '.join(parts)) def _print_builds(self, mylist): """small helper function for output""" for build in mylist: - print " %s (%s)" % (build.nvr, build.state) + log (" %s (%s)" % (build.nvr, build.state)) def checkJobs(self, tag=None): """Check outstanding jobs. Return true if anything changes""" @@ -1167,42 +1207,42 @@ class BuildTracker(object): for build_id, build in self.state_idx['pending'].items(): #check pending builds if not build.task_id: - print "No task id recorded for %s" % build.nvr + log ("No task id recorded for %s" % build.nvr) build.updateState() ret = True info = session.getTaskInfo(build.task_id) if not info: - print "No such task: %i (build %s)" % (build.task_id, build.nvr) + 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'): - print "Task %i is %s (build %s)" % (build.task_id, state, build.nvr) + 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': - print "Task %i complete (build %s)" % (build.task_id, build.nvr) + 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': - print "Task %i finished, but %s still missing" \ - % (build.task_id, build.nvr) + 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: - #print "No revised deplist yet for %s" % build.nvr + #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: - print "Can't rebuild %s, missing %i deps" % (build.nvr, len(problem)) + log ("Can't rebuild %s, missing %i deps" % (build.nvr, len(problem))) build.setState('brokendeps') self._print_builds(problem) return False @@ -1210,7 +1250,7 @@ class BuildTracker(object): if x.state not in ('common', 'local')] if not_common: #could be missing or still building or whatever - #print "Still missing %i revised deps for %s" % (len(not_common), build.nvr) + #log ("Still missing %i revised deps for %s" % (len(not_common), build.nvr)) return False #otherwise, we should be good to rebuild return True @@ -1228,7 +1268,7 @@ class BuildTracker(object): if not self.checkBuildDeps(build): continue #otherwise, we should be good to rebuild - print "rebuild: %s" % build.nvr + log ("rebuild: %s" % build.nvr) task_id = self.rebuild(build) ret = True if options.test: @@ -1236,7 +1276,7 @@ class BuildTracker(object): build.setState('common') elif not task_id: #something went wrong setting up the rebuild - print "Did not get a task for %s" % build.nvr + log ("Did not get a task for %s" % build.nvr) build.setState('broken') else: # build might not show up as 'BUILDING' immediately, so we @@ -1245,13 +1285,13 @@ class BuildTracker(object): build.setState('pending') if options.max_jobs and len(self.state_idx['pending']) >= options.max_jobs: if options.debug: - print "Maximum number of jobs reached." + log ("Maximum number of jobs reached.") break return ret def runRebuilds(self, tag=None): """Rebuild missing builds""" - print "Determining rebuild order" + 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']) @@ -1267,37 +1307,50 @@ class BuildTracker(object): time.sleep(30) continue self.report_brief() - print "Rebuilt %i builds" % (len(self.state_idx['common']) - initial_avail) + 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) - print "tagged %s to %s" % (nvr, tag) + log ("tagged %s to %s" % (nvr, tag)) except koji.TagError: - print "NOTICE: %s already tagged in %s" % (nvr, tag) + 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: - print "Tag is required" + log ("Tag is required") return else: - print "Working on tag %s" % (tag) + 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__": @@ -1331,7 +1384,7 @@ if __name__ == "__main__": # else: # exctype, value = sys.exc_info()[:2] # rv = 1 - # print "%s: %s" % (exctype, value) + # log ("%s: %s" % (exctype, value)) try: session.logout() except: