allow configurable log length, fix #28

Author: samuelcolvin

arq/worker.py

@@ -76,6 +76,10 @@ class BaseWorker(RedisMixin):
     # allowing reuse of the worker, eg. ``worker.run()`` can be called multiple times.
     reusable = False
 
+    #: Adjust the length at which arguments of concurrent functions and job results are curtailed
+    # when logging job execution
+    log_curtail = 80
+
     def __init__(self, *,
                  burst: bool=False,
                  shadows: list=None,
@@ -342,17 +346,16 @@ def job_callback(self, task):
             self.jobs_failed += 1
         jobs_logger.debug('task complete, %d jobs done, %d failed', self.jobs_complete, self.jobs_failed)
 
-    @classmethod
-    def log_job_start(cls, started_at: float, j: Job):
+    def log_job_start(self, started_at: float, j: Job):
         if jobs_logger.isEnabledFor(logging.INFO):
-            jobs_logger.info('%-4s queued%7.3fs → %s', j.queue, started_at - j.queued_at, j)
+            job_str = j.to_string(self.log_curtail)
+            jobs_logger.info('%-4s queued%7.3fs → %s', j.queue, started_at - j.queued_at, job_str)
 
-    @classmethod
-    def log_job_result(cls, started_at: float, result, j: Job):
+    def log_job_result(self, started_at: float, result, j: Job):
         if not jobs_logger.isEnabledFor(logging.INFO):
             return
         job_time = timestamp() - started_at
-        sr = '' if result is None else ellipsis(repr(result))
+        sr = '' if result is None else ellipsis(repr(result), self.log_curtail)
         jobs_logger.info('%-4s ran in%7.3fs ← %s.%s ● %s', j.queue, job_time, j.class_name, j.func_name, sr)
 
     def handle_prepare_exc(self, msg: str):

tests/test_worker.py

@@ -36,6 +36,19 @@ async def test_long_args(mock_actor_worker, caplog):
             "'0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19 + 0,1,2,3,4,5,6,7,8,9,10,11,…\n") in log
 
 
+async def test_longer_args(mock_actor_worker, caplog):
+    actor, worker = mock_actor_worker
+    worker.log_curtail = 90
+    v = ','.join(map(str, range(20)))
+    await actor.concat(a=v, b=v)
+    await worker.run()
+    log = caplog(('0.0\d\ds', '0.0XXs'))
+    assert ("dft  queued  0.0XXs → MockRedisDemoActor.concat"
+            "(a='0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19', b='0,1,2,3,4,5,6,7,8,9,10,11,12,13…)\n") in log
+    assert ("dft  ran in  0.0XXs ← MockRedisDemoActor.concat ● "
+            "'0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19 + 0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,1…\n") in log
+
+
 async def test_stop_job_normal(mock_actor_worker, caplog):
     caplog.set_loggers(fmt='%(name)s %(levelname)s: %(message)s')
     actor, worker = mock_actor_worker