Add LoggerAdapter for executor jobs

Create a logger adapter for executor jobs that ensures that every
log entry has the job uuid associated with it.  Pass this into
the associated mergers as well, since they are also performing
interesting tasks in parallel on the executor.

The uuid is also added to the extras dict so that it's available
to logging systems which can handle extra data.

Change-Id: I28e0bcd0f030361659e5a72c162d549c1f0d6acb

zuul/executor/server.py

@@ -302,14 +302,14 @@ class ExecutorServer(object):
 
         self.job_workers = {}
 
-    def _getMerger(self, root):
+    def _getMerger(self, root, logger=None):
         if root != self.merge_root:
             cache_root = self.merge_root
         else:
             cache_root = None
         return zuul.merger.merger.Merger(root, self.connections,
                                          self.merge_email, self.merge_name,
-                                         cache_root)
+                                         cache_root, logger)
 
     def start(self):
         self._running = True
@@ -500,15 +500,22 @@ class ExecutorServer(object):
         job.sendWorkComplete(json.dumps(result))
 
 
-class AnsibleJob(object):
-    log = logging.getLogger("zuul.AnsibleJob")
+class AnsibleJobLogAdapter(logging.LoggerAdapter):
+    def process(self, msg, kwargs):
+        msg, kwargs = super(AnsibleJobLogAdapter, self).process(msg, kwargs)
+        msg = '[build: %s] %s' % (kwargs['extra']['job'], msg)
+        return msg, kwargs
 
+
+class AnsibleJob(object):
     RESULT_NORMAL = 1
     RESULT_TIMED_OUT = 2
     RESULT_UNREACHABLE = 3
     RESULT_ABORTED = 4
 
     def __init__(self, executor_server, job):
+        logger = logging.getLogger("zuul.AnsibleJob")
+        self.log = AnsibleJobLogAdapter(logger, {'job': job.unique})
         self.executor_server = executor_server
         self.job = job
         self.jobdir = None
@@ -570,7 +577,8 @@ class AnsibleJob(object):
             task.wait()
 
         self.log.debug("Job %s: git updates complete" % (self.job.unique,))
-        merger = self.executor_server._getMerger(self.jobdir.src_root)
+        merger = self.executor_server._getMerger(self.jobdir.src_root,
+                                                 self.log)
         repos = {}
         for project in args['projects']:
             self.log.debug("Cloning %s/%s" % (project['connection'],
@@ -829,7 +837,8 @@ class AnsibleJob(object):
         # the stack of changes we are testing, so check out the branch
         # tip into a dedicated space.
 
-        merger = self.executor_server._getMerger(jobdir_playbook.root)
+        merger = self.executor_server._getMerger(jobdir_playbook.root,
+                                                 self.log)
         merger.checkoutBranch(playbook['connection'], project.name,
                               playbook['branch'])
 
@@ -913,7 +922,8 @@ class AnsibleJob(object):
             # in the dependency chain for the change (in which case,
             # there is no existing untrusted checkout of it).  Check
             # out the branch tip into a dedicated space.
-            merger = self.executor_server._getMerger(trusted_root)
+            merger = self.executor_server._getMerger(trusted_root,
+                                                     self.log)
             merger.checkoutBranch(role['connection'], project.name,
                                   'master')
             orig_repo_path = os.path.join(trusted_root,

zuul/merger/merger.py

@@ -42,9 +42,12 @@ class ZuulReference(git.Reference):
 
 
 class Repo(object):
-    log = logging.getLogger("zuul.Repo")
-
-    def __init__(self, remote, local, email, username, cache_path=None):
+    def __init__(self, remote, local, email, username,
+                 cache_path=None, logger=None):
+        if logger is None:
+            self.log = logging.getLogger("zuul.Repo")
+        else:
+            self.log = logger
         self.remote_url = remote
         self.local_path = local
         self.email = email
@@ -261,10 +264,13 @@ class Repo(object):
 
 
 class Merger(object):
-    log = logging.getLogger("zuul.Merger")
-
     def __init__(self, working_root, connections, email, username,
-                 cache_root=None):
+                 cache_root=None, logger=None):
+        self.logger = logger
+        if logger is None:
+            self.log = logging.getLogger("zuul.Merger")
+        else:
+            self.log = logger
         self.repos = {}
         self.working_root = working_root
         if not os.path.exists(working_root):
@@ -300,7 +306,8 @@ class Merger(object):
                                           project_name)
             else:
                 cache_path = None
-            repo = Repo(url, path, self.email, self.username, cache_path)
+            repo = Repo(url, path, self.email, self.username, cache_path,
+                        self.logger)
 
             self.repos[key] = repo
         except Exception: