From 8141f8b90581165f36241a3aef9bcd3f0c6a6719 Mon Sep 17 00:00:00 2001
From: Vladimir ProvaLove <vladimir.provalov@emlid.com>
Date: Tue, 27 Nov 2018 16:49:03 +0300
Subject: [PATCH] dependencies.py: log worker is started/finished

- add 'data' field to log
---
 nameko_worker_logger/dependencies.py | 21 +++++++++++++++------
 1 file changed, 15 insertions(+), 6 deletions(-)

diff --git a/nameko_worker_logger/dependencies.py b/nameko_worker_logger/dependencies.py
index d78dced..bd5c5e6 100644
--- a/nameko_worker_logger/dependencies.py
+++ b/nameko_worker_logger/dependencies.py
@@ -38,18 +38,21 @@
 
 
 def _worker_ctx_to_dict(worker_ctx):
-    return {
+    ctx = {
         'call_id': worker_ctx.call_id,
         'call_id_parent': worker_ctx.immediate_parent_call_id,
         'call_id_stack': worker_ctx.call_id_stack,
         'method_name': worker_ctx.entrypoint.method_name,
-        'service_name': worker_ctx.service_name
+        'service_name': worker_ctx.service_name,
+        'data': worker_ctx.data,
     }
+    return {'worker': ctx}
 
 
 def _exception_info_to_dict(exc_info):
     exc_type, msg, traceback = exc_info
-    return {'type': exc_type, 'message': msg, 'traceback': traceback}
+    info = {'type': exc_type, 'message': msg, 'traceback': traceback}
+    return {'exception_info': info}
 
 
 class WorkerLogger(DependencyProvider):
@@ -61,14 +64,20 @@ def __init__(self, logger_name):
 
     def get_dependency(self, worker_ctx):
         """Create logger adapter with worker's contextual data."""
-        worker_info = {'worker': _worker_ctx_to_dict(worker_ctx)}
+        worker_info = _worker_ctx_to_dict(worker_ctx)
         adapter = logging.LoggerAdapter(self.logger, extra=worker_info)
         return adapter
 
+    def worker_setup(self, worker_ctx):
+        """Log task info, before starting task execution."""
+        worker_info = _worker_ctx_to_dict(worker_ctx)
+        self.logger.info("worker is started", extra=worker_info)
+
     def worker_result(self, worker_ctx, result=None, exc_info=None):
         """Log exception info, if it is present."""
+        worker_info = _worker_ctx_to_dict(worker_ctx)
         if exc_info is None:
+            self.logger.info("worker successfully finished", extra=worker_info)
             return
-        exception_info = {'exception_info': _exception_info_to_dict(exc_info)}
-        worker_info = {'worker': _worker_ctx_to_dict(worker_ctx)}
+        exception_info = _exception_info_to_dict(exc_info)
         self.logger.error(exception_info, extra=worker_info)