kouprlabs / voltaserve

⚡️ Cloud Storage for Creators
https://voltaserve.com
Other
248 stars 13 forks source link

Console usvc not reconnecting to database after database restart #316

Open Mrkazik99 opened 2 weeks ago

Mrkazik99 commented 2 weeks ago

Ensure these are true before submitting the bug report

Provide a brief summary of the bug

When database has been restarted, then Console microservice is not reconnecting by default (this issue especially impacts k8s deployments, but other deployments might be impacted)

Detailed steps to reproduce the bug

  1. Start voltaserve
  2. Restart databse
  3. Voila

Expected Result

On connection issue console tries to reconnect to database, after X failure it gets restarted (restart would be nice if there would be some network issue)

Actual Result

Console does nothing except throwing exceptions

Screenshots or Code Snippets (if applicable)

image

Deployment type

Additional environment details

Not needed

Any additional information, context, or logs

{"timestamp":"2024-09-07 14:19:31,106","logger_name":"console.api.responses","log_level":"DEBUG","message":"","type":"response","identifier":"69dcbcdd-c5ae-457b-9dab-15e30faca863","code":"200","headers":"{'content-length': '154', 'content-type': 'application/json'}" 2024-09-07T14:19:36.328134661Z {"timestamp":"2024-09-07 14:19:36,328","logger_name":"console.api.requests","log_level":"DEBUG","message":"","type":"request","identifier":"91da7cbb-4e18-44b0-80a0-2d0a1bac1a03","path":"/v1/liveness","method":"GET","headers":"{'host': '127.0.0.1:8086', 'user-agent': 'Wget', 'accept': '/', 'connection': 'close'}","query_params":"{}","path_params":"{}"} 2024-09-07T14:19:36.328568963Z {"timestamp":"2024-09-07 14:19:36,328","logger_name":"console.api.responses","log_level":"DEBUG","message":"","type":"response","identifier":"91da7cbb-4e18-44b0-80a0-2d0a1bac1a03","code":"503","headers":"{'content-length': '187', 'content-type': 'application/json'}" 2024-09-07T14:19:45.038510060Z {"timestamp":"2024-09-07 14:19:45,038","logger_name":"console.api.requests","log_level":"DEBUG","message":"","type":"request","identifier":"b8345864-5060-4257-b01d-db84ac42b8a1","path":"/v1/group/all","method":"GET","headers":"{'priority': 'u=0', 'sec-fetch-site': 'same-origin', 'sec-fetch-mode': 'cors', 'sec-fetch-dest': 'empty', 'cookie': 'voltaserve_access_token=eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJRd09acVlMRUciLCJpc19hZG1pbiI6dHJ1ZSwiaWF0IjoxNzI1NzE4NzY2LCJpc3MiOiJsb2NhbGhvc3QiLCJhdWQiOiJsb2NhbGhvc3QiLCJleHAiOjE3MjgzMTA3NjZ9.r54T-RO437iX4_L_DugBSCZrDkRrHrAQ1QaWsm31xEE', 'connection': 'close', 'authorization': 'Bearer eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJRd09acVlMRUciLCJpc19hZG1pbiI6dHJ1ZSwiaWF0IjoxNzI1NzE4NzY2LCJpc3MiOiJsb2NhbGhvc3QiLCJhdWQiOiJsb2NhbGhvc3QiLCJleHAiOjE3MjgzMTA3NjZ9.r54T-RO437iX4_L_DugBSCZrDkRrHrAQ1QaWsm31xEE', 'content-type': 'application/json', 'referer': 'http://localhost:3000/console/groups?page=1', 'accept-encoding': 'gzip, deflate, br, zstd', 'accept-language': 'pl', 'accept': '/', 'user-agent': 'Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0', 'host': '127.0.0.1:8086'}","query_params":"{'page': '1', 'size': '5'}","path_params":"{}"} 2024-09-07T14:19:45.039664496Z {"timestamp":"2024-09-07 14:19:45,039","logger_name":"console.api.router.group","log_level":"ERROR","message":"the connection is closed"} 2024-09-07T14:19:45.039684706Z Traceback (most recent call last): 2024-09-07T14:19:45.039688766Z File "/app/api/routers/group.py", line 73, in get_all_groups 2024-09-07T14:19:45.039692336Z groups, count = fetch_groups(page=data.page, size=data.size) 2024-09-07T14:19:45.039695866Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2024-09-07T14:19:45.039699386Z File "/app/api/database/group.py", line 103, in fetch_groups 2024-09-07T14:19:45.039715406Z raise error 2024-09-07T14:19:45.039717776Z File "/app/api/database/group.py", line 67, in fetch_groups 2024-09-07T14:19:45.039720586Z with conn.cursor() as curs: 2024-09-07T14:19:45.039722976Z ^^^^^^^^^^^^^ 2024-09-07T14:19:45.039725506Z File "/usr/local/lib/python3.12/site-packages/psycopg/connection.py", line 213, in cursor 2024-09-07T14:19:45.039727936Z self._check_connection_ok() 2024-09-07T14:19:45.039730356Z File "/usr/local/lib/python3.12/site-packages/psycopg/_connection_base.py", line 524, in _check_connection_ok 2024-09-07T14:19:45.039732866Z raise e.OperationalError("the connection is closed") 2024-09-07T14:19:45.039735096Z psycopg.OperationalError: the connection is closed 2024-09-07T14:19:45.039842067Z {"timestamp":"2024-09-07 14:19:45,039","logger_name":"console.api.responses","log_level":"DEBUG","message":"","type":"response","identifier":"b8345864-5060-4257-b01d-db84ac42b8a1","code":"500","headers":"{'content-length': '195', 'content-type': 'application/json'}" 2024-09-07T14:19:45.081759761Z {"timestamp":"2024-09-07 14:19:45,081","logger_name":"console.api.requests","log_level":"DEBUG","message":"","type":"request","identifier":"70dc3794-81a2-48ca-a677-eabd0c8fba89","path":"/v1/group/all","method":"GET","headers":"{'priority': 'u=0', 'sec-fetch-site': 'same-origin', 'sec-fetch-mode': 'cors', 'sec-fetch-dest': 'empty', 'cookie': 'voltaserve_access_token=eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJRd09acVlMRUciLCJpc19hZG1pbiI6dHJ1ZSwiaWF0IjoxNzI1NzE4NzY2LCJpc3MiOiJsb2NhbGhvc3QiLCJhdWQiOiJsb2NhbGhvc3QiLCJleHAiOjE3MjgzMTA3NjZ9.r54T-RO437iX4_L_DugBSCZrDkRrHrAQ1QaWsm31xEE', 'connection': 'close', 'authorization': 'Bearer eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJRd09acVlMRUciLCJpc19hZG1pbiI6dHJ1ZSwiaWF0IjoxNzI1NzE4NzY2LCJpc3MiOiJsb2NhbGhvc3QiLCJhdWQiOiJsb2NhbGhvc3QiLCJleHAiOjE3MjgzMTA3NjZ9.r54T-RO437iX4_L_DugBSCZrDkRrHrAQ1QaWsm31xEE', 'content-type': 'application/json', 'referer': 'http://localhost:3000/console/groups?page=1', 'accept-encoding': 'gzip, deflate, br, zstd', 'accept-language': 'pl', 'accept': '/', 'user-agent': 'Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0', 'host': '127.0.0.1:8086'}","query_params":"{'page': '1', 'size': '5'}","path_params":"{}"} 2024-09-07T14:19:45.083319309Z {"timestamp":"2024-09-07 14:19:45,082","logger_name":"console.api.router.group","log_level":"ERROR","message":"the connection is closed"} 2024-09-07T14:19:45.083348929Z Traceback (most recent call last): 2024-09-07T14:19:45.083354779Z File "/app/api/routers/group.py", line 73, in get_all_groups 2024-09-07T14:19:45.083359839Z groups, count = fetch_groups(page=data.page, size=data.size) 2024-09-07T14:19:45.083364699Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2024-09-07T14:19:45.083369479Z File "/app/api/database/group.py", line 103, in fetch_groups 2024-09-07T14:19:45.083387620Z raise error 2024-09-07T14:19:45.083395940Z File "/app/api/database/group.py", line 67, in fetch_groups 2024-09-07T14:19:45.083400970Z with conn.cursor() as curs: 2024-09-07T14:19:45.083405700Z ^^^^^^^^^^^^^ 2024-09-07T14:19:45.083410670Z File "/usr/local/lib/python3.12/site-packages/psycopg/connection.py", line 213, in cursor 2024-09-07T14:19:45.083433570Z self._check_connection_ok() 2024-09-07T14:19:45.083439130Z File "/usr/local/lib/python3.12/site-packages/psycopg/_connection_base.py", line 524, in _check_connection_ok 2024-09-07T14:19:45.083444570Z raise e.OperationalError("the connection is closed") 2024-09-07T14:19:45.083449690Z psycopg.OperationalError: the connection is closed 2024-09-07T14:19:45.083785791Z {"timestamp":"2024-09-07 14:19:45,083","logger_name":"console.api.responses","log_level":"DEBUG","message":"","type":"response","identifier":"70dc3794-81a2-48ca-a677-eabd0c8fba89","code":"500","headers":"{'content-length': '195', 'content-type': 'application/json'}" 2024-09-07T14:19:55.503983220Z {"timestamp":"2024-09-07 14:19:55,503","logger_name":"uvicorn.error","log_level":"INFO","message":"Shutting down"} 2024-09-07T14:19:55.604438650Z {"timestamp":"2024-09-07 14:19:55,604","logger_name":"uvicorn.error","log_level":"INFO","message":"Waiting for application shutdown."} 2024-09-07T14:19:55.604567570Z {"timestamp":"2024-09-07 14:19:55,604","logger_name":"uvicorn.error","log_level":"INFO","message":"Application shutdown complete."} 2024-09-07T14:19:55.604748251Z {"timestamp":"2024-09-07 14:19:55,604","logger_name":"uvicorn.error","log_level":"INFO","message":"Finished server process [1]"} 2024-09-07T14:19:59.287365575Z {"timestamp":"2024-09-07 14:19:59,287","logger_name":"uvicorn.error","log_level":"INFO","message":"Started server process [1]"} 2024-09-07T14:19:59.287429266Z {"timestamp":"2024-09-07 14:19:59,287","logger_name":"uvicorn.error","log_level":"INFO","message":"Waiting for application startup."} 2024-09-07T14:19:59.287585336Z {"timestamp":"2024-09-07 14:19:59,287","logger_name":"uvicorn.error","log_level":"INFO","message":"Application startup complete."}

loboda4450 commented 2 weeks ago

K8s deployments are secured by readiness/liveness endpoints, so the service should restart itself, but that is definitely an issue.