{"id":22226,"date":"2024-06-21T10:15:24","date_gmt":"2024-06-21T14:15:24","guid":{"rendered":"https:\/\/qxf2.com\/blog\/?p=22226"},"modified":"2024-06-21T10:15:24","modified_gmt":"2024-06-21T14:15:24","slug":"how-we-debugged-a-flask-session-error","status":"publish","type":"post","link":"https:\/\/qxf2.com\/blog\/how-we-debugged-a-flask-session-error\/","title":{"rendered":"How we debugged a Flask session error"},"content":{"rendered":"

Qxf2<\/a>‘s CI test started failing recently, debugging the error helped us learn about an important aspect of serving Flask<\/a> application using Uvicorn<\/a> workers. In this short post I will be going over the details on how we went about identifying the error.<\/p>\n

\n

Understanding the problem<\/h3>\n

We started with the pytest<\/a> output summary for the failed API test to validate our Cars API application. We noticed the scenario – Verify car count after adding a new car to the cars list<\/code> failed.<\/p>\n

\r\n2024-05-23 12:11:07 | INFO | Base_Logging | log_result | PASS: Successfully added new car with details {'name': 'figo', 'brand': 'ford', 'price_range': '5-8 lacs', 'car_type': 'hatchback'}\r\n2024-05-23 12:11:08 | INFO | Base_Logging | conditional_write |   - Successfully fetched cars\r\n2024-05-23 12:11:10 | INFO | Base_Logging | log_result | FAIL: Total car count doesnt match expected count\r\n2024-05-23 12:11:10 | WARNING | test_api_example | \r\n2024-05-23 12:11:10 | INFO | Base_Logging | test_api_example | Exception when trying to run test:\/Users\/shivahari\/Projects\/qxf2-page-object-model\/tests\/test_api_example.py\r\n<\/pre>\n
If two different HTTP<\/code> requests:
\n1. POST<\/code> request to add a car
\n2. GET<\/code> request to get the list of cars
\nboth return status code of 200<\/code> but show a mismatch in car count, it could indicate that these HTTP<\/code> requests are interacting with separate data. This lead us to wonder if the session data is persisting between requests for the same client session.
\nWe looked through the commit history<\/a> to determine if any recent changes had caused the error, but the last changes we made to the application was months ago. This helped prove that the application functionality had not changed recently.<\/p>\n
\n
Isolating the problem<\/h3>\n
The API test in our CI runs against the hosted Cars App<\/a> application. We decided to check if the test failed when we run the test against the Flask application running locally too, to our surprise the test passed. This helped prove that issue is with the application running on remote server only.
\nThere were two aspects of the application in the remote server that could have caused the issue:
\n1. The Flask application running in the server
\n2. The systemd service we have used to serve the application
\nSince there was no changes added to the application lately and the functionality was validated on the local environment we realised option #2 could be the one causing the error.<\/p>\n
\n
Identifying the problem<\/h3>\n
We started looking at the systemd service log for the unit that serves the application, we observed the values emitted during the scenario that fails in the API test, this lead us right to the bug!<\/p>\n
\r\nMay 23 12:11:07 ip-172-31-10-107 gunicorn[51463]: [2024-05-23 12:34:06,721] INFO in cars_app: successfully added {'name': 'figo', 'brand': 'ford', 'price_range': '5-8 lacs', 'car_type': 'hatchback'}\r\nMay 23 12:11:08 ip-172-31-10-107 gunicorn[51465]: [2024-05-23 12:34:07,021] INFO in cars_app: Processing \/GET request against \/cars\r\n<\/pre>\n
We identified that two different Uvicorn worker process: PID – 51463 & PID – 51465 were used to handle the two requests: add car & get car count. This could mean that two distinct session data were in use while handling those requests, and hence the total cars did not include the new car added in that client session.
\nThis proved our initial suspicion that the session data was not persistent!<\/p>\n
\n
There you go, a valuable lesson learnt about using Uvicorn workers to host Flask applications.
\nWith this technical information about the error we were able to understand and fix the bug. For a swift resolution we decided to remove the Uvicorn workers we had used to serve the application.<\/p>\n
\n
Hire testers from Qxf2<\/h3>\n
Qxf2 is the home for technical testers. Our QA engineers have a wide range of technical abilities that build upon the solid foundation of testing well. As you can see from this post, our engineer used a process to identify a bug. If you want smart testers who take the time to understand and raise the technical issues, contact Qxf2<\/a>.<\/p>\n
\n","protected":false},"excerpt":{"rendered":"
Qxf2‘s CI test started failing recently, debugging the error helped us learn about an important aspect of serving Flask application using Uvicorn workers. In this short post I will be going over the details on how we went about identifying the error. Understanding the problem We started with the pytest output summary for the failed API test to validate our […]<\/p>\n","protected":false},"author":9,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[43,172,422,421],"tags":[],"class_list":["post-22226","post","type-post","status-publish","format-standard","hentry","category-api-testing","category-flask","category-session","category-uvicorn"],"_links":{"self":[{"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/posts\/22226","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/users\/9"}],"replies":[{"embeddable":true,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/comments?post=22226"}],"version-history":[{"count":32,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/posts\/22226\/revisions"}],"predecessor-version":[{"id":22280,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/posts\/22226\/revisions\/22280"}],"wp:attachment":[{"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/media?parent=22226"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/categories?post=22226"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/qxf2.com\/blog\/wp-json\/wp\/v2\/tags?post=22226"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}