Improve performance of custom field models and serializers #4998

roganartu · 2020-08-13T18:42:22Z

Environment

Python version: 3.6.5
NetBox version: 2.8.8

Proposed Functionality

Improve the performance of custom field models and serializers by reducing the number of SQL queries issued per request. GET /api/dcim/devices?limit=1000 takes ~20-30s on our best bare metal hardware (~10-15s with exclude=config_context), and results in thousands of duplicate SQL queries relating to custom fields.

The profiling I did seems to suggest some of this performance may be improved by #4878 too, though this issue seemed distinct enough to warrant a separate ticket. If you disagree, please feel free to close this.

Profiling

I did some Python profiling and Postgres query logging and found that the majority of queries come from a small number of sources. I will try to document the process I used thoroughly to make reproducing this easier.

I used the following command to generate the request each time:

$ time curl -k -L -s "http://localhost/api/dcim/devices/?limit=1000&exclude=config_context" | jq -r '.results[] | .name' | sort | uniq | wc -l

With the following postgres query logging config:

# Log queries temporarily
log_statement = 'all'
log_duration = on
log_filename = 'postgresql-%Y-%m-%d_%H%M%S'
log_destination = 'csvlog'
logging_collector = on
log_min_error_statement = error

Each query then created two lines in the query log like this:

2020-08-11 15:07:00.035 EDT,"netbox","netbox",7756,"127.0.0.1:57040",5f32ec50.1e4c,109,"idle",2020-08-11 15:06:56 EDT,6/68,0,LOG,00000,"statement: SELECT ""dcim_device"".""id"", ""dcim_device"".""local_context_data"", ""dcim_device"".""created"", ""dcim_device"".""last_updated"", ""dcim_device"".""device_type_id"", ""dcim_device"".""device_role_id"", ""dcim_device"".""tenant_id"", ""dcim_device"".""platform_id"", ""dcim_device"".""name"", ""dcim_device"".""_name"", ""dcim_device"".""serial"", ""dcim_device"".""asset_tag"", ""dcim_device"".""site_id"", ""dcim_device"".""rack_id"", ""dcim_device"".""position"", ""dcim_device"".""face"", ""dcim_device"".""status"", ""dcim_device"".""primary_ip4_id"", ""dcim_device"".""primary_ip6_id"", ""dcim_device"".""cluster_id"", ""dcim_device"".""virtual_chassis_id"", ""dcim_device"".""vc_position"", ""dcim_device"".""vc_priority"", ""dcim_device"".""comments"" FROM ""dcim_device"" WHERE ""dcim_device"".""id"" = 594219 LIMIT 21",,,,,,,,,""
2020-08-11 15:07:00.035 EDT,"netbox","netbox",7756,"127.0.0.1:57040",5f32ec50.1e4c,110,"SELECT",2020-08-11 15:06:56 EDT,6/0,0,LOG,00000,"duration: 0.224 ms",,,,,,,,,""

I then used the following (on a freshly rotated log file for each request) to aggregate query counts:

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" <path_to_log_file> | sort | uniq -c | sort -nr
      4 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584989 LIMIT 21
    ...

I also wrote an adhoc middleware plugin that let me pass enable_profiler=1 to get a cProfile.Profile() of the request dumped to /tmp that I then extracted the call graph from using gprof2dot and visualised using xdot. This allowed me to narrow down some of the sources of the SQL a little easier, since I'm not very familiar with Django.

The test database I did this profiling on contains:

~15k devices
24 custom fields
13 custom field choices across two custom fields
~200k custom field values for the dcim_device obj_type_id

Vanilla v2.8.8

The request typically takes ~10-15s depending on server load and executes ~3k SQL queries. This example is relatively fast because it was run with a local test DB that was idle:

$ time curl -k -L -s "http://localhost/api/dcim/devices/?limit=1000&exclude=config_context" | jq -r '.results[] | .name' | sort | uniq | wc -l
1000
curl -k -L -s   0.02s user 0.01s system 0% cpu 9.100 total
jq -r '.results[] | .name'  0.11s user 0.02s system 1% cpu 9.127 total
sort  0.00s user 0.00s system 0% cpu 9.113 total
uniq  0.00s user 0.00s system 0% cpu 9.111 total
wc -l  0.00s user 0.00s system 0% cpu 9.109 total

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" vanilla.csv | wc -l
3049

Almost all of these are identical, repeatedly fetching custom field names and choices:

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" vanilla.csv | sort | uniq -c | sort -nr | head
   1003 statement: SELECT "extras_customfield"."id", "extras_customfield"."type", "extras_customfield"."name", "extras_customfield"."label", "extras_customfield"."description", "extras_customfield"."required", "extras_customfield"."filter_logic", "extras_customfield"."default", "extras_customfield"."weight" FROM "extras_customfield" INNER JOIN "extras_customfield_obj_type" ON ("extras_customfield"."id" = "extras_customfield_obj_type"."customfield_id") WHERE "extras_customfield_obj_type"."contenttype_id" = 32 ORDER BY "extras_customfield"."weight" ASC, "extras_customfield"."name" ASC
   1000 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 65 AND "extras_customfieldchoice"."id" = 23) LIMIT 21
    850 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 76 AND "extras_customfieldchoice"."id" = 26) LIMIT 21
    146 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 76 AND "extras_customfieldchoice"."id" = 28) LIMIT 21
      4 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584989 LIMIT 21
      3 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 76 AND "extras_customfieldchoice"."id" = 32) LIMIT 21
      3 statement: SELECT d.datname as "Name", pg_catalog.pg_get_userbyid(d.datdba) as "Owner", pg_catalog.pg_encoding_to_char(d.encoding) as "Encoding", d.datcollate as "Collate", d.datctype as "Ctype", pg_catalog.array_to_string(d.datacl, E'\n') AS "Access privileges" FROM pg_catalog.pg_database d ORDER BY 1;
      3 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584969 LIMIT 21
      2 statement: SELECT "ipam_ipaddress"."id", "ipam_ipaddress"."created", "ipam_ipaddress"."last_updated", "ipam_ipaddress"."address", "ipam_ipaddress"."vrf_id", "ipam_ipaddress"."tenant_id", "ipam_ipaddress"."status", "ipam_ipaddress"."role", "ipam_ipaddress"."interface_id", "ipam_ipaddress"."nat_inside_id", "ipam_ipaddress"."dns_name", "ipam_ipaddress"."description" FROM "ipam_ipaddress" WHERE "ipam_ipaddress"."id" IN (NULL) ORDER BY "ipam_ipaddress"."address" ASC, "ipam_ipaddress"."id" ASC
      2 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" INNER JOIN "extras_customfield" ON ("extras_customfieldchoice"."field_id" = "extras_customfield"."id") WHERE "extras_customfieldchoice"."field_id" IN (63, 65, 115, 67, 68, 69, 71, 74, 75, 76, 78, 79, 83) ORDER BY "extras_customfield"."weight" ASC, "extras_customfield"."name" ASC, "extras_customfieldchoice"."weight" ASC, "extras_customfieldchoice"."value" ASC

`CustomFieldModelSerializer`

Found here:

netbox/netbox/extras/api/customfields.py

Line 132 in ee51dae

class CustomFieldModelSerializer(ValidatedModelSerializer):

These two lines result in one SQL query per device object:

netbox/netbox/extras/api/customfields.py

Lines 146 to 148 in ee51dae

    
           # Retrieve the set of CustomFields which apply to this type of object 
        
           content_type = ContentType.objects.get_for_model(self.Meta.model) 
        
           fields = CustomField.objects.filter(obj_type=content_type)

The specific query this executes ~1000 times is:

SELECT "extras_customfield"."id", "extras_customfield"."type", "extras_customfield"."name", "extras_customfield"."label", "extras_customfield"."description", "extras_customfield"."required", "extras_customfield"."filter_logic", "extras_customfield"."default", "extras_customfield"."weight" FROM "extras_customfield" INNER JOIN "extras_customfield_obj_type" ON ("extras_customfield"."id" = "extras_customfield_obj_type"."customfield_id") WHERE "extras_customfield_obj_type"."contenttype_id" = 32 ORDER BY "extras_customfield"."weight" ASC, "extras_customfield"."name" ASC

However, afaict these lines can be removed and fields can be replaced with the existing self.context["custom_fields"] without any problems. It requires a minor change to how CustomFieldModel caches too since that seems to be where the DRF lazy execution actually ends up triggering the query. Someone who understands Django better should comment on the viability, but this use of self.context reduced the query count to ~2k and response time by ~17%:

$ time curl -k -L -s "http://localhost/api/dcim/devices/?limit=1000&exclude=config_context" | jq -r '.results[] | .name' | sort | uniq | wc -l
1000
curl -k -L -s   0.01s user 0.02s system 0% cpu 7.604 total
jq -r '.results[] | .name'  0.12s user 0.03s system 1% cpu 7.632 total
sort  0.00s user 0.00s system 0% cpu 7.612 total
uniq  0.00s user 0.00s system 0% cpu 7.611 total
wc -l  0.00s user 0.00s system 0% cpu 7.609 total

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldModelSerializer.csv | wc -l
2052

Here is the commit that achieved this, let me know if this makes sense and I can submit a PR: roganartu@13238ea

I did some adhoc testing of the returned objects, and the custom_fields in them appeared to be correct. I admit I do not understand how DRF serialization contexts work (further than a cursory read while doing this investigation), so if this is obviously the incorrect way to fix this I'd love to learn more.

`CustomFieldManager`

This one is basically the same as above, but the calls are generated from each instantiated model instead of each serializer. This seems to make it harder to deal with on a per-request basis, since the CustomFieldManager doesn't appear to have any kind of request context, unlike the serializer which has the per-request self.context["custom_fields"].

I don't know how to approach this correctly, but as a proof-of-concept to demonstrate this is where these queries are coming from, I made the CustomFieldManager a singleton with a per-model._meta.concrete_model lru_cache around the CustomFieldManager.get_for_model method from here:

netbox/netbox/extras/models/customfields.py

Line 61 in d5b9722

def get_for_model(self, model):

Before (including the CustomFieldModelSerializer fix):

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldModelSerializer.csv | wc -l
2052

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldModelSerializer.csv | sort | uniq -c | sort -nr | head -n 3
   1000 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 65 AND "extras_customfieldchoice"."id" = 23) LIMIT 21
    850 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 76 AND "extras_customfieldchoice"."id" = 26) LIMIT 21
    146 statement: SELECT "extras_customfieldchoice"."id", "extras_customfieldchoice"."field_id", "extras_customfieldchoice"."value", "extras_customfieldchoice"."weight" FROM "extras_customfieldchoice" WHERE ("extras_customfieldchoice"."field_id" = 76 AND "extras_customfieldchoice"."id" = 28) LIMIT 21

After (including the CustomFieldModelSerializer fix):

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldManager.csv | wc -l
57

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldManager.csv | sort | uniq -c | sort -nr | head -n 1
      4 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584989 LIMIT 21

This is the part of this issue that I think is most related to #4878. I wonder if thread locals could be used (with a middleware to create/del a context dict) to give a per-request cache for this stuff to the model objects?

Missing Index

I didn't do enough digging to see what exactly is generating this query, but it's missing an index which makes it rather slow on large extras_customfieldvalue tables.

Before:

SELECT "extras_customfieldvalue"."id", "extras_customfieldvalue"."field_id", "extras_customfieldvalue"."obj_type_id", "extras_customfieldvalue"."obj_id", "extras_customfieldvalue"."serialized_value" FROM "extras_customfieldvalue" WHERE ("extras_customfieldvalue"."obj_id" IN (<many IDs>) AND "extras_customfieldvalue"."obj_type_id" = 32) ORDER BY "extras_customfieldvalue"."obj_type_id" ASC, "extras_customfieldvalue"."obj_id" ASC, "extras_customfieldvalue"."id" ASC

 Gather Merge  (cost=153573.71..154312.58 rows=6425 width=19) (actual time=699.040..701.888 rows=11768 loops=1)
   Workers Planned: 1
   Workers Launched: 1
   ->  Sort  (cost=152573.70..152589.76 rows=6425 width=19) (actual time=697.309..697.566 rows=5884 loops=2)
         Sort Key: obj_id, id
         Sort Method: quicksort  Memory: 651kB
         Worker 0:  Sort Method: quicksort  Memory: 654kB
         ->  Parallel Seq Scan on extras_customfieldvalue  (cost=0.00..152167.33 rows=6425 width=19) (actual time=0.307..695.073 rows=5884 loops=2)
               Filter: ((obj_type_id = 32) AND (obj_id = ANY ('{<many IDs>}'::integer[])))
               Rows Removed by Filter: 95668
 Planning Time: 13.572 ms
 Execution Time: 702.269 ms

Proposed index:

netbox=# CREATE INDEX ON extras_customfieldvalue (obj_id, obj_type_id);
CREATE INDEX

After:

 Sort  (cost=8810.83..8838.14 rows=10922 width=19) (actual time=7.269..7.647 rows=11768 loops=1)
   Sort Key: obj_id, id
   Sort Method: quicksort  Memory: 1304kB
   ->  Index Scan using extras_customfieldvalue_obj_id_obj_type_id_idx on extras_customfieldvalue  (cost=0.42..8078.24 rows=10922 width=19) (actual time=0.210..4.884 rows=11768 loops=1)
         Index Cond: ((obj_id = ANY ('{<many IDs>}'::integer[])) AND (obj_type_id = 32))
 Planning Time: 13.444 ms
 Execution Time: 7.953 ms

I can submit a PR with a migration to add this index if you agree it should be fixed.

Remaining queries

This should probably be a separate issue, but about half the remaining queries seem to be parent device lookups. It'd be nice if these were just one query (eg as WHERE dcim_device.id IN (...)) but I'm not sure how easy Django makes that. This is obviously a much less significant improvement than the other 3,000 queries though!

$ python -c "import csv; import sys; reader = csv.reader(open(sys.argv[1], 'r')); print('\n'.join([' '.join(r[13].split()) for r in reader if r[13].startswith('statement: ')]))" CustomFieldManager.csv | sort | uniq -c | sort -nr | rg ' WHERE "dcim_device"."id"'
      4 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584989 LIMIT 21
      3 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584969 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 594197 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 594114 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 594110 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 593992 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 593954 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 593864 LIMIT 21
      2 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 585350 LIMIT 21
      1 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 594219 LIMIT 21
      1 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 593979 LIMIT 21
      1 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 593883 LIMIT 21
      1 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 585165 LIMIT 21
      1 statement: SELECT "dcim_device"."id", "dcim_device"."local_context_data", "dcim_device"."created", "dcim_device"."last_updated", "dcim_device"."device_type_id", "dcim_device"."device_role_id", "dcim_device"."tenant_id", "dcim_device"."platform_id", "dcim_device"."name", "dcim_device"."_name", "dcim_device"."serial", "dcim_device"."asset_tag", "dcim_device"."site_id", "dcim_device"."rack_id", "dcim_device"."position", "dcim_device"."face", "dcim_device"."status", "dcim_device"."primary_ip4_id", "dcim_device"."primary_ip6_id", "dcim_device"."cluster_id", "dcim_device"."virtual_chassis_id", "dcim_device"."vc_position", "dcim_device"."vc_priority", "dcim_device"."comments" FROM "dcim_device" WHERE "dcim_device"."id" = 584795 LIMIT 21

Use Case

We do a lot of things that involve fetching data for a large number of devices. Additionally, we have a large number of custom fields, though that doesn't seem to really matter that much here. It seems that the number of queries currently executed is 3*N where N is number of CustomFieldModel objects instantiated. Reducing this to a constant number of queries should significantly improve general Netbox performance.

Database Changes

See Proposed index section above.

External Dependencies

None.

The text was updated successfully, but these errors were encountered:

DanSheps · 2020-08-17T16:45:49Z

I think we would be best to hold off on this until we get #4878 completed

jeremystretch · 2020-08-18T18:57:40Z

While I appreciate the thoughtful analysis, as Dan points out, #4878 was opened specifically to address the shortcomings of the current implementation. I'd hate to see people spend too much time working to improve the current implementation only for it to be ripped out in v2.10. That said, I'll leave this open for anyone who wants to volunteer to make improvements, with the understanding that any changes to the data model itself are untenable given the pending work.

roganartu · 2020-08-18T19:28:33Z

That's entirely reasonable. The primary motivation for submitting this was that I'd done the profiling and I figured a ticket seemed as good a place as any to document my findings since I hadn't seen an deep analysis of the root causes anywhere yet.

Would a PR for roganartu@13238ea be compatible with your plans for #4878? It represents a nearly 20% improvement by cutting out one SQL query per result object, and only touches the model to add an optional kwarg for custom field memoisation, otherwise it just uses the existing serialiser cache.

jeremystretch · 2020-09-17T17:32:00Z

Given that #4878 has been merged into develop-2.10 at this point, I don't think it makes sense to commit any further development effort to the current implementation (except for any bugs that happen to pop up). However I invite you to experiment with the upcoming release and share any suggestions you have for improvements.

DanSheps added type: housekeeping Changes to the application which do not directly impact the end user status: under review Further discussion is needed to determine this issue's scope and/or implementation labels Aug 17, 2020

jeremystretch added status: needs owner This issue is tentatively accepted pending a volunteer committed to its implementation and removed status: under review Further discussion is needed to determine this issue's scope and/or implementation labels Aug 18, 2020

jeremystretch closed this as completed Sep 17, 2020

jeremystretch removed the status: needs owner This issue is tentatively accepted pending a volunteer committed to its implementation label Sep 17, 2020

github-actions bot locked as resolved and limited conversation to collaborators Dec 17, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Improve performance of custom field models and serializers #4998

Improve performance of custom field models and serializers #4998

roganartu commented Aug 13, 2020 •

edited

Loading

DanSheps commented Aug 17, 2020

jeremystretch commented Aug 18, 2020

roganartu commented Aug 18, 2020

jeremystretch commented Sep 17, 2020

Improve performance of custom field models and serializers #4998

Improve performance of custom field models and serializers #4998

Comments

roganartu commented Aug 13, 2020 • edited Loading

Environment

Proposed Functionality

Profiling

Vanilla v2.8.8

CustomFieldModelSerializer

CustomFieldManager

Missing Index

Remaining queries

Use Case

Database Changes

External Dependencies

DanSheps commented Aug 17, 2020

jeremystretch commented Aug 18, 2020

roganartu commented Aug 18, 2020

jeremystretch commented Sep 17, 2020

roganartu commented Aug 13, 2020 •

edited

Loading

`CustomFieldModelSerializer`

`CustomFieldManager`