Merge pull request #3007 from AlanCoding/test_logging

Updates to logging, specifically for unit tests

Reviewed-by: https://github.com/softwarefactory-project-zuul[bot]

awx/main/models/inventory.py

@@ -3,6 +3,7 @@
 
 # Python
 import datetime
+import time
 import logging
 import re
 import copy
@@ -428,7 +429,8 @@ class Inventory(CommonModelNameNotUnique, ResourceMixin, RelatedJobsMixin):
         '''
         Update model fields that are computed from database relationships.
         '''
-        logger.debug("Going to update inventory computed fields")
+        logger.debug("Going to update inventory computed fields, pk={0}".format(self.pk))
+        start_time = time.time()
         if update_hosts:
             self.update_host_computed_fields()
         if update_groups:
@@ -465,7 +467,8 @@ class Inventory(CommonModelNameNotUnique, ResourceMixin, RelatedJobsMixin):
                 computed_fields.pop(field)
         if computed_fields:
             iobj.save(update_fields=computed_fields.keys())
-        logger.debug("Finished updating inventory computed fields")
+        logger.debug("Finished updating inventory computed fields, pk={0}, in "
+                     "{1:.3f} seconds".format(self.pk, time.time() - start_time))
 
     def websocket_emit_status(self, status):
         connection.on_commit(lambda: emit_channel_notification(

awx/main/tests/unit/test_tasks.py

@@ -246,8 +246,6 @@ class TestJobExecution(object):
             # If `Job.update_model` is called, we're not actually persisting
             # to the database; just update the status, which is usually
             # the update we care about for testing purposes
-            if kwargs.get('result_traceback'):
-                raise Exception('Task encountered error:\n{}'.format(kwargs['result_traceback']))
             if 'status' in kwargs:
                 self.instance.status = kwargs['status']
             if 'job_env' in kwargs:

awx/main/utils/common.py

@@ -10,7 +10,6 @@ import os
 import re
 import subprocess
 import stat
-import sys
 import urllib
 import urlparse
 import threading
@@ -118,7 +117,7 @@ class RequireDebugTrueOrTest(logging.Filter):
 
     def filter(self, record):
         from django.conf import settings
-        return settings.DEBUG or 'test' in sys.argv
+        return settings.DEBUG or settings.IS_TESTING()
 
 
 class IllegalArgumentError(ValueError):

awx/settings/development.py

@@ -45,6 +45,8 @@ SHELL_PLUS_PRINT_SQL = False
 # show colored logs in the dev environment
 # to disable this, set `COLOR_LOGS = False` in awx/settings/local_settings.py
 LOGGING['handlers']['console']['()'] = 'awx.main.utils.handlers.ColorHandler'
+# task system does not propagate to AWX, so color log these too
+LOGGING['handlers']['task_system'] = LOGGING['handlers']['console'].copy()
 COLOR_LOGS = True
 
 # Pipe management playbook output to console

awx/settings/local_settings.py.docker_compose

@@ -91,9 +91,6 @@ CHANNEL_LAYERS = {
                 'CONFIG': {'url': BROKER_URL}}
 }
 
-# Set True to enable additional logging from the job_event_callback plugin
-JOB_CALLBACK_DEBUG = False
-
 # Absolute filesystem path to the directory to host projects (with playbooks).
 # This directory should NOT be web-accessible.
 PROJECTS_ROOT = '/projects/'
@@ -144,9 +141,6 @@ PROXY_IP_WHITELIST = []
 # If set, use -vvv for project updates instead of -v for more output.
 # PROJECT_UPDATE_VVV=True
 
-# Set verbosity for inventory import command when running inventory updates.
-# INVENTORY_UPDATE_VERBOSITY=1
-
 ###############################################################################
 # EMAIL SETTINGS
 ###############################################################################
@@ -221,9 +215,9 @@ LOGGING['handlers']['management_playbooks'] = {'class': 'logging.NullHandler'}
 #}
 
 # Enable the following lines to turn on lots of permissions-related logging.
-#LOGGING['loggers']['awx.main.access']['propagate'] = True
-#LOGGING['loggers']['awx.main.signals']['propagate'] = True
-#LOGGING['loggers']['awx.main.permissions']['propagate'] = True
+#LOGGING['loggers']['awx.main.access']['level'] = 'DEBUG'
+#LOGGING['loggers']['awx.main.signals']['level'] = 'DEBUG'
+#LOGGING['loggers']['awx.main.permissions']['level'] = 'DEBUG'
 
 # Enable the following line to turn on database settings logging.
 #LOGGING['loggers']['awx.conf']['level'] = 'DEBUG'

awx/settings/local_settings.py.example

@@ -48,9 +48,6 @@ if is_testing(sys.argv):
 # AMQP configuration.
 BROKER_URL = 'amqp://guest:guest@localhost:5672'
 
-# Set True to enable additional logging from the job_event_callback plugin
-JOB_CALLBACK_DEBUG = False
-
 # Absolute filesystem path to the directory to host projects (with playbooks).
 # This directory should NOT be web-accessible.
 PROJECTS_ROOT = os.path.join(BASE_DIR, 'projects')
@@ -100,9 +97,6 @@ PROXY_IP_WHITELIST = []
 # If set, use -vvv for project updates instead of -v for more output.
 # PROJECT_UPDATE_VVV=True
 
-# Set verbosity for inventory import command when running inventory updates.
-# INVENTORY_UPDATE_VERBOSITY=1
-
 ###############################################################################
 # EMAIL SETTINGS
 ###############################################################################
@@ -158,9 +152,9 @@ LOGGING['handlers']['syslog'] = {
 #}
 
 # Enable the following lines to turn on lots of permissions-related logging.
-#LOGGING['loggers']['awx.main.access']['propagate'] = True
-#LOGGING['loggers']['awx.main.signals']['propagate'] = True
-#LOGGING['loggers']['awx.main.permissions']['propagate'] = True
+#LOGGING['loggers']['awx.main.access']['level'] = 'DEBUG'
+#LOGGING['loggers']['awx.main.signals']['level'] = 'DEBUG'
+#LOGGING['loggers']['awx.main.permissions']['level'] = 'DEBUG'
 
 # Enable the following line to turn on database settings logging.
 #LOGGING['loggers']['awx.conf']['level'] = 'DEBUG'