How we debugged a Flask session error

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 Cars API application. We noticed the scenario – Verify car count after adding a new car to the cars list failed.

2024-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'}
2024-05-23 12:11:08 | INFO | Base_Logging | conditional_write |   - Successfully fetched cars
2024-05-23 12:11:10 | INFO | Base_Logging | log_result | FAIL: Total car count doesnt match expected count
2024-05-23 12:11:10 | WARNING | test_api_example | 
2024-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/

If two different HTTP requests:
1. POST request to add a car
2. GET request to get the list of cars
both return status code of 200 but show a mismatch in car count, it could indicate that these HTTP requests are interacting with separate data. This lead us to wonder if the session data is persisting between requests for the same client session.
We looked through the commit history 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.

Isolating the problem

The API test in our CI runs against the hosted Cars App 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.
There were two aspects of the application in the remote server that could have caused the issue:
1. The Flask application running in the server
2. The systemd service we have used to serve the application
Since 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.

Identifying the problem

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!

May 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'}
May 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

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.
This proved our initial suspicion that the session data was not persistent!

There you go, a valuable lesson learnt about using Uvicorn workers to host Flask applications.
With 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.

Hire testers from Qxf2

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.

Leave a Reply

Your email address will not be published. Required fields are marked *