search

jdholtz / auto-southwest-check-in

A Python script that automatically checks in to your Southwest flight 24 hours beforehand.
GNU General Public License v3.0
460 stars 89 forks source link

Reservation monitor hung with lock #249

Closed rufus210 closed 4 months ago

rufus210 commented 7 months ago

Version

Auto-Southwest Check-In v7.3

Browser Version

google-chrome-stable 123.0.6312.86-1

Description

The script missed checking in to a flight for me and looking at the log it hasn't done anything for quite a while. From the logs reservation_monitor acquired a lock but never released it, causing later processing to fail.

To Reproduce

Just running the script normally.

Expected Behavior

Process the trips and check in for them

Relevant logs and program output

My flight was on 4/2.  I see it trying to checkin on 4/1 but it failed to acquire the lock so couldn't check in.

2024-03-12 10:28:05 DEBUG Process-1[reservation_monitor:181]: Lock released
2024-03-12 10:28:05 DEBUG Process-1[reservation_monitor:130]: Sleeping for 86348 seconds
2024-03-13 10:27:13 DEBUG Process-2[reservation_monitor:168]: Acquiring lock...
2024-03-13 10:27:13 DEBUG Process-1[reservation_monitor:168]: Acquiring lock...
2024-03-13 10:27:13 DEBUG Process-2[reservation_monitor:170]: Lock acquired
2024-03-13 10:27:13 DEBUG Process-2[reservation_monitor:192]: Retrieving reservations for account
2024-03-13 10:27:13 DEBUG Process-2[webdriver:106]: Starting webdriver for current session
2024-03-13 10:27:15 DEBUG Process-2[webdriver:122]: Using browser version: 122.0.6261.111
2024-03-13 10:27:15 DEBUG Process-2[webdriver:126]: Loading Southwest Check-In page
2024-03-13 10:27:22 DEBUG Process-2[webdriver:79]: Logging into account to get a list of reservations and valid headers
2024-03-13 10:27:24 DEBUG Process-2[webdriver:155]: Waiting for headers_set to be set
2024-03-13 10:27:24 DEBUG Process-2[webdriver:159]: headers_set set successfully
2024-03-13 10:27:29 DEBUG Process-2[webdriver:147]: Login response has been received
2024-03-13 10:27:30 DEBUG Process-2[webdriver:155]: Waiting for login_request_id to be set
2024-03-13 10:27:30 DEBUG Process-2[webdriver:159]: login_request_id set successfully
2024-03-13 10:27:30 DEBUG Process-2[webdriver:155]: Waiting for trips_request_id to be set
2024-03-13 10:27:30 DEBUG Process-2[webdriver:151]: Upcoming trips response has been received
2024-03-13 10:27:31 DEBUG Process-2[webdriver:159]: trips_request_id set successfully
2024-03-13 10:27:31 DEBUG Process-2[reservation_monitor:211]: Successfully retrieved 2 reservations
2024-03-13 10:27:31 DEBUG Process-2[reservation_monitor:86]: Scheduling flight check-ins for 2 reservations
2024-03-13 10:27:31 DEBUG Process-2[checkin_scheduler:76]: Retrieving reservation information
2024-03-13 10:27:33 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:33 DEBUG Process-2[checkin_scheduler:89]: Successfully retrieved reservation information
2024-03-13 10:27:33 DEBUG Process-2[checkin_scheduler:57]: 1 flights found under current reservation
2024-03-13 10:27:33 DEBUG Process-2[checkin_scheduler:76]: Retrieving reservation information
2024-03-13 10:27:35 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:89]: Successfully retrieved reservation information
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:57]: 1 flights found under current reservation
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:43]: 2 total flights were found
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:100]: 0 new flights found
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:104]: Scheduling 0 flights for check-in
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:116]: 2 flights are currently scheduled. Removing old flights
2024-03-13 10:27:35 DEBUG Process-2[checkin_scheduler:132]: Successfully removed old flights. 2 flights are now scheduled
2024-03-13 10:27:35 DEBUG Process-2[reservation_monitor:95]: Checking fares for 2 flights
2024-03-13 10:27:35 DEBUG Process-2[fare_checker:30]: Checking current price for flight
2024-03-13 10:27:35 DEBUG Process-2[fare_checker:88]: Retrieving reservation information
2024-03-13 10:27:36 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:36 DEBUG Process-2[fare_checker:103]: Retrieving search information for the current flight
2024-03-13 10:27:38 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:38 DEBUG Process-2[fare_checker:82]: Retrieving matching flights
2024-03-13 10:27:40 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:40 DEBUG Process-2[fare_checker:50]: Found 19 matching flights
2024-03-13 10:27:40 DEBUG Process-2[fare_checker:37]: Flight price change found for +120 USD
2024-03-13 10:27:40 DEBUG Process-2[fare_checker:30]: Checking current price for flight
2024-03-13 10:27:40 DEBUG Process-2[fare_checker:88]: Retrieving reservation information
2024-03-13 10:27:41 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:41 DEBUG Process-2[fare_checker:103]: Retrieving search information for the current flight
2024-03-13 10:27:43 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:43 DEBUG Process-2[fare_checker:82]: Retrieving matching flights
2024-03-13 10:27:45 DEBUG Process-2[utils:33]: Successfully made request after 1 attempts
2024-03-13 10:27:45 DEBUG Process-2[fare_checker:50]: Found 16 matching flights
2024-03-13 10:27:45 DEBUG Process-2[fare_checker:37]: Flight price change found for +2281 PTS
2024-03-13 10:27:45 DEBUG Process-1[reservation_monitor:170]: Lock acquired
2024-03-13 10:27:45 DEBUG Process-1[reservation_monitor:192]: Retrieving reservations for account
2024-03-13 10:27:45 DEBUG Process-1[webdriver:106]: Starting webdriver for current session
2024-03-13 10:27:46 DEBUG Process-2[reservation_monitor:181]: Lock released
2024-03-13 10:27:46 DEBUG Process-2[reservation_monitor:130]: Sleeping for 86367 seconds
2024-03-13 10:27:46 DEBUG Process-1[webdriver:122]: Using browser version: 122.0.6261.111
2024-03-13 10:27:46 DEBUG Process-1[webdriver:126]: Loading Southwest Check-In page
2024-03-13 10:27:51 DEBUG Process-1[webdriver:79]: Logging into account to get a list of reservations and valid headers
2024-03-13 10:27:53 DEBUG Process-1[webdriver:155]: Waiting for headers_set to be set
2024-03-13 10:27:53 DEBUG Process-1[webdriver:159]: headers_set set successfully
2024-03-13 10:27:54 DEBUG Process-1[webdriver:147]: Login response has been received
2024-03-13 10:27:54 DEBUG Process-1[webdriver:155]: Waiting for login_request_id to be set
2024-03-13 10:27:54 DEBUG Process-1[webdriver:159]: login_request_id set successfully
2024-03-13 10:27:54 DEBUG Process-1[webdriver:215]: Logging in failed for an unknown reason
2024-03-13 10:27:54 WARNING Process-1[reservation_monitor:201]: Encountered a Too Many Requests error while logging in. Skipping reservation retrieval
2024-03-13 10:27:54 DEBUG Process-1[reservation_monitor:181]: Lock released
2024-03-13 10:27:54 DEBUG Process-1[reservation_monitor:130]: Sleeping for 86359 seconds
2024-03-14 10:27:14 DEBUG Process-2[reservation_monitor:168]: Acquiring lock...
2024-03-14 10:27:14 DEBUG Process-1[reservation_monitor:168]: Acquiring lock...
2024-03-14 10:27:14 DEBUG Process-2[reservation_monitor:170]: Lock acquired
2024-03-14 10:27:14 DEBUG Process-2[reservation_monitor:192]: Retrieving reservations for account
2024-03-14 10:27:14 DEBUG Process-2[webdriver:106]: Starting webdriver for current session
2024-03-14 10:27:15 DEBUG Process-2[webdriver:122]: Using browser version: 122.0.6261.111
2024-03-14 10:27:15 DEBUG Process-2[webdriver:126]: Loading Southwest Check-In page
2024-03-14 10:27:22 DEBUG Process-2[webdriver:79]: Logging into account to get a list of reservations and valid headers
2024-03-14 10:27:24 DEBUG Process-2[webdriver:155]: Waiting for headers_set to be set
2024-03-14 10:27:26 DEBUG Process-2[webdriver:147]: Login response has been received
2024-03-14 10:27:27 DEBUG Process-2[webdriver:151]: Upcoming trips response has been received
2024-03-21 06:09:55 DEBUG Process-2:1[checkin_handler:94]: Acquiring lock...
2024-03-26 17:14:55 DEBUG Process-2:2[checkin_handler:94]: Acquiring lock...
2024-04-01 10:49:55 DEBUG Process-1:1[checkin_handler:94]: Acquiring lock...

Additional context

No response

jdholtz commented 7 months ago

2024-03-14 10:27:24 DEBUG Process-2[webdriver:155]: Waiting for headers_set to be set

The reason this is happening is because it never receives the headers. This would cause the lock to never release, which results in the issues you are seeing. This is most likely the issue seen in #248.

Additionally, I will add a timeout for waiting for the headers so it doesn't totally halt the script if the headers never come.

jdholtz commented 7 months ago

@rufus210 I thought more about adding a timeout and I'm not sure it is the best idea. For example, when it times out it will need to skip retrieving/checking reservations (as the headers will be invalid) which isn't bad. However, the timeout can also happen when refreshing the headers right before checking in to ensure the script has a fresh session. In this case, it wouldn't be a good idea to ignore the error and continue with the checkin.

One idea I have would be to send a notification to users when this happens so they know the check-in will probably fail (or it can completely stop the check-in and tell the user to do so manually). Let me know your thoughts on this.

jdholtz commented 7 months ago

Hey @rufus210, any thoughts on my comment above?

darryllee commented 6 months ago

Ooof, this happened to me. I would appreciate a notification.

aaron-pham commented 6 months ago

One idea I have would be to send a notification to users when this happens so they know the check-in will probably fail (or it can completely stop the check-in and tell the user to do so manually). Let me know your thoughts on this.

This would be awesome. Similar issue happened to me & I didn't realize the check-in was going to fail until too late.

jdholtz commented 4 months ago

The script will now timeout if this happens to prevent a deadlock (added in #281). A notice notification will be sent as well. The actual issue of it timing out is tracked in #248.