ara
ara copied to clipboard
ara_record fails to decrypt SSL on https endpoint GET /api/v1/results
The ara_record module seems to have an issue instantiating the results api
Ansible 2.9.1, python 3.6.1, ara and ara[server] 1.3.0 I run the API server in django using nginx proxy+uwsgi on Debian bare metal
I am using a simple playbook to record the local branch
hosts: 127.0.0.1
connection: local
become: no
vars:
ara_playbook_name: ara-record
tasks:
- name: Lookup local git branch
command: "git rev-parse --abbrev-ref HEAD"
register: git_branch
changed_when: false
check_mode: no
- name: Record git branch in ARA
ara_record:
key: "active_git_branch"
value: "{{ git_branch.stdout }}"
ignore_errors: "{{ ansible_check_mode }}"
This works, tested in 1.2.0 and 1.30 - so thank you - we still can record our git branch
But there is a PYTHON_WARNING thrown on SSL decryption:
TASK [Record git branch in ARA] ****************************************************************************************************
task path: /ansible_2.9.1/playbooks/ara-record.yml:19
changed: [127.0.0.1] => {
"changed": true,
"created": "2019-12-07T14:28:50.050584-08:00",
"key": "active_git_branch",
"msg": "Record created or updated in ARA",
"playbook_id": 100,
"type": "text",
"updated": "2019-12-07T14:28:50.050629-08:00",
"value": "master"
}
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object
at 0x7fa429e70ef0>): HTTPSConnectionPool(host='verified.site.com', port=443): Max retries exceeded with url: /api/v1/results
(Caused by SSLError(SSLError(1, '[SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption failed or bad record mac (_ssl.c:2178)'),))
Callback Exception:
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ansible/executor/task_queue_manager.py", line 323, in send_callback
method(*new_args, **kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/plugins/callback/ara_default.py", line 261, in v2_runner_on_ok
self._load_result(result, "ok", **kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/plugins/callback/ara_default.py", line 373, in _load_result
ignore_errors=kwargs.get("ignore_errors", False) or False,
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/clients/http.py", line 115, in post
return self._request("post", endpoint, **kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/clients/http.py", line 93, in _request
response = func(url, **kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/clients/http.py", line 69, in post
return self._request("post", url, data=json.dumps(payload))
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/ara/clients/http.py", line 57, in _request
return self.http.request(method, self.endpoint + url, timeout=self.timeout, **payload)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/requests/sessions.py", line 533, in request
resp = self.send(prep, **send_kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/requests/sessions.py", line 646, in send
r = adapter.send(request, **kwargs)
File "/ansible_2.9.1/venv/lib/python3.6/site-packages/requests/adapters.py", line 514, in send
raise SSLError(e, request=request)
I assume something is lost here, but whatever is lost by not grabbing /api/v1/results
Thanks! P.S. Keep on doing ARA up... glad to see so much movement since 1.x
Haven't looked at this issue yet but wanted to point out that I've been seeing it as well:
TASK [smoke-tests : Record data with no type] **********************************
task path: /home/zuul/src/opendev.org/recordsansible/ara/tests/integration/roles/smoke-tests/tasks/ara-ops.yaml:30
changed: [localhost] => {
"changed": true,
"created": "2020-01-30T00:15:25.989098Z",
"key": "notype",
"msg": "Record created or updated in ARA",
"playbook_id": 6,
"type": "text",
"updated": "2020-01-30T00:15:25.989138Z",
"value": "text"
}
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7fac33c8f910>): HTTPSConnectionPool(host='api.demo.recordsansible.org',
port=443): Max retries exceeded with url: /api/v1/results (Caused by
SSLError(SSLError(1, '[SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption
failed or bad record mac (_ssl.c:2508)')))
Callback Exception:
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/ansible/executor/task_queue_manager.py", line 324, in send_callback
method(*new_args, **kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib/python3.7/site-packages/ara/plugins/callback/ara_default.py", line 283, in v2_runner_on_ok
self._load_result(result, "ok", **kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib/python3.7/site-packages/ara/plugins/callback/ara_default.py", line 395, in _load_result
ignore_errors=kwargs.get("ignore_errors", False) or False,
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/ara/clients/http.py", line 115, in post
return self._request("post", endpoint, **kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/ara/clients/http.py", line 93, in _request
response = func(url, **kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/ara/clients/http.py", line 69, in post
return self._request("post", url, data=json.dumps(payload))
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/ara/clients/http.py", line 57, in _request
return self.http.request(method, self.endpoint + url, timeout=self.timeout, **payload)
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/requests/sessions.py", line 533, in request
resp = self.send(prep, **send_kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/requests/sessions.py", line 646, in send
r = adapter.send(request, **kwargs)
File "/home/zuul/.ara-tests/virtualenv/lib64/python3.7/site-packages/requests/adapters.py", line 514, in send
raise SSLError(e, request=request)
I've investigated this a bit but haven't found the root cause yet. It looks like perhaps there could be something wrong with our usage of weakref for re-using the client instance ?
tl;dr:
- Client sends POST requests to create the playbook, the play, the task without issues
- Client sends POST request to create a record from ara_record without issues
- After the ara_record task, the callback gets a SSLError exception when trying to POST the result of the task
The relevant order of events:
- callback creates a new http client instance: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/callback/ara_default.py#L187-L194
-
v2_playbook_on_start
runs fine: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/callback/ara_default.py#L196 -
v2_playbook_on_play_start
runs fine: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/callback/ara_default.py#L221 -
v2_playbook_on_task_start
runs fine: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/callback/ara_default.py#L261 - the task started is an ara_record task
- ara_record recovers the active client instance through weakref: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/action/ara_record.py#L143
- ara_record uses client.post to create the new key/value: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/action/ara_record.py#L150
- the task completes successfully, invoking
v2_runner_on_ok
-
v2_runner_on_ok
raises an SSLError exception when doing a post for the result of the task: https://github.com/ansible-community/ara/blob/b1e450b9bd77609c741e4bd667b2fd4f9c5e8e25/ara/plugins/callback/ara_default.py#L402 - The remainder of the playbook runs fine and is recorded properly (aside from the results of ara_record tasks)
Yeah, the issue has something to do with passing the instance weakref back and forth.
If I revert the patch that introduced the weakref, I am unable to reproduce the issue.
I haven't found a definitive fix for this yet and it didn't warrant blocking the release of 1.4, we can fix it in an upcoming dot release.
I haven't revisited this issue in a long time but perhaps this PR could fix it: https://github.com/ansible-community/ara/pull/274
Hi @dmsimard,
funny, I had exactly that error today when I used lookup('ara_api', '/api/')
in a run with more than one host.
The solution was to set run_once: true
, thus also what you are doing in your PR.
I still need to analyze it, but I ran it with ANSIBLE_DEBUG=1
TASK [Record in ARA] ************************************************************************************************
task path: /opt/ansible/projects/element-networks/playbooks/.480262.main.yml:19
480273 1635264143.62403: sending task start callback
480273 1635264143.62406: entering _queue_task() for aptproxy.nc.element-networks.nl/ara_record
480273 1635264143.62408: Creating lock for ara_record
480273 1635264143.62597: worker is 2 (out of 3 available)
480273 1635264143.62613: exiting _queue_task() for aptproxy.nc.element-networks.nl/ara_record
480273 1635264143.62615: done queuing things up, now waiting for results queue to drain
480273 1635264143.62616: waiting for pending results...
480313 1635264143.62727: running TaskExecutor() for aptproxy.nc.element-networks.nl/TASK: Record in ARA
480313 1635264143.62760: in run() - task 4abf3276-fafa-b41d-0aaa-00000000004b
480313 1635264143.62772: variable 'ansible_search_path' from source: unknown
480313 1635264143.62790: variable '_ansible_loop_cache' from source: unknown
480313 1635264143.62792: calling self._execute()
480313 1635264143.62824: variable 'ansible_delegated_vars' from source: unknown
480313 1635264143.62831: variable 'ansible_connection' from source: host vars for 'localhost'
480313 1635264143.62837: no remote address found for delegated host localhost
using its name, so success depends on DNS resolution
480313 1635264143.62849: variable 'omit' from source: magic vars
480313 1635264143.62901: variable 'omit' from source: magic vars
480313 1635264143.62915: variable 'omit' from source: magic vars
480313 1635264143.63029: variable 'ansible_role_versions' from source: set_fact
480313 1635264143.63066: variable 'ansible_delegated_vars' from source: unknown
480313 1635264143.63072: variable 'ansible_connection' from source: host vars for 'localhost'
480313 1635264143.63077: variable 'ansible_connection' from source: host vars for 'localhost'
480313 1635264143.63100: trying /usr/lib/python3/dist-packages/ansible/plugins/connection
480313 1635264143.63121: Loading Connection 'local' from /usr/lib/python3/dist-packages/ansible/plugins/connection/local.py (found_in_cache=True, class_only=False)
480313 1635264143.63135: trying /usr/lib/python3/dist-packages/ansible/plugins/shell
480313 1635264143.63150: Loading ShellModule 'sh' from /usr/lib/python3/dist-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
480313 1635264143.63160: Loading ShellModule 'sh' from /usr/lib/python3/dist-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
480313 1635264143.63205: Loading ActionModule 'ara_record' from /opt/ansible/projects/element-networks/library/action/ara_record.py (searched paths: /usr/lib/python3/dist-packages/ansible/plugins/action:/opt/ansible/projects/element-networks/library/action/__pycache__:/opt/ansible/projects/element-networks/library/action) (found_in_cache=True, class_only=False)
480313 1635264143.63216: variable 'omit' from source: magic vars
480313 1635264143.63226: starting attempt loop
480313 1635264143.63232: running the handler
480313 1635264143.65157: handler run complete
480313 1635264143.65172: Evaluated conditional (False): False
480313 1635264143.65180: variable 'ansible_host' from source: unknown
480313 1635264143.65186: variable 'ansible_port' from source: unknown
480313 1635264143.65193: variable 'ansible_user' from source: unknown
480313 1635264143.65199: variable 'ansible_connection' from source: host vars for 'localhost'
480313 1635264143.65205: attempt loop complete, returning result
480313 1635264143.65211: _execute() done
480313 1635264143.65214: dumping result to json
480313 1635264143.65224: done dumping result, returning
480313 1635264143.65234: done running TaskExecutor() for aptproxy.nc.element-networks.nl/TASK: Record in ARA [4abf3276-fafa-b41d-0aaa-00000000004b]
480313 1635264143.65240: sending task result for task 4abf3276-fafa-b41d-0aaa-00000000004b
480313 1635264143.65277: done sending task result for task 4abf3276-fafa-b41d-0aaa-00000000004b
480313 1635264143.65300: WORKER PROCESS EXITING
ok: [aptproxy.nc.element-networks.nl -> localhost] => changed=false
created: '2021-10-26T18:02:23.647591+02:00'
key: ansible_role_versions
msg: Record created or updated in ARA
playbook_id: 1953
type: text
updated: '2021-10-26T18:02:23.647610+02:00'
value: |-
480305 1635264142.78273: starting run
480305 1635264143.09209: Validate TLS certificates for https://galaxy.ansible.com: True
# /opt/ansible/projects/element-networks/roles
480305 1635264143.47176: Validate TLS certificates: True
480305 1635264143.47192: Validate TLS certificates: True
- motd, 1.1.3
480305 1635264143.47407: Validate TLS certificates: True
- subscription_manager, 1.2.2
480305 1635264143.47585: Validate TLS certificates: True
- sshd, 2.5.3
480305 1635264143.47775: Validate TLS certificates: True
- odoo, (unknown version)
480305 1635264143.47932: Validate TLS certificates: True
480305 1635264143.47940: Validate TLS certificates: True
- docker_services, master
480305 1635264143.48176: Validate TLS certificates: True
- pip, 2.0.0
480305 1635264143.48444: Validate TLS certificates: True
- nullmailer, 1.1.0
480305 1635264143.48636: Validate TLS certificates: True
- ldap, 2.2.2
480305 1635264143.48879: Validate TLS certificates: True
- dns_server, 3.3.1
480305 1635264143.49051: Validate TLS certificates: True
- apt, 1.8.0
480305 1635264143.49269: Validate TLS certificates: True
- zabbix_agent, 1.6.0
480305 1635264143.49495: Validate TLS certificates: True
480305 1635264143.49503: Validate TLS certificates: True
- proxmox_setup, (unknown version)
480305 1635264143.49676: Validate TLS certificates: True
- branding, 1.0.0
480305 1635264143.49849: Validate TLS certificates: True
- acme_ssl, 3.7.1
480305 1635264143.50084: Validate TLS certificates: True
- ansible_controller, 1.4.3
480305 1635264143.50314: Validate TLS certificates: True
- docker, 2.8.1
480305 1635264143.50591: Validate TLS certificates: True
- wireguard, 2.1.3
480305 1635264143.50762: Validate TLS certificates: True
- nginx_revproxy, 2.0.0
480305 1635264143.50969: Validate TLS certificates: True
- postgresql, 3.1.1
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fb967d9f6d0>):
HTTPSConnectionPool(host='ara.zm1.element-networks.nl', port=443): Max retries exceeded with url: /api/v1/results
(Caused by SSLError(SSLError(1, '[SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption failed or bad record mac
(_ssl.c:2622)')))
Callback Exception:
File "/usr/lib/python3/dist-packages/ansible/executor/task_queue_manager.py", line 441, in send_callback
method(*new_args, **kwargs)
File "/opt/ansible/projects/element-networks/library/callback/ara_default.py", line 385, in v2_runner_on_ok
self._submit_thread("task", self._load_result, result, "ok", **kwargs)
File "/opt/ansible/projects/element-networks/library/callback/ara_default.py", line 249, in _submit_thread
func(*args, **kwargs)
File "/opt/ansible/projects/element-networks/library/callback/ara_default.py", line 584, in _load_result
self.result = self.client.post(
File "/usr/local/lib/python3.9/dist-packages/ara/clients/http.py", line 115, in post
return self._request("post", endpoint, **kwargs)
File "/usr/local/lib/python3.9/dist-packages/ara/clients/http.py", line 93, in _request
response = func(url, **kwargs)
File "/usr/local/lib/python3.9/dist-packages/ara/clients/http.py", line 69, in post
return self._request("post", url, data=json.dumps(payload))
File "/usr/local/lib/python3.9/dist-packages/ara/clients/http.py", line 57, in _request
return self.http.request(method, self.endpoint + url, timeout=self.timeout, **payload)
File "/usr/lib/python3/dist-packages/requests/sessions.py", line 542, in request
resp = self.send(prep, **send_kwargs)
File "/usr/lib/python3/dist-packages/requests/sessions.py", line 655, in send
r = adapter.send(request, **kwargs)
File "/usr/lib/python3/dist-packages/requests/adapters.py", line 514, in send
raise SSLError(e, request=request)
480273 1635264143.65894: no more pending results, returning what we have
480273 1635264143.65912: results queue empty
480273 1635264143.65914: checking for any_errors_fatal
480273 1635264143.65918: done checking for any_errors_fatal
480273 1635264143.65919: checking for max_fail_percentage
480273 1635264143.65920: done checking for max_fail_percentage
480273 1635264143.65921: checking to see if all hosts have failed and the running result is not ok
480273 1635264143.65922: done checking to see if all hosts have failed
480273 1635264143.65923: getting the remaining hosts for this loop
480273 1635264143.65925: done getting the remaining hosts for this loop
480273 1635264143.65929: building list of next tasks for hosts
480273 1635264143.65931: getting the next task for host aptproxy.nc.element-networks.nl
480273 1635264143.65934: done getting next task for host aptproxy.nc.element-networks.nl
480273 1635264143.65935: ^ task is: TASK: Collect git repo version
480273 1635264143.65937: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65938: getting the next task for host aptproxy.nm.element-networks.nl
480273 1635264143.65940: done getting next task for host aptproxy.nm.element-networks.nl
480273 1635264143.65941: ^ task is: TASK: Collect git repo version
480273 1635264143.65942: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65944: getting the next task for host aptproxy.zm1.element-networks.nl
480273 1635264143.65945: done getting next task for host aptproxy.zm1.element-networks.nl
480273 1635264143.65946: ^ task is: TASK: Collect git repo version
480273 1635264143.65947: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65948: done building task lists
480273 1635264143.65949: counting tasks in each state of execution
480273 1635264143.65951: done counting tasks in each state of execution:
num_setups: 0
num_tasks: 3
num_rescue: 0
num_always: 0
480273 1635264143.65952: advancing hosts in ITERATING_TASKS
480273 1635264143.65953: starting to advance hosts
480273 1635264143.65954: getting the next task for host aptproxy.nc.element-networks.nl
480273 1635264143.65955: done getting next task for host aptproxy.nc.element-networks.nl
480273 1635264143.65957: ^ task is: TASK: Collect git repo version
480273 1635264143.65958: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65959: getting the next task for host aptproxy.nm.element-networks.nl
480273 1635264143.65961: done getting next task for host aptproxy.nm.element-networks.nl
480273 1635264143.65962: ^ task is: TASK: Collect git repo version
480273 1635264143.65963: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65964: getting the next task for host aptproxy.zm1.element-networks.nl
480273 1635264143.65965: done getting next task for host aptproxy.zm1.element-networks.nl
480273 1635264143.65966: ^ task is: TASK: Collect git repo version
480273 1635264143.65967: ^ state is: HOST STATE: block=2, task=3, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
480273 1635264143.65968: done advancing hosts to next task
480273 1635264143.65969: getting variables
480273 1635264143.65971: in VariableManager get_vars()
480273 1635264143.65984: Calling all_inventory to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.65987: Calling groups_inventory to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.65990: Calling all_plugins_inventory to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.66005: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66024: Loading data from /opt/ansible/projects/element-networks/inventory/group_vars/all.yml
480273 1635264143.66028: Calling all_plugins_play to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.66036: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66048: Calling groups_plugins_inventory to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.66056: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66067: Loading data from /opt/ansible/projects/element-networks/inventory/group_vars/aptproxies.yml
480273 1635264143.66073: Loading data from /opt/ansible/projects/element-networks/inventory/group_vars/loc_nc.yml
480273 1635264143.66078: Loading data from /opt/ansible/projects/element-networks/inventory/group_vars/proxmox_all_lxc.yml
480273 1635264143.66086: Calling groups_plugins_play to load vars for aptproxy.nc.element-networks.nl
480273 1635264143.66094: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66124: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66135: Loading data from /opt/ansible/projects/element-networks/inventory/host_vars/aptproxy.nc.element-networks.nl.yml
480273 1635264143.66144: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66180: in VariableManager get_vars()
480273 1635264143.66188: Calling all_inventory to load vars for localhost
480273 1635264143.66191: Calling groups_inventory to load vars for localhost
480273 1635264143.66192: Calling all_plugins_inventory to load vars for localhost
480273 1635264143.66201: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66212: Loading data from /opt/ansible/projects/element-networks/inventory/group_vars/all.yml
480273 1635264143.66216: Calling all_plugins_play to load vars for localhost
480273 1635264143.66224: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66235: Calling groups_plugins_inventory to load vars for localhost
480273 1635264143.66243: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66251: Calling groups_plugins_play to load vars for localhost
480273 1635264143.66259: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66274: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66291: Loading VarsModule 'host_group_vars' from /usr/lib/python3/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
480273 1635264143.66316: done with get_vars()
480273 1635264143.66319: done with get_vars()
480273 1635264143.66324: done getting variables
480273 1635264143.66367: Loading ActionModule 'command' from /usr/lib/python3/dist-packages/ansible/plugins/action/command.py (searched paths: /usr/lib/python3/dist-packages/ansible/plugins/action:/opt/ansible/projects/element-networks/library/action/__pycache__:/opt/ansible/projects/element-networks/library/action) (found_in_cache=False, class_only=True)
480273 1635264143.66371: sending task start callback, copying the task so we can template it temporarily
480273 1635264143.66372: done copying, going to template now
480273 1635264143.66373: done templating
480273 1635264143.66374: here goes the callback...
FYI - when I updated to 1.5.8 recently I noticed that setting the callback_threads=1 in ansible.cfg solved this issue I suspect when you bump to Django 3 you will find it resolved
Issue still exists in 1.6.1. With setting callback_threads
no exception is comming anymore, but still the results are not stored in Ara. With new tasks page this is good visible: