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
463 stars 89 forks source link

Check-in attempt occurred 3 minutes late (didn't sleep computer) #252

Closed natecodes closed 7 months ago

natecodes commented 7 months ago

Version

Auto-Southwest Check-In v7.3

Browser Version

123.0.6312.107

Description

Check in is supposed to be at 11 AM. It was scheduled properly according to sleep logs. I didn't close/sleep my computer.

To Reproduce

Run as normal

Expected Behavior

Expect that it would begin check in process at 10:59 or 11.

Relevant logs and program output

python3 southwest.py XXXXXX FIRST LAST --verbose
2024-04-08 09:43:14 DEBUG MainProcess[log:23]: Initialized the application
2024-04-08 09:43:14 DEBUG MainProcess[main:105]: Auto-Southwest Check-In v7.3
2024-04-08 09:43:14 DEBUG MainProcess[main:66]: Called with 3 arguments
2024-04-08 09:43:14 DEBUG MainProcess[config:132]: Initializing configuration file
2024-04-08 09:43:14 DEBUG MainProcess[config:161]: Reading the configuration file
2024-04-08 09:43:14 DEBUG MainProcess[config:174]: Reading configuration from environment variables
2024-04-08 09:43:14 DEBUG MainProcess[config:60]: Setting check fares to True
2024-04-08 09:43:14 DEBUG MainProcess[config:75]: Setting retrieval interval to 24 hours
2024-04-08 09:43:14 DEBUG MainProcess[config:109]: Setting notification level to <NotificationLevel.INFO: 1>
2024-04-08 09:43:14 DEBUG MainProcess[config:122]: Using 0 notification services
2024-04-08 09:43:14 DEBUG MainProcess[config:144]: Creating configurations for 0 accounts
2024-04-08 09:43:14 DEBUG MainProcess[config:151]: Creating configurations for 0 reservations
2024-04-08 09:43:14 DEBUG MainProcess[config:151]: Creating configurations for 1 reservations
2024-04-08 09:43:14 DEBUG MainProcess[main:85]: Reservation added through CLI arguments
2024-04-08 09:43:14 DEBUG MainProcess[main:90]: Monitoring 0 accounts and 1 reservations
2024-04-08 09:43:14 DEBUG Process-1[reservation_monitor:62]: Acquiring lock...
2024-04-08 09:43:14 DEBUG Process-1[reservation_monitor:64]: Lock acquired
2024-04-08 09:43:14 DEBUG Process-1[checkin_scheduler:50]: Refreshing headers for current session
2024-04-08 09:43:14 DEBUG Process-1[webdriver:106]: Starting webdriver for current session
2024-04-08 09:43:15 DEBUG Process-1[webdriver:122]: Using browser version: 123.0.6312.107
2024-04-08 09:43:15 DEBUG Process-1[webdriver:126]: Loading Southwest Check-In page
2024-04-08 09:43:15 DEBUG Process-1[webdriver:64]: Waiting for valid headers
2024-04-08 09:43:15 DEBUG Process-1[webdriver:155]: Waiting for headers_set to be set
2024-04-08 09:43:19 DEBUG Process-1[webdriver:159]: headers_set set successfully
2024-04-08 09:43:19 DEBUG Process-1[reservation_monitor:86]: Scheduling flight check-ins for 1 reservations
2024-04-08 09:43:19 DEBUG Process-1[checkin_scheduler:76]: Retrieving reservation information
2024-04-08 09:43:21 DEBUG Process-1[utils:33]: Successfully made request after 1 attempts
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:89]: Successfully retrieved reservation information
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:57]: 1 flights found under current reservation
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:43]: 1 total flights were found
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:100]: 1 new flights found
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:104]: Scheduling 1 flights for check-in
2024-04-08 09:43:21 DEBUG Process-1[checkin_handler:41]: Scheduling check-in for current flight
2024-04-08 09:43:21 DEBUG Process-1[notification_handler:69]: Sending new flights notification
Successfully scheduled the following flights to check in for FIRST LAST:
Flight from Los Angeles to San Francisco at 2024-04-09 11:00 AM PDT

2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:116]: 1 flights are currently scheduled. Removing old flights
2024-04-08 09:43:21 DEBUG Process-1[checkin_scheduler:132]: Successfully removed old flights. 1 flights are now scheduled
2024-04-08 09:43:21 DEBUG Process-1[reservation_monitor:95]: Checking fares for 1 flights
2024-04-08 09:43:21 DEBUG Process-1[fare_checker:30]: Checking current price for flight
2024-04-08 09:43:21 DEBUG Process-1[fare_checker:88]: Retrieving reservation information
2024-04-08 09:43:21 DEBUG Process-1:1[checkin_handler:89]: Sleeping until thirty minutes before check-in...
2024-04-08 09:43:24 DEBUG Process-1[utils:33]: Successfully made request after 1 attempts
2024-04-08 09:43:24 DEBUG Process-1[fare_checker:103]: Retrieving search information for the current flight
2024-04-08 09:43:25 DEBUG Process-1[utils:33]: Successfully made request after 1 attempts
2024-04-08 09:43:25 DEBUG Process-1[fare_checker:82]: Retrieving matching flights
2024-04-08 09:43:27 DEBUG Process-1[utils:33]: Successfully made request after 1 attempts
2024-04-08 09:43:27 DEBUG Process-1[fare_checker:50]: Found 15 matching flights
2024-04-08 09:43:27 DEBUG Process-1[fare_checker:37]: Flight price change found for +48 USD
2024-04-08 09:43:27 DEBUG Process-1[reservation_monitor:82]: Lock released
2024-04-08 09:43:27 DEBUG Process-1[reservation_monitor:130]: Sleeping for 86387 seconds
2024-04-08 10:29:54 DEBUG Process-1:1[checkin_handler:94]: Acquiring lock...
2024-04-08 10:29:55 DEBUG Process-1:1[checkin_handler:96]: Lock acquired
2024-04-08 10:29:55 DEBUG Process-1:1[checkin_scheduler:50]: Refreshing headers for current session
2024-04-08 10:29:55 DEBUG Process-1:1[webdriver:106]: Starting webdriver for current session
2024-04-08 10:29:56 DEBUG Process-1:1[webdriver:122]: Using browser version: 123.0.6312.107
2024-04-08 10:29:56 DEBUG Process-1:1[webdriver:126]: Loading Southwest Check-In page
2024-04-08 10:30:02 DEBUG Process-1:1[webdriver:64]: Waiting for valid headers
2024-04-08 10:30:02 DEBUG Process-1:1[webdriver:155]: Waiting for headers_set to be set
2024-04-08 10:30:02 DEBUG Process-1:1[webdriver:159]: headers_set set successfully
2024-04-08 10:30:03 DEBUG Process-1:1[checkin_handler:99]: Lock released
2024-04-08 10:30:03 DEBUG Process-1:1[checkin_handler:103]: Sleeping until check-in: 1791 seconds...
2024-04-08 11:03:20 DEBUG Process-1:1[checkin_handler:124]: Attempting to check in
Checking in to flight from 'Los Angeles' to 'San Francisco' for FIRST LAST

2024-04-08 11:03:20 DEBUG Process-1:1[checkin_handler:138]: Making GET request to check in
2024-04-08 11:03:21 DEBUG Process-1:1[utils:33]: Successfully made request after 1 attempts
2024-04-08 11:03:21 DEBUG Process-1:1[checkin_handler:144]: Making POST request to check in
2024-04-08 11:03:22 DEBUG Process-1:1[utils:33]: Successfully made request after 1 attempts
2024-04-08 11:03:22 DEBUG Process-1:1[checkin_handler:151]: Successfully checked in!
2024-04-08 11:03:22 DEBUG Process-1:1[notification_handler:103]: Sending successful check-in notification...
Successfully checked in to flight from 'Los Angeles' to 'San Francisco' for FIRST LAST!
FIRST LAST got B41!

^C2024-04-08 11:07:29 INFO MainProcess[main:114]:
Ctrl+C pressed. Stopping all check-ins

Stopping monitoring for reservation with confirmation number XXXXXX and name FIRST LAST
Cancelling check-in from 'Los Angeles' to 'San Francisco' for FIRST LAST
2024-04-08 11:07:29 DEBUG Process-1[checkin_handler:52]: Stopping check-in for current flight
2024-04-08 11:07:29 DEBUG Process-1[checkin_handler:55]: Killing process with PID 31715
2024-04-08 11:07:29 DEBUG Process-1[checkin_handler:59]: Waiting for process with PID 31715 to be terminated
2024-04-08 11:07:29 DEBUG Process-1[checkin_handler:65]: Process with PID 31715 successfully terminated

Additional context

No response

jdholtz commented 7 months ago

2024-04-08 10:30:03 DEBUG Process-1:1[checkin_handler:103]: Sleeping until check-in: 1791 seconds... 2024-04-08 11:03:20 DEBUG Process-1:1[checkin_handler:124]: Attempting to check in

These two lines indicate that the script slept for 33 minutes 17 seconds (1997 seconds), but the only code that executed between these two debug messages is time.sleep(1791) (1791 seconds from checking in at 10:59:55--plus a second probably due to rounding). Are you sure nothing halted the process while it was sleeping from 10:30 to 11? I don't see any explanation within the script as to why this would happen and am curious what could have affected it.

babehboi commented 7 months ago

Question: What OS were you running it on?

Typically it runs like a few seconds before the intended time and makes several attempts to go through. Interestingly your sleep timer does bring it to about 10:59:51 - however his script has a delta of -5s before the scheduled time to actually start.

natecodes commented 7 months ago

MacOS Sonoma 14.4.1

jdholtz commented 7 months ago

Interestingly your sleep timer does bring it to about 10:59:51 - however his script has a delta of -5s before the scheduled time to actually start.

The time is actually correct as it starts sleeping for 1791 seconds at 10:30:03. This results in it being 10:59:54, which is off by a second most likely due to a rounding error when subtracting the times.

natecodes commented 7 months ago

I agree, but that doesn't explain how it could have been 3 minutes late

jdholtz commented 7 months ago

I agree, but that doesn't explain how it could have been 3 minutes late

From my analysis above, there doesn't seem to be any bug in this program that would cause this and I cannot reproduce this issue (additionally, nobody has reported an issue about this before). Perhaps your OS just scheduled the process to run really late--although 3 minutes seems extreme. If this is the case, I'm not sure how to fix that within the program.

If you've used this for other check-ins, have you seen this issue with those check-ins as well?

jdholtz commented 7 months ago

Hey @natecodes, I recently added fetching the current time from an NTP server instead of relying on the computer's local time. I don't think this is what happened here but it's a possibility. If there aren't any further steps to debug this issue (or if you don't have any other suggestions), I'll close this issue as non-reproducible.

natecodes commented 7 months ago

That sounds good to me. I have a check in coming up on Tuesday so if it still does the same bug then I'll reopen the issue.