diff --git a/furious/handlers/__init__.py b/furious/handlers/__init__.py index b153283..c4ba795 100644 --- a/furious/handlers/__init__.py +++ b/furious/handlers/__init__.py @@ -43,6 +43,7 @@ def process_async_task(headers, request_body): def _log_task_info(headers, extra_task_info=None): """Processes the header from task requests to log analytical data.""" ran_at = time.time() + trace = headers.get("X-Cloud-Trace-Context") task_eta = float(headers.get('X-Appengine-Tasketa', 0.0)) task_info = { 'retry_count': headers.get('X-Appengine-Taskretrycount', ''), @@ -51,6 +52,8 @@ def _log_task_info(headers, extra_task_info=None): 'ran': ran_at, 'gae_latency_seconds': ran_at - task_eta } + if trace: + task_info['trace'] = trace if extra_task_info: task_info['extra'] = extra_task_info diff --git a/furious/tests/handlers/test__init__.py b/furious/tests/handlers/test__init__.py index b2735f3..af3ccbe 100644 --- a/furious/tests/handlers/test__init__.py +++ b/furious/tests/handlers/test__init__.py @@ -32,14 +32,15 @@ def test_all_headers(self, debug_mock, time_mock): headers = { 'X-Appengine-Taskretrycount': 'blue', 'X-Appengine-Taskexecutioncount': 'yellow', - 'X-Appengine-Tasketa': '0.50' + 'X-Appengine-Tasketa': '0.50', + 'X-Cloud-Trace-Context': "atrace" } handlers._log_task_info(headers) expected_logs = ( - '{"ran": 1.5, "retry_count": "blue", "gae_latency_seconds": 1.0, ' - '"task_eta": 0.5, "execution_count": "yellow"}') + '{"gae_latency_seconds": 1.0, "task_eta": 0.5, "trace": "atrace", ' + '"execution_count": "yellow", "ran": 1.5, "retry_count": "blue"}') debug_mock.assert_called_with('TASK-INFO: %s', expected_logs)