[GH-ISSUE #579] HTTP 500 in /api/users/me #452

Closed
opened 2026-02-25 21:31:57 +03:00 by kerem · 7 comments
Owner

Originally created by @oliverrahner on GitHub (Jan 18, 2024).
Original GitHub issue: https://github.com/ciur/papermerge/issues/579

Originally assigned to: @ciur on GitHub.

Description

Situation:

  • freshly set up papermerge, using docker compose (see docker-compose.yml below)
  • after logging in, I only get a message stating "Error"
  • the request to /api/users/me fails with an HTTP 500

The JWT for the request to /api/users/me is this:

{
  "sub": "oliver",
  "user_id": "506c4976c6fb4262ae9d0647a88e658e",
  "exp": 1705514430
}

In the logs I see:

papermerge-web-1  | Exception in ASGI application
papermerge-web-1  | Traceback (most recent call last):
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 408, in run_asgi
papermerge-web-1  |     result = await app(  # type: ignore[func-returns-value]
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
papermerge-web-1  |     return await self.app(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/fastapi/applications.py", line 289, in __call__
papermerge-web-1  |     await super().__call__(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
papermerge-web-1  |     await self.middleware_stack(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
papermerge-web-1  |     raise exc
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
papermerge-web-1  |     await self.app(scope, receive, _send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/cors.py", line 83, in __call__
papermerge-web-1  |     await self.app(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
papermerge-web-1  |     raise exc
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
papermerge-web-1  |     await self.app(scope, receive, sender)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 20, in __call__
papermerge-web-1  |     raise e
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 17, in __call__
papermerge-web-1  |     await self.app(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
papermerge-web-1  |     await route.handle(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
papermerge-web-1  |     await self.app(scope, receive, send)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
papermerge-web-1  |     response = await func(request)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/fastapi/routing.py", line 263, in app
papermerge-web-1  |     solved_result = await solve_dependencies(
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/fastapi/dependencies/utils.py", line 586, in solve_dependencies
papermerge-web-1  |     solved = await run_in_threadpool(call, **sub_values)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/starlette/concurrency.py", line 41, in run_in_threadpool
papermerge-web-1  |     return await anyio.to_thread.run_sync(func, *args)
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/anyio/to_thread.py", line 56, in run_sync
papermerge-web-1  |     return await get_async_backend().run_sync_in_worker_thread(
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 2134, in run_sync_in_worker_thread
papermerge-web-1  |     return await future
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 851, in run
papermerge-web-1  |     result = context.run(func, *args)
papermerge-web-1  |   File "/core_app/papermerge/core/auth/__init__.py", line 43, in get_current_user
papermerge-web-1  |     user = db.get_user(engine, user_id)
papermerge-web-1  |   File "/core_app/papermerge/core/db/users.py", line 35, in get_user
papermerge-web-1  |     db_user = session.scalars(stmt, params).one()
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1824, in one
papermerge-web-1  |     return self._only_one_row(
papermerge-web-1  |   File "/core_app/.venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 757, in _only_one_row
papermerge-web-1  |     raise exc.NoResultFound(
papermerge-web-1  | sqlalchemy.exc.NoResultFound: No row was found when one was required

The actual database query is this:

papermerge-web-1  | DEBUG 2024-01-18 08:48:28,361 base SELECT core_user.id, core_user.username, core_user.email, core_user.password, core_user.first_name, core_user.last_name, core_user.is_superuser, core_user.is_staff, core_user.is_active, core_user.home_folder_id, core_user.inbox_folder_id, core_user.created_at, core_user.date_joined, core_user.updated_at
papermerge-web-1  | FROM core_user
papermerge-web-1  | WHERE core_user.username = %s
papermerge-web-1  | DEBUG 2024-01-18 08:48:28,361 base [generated in 0.00021s] ('506c4976c6fb4262ae9d0647a88e658e',)

So seemingly, somewhere username and user id get mixed up, because the query tries to find a user that has his id as name.
When I change the username to the user's id, I can log in, and other issues appear then but maybe that's something for a follow up.

Info:
docker-compose.yml:

version: "3.9"

x-backend: &common
  image: papermerge/papermerge:3.0.1
  environment:
      PAPERMERGE__SECURITY__SECRET_KEY: "6542097834589734"
      PAPERMERGE__AUTH__USERNAME: oliver
      PAPERMERGE__AUTH__PASSWORD: "C9!*SzG4oL&"
      PAPERMERGE__DATABASE__URL: mysql://papermate:CGhmdZEbHLo(Qe-N@host.docker.internal:3306/papermate
      PAPERMERGE__REDIS__URL: redis://redis:6379/0
      PAPERMERGE__SEARCH__URL: solr://solr:8983/pmg-index
      PAPERMERGE__MAIN__LOGGING_CFG: /core_app/logging.yml
  volumes:
    - media_root:/core_app/media
    - ./logging.yml:/core_app/logging.yml
  extra_hosts:
    - "host.docker.internal:host-gateway"
  depends_on:
    - redis
    - solr

services:
  web:
    <<: *common
    ports:
     - "11000:80"
  worker:
    <<: *common
    command: worker
  redis:
    image: redis:6
  solr:
    image: solr:9.3
#    ports:
#     - "8983:8983"
    volumes:
      - solr_data:/var/solr
    command:
      - solr-precreate
      - pmg-index
volumes:
  solr_data:
  media_root:
Originally created by @oliverrahner on GitHub (Jan 18, 2024). Original GitHub issue: https://github.com/ciur/papermerge/issues/579 Originally assigned to: @ciur on GitHub. **Description** Situation: - freshly set up papermerge, using docker compose (see `docker-compose.yml` below) - after logging in, I only get a message stating "Error" - the request to `/api/users/me` fails with an HTTP 500 The JWT for the request to `/api/users/me` is this: ``` { "sub": "oliver", "user_id": "506c4976c6fb4262ae9d0647a88e658e", "exp": 1705514430 } ``` In the logs I see: ``` papermerge-web-1 | Exception in ASGI application papermerge-web-1 | Traceback (most recent call last): papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 408, in run_asgi papermerge-web-1 | result = await app( # type: ignore[func-returns-value] papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__ papermerge-web-1 | return await self.app(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/fastapi/applications.py", line 289, in __call__ papermerge-web-1 | await super().__call__(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__ papermerge-web-1 | await self.middleware_stack(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__ papermerge-web-1 | raise exc papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__ papermerge-web-1 | await self.app(scope, receive, _send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/cors.py", line 83, in __call__ papermerge-web-1 | await self.app(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__ papermerge-web-1 | raise exc papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__ papermerge-web-1 | await self.app(scope, receive, sender) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 20, in __call__ papermerge-web-1 | raise e papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 17, in __call__ papermerge-web-1 | await self.app(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__ papermerge-web-1 | await route.handle(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle papermerge-web-1 | await self.app(scope, receive, send) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/routing.py", line 66, in app papermerge-web-1 | response = await func(request) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/fastapi/routing.py", line 263, in app papermerge-web-1 | solved_result = await solve_dependencies( papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/fastapi/dependencies/utils.py", line 586, in solve_dependencies papermerge-web-1 | solved = await run_in_threadpool(call, **sub_values) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/starlette/concurrency.py", line 41, in run_in_threadpool papermerge-web-1 | return await anyio.to_thread.run_sync(func, *args) papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/anyio/to_thread.py", line 56, in run_sync papermerge-web-1 | return await get_async_backend().run_sync_in_worker_thread( papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 2134, in run_sync_in_worker_thread papermerge-web-1 | return await future papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 851, in run papermerge-web-1 | result = context.run(func, *args) papermerge-web-1 | File "/core_app/papermerge/core/auth/__init__.py", line 43, in get_current_user papermerge-web-1 | user = db.get_user(engine, user_id) papermerge-web-1 | File "/core_app/papermerge/core/db/users.py", line 35, in get_user papermerge-web-1 | db_user = session.scalars(stmt, params).one() papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1824, in one papermerge-web-1 | return self._only_one_row( papermerge-web-1 | File "/core_app/.venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 757, in _only_one_row papermerge-web-1 | raise exc.NoResultFound( papermerge-web-1 | sqlalchemy.exc.NoResultFound: No row was found when one was required ``` The actual database query is this: ``` papermerge-web-1 | DEBUG 2024-01-18 08:48:28,361 base SELECT core_user.id, core_user.username, core_user.email, core_user.password, core_user.first_name, core_user.last_name, core_user.is_superuser, core_user.is_staff, core_user.is_active, core_user.home_folder_id, core_user.inbox_folder_id, core_user.created_at, core_user.date_joined, core_user.updated_at papermerge-web-1 | FROM core_user papermerge-web-1 | WHERE core_user.username = %s papermerge-web-1 | DEBUG 2024-01-18 08:48:28,361 base [generated in 0.00021s] ('506c4976c6fb4262ae9d0647a88e658e',) ``` So seemingly, somewhere username and user id get mixed up, because the query tries to find a user that has his id as name. When I change the username to the user's id, I can log in, and other issues appear then but maybe that's something for a follow up. **Info:** `docker-compose.yml`: ``` version: "3.9" x-backend: &common image: papermerge/papermerge:3.0.1 environment: PAPERMERGE__SECURITY__SECRET_KEY: "6542097834589734" PAPERMERGE__AUTH__USERNAME: oliver PAPERMERGE__AUTH__PASSWORD: "C9!*SzG4oL&" PAPERMERGE__DATABASE__URL: mysql://papermate:CGhmdZEbHLo(Qe-N@host.docker.internal:3306/papermate PAPERMERGE__REDIS__URL: redis://redis:6379/0 PAPERMERGE__SEARCH__URL: solr://solr:8983/pmg-index PAPERMERGE__MAIN__LOGGING_CFG: /core_app/logging.yml volumes: - media_root:/core_app/media - ./logging.yml:/core_app/logging.yml extra_hosts: - "host.docker.internal:host-gateway" depends_on: - redis - solr services: web: <<: *common ports: - "11000:80" worker: <<: *common command: worker redis: image: redis:6 solr: image: solr:9.3 # ports: # - "8983:8983" volumes: - solr_data:/var/solr command: - solr-precreate - pmg-index volumes: solr_data: media_root: ```
kerem 2026-02-25 21:31:57 +03:00
Author
Owner

@schischo commented on GitHub (Jan 18, 2024):

same here, but with sqlite3

<!-- gh-comment-id:1898385058 --> @schischo commented on GitHub (Jan 18, 2024): same here, but with sqlite3
Author
Owner

@oliverrahner commented on GitHub (Jan 18, 2024):

Found the next level of the issue:
user.id is not a UUID, but a 16-byte (32-char) hex string.
That's why is_valid_uuid returns false on this value, leading to a search for username instead of user ID.

<!-- gh-comment-id:1898432080 --> @oliverrahner commented on GitHub (Jan 18, 2024): Found the next level of the issue: `user.id` is not a UUID, but a 16-byte (32-char) hex string. That's why [`is_valid_uuid`](https://github.com/papermerge/papermerge-core/blob/b015a9753504cbb8f2cf61c476dd6454f3532d33/papermerge/core/utils/misc.py#L4) returns `false` on this value, leading to a search for username instead of user ID.
Author
Owner

@oliverrahner commented on GitHub (Jan 18, 2024):

The problem is this line:
github.com/papermerge/auth-server@0f19caf2c6/auth_server/crud.py (L84)

So it only relates to user accounts that are created via the auth-server, the creation from inside core seems to be fine, because it does not convert the UUIDs to a pure .hex() representation.

<!-- gh-comment-id:1898470001 --> @oliverrahner commented on GitHub (Jan 18, 2024): The problem is this line: https://github.com/papermerge/auth-server/blob/0f19caf2c67da2142556b04cd2456bd3af66f250/auth_server/crud.py#L84 So it only relates to user accounts that are created via the `auth-server`, the [creation from inside `core`](https://github.com/papermerge/papermerge-core/blob/b015a9753504cbb8f2cf61c476dd6454f3532d33/papermerge/core/db/users.py#L56) seems to be fine, because it does not convert the UUIDs to a pure `.hex()` representation.
Author
Owner

@ciur commented on GitHub (Jan 19, 2024):

@oliverrahner thank you for awesome report!

Issue seems to happen only with mysql/mariadb/sqlite, but not with postgres.

I will fix auth_server.crud.create_user function to insert UUIDs similarely to the one from the papermerge.core.db.users.create_user.

<!-- gh-comment-id:1899782126 --> @ciur commented on GitHub (Jan 19, 2024): @oliverrahner thank you for awesome report! Issue seems to happen only with mysql/mariadb/sqlite, but not with postgres. I will fix `auth_server.crud.create_user` function to insert UUIDs similarely to the one from the `papermerge.core.db.users.create_user`.
Author
Owner

@oliverrahner commented on GitHub (Jan 19, 2024):

Sqlalchemy seems to map UUID field types to char columns for mysql (with a fixed 32 char size!), which makes the format very explicit, leading to the issue with these differences…
The fixed size also means that you wouldn’t be able to save the UUID including the dashes, making the fix more complex 😏

<!-- gh-comment-id:1899827291 --> @oliverrahner commented on GitHub (Jan 19, 2024): Sqlalchemy seems to map UUID field types to char columns for mysql (with a fixed 32 char size!), which makes the format very explicit, leading to the issue with these differences… The fixed size also means that you wouldn’t be able to save the UUID including the dashes, making the fix more complex 😏
Author
Owner

@ciur commented on GitHub (Jan 21, 2024):

@oliverrahner @schischo

I've published 3.0.2 which should fix current issue (uuid/mysql/sqlite thingy).
Also in documentation I've updated docker-compose examples to include healthcheck key - which ensures that webapp/workers will start only after database process (not just db container) is up and running.

<!-- gh-comment-id:1902614288 --> @ciur commented on GitHub (Jan 21, 2024): @oliverrahner @schischo I've published 3.0.2 which should fix current issue (uuid/mysql/sqlite thingy). Also in documentation I've updated [docker-compose examples](https://docs.papermerge.io/3.0/setup/docker-compose/#mysql-mariadb) to include [healthcheck](https://docs.docker.com/compose/compose-file/compose-file-v3/#healthcheck) key - which ensures that webapp/workers will start only after database process (not just db container) is up and running.
Author
Owner

@oliverrahner commented on GitHub (Jan 21, 2024):

@ciur I can confirm this fixed my issue!

<!-- gh-comment-id:1902631039 --> @oliverrahner commented on GitHub (Jan 21, 2024): @ciur I can confirm this fixed my issue!
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/papermerge#452
No description provided.