Add start and end timestamp to task and play result in json callback (a…

…nsible#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

@@ -29,6 +29,7 @@
         type: bool
 '''
 
+import datetime
 import json
 
 from functools import partial
@@ -38,6 +39,10 @@
 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 @@ def _new_play(self, play):
         return {
             'play': {
                 'name': play.get_name(),
-                'id': str(play._uuid)
+                'id': str(play._uuid),
+                'duration': {
+                    'start': current_time()
+                }
             },
             'tasks': []
         }
@@ -60,7 +68,10 @@ def _new_task(self, task):
         return {
             'task': {
                 'name': task.get_name(),
-                'id': str(task._uuid)
+                'id': str(task._uuid),
+                'duration': {
+                    'start': current_time()
+                }
             },
             'hosts': {}
         }
@@ -110,6 +121,9 @@ def _record_task_result(self, on_info, result, **kwargs):
         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"""