Awx: Set global logging to INFO partial working

[philippwiesner]

ISSUE TYPE

• Bug Report

COMPONENT NAME

• UI
• Django Framework
  
  
  
  • Task Scheduler
  
  

SUMMARY

The awx_task log is full of Debug messages, filling /var/log/messages. We wanted to set the global logging level to INFO, so that messages like

[2017-11-20 11:11:26,258: DEBUG/MainProcess] awx.main.scheduler.tasks.run_task_manager sent. id->71bf8b50-bbf9-4869-ab93-cc7235721148
[2017-11-20 11:11:26,260: DEBUG/MainProcess] beat: Waking up in 9.97 seconds.

won't appear anymore in the log. However setting

LOGGING['handlers']['console'] = {
'()': 'logging.StreamHandler',
'level': 'INFO',
'formatter': 'simple',
}

seems to have only partial effect, as those messages are still appearing, but the django settings accessed via awx-manage shell prints:

console: {(): logging.StreamHandler, formatter: simple, level: INFO}

At the moment there seems no setting via the UI or in the /etc/tower/settings.py where you can set the global log level to Info.

From the django settings accessed by awx-manage I can see that there are some loggers set to DEBUG, but I haven't found where they are set to those values:

loggers:
awx:
handlers: [console]
level: INFO
awx.analytics:
handlers: [http_receiver]
level: INFO
propagate: false
awx.api.permissions:
handlers: ['null']
propagate: false
awx.conf:
handlers: ['null']
level: WARNING
awx.conf.settings:
handlers: ['null']
level: WARNING
awx.isolated.manager.playbooks:
handlers: [console]
propagate: false
awx.main:
handlers: ['null']
awx.main.access:
handlers: ['null']
propagate: false
awx.main.commands.inventory_import:
handlers: [console]
propagate: false
awx.main.commands.run_callback_receiver:
handlers: [console]
awx.main.consumers:
handlers: ['null']
awx.main.scheduler:
handlers: [console]
level: INFO
awx.main.signals:
handlers: ['null']
propagate: false
awx.main.tasks:
handlers: [console]
django:
handlers: [console]
django.request:
handlers: [console]
level: WARNING
django_auth_ldap:
handlers: [console]
level: DEBUG
py.warnings:
handlers: [console]
rbac_migrations:
handlers: [console]
level: DEBUG
rest_framework.request:
handlers: [console]
level: WARNING
propagate: false
social:
handlers: [console]
level: DEBUG
system_tracking_migrations:
handlers: [console]
level: DEBUG

Is the only current way in changing those values to INFO by setting those directly in the django settings.py for each entry separately?

ENVIRONMENT

• AWX version: 1.0.1.54
• AWX install method: local docker with self build containers
• Ansible version: 2.4.1.0
• Operating System: RHEL7
• Web Browser: Yandex

STEPS TO REPRODUCE

Set LOGGING['handlers']['console']['level'] to 'INFO' in /etc/tower/settings.py
Set LOGGING['loggers']['awx.main.scheduler'] to 'INFO' in /etc/tower/settings.py

EXPECTED RESULTS

Only INFO logging messages in logging
Only INFO log messages for awx.main.scheduler

ACTUAL RESULTS

Still debug log messages for awx.main.scheduler

[2017-11-20 11:11:26,258: DEBUG/MainProcess] awx.main.scheduler.tasks.run_task_manager sent. id->71bf8b50-bbf9-4869-ab93-cc7235721148
[2017-11-20 11:11:26,260: DEBUG/MainProcess] beat: Waking up in 9.97 seconds.

[AlanCoding]

I think you're mostly looking in the wrong place for this. Try the following:

LOGGING['loggers']['celery'] = {}
LOGGING['loggers']['celery']['level'] = 'WARNING'

In addition to this put --loglevel=WARNING on the celery command in the Makefile make celeryd.

This manages to silence the logs you mention. However, this still leaves some junk duplication of logs that tasks emit (regardless of level). You could get rid of those, too, by not propagating the awx logs to the root logger, LOGGING['loggers']['awx']['propagate'] = False, however, this is a completely unacceptable solution. I have, in the past, attempted to fight celery's behavior with the root logger redirection, but I still don't have a good answer. Worse case, something could be done to change that behavior by an action in the celery setup logging signals.

Someday, I would like to have a solution to this which actually controls the log level, as opposed to just hiding these logs.

[philippwiesner]

Thanks, that helped reducing the logging mass a bit. In general it would be good if even in the container setup the log messages would be split apart in multiple files like already present in this file:
https://github.com/ansible/awx/blob/3118092e51ff037bbccd48b22cf8dabfda53516b/awx/settings/production.py#L53-L59

Because with the standard setup of local docker everything will the directed to journald and depending on the system configuration spamming the /var/log/messages

[akcrisp]

I just found the amount of logging filled our /var partition on our dev instance. I've just set it to INFO as per above. This really does need addressing.

[cpu100]

Refer by awx/settings/defaults.py

    LOGGING['handlers']['console'] = {
        '()': 'logging.StreamHandler',
        'level': 'WARNING',
        'formatter': 'simple',
    }

    LOGGING['loggers']['awx']['level'] = 'WARNING'