Minor changes (#1544)

* Added test for job timeout

* Added more debugging statements

rq/worker.py

@@ -993,6 +993,7 @@ class Worker:
 
                     result_ttl = job.get_result_ttl(self.default_result_ttl)
                     if result_ttl != 0:
+                        self.log.debug('Setting job %s status to finished', job.id)
                         job.set_status(JobStatus.FINISHED, pipeline=pipeline)
                         job.worker_name = None
                         # Don't clobber the user's meta dictionary!
@@ -1003,9 +1004,11 @@ class Worker:
 
                     job.cleanup(result_ttl, pipeline=pipeline,
                                 remove_from_queue=False)
+                    self.log.debug('Removing job %s from StartedJobRegistry', job.id)
                     started_job_registry.remove(job, pipeline=pipeline)
 
                     pipeline.execute()
+                    self.log.debug('Finished handling successful execution of job %s', job.id)
                     break
                 except redis.exceptions.WatchError:
                     continue

tests/test_worker.py

@@ -329,6 +329,15 @@ class TestWorker(RQTestCase):
             # third is successful, after "recovery"
             assert mocked.call_count == 3
 
+    def test_job_timeout_moved_to_failed_job_registry(self):
+        """Jobs that run long are moved to FailedJobRegistry"""
+        queue = Queue()
+        worker = Worker([queue])
+        job = queue.enqueue(long_running_job, 5, job_timeout=1)
+        worker.work(burst=True)
+        self.assertIn(job, job.failed_job_registry)
+        job.refresh()
+        self.assertIn('rq.timeouts.JobTimeoutException', job.exc_info)
 
     @slow
     def test_heartbeat_busy(self):