itchannel / fordpass-ha

Fordpass integration for Home Assistant
316 stars 58 forks source link

500 error after several hours #26

Closed pinballnewf closed 3 years ago

pinballnewf commented 3 years ago

Component becomes unavailable after several hours. Opening the app on the phone and refreshing the vehicle fixes this for a few hours but it comes back. [VIN Redacted]

'vehiclestatus' 500 Server Error: Internal Server Error for url: https://usapi.cv.ford.com/api/vehicles/v4/1F***********8/status?lrdt=01-01-1970+00%3A00%3A00

Logger: custom_components.fordpass-ha Source: custom_components/fordpass-ha/init.py:110 Integration: fordpass-ha First occurred: November 18, 2020, 12:08:10 PM (509 occurrences) Last logged: November 20, 2020, 10:04:55 PM

Error communicating with FordPass for 1F***8

itchannel commented 3 years ago

@pinballnewf When this occurs can you try running the service "fordpass.refresh_status" and see if it updates correctly. As this should repoll the data from the car.

It shouldn't really expire the data like the error your getting as long as your using the fordpass python module that comes with the integration as it checks and refreshes the token to avoid any 500 errors. Can I confirm you haven't installed the fordpass py library from pip as I know that does have the issue you mention where as the one embedded in this integration works fine for me without having to poll the car

TRusselo commented 3 years ago

Ford has been experiencing issues with their service lately and are working on fixing it.

My phone app has been unreliable for being able to communicate with my vehicle the past 2 weeks. 2 days ago in the android app, it popped up with a message that they are working on it. this was a pop-up on top of the small red message at the top of page when it cant communicate with the vehicle

pinballnewf - what up newfie? im in the mac .... your province's capitol city ! lolz Your fordpass integration probably tried to update while ford servers were being derpy.

pinballnewf commented 3 years ago

Hey @itchannel , My HA instance runs in docker, so it's unlikely that the original fordpass.py library would be loaded, I DID check the host machine for it nonetheless - it's a good call because i had been messing with that library - but it wasn't on the host either. It's still happening, and the fordpass.refresh does NOT bring it back. Opening the app though brings it back every time. Anything else you'd like me to try?

@Trusselo, Ha! I'm much much closer to the mac nowadays! I haven't had any app trouble, and the integration becomes available like magic after opening the app, but i'll keep my eyes on the lookout for app outages. I've done the app open thing about 15 times so far, and it works, so it's likely expiring data or something as @itchannel mentioned.

petheridge commented 3 years ago

Hi @itchannel I appear to be experiencing a similar issue. Installed package via HACS. After several hours the entities go unavailable. The FordPass.refresh_status service does not seem to bring it back, opening the FordPass app brings it back.

2020-11-22 10:41:38 WARNING (MainThread) [custom_components.fordpass] 401 Client Error: Unauthorized for url: https://usapi.cv.ford.com/api/vehicles/v4/WF0JXXGAHJKKxxxxx/status?lrdt=01-01-1970+00%3A00%3A00 2020-11-22 10:41:38 WARNING (MainThread) [custom_components.fordpass] Error communicating with FordPass for WF0JXXGAHJKKxxxx 2020-11-22 10:41:38 ERROR (MainThread) [custom_components.fordpass] Error fetching fordpass data: Error communicating with FordPass for WF0JXXGAHJKKxxxxx

itchannel commented 3 years ago

@petheridge @pinballnewf next time it becomes unavaliable can you restart your home assistant and tell me if it comes back.

During testing I had this exact issue which came down to the app making a secondary call to another API endpoint after login which fetches the refresh token to be used. I've emulated this functionality but I wonder if for some reason on your setups it's not getting this refresh token properly. If you can restart home assistant and it comes back then it's a refresh token and I'll need to provide you with a couple of debug files to run so I can pull back the exact requests/responses and try and debug it further.

Also if you can let me know the following info so I can see if there's a similarity:

TRusselo commented 3 years ago

Happening to me too now. I was restarting HA 100 times yesterday as I updated things.

Home Assistant Core - running on Unraid Docker Version 118.0 old version from pip ? no Canada Opening the app AND clicking "refresh info" on my vehicle fixes it yes.

petheridge commented 3 years ago

@itchannel Install is Home Assistant Supervised but in docker - RPi4. Version 0.118.0 Not installed the FordPass lib via PIP ever. Country - UK Become unavailable 20 minutes ago. Called FordPass.refresh_status first, waited 10minutes - still unavailable Restarted Home assistant - still unavailable. Opened Ford pass app (did not go to vehicle details screen or request refresh from FordPass app) - entities became available.

petheridge commented 3 years ago

Interestingly, entities became unavailable at 16:02, they reappeared 16:20 after opening the FordPass App. Now Fordpass_lastRefresh = 11-22-2020 13:17:07.

Not sure if this helps understand what's going on!

TRusselo commented 3 years ago

it seems to happen after 4 hours of inactivity.

TRusselo commented 3 years ago

I was thinking, in the android app, there is a refresh button... so there must be a call service... (i think is the term for it) perhaps the integration could use that call to check-in every 4 hours maybe it'll keep the integration alive...

image

pinballnewf commented 3 years ago

@itchannel Install is Home Assistant Core in docker Version 0.117.5 No fordpass lib Country - Canada

TRusselo commented 3 years ago

should call this CanadaPass

itchannel commented 3 years ago

So there is 2 calls in the mobile application one of which refreshes the token and the reason why when you open the app it fixes it again. The python module I created should replicate this by making the two API calls one of which does the refresh as this happened for me originally. However since adding the second call mine has worked fine for the last month without becoming unavailable so I don't fully understand why it's doing it for you guys.

Easiest option will be to provide you with the fordpass_python.py and a test python file to run when it becomes unavailable and log the API calls to see if there's a different call being made depending on the app region maybe. I'll upload some test files in a couple of hours.

itchannel commented 3 years ago

Anyone experiencing issues can you please download the linked repo Debug and follow the instructions and send me the log.txt that is created. Happy for you to remove your password etc from the log.txt file. However I need to check the tokens being sent to/from.

Can you please run the file first and it should return a big json of your vehicle status and then rerun it once home assistant goes unavalaible then send me the output so I can compare with mine. (No need to run the python script on your home assistant box)

TRusselo commented 3 years ago

i have already run the first log. just waiting for it to go offline. I am so proud of myself for figuring out how to use that once-set-up linux vm... got all the requisites and the debug installed and working without running to a forum. I love my unraid box.

itchannel commented 3 years ago

@pinballnewf cheers for the output. Next time it expires can you delete the the cached token file /tmp/token.txt and rerun that script it and tell me if it works

It looks like it's not refreshing the token correctly which is strange as it works everytime for me.

pinballnewf commented 3 years ago

@itchannel Got to say this is the first time i've seen HTTP 402 status. had to look that one up haha

I deleted /tmp/token.txt and the result is the exact same failure.

pinballnewf commented 3 years ago

Also, I opened the app after the failure and reran [with /tmp/token.txt intact] and it did work.

If you want a capture from opening the app, I can provide that. Just lemme know, and if you prefer Apple or Android [not that it should matter]

itchannel commented 3 years ago

Yeah it's the 402 error which is why the multi step token part is in there. Can you delete /tmp/token.txt and then run the command again changing the 1 to a 0.

Also on line 94 of fordpass_new.py change it to read if self.saveToken == False:

That should make the script not save the token and just request a new one every time. Trying to work out why it's not working for some people but working for others

pinballnewf commented 3 years ago

Ok, i can do that. I'll wait the two hours for expiry again just to make sure.

itchannel commented 3 years ago

@pinballnewf If you can provide a capture from the app that would be amazing. As I'm replicating my version of the app (Australia) and it all works fine so would be good to compare against another region of the app just incase.

itchannel commented 3 years ago

Just wish I could replicate it on my end, but it performs flawlessly for me in HA and on the test script without expiring lol

pinballnewf commented 3 years ago

@itchannel no worries! I was actually getting ready to tackle building this integration on my own, but decided to see if anyone had done it and you were much further along than anyone else, so I thank you :-) We'll figure it out.

TRusselo commented 3 years ago

~ Removed ~

here's my log. worked first time. failed 2nd

itchannel commented 3 years ago

@TRusselo Thanks for the log at least is shows you and @pinballnewf are having the exact same issue. Can you try doing what I suggested to @pinballnewf . Basically change line 94 to if self.saveToken == False: and instead of doing 1 at the end of the command do 0. Also deleted /tmp/token.txt. What this should do is force the script to not save or reuse the token and just request a new one each time. Want to see if it's a refresh token issue or whether your version of the app makes different requests to the australia one hence it 402'ing

Deleted the log content to avoid GPS coordinates in this thread 👍

petheridge commented 3 years ago

Hi @itchannel, below are the logs for the steps you outlined above.

  1. First log with everything working fine : entities okay log.txt

  2. Log file while entities unavailable in HA: entities unavailable.txt

Traceback (most recent call last): File "/Users/pauletheridge/Desktop/ford_debug-master/debug.py", line 17, in <module> print(r.status()) # Print the status of the car File "/Users/pauletheridge/Desktop/ford_debug-master/fordpass_new.py", line 189, in status return result["vehiclestatus"] KeyError: 'vehiclestatus'

  1. With the entities still unavailable I deleted /temp/token.txt file, and changed line 94 of ford pass_new.py to if self.saveToken == False:, running with 0 in place of 1, I ran this multiple times, it does not seem to have succeeded: entities unavailable_token_removed.txt

  2. I then opened the FordPass app and ran the same modified ford pass_new.py file, with success: entities unavailable_token_removed_fordpass_OPENED.txt

Let me know if there is anything else you want me to try!

arjan-s commented 3 years ago

Same behavior here. It stops working in HA after a few hours, and starts working again by simply opening the FordPass app on my phone,withoit any interaction with HA.

TRusselo commented 3 years ago

Same behavior here. It stops working in HA after a few hours, and starts working again by simply opening the FordPass app on my phone,withoit any interaction with HA.

Have you updated to new version of integration in HACS? should have been fixed last night

arjan-s commented 3 years ago

Yes, I'm running 1.0.6, which is the latest as far as I can tell.

TRusselo commented 3 years ago

Mine just went unavailable too. 1.0.6

petheridge commented 3 years ago

Same here about 1 hour ago. also on 1.0.6.

pinballnewf commented 3 years ago

Hey @itchannel , a capture of app traffic for you. I entered the app, then selected the 'details' button and then 'refresh', though not all of that is probably required, it might be beneficia for other developmentl. I've tampered with the OAUTH tokens and redacted the VIN. If that causes you trouble let me know and I can send you the original privately.

-capture removed - got sick of scrolling past it!

itchannel commented 3 years ago

1.0.6 doesn't fix this bug. @pinballnewf thanks for the packet capture. What's annoying is the refresh flow is identical to the python script which makes 0 sense. The only thing I can think is it's utilising one of the extra cookies but then that wouldn't explain why the HA starts working when the app is opened. In Australia the application makes identical calls to the API but works fine and the refresh works perfectly without me having to open the fordpass app.

Can someone try the modified debug script https://github.com/itchannel/ford_debug with a value of 0 at the end. I've told it to login and refresh the token at the same time. Don't know if this will work but it's a matter of trying to work out what's different for your version.

TRusselo commented 3 years ago

just waiting for it to go offline again.... however not sure if its going to matter, but i switched to hassio supervised docker today... was on core

TRusselo commented 3 years ago

log.txt downloaded the updated debug and ran with 0 before and after "UNAVAILABLE"

pinballnewf commented 3 years ago

@itchannel I've been messing with this quite a bit today, and it doesn't look like anything to do with OAUTH or tokens. It seems I must issue the refresh command from the app for the component to become available again. I stepped through every call the app made, and after completing the refresh [which is 4 API calls] the component became available again. The component is only making 1 refresh call [/api/vehicles/v2]. This call returns a 'commandID' that must be passed to the other calls [V3 & V4]. Might be a vehicle specific thing.
I'm going to implement the extra calls tomorrow and see if it makes a difference.

Can anyone else experiencing this let me know merely opening the app brings the component available, or must you refresh the vehicle status?

arjan-s commented 3 years ago

For me simply opening the FordPass app is enough. I don't have to click anything in it.

itchannel commented 3 years ago

@pinballnewf I originally had this exact issue and opening the app (No refresh needed) was the way to fix it until I noticed the call to /"https://api.mps.ford.com/api/oauth2/v1/token" which I added after login which fixed it for mine. So maybe on your app or vehicle there is another call needed. Be good to see what comes out of your research, unfortunately I'm somewhat stuck without having a non working version :)

petheridge commented 3 years ago

For me also entities unavailable from 1:40am, the FordPass app was open in the background on my iPhone overnight (I did not do a fresh launch), at 7am I switched over to the FordPass app, didn't click anything or refresh from the app. About 3 minutes later the entities were available in HA.

pinballnewf commented 3 years ago

Well, I've managed to keep my home assistant connected to Ford for 4 hours now, which is a record for me! Still to early to tell if it's a bonafide fix or not, but if anyone wants to try. This will likely only work for people in North America, as the app is broken down by region, and the required field would need to be determined for each.

Here is what I did:

Delete the fordpass integration [this may not be necessary, i don't know] Stop home assistant Edit 'fordpass_new.py' file in the component, find line 11, 'User-Agent'' and update it to read: [this is probably un-necessary as well as it's the application ID that seems to cause the problem, but for completeness might as well] "User-Agent": "fordpass-na/449 CFNetwork/1206 Darwin/20.1.0",

and line 12 to read: "Application-Id": "71A3AD0A-CF46-4CCF-B473-FC7FE5BC4592",

delete the file /tmp/token.txt [if you are running in docker you will need to get a shell in the container] start HA, re-add the integration through the UI

@itchannel, I found a bug while working on this. Deleting the fordpass integration does NOT delete the /tmp/token.txt file, preventing one from readding the integration. I'd suggest deleting the file during setup if it exists.

itchannel commented 3 years ago

Be interesting to see if that fixes it. I did change the application ID to my app ID so maybe your on to something with it being region specific. I believe the APP ID is a the ID of Azure application gateway used for the relevant API.

If it does fix it then I can add an option to enter a Application ID and we will just have to accumulate a list of APP ID's for each region maybe.

Thanks for the bug, I'll add in a check on setup.

pinballnewf commented 3 years ago

@itchannel been 5 hours now, and still connected, so I'm feeling quite hopeful. Most I got previously was 2. Would be nice to have a 'region' option during setup, that way the App-ID [and UA string] can be set appropriately. So far, we've seen North America and Asia Pacific [assuming thats what the -AP is from your UA]

itchannel commented 3 years ago

Agreed a drop down and associated lookup table would be the nicest way. Only issue is collecting the data set first :)

arjan-s commented 3 years ago

Depending on the size of the regions, I can provide the NL or EU app ID. However, reading back in this issue, I don't immediately see how to do that.

itchannel commented 3 years ago

@arjan-s it basically requires proxying traffic from your phone using something like burp proxy to see the API calls being made. Would be good if we can get a database of common regions together if @pinballnewf reports back that it's still working for him

pinballnewf commented 3 years ago

Still connected this morning without any dropouts, so I'm calling that a success...

petheridge commented 3 years ago

Managed to grab thIs using Burb Proxy for the first time! User in the UK.

User-Agent: fordpass-eu/314 CFNetwork/1206 Darwin/20.1.0 application-id: 1E8C7794-FF5F-49BC-9596-A1E0C86C5B19

petheridge commented 3 years ago

@pinballnewf do you know how to go about deleting the temp token file? Running HA supervised in Docker 🤷‍♂️ I'd like to test the new application-Id overnight.

pinballnewf commented 3 years ago

Yep docker exec -it <container name> /bin/bash

when you get the bash# prompt issue command rm /tmp/token.txt

If you don't know the container name docker ps will list running containers

petheridge commented 3 years ago

@pinballnewf thanks so much for that! - I have added in the EU user-agent and application-id I captured. Now have the integration re-added and working. Will leave it overnight and see if it also works for me.