more than one row returned by a subquery used as an expression

nikolai2111 commented 1 month ago

Please verify that this bug has NOT been raised before.

[X] I checked and didn't find a similar issue

Describe the bug*

I updated to the newest version of Inventree. When I want to use the GUI it loads all the content, but when I click on 'Part' there gets no table loaded and this error message shows up.

Error message from Admin Panel ([Home] › [Errors] › Error object (17)):

Change Error
Error object (17)

Type: ProgrammingError
Path: /api/part/
Info: more than one row returned by a subquery used as an expression
When: July 6, 2024, 7 p.m.
Data:
Traceback (most recent call last):

File "/root/.local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
return self.cursor.execute(sql, params)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/psycopg/cursor.py", line 732, in execute
raise ex.with_traceback(None)

psycopg.errors.CardinalityViolation: more than one row returned by a subquery used as an expression

The above exception was the direct cause of the following exception:

Traceback (most recent call last):

File "/root/.local/lib/python3.11/site-packages/rest_framework/views.py", line 506, in dispatch
response = handler(request, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/home/inventree/src/backend/InvenTree/InvenTree/api.py", line 414, in get
return super().get(request, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/rest_framework/generics.py", line 239, in get
return self.list(request, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/home/inventree/src/backend/InvenTree/part/api.py", line 1226, in list
page = self.paginate_queryset(queryset)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/rest_framework/generics.py", line 171, in paginate_queryset
return self.paginator.paginate_queryset(queryset, self.request, view=self)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/rest_framework/pagination.py", line 395, in paginate_queryset
return list(queryset[self.offset:self.offset + self.limit])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/django/db/models/query.py", line 398, in __iter__
self._fetch_all()

File "/root/.local/lib/python3.11/site-packages/django/db/models/query.py", line 1881, in _fetch_all
self._result_cache = list(self._iterable_class(self))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/django/db/models/query.py", line 91, in __iter__
results = compiler.execute_sql(
^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1562, in execute_sql
cursor.execute(sql, params)

File "/root/.local/lib/python3.11/site-packages/django/db/backends/utils.py", line 67, in execute
return self._execute_with_wrappers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
return executor(sql, params, many, context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/django/db/backends/utils.py", line 84, in _execute
with self.db.wrap_database_errors:

File "/root/.local/lib/python3.11/site-packages/django/db/utils.py", line 91, in __exit__
raise dj_exc_value.with_traceback(traceback) from exc_value

File "/root/.local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
return self.cursor.execute(sql, params)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/root/.local/lib/python3.11/site-packages/psycopg/cursor.py", line 732, in execute
raise ex.with_traceback(None)

django.db.utils.ProgrammingError: more than one row returned by a subquery used as an expression

Steps to Reproduce

Update to newest version
Load GUI
Navigate to Part
Navigate to Index
Read out error message

Expected behaviour

It should load the parts as it has always done before.

Deployment Method

[X] Docker
[ ] Package
[ ] Bare metal
[ ] Other - added info in Steps to Reproduce

Version Information

InvenTree Version 0.15.4 API Version 196 Python Version 3.11.9 Django Version 4.2.12

Please verify if you can reproduce this bug on the demo site.

[ ] I can reproduce this bug on the demo site.

Relevant log output

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 700, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 395, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/lib/python3.10/http/client.py", line 1283, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1329, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1278, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1038, in _send_output
    self.send(msg)
  File "/usr/lib/python3.10/http/client.py", line 976, in send
    self.connect()
  File "/usr/lib/python3/dist-packages/docker/transport/unixconn.py", line 30, in connect
    sock.connect(self.unix_socket)
PermissionError: [Errno 13] Permission denied

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 756, in urlopen
    retries = retries.increment(
  File "/usr/lib/python3/dist-packages/urllib3/util/retry.py", line 532, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3/dist-packages/six.py", line 718, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 700, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 395, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/lib/python3.10/http/client.py", line 1283, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1329, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1278, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.10/http/client.py", line 1038, in _send_output
    self.send(msg)
  File "/usr/lib/python3.10/http/client.py", line 976, in send
    self.connect()
  File "/usr/lib/python3/dist-packages/docker/transport/unixconn.py", line 30, in connect
    sock.connect(self.unix_socket)
urllib3.exceptions.ProtocolError: ('Connection aborted.', PermissionError(13, 'Permission denied'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/docker/api/client.py", line 214, in _retrieve_server_version
    return self.version(api_version=False)["ApiVersion"]
  File "/usr/lib/python3/dist-packages/docker/api/daemon.py", line 181, in version
    return self._result(self._get(url), json=True)
  File "/usr/lib/python3/dist-packages/docker/utils/decorators.py", line 46, in inner
    return f(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/docker/api/client.py", line 237, in _get
    return self.get(url, **self._set_request_timeout(kwargs))
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 557, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 544, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 657, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', PermissionError(13, 'Permission denied'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/docker-compose", line 33, in <module>
    sys.exit(load_entry_point('docker-compose==1.29.2', 'console_scripts', 'docker-compose')())
  File "/usr/lib/python3/dist-packages/compose/cli/main.py", line 81, in main
    command_func()
  File "/usr/lib/python3/dist-packages/compose/cli/main.py", line 200, in perform_command
    project = project_from_options('.', options)
  File "/usr/lib/python3/dist-packages/compose/cli/command.py", line 60, in project_from_options
    return get_project(
  File "/usr/lib/python3/dist-packages/compose/cli/command.py", line 152, in get_project
    client = get_client(
  File "/usr/lib/python3/dist-packages/compose/cli/docker_client.py", line 41, in get_client
    client = docker_client(
  File "/usr/lib/python3/dist-packages/compose/cli/docker_client.py", line 170, in docker_client
    client = APIClient(use_ssh_client=not use_paramiko_ssh, **kwargs)
  File "/usr/lib/python3/dist-packages/docker/api/client.py", line 197, in __init__
    self._version = self._retrieve_server_version()
  File "/usr/lib/python3/dist-packages/docker/api/client.py", line 221, in _retrieve_server_version
    raise DockerException(
docker.errors.DockerException: Error while fetching server API version: ('Connection aborted.', PermissionError(13, 'Permission denied'))

SchrodingersGat commented 1 month ago

@nikolai2111 thanks for raising this, it's a weird one. Have not seen something like this before. Can you please answer a few questions:

Does this happen every time you try to load the page? Can you try a few reloads and see
In your browser developer view, can you look at the exact API calls which are throwing the error (should be status 500)
Please let me know the exact API call (you can redact your main server URL)

nikolai2111 commented 1 month ago

Yes when I reload the site I get a new error message. The following tables get not loaded:
- Parts
- Stock Items

All other tables like the following get loaded without a problem:

- Subcategories
- Sublocations
- Build Orders
- Suppliers
- Manufacturers
- Purchase Orders
- Customers
- Sales Orders

I reloaded the part page. Do you mean this API call?
I reloaded the part page and these were the API calls:

I hope this meets your needs, and we could fix this bug as soon as possible.

SchrodingersGat commented 1 month ago

Do you get the same error if you navigate in your browser to:

<your server name>/api/part/?limit=1&format=json

nikolai2111 commented 1 month ago

No, no error occurs.

Response Header:

Allow: GET, POST, HEAD, OPTIONS
Content-Encoding: gzip
Content-Language: en
Content-Length: 661
Content-Type: application/json
Cross-Origin-Opener-Policy: same-origin
Date: Wed, 10 Jul 2024 19:01:07 GMT
Referrer-Policy: same-origin
Server: Caddy, gunicorn
Vary: origin, Accept-Language, Cookie, Accept-Encoding
X-Content-Type-Options: nosniff
X-Frame-Options: DENY

Request Header:

Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en
Connection: keep-alive
DNT: 1
Host: inventree.local
Priority: u=1
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0

Content of the .json file:

{"count":1418,"next":"http://inventree.local/api/part/?format=json&limit=1&offset=1","previous":null,"results":[{"active":true,"assembly":false,"barcode_hash":"","category":120,"component":true,"creation_date":"2024-02-04","creation_user":1,"default_expiry":0,"default_location":null,"default_supplier":null,"description":"0.91\" OLED DISPLAY MODULE I2C","full_name":"0701.0400.0002 | 0.91\" OLED DISPLAY MODULE I2C | A","image":"/media/part_images/s-l1600_TtZrTam.jpg","IPN":"0701.0400.0002","is_template":false,"keywords":"","last_stocktake":null,"link":"","minimum_stock":0.0,"name":"0.91\" OLED DISPLAY MODULE I2C","notes":null,"pk":98,"purchaseable":true,"revision":"A","salable":false,"starred":false,"thumbnail":"/media/part_images/s-l1600_TtZrTam.thumbnail.jpg","trackable":false,"units":"","variant_of":null,"virtual":false,"pricing_min":"3.251594","pricing_max":"3.251594","pricing_updated":"2024-07-10 19:00","responsible":null,"allocated_to_build_orders":0.0,"allocated_to_sales_orders":0.0,"building":0.0,"category_default_location":null,"in_stock":3.0,"ordering":0.0,"required_for_build_orders":0,"required_for_sales_orders":0,"stock_item_count":2,"suppliers":1,"total_in_stock":3.0,"external_stock":0.0,"unallocated_stock":3.0,"variant_stock":0.0,"copy_category_parameters":true,"tags":[]}]}

SchrodingersGat commented 1 month ago

Ok, that's something.

When the error occurs, the browser is passing a bunch of different query parameters to the URL (you can see in the screenshot of the request, above). Such as:

category_detail=true
category=null

I cannot see the full list there, but you should be able to see them if you expand the columns.

What I would like you to do is:

Reproduce the error in the user interface, such that the "500" error occurs in the developer console (as per your screenshot above)
Right click on the 500 error and select "open in new tab"
This should result in the same 500 error code as before
In the browser address bar, remove query parameters one at a time, until the error is no longer there
Let me know which query parameter is responsible for the error

Does all this make sense?

nikolai2111 commented 1 month ago

I understand a little bit where you want to go. You want to rule out the parameters.

I removed the following parameters and reloaded query with Enter:

&category_detail=true
&category=null
&cascade=1
&limit=25
&offset=0
?search=

The error I got was still the same for every reload.

{"error":"ProgrammingError","error_class":"<class 'django.db.utils.ProgrammingError'>","detail":"Error details can be found in the admin panel","path":"/api/part/","status_code":500}

SchrodingersGat commented 1 month ago

@nikolai2111 ok, unfortunately that's not very helpful. I am unable to reproduce your problem - at least with the data that I have.

It may be related to a particula record. Could you try the following queries and see if any work?

/api/part/?limit=0&offset=0
/api/part/?limit=1&offset=0
/api/part/?limit=1&offset=100

felixandersen commented 3 weeks ago

I got this issue on my install while adding my inventory. I've added about 25 parts and stock items for each. I've added a few levels of part categories. Nothing special. I got the issue suddenly as I was adding a part and I see no difference in how the newly added part looks that would trigger a bug like this.

The database logs the problematic queries, one of them was:

SELECT 
  "part_part"."id", 
  "part_part"."metadata", 
  "part_part"."notes", 
  "part_part"."barcode_data", 
  "part_part"."barcode_hash", 
  "part_part"."name", 
  "part_part"."is_template", 
  "part_part"."variant_of_id", 
  "part_part"."description", 
  "part_part"."keywords", 
  "part_part"."category_id", 
  "part_part"."IPN", 
  "part_part"."revision", 
  "part_part"."link", 
  "part_part"."image", 
  "part_part"."default_location_id", 
  "part_part"."default_supplier_id", 
  "part_part"."default_expiry", 
  "part_part"."minimum_stock", 
  "part_part"."units", 
  "part_part"."assembly", 
  "part_part"."component", 
  "part_part"."trackable", 
  "part_part"."purchaseable", 
  "part_part"."salable", 
  "part_part"."active", 
  "part_part"."virtual", 
  "part_part"."bom_checksum", 
  "part_part"."bom_checked_by_id", 
  "part_part"."bom_checked_date", 
  "part_part"."creation_date", 
  "part_part"."creation_user_id", 
  "part_part"."responsible_owner_id", 
  "part_part"."last_stocktake", 
  "part_part"."base_cost", 
  "part_part"."multiple", 
  "part_part"."lft", 
  "part_part"."rght", 
  "part_part"."tree_id", 
  "part_part"."level", 
  COALESCE(
    "part_partcategory"."default_location_id", 
    (
      SELECT 
        U0."default_location_id" 
      FROM 
        "part_partcategory" U0 
      WHERE 
        (
          U0."level" <= ("part_partcategory"."level") 
          AND U0."lft" < ("part_partcategory"."lft") 
          AND U0."parent_id" IS NOT NULL 
          AND U0."rght" > ("part_partcategory"."rght") 
          AND U0."tree_id" = ("part_partcategory"."tree_id") 
          AND U0."default_location_id" IS NOT NULL
        ) 
      ORDER BY 
        U0."level" DESC
    ), 
    NULL
  ) AS "category_default_location" 
FROM 
  "part_part" 
  LEFT OUTER JOIN "part_partcategory" ON (
    "part_part"."category_id" = "part_partcategory"."id"
  ) 
WHERE 
  "part_part"."id" IN (
    14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 26
  ) 
ORDER BY 
  "part_part"."tree_id" ASC, 
  "part_part"."lft" ASC

(indented and formatted for readability)

If I put a LIMIT 1 at the end of the SELECT within the COALESCE the query works and returns reasonable data. Not sure if it breaks any functionality though.

I can supply a complete database-dump and even a complete docker compose-setup with data if needed. I would prefer to do it privately to whoever needs it.

InvenTree Version 0.15.3 API Version 196 Python Version 3.11.9 Django Version 4.2.12

SchrodingersGat commented 3 weeks ago

@felixandersen this is a really good insight. When you have added "a few levels of part categories" - do any of those have a "default location" attribute set?

This issue has likely from from here - https://github.com/inventree/InvenTree/pull/5972/files#diff-f3f90d75a975058068e26c3c55d1b05265e0339cf91da080afdd537e9c9f5146

@LavissaWoW an interesting issue, looks like we need to explicitly limit the returned results in the annotated query.

felixandersen commented 3 weeks ago

@SchrodingersGat yes they do. 4 out of 11 had a default location. I tried setting the column part_partcategory.default_location_id to NULL for all rows in the database and that made the problem go away. Until a fix is provided that looks like a reasonable workaround. I have no use for the default location feature for now anyway.

Thanks for a great project

LavissaWoW commented 3 weeks ago

@SchrodingersGat Interesting. Thought I'd checked that you could have multiple default locations in parenct categories.

Well, I think I see the problem. i'll test it out and submit a fix

LavissaWoW commented 3 weeks ago

I'm not able to break the code using the demo dataset, and therein might lie the reason for not discovering it sooner. But I see where the query might output more rows than intended.

@felixandersen Are you able to list your category structure, and which ones have default locations, and what? Don't need to be actual names of anything, just a structure I can replicate to see if I can provoke the bug to verify the fix.

i.e.:

C1
- C2, Loc a
-- C3, loc3
-C4, no loc
C5 loc a
-C6
-- C7
--- C8

etc

LavissaWoW commented 3 weeks ago

Or, if you 're tech savvy enough, modify: https://github.com/inventree/InvenTree/blob/c8870c4ade2c2ecd8ca8b57396fe685b11a6d892/src/backend/InvenTree/part/filters.py#L306

to .values('default_location')[:1]

Restart the bakcend server, and see if that eliminates your problem

SchrodingersGat commented 3 weeks ago

@LavissaWoW nice work :)

@felixandersen can you please share exactly where you found those SQL logs?

felixandersen commented 3 weeks ago

@SchrodingersGat I run the InvenTree database in a docker container so I was simply tailing it and picked the query out of there: docker logs inventree-db -f

@LavissaWoW Here is a dump of my part_partcategory table:

INSERT INTO "public"."part_partcategory" ("id", "name", "description", "default_keywords", "default_location_id", "parent_id", "level", "lft", "rght", "tree_id", "metadata", "pathstring", "icon", "structural") VALUES
(1, 'Mechanical', '', NULL, NULL, NULL, 0, 1, 16, 2, '{}', 'Mechanical', '', 't'),
(2, 'Fixings and anchors', '', NULL, NULL, 1, 1, 10, 15, 2, '{}', 'Mechanical/Fixings and anchors', '', 't'),
(3, 'Wall plugs', '', NULL, 2, 2, 2, 13, 14, 2, '{}', 'Mechanical/Fixings and anchors/Wall plugs', '', 'f'),
(4, 'Fasteners', '', NULL, 2, 1, 1, 2, 9, 2, '{}', 'Mechanical/Fasteners', '', 't'),
(5, 'Screws and bolts', '', NULL, 2, 4, 2, 3, 8, 2, '{}', 'Mechanical/Fasteners/Screws and bolts', '', 'f'),
(6, 'Wood screws', '', NULL, NULL, 5, 3, 6, 7, 2, '{}', 'Mechanical/Fasteners/Screws and bolts/Wood screws', '', 'f'),
(7, 'Electronics', '', NULL, NULL, NULL, 0, 1, 4, 1, '{}', 'Electronics', '', 't'),
(8, 'Connectors', '', NULL, NULL, 7, 1, 2, 3, 1, '{}', 'Electronics/Connectors', '', 'f'),
(9, 'Cable fixings', '', NULL, NULL, 2, 2, 11, 12, 2, '{}', 'Mechanical/Fixings and anchors/Cable fixings', '', 'f'),
(10, 'Organizing and labeling', '', NULL, NULL, NULL, 0, 1, 2, 3, '{}', 'Organizing and labeling', '', 'f'),
(11, 'Socket screws', '', NULL, NULL, 5, 3, 4, 5, 2, '{}', 'Mechanical/Fasteners/Screws and bolts/Socket screws', '', 'f');

With this state the issue shows up.

LavissaWoW commented 3 weeks ago

Thanks @felixandersen

I purged the demo data from my devcontainer, then added 5 arbitrary locations. I input the SQL query directly into the db container, and reloaded. Nothing out of the ordinary to begin with, but after making a single part in category ID 11, the category causes HTTP 500 with the error message in the original post. Any other category loads fine.

Applying the fix from the linked PR eliminates the HTTP 500, and the part table is subsequently loaded.

This annotation is used on Category, Part, Stock Item, and Order Line serializers, so the bug will probably affect any API call that uses these serializers.

nikolai2111 commented 2 weeks ago

Hello everyone,

Sorry for not answering the questions, unfortunately I was away on holiday.

@nikolai2111 ok, unfortunately that's not very helpful. I am unable to reproduce your problem - at least with the data that I have.

It may be related to a particula record. Could you try the following queries and see if any work?
* `/api/part/?limit=0&offset=0`

* `/api/part/?limit=1&offset=0`

* `/api/part/?limit=1&offset=100`

However, as far as I can see the problem has been solved, thank you all!

The fix will probably have been fixed in version 0.16.0?

LavissaWoW commented 2 weeks ago

@nikolai2111 The fix will be present in 0.16.0, yeah. It has also been marked for backporting, so I presume @SchrodingersGat will add it to the next 0.15.x release.

inventree / InvenTree