Sometimes (randomly) I get the error: No inventory was parsed, only implicit localhost is available

[ane-ruiz]

Hello,

Currently I have my environment composed by Netbox (version 3.5.3), Ansible (core version 2.14.4) and jenkins (version 2.387.1). Also, the python version is 3.10.6. The problem I have is that sometimes, without any consistency, I get the following error:

[DEPRECATION WARNING]: [defaults]callback_whitelist option, normalizing names 
to new standard, use callbacks_enabled instead. This feature will be removed 
from ansible-core in version 2.15. Deprecation warnings can be disabled by 
setting deprecation_warnings=False in ansible.cfg.
Exception in thread Thread-4 (wrapper):
Traceback (most recent call last):
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 410, in _fetch_information
    response = open_url(
  File "/usr/local/lib/python3.10/dist-packages/ansible/module_utils/urls.py", line 1665, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/usr/local/lib/python3.10/dist-packages/ansible/module_utils/urls.py", line 1557, in open
    r = urllib_request.urlopen(request, None, timeout)
  File "/usr/lib/python3.10/urllib/request.py", line 216, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.10/urllib/request.py", line 525, in open
    response = meth(req, response)
  File "/usr/lib/python3.10/urllib/request.py", line 634, in http_response
    response = self.parent.error(
  File "/usr/lib/python3.10/urllib/request.py", line 563, in error
    return self._call_chain(*args)
  File "/usr/lib/python3.10/urllib/request.py", line 496, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.10/urllib/request.py", line 643, in http_error_default
    raise HTTPError(req.full_url, code, msg, hdrs, fp)
urllib.error.HTTPError: HTTP Error 500: Internal Server Error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1459, in wrapper
    raise e
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1454, in wrapper
    lookup()
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1122, in refresh_locations_lookup
    locations = self.get_resource_list(api_url=url)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 468, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 436, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "could not open file \"base/16385/16637\": Operation not permitted\n", "exception": "ProgrammingError", "netbox_version": "3.5.3", "python_version": "3.10.6"}
Exception in thread Thread-3 (wrapper):
Traceback (most recent call last):
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 410, in _fetch_information
    response = open_url(
  File "/usr/local/lib/python3.10/dist-packages/ansible/module_utils/urls.py", line 1665, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/usr/local/lib/python3.10/dist-packages/ansible/module_utils/urls.py", line 1557, in open
    r = urllib_request.urlopen(request, None, timeout)
  File "/usr/lib/python3.10/urllib/request.py", line 216, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.10/urllib/request.py", line 525, in open
    response = meth(req, response)
  File "/usr/lib/python3.10/urllib/request.py", line 634, in http_response
    response = self.parent.error(
  File "/usr/lib/python3.10/urllib/request.py", line 563, in error
    return self._call_chain(*args)
  File "/usr/lib/python3.10/urllib/request.py", line 496, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.10/urllib/request.py", line 643, in http_error_default
    raise HTTPError(req.full_url, code, msg, hdrs, fp)
urllib.error.HTTPError: HTTP Error 500: Internal Server Error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1459, in wrapper
    raise e
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1454, in wrapper
    lookup()
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 1099, in refresh_site_groups_lookup
    site_groups = self.get_resource_list(api_url=url)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 468, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/var/lib/jenkins/.ansible/collections/ansible_collections/netbox/netbox/plugins/inventory/nb_inventory.py", line 436, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "could not open file \"base/16385/16819\": Operation not permitted\n", "exception": "ProgrammingError", "netbox_version": "3.5.3", "python_version": "3.10.6"}
[WARNING]:  * Failed to parse /var/lib/jenkins/workspace/Network
Automation/Himeji UFW - Microsegmentacion/Firewall Automation by
Service/netbox_inventory_service.yml with auto plugin: {"error": "could not
open file \"base/16385/16637\": Operation not permitted\n", "exception":
"ProgrammingError", "netbox_version": "3.5.3", "python_version": "3.10.6"}
[WARNING]:  * Failed to parse /var/lib/jenkins/workspace/Network
Automation/Himeji UFW - Microsegmentacion/Firewall Automation by
Service/netbox_inventory_service.yml with yaml plugin: Plugin configuration
YAML file, not YAML inventory
[WARNING]:  * Failed to parse /var/lib/jenkins/workspace/Network
Automation/Himeji UFW - Microsegmentacion/Firewall Automation by
Service/netbox_inventory_service.yml with ini plugin: Invalid host pattern
'---' supplied, '---' is normally a sign this is a YAML file.
[WARNING]: Unable to parse /var/lib/jenkins/workspace/Network Automation/Himeji
UFW - Microsegmentacion/Firewall Automation by
Service/netbox_inventory_service.yml as an inventory source
[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'

PLAY [Firewall automation] *****************************************************
skipping: no hosts matched

If I rerun the job launches an ansible playbook, the parse with the inventory works correctly.

Does anyone know what this is due to and how I can fix it?

The Netbox server and the one with Ansible+Jenkins are on the same network, with direct connectivity. When I run it manually I don't mind re-running it, but for scheduled or automatic tasks with webhooks I don't like this happening. Has anything similar happened to anyone?

Please help.
Thank you!!

Ane

[sc68cal]

Code path where this error happens is

ansible_modules/plugins/inventory/nb_inventory.py

Line 433 in 0215e17

Please check issue #294 for more info.

[sc68cal]

Can you look on the NetBox server and see what is in the logs, as to why the server returned a 500 error?

[sc68cal]

You are probably going to have to enable debug in the Netbox server so we can see the tracebacks for those 500 internal server errors

https://demo.netbox.dev/static/docs/configuration/optional-settings/

[ane-ruiz]

Hi,

I have enabled the DEBUG level you indicate but it still doesn't tell me anything clear. At the time of the error I see similar lines:

(In this case, the time of the error was 14:26.)

2023-07-13 14:23:39,304 netbox.config DEBUG: Initialized configuration
2023-07-13 14:23:39,418 netbox.config DEBUG: Cleared configuration
2023-07-13 14:23:39,798 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:23:39,798 netbox.config DEBUG: Initialized configuration
2023-07-13 14:23:39,915 netbox.config DEBUG: Cleared configuration
2023-07-13 14:23:40,047 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:23:40,047 netbox.config DEBUG: Initialized configuration
2023-07-13 14:23:40,143 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:35,101 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:35,102 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:35,179 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:37,398 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:37,398 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:37,412 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:37,625 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:37,625 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:40,732 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:41,314 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,314 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,380 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:41,395 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,395 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,500 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:41,527 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,527 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,536 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,536 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,551 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,551 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,584 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,585 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,606 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:41,606 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:41,673 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:41,674 django.request ERROR: Internal Server Error: /api/dcim/regions/
2023-07-13 14:26:42,312 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,313 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,324 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,324 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,328 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,328 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,345 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,345 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,400 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,423 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,424 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,523 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,598 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,609 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,614 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,629 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,629 netbox.config DEBUG: No previous configuration found in database; proceeding with default values
2023-07-13 14:26:42,634 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,640 netbox.config DEBUG: Initialized configuration
2023-07-13 14:26:42,740 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,741 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,776 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,924 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:42,954 netbox.config DEBUG: Cleared configuration
2023-07-13 14:26:43,065 netbox.config DEBUG: Cleared configuration

In postgresql (version 12) the time shown is 2 hours less than the real time (12:26). This is the log in postgresql:

2023-07-13 12:06:21.261 UTC [204463] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:18:40.192 UTC [206437] netbox@netbox LOG:  could not receive data from client: Connection reset by peer
2023-07-13 12:20:22.320 UTC [206688] netbox@netbox LOG:  could not receive data from client: Connection reset by peer
2023-07-13 12:20:25.869 UTC [206697] netbox@netbox LOG:  could not receive data from client: Connection reset by peer
2023-07-13 12:26:41.646 UTC [207861] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:26:41.646 UTC [207864] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:26:41.646 UTC [207863] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:26:41.649 UTC [207859] netbox@netbox ERROR:  could not open file "base/16385/16794": Operation not permitted
2023-07-13 12:26:41.649 UTC [207859] netbox@netbox STATEMENT:  SELECT COUNT(*) FROM (SELECT (SELECT count(*) FROM (SELECT U0."id" FROM "dcim_site" U0 INNER JOIN "dcim_region" U1 ON (U0."region_id" = U1."id") WHERE (U1."lft" >= ("dcim_region"."lft") AND U1."lft" <= ("dcim_region"."rght") AND U1."tree_id" = ("dcim_region"."tree_id")) ORDER BY U0."_name" ASC) _count) AS "site_count" FROM "dcim_region") subquery

In the postgresql configuration file I have the following, according to the characteristics that my netbox virtual machine has (Postgresql version 12, Linux, RAM 4GB, 2 CPUs, HDD Storage):

# DB Version: 12
# OS Type: linux
# DB Type: web
# Total Memory (RAM): 4 GB
# CPUs num: 2
# Data Storage: hdd

max_connections = 200
shared_buffers = 1GB
effective_cache_size = 3GB
maintenance_work_mem = 256MB
checkpoint_completion_target = 0.9
wal_buffers = 16MB
default_statistics_target = 100
random_page_cost = 4
effective_io_concurrency = 2
work_mem = 2621kB
min_wal_size = 1GB
max_wal_size = 4GB

With this info, would you know what the error could be due to?

Thank you!!!!

[sc68cal]

2023-07-13 12:26:41.646 UTC [207861] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:26:41.646 UTC [207864] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted
2023-07-13 12:26:41.646 UTC [207863] netbox@netbox FATAL:  could not open file "global/pg_filenode.map": Operation not permitted

Is your filesystem full?

[ane-ruiz]

Hello,

Checking the Ubuntu 22.04 virtual machine, it does not have the filesystem full. Also, I have upgraded the resources to 4 CPUs and 8GB of RAM. I have removed version 12 of postgresql that we had when the machine was Ubuntu 20.04 and now I am using version 14. I have modified the values in the postgresql configuration file to the following:

# DB Version: 14
# OS Type: linux
# DB Type: web
# Total Memory (RAM): 8 GB
# CPUs num: 4
# Data Storage: hdd

max_connections = 200
shared_buffers = 2GB
effective_cache_size = 6GB
maintenance_work_mem = 512MB
checkpoint_completion_target = 0.9
wal_buffers = 16MB
default_statistics_target = 100
random_page_cost = 4
effective_io_concurrency = 2
work_mem = 5242kB
min_wal_size = 1GB
max_wal_size = 4GB
max_worker_processes = 4
max_parallel_workers_per_gather = 2
max_parallel_workers = 4
max_parallel_maintenance_workers = 2

I keep getting the same error....

Help, please.
Thanks!!

[sc68cal]

Honestly, this is a postgres issue or a netbox server issue, not a ansible issue, so I don't think we can really help. It's things that are out of scope for this Github repository. I would suggest asking elsewhere