Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HTTP 500 in /api/users/me #579

Closed
oliverrahner opened this issue Jan 18, 2024 · 7 comments
Closed

HTTP 500 in /api/users/me #579

oliverrahner opened this issue Jan 18, 2024 · 7 comments
Assignees
@ciur
Labels
3.0.1 bug Something isn't working confirmed

Comments

@oliverrahner
Copy link

oliverrahner commented Jan 18, 2024 •
edited
Loading

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:
@oliverrahner oliverrahner added the bug Something isn't working label Jan 18, 2024
@schischo
Copy link

same here, but with sqlite3

@oliverrahner
Copy link
Author

oliverrahner commented Jan 18, 2024 •
edited
Loading

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.

@oliverrahner
Copy link
Author

oliverrahner commented Jan 18, 2024 •
edited
Loading

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 seems to be fine, because it does not convert the UUIDs to a pure .hex() representation.

@ciur ciur mentioned this issue Jan 19, 2024
Closed
@ciur
Copy link
Owner

ciur commented Jan 19, 2024 •
edited
Loading

@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.

@oliverrahner
Copy link
Author

oliverrahner commented Jan 19, 2024 •
edited
Loading

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 😏

This was referenced Jan 20, 2024
Closed
Merged
@ciur
Copy link
Owner

ciur commented Jan 21, 2024 •
edited
Loading

@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.

@oliverrahner
Copy link
Author

@ciur I can confirm this fixed my issue!

@ciur ciur closed this as completed Jan 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@ciur ciur

Labels
3.0.1 bug Something isn't working confirmed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@oliverrahner @ciur @schischo