ansible-community / ara

ARA Records Ansible and makes it easier to understand and troubleshoot.
https://ara.recordsansible.org
GNU General Public License v3.0
1.87k stars 174 forks source link

Ara without server failing with /api errors on fresh install #533

Open DavidEdell opened 10 months ago

DavidEdell commented 10 months ago

I'm seeing the errors below on a fresh installation under Ubuntu 20.04 & python 3.8.10 in a VENV. I'm using the "without an API server" directions from the getting started docs as a starting point. I'm using an ansible.cfg file generated by python -m ara.setup.ansible | tee ansible.cfg. The same directions worked on a docker-compose test setup, albeit with a more recent version of Python (and warnings when generating it's initial configuration already covered in another issue) and no venv.

Side note: The 'Getting Started' directions should likely include a mention of running ara-manage migrate to create the DB.

The sqlite3 db file is created, but nothing is getting inserted into it after running a playbook. Consequently there is no data in the web server and running ara queries gives me

ara host list
[ara] No setting found for SECRET_KEY. Generating a random key...
2023-12-29 21:51:37,108 ERROR ara.clients.http: Failed to get on /api/v1/hosts: {'params': {'order': '-updated', 'limit': 50}}
2023-12-29 21:51:37,108 ERROR ara.clients.http: Failed to get on /api/v1/hosts: {'params': {'order': '-updated', 'limit': 50}}
2023-12-29 21:51:37,108 ERROR ara: Expecting value: line 1 column 1 (char 0)

When I run a playbook, stderr gives me

[WARNING]: Failure using method (v2_runner_on_failed) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7fe25b8a7be0>): '9b1ee0f8-7945-d3f8-2e93-000000000013'
[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7fe25b8a7be0>): 'NoneType' object is not subscriptable
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
BrokenPipeError: [Errno 32] Broken pipe

The first error I get (with -vvv giving additional details) is:

2023-12-29 21:16:38,417 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {...
Callback Exception:
  File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 446, in v2_playbook_on_start
    self.playbook = self.client.post(
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/clients/http.py", line 105, in post
    return self._request("post", endpoint, **kwargs)
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/clients/http.py", line 96, in _request
    return response.json()
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
1 plays in playbooks/hello.yml

And the last error is:

[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fbd6bf4f400>): 'NoneType' object is not
subscriptable
Callback Exception:
  File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 622, in v2_playbook_on_stats
    self._load_stats(stats)
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 847, in _load_stats
    host = self._get_or_create_host(hostname)
   File "/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 733, in _get_or_create_host
    self.host_cache[host] = self.client.post("/api/v1/hosts", name=host, playbook=self.playbook["id"])

pip3 freeze in my case is:

ansible==6.7.0
ansible-core==2.13.13
ara==1.7.0
asgiref==3.7.2
attrs==23.1.0
autopage==0.5.2
backports.zoneinfo==0.2.1
certifi==2023.11.17
cffi==1.16.0
charset-normalizer==3.3.2
cliff==4.4.0
cmd2==2.4.3
cryptography==41.0.7
Django==4.2.8
django-cors-headers==4.3.1
django-filter==23.5
django-health-check==3.17.0
djangorestframework==3.14.0
dynaconf==3.2.4
idna==3.6
importlib-metadata==7.0.1
Jinja2==3.1.2
jmespath==1.0.1
MarkupSafe==2.1.3
packaging==23.2
pbr==6.0.0
prettytable==3.9.0
pycparser==2.21
pygments==2.17.2
pyperclip==1.8.2
pytz==2023.3.post1
PyYAML==6.0.1
requests==2.31.0
resolvelib==0.8.1
ruamel.yaml==0.18.5
ruamel.yaml.clib==0.2.8
sqlparse==0.4.4
stevedore==5.1.0
typing-extensions==4.9.0
tzlocal==5.2
urllib3==2.1.0
wcwidth==0.2.12
whitenoise==6.6.0
zipp==3.17.0

Note: The error message I'm seeing is somewhat similar to #532 but the circumstances are different enough that I don't want to confuse his issue.

Any suggestions? thanks

flowerysong commented 10 months ago

I don't see any way this output could be the result of following the steps from the documentation that you pointed to. The error you're receiving is from the http client, which should only be used if you explicitly request it instead of the default offline client. It would be helpful to know what steps you actually followed.

ec2-user@live-asagustu ~ $ pip3 install --user ansible ara[server] 'ruamel.yaml<0.18'
[...]
ec2-user@live-asagustu ~ $ cat >test.yml <<EOF
> - hosts: localhost
>   tasks:
>     - debug:
> EOF
ec2-user@live-asagustu ~ $ export ANSIBLE_CALLBACK_PLUGINS="$(python3 -m ara.setup.callback_plugins)"
ec2-user@live-asagustu ~ $ ansible-playbook test.yml
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that
the implicit localhost does not match 'all'
[ara] No setting found for SECRET_KEY. Generating a random key...
[ara] Creating data & configuration directory: /home/ec2-user/.ara/server
[ara] Writing default settings to /home/ec2-user/.ara/server/settings.yaml
Operations to perform:
  Apply all migrations: admin, api, auth, contenttypes, db, sessions
Running migrations:
  Applying contenttypes.0001_initial... OK
  Applying auth.0001_initial... OK
  Applying admin.0001_initial... OK
  Applying admin.0002_logentry_remove_auto_add... OK
  Applying admin.0003_logentry_add_action_flag_choices... OK
  Applying api.0001_initial... OK
  Applying api.0002_remove_host_alias... OK
  Applying api.0003_add_missing_result_properties... OK
  Applying api.0004_duration_in_database... OK
  Applying api.0005_unique_label_names... OK
  Applying api.0006_remove_result_statuses... OK
  Applying api.0007_add_expired_status... OK
  Applying api.0008_playbook_controller... OK
  Applying api.0009_latesthost... OK
  Applying api.0010_result_delegated_to... OK
  Applying api.0011_play_label_name_max_length... OK
  Applying api.0012_playbook_user... OK
  Applying api.0013_task_status... OK
  Applying api.0014_ara_versions... OK
  Applying api.0015_task_uuid... OK
  Applying api.0016_revert_play_label_name_length... OK
  Applying api.0017_optional_playbook_controller... OK
  Applying contenttypes.0002_remove_content_type_name... OK
  Applying auth.0002_alter_permission_name_max_length... OK
  Applying auth.0003_alter_user_email_max_length... OK
  Applying auth.0004_alter_user_username_opts... OK
  Applying auth.0005_alter_user_last_login_null... OK
  Applying auth.0006_require_contenttypes_0002... OK
  Applying auth.0007_alter_validators_add_error_messages... OK
  Applying auth.0008_alter_user_username_max_length... OK
  Applying auth.0009_alter_user_last_name_max_length... OK
  Applying auth.0010_alter_group_name_max_length... OK
  Applying auth.0011_update_proxy_permissions... OK
  Applying auth.0012_alter_user_first_name_max_length... OK
  Applying db.0001_initial... OK
  Applying sessions.0001_initial... OK

PLAY [localhost] ***************************************************************

TASK [Gathering Facts] *********************************************************
ok: [localhost]

TASK [debug] *******************************************************************
ok: [localhost] => {
    "msg": "Hello world!"
}

PLAY RECAP *********************************************************************
localhost                  : ok=2    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

As you can see the necessary setup happens on demand, which is why the documentation doesn't include any optional steps like running the migrations ahead of time.

I suggest checking the output of ansible-config dump --only-changed -t all to see if incorrect settings are being picked up from somewhere, e.g.:

CALLBACK:
========

ara_default:
___________
api_client(env: ARA_API_CLIENT) = http
api_server(env: ARA_API_SERVER) = http://127.0.0.1:8000
DavidEdell commented 10 months ago

Clearly something is going awry on this system.

First off:

ansible-config dump --only-changed -t all
DEFAULT_ACTION_PLUGIN_PATH(/home/user/ansible_setup/ansible.cfg) = ['/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/action']
DEFAULT_CALLBACK_PLUGIN_PATH(env: ANSIBLE_CALLBACK_PLUGINS) = ['/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/callback']
DEFAULT_HOST_LIST(env: ANSIBLE_INVENTORY) = ['/home/user/ansible_setup/inventory.yml']
DEFAULT_LOOKUP_PLUGIN_PATH(/home/user/ansible_setup/ansible.cfg) = ['/home/user/ansible_setup/myvenv/lib/python3.8/site-packages/ara/plugins/lookup']

I'll start with a fresh venv to confirm my steps:

# Clear old data (and running in a fresh terminal)
mkdir take1 && mv ~/.ara take1/

# Setup
python3 -m venv take2
source take2/bin/activate
pip3 install wheel # Without this subsequent install steps give an error
pip3 --default-timeout=100 install ansible "ara[server]"

# ENV (there are no other ARA or ANSIBLE options previously set)
export ANSIBLE_CALLBACK_PLUGINS="$(python3 -m ara.setup.callback_plugins)"
export ANSIBLE_INVENTORY=${PWD}/inventory.yml

# Test
ansible-playbook playbooks/hello.yml
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'
[ara] No setting found for SECRET_KEY. Generating a random key...
[ara] Creating data & configuration directory: /home/user/.ara/server
[ara] Writing default settings to /home/user/.ara/server/settings.yaml
[WARNING]: Skipping callback 'ara_default', unable to load due to:  "dump()" has been removed, use    yaml = YAML(typ='unsafe', pure=True)   yaml.dump(...)  instead of file
"/home/user/ansible_setup/take2/lib/python3.8/site-packages/ara/server/settings.py", line 306          yaml.dump({"default": SETTINGS}, settings_file, default_flow_style=False)

PLAY [Update test.log and Echo] **************************************************************************************************************************************************************************************
skipping: no hosts matched

PLAY RECAP ***********************************************************************************************************************************************************************************************************

# Retry
ansible-playbook playbooks/hello.yml
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'
[ara] No setting found for SECRET_KEY. Generating a random key...
Operations to perform:
  Apply all migrations: admin, api, auth, contenttypes, db, sessions
Running migrations:
  Applying contenttypes.0001_initial... OK
  Applying auth.0001_initial... OK
  Applying admin.0001_initial... OK
  Applying admin.0002_logentry_remove_auto_add... OK
  Applying admin.0003_logentry_add_action_flag_choices... OK
  Applying api.0001_initial... OK
  Applying api.0002_remove_host_alias... OK
  Applying api.0003_add_missing_result_properties... OK
  Applying api.0004_duration_in_database... OK
  Applying api.0005_unique_label_names... OK
  Applying api.0006_remove_result_statuses... OK
  Applying api.0007_add_expired_status... OK
  Applying api.0008_playbook_controller... OK
  Applying api.0009_latesthost... OK
  Applying api.0010_result_delegated_to... OK
  Applying api.0011_play_label_name_max_length... OK
  Applying api.0012_playbook_user... OK
  Applying api.0013_task_status... OK
  Applying api.0014_ara_versions... OK
  Applying api.0015_task_uuid... OK
  Applying api.0016_revert_play_label_name_length... OK
  Applying api.0017_optional_playbook_controller... OK
  Applying contenttypes.0002_remove_content_type_name... OK
  Applying auth.0002_alter_permission_name_max_length... OK
  Applying auth.0003_alter_user_email_max_length... OK
  Applying auth.0004_alter_user_username_opts... OK
  Applying auth.0005_alter_user_last_login_null... OK
  Applying auth.0006_require_contenttypes_0002... OK
  Applying auth.0007_alter_validators_add_error_messages... OK
  Applying auth.0008_alter_user_username_max_length... OK
  Applying auth.0009_alter_user_last_name_max_length... OK
  Applying auth.0010_alter_group_name_max_length... OK
  Applying auth.0011_update_proxy_permissions... OK
  Applying auth.0012_alter_user_first_name_max_length... OK
  Applying db.0001_initial... OK
  Applying sessions.0001_initial... OK
2023-12-30 10:48:16,080 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 0, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('playbooks/hello.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/playbooks/hello.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2023-12-30T15:48:16.074681+00:00'}
2023-12-30 10:48:16,081 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 0, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('playbooks/hello.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/playbooks/hello.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2023-12-30T15:48:16.074681+00:00'}
[WARNING]: Failure using method (v2_playbook_on_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fb5160cc340>): Expecting value: line 1 column 1 (char 0)

PLAY [Update test.log and Echo] **************************************************************************************************************************************************************************************
[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fb5160cc340>): 'NoneType' object is not subscriptable
skipping: no hosts matched

PLAY RECAP ***********************************************************************************************************************************************************************************************************

[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fb5160cc340>): 'NoneType' object is not subscriptable

ara playbook list
[ara] No setting found for SECRET_KEY. Generating a random key...
2023-12-30 10:49:17,021 ERROR ara.clients.http: Failed to get on /api/v1/playbooks: {'params': {'order': '-started', 'limit': 50}}
2023-12-30 10:49:17,021 ERROR ara.clients.http: Failed to get on /api/v1/playbooks: {'params': {'order': '-started', 'limit': 50}}
2023-12-30 10:49:17,021 ERROR ara: Expecting value: line 1 column 1 (char 0)
DavidEdell commented 10 months ago

Also, retrying a 3rd time with your exact commands (modified only for venv and my weird network) did resolve the dump warning on the first execution, but (using your test.yml) gave the same api error as the second execution in the previous take.

python3 -m venv take3
source take3/bin/activate
pip install wheel
pip3 install --default-timeout=100 ansible ara[server] 'ruamel.yaml<0.18'
export ANSIBLE_CALLBACK_PLUGINS="$(python3 -m ara.setup.callback_plugins)"
ansible-playbook test.yml
...
  Applying sessions.0001_initial... OK
2023-12-30 11:03:09,666 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 0, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('test.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/test.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2023-12-30T16:03:09.660164+00:00'}
2023-12-30 11:03:09,667 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 0, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('test.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/test.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2023-12-30T16:03:09.660164+00:00'}
[WARNING]: Failure using method (v2_playbook_on_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f0d545fe9d0>): Expecting value: line 1 column 1
(char 0)

PLAY [localhost] *****************************************************************************************************************************************************************************
[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f0d545fe9d0>): 'NoneType' object is not
subscriptable

TASK [Gathering Facts] ***********************************************************************************************************************************************************************
[WARNING]: Failure using method (v2_playbook_on_task_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f0d545fe9d0>): 'NoneType' object is not
subscriptable
ok: [localhost]
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f0d545fe9d0>): 'NoneType' object is not subscriptable

TASK [debug] *********************************************************************************************************************************************************************************
ok: [localhost] => {
    "msg": "Hello world!"
}

PLAY RECAP ***********************************************************************************************************************************************************************************
localhost                  : ok=2    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f0d545fe9d0>): 'NoneType' object is not
subscriptable
(
dmsimard commented 10 months ago

Hi @DavidEdell, could you provide the full output of the command with ansible-playbook -vvv ?

It will provide the exception tracebacks and some additional information.

Thanks.

Edit: to be clear, do not truncate the output to only the tracebacks, I'm also interested in the rest of the output.

DavidEdell commented 10 months ago

Here's the full output. I cleared the ~/.ara folder first to be sure.

ansible-playbook -vvv test.yml
ansible-playbook [core 2.13.13]
  config file = None
  configured module search path = ['/home/user/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible
  ansible collection location = /home/user/.ansible/collections:/usr/share/ansible/collections
  executable location = /home/user/ansible_setup/take3/bin/ansible-playbook
  python version = 3.8.10 (default, Nov 22 2023, 10:22:35) [GCC 9.4.0]
  jinja version = 3.1.2
  libyaml = True
No config file found; using defaults
host_list declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
script declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
auto declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
yaml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
ini declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
toml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'
[ara] No setting found for SECRET_KEY. Generating a random key...
[ara] Creating data & configuration directory: /home/user/.ara/server
[ara] Writing default settings to /home/user/.ara/server/settings.yaml
Operations to perform:
  Apply all migrations: admin, api, auth, contenttypes, db, sessions
Running migrations:
  Applying contenttypes.0001_initial... OK
  Applying auth.0001_initial... OK
  Applying admin.0001_initial... OK
  Applying admin.0002_logentry_remove_auto_add... OK
  Applying admin.0003_logentry_add_action_flag_choices... OK
  Applying api.0001_initial... OK
  Applying api.0002_remove_host_alias... OK
  Applying api.0003_add_missing_result_properties... OK
  Applying api.0004_duration_in_database... OK
  Applying api.0005_unique_label_names... OK
  Applying api.0006_remove_result_statuses... OK
  Applying api.0007_add_expired_status... OK
  Applying api.0008_playbook_controller... OK
  Applying api.0009_latesthost... OK
  Applying api.0010_result_delegated_to... OK
  Applying api.0011_play_label_name_max_length... OK
  Applying api.0012_playbook_user... OK
  Applying api.0013_task_status... OK
  Applying api.0014_ara_versions... OK
  Applying api.0015_task_uuid... OK
  Applying api.0016_revert_play_label_name_length... OK
  Applying api.0017_optional_playbook_controller... OK
  Applying contenttypes.0002_remove_content_type_name... OK
  Applying auth.0002_alter_permission_name_max_length... OK
  Applying auth.0003_alter_user_email_max_length... OK
  Applying auth.0004_alter_user_username_opts... OK
  Applying auth.0005_alter_user_last_login_null... OK
  Applying auth.0006_require_contenttypes_0002... OK
  Applying auth.0007_alter_validators_add_error_messages... OK
  Applying auth.0008_alter_user_username_max_length... OK
  Applying auth.0009_alter_user_last_name_max_length... OK
  Applying auth.0010_alter_group_name_max_length... OK
  Applying auth.0011_update_proxy_permissions... OK
  Applying auth.0012_alter_user_first_name_max_length... OK
  Applying db.0001_initial... OK
  Applying sessions.0001_initial... OK
Skipping callback 'default', as we already have a stdout callback.
Skipping callback 'minimal', as we already have a stdout callback.
Skipping callback 'oneline', as we already have a stdout callback.

PLAYBOOK: test.yml **********************************************************************************************************************************************************************************************************************************
2024-01-01 11:32:57,727 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 3, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('test.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/test.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2024-01-01T16:32:57.721459+00:00'}
2024-01-01 11:32:57,727 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 3, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('test.yml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/test.yml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2024-01-01T16:32:57.721459+00:00'}
[WARNING]: Failure using method (v2_playbook_on_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fab29dbb0a0>): Expecting value: line 1 column 1 (char 0)
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 446, in v2_playbook_on_start
    self.playbook = self.client.post(
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 105, in post
    return self._request("post", endpoint, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 96, in _request
    return response.json()
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
1 plays in test.yml

PLAY [localhost] ************************************************************************************************************************************************************************************************************************************
[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fab29dbb0a0>): 'NoneType' object is not subscriptable
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 500, in v2_playbook_on_play_start
    self._submit_thread("global", self._set_playbook_labels, labels)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 395, in _submit_thread
    func(*args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 675, in _set_playbook_labels
    current_labels = [label["name"] for label in self.playbook["labels"]]

TASK [Gathering Facts] ******************************************************************************************************************************************************************************************************************************
task path: /home/user/ansible_setup/test.yml:1
[WARNING]: Failure using method (v2_playbook_on_task_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fab29dbb0a0>): 'NoneType' object is not subscriptable
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 554, in v2_playbook_on_task_start
    task_file = self._get_or_create_file(path)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 709, in _get_or_create_file
    "/api/v1/files", playbook=self.playbook["id"], path=path, content=content
<127.0.0.1> ESTABLISH LOCAL CONNECTION FOR USER: user
<127.0.0.1> EXEC /bin/sh -c 'echo ~user && sleep 0'
<127.0.0.1> EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /home/user/.ansible/tmp `"&& mkdir "` echo /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881 `" && echo ansible-tmp-1704126777.7743523-998825-4597634615881="` echo /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881 `" ) && sleep 0'
Using module file /home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/modules/setup.py
<127.0.0.1> PUT /home/user/.ansible/tmp/ansible-local-998819qo4t2cpy/tmpaommcyz0 TO /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881/AnsiballZ_setup.py
<127.0.0.1> EXEC /bin/sh -c 'chmod u+x /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881/ /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881/AnsiballZ_setup.py && sleep 0'
<127.0.0.1> EXEC /bin/sh -c '/home/user/ansible_setup/take3/bin/python3 /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881/AnsiballZ_setup.py && sleep 0'
<127.0.0.1> EXEC /bin/sh -c 'rm -f -r /home/user/.ansible/tmp/ansible-tmp-1704126777.7743523-998825-4597634615881/ > /dev/null 2>&1 && sleep 0'
ok: [localhost]
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fab29dbb0a0>): 'NoneType' object is not subscriptable
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 568, in v2_runner_on_ok
    self._submit_thread("task", self._load_result, result, "ok", **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 395, in _submit_thread
    func(*args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 782, in _load_result
    host = self._get_or_create_host(hostname)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 733, in _get_or_create_host
    self.host_cache[host] = self.client.post("/api/v1/hosts", name=host, playbook=self.playbook["id"])
META: ran handlers

TASK [debug] ****************************************************************************************************************************************************************************************************************************************
task path: /home/user/ansible_setup/test.yml:3
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 554, in v2_playbook_on_task_start
    task_file = self._get_or_create_file(path)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 709, in _get_or_create_file
    "/api/v1/files", playbook=self.playbook["id"], path=path, content=content
ok: [localhost] => {
    "msg": "Hello world!"
}
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 568, in v2_runner_on_ok
    self._submit_thread("task", self._load_result, result, "ok", **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 395, in _submit_thread
    func(*args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 782, in _load_result
    host = self._get_or_create_host(hostname)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 733, in _get_or_create_host
    self.host_cache[host] = self.client.post("/api/v1/hosts", name=host, playbook=self.playbook["id"])
META: ran handlers
META: ran handlers

PLAY RECAP ******************************************************************************************************************************************************************************************************************************************
localhost                  : ok=2    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7fab29dbb0a0>): 'NoneType' object is not subscriptable
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 622, in v2_playbook_on_stats
    self._load_stats(stats)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 847, in _load_stats
    host = self._get_or_create_host(hostname)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 733, in _get_or_create_host
    self.host_cache[host] = self.client.post("/api/v1/hosts", name=host, playbook=self.playbook["id"])

The auto-generated ~/.ara/server/settings.yml

---
# This is a default settings template generated by ARA.
# To use a settings file such as this one, you need to export the
# ARA_SETTINGS environment variable like so:
#   $ export ARA_SETTINGS="/home/user/.ara/server/settings.yaml"

default:
  ALLOWED_HOSTS:
  - ::1
  - 127.0.0.1
  - localhost
  BASE_DIR: /home/user/.ara/server
  BASE_PATH: /
  CORS_ORIGIN_ALLOW_ALL: false
  CORS_ORIGIN_REGEX_WHITELIST: []
  CORS_ORIGIN_WHITELIST:
  - http://127.0.0.1:8000
  - http://localhost:3000
  CSRF_TRUSTED_ORIGINS: []
  DATABASE_CONN_MAX_AGE: 0
  DATABASE_ENGINE: django.db.backends.sqlite3
  DATABASE_HOST: null
  DATABASE_NAME: /home/user/.ara/server/ansible.sqlite
  DATABASE_OPTIONS: {}
  DATABASE_PASSWORD: null
  DATABASE_PORT: null
  DATABASE_USER: null
  DEBUG: false
  DISTRIBUTED_SQLITE: false
  DISTRIBUTED_SQLITE_PREFIX: ara-report
  DISTRIBUTED_SQLITE_ROOT: /var/www/logs
  EXTERNAL_AUTH: false
  LOGGING:
    disable_existing_loggers: false
    formatters:
      normal:
        format: '%(asctime)s %(levelname)s %(name)s: %(message)s'
    handlers:
      console:
        class: logging.StreamHandler
        formatter: normal
        level: INFO
        stream: ext://sys.stdout
    loggers:
      ara:
        handlers:
        - console
        level: INFO
        propagate: 0
    version: 1
  LOG_LEVEL: INFO
  PAGE_SIZE: 100
  READ_LOGIN_REQUIRED: false
  SECRET_KEY: WDpaZwKEL7iMLu7KDBwjvUPxVk1CqiYLVLfDZC8FwEoGFGY1IW
  TIME_ZONE: America/New_York
  WRITE_LOGIN_REQUIRED: false
dmsimard commented 10 months ago

@DavidEdell thanks for providing the tracebacks. Nothing jumps at me from looking at the output but maybe we can troubleshoot and figure it out.

It's unable to create a playbook and then everything cascades from there.

By default, the value for ARA_API_CLIENT is offline which takes care of running the sqlite migrations and spinning up an ephemeral ara server in the background to send requests to.

It seems the server spins up but the callback isn't able to send data to it for some reason.

Could you try running this test playbook and see if the server is running ? Can you curl it or check it out in your browser ? Could there be something preventing the callback from reaching the server that is spun up ?

It should look something like this: sleeping_server

DavidEdell commented 10 months ago

It doesn't look like a server is running, but it's also not even running the sleep commands from this playbook (it doesn't pause at all).

Output:

ansible-playbook -vvv playbooks/sleeping_server.yaml > sleeping_server.log
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that
the implicit localhost does not match 'all'
[WARNING]: Failure using method (v2_playbook_on_start) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f95bcf5deb0>): Expecting value: line 1 column 1 (char 0)
[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f95bcf5deb0>): 'NoneType' object is not subscriptable
[WARNING]: Failure using method (v2_playbook_on_task_start) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f95bcf5deb0>): 'NoneType' object is not subscriptable
[WARNING]: Failure using method (v2_runner_on_failed) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f95bcf5deb0>): '9b1ee0f8-7945-69be-cba2-000000000007'
[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin
(<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f95bcf5deb0>): 'NoneType' object is not subscriptable

stdout:

cat sleeping_server.log
ansible-playbook [core 2.13.13]
  config file = None
  configured module search path = ['/home/user/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible
  ansible collection location = /home/user/.ansible/collections:/usr/share/ansible/collections
  executable location = /home/user/ansible_setup/take3/bin/ansible-playbook
  python version = 3.8.10 (default, Nov 22 2023, 10:22:35) [GCC 9.4.0]
  jinja version = 3.1.2
  libyaml = True
No config file found; using defaults
host_list declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
script declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
auto declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
yaml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
ini declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Skipping due to inventory source not existing or not being readable by the current user
toml declined parsing /etc/ansible/hosts as it did not pass its verify_file() method
Operations to perform:
  Apply all migrations: admin, api, auth, contenttypes, db, sessions
Running migrations:
  No migrations to apply.
Skipping callback 'default', as we already have a stdout callback.
Skipping callback 'minimal', as we already have a stdout callback.
Skipping callback 'oneline', as we already have a stdout callback.

PLAYBOOK: sleeping_server.yaml *************************************************
2024-01-16 10:28:28,103 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 3, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('playbooks/sleeping_server.yaml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/playbooks/sleeping_server.yaml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2024-01-16T15:28:28.097394+00:00'}
2024-01-16 10:28:28,103 ERROR ara.clients.http: Failed to post on /api/v1/playbooks: {'ansible_version': '2.13.13', 'client_version': '1.7.0', 'python_version': '3.8.10', 'arguments': {'version': None, 'verbosity': 3, 'private_key_file': None, 'remote_user': None, 'connection': 'smart', 'timeout': 10, 'ssh_common_args': None, 'sftp_extra_args': None, 'scp_extra_args': None, 'ssh_extra_args': None, 'ask_pass': False, 'connection_password_file': None, 'force_handlers': False, 'flush_cache': False, 'become': False, 'become_method': 'sudo', 'become_user': None, 'become_ask_pass': False, 'become_password_file': None, 'tags': ('all',), 'skip_tags': (), 'check': False, 'syntax': False, 'diff': False, 'inventory': ('/etc/ansible/hosts',), 'listhosts': False, 'subset': None, 'extra_vars': "Not saved by ARA as configured by 'ignored_arguments'", 'vault_ids': (), 'ask_vault_pass': False, 'vault_password_files': (), 'forks': 5, 'module_path': None, 'listtasks': False, 'listtags': False, 'step': False, 'start_at_task': None, 'args': ('playbooks/sleeping_server.yaml',)}, 'status': 'running', 'path': '/home/user/ansible_setup/playbooks/sleeping_server.yaml', 'controller': 'cor-moog-1', 'user': 'user', 'started': '2024-01-16T15:28:28.097394+00:00'}
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 446, in v2_playbook_on_start
    self.playbook = self.client.post(
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 105, in post
    return self._request("post", endpoint, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 96, in _request
    return response.json()
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
1 plays in playbooks/sleeping_server.yaml

PLAY [Spin up a server and sleep] **********************************************
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 500, in v2_playbook_on_play_start
    self._submit_thread("global", self._set_playbook_labels, labels)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 395, in _submit_thread
    func(*args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 675, in _set_playbook_labels
    current_labels = [label["name"] for label in self.playbook["labels"]]
META: ran handlers

TASK [Recover base url from ara] ***********************************************
task path: /home/user/ansible_setup/playbooks/sleeping_server.yaml:11
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 554, in v2_playbook_on_task_start
    task_file = self._get_or_create_file(path)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 709, in _get_or_create_file
    "/api/v1/files", playbook=self.playbook["id"], path=path, content=content
fatal: [localhost]: FAILED! => {
    "msg": "lookup plugin (ara_api) not found"
}
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 589, in v2_runner_on_failed
    "/api/v1/tasks/%s" % self.task_cache[task_uuid]["id"], status="failed"

PLAY RECAP *********************************************************************
localhost                  : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 622, in v2_playbook_on_stats
    self._load_stats(stats)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 847, in _load_stats
    host = self._get_or_create_host(hostname)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 733, in _get_or_create_host
    self.host_cache[host] = self.client.post("/api/v1/hosts", name=host, playbook=self.playbook["id"])
dmsimard commented 10 months ago

It looks like it fails before sleeping, here: lookup plugin (ara_api) not found.

Can you try again with export ANSIBLE_LOOKUP_PLUGINS=$(python3 -m ara.setup.lookup_plugins) in addition to the callback configuration ?

DavidEdell commented 10 months ago

Results were very similar. The only difference (I diff'd the stdout) was a different exception in the recover base url task:

TASK [Recover base url from ara] ***********************************************
task path: /home/user/ansible_setup/playbooks/sleeping_server.yaml:11
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 554, in v2_playbook_on_task_start
    task_file = self._get_or_create_file(path)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 709, in _get_or_create_file
    "/api/v1/files", playbook=self.playbook["id"], path=path, content=content
2024-01-16 20:46:25,034 ERROR ara.clients.http: Failed to get on /api/: {'params': {}}
2024-01-16 20:46:25,034 ERROR ara.clients.http: Failed to get on /api/: {'params': {}}
exception during Jinja2 execution: Traceback (most recent call last):
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/requests/models.py", line 971, in json
    return complexjson.loads(self.text, **kwargs)
  File "/usr/lib/python3.8/json/__init__.py", line 357, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.8/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python3.8/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/template/__init__.py", line 984, in _lookup
    ran = instance.run(loop_terms, variables=self._available_variables, **kwargs)
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/lookup/ara_api.py", line 46, in run
    ret.append(self.client.get(term))
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 99, in get
    return self._request("get", endpoint, params=kwargs)
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/clients/http.py", line 96, in _request
    return response.json()
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
requests.exceptions.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
fatal: [localhost]: FAILED! => {
    "msg": "An unhandled exception occurred while running the lookup plugin 'ara_api'. Error was a <class 'requests.exceptions.JSONDecodeError'>, original message: Expecting value: line 1 column 1 (char 0). Expecting value: line 1 column 1 (char 0)"
}
Callback Exception:
  File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ansible/executor/task_queue_manager.py", line 434, in send_callback
    method(*new_args, **kwargs)
   File "/home/user/ansible_setup/take3/lib/python3.8/site-packages/ara/plugins/callback/ara_default.py", line 589, in v2_runner_on_failed
    "/api/v1/tasks/%s" % self.task_cache[task_uuid]["id"], status="failed"
NRamdat commented 6 months ago

Got a solution already? It has been 3 months..

DavidEdell commented 6 months ago

I haven't made any progress (or even looked at this) since my last message. I may poke at it again soon, as my project is now circling back to a point where Ara would actually be useful.

NRamdat commented 6 months ago

Thanks, to bad. I have similar errors. At the moment the API version on one machine works, but when I try to add another with the API callback. Nothing happens. I will keep troubleshooting and will keep you posted if I found any solution.

dmsimard commented 6 months ago

I haven't been able to reproduce the issue on my end and so I don't have a hint about the problem or the solution.

If someone finds more information about the problem I can look into it but it is not on top of my to-do list at the moment.

DavidEdell commented 6 months ago

I just gave it another try, this time after starting an API server and pointing ARA to it, but I'm still getting the same errors.

DavidEdell commented 6 months ago

I got things (somewhat) working using a discrete API server, though only when it is also running on the localhost. Prior to that, some printf-based-debugging showed that http.py's self.http.request call was returning a "400 bad request" when configured with the API server on a remote host (which is a secondary issue). When configured for the original offline client, it was getting a 503 error while querying localhost:40389.

I also found I need to run ara-manage migrate before ara-manage runserver 8080 gave me functional output.

The lingering issue is that while ara playbook list works, the server's browser interface confusingly only reports No recorded results found. A manual query of the ~/.ara/server/ansible.sqlite DB shows it is empty (no records). Debug outputs show that http.py is doing a GET of http://localhost:8000/api/v1/playbooks and returning the list of playbooks I expect and which ara playbook list displays. Yet if I try accessing that API path in the browser I get a Django UI with an empty results:[], while wget returns a 503 error. Something isn't adding up here.

Fyi, the machine I'm running ARA on doesn't have direct network access however, so I had to manually import the docker container to get the API server easily running:

docker pull docker.io/recordsansible/ara-api:latest
docker save --output ara-api-server.tar recordsansible/ara-api
# Copy tar file to other machine
docker load < ara-api-server.tar
docker run --name api-server --detach --tty --volume ~/.ara/server:/opt/ara:z -p 8000:8000 docker.io/recordsansible/ara-api:latest