>From 2f61e1f8f2ba397ecaded80335d38beea79bd10b Mon Sep 17 00:00:00 2001
From: Karsten Hopp <karsten@redhat.com>
Date: Wed, 13 Feb 2013 11:54:39 +0100
Subject: [PATCH] add '--logfile <filename>' parameter for better logging

---
 util/koji-shadow | 130 ++++++++++++++++++++++++++++++++-----------------------
 1 file changed, 75 insertions(+), 55 deletions(-)

diff --git a/util/koji-shadow b/util/koji-shadow
index 1967fbd..41d034f 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-2008 Red Hat
+# Copyright (c) 2007-2013 Red Hat
 #
 #    Koji is free software; you can redistribute it and/or
 #    modify it under the terms of the GNU Lesser General Public
@@ -46,7 +46,7 @@ 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+":
@@ -63,6 +63,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"""
@@ -138,6 +143,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=_("write log into file"))
     parser.add_option("--arches",
                       help=_("arches to use when creating tags"))
 
@@ -715,20 +722,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
@@ -738,29 +745,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 not (options.build or 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
@@ -769,24 +776,24 @@ class BuildTracker(object):
             self.importBuild(build, tag)
         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)
@@ -800,7 +807,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
@@ -808,7 +815,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:
@@ -836,11 +843,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):
@@ -853,7 +860,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)
@@ -866,24 +873,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)
@@ -912,7 +919,7 @@ 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:
@@ -926,10 +933,10 @@ class BuildTracker(object):
         #    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
@@ -952,7 +959,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']):
@@ -1008,7 +1015,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
@@ -1019,7 +1026,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 = []
@@ -1059,7 +1066,7 @@ 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
@@ -1069,7 +1076,7 @@ class BuildTracker(object):
             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
@@ -1079,15 +1086,16 @@ class BuildTracker(object):
         return task_id
 
     def report(self):
-        print "-- %s --" % time.asctime()
+        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)
-            print "%s: %i (+%i replaced)" % (state, len(not_replaced), n_replaced)
+            log("%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])
+                temp = '', ' '.join([b.nvr for b in not_replaced])
+                log(temp)
         #generate a report of the most frequent problem deps
         problem_counts = {}
         for build in self.state_idx['brokendeps'].values():
@@ -1117,9 +1125,9 @@ class BuildTracker(object):
             order.sort()
             order.reverse()
             #print top 5 problems
-            print "-- top problems --"
+            log("-- top problems --")
             for (c, nvr) in order[:5]:
-                print " %s (%i)" % (nvr, c)
+                log(" %s (%i)" % (nvr, c))
 
     def report_brief(self):
         N = len(self.builds)
@@ -1127,12 +1135,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"""
@@ -1140,31 +1148,31 @@ 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):
@@ -1175,7 +1183,7 @@ class BuildTracker(object):
         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
@@ -1201,7 +1209,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:
@@ -1209,7 +1217,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
@@ -1218,13 +1226,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'])
@@ -1240,23 +1248,33 @@ 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()
     #binfo = remote.getBuild(args[0], strict=True)
     #tracker.scanBuild(binfo['id'])
     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:
+        print "logging to %s" % filename
+        os.write(logfile, "\n\n========================================================================\n")
     if options.build:
         binfo = remote.getBuild(options.build, strict=True)
         tracker.scanBuild(binfo['id'])
@@ -1265,6 +1283,8 @@ def main(args):
         tracker.scanTag(tag)
     tracker.report()
     tracker.runRebuilds(tag)
+    if logfile is not None:
+        os.close(logfile)
 
 
 if __name__ == "__main__":
-- 
1.8.1.2

