Added more logging

scripts/master/try_job_rietveld.py

 # Copyright (c) 2012 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 import datetime
 import hashlib
 import json
 import os
 import pytz
 import time
@@ skipping 212 matching lines @@
 
     Returns:
       A deferred object to be called once the operation completes.
     """
 
     log.msg('[RPWC] Poll started')
     log.msg('[RPWC] Downloading %s...' % self._pending_jobs_url)
     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):
     base.PollingChangeSource.setServiceParent(self, parent)
     self._try_job_rietveld = parent
 
   @defer.inlineCallbacks
   def _InitProcessedKeysCache(self):
     log.msg('[RPWC] Initializing processed keys cache...')
 
     # 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()
       if dt.tzinfo is None:
         return dt
       utc_datetime = dt.astimezone(pytz.utc)
       return utc_datetime.replace(tzinfo=None)
 
     # Compose a map of buildset ids to the submission timestamp.
     buildsets = {}
     for brdict in brdicts:
       bsid = brdict.get('buildsetid')
       if bsid is not None:
         buildsets[bsid] = asNaiveUTC(brdict.get('submitted_at'))
 
     # 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]
         self._processed_keys[key] = buildsets[bsid]
 
     log.msg('[RPWC] Initialized processed keys cache from master with %d '
             'jobs.' % len(self._processed_keys))
 
   @defer.inlineCallbacks
   def _ProcessResults(self, first_page_json):
@@ skipping 41 matching lines @@
       yield self._try_job_rietveld.SubmitJobs(new_jobs)
     else:
       log.msg('[RPWC] No new jobs.')
 
     # Update processed keys cache.
     new_processed_keys = {}
     for job in new_jobs:
       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
 
 
 class TryJobRietveld(TryJobBase):
   """A try job source that gets jobs from pending Rietveld patch sets."""
 
   def __init__(self, name, pools, properties=None, last_good_urls=None,
                code_review_sites=None, project=None, filter_master=False,
                cachepath=None, cache_processed_jobs=False):
     """Creates a try job source for Rietveld patch sets.
@@ skipping 143 matching lines @@
         else:
           self.processed_keys.add(job['key'])
           log.err('Rietveld not updated: no corresponding service found.')
 
   # TryJobBase overrides:
   def setServiceParent(self, parent):
     TryJobBase.setServiceParent(self, parent)
     self._poller.setServiceParent(self)
     self._poller.master = self.master
     self._valid_users.setServiceParent(self)