Merge pull request #8323 from AlanCoding/prepare_your_containers

Refactor to hook in programmatic use of inventory import saving-to-DB code

Reviewed-by: Jim Ladd
             https://github.com/jladdjr

awx/main/utils/formatters.py

@@ -9,6 +9,7 @@ import socket
 from datetime import datetime
 
 from dateutil.tz import tzutc
+from django.utils.timezone import now
 from django.core.serializers.json import DjangoJSONEncoder
 from django.conf import settings
 
@@ -17,8 +18,15 @@ class TimeFormatter(logging.Formatter):
     '''
     Custom log formatter used for inventory imports
     '''
+    def __init__(self, start_time=None, **kwargs):
+        if start_time is None:
+            self.job_start = now()
+        else:
+            self.job_start = start_time
+        super(TimeFormatter, self).__init__(**kwargs)
+
     def format(self, record):
-        record.relativeSeconds = record.relativeCreated / 1000.0
+        record.relativeSeconds = (now() - self.job_start).total_seconds()
         return logging.Formatter.format(self, record)
 
 

awx/main/utils/handlers.py

@@ -7,6 +7,10 @@ import os.path
 
 # Django
 from django.conf import settings
+from django.utils.timezone import now
+
+# AWX
+from awx.main.exceptions import PostRunError
 
 
 class RSysLogHandler(logging.handlers.SysLogHandler):
@@ -40,6 +44,58 @@ class RSysLogHandler(logging.handlers.SysLogHandler):
             pass
 
 
+class SpecialInventoryHandler(logging.Handler):
+    """Logging handler used for the saving-to-database part of inventory updates
+    ran by the task system
+    this dispatches events directly to be processed by the callback receiver,
+    as opposed to ansible-runner
+    """
+
+    def __init__(self, event_handler, cancel_callback, job_timeout, verbosity,
+                 start_time=None, counter=0, initial_line=0, **kwargs):
+        self.event_handler = event_handler
+        self.cancel_callback = cancel_callback
+        self.job_timeout = job_timeout
+        if start_time is None:
+            self.job_start = now()
+        else:
+            self.job_start = start_time
+        self.last_check = self.job_start
+        self.counter = counter
+        self.skip_level = [logging.WARNING, logging.INFO, logging.DEBUG, 0][verbosity]
+        self._current_line = initial_line
+        super(SpecialInventoryHandler, self).__init__(**kwargs)
+
+    def emit(self, record):
+        # check cancel and timeout status regardless of log level
+        this_time = now()
+        if (this_time - self.last_check).total_seconds() > 0.5:  # cancel callback is expensive
+            self.last_check = this_time
+            if self.cancel_callback():
+                raise PostRunError('Inventory update has been canceled', status='canceled')
+        if self.job_timeout and ((this_time - self.job_start).total_seconds() > self.job_timeout):
+            raise PostRunError('Inventory update has timed out', status='canceled')
+
+        # skip logging for low severity logs
+        if record.levelno < self.skip_level:
+            return
+
+        self.counter += 1
+        msg = self.format(record)
+        n_lines = len(msg.strip().split('\n'))  # don't count line breaks at boundry of text
+        dispatch_data = dict(
+            created=now().isoformat(),
+            event='verbose',
+            counter=self.counter,
+            stdout=msg,
+            start_line=self._current_line,
+            end_line=self._current_line + n_lines
+        )
+        self._current_line += n_lines
+
+        self.event_handler(dispatch_data)
+
+
 ColorHandler = logging.StreamHandler
 
 if settings.COLOR_LOGS is True: