Prepend timestamp callback output

It's useful to know when a command last ran as well as being able to
cross coordinate when something was running between the ansible output
and other logs. We can use the output timestamp do this.

Change-Id: I3f55f0a7f966f025a9938576ccf735f50f4c8589

tripleo_ansible/ansible_plugins/callback/tripleo_dense.py

@@ -6,15 +6,17 @@ import uuid
 from ansible import constants as C
 from ansible.playbook.task_include import TaskInclude
 from ansible.plugins.callback.default import CallbackModule as DefaultCallback
+from datetime import datetime
 
 
 class CallbackModule(DefaultCallback):
 
-    def _output(self, msg, color):
+    def _output(self, msg, color=None):
+        timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S.%f")
         if isinstance(msg, list):
-            output = ' | '.join(msg)
+            output = ' | '.join([timestamp] + msg)
         else:
-            output = msg
+            output = timestamp + ' | ' + msg
         self._display.display(output, color=color)
 
     def _get_host(self, result):

tripleo_ansible/ansible_plugins/callback/tripleo_profile_tasks.py

@@ -7,6 +7,7 @@ from ansible import constants as C
 from ansible.plugins.callback.profile_tasks import secondsToStr
 from ansible.plugins.callback.profile_tasks import timestamp
 from ansible.plugins.callback.profile_tasks import CallbackModule as PT
+from datetime import datetime
 
 DOCUMENTATION = '''
     callback: tripleo_profile_tasks
@@ -49,6 +50,14 @@ class CallbackModule(PT):
         self.start_time = time.time()
         super(CallbackModule, self).__init__()
 
+    def _output(self, msg, color):
+        timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S.%f")
+        if isinstance(msg, list):
+            output = ' | '.join([timestamp] + msg)
+        else:
+            output = timestamp + ' | ' + msg
+        self._output(output, color=color)
+
     def _output_previous_timings(self, uuid):
         # no previous timing because uuid was null
         if not uuid:
@@ -60,7 +69,7 @@ class CallbackModule(PT):
             secondsToStr(time.time() - self.start_time),
             u'{0:.02f}s'.format(self.stats[uuid].get('time', '-1'))
         ]
-        self._display.display(' | '.join(line), color=C.COLOR_DEBUG)
+        self._output(line, C.COLOR_DEBUG)
 
     def _record_task(self, task):
         timestamp(self)
@@ -84,10 +93,10 @@ class CallbackModule(PT):
             )
         results = results[:self.task_output_limit]
 
-        self._display.display('~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~'
+        self._output('~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~'
-                              ' Summary Information '
+                     ' Summary Information '
-                              '~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~')
+                     '~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~')
-        self._display.display(
+        self._output(
             '~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~'
             ' Elapsed Time: {} '
             '~~~~~~~~~~~~~~~~~~~~~~~~~~~~'.format(
@@ -99,7 +108,7 @@ class CallbackModule(PT):
             '{}'.format('Task Name'),
             '{:>10}'.format('Run Time'),
         ]
-        self._display.display(' | '.join(header))
+        self._output(' | '.join(header))
 
         for uuid, result in results:
             line = [
@@ -108,4 +117,4 @@ class CallbackModule(PT):
                 result['name'],
                 u'{0:.02f}s'.format(result['time'])
             ]
-            self._display.display(' | '.join(line))
+            self._output(' | '.join(line))