pynautobot reqeust error

[nanisyako]

Environment

• Python version: 3.6.8
• Nautobot version: 1.0.3

Steps to Reproduce

When I am trying to match a tag when running a nornir script

nb_url= 'https://test-nautobot.lab.com'
    nb_token= "hiddenhidden"
    """Nornir testing."""
    nr = InitNornir(
        inventory={
            "plugin": "NautobotInventory",
            "options": {
                "nautobot_url": nb_url,
                "nautobot_token": nb_token,
                "ssl_verify": False,
            },
            "transform_function": "populate_creds",
        },
    )

Expected Behavior

to match the filtered tag

Observed Behavior

File "/home/test/pynet_nautobot/lib64/python3.6/site-packages/pynautobot/core/query.py", line 226, in _make_call
    raise RequestError(req)
pynautobot.core.query.RequestError: The request failed with code 504 Gateway Time-out but more specific details were not returned in json. Check the Nautobot Logs or investigate this exception's error attribute.

[glennmatthews]

I believe the original report was at nautobot/pynautobot#23, and includes some additional details not presented here.

[glennmatthews]

Thanks for the report. Can you provide more details as to where exactly the error is being seen? Is it coming from your InitNornir call itself, or from subsequently when you're using the returned object to run a specific query? Is Nornir actually a factor at all or is the error coming from a direct call to pynautobot?

[nanisyako]

thanks for looking into it. Yes it is generated from the init call itself

python PynetBoxCallableBackup.py  -f tag:test_api
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(13)CallableFilterPynautobot()
     12 
---> 13     nb_url= 'https://nautobot.lab.com'
     14     nb_token= "hidden"

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(14)CallableFilterPynautobot()
     13     nb_url= 'https://nautobot.lab.com'
---> 14     nb_token= "hidden"
     15     """Nornir testing."""

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(16)CallableFilterPynautobot()
     15     """Nornir testing."""
---> 16     nr = InitNornir(
     17         inventory={

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(18)CallableFilterPynautobot()
     17         inventory={
---> 18             "plugin": "NautobotInventory",
     19             "options": {

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(20)CallableFilterPynautobot()
     19             "options": {
---> 20                 "nautobot_url": nb_url,
     21                 "nautobot_token": nb_token,

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(21)CallableFilterPynautobot()
     20                 "nautobot_url": nb_url,
---> 21                 "nautobot_token": nb_token,
     22                 "ssl_verify": False,

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(22)CallableFilterPynautobot()
     21                 "nautobot_token": nb_token,
---> 22                 "ssl_verify": False,
     23             },

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(26)CallableFilterPynautobot()
     25         },
---> 26         runner={"plugin": "threaded", "options": {"num_workers": 20}},
     27         logging = {"enabled" : False}

ipdb> n
> /home/test/pynet_nautobot/nornir_scripts/PynautobotCallableFilter.py(27)CallableFilterPynautobot()
     26         runner={"plugin": "threaded", "options": {"num_workers": 20}},
---> 27         logging = {"enabled" : False}
     28     )

ipdb> n
/home/test/pynet_nautobot/lib64/python3.6/site-packages/urllib3/connectionpool.py:1020: InsecureRequestWarning: Unverified HTTPS request is being made to host '-nautobot.lab.com'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  InsecureRequestWarning,
/home/test/pynet_nautobot/lib64/python3.6/site-packages/urllib3/connectionpool.py:1020: InsecureRequestWarning: Unverified HTTPS request is being made to host '-nautobot.lab.com'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings
  InsecureRequestWarning,
pynautobot.core.query.RequestError: The request failed with code 504 Gateway Time-out but more specific details were not returned in json. Check the Nautobot Logs or investigate this exception's error attribute.

[jvanderaa]

So during the init call for this it is using the REST API through pynautobot to gather device information. The specific all is a pynautobot get all devices - https://github.com/nautobot/nornir-nautobot/blob/develop/nornir_nautobot/plugins/inventory/nautobot.py#L111-L125

It is likely having a timeout within there from the gateway of gathering the devices.

How many devices are within Nautobot at this point in time?

[nanisyako]

it is working intermittently. We have around 2300 devices and 2000 cables

[itdependsnetworks]

Can you confirm the resource utilization of the server when this happens?

[nanisyako]

I checked both CPU and Memory. All looks good for the last two weeks. Even in this condition, I am having the same problem.

Tasks: 188 total, 1 running, 187 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.0 us, 2.7 sy, 0.0 ni, 96.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 16247540 total, 951580 free, 2618128 used, 12677832 buff/cache
KiB Swap: 4190204 total, 4184060 free, 6144 used. 12696888 avail Mem

[nanisyako]

btw, we have similar set up for both dev and prod, and I am having the same issue on both

[itdependsnetworks]

• A two week view will not be very helpful, only the few seconds while there is an issue
• Can you obtain the logs from the server while there is an issue? (You have shown the script side pdb trace, but not the server side) This is indicated here Check the Nautobot Logs or investigate this exception's error attribute.

[nanisyako]

based on the nautobot_config.py, where I should look for nautobot logs?

LOG_LEVEL = "DEBUG" if DEBUG else "INFO"
LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "normal": {
            "format": "%(asctime)s.%(msecs)03d %(levelname)-7s %(name)s:  %(message)s",
            "datefmt": "%H:%M:%S",
        },
    },
    "handlers": {
        "normal_console": {
            "level": "DEBUG",
            "class": "logging.StreamHandler",
            "formatter": "normal",
        },
    },
    "loggers": {
        "django": {
            "handlers": ["normal_console"],
            "level": "INFO"
        },
        "nautobot": {
            "handlers": ["normal_console"],
            "level": LOG_LEVEL,
        },
    },
    "root": {
        "handlers": ["normal_console"],
        "level": LOG_LEVEL,
    },

I checked nginx and I getting:

2021/10/06 15:52:09 [error] 46732#46732: *71274 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 1.1.1.1, server: localhost.tests-nautobot.lab.com/, request: "GET /api/dcim/devices/?limit=2072&offset=50 HTTP/1.1", upstream: "uwsgi://127.0.0.1:8001", host: "tests-nautobot.lab.com"
2021/10/06 15:53:35 [error] 46732#46732: *71277 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 1.1.1.1, server: localhost.tests-nautobot.lab.com/, request: "GET /api/dcim/devices/?limit=1000&offset=1050 HTTP/1.1", upstream: "uwsgi://127.0.0.1:8001", host: "tests-nautobot.lab.com"
2021/10/06 20:13:01 [error] 46732#46732: *71408 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 1.1.1.1, server: localhost.tests-nautobot.lab.com/, request: "GET /api/dcim/devices/?limit=2072&offset=50 HTTP/1.1", upstream: "uwsgi://127.0.0.1:8001", host: "tests-nautobot.lab.com"
2021/10/06 20:16:03 [error] 46732#46732: *71411 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 1.1.1.1, server: localhost.tests-nautobot.lab.com/, request: "GET /api/dcim/devices/?limit=1000&offset=1050 HTTP/1.1", upstream: "uwsgi://127.0.0.1:8001", host: "tests-nautobot.lab.com"

[nanisyako]

could it be pagination problem? how I can change the pagination from 1000 to more ?

[glennmatthews]

Pynautobot should handle pagination for you; if anything, decreasing the MAX_PAGE_SIZE on your Nautobot instance might be a resolution to this. Some directions to investigate:

• Decrease MAX_PAGE_SIZE in Nautobot
• Increase request timeout in your nginx configs (I think that'd be uwsgi_read_timeout?)
• nornir-nautobot should probably enable multithreaded requests in pynautobot (https://github.com/nautobot/nornir-nautobot/blob/develop/nornir_nautobot/plugins/inventory/nautobot.py#L106, https://github.com/nautobot/pynautobot/blob/e362b94e033562fcb06bce913631ea8e4c140685/README.md#threading)
• It doesn't look like pynautobot supports using exclude=config_context(https://nautobot.readthedocs.io/en/stable/rest-api/overview/#excluding-config-contexts) when making a filter() call, but I think this would be a desirable enhancement to that library. Once that's added, the nornir-nautobot inventory should probably be updated to make use of it. (Edit: looks like Support add_params in EndPoint pynautobot#24)

[jvanderaa]

@nanisyako you can also add exclude to the "options" section of the inventory. This will get rid of the config context data.

    my_nornir = InitNornir(
        inventory={
            "plugin": "NautobotInventory",
            "options": {
                "nautobot_url": os.getenv("NAUTOBOT_URL"),
                "nautobot_token": os.getenv("NAUTBOT_TOKEN"),
                "filter_parameters": {"site": site, "exclude": "config_context"},
                "ssl_verify": False,
            },
        },
    )

[nanisyako]

Actually, I don't want to filter on site since I am calling the filter from the cli and I am using tags.

python PynautoBotCallableBackup.py  -f tag:test_api

If I hardcoded the site it is throwing an error:

Error in the query filters. Please verify the parameters.

[jvanderaa]

Sorry about including the site, that was from the examples. Take the site off, really it is this then:

    my_nornir = InitNornir(
        inventory={
            "plugin": "NautobotInventory",
            "options": {
                "nautobot_url": os.getenv("NAUTOBOT_URL"),
                "nautobot_token": os.getenv("NAUTBOT_TOKEN"),
                "filter_parameters": {"exclude": "config_context"},
                "ssl_verify": False,
            },
        },
    )

The one with the site works if there was one, tested against demo.nautobot.com.

[nanisyako]

awesommeeee it looks promising, I will testing it for couple of hours since it was timing out after couple of idle hours then we can close the issue

[nanisyako]

After excludinf the config context, no more timeouts