From f9d42e8a177eb4356cc5dc29de6a4f410127ed1f Mon Sep 17 00:00:00 2001
From: Selwin Ong <selwin.ong@gmail.com>
Date: Sat, 22 Jun 2019 16:42:05 +0700
Subject: [PATCH] Added logging statements to handle_job_success and
 handle_job_failure (#1112)

---
 rq/worker.py         | 3 ++-
 tests/test_queue.py  | 2 +-
 tests/test_worker.py | 9 ++++-----
 3 files changed, 7 insertions(+), 7 deletions(-)

diff --git a/rq/worker.py b/rq/worker.py
index cccdbc1..d93c5ff 100644
--- a/rq/worker.py
+++ b/rq/worker.py
@@ -735,6 +735,7 @@ class Worker(object):
             3. Setting the workers current job to None
             4. Add the job to FailedJobRegistry
         """
+        self.log.debug('Handling failed execution of job %s', job.id)
         with self.connection.pipeline() as pipeline:
             if started_job_registry is None:
                 started_job_registry = StartedJobRegistry(
@@ -767,7 +768,7 @@ class Worker(object):
                 pass
 
     def handle_job_success(self, job, queue, started_job_registry):
-
+        self.log.debug('Handling successful execution of job %s', job.id)
         with self.connection.pipeline() as pipeline:
             while True:
                 try:
diff --git a/tests/test_queue.py b/tests/test_queue.py
index 750edde..20fb058 100644
--- a/tests/test_queue.py
+++ b/tests/test_queue.py
@@ -3,7 +3,7 @@ from __future__ import (absolute_import, division, print_function,
                         unicode_literals)
 
 from tests import RQTestCase
-from tests.fixtures import echo, Number, say_hello
+from tests.fixtures import echo, say_hello
 
 from rq import Queue
 from rq.exceptions import InvalidJobDependency
diff --git a/tests/test_worker.py b/tests/test_worker.py
index 1c17a76..3649834 100644
--- a/tests/test_worker.py
+++ b/tests/test_worker.py
@@ -318,7 +318,7 @@ class TestWorker(RQTestCase):
         worker.refresh()
         self.assertEqual(worker.failed_job_count, 1)
         self.assertEqual(worker.successful_job_count, 1)
-        self.assertEqual(worker.total_working_time, 1.5) # 1.5 seconds
+        self.assertEqual(worker.total_working_time, 1.5)  # 1.5 seconds
 
         worker.handle_job_failure(job)
         worker.handle_job_success(job, queue, registry)
@@ -644,7 +644,6 @@ class TestWorker(RQTestCase):
         # Score in queue is +inf
         self.assertEqual(self.testconn.zscore(registry.key, job.id), float('Inf'))
 
-
     def test_work_unicode_friendly(self):
         """Worker processes work with unicode description, then quits."""
         q = Queue('foo')
@@ -909,16 +908,16 @@ class TestWorker(RQTestCase):
         """Check that log_job_description True causes job lifespan to be logged."""
         q = Queue()
         w = Worker([q])
-        job = q.enqueue(say_hello, args=('Frank',), result_ttl=10)
+        q.enqueue(say_hello, args=('Frank',), result_ttl=10)
         w.dequeue_job_and_maintain_ttl(10)
-        self.assertIn("Frank",  mock_logger_info.call_args[0][2])
+        self.assertIn("Frank", mock_logger_info.call_args[0][2])
 
     @mock.patch('rq.worker.logger.info')
     def test_log_job_description_false(self, mock_logger_info):
         """Check that log_job_description False causes job lifespan to not be logged."""
         q = Queue()
         w = Worker([q], log_job_description=False)
-        job = q.enqueue(say_hello, args=('Frank',), result_ttl=10)
+        q.enqueue(say_hello, args=('Frank',), result_ttl=10)
         w.dequeue_job_and_maintain_ttl(10)
         self.assertNotIn("Frank", mock_logger_info.call_args[0][2])