ara icon indicating copy to clipboard operation
ara copied to clipboard

Ansible inventory hostnames longer than 255 characters lead to exceptions

Open nerijus opened this issue 4 years ago • 18 comments

I updated to ara 1.5.6 hoping that it will fix it (see https://github.com/ansible-community/ara/issues/211), but exceptions remain:

[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f9ff7d6d3a0>): 'id'
[WARNING]: Failure using method (v2_playbook_on_task_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f9ff7d6d3a0>): 'id'

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

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

[WARNING]: Failure using method (v2_playbook_on_stats) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7f9ff7d6d3a0>): 'id'

Versions:

Ansible Version: 2.10.6
ARA Version: 1.5.6

Server side logs:

bal. 19 13:19:56 localhost gunicorn[511750]: 2021-04-19 13:19:56,084 WARNING django.request: Bad Request: /api/v1/plays

nerijus avatar Apr 19 '21 13:04 nerijus

Hi @nerijus and thanks for the issue.

Could you tell us a bit more about how you are running into the error ? Can you provide the steps to reproduce it ?

Thanks,

dmsimard avatar Apr 19 '21 22:04 dmsimard

I am running ansible-playbook prod.yaml --tags frontend --limit core_frontend --skip-tags install. How do I provide more info? Tried running ARA_DEBUG=true ARA_LOG_LEVEL=DEBUG ansible-playbook ... - did not give any additional output.

nerijus avatar Apr 20 '21 07:04 nerijus

Providing ARA_DEBUG=true and ARA_LOG_LEVEL=DEBUG to the server side (gunicorn) should hopefully provide more logging, if not, can you try running without gunicorn and the default API client (offline) ?

It should look something like this:

> export ARA_DEBUG=true
> export ARA_LOG_LEVEL=DEBUG
> export ANSIBLE_CALLBACK_PLUGINS=$(python3 -m ara.setup.callback_plugins)
> ansible-playbook tests/integration/hosts.yaml
[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'
Operations to perform:
  Apply all migrations: admin, api, auth, contenttypes, db, sessions
Running migrations:
  No migrations to apply.
2021-04-20 09:56:14,678 DEBUG ara.plugins.callback.default: v2_playbook_on_start
2021-04-20 09:56:14,679 DEBUG ara.plugins.callback.default: Ignoring argument: extra_vars
2021-04-20 09:56:14,680 DEBUG urllib3.connectionpool: Starting new HTTP connection (1): localhost:35697
2021-04-20 09:56:14,708 DEBUG urllib3.connectionpool: http://localhost:35697 "POST /api/v1/playbooks HTTP/1.1" 201 1116
2021-04-20 09:56:14,708 DEBUG ara.clients.http: HTTP 201: post on /api/v1/playbooks
2021-04-20 09:56:14,708 DEBUG ara.plugins.callback.default: File not in cache, getting or creating: /home/dmsimard/dev/git/ansible-community/ara/tests/integration/hosts.yaml
2021-04-20 09:56:14,723 DEBUG urllib3.connectionpool: http://localhost:35697 "POST /api/v1/files HTTP/1.1" 201 1784
2021-04-20 09:56:14,724 DEBUG ara.clients.http: HTTP 201: post on /api/v1/files

PLAY [Create fake hosts for host tests] ****************************************************************************************************************************************************************************************************************************************************
2021-04-20 09:56:14,726 DEBUG ara.plugins.callback.default: v2_playbook_on_play_start
2021-04-20 09:56:14,726 DEBUG ara.plugins.callback.default: Updating playbook labels to match: check:False,tags:all
2021-04-20 09:56:14,750 DEBUG urllib3.connectionpool: http://localhost:35697 "PATCH /api/v1/playbooks/13 HTTP/1.1" 200 1172
2021-04-20 09:56:14,751 DEBUG ara.clients.http: HTTP 200: patch on /api/v1/playbooks/13
2021-04-20 09:56:14,806 DEBUG urllib3.connectionpool: http://localhost:35697 "POST /api/v1/plays HTTP/1.1" 201 294
2021-04-20 09:56:14,807 DEBUG ara.clients.http: HTTP 201: post on /api/v1/plays

# [...]

Edit: also, ansible-playbook tends to "eat" exceptions from the callback too unless it is super verbose (ansible-playbook -vvv).

dmsimard avatar Apr 20 '21 13:04 dmsimard

Thank you. Output of ansible-playbook -vvv:

[WARNING]: Failure using method (v2_playbook_on_task_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7efe4a32b640>): 'id'
Callback Exception: 
  File "/usr/lib/python3.9/site-packages/ansible/executor/task_queue_manager.py", line 389, in send_callback
    method(*new_args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 378, in v2_playbook_on_task_start
    play=self.play["id"],
Read vars_file 'prod-vars.yaml'
[WARNING]: Failure using method (v2_runner_on_skipped) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7efe4a32b640>): 'NoneType' object is not subscriptable
Callback Exception: 
  File "/usr/lib/python3.9/site-packages/ansible/executor/task_queue_manager.py", line 389, in send_callback
    method(*new_args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 403, in v2_runner_on_skipped
    self._submit_thread("task", self._load_result, result, "skipped", **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 247, in _submit_thread
    func(*args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 532, in _load_result
    task=self.task["id"],
Read vars_file 'prod-vars.yaml'
...
[WARNING]: Failure using method (v2_playbook_on_play_start) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7efe4a32b640>): 'id'
Callback Exception: 
  File "/usr/lib/python3.9/site-packages/ansible/executor/task_queue_manager.py", line 389, in send_callback
    method(*new_args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 308, in v2_playbook_on_play_start
    self._end_play()
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 433, in _end_play
    "/api/v1/plays/%s" % self.play["id"],
Read vars_file 'prod-vars.yaml'
META: ran handlers
Read vars_file 'prod-vars.yaml'
...
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at 0x7efe4a32b640>): 'NoneType' object is not subscriptable
Callback Exception: 
  File "/usr/lib/python3.9/site-packages/ansible/executor/task_queue_manager.py", line 389, in send_callback
    method(*new_args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 394, in v2_runner_on_ok
    self._submit_thread("task", self._load_result, result, "ok", **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 247, in _submit_thread
    func(*args, **kwargs)
   File "/usr/lib/python3.9/site-packages/ara/plugins/callback/ara_default.py", line 532, in _load_result
    task=self.task["id"],

nerijus avatar Apr 20 '21 15:04 nerijus

@nerijus thanks for the additional logging. Some questions:

  • Do you have playbooks in the web interface at all ?
  • Does the playbook use serial ?
  • Assuming you have ARA_API_CLIENT=http, do you also enable multi-threading with ARA_CALLBACK_THREADS ?

dmsimard avatar Apr 20 '21 16:04 dmsimard

Yes. Yes, but the tag which I use does not have serial. I do not have ARA_CALLBACK_THREADS, all I have in ansible.cfg about ara is:

[defaults]
callback_plugins=~/.local/lib/python3.*/*-packages/ara/plugins/callback:/usr/lib/python3.*/*-packages/ara/plugins/callback:/usr/local/lib/python*/*-packages/ara/plugins/callback
action_plugins=~/.local/lib/python3.*/*-packages/ara/plugins/action:/usr/lib/python3.*/*-packages/ara/plugins/action:/usr/local/lib/python*/*-packages/ara/plugins/action
lookup_plugins=~/.local/lib/python3.*/*-packages/ara/plugins/lookup:/usr/lib/python3.*/*-packages/ara/plugins/lookup:/usr/local/lib/python*/*-packages/ara/plugins/lookup

[ara]
api_client = http
api_server = https://ara...
api_username = ara
api_password = ...

nerijus avatar Apr 20 '21 17:04 nerijus

I minimized playbook so that only tasks which use my tags are left, but then there are no more warnings/exceptions. So it could be related to serial.

nerijus avatar Apr 21 '21 08:04 nerijus

I restored playbook and removed only this section (which is skipped as it does not have needed tags):

- hosts: "{{ proxy_config | map(attribute='hosts') | flatten | join(':') }}"
  vars_files:
    - "prod-vars.yaml"
  roles:
    - role: nginx

and there are no more warnings/exceptions.

nerijus avatar Apr 21 '21 08:04 nerijus

@nerijus I'm not certain I understand and would like to clarify -- are you saying that you are able to reproduce the errors with the playbook in your last comment ? Otherwise, can you provide a playbook that reproduces the issue ?

Thanks,

dmsimard avatar Apr 21 '21 14:04 dmsimard

Yes, I am able to reproduce errors when this part is in the playbook (although this part is skipped because of tags).

nerijus avatar Apr 21 '21 15:04 nerijus

I have, also, experienced the same issue and managed to find out when it occurs. It seems that warning messages appear when hosts list contains more than 255 characters. I have tested with hosts list less than 255 characters and no more warning messages appears.

My guess: this issue might be linked to the following code part https://github.com/ansible-community/ara/blob/master/ara/api/models.py#L228.

@nerijus Maybe this Jinja2 expression returns more than 255 characters ?

- hosts: "{{ proxy_config | map(attribute='hosts') | flatten | join(':') }}"

bsdmon avatar Nov 15 '21 13:11 bsdmon

if this is the reason you should see error messages in your server log which are locking like this:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/mysql/base.py", line 71, in execute
    return self.cursor.execute(query, args)
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 209, in execute
    res = self._query(query)
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 315, in _query
    db.query(q)
  File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 239, in query
    _mysql.connection.query(self, query)
MySQLdb._exceptions.DataError: (1406, "Data too long for column 'name' at row 1")

hille721 avatar Nov 15 '21 15:11 hille721

Maybe this Jinja2 expression returns more than 255 characters ?

- hosts: "{{ proxy_config | map(attribute='hosts') | flatten | join(':') }}"

No, it has 231 characters.

nerijus avatar Nov 15 '21 15:11 nerijus

Thanks for reviving this issue @nerijus :)

This reminded me of another issue about labels also running into a 255 character limit: https://github.com/ansible-community/ara/issues/185

I'm not sure if it's possible to have a DNS that long (stackoverflow suggests max 253 characters) but the ansible inventory name, on the other hand...

echo $(python3 -c "print('a'*512)") ansible_host=127.0.0.1 ansible_connection=local > /tmp/hosts
export ANSIBLE_CALLBACK_PLUGINS=$(python3 -m ara.setup.callback_plugins)
export ARA_DEBUG=true
export ARA_LOG_LEVEL=DEBUG
ansible-playbook -i /tmp/hosts tests/integration/hosts.yaml -vv
# ...

ok: [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa]
2021-11-15 21:36:48,897 DEBUG ara.plugins.callback.default: Host not in cache, getting or creating: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
Bad Request: /api/v1/hosts
2021-11-15 21:36:48,909 WARNING django.request: Bad Request: /api/v1/hosts
2021-11-15 21:36:48,910 DEBUG urllib3.connectionpool: http://localhost:37563 "POST /api/v1/hosts HTTP/1.1" 400 63
2021-11-15 21:36:48,911 DEBUG ara.clients.http: HTTP 400: post on /api/v1/hosts
2021-11-15 21:36:48,912 ERROR ara.clients.http: Failed to post on /api/v1/hosts: {'name': 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa', 'playbook': 313}
2021-11-15 21:36:48,916 DEBUG ara.plugins.callback.default: Ignoring fact: ansible_env
[WARNING]: Failure using method (v2_runner_on_ok) in callback plugin (<ansible.plugins.callback.ara_default.CallbackModule object at
0x7f2760d06b30>): 'id'
# ...

and then later exceptions are raised because the host doesn't exist as the ara callback tries to associate results to it.

(on another note, I have briefly tried to get the actual django traceback from the API server and I didn't manage to get it.. TODO: improve logging...)

Should the callback truncate to 254 characters before sending the inventory hostname ? I tested and it works but the web interface doesn't handle it very gracefully :rofl:

screenshot_2021-11-15_8cc8cc

dmsimard avatar Nov 16 '21 03:11 dmsimard

I have a commit that truncates the inventory hostname if it's >=255 characters: https://github.com/dmsimard/ara/commit/ae61690e65ea98514c4fc877782a82ce728a55db

It works but I would need to write a test or two for it. We could also argue that we could lift the character limit of the hostname field instead.

I looked at the AWX host model out of curiosity and they limit it at 512 instead of 255: https://github.com/ansible/awx/blob/ba324c73ceefa22d516d872527649d090d3bc0cc/awx/main/models/base.py#L368-L377

I don't have a strong opinion -- is there a significant impact other than a sql migration to alter the field ?

dmsimard avatar Nov 20 '21 20:11 dmsimard

It seems it is char limit - when expr length is 294 and 261 chars, we get error, and when we remove servers from the list until expr length is 228 chars, it works. @dmsimard , I would suggest limit it at 512 as awx does too.

nerijus avatar Mar 30 '22 10:03 nerijus

I'm re-opening this because I just came across a warning when using a MySQL backend:

api.Label.name: (mysql.W003) MariaDB may not allow unique CharFields to have a max_length > 255.
	HINT: See: https://docs.djangoproject.com/en/3.2/ref/databases/#mysql-character-fields

I will look into it another time, I just didn't want to forget about it.

cc @dvwh

dmsimard avatar Aug 16 '22 14:08 dmsimard

From the django documentation:

Screenshot from 2022-09-17 19-47-08

I suppose AWX does not run into this restriction because it requires postgresql while ara targets to be compatible with mysql and sqlite as well.

With that in mind, I suppose we should instead truncate the names if they are longer than 255 characters such that it does not fail. We should print a warning if we do that in order to let the user know, though.

I am satisfied with classifying this under known issues.

dmsimard avatar Sep 17 '22 23:09 dmsimard

I've sent a PR to truncate names to 255 characters and reverted the migration that upped the limit to 512 characters to prevent impacting mysql support: https://github.com/ansible-community/ara/pull/437

The callback will print a warning when it truncates something so it is not done silently.

It isn't ideal but shouldn't result in exceptions if there are things longer than 255 characters now.

dmsimard avatar Oct 06 '22 01:10 dmsimard

I've sent a PR to truncate names to 255 characters and reverted the migration that upped the limit to 512 characters to prevent impacting mysql support: #437 You say in 437:

Trying to send an inventory hostname that is longer than 255 characters to the API trips into an exception because the field is a varchar(255).

Truncate the hostname to prevent an exception and warn about it once per host if it happens.

In our case the problem is not with the single hostname (we don't have hostnames length > 255), but with a list of hosts:

- hosts: "{{ proxy_config | map(attribute='hosts') | flatten | join(':') }}"

Will it work in our case too?

nerijus avatar Oct 06 '22 13:10 nerijus

@nerijus what ara records are the individual host names, not the full list (or jinja expression) provided to the hosts key of a play.

So long as your jinja expression doesn't yield individual hosts that have names longer than 255 characters, it should be fine. And now, even if they have names longer than 255 characters, it will still work but they will be truncated to fit.

dmsimard avatar Oct 06 '22 16:10 dmsimard

But it is not fine, we still get exceptions like in the 1st post, although all our hostnames are less than 255. Are you telling that it should work even now without #437 ?

nerijus avatar Oct 06 '22 17:10 nerijus

I just tested with #437 , it is ok now, I don't get exceptions anymore. Thanks!

nerijus avatar Oct 07 '22 10:10 nerijus

I just tested with #437 , it is ok now, I don't get exceptions anymore. Thanks!

Yes, this is what the PR is intended to mitigate. Thanks for testing and confirming it works for you!

dmsimard avatar Oct 07 '22 15:10 dmsimard

Closing this issue now that the fix has merged in the master branch. It'll be released in 1.6.0.

dmsimard avatar Oct 08 '22 15:10 dmsimard