Merge pull request #2274 from AlanCoding/callback_debugging

Reduce default verbosity of dev-specific callback logging

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

awx/main/dispatch/worker/base.py

@@ -125,7 +125,7 @@ class BaseWorker(object):
             except QueueEmpty:
                 continue
             except Exception as e:
-                logger.error("Exception on worker, restarting: " + str(e))
+                logger.error("Exception on worker {}, restarting: ".format(idx) + str(e))
                 continue
             try:
                 self.perform_work(body, *args)

awx/main/dispatch/worker/callback.py

@@ -40,14 +40,6 @@ class CallbackBrokerWorker(BaseWorker):
 
             if not any([key in body for key in event_map]):
                 raise Exception('Payload does not have a job identifier')
-            if settings.DEBUG:
-                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'))
-                )[:1024 * 4])
 
             def _save_event_data():
                 for key, cls in event_map.items():
@@ -55,11 +47,29 @@ class CallbackBrokerWorker(BaseWorker):
                         cls.create_from_data(**body)
 
             job_identifier = 'unknown job'
+            job_key = 'unknown'
             for key in event_map.keys():
                 if key in body:
                     job_identifier = body[key]
+                    job_key = key
                     break
 
+            if settings.DEBUG:
+                from pygments import highlight
+                from pygments.lexers import PythonLexer
+                from pygments.formatters import Terminal256Formatter
+                from pprint import pformat
+                if body.get('event') == 'EOF':
+                    event_thing = 'EOF event'
+                else:
+                    event_thing = 'event {}'.format(body.get('counter', 'unknown'))
+                logger.info('Callback worker received {} for {} {}'.format(
+                    event_thing, job_key[:-len('_id')], job_identifier
+                ))
+                logger.debug('Body: {}'.format(
+                    highlight(pformat(body, width=160), PythonLexer(), Terminal256Formatter(style='friendly'))
+                )[:1024 * 4])
+
             if body.get('event') == 'EOF':
                 try:
                     final_counter = body.get('final_counter', 0)

awx/settings/defaults.py

@@ -1142,6 +1142,7 @@ LOGGING = {
         },
         'awx.main.commands.run_callback_receiver': {
             'handlers': ['callback_receiver'],
+            'level': 'INFO'  # in debug mode, includes full callback data
         },
         'awx.main.dispatch': {
             'handlers': ['dispatcher'],

awx/settings/local_settings.py.docker_compose

@@ -196,6 +196,7 @@ LOGGING['handlers']['syslog'] = {
 LOGGING['loggers']['django.request']['handlers'] = ['console']
 LOGGING['loggers']['rest_framework.request']['handlers'] = ['console']
 LOGGING['loggers']['awx']['handlers'] = ['console', 'external_logger']
+LOGGING['loggers']['awx.main.commands.run_callback_receiver']['handlers'] = []  # propogates to awx
 LOGGING['loggers']['awx.main.tasks']['handlers'] = ['console', 'external_logger']
 LOGGING['loggers']['awx.main.scheduler']['handlers'] = ['console', 'external_logger']
 LOGGING['loggers']['django_auth_ldap']['handlers'] = ['console']