Relationship filter broken with too many items in filter

[jakubkrysl]

Environment

• Python version: 3.6.15
• Nautobot version: v1.2.10

We are using relationships to model hypervizors (One-to-Many Device to VMs). To avoid performance impact of 96 relationships (see issue #1593 ), we tried having single association with all the cluster_ids in single filter. The filter is the same on both sides, looks like this:

{
    "cluster_id": [
        "09c340b3-42b9-4799-b19b-9db45abd11d3",
        "0bd6582c-4ede-478c-a61c-691e044c674f",
        .... 94 more UUIDs here ....
    ]
}

But now it is not possible to set this relationship association in UI. It works via API, but UI always shows The results could not be loaded. from VM and Device alike. If I remove the filter, I am able to list all VMs and Devices respectively. But since I don't want this Relationship to show for all Devices, I need to have some sort of filter in place to tell Nautobot the Device is in Cluster.

Steps to Reproduce

1. create many clusters (we hit it with 96, but the critical number is 28 clusters - works with 27, does not with 28)
2. create relationship between Device and VM, filter for cluster_id with list of all 28 clusters on source and destination
3. try to add the relationship association from UI

Expected Behavior

all devices/VMs in those clusters listed

Observed Behavior

following message on both sides, which means inability to fill this field

Note: It works if I remove the filter

[glennmatthews]

I can't reproduce this so far (though in my case I'm using a Device-to-Circuit relationship filtered on site_id rather than a Device-to-VirtualMachine relationship filtered on cluster_id). I've gone up to 75 sites in each filter and it still works.

I have two theories at the moment:

1. the AJAX query to populate the menu might be timing out in the browser (perhaps you can check this with browser web developer tools?)
2. the query string might be exceeding some length limit enforced somewhere in your deployment chain (in my testing in a dev environment it works even when the query is something like /api/dcim/devices/?q=&limit=50&brief=true&site_id=d25b6c47-2eb1-570e-aee0-8de6b100273d&site_id=94f0e341-a729-58e4-ad02-efabeb302b15&site_id=899571ad-7c3e-5094-9681-b0564e3709a2&site_id=97e88dbc-9879-5c32-8b6a-808f4c65114c&site_id=abd88731-a1ab-5fdb-8cc2-7eb3ae8588c9&site_id=aa76a8bf-8b7a-5972-b40d-bc76fed4313b&site_id=a3ad556e-643c-485a-891a-b2b728a85f91&site_id=aa7b29b8-fd65-41c3-80dd-9fd770b4b978&site_id=378c6c54-0a24-5ee9-858e-9873c824ebb8&site_id=7ed8a1ca-1713-4067-a98c-cb83860b38ff&site_id=355ddca8-bc15-5a8f-ac5e-c6796b661914&site_id=593780c0-7a71-4458-b070-3773e2f47288&site_id=4596c36d-06ac-5bce-a059-c858206fda98&site_id=5b636b58-4660-5f31-ab33-2af1c103c498&site_id=ec4698bf-7b3c-5ffe-a9f0-9e09ec424e3b&site_id=0340571b-e0de-53e2-b2e0-a896b4dbf81c&site_id=9ec81af7-e1d8-500d-b89d-8f1ecc2ec0ab&site_id=8c7b8677-23d7-50ec-90d8-f51681f22d81&site_id=d45d6bfd-f397-5765-b627-222e50e7edb5&site_id=30bbfe50-95ef-5235-8211-7dce8a753b76&site_id=5f74a7f0-4940-5aaf-81b0-f5d90d12c6ee&site_id=07e44cd7-bc94-5663-b1e1-a195f0684026&site_id=2a9f7691-ac19-54f1-a78d-d0330b3c04d1&site_id=049fb08a-7787-5ce7-ab62-c61f9a44bd54&site_id=4d85d01c-a9a1-537c-aab4-012395cc290f&site_id=3def6c90-ef0a-555d-bc91-a999ee0c30e9&site_id=d9fef5d5-42e8-5419-9380-0f6b5deb61f0&site_id=89bbd4d6-e502-5a06-8422-e501c5168119&site_id=e78cbebb-e5bf-573a-9f50-f7f9476c7c63&site_id=37dfa6cf-41e6-5b20-bfd2-645bb931b8f5&site_id=9a67de33-79ec-5d3b-9e94-f366b2d8828d&site_id=a14de5a7-4553-48bf-84e7-381c4682b743&site_id=75434d05-7c79-52c8-96ab-accf180edcfc&site_id=c7d805f3-9383-574a-a3ce-b3d99bdfdc2e&site_id=98cdf810-aa4e-592b-be2f-f8a4a70e1004&site_id=c3e12c07-a64e-5778-a64f-e00023517a18&site_id=1620e3e7-2feb-5a3e-8959-6508ac32568e&site_id=e79eed99-4d11-5064-8905-24de1d986ccb&site_id=388973a3-9d27-5e0b-af0b-46d9b76e3576&site_id=67679d79-f13b-56ae-9125-c208975bc2ae&site_id=0bdd6f21-33e5-456f-b060-188bfbadc30e&site_id=3c1ce61a-e1de-5355-a556-907f2f3a22a1&site_id=b123ff36-1f75-5138-8322-63a54380a002&site_id=2322b457-e9b7-5ba7-b41e-9de9b2bb4b5e&site_id=cce4b8b6-7b2a-5a69-bd7a-c3cc44cc0bac&site_id=8cdbf574-f5c2-5b11-846e-677cbc0e2df1&site_id=17dbfe10-341c-5560-8abd-1b19a103523e&site_id=21bb2705-b56a-5e84-b126-039e3e45a61a&site_id=da4d37e6-8149-5bba-98fc-644ffd2c5b1b&site_id=b799cbe6-f5af-5eff-9d23-c5db92e17f2e&site_id=67524000-3548-565b-93e9-8a70147fab3a&site_id=5ed9dedd-faf2-5783-9214-c98b50f332c4&site_id=5f8bb057-e807-5723-a966-3c21aa11a5fe&site_id=0ea2db6d-d145-51c8-8ab1-8152935722e7&site_id=e255bca2-a1ea-5823-bffe-75979e6b9b98&site_id=b3970fb0-b430-57c9-8279-d53a3d24b995&site_id=d2f6bbeb-00cb-57f5-bb18-c36408a11487&site_id=5c215784-e0d4-5b17-b8e1-8dedc423e8dc&site_id=48a97306-04bc-53eb-a4ee-1a116c6ffc12&site_id=53318e19-8ee8-58a0-ac8a-9098e10bf265&site_id=fceb99a8-9cf0-58a7-a8cb-0365eb4f7221&site_id=0c14bd7c-cb35-5190-abf6-677aa07fb1d7&site_id=6e638098-267a-5c5e-991c-53cfd1e32f79&site_id=4cfd2868-5ff6-56e3-911d-0689228e2881&site_id=9cdda884-70f8-5a3e-89f8-18cba81a1e4b&site_id=b62395db-ed78-54bf-9783-a5aa76270096&site_id=9e6affb7-2751-5622-b8cf-dd2004349919&site_id=4bf75694-7c21-546d-a37a-70234848b986&site_id=d9d2ea07-6e36-53c1-b4ee-824dd0d96667&site_id=8653d41f-9bc7-5ae9-8e47-71fd48d84fe6&site_id=b39579cd-985e-5bd4-bc18-0154fe69fad4&site_id=17525393-6a7c-5ce0-a1f7-650db68af587&site_id=bfc7c673-3cb6-5f98-9b2e-d8861cfc895a&site_id=993f5d6f-fc75-5ec1-a2b5-983763d9bc4a&site_id=0d1765b2-fe2c-5653-81ca-8c9d5f571c52)

Can you enable django.server logging at level INFO as a way of profiling the inbound requests and their responses, and see what gets logged in the succeeding and failing cases in your environment?

[jakubkrysl]

I did some further testing to try to narrow it a bit. I could not get any logs at all, even at DEBUG. We already are logging everything from django, so I added extra django.server logger at DEBUG level. Nothing appeared there when I refreshed the edit page and tried to list the options.
I found out few things:

1. It only happens on the side with filter, other side with no filter shows everything correctly (so if there is filter on source, destination works without issues)
2. It is not timeout, the message The results could not be loaded shows right away
3. It only happens on our test/production deployment (they are mostly identical), I could not reproduce it locally with different docker-compose setup. On localhost I run with http directly via the uwsgi, in production we have nginx in front.
4. On localhost it just shows Searching... and probably will show the results in future. I left it 10 minutes without change though, so cannot verify this guess.

It seems it is able to figure out the request will take way too long and just fails it right away...

Is there anything else you want me to try?

[bryanculver]

Potentially could be solved by #1883

[bryanculver]

Worked with @Thetacz to reproduce this issue. We confirmed that it's a result of a very low default limit on the uWSGI buffer size:

By default uWSGI allocates a very small buffer (4096 bytes) for the headers of each request. If you start receiving “invalid request block size” in your logs, it could mean you need a bigger buffer. Increase it (up to 65535) with the buffer-size option.

Source: https://uwsgi-docs.readthedocs.io/en/latest/ThingsToKnow.html

We manually bumped the buffer size as an addition command-line arg to the container and it resolved the issue.

Evaluating if we should increase the default directly in: https://github.com/nautobot/nautobot/blob/develop/docker/uwsgi.ini or should this be configurable as an environment variable.

In the meantime, anyone running into this (or similar) issues can at minimum update their runtime command for the Nautobot container to be "nautobot-server start --ini /opt/nautobot/uwsgi.ini -b 65000"

[jathanism]

Let's get this into our troubleshooting docs in server install section.