improve readability of the honcho console logs in the dev environment

* colorize uwsgi and celery logs; DEBUG lines are green, WARN lines
  are yellow, ERROR lines (and tracebacks) are red
* pretty-print fact callback receiver JSON
* simplify the uwsgi log format so it's more legible

8 files changed, 54 insertions, 4 deletions

diff --git a/Makefile b/Makefile
index c346268767..ae28d1179f 100644
--- a/Makefile
+++ b/Makefile
@@ -430,7 +430,7 @@ uwsgi: collectstatic
 	@if [ "$(VENV_BASE)" ]; then \
 		. $(VENV_BASE)/tower/bin/activate; \
 	fi; \
-    uwsgi -b 32768 --socket 127.0.0.1:8050 --module=awx.wsgi:application --home=/venv/tower --chdir=/tower_devel/ --vacuum --processes=5 --harakiri=120 --master --no-orphans --py-autoreload 1 --max-requests=1000 --stats /tmp/stats.socket --master-fifo=/awxfifo --lazy-apps
+    uwsgi -b 32768 --socket 127.0.0.1:8050 --module=awx.wsgi:application --home=/venv/tower --chdir=/tower_devel/ --vacuum --processes=5 --harakiri=120 --master --no-orphans --py-autoreload 1 --max-requests=1000 --stats /tmp/stats.socket --master-fifo=/awxfifo --lazy-apps --logformat "%(addr) %(method) %(uri) - %(proto) %(status)"
 
 daphne:
 	@if [ "$(VENV_BASE)" ]; then \
diff --git a/awx/main/management/commands/run_callback_receiver.py b/awx/main/management/commands/run_callback_receiver.py
index c262b23024..8c14166679 100644
--- a/awx/main/management/commands/run_callback_receiver.py
+++ b/awx/main/management/commands/run_callback_receiver.py
@@ -114,7 +114,13 @@ class CallbackBrokerWorker(ConsumerMixin):
                 if 'job_id' not in body and 'ad_hoc_command_id' not in body:
                     raise Exception('Payload does not have a job_id or ad_hoc_command_id')
                 if settings.DEBUG:
-                    logger.info('Body: {}'.format(body))
+                    from pygments import highlight
+                    from pygments.lexers import PythonLexer
+                    from pygments.formatters import Terminal256Formatter
+                    from pprint import pformat
+                    logger.info('Body: {}'.format(
+                        highlight(pformat(body, width=160), PythonLexer(), Terminal256Formatter(style='friendly'))
+                    ))
                 try:
                     if 'job_id' in body:
                         JobEvent.create_from_data(**body)
diff --git a/awx/main/tasks.py b/awx/main/tasks.py
index 19bd26bb1f..8e567ab312 100644
--- a/awx/main/tasks.py
+++ b/awx/main/tasks.py
@@ -225,7 +225,7 @@ def tower_periodic_scheduler(self):
     run_now = now()
     state = TowerScheduleState.get_solo()
     last_run = state.schedule_last_run
-    logger.debug("Last run was: %s", last_run)
+    logger.debug("Last scheduler run was: %s", last_run)
     state.schedule_last_run = run_now
     state.save()
 
diff --git a/awx/main/utils/handlers.py b/awx/main/utils/handlers.py
index 9d8a3572ea..b8143577f0 100644
--- a/awx/main/utils/handlers.py
+++ b/awx/main/utils/handlers.py
@@ -17,6 +17,7 @@ from requests.exceptions import RequestException
 # loggly
 import traceback
 
+from django.conf import settings
 from requests_futures.sessions import FuturesSession
 
 # AWX
@@ -304,6 +305,33 @@ HANDLER_MAPPING = {
 }
 
 
+ColorHandler = logging.StreamHandler
+
+if settings.COLOR_LOGS is True:
+    try:
+        from logutils.colorize import ColorizingStreamHandler
+
+        class ColorHandler(ColorizingStreamHandler):
+
+            def format(self, record):
+                message = logging.StreamHandler.format(self, record)
+                return '\n'.join([
+                    self.colorize(line, record)
+                    for line in message.splitlines()
+                ])
+
+            level_map = {
+                logging.DEBUG: (None, 'green', True),
+                logging.INFO: (None, None, True),
+                logging.WARNING: (None, 'yellow', True),
+                logging.ERROR: (None, 'red', True),
+                logging.CRITICAL: (None, 'red', True),
+            }
+    except ImportError:
+        # logutils is only used for colored logs in the dev environment
+        pass
+
+
 def _add_or_remove_logger(address, instance):
     specific_logger = logging.getLogger(address)
     for i, handler in enumerate(specific_logger.handlers):
diff --git a/awx/settings/defaults.py b/awx/settings/defaults.py
index 537f5f07b6..2f3c4e930e 100644
--- a/awx/settings/defaults.py
+++ b/awx/settings/defaults.py
@@ -917,9 +917,9 @@ LOGGING = {
     },
     'handlers': {
         'console': {
+            '()': 'logging.StreamHandler',
             'level': 'DEBUG',
             'filters': ['require_debug_true_or_test'],
-            'class': 'logging.StreamHandler',
             'formatter': 'simple',
         },
         'null': {
@@ -1091,3 +1091,4 @@ LOGGING = {
         },
     }
 }
+COLOR_LOGS = False
diff --git a/awx/settings/development.py b/awx/settings/development.py
index 0edf353f6a..da2b73d091 100644
--- a/awx/settings/development.py
+++ b/awx/settings/development.py
@@ -19,6 +19,11 @@ from split_settings.tools import optional, include
 # Load default settings.
 from defaults import *  # NOQA
 
+# 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'
+COLOR_LOGS = True
+
 ALLOWED_HOSTS = ['*']
 
 mimetypes.add_type("image/svg+xml", ".svg", True)
@@ -40,6 +45,9 @@ TEMPLATE_LOADERS = (
 if 'celeryd' in sys.argv:
     SQL_DEBUG = False
 
+CELERYD_HIJACK_ROOT_LOGGER = False
+CELERYD_LOG_COLOR = True
+
 CALLBACK_QUEUE = "callback_tasks"
 
 # Enable PROOT for tower-qa integration tests.
diff --git a/requirements/requirements_dev.txt b/requirements/requirements_dev.txt
index 7e95b98060..9cf2c55573 100644
--- a/requirements/requirements_dev.txt
+++ b/requirements/requirements_dev.txt
@@ -10,5 +10,6 @@ pytest-cov
 pytest-django
 pytest-pythonpath
 pytest-mock
+logutils
 flower
 uwsgitop
diff --git a/tools/rdb.py b/tools/rdb.py
index 227d2448e5..9552c5317e 100644
--- a/tools/rdb.py
+++ b/tools/rdb.py
@@ -14,6 +14,7 @@ from celery.contrib.rdb import Rdb
 
 import cmd
 import contextlib
+import logging
 import os
 import pprint
 import re
@@ -27,6 +28,8 @@ from pygments import highlight
 from pygments.lexers import PythonLexer
 from pygments.formatters import Terminal256Formatter
 
+logger = logging.getLogger('awx')
+
 
 @contextlib.contextmanager
 def style(im_self, filepart=None, lexer=None):
@@ -158,6 +161,9 @@ class CustomPdb(Rdb):
         )
         return (sock, port)
 
+    def say(self, m):
+        logger.warning(m)
+
 
 CustomPdb.complete = rlcompleter.Completer(locals()).complete