improve some logging, particularly errors that get retried

Author: joeshaw

pyres/job.py

@@ -1,3 +1,4 @@
+import logging
 import time
 from datetime import timedelta
 from pyres import ResQ, safe_str_to_class
@@ -88,6 +89,7 @@ def perform(self):
                 raise
             else:
                 metadata["retried"] = True
+                logging.exception("Retry scheduled after error in %s", job)
         finally:
             after_perform = getattr(payload_class, "after_perform", None)
             if after_perform and check_after:

pyres/worker.py

@@ -22,9 +22,9 @@ class and passes a comma-separated list of queues to listen on.::
        >>> Worker.run([queue1, queue2], server="localhost:6379")
 
     """
-    
+
     job_class = Job
-    
+
     def __init__(self, queues=(), server="localhost:6379", password=None, timeout=None):
         self.queues = queues
         self.validate_queues()
@@ -209,10 +209,10 @@ def fork_worker(self, job):
             logger.debug('done waiting')
         else:
             self._setproctitle("Processing %s since %s" %
-                               (job._queue,
+                               (job,
                                 datetime.datetime.now()))
             logger.info('Processing %s since %s' %
-                         (job._queue, datetime.datetime.now()))
+                         (job, datetime.datetime.now()))
             self.after_fork(job)
 
             # re-seed the Python PRNG after forking, otherwise
@@ -263,7 +263,7 @@ def process(self, job=None):
                 logger.info('completed job')
                 logger.debug('job details: %s' % job)
         finally:
-            self.done_working()
+            self.done_working(job)
 
     def _handle_job_exception(self, job):
         exceptionType, exceptionValue, exceptionTraceback = sys.exc_info()
@@ -290,8 +290,8 @@ def working_on(self, job):
         logger.debug("worker:%s" % str(self))
         logger.debug(self.resq.redis["resque:worker:%s" % str(self)])
 
-    def done_working(self):
-        logger.info('done working')
+    def done_working(self, job):
+        logger.info('done working on %s', job)
         self.processed()
         self.resq.redis.delete("resque:worker:%s" % str(self))