Improve scheduler log messages

* The "Adding .. event" log messages are redundant -- whatever is adding the
  event logs it just as well, and it makes filtering for Scheduler messages
  difficult.  Remove them.
* The gerrit/github connections log both the driver and connection name.
  the driver can be inferred from the connection, and very frequently
  this just ends up saying "Scheduling gerrit event from gerrit" which
  is weird.  Remove the driver name.
* Make the pipeline logs say which pipeline they are for.  This is way more
  useful than the manager name (which is implied by the pipeline name anyway).

Change-Id: I8fcaef87ddcd8428776ee76a4519e4764f2d9c5b

zuul/connection/__init__.py

@@ -46,10 +46,9 @@ class BaseConnection(object, metaclass=abc.ABCMeta):
 
     def logEvent(self, event):
         self.log.debug(
-            'Scheduling {driver} event from {connection}: {event}'.format(
-                driver=self.driver.name,
+            'Scheduling event from {connection}: {event}'.format(
                 connection=self.connection_name,
-                event=event.type))
+                event=event))
         try:
             if self.statsd:
                 self.statsd.incr(

zuul/manager/__init__.py

@@ -42,9 +42,8 @@ class StaticChangeQueueContextManager(object):
 class PipelineManager(object):
     """Abstract Base Class for enqueing and processing Changes in a Pipeline"""
 
-    log = logging.getLogger("zuul.PipelineManager")
-
     def __init__(self, sched, pipeline):
+        self.log = logging.getLogger("zuul.Pipeline.%s" % (pipeline.name,))
         self.sched = sched
         self.pipeline = pipeline
         self.event_filters = []

zuul/manager/dependent.py

@@ -10,8 +10,6 @@
 # License for the specific language governing permissions and limitations
 # under the License.
 
-import logging
-
 from zuul import model
 from zuul.manager import PipelineManager, StaticChangeQueueContextManager
 from zuul.manager import DynamicChangeQueueContextManager
@@ -25,7 +23,6 @@ class DependentPipelineManager(PipelineManager):
     using the Optmistic Branch Prediction logic with Nearest Non-Failing Item
     reparenting algorithm for handling errors.
     """
-    log = logging.getLogger("zuul.DependentPipelineManager")
     changes_merge = True
 
     def __init__(self, *args, **kwargs):

zuul/manager/independent.py

@@ -10,8 +10,6 @@
 # License for the specific language governing permissions and limitations
 # under the License.
 
-import logging
-
 from zuul import model
 from zuul.manager import PipelineManager, DynamicChangeQueueContextManager
 
@@ -19,7 +17,6 @@ from zuul.manager import PipelineManager, DynamicChangeQueueContextManager
 class IndependentPipelineManager(PipelineManager):
     """PipelineManager that puts every Change into its own ChangeQueue."""
 
-    log = logging.getLogger("zuul.IndependentPipelineManager")
     changes_merge = False
 
     def _postConfig(self, layout):

zuul/scheduler.py

@@ -262,22 +262,16 @@ class Scheduler(threading.Thread):
         self.zk = zk
 
     def addEvent(self, event):
-        self.log.debug("Adding trigger event: %s" % event)
         self.trigger_event_queue.put(event)
         self.wake_event.set()
-        self.log.debug("Done adding trigger event: %s" % event)
 
     def onBuildStarted(self, build):
-        self.log.debug("Adding start event for build: %s" % build)
         build.start_time = time.time()
         event = BuildStartedEvent(build)
         self.result_event_queue.put(event)
         self.wake_event.set()
-        self.log.debug("Done adding start event for build: %s" % build)
 
     def onBuildCompleted(self, build, result, result_data):
-        self.log.debug("Adding complete event for build: %s result: %s" % (
-            build, result))
         build.end_time = time.time()
         build.result_data = result_data
         # Note, as soon as the result is set, other threads may act
@@ -316,20 +310,15 @@ class Scheduler(threading.Thread):
         event = BuildCompletedEvent(build)
         self.result_event_queue.put(event)
         self.wake_event.set()
-        self.log.debug("Done adding complete event for build: %s" % build)
 
     def onMergeCompleted(self, build_set, merged, updated,
                          commit, files, repo_state):
-        self.log.debug("Adding merge complete event for build set: %s" %
-                       build_set)
         event = MergeCompletedEvent(build_set, merged,
                                     updated, commit, files, repo_state)
         self.result_event_queue.put(event)
         self.wake_event.set()
 
     def onNodesProvisioned(self, req):
-        self.log.debug("Adding nodes provisioned event for build set: %s" %
-                       req.build_set)
         event = NodesProvisionedEvent(req)
         self.result_event_queue.put(event)
         self.wake_event.set()