Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Closed
natecodes opened this issue Apr 8, 2024 · 8 comments
Closed

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

natecodes opened this issue Apr 8, 2024 · 8 comments
Labels
invalid This doesn't seem right

Comments

@natecodes
Copy link
Contributor

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
@natecodes natecodes added the bug Something isn't working label Apr 8, 2024
@jdholtz
Copy link
Owner

jdholtz commented Apr 9, 2024

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
Copy link

babehboi commented Apr 9, 2024

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
Copy link
Contributor Author

natecodes commented Apr 9, 2024 via email •
edited
Loading

@jdholtz
Copy link
Owner

jdholtz commented Apr 9, 2024

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
Copy link
Contributor Author

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

@jdholtz
Copy link
Owner

jdholtz commented Apr 19, 2024

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 jdholtz mentioned this issue Apr 19, 2024
Closed
@jdholtz
Copy link
Owner

jdholtz commented Apr 20, 2024

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
Copy link
Contributor Author

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.

@natecodes natecodes reopened this Apr 20, 2024
@natecodes natecodes closed this as not planned Won't fix, can't repro, duplicate, stale Apr 20, 2024
@jdholtz jdholtz added invalid This doesn't seem right and removed bug Something isn't working labels Apr 20, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
invalid This doesn't seem right
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@natecodes @jdholtz @babehboi