Added more logging

scripts/master/try_job_rietveld.py

Index: scripts/master/try_job_rietveld.py
diff --git a/scripts/master/try_job_rietveld.py b/scripts/master/try_job_rietveld.py
index 26c790433ee3dcaf0c686575bf70b82c39835a6d..6efdc2ce8360e89ae79826d3e2116a469cd5afd9 100644
--- a/scripts/master/try_job_rietveld.py
+++ b/scripts/master/try_job_rietveld.py
@@ -230,7 +230,7 @@ class _RietveldPollerWithCache(base.PollingChangeSource):
     pollDeferred = client.getPage(self._pending_jobs_url, agent='buildbot',
                                   timeout=2*60)
     pollDeferred.addCallback(self._ProcessResults)
-    pollDeferred.addErrback(log.err, 'error in RietveldPollerWithCache')
+    pollDeferred.addErrback(log.err, '[RPWC] error')
     return pollDeferred
 
   def setServiceParent(self, parent):
@@ -244,6 +244,8 @@ class _RietveldPollerWithCache(base.PollingChangeSource):
     # Get all BuildBot build requests.
     brdicts = yield self.master.db.buildrequests.getBuildRequests()
 
+    log.msg('[RPWC] Received build request dicts')
+
     def asNaiveUTC(dt):
       if dt is None:
         return datetime.datetime.now()
@@ -262,6 +264,7 @@ class _RietveldPollerWithCache(base.PollingChangeSource):
     # Find jobs for each buildset and add them to the processed keys cache.
     self._processed_keys = {}
     for bsid in buildsets.keys():
+      log.msg('[RPWC] Loading properties of the buildset %d' % bsid)
       bsprops = yield self.master.db.buildsets.getBuildsetProperties(bsid)
       if 'try_job_key' in bsprops:
         key = bsprops['try_job_key'][0]
@@ -323,9 +326,17 @@ class _RietveldPollerWithCache(base.PollingChangeSource):
       parsed_timestamp = datetime.datetime.strptime(job['timestamp'],
                                                     '%Y-%m-%d %H:%M:%S.%f')
       new_processed_keys[job['key']] = parsed_timestamp
+    if len(new_processed_keys):

[Paweł Hajdan Jr., 2014/06/02 13:45:47]

nit: No need to use len in the condition.

Actually it may be better to always log something here.

[Sergiy Byelozyorov, 2014/06/02 13:52:27]

Done.

+      log.msg('[RPWC] Added %d new jobs to the cache.' %
+              len(new_processed_keys))
+    num_removed = 0
     for processed_key, timestamp in self._processed_keys.iteritems():
       if timestamp > cutoff_timestamp:
         new_processed_keys[processed_key] = timestamp
+      else:
+        num_removed += 1
+    if num_removed:

[Paweł Hajdan Jr., 2014/06/02 13:45:47]

Same here, why not make the log statement unconditional?

[Sergiy Byelozyorov, 2014/06/02 13:52:27]

Done.

+      log.msg('[RPWC] Removed %d old jobs from the cache.' % num_removed)
     self._processed_keys = new_processed_keys