Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Concurrency issues(²?) #950

Closed
u1735067 opened this issue Sep 28, 2021 · 8 comments · Fixed by #2424
Closed

Concurrency issues(²?) #950

u1735067 opened this issue Sep 28, 2021 · 8 comments · Fixed by #2424
Assignees
Labels
type: bug Something isn't working as expected

Comments

@u1735067
Copy link
Contributor

Environment

  • Python version: 3.9.7
  • Nautobot version: 1.1.3-py39
  • Redis: redis:6.2.5-alpine
  • PSQL: postgres:13.3-alpine

Docker-compose extract:

---
version: '3.4'

services:
  nautobot: &nautobot
    image: networktocode/nautobot:1.1.3-py3.9
    restart: unless-stopped
    depends_on:
      - postgres
      - redis
    volumes:
      - ./volumes/media:/opt/nautobot/media:z,rw
      - ./volumes/git:/opt/nautobot/git:z,rw
      - ./volumes/jobs:/opt/nautobot/jobs:z,rw
    environment:
      NAUTOBOT_DB_HOST: postgres
      NAUTOBOT_DB_USER: nautobot
      NAUTOBOT_DB_PASSWORD: nautobot
      NAUTOBOT_DB_NAME: nautobot
      NAUTOBOT_REDIS_HOST: redis
      NAUTOBOT_SECRET_KEY: "*****"
      NAUTOBOT_MAX_PAGE_SIZE: "5000"
      NAUTOBOT_CHANGELOG_RETENTION: "366"
      NAUTOBOT_METRICS_ENABLED: "false"
      ### NAUTOBOT_CACHEOPS_ENABLED: "false"
      ### NAUTOBOT_UWSGI_PROCESSES: 1
    healthcheck:
      interval: 30s
      timeout: 15s
      start_period: 5s
      retries: 3
      test: ["CMD-SHELL", "curl --fail http://localhost:8080/health/ || exit 1"]

  celery_worker:
    <<: *nautobot
    entrypoint: "nautobot-server celery worker -l INFO"
    networks:
      - default
    labels: []
    depends_on:
      - nautobot
    healthcheck:
      interval: 30s
      timeout: 15s
      start_period: 5s
      retries: 3
      test: ["CMD", "nautobot-server", "health_check"]

  # postgres - https://hub.docker.com/_/postgres
  postgres:
    image: postgres:13.3-alpine
    restart: unless-stopped
    volumes:
      - ./volumes/pgsql:/var/lib/postgresql/data
    environment:
      TZ: Europe/Paris
      POSTGRES_USER: nautobot
      POSTGRES_PASSWORD: nautobot
      POSTGRES_DB: nautobot

  # redis - https://hub.docker.com/_/redis
  redis:
    image: redis:6.2.5-alpine

Steps to Reproduce

  1. Prepare an Ansible inventory using the inventory plugin from https://github.com/nautobot/nautobot-ansible/, like:
    # my_inventory.yml
    plugin: networktocode.nautobot.inventory
    api_endpoint: https://MY_URL/
    token: MY_TOKEN
    config_context: true
    plurals: false
    interfaces: true
    group_by:
      - platform
      - role
      - site
    device_query_filters:
      - tenant: adm
      - status: active
    compose:
  2. Start a populated Nautobot docker-compose stack after removing all anonymous volumes (like redis data if any):
    • docker-compose down -v --remove-orphans
    • docker-compose up -d
    • docker-compose logs -f
  3. Ask Ansible to fetch the inventory, like: ansible-inventory --list -i my_inventory.yml -vv | grep -v ansible_password > inv.json

Expected Behavior

Nautobot answers to all requests without errors, so the Ansible plugin can construct the consolidated inventory

Observed Behavior

Nautobot answers with random errors, like in #744

Additional informations

docker-compose logs
$docker-compose logs -f
Attaching to nautobot-simulation_celery_worker_1, nautobot-simulation_nautobot_1, nautobot-simulation_redis_1, nautobot-simulation_postgres_1
celery_worker_1  |
celery_worker_1  |  -------------- celery@hostname v5.1.2 (sun-harmonics)
celery_worker_1  | --- ***** -----
celery_worker_1  | -- ******* ----
celery_worker_1  | - *** --- * ---
celery_worker_1  | - ** ---------- [config]
celery_worker_1  | - ** ---------- .> app:         nautobot:0x7f78c9732070
celery_worker_1  | - ** ---------- .> transport:   redis://redis:6379/0
celery_worker_1  | - ** ---------- .> results:     redis://redis:6379/0
celery_worker_1  | - *** --- * --- .> concurrency: 2 (prefork)
celery_worker_1  | -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
celery_worker_1  | --- ***** -----
celery_worker_1  |  -------------- [queues]
celery_worker_1  |                 .> celery           exchange=celery(direct) key=celery
celery_worker_1  |
celery_worker_1  |
celery_worker_1  | [tasks]
celery_worker_1  |   . nautobot.extras.datasources.git.pull_git_repository_and_refresh_data
celery_worker_1  |   . nautobot.extras.jobs.run_job
celery_worker_1  |   . nautobot.extras.tasks.delete_custom_field_data
celery_worker_1  |   . nautobot.extras.tasks.process_webhook
celery_worker_1  |   . nautobot.extras.tasks.provision_field
celery_worker_1  |   . nautobot.extras.tasks.update_custom_field_choice_data
celery_worker_1  |   . nautobot.utilities.tasks.get_releases
celery_worker_1  |
celery_worker_1  | [2021-09-28 11:52:17,951: INFO/MainProcess] Connected to redis://redis:6379/0
celery_worker_1  | [2021-09-28 11:52:17,958: INFO/MainProcess] mingle: searching for neighbors
celery_worker_1  | [2021-09-28 11:52:18,972: INFO/MainProcess] mingle: all alone
celery_worker_1  | [2021-09-28 11:52:18,982: INFO/MainProcess] celery@hostname ready.
nautobot_1       | Performing database migrations...
nautobot_1       | Operations to perform:
nautobot_1       |   Apply all migrations: admin, auth, circuits, contenttypes, dcim, extras, ipam, sessions, social_django, taggit, tenancy, users, virtualization
nautobot_1       | Running migrations:
nautobot_1       |   No migrations to apply.
nautobot_1       |
nautobot_1       | Generating cable paths...
nautobot_1       | Found no missing circuit termination paths; skipping
nautobot_1       | Found no missing console port paths; skipping
nautobot_1       | Found no missing console server port paths; skipping
nautobot_1       | Found no missing interface paths; skipping
nautobot_1       | Found no missing power feed paths; skipping
nautobot_1       | Found no missing power outlet paths; skipping
nautobot_1       | Found no missing power port paths; skipping
nautobot_1       | Finished.
nautobot_1       |
nautobot_1       | Collecting static files...
nautobot_1       |
nautobot_1       | 965 static files copied to '/opt/nautobot/static'.
nautobot_1       |
nautobot_1       | Removing stale content types...
nautobot_1       |
nautobot_1       | Removing expired sessions...
nautobot_1       |
nautobot_1       | ⏳ Running initial systems check...
nautobot_1       | System check identified some issues:
nautobot_1       |
nautobot_1       | WARNINGS:
nautobot_1       | ?: (security.W004) You have not set a value for the SECURE_HSTS_SECONDS setting. If your entire site is served only over SSL, you may want to consider setting a value and enabling HTTP Strict Transport Security. Be sure to read the documentation first; enabling HSTS carelessly can cause serious, irreversible problems.
nautobot_1       | ?: (security.W008) Your SECURE_SSL_REDIRECT setting is not set to True. Unless your site should be available over both SSL and non-SSL connections, you may want to either set this setting True or configure a load balancer or reverse-proxy server to redirect all connections to HTTPS.
nautobot_1       | ?: (security.W012) SESSION_COOKIE_SECURE is not set to True. Using a secure-only session cookie makes it more difficult for network traffic sniffers to hijack user sessions.
nautobot_1       | ?: (security.W016) You have 'django.middleware.csrf.CsrfViewMiddleware' in your MIDDLEWARE, but you have not set CSRF_COOKIE_SECURE to True. Using a secure-only CSRF cookie makes it more difficult for network traffic sniffers to steal the CSRF token.
nautobot_1       | ?: (security.W019) You have 'django.middleware.clickjacking.XFrameOptionsMiddleware' in your MIDDLEWARE, but X_FRAME_OPTIONS is not set to 'DENY'. Unless there is a good reason for your site to serve other parts of itself in a frame, you should change it to 'DENY'.
nautobot_1       |
nautobot_1       | System check identified 5 issues (0 silenced).
postgres_1       |
postgres_1       | PostgreSQL Database directory appears to contain a database; Skipping initialization
postgres_1       |
postgres_1       | 2021-09-28 09:52:14.673 UTC [1] LOG:  starting PostgreSQL 13.3 on x86_64-pc-linux-musl, compiled by gcc (Alpine 10.2.1_pre1) 10.2.1 20201203, 64-bit
postgres_1       | 2021-09-28 09:52:14.675 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
postgres_1       | 2021-09-28 09:52:14.676 UTC [1] LOG:  could not create IPv6 socket for address "::": Address family not supported by protocol
postgres_1       | 2021-09-28 09:52:14.679 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
postgres_1       | 2021-09-28 09:52:14.685 UTC [20] LOG:  database system was shut down at 2021-09-28 09:52:11 UTC
postgres_1       | 2021-09-28 09:52:14.688 UTC [1] LOG:  database system is ready to accept connections
redis_1          | 1:C 28 Sep 2021 11:52:14.618 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1          | 1:C 28 Sep 2021 11:52:14.618 # Redis version=6.2.5, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1          | 1:C 28 Sep 2021 11:52:14.618 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
redis_1          | 1:M 28 Sep 2021 11:52:14.619 * monotonic clock: POSIX clock_gettime
redis_1          | 1:M 28 Sep 2021 11:52:14.620 # Warning: Could not create server TCP listening socket ::*:6379: unable to bind socket, errno: 97
redis_1          | 1:M 28 Sep 2021 11:52:14.620 * Running mode=standalone, port=6379.
redis_1          | 1:M 28 Sep 2021 11:52:14.620 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
redis_1          | 1:M 28 Sep 2021 11:52:14.620 # Server initialized
redis_1          | 1:M 28 Sep 2021 11:52:14.620 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
redis_1          | 1:M 28 Sep 2021 11:52:14.620 * Ready to accept connections
nautobot_1       | 11:52:22.026 INFO    nautobot :
nautobot_1       |   Nautobot initialized!
nautobot_1       | [uWSGI] getting INI configuration from /opt/nautobot/uwsgi.ini
nautobot_1       | [uwsgi-static] added mapping for /static => /opt/nautobot/static
nautobot_1       | *** Starting uWSGI 2.0.19.1 (64bit) on [Tue Sep 28 11:52:22 2021] ***
nautobot_1       | compiled with version: 10.2.1 20210110 on 15 September 2021 16:59:02
nautobot_1       | nodename: hostname
nautobot_1       | machine: x86_64
nautobot_1       | clock source: unix
nautobot_1       | detected number of CPU cores: 2
nautobot_1       | current working directory: /opt/nautobot
nautobot_1       | detected binary path: /usr/local/bin/python3.9
nautobot_1       | !!! no internal routing support, rebuild with pcre support !!!
nautobot_1       | your memory page size is 4096 bytes
nautobot_1       | detected max file descriptor number: 1048576
nautobot_1       | building mime-types dictionary from file /etc/mime.types...1476 entry found
nautobot_1       | lock engine: pthread robust mutexes
nautobot_1       | thunder lock: disabled (you can enable it with --thunder-lock)
nautobot_1       | uWSGI http bound on 0.0.0.0:8080 fd 12
nautobot_1       | uWSGI http bound on 0.0.0.0:8443 fd 13
nautobot_1       | uwsgi socket 0 bound to TCP address 127.0.0.1:35739 (port auto-assigned) fd 11
nautobot_1       | Python version: 3.9.7 (default, Sep  3 2021, 02:02:37)  [GCC 10.2.1 20210110]
nautobot_1       | --- Python VM already initialized ---
nautobot_1       | Python main interpreter initialized at 0x55b12876ab90
nautobot_1       | python threads support enabled
nautobot_1       | your server socket listen backlog is limited to 128 connections
nautobot_1       | your mercy for graceful operations on workers is 60 seconds
nautobot_1       | mapped 291680 bytes (284 KB) for 3 cores
nautobot_1       | *** Operational MODE: preforking ***
nautobot_1       | WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x55b12876ab90 pid: 1 (default app)
nautobot_1       | spawned uWSGI master process (pid: 1)
nautobot_1       | spawned uWSGI worker 1 (pid: 14, cores: 1)
nautobot_1       | spawned uWSGI worker 2 (pid: 15, cores: 1)
nautobot_1       | spawned uWSGI worker 3 (pid: 16, cores: 1)
nautobot_1       | spawned uWSGI http 1 (pid: 17)
nautobot_1       | 11:53:02.305 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/platforms/
nautobot_1       | [pid: 16|app: 0|req: 4/23] 172.31.0.2 () {44 vars in 735 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/platforms/?limit=0 => generated 128 bytes in 24 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.337 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/sites/
nautobot_1       | [pid: 15|app: 0|req: 3/25] 172.31.0.2 () {44 vars in 727 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/sites/?limit=0 => generated 178 bytes in 69 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.374 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/tenancy/tenants/
nautobot_1       | [pid: 15|app: 0|req: 4/26] 172.31.0.2 () {44 vars in 738 bytes} [Tue Sep 28 11:53:02 2021] GET /api/tenancy/tenants/?limit=0 => generated 128 bytes in 37 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.382 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/racks/
nautobot_1       | [pid: 16|app: 0|req: 6/27] 172.31.0.2 () {44 vars in 728 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/racks/?limit=0 => generated 150 bytes in 53 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.405 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/device-roles/
nautobot_1       | [pid: 16|app: 0|req: 7/28] 172.31.0.2 () {44 vars in 742 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/device-roles/?limit=0 => generated 128 bytes in 22 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.414 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/device-types/
nautobot_1       | [pid: 15|app: 0|req: 5/29] 172.31.0.2 () {44 vars in 742 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/device-types/?limit=0 => generated 150 bytes in 40 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.442 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/manufacturers/
nautobot_1       | [pid: 15|app: 0|req: 6/30] 172.31.0.2 () {44 vars in 744 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/manufacturers/?limit=0 => generated 128 bytes in 27 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.450 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/interfaces/
nautobot_1       | [pid: 16|app: 0|req: 8/31] 172.31.0.2 () {44 vars in 738 bytes} [Tue Sep 28 11:53:02 2021] GET /api/dcim/interfaces/?limit=0 => generated 150 bytes in 44 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.475 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/virtualization/clusters/
nautobot_1       | [pid: 16|app: 0|req: 9/32] 172.31.0.2 () {44 vars in 754 bytes} [Tue Sep 28 11:53:02 2021] GET /api/virtualization/clusters/?limit=0 => generated 128 bytes in 25 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
nautobot_1       | 11:53:02.637 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/ipam/services/
nautobot_1       | [pid: 15|app: 0|req: 7/33] 172.31.0.2 () {44 vars in 734 bytes} [Tue Sep 28 11:53:02 2021] GET /api/ipam/services/?limit=0 => generated 150 bytes in 194 msecs (HTTP/1.1 500) 7 headers in 223 bytes (1 switches on core 0)
^CERROR: Aborting.
ansible stack trace
Exception in thread Thread-7:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 740, in refresh_platforms_lookup
    platforms = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "generator raised StopIteration", "exception": "RuntimeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 747, in refresh_sites_lookup
    sites = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "get() returned more than one ContentType -- it returned more than 20!", "exception": "MultipleObjectsReturned", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-3:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 779, in refresh_tenants_lookup
    tenants = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "generator raised StopIteration", "exception": "RuntimeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-4:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 784, in refresh_racks_lookup
    racks = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "'>' not supported between instances of 'UUID' and 'int'", "exception": "TypeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-6:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 820, in refresh_device_roles_lookup
    device_roles = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "generator raised StopIteration", "exception": "RuntimeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-8:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 827, in refresh_device_types_lookup
    device_types = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "'>' not supported between instances of 'UUID' and 'int'", "exception": "TypeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-9:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 834, in refresh_manufacturers_lookup
    manufacturers = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "generator raised StopIteration", "exception": "RuntimeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-11:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 908, in refresh_interfaces
    device_interfaces = self.get_resource_list(url_device_interfaces)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "'>' not supported between instances of 'UUID' and 'int'", "exception": "TypeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-10:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
   self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 841, in refresh_clusters_lookup
    clusters = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "generator raised StopIteration", "exception": "RuntimeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}
Exception in thread Thread-12:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, 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 "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1078, in wrapper
    raise e
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 865, in refresh_services
    services = self.get_resource_list(url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: {"error": "'>' not supported between instances of 'UUID' and 'int'", "exception": "TypeError", "nautobot_version": "1.1.3", "python_version": "3.9.7"}


^C [ERROR]: User interrupted execution


Exception in thread Thread-5:
Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 287, in _fetch_information
    response = open_url(
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1393, in open_url
    return Request().open(method, url, data=data, headers=headers, use_proxy=use_proxy,
  File "/home/user/venv-ansible-2.10/lib/python3/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/opt/python/3/lib/python3/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/opt/python/3/lib/python3/urllib/request.py", line 640, in http_response
    response = self.parent.error(
  File "/opt/python/3/lib/python3/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 502, in _call_chain
    result = func(*args)
  File "/opt/python/3/lib/python3/urllib/request.py", line 649, in http_error_default
    raise HTTPError(req.full_url, code, msg, hdrs, fp)
urllib.error.HTTPError: HTTP Error 502: Bad Gateway

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1073, in wrapper
    lookup()
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 804, in refresh_rack_groups_lookup
    rack_groups = self.get_resource_list(api_url=url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 342, in get_resource_list
    api_output = self._fetch_information(api_url)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 310, in _fetch_information
    raise AnsibleError(to_native(e.fp.read()))
ansible.errors.AnsibleError: Bad Gateway

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/python/3/lib/python3/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/opt/python/3/lib/python3/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/ansible-nautobot/collections.galaxy/ansible_collections/networktocode/nautobot/plugins/inventory/inventory.py", line 1077, in wrapper
    thread_exceptions.append(e)
AttributeError: 'NoneType' object has no attribute 'append'

Some errors extract:

  • get() returned more than one ContentType -- it returned more than 20!
  • generator raised StopIteration
  • '>' not supported between instances of 'UUID' and 'int'

Setting NAUTOBOT_UWSGI_PROCESSES to 1 seems to mitigate the issue, but makes Nautobot incredibly slow, with some requests (like /api/dcim/interfaces/?limit=0, even with NAUTOBOT_MAX_PAGE_SIZE: "5000" instead of 50000) falling in timeout (which if using Traefik as reverse-proxy, can make it return 404 momentarily due to the healthcheck https://github.com/nautobot/nautobot/blob/v1.1.3/docker/Dockerfile#L20 failing and Traefik removing the destination).

I haven't tried to play with NAUTOBOT_CACHEOPS_ENABLED this time, it was commented in all tests.

@u1735067
Copy link
Contributor Author

u1735067 commented Sep 28, 2021

Not sure this is relevant, but: psycopg/psycopg2#840 (comment)

@u1735067
Copy link
Contributor Author

Another workaround: NAUTOBOT_DB_TIMEOUT: 0

@u1735067
Copy link
Contributor Author

And possibly related: #127, found from https://github.com/nautobot/nautobot/blob/v1.1.3/nautobot/docs/installation/services.md#ssl-error by searching CONN_MAX_AGE in this project.

@glennmatthews glennmatthews added the type: bug Something isn't working as expected label Oct 1, 2021
@u1735067
Copy link
Contributor Author

u1735067 commented Apr 1, 2022

@jathanism In #127 (comment), you mentioned that disabling SSL was a solution, I remembered reading at https://www.psycopg.org/docs/install.html#psycopg-vs-psycopg-binary that the source distribution should be used in production, otherwise some issues related to SSL may appear under concurrency -> have you tried to reproduce the issue by using psycopg instead of psycopg-binary?

After understanding the issue in #1515, I was interested to look at this again, but from my testing however, neither using psycopg nor setting DATABASES['default']['OPTIONS'] = {"sslmode": "disable"} worked.

I wanted to try the uswsgidecorators.postfork decorator (do you still have your test?), but at first I had some trouble making it work (ImportError of uwsgi) because the startup is unusual (at least to me). I think I finally was able to understand the startup process:

# nautobot-server
nautobot.core.cli.main()
# https://github.com/nautobot/nautobot/blob/v1.2.10/nautobot/core/cli.py
nautobot.core.runner.run_app()
# https://github.com/nautobot/nautobot/blob/v1.2.10/nautobot/core/runner/runner.py
django.core.management.execute_from_command_line()
# https://github.com/django/django/blob/stable/3.1.x/django/core/management/__init__.py
django_webserver.management.commands.pyuwsgi.Command.run_from_argv()  # (from django_webserver.base_command.WebserverCommand)
# https://github.com/lincolnloop/django-webserver/blob/v1.2.0/django_webserver/management/commands/pyuwsgi.py
if WEBSERVER_WARMUP is True:  # by default -> the WSGI_APPLICATION is called before uwsgi is loaded here
  django.core.servers.basehttp.get_internal_wsgi_application()
django_webserver.management.commands.pyuwsgi.Command.prep_server_args()
django_webserver.management.commands.pyuwsgi.Command.start_server()
# https://github.com/lincolnloop/django-webserver/blob/v1.2.0/django_webserver/base_command.py
pyuwsgi.run()
# -> Will try to run WSGI_APPLICATION (= nautobot.core.wsgi:application)
# Now we have the uwsgi module loaded
# https://github.com/nautobot/nautobot/blob/v1.2.10/nautobot/core/wsgi.py
nautobot.setup()
django.core.wsgi.get_wsgi_application
django.setup(set_prefix=False)
# https://github.com/django/django/blob/stable/3.1.x/django/core/wsgi.py
django.core.handlers.wsgi.WSGIHandler()
# https://github.com/django/django/blob/stable/3.1.x/django/core/handlers/wsgi.py
# Now uwsgi loaded the application, it'll create threads

https://code.djangoproject.com/ticket/20562#comment:12 (found via https://stackoverflow.com/questions/8242837/django-multiprocessing-and-database-connections) seems to talk about this startup process (forking from management command)?

Before understanding this, I tried to hack around nautobot/core/management/commands/start.py:

from django_webserver.management.commands.pyuwsgi import Command as uWSGICommand

"""
try:
  import uwsgidecorators
  @uwsgidecorators.postfork
  def fix_uwsgi():
      import logging
      logging.getLogger("nautobot").warning('>>>>>>>>>>> close')
      import django.db
      django.db.connections.close_all()
except ImportError:
  pass
"""

class Command(uWSGICommand):
    help = "Start Nautobot uWSGI server."

    def run_from_argv(self, argv):
      import logging
      logging.getLogger("nautobot").warning('>>>>>>>>>>> close')
      import django.db
      django.db.connections.close_all()
      super().run_from_argv(argv)

This seems to works, but it's not the best place to put this. After understanding the startup process, I tried the following solutions (separately), all of them seems to work too:

  • nautobot/core/wsgi.py:
[...]

# Use try/except because we might not be running uWSGI.
# Like `django_webserver.base_command.WebserverCommand`, when
# `settings.WEBSERVER_WARMUP` is not set to `False`, will first call 
# `get_internal_wsgi_application` which does not have `uwsgi` module loaded
# already -> you must set `settings.WEBSERVER_WARMUP` to `False` for this
# code to be loaded
try:
    import uwsgidecorators

    @uwsgidecorators.postfork
    def fix_uwsgi():
        import uwsgi, logging
        logging.getLogger("nautobot").info(f'Closing existing DB and cache connections on worker {uwsgi.worker_id()} after uWSGI forked ...')
        import django.db, django.core.cache
        django.db.connections.close_all()
        django.core.cache.close_caches()

except ImportError:
    pass

application = [...]

This should be the "correct" way to do it? But closing must be done on each fork, also settings.WEBSERVER_WARMUP must be set to False, otherwise when this module is loaded the first time by django_webserver, uwsgi is not present and the code is ignored.

  • nautobot/core/management/commands/start.py:
from django_webserver.management.commands.pyuwsgi import Command as uWSGICommand

class Command(uWSGICommand):
    help = "Start Nautobot uWSGI server."

    def start_server(self, *argv):
        import logging
        logging.getLogger("nautobot").info('Closing existing DB and cache connections before uWSGI forks ...')
        import django.db, django.core.cache
        django.db.connections.close_all()
        django.core.cache.close_caches()
        super().start_server(*argv)

This seems to be working from my tests, this doesn't require to disable WEBSERVER_WARMUP, but this is happening early, some setup() occur later in nautobot.core.wsgi (could this be unsignificant?).

  • nautobot/core/wsgi.py:
[...]

# Use try/except because we might not be running uWSGI.
# Like `django_webserver.base_command.WebserverCommand`, when
# `settings.WEBSERVER_WARMUP` is not set to `False`, will first call 
# `get_internal_wsgi_application` which does not have `uwsgi` module loaded
# already -> you must set `settings.WEBSERVER_WARMUP` to `False` for this
# code to be loaded
try:
    import uwsgi   
except ImportError:
    pass
else:
    # uwsgi is initialized and will fork when it gets `application`
    import logging
    logging.getLogger("nautobot").info('Closing existing DB and cache connections before uWSGI forks ...')
    import django.db, django.core.cache
    django.db.connections.close_all()
    django.core.cache.close_caches()


application = [...]

This should allow to remove exiting connections just before the fork, but it requires to disable WEBSERVER_WARMUP (same reason) and might not handle all uwsgi configurations.

And for the record, this is NOT working (calling pyuwsgi.setup() before pyuwsgi.run() to try to have uwsgi module available):

def start_server(self, *args):
  import pyuwsgi, uwsgidecorators
  # Setup uWSGI to load the uwsgi module (required by uwsgidecorators)
  pyuwsgi.setup(args)

  import uwsgidecorators
  @uwsgidecorators.postfork
  def fix_uwsgi():
      import logging
      logging.getLogger("nautobot").warning('>>>>>>>>>>> close')
      import django.db
      django.db.connections.close_all()

  # Run the loop
  super().start_server(args)

To test, I used NAUTOBOT_UWSGI_PROCESSES: 10 and stopped the redis process (as caching seems to help hiding those errors).

To get a shell with uwsgi available:

docker-compose run --rm --entrypoint nautobot-server nautobot start --ini uwsgi.ini --pyshell

(and I have about 50 links of source code that where useful to trace the startup process, but I won't spam here :) )

@u1735067
Copy link
Contributor Author

Hi,

were you able to look into this? Maybe there's a refactoring/change to come and make this obsolete (like remove uWSGI)? Or would you accept a PR for any of those solutions (maybe solution n°2, nautobot/core/management/commands/start.py + set settings.WEBSERVER_WARMUP=False + warn if not False, since this file is uWSGI specific?) ?

Best,

@u1735067
Copy link
Contributor Author

Able to reproduce in 1.4.1 (and to fix using at least the last solution, closing connections just before handing over application to uwsgi):

$ ansible-inventory --list -i my_inventory.yml -vv | grep -v ansible_password > inv.json
ansible.errors.AnsibleError: {"error": "lost synchronization with server: got message type \"6\", length 825713971\n", "exception": "OperationalError", "nautobot_version": "1.4.1", "python_version": "3.10.6"}
ansible.errors.AnsibleError: {"error": "list index out of range", "exception": "IndexError", "nautobot_version": "1.4.1", "python_version": "3.10.6"}
nautobot_1       | 18:04:44.438 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/tenancy/tenants/
nautobot_1       | [pid: 19|app: 0|req: 6/29] 172.28.0.2 () {44 vars in 738 bytes} [Tue Aug 30 18:04:44 2022] GET /api/tenancy/tenants/?limit=0 => generated 120 bytes in 57 msecs (HTTP/1.1 500) 6 headers in 199 bytes (1 switches on core 0)
nautobot_1       | 18:04:44.487 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/device-roles/
nautobot_1       | [pid: 17|app: 0|req: 3/31] 172.28.0.2 () {44 vars in 742 bytes} [Tue Aug 30 18:04:44 2022] GET /api/dcim/device-roles/?limit=0 => generated 120 bytes in 32 msecs (HTTP/1.1 500) 6 headers in 199 bytes (1 switches on core 0)
nautobot_1       | 18:04:44.706 ERROR   django.request :
nautobot_1       |   Internal Server Error: /api/dcim/device-types/
nautobot_1       | [pid: 19|app: 0|req: 9/35] 172.28.0.2 () {44 vars in 742 bytes} [Tue Aug 30 18:04:44 2022] GET /api/dcim/device-types/?limit=0 => generated 179 bytes in 28 msecs (HTTP/1.1 500) 6 headers in 199 bytes (1 switches on core 0)

@jathanism
Copy link
Contributor

@u1735067 This issue got lost in the shuffle due to it already being groomed. I'm taking a look at this and try to wrap my head around your experience. Thanks for your patience for submitting your detailed analysis as you're known to do!

@jathanism
Copy link
Contributor

jathanism commented Sep 14, 2022

After testing the fix with the following:

  • settings.DATABASES["default"]["OPTIONS"]["CONN_MAX_AGE"] = 300 (the default value)
  • settings.WEBSERVER_WARMUP = False set
  • SSL database connections (Postgres)
  • The @uwsgidecorators.postfork callback defined inside of nautobot.core.wsgi
  • Running uWSGI with 5 worker processes
  • Manually running a ton of synthetic requests to the Nautobot server

I have confirmed that this absolutely fixes this problem and will allow Nautobot to support SSL database connections WITH persistent connections.

Thank you @u1735067 for your patience and for your time in debugging and getting to the bottom of this!

I'll provide a patch soon and make sure you get the credit. For reference, it's this:

nautobot/core/wsgi.py

import logging

from django.core import cache
from django.core.wsgi import get_wsgi_application
from django.db import connections

import nautobot

# This is the Django default left here for visibility on how the Nautobot pattern
# differs.
# os.environ.setdefault("DJANGO_SETTINGS_MODULE", "nautobot.core.settings")

# Instead of importing `DJANGO_SETTINGS_MODULE` we're using the custom loader
# pattern from `nautobot.core.runner` to read environment or config path for us.
nautobot.setup()

# Use try/except because we might not be running uWSGI.
# Like `django_webserver.base_command.WebserverCommand`, when
# `settings.WEBSERVER_WARMUP` is not set to `False`, will first call
# `get_internal_wsgi_application` which does not have `uwsgi` module loaded
# already -> you must set `settings.WEBSERVER_WARMUP` to `False` for this
# code to be loaded
try:
    import uwsgidecorators

    @uwsgidecorators.postfork
    def fix_uwsgi():
        import uwsgi
        logging.getLogger("nautobot").info(f'Closing existing DB and cache connections on worker {uwsgi.worker_id()} after uWSGI forked ...')
        connections.close_all()
        cache.close_caches()

except ImportError:
    pass

application = get_wsgi_application()

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Dec 15, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
type: bug Something isn't working as expected
Projects
No open projects
Archived in project
Development

Successfully merging a pull request may close this issue.

4 participants