From b7b19d139e910da4445c4fa0aa39d04f59f58b3c Mon Sep 17 00:00:00 2001
From: Felix Schmidt <felixfelix.schmidt@googlemail.com>
Date: Fri, 25 May 2018 18:19:14 +0200
Subject: [PATCH] Add start and end timestamp to task and play result in json
 callback (#39277)

* Add start and end timestamp to task result in json callback

Currently, the timestamp information is only provided directly by a few
Ansible modules (e.g. the command module, which shows the runtime of a
command per host result).
This change adds an 'overall' time information to all executed tasks. The
delta between both timestamps shows how long it took a task to finish
across all hosts/nodes.

This patch is also proposed for zuul and can be found here:
https://review.openstack.org/#/c/563888

* Add missing timezone information to 'start' and 'end' timestamps

As the datetime.isoformat() function is missing the timezone information,
we assume it's local time.

* Nest 'start' and 'end' timestamps in 'duration' field.

To clarify the purpose of those fields.

* Add 'start' and 'end' timestamps also for plays
---
 lib/ansible/plugins/callback/json.py | 18 ++++++++++++++++--
 1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/lib/ansible/plugins/callback/json.py b/lib/ansible/plugins/callback/json.py
index c04dd49e237..3961a78aab9 100644
--- a/lib/ansible/plugins/callback/json.py
+++ b/lib/ansible/plugins/callback/json.py
@@ -29,6 +29,7 @@ DOCUMENTATION = '''
         type: bool
 '''
 
+import datetime
 import json
 
 from functools import partial
@@ -38,6 +39,10 @@ from ansible.inventory.host import Host
 from ansible.plugins.callback import CallbackBase
 
 
+def current_time():
+    return '%sZ' % datetime.datetime.utcnow().isoformat()
+
+
 class CallbackModule(CallbackBase):
     CALLBACK_VERSION = 2.0
     CALLBACK_TYPE = 'stdout'
@@ -51,7 +56,10 @@ class CallbackModule(CallbackBase):
         return {
             'play': {
                 'name': play.get_name(),
-                'id': str(play._uuid)
+                'id': str(play._uuid),
+                'duration': {
+                    'start': current_time()
+                }
             },
             'tasks': []
         }
@@ -60,7 +68,10 @@ class CallbackModule(CallbackBase):
         return {
             'task': {
                 'name': task.get_name(),
-                'id': str(task._uuid)
+                'id': str(task._uuid),
+                'duration': {
+                    'start': current_time()
+                }
             },
             'hosts': {}
         }
@@ -110,6 +121,9 @@ class CallbackModule(CallbackBase):
         task_result.update(on_info)
         task_result['action'] = task.action
         self.results[-1]['tasks'][-1]['hosts'][host.name] = task_result
+        end_time = current_time()
+        self.results[-1]['tasks'][-1]['task']['duration']['end'] = end_time
+        self.results[-1]['play']['duration']['end'] = end_time
 
     def __getattribute__(self, name):
         """Return ``_record_task_result`` partial with a dict containing skipped/failed if necessary"""