No logging in file, when using Ara

[arjandekker]

SUMMARY

We are using Ansible and ARA together. When we use Ansible 2.3.2 we are able to log to a file and send the log to a remote ARA server. This way we have a nice output of our Ansible runs and the details are in the logfile. But with version 2.5.5 the logging to ARA works fine, but the logfile is empty. When we remove the ARA callback plugin directory from the ansible.cfg file (remove from callback_plugins) the logging is working again, but of course ARA isn't. It doesn't matter if we use ANSIBLE_LOG_PATH or log_path (inside ansible.cfg).

ISSUE TYPE

• Bug Report

COMPONENT NAME

log

ANSIBLE VERSION

ansible 2.5.5
  config file = /home/adekker/git/ansible/ansible.cfg
  configured module search path = [u'/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/modules']
  ansible python module location = /usr/local/ansible25/lib/python2.7/site-packages/ansible
  executable location = /usr/local/ansible25/bin/ansible
  python version = 2.7.5 (default, May  3 2017, 07:55:04) [GCC 4.8.5 20150623 (Red Hat 4.8.5-14)]

CONFIGURATION

ANSIBLE_PIPELINING(/home/adekker/git/ansible/ansible.cfg) = True
ANSIBLE_SSH_ARGS(/home/adekker/git/ansible/ansible.cfg) = -o ControlMaster=auto -o ControlPersist=30m -o ServerAliveInterval=10 -o ConnectionAttempts=10
CACHE_PLUGIN(/home/adekker/git/ansible/ansible.cfg) = memory
DEFAULT_ACTION_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/action', u'/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/actions']
DEFAULT_CALLBACK_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/callback', u'/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/callbacks']
DEFAULT_CONNECTION_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/connection']
DEFAULT_FILTER_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/filter']
DEFAULT_FORKS(/home/adekker/git/ansible/ansible.cfg) = 10
DEFAULT_GATHERING(/home/adekker/git/ansible/ansible.cfg) = smart
DEFAULT_HASH_BEHAVIOUR(/home/adekker/git/ansible/ansible.cfg) = merge
DEFAULT_HOST_LIST(/home/adekker/git/ansible/ansible.cfg) = [u'/etc/ansible/hosts']
DEFAULT_LOAD_CALLBACK_PLUGINS(/home/adekker/git/ansible/ansible.cfg) = True
DEFAULT_LOG_PATH(env: ANSIBLE_LOG_PATH) = /home/adekker/git/ansible/log/ansible.log
DEFAULT_LOOKUP_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/lookup']
DEFAULT_MANAGED_STR(/home/adekker/git/ansible/ansible.cfg) = Ansible managed: {file} modified on %Y-%m-%d %H:%M:%S by {uid} on {host}
DEFAULT_MODULE_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/modules']
DEFAULT_POLL_INTERVAL(/home/adekker/git/ansible/ansible.cfg) = 15
DEFAULT_TIMEOUT(/home/adekker/git/ansible/ansible.cfg) = 60
DEFAULT_TRANSPORT(/home/adekker/git/ansible/ansible.cfg) = smart
DEFAULT_VARS_PLUGIN_PATH(/home/adekker/git/ansible/ansible.cfg) = [u'/usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/vars']
HOST_KEY_CHECKING(/home/adekker/git/ansible/ansible.cfg) = False

OS / ENVIRONMENT

RHEL7
pip install ansible
pip install ara

STEPS TO REPRODUCE

install Ansible like this, pip install ansible
install ARA like this, pip install ara

Use a remote ARA server, in ansible.cfg:

[ara]
database = mysql+pymysql://ara:xxxxxxxx@localhost/ara

Specify the Ansible plugin for ARA, in ansible.cfg:

action_plugins     =  /usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/action:/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/actions
callback_plugins   =  /usr/local/ansible25/lib64/python2.7/site-packages/ansible/plugins/callback/:/usr/local/ansible25/lib/python2.7/site-packages/ara/plugins/callbacks

Change the log_path in ansible.cfg:

log_path = log/ansible.log

Run a playbook and check the logfile. It should be empty.

EXPECTED RESULTS

Logging to both ARA and the logfile

ACTUAL RESULTS

Logging in ARA works fine, but the logfile is empty.

[ansibot]

Files identified in the description:
None

If these files are inaccurate, please update the component name section of the description or use the !component bot command.

click here for bot help

[sivel]

cc @dmsimard

[dmsimard]

@sivel thanks for the ping.

@arjandekker this is quite a strange bug. I'll try to see if I can figure it out, thanks for reporting it !

[dmsimard]

I have narrowed down the issue to the logging configuration between Ansible and ARA conflicting.

We landed a logging configuration refactor in the latest version of ARA (0.15.0).
It's the likely cause for this regression because I am unable to reproduce this issue when using ARA 0.14.6, regardless of the version of Ansible.

For what it's worth, the reproducer that I've used: https://gist.github.com/dmsimard/e3716a1d6f1e97e787aeb4e016d0fd6a

As such, I don't think this is an Ansible bug but there might be a possible improvement. I don't know yet, I'll need to spend a bit more time on this.
In the meantime, I'd recommend pinning ARA to 0.14.6.

[Akasurde]

@arjandekker Are you still facing this issue? needs_info

[ansibot]

@arjandekker This issue is waiting for your response. Please respond or the issue will be closed.

click here for bot help

[ansibot]

@arjandekker You have not responded to information requests in this issue so we will assume it no longer affects you. If you are still interested in this, please create a new issue with the requested information.

click here for bot help