costastf / locationsharinglib

A library to retrieve coordinates from an google account that has been shared locations of other accounts.
MIT License
170 stars 29 forks source link

Future exception was never retrieved, error shows up randomly after component has been setup successfully #20

Closed dshokouhi closed 6 years ago

dshokouhi commented 6 years ago

I have the following setup:

Home assistant installed in a virtual environment 0.68.1, python 3.6.3, ubuntu 17.10

The account is setup properly as the component will be setup right. The issue is that randomly I will receive the following error that repeats itself for at least 2.5 hours:

2018-05-06 16:13:14 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/google_maps.py", line 67, in _update_info
    for person in self.service.get_all_people():
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 324, in get_all_people
    people = self.get_shared_people() + [self.get_authenticated_person()]
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 291, in get_shared_people
    output = self._get_data()
  File "/srv/homeassistant/lib/python3.6/site-packages/cachetools/__init__.py", line 46, in wrapper
    v = func(*args, **kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 285, in _get_data
    return json.loads(response.text.split("'", 1)[1])
  File "/usr/lib/python3.6/json/__init__.py", line 354, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.6/json/decoder.py", line 339, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python3.6/json/decoder.py", line 357, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

I see this error show up twice a minute. During the time of this error the component will not receive any updates. If I open an incognito window and navigate to https;//maps.google.com I am presented with a "are you a human" checkpoint where I have to select road signs or cars or whatever Google wants me to do. During this time the "are you a human" checkpoint shows up each time I close the incognito window, open it and navigate back to Google Maps no matter how many times I get the checkpoint right. If I restart home assistant the component will fail to setup and will not work. After a few hours I can restart home assistant again and the component will work again. It is not necessary to delete the cookies file during this time as the component will start working again after a few hours.

If there are any more details needed please let me know. I am also willing to apply any code updates on my end as well. I suspect though that any troubleshooting steps or logs needed will need to be grabbed during the time the "are you a human" checkpoint appears.

The odd part is that the last time I encountered this error it seemed to have resolved itself after 2.5 hours however if I decide to restart during this time the component will not work. Maybe there is some kind of time out?

costastf commented 6 years ago

Please update the version to the latest one 2.0.2 in the component and report back when you get a traceback. The latest version handles this exception and logs the actual response which will start getting us somewhere.

dshokouhi commented 6 years ago

Ok will do, thank you :)

dshokouhi commented 6 years ago

ok error finally showed up:

Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/google_maps.py", line 67, in _update_info
    for person in self.service.get_all_people():
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 393, in get_all_people
    people = self.get_shared_people() + [self.get_authenticated_person()]
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 360, in get_shared_people
    output = self._get_data()
  File "/srv/homeassistant/lib/python3.6/site-packages/cachetools/__init__.py", line 46, in wrapper
    v = func(*args, **kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 354, in _get_data
    return data
UnboundLocalError: local variable 'data' referenced before assignment
dshokouhi commented 6 years ago

Ok update on this. I am referrencing the time stamp in home-assistant.log

The above error started here:

2018-05-14 13:48:40 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/google_maps.py", line 67, in _update_info
    for person in self.service.get_all_people():
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 393, in get_all_people
    people = self.get_shared_people() + [self.get_authenticated_person()]
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 360, in get_shared_people
    output = self._get_data()
  File "/srv/homeassistant/lib/python3.6/site-packages/cachetools/__init__.py", line 46, in wrapper
    v = func(*args, **kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 354, in _get_data
    return data

And the last message before the component started working again:

2018-05-14 16:45:48 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/components/device_tracker/google_maps.py", line 67, in _update_info
    for person in self.service.get_all_people():
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 393, in get_all_people
    people = self.get_shared_people() + [self.get_authenticated_person()]
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 360, in get_shared_people
    output = self._get_data()
  File "/srv/homeassistant/lib/python3.6/site-packages/cachetools/__init__.py", line 46, in wrapper
    v = func(*args, **kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 354, in _get_data
    return data
UnboundLocalError: local variable 'data' referenced before assignment

I can also see that the device had its last update at 1:40 pm PST and the next update was at 4:30pm PST so I guess the error is somewhat safe to ignore but during the time of the error the component will not update.

costastf commented 6 years ago

I am afraid that you are not using v2.0.2 on that version data is always returned and it logs the contents of there is an exception so we can see what the actual response is and troubleshoot.

dshokouhi commented 6 years ago

Darn ok I will update it in the morning and next time the error comes will update this bug. I thought I upgraded again after updating to 0.69 but obviously I didn't. My bad

costastf commented 6 years ago

If you take a look at issue 21 I think we have our culprit. I can try to work around that but I won't be able to spend any time on it before next Thursday.

dshokouhi commented 6 years ago

It is very similar if not the same maybe

dshokouhi commented 6 years ago

@costastf this is really weird but for some reason after upgrading my venv to 2.0.2

(homeassistant) homeassistant@ubuntu:/home/danny$ pip show locationsharinglib   Name: locationsharinglib
Version: 2.0.2

and restarting home assistant the version downgrades to 1.2.2 I am not sure how to proceed as I have not seen that before

costastf commented 6 years ago

You need to update the version in the component and not manually install it, since the component installs it's required dependencies automatically.

dshokouhi commented 6 years ago

Ah thank you for explaining that :) I have now updated the component and can confirm version 2.0.2 is installed. Also, not entirely sure #21 is related as the user could not setup the component. I had also seen the Future Exception show up once last night so hopefully we will see it again soon.

(homeassistant) homeassistant@ubuntu:/home/danny$ pip show locationsharinglib   Name: locationsharinglib
Version: 2.0.2
dshokouhi commented 6 years ago

I am not sure if this is related but just saw this error:

2018-05-16 20:38:01 ERROR (SyncWorker_10) [locationsharinglib.Service] Unable to parse response :<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 500 (Server Error)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>500.</b> <ins>That’s an error.</ins>
  <p>The server encountered an error and could not complete your request.<p>If the problem persists, please <A HREF="http://www.google.com/support/">report</A> your problem and mention this error message and the query that caused it.  <ins>That’s all we know.</ins>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 382, in _get_data
    data = json.loads(response.text.split("'", 1)[1])
IndexError: list index out of range
dshokouhi commented 6 years ago

ok the error just started about 20 minutes ago. Here is an example of the error. It started at 3:46pm and ended at 7:01 pm:

2018-05-19 19:01:16 ERROR (SyncWorker_14) [locationsharinglib.Service] Unable to parse response :<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head><meta http-equiv="content-type" content="text/html; charset=utf-8"><meta name="viewport" content="initial-scale=1"><title>https://www.google.com/maps/preview/locationsharing/read?authuser=0&amp;hl=en&amp;gl=us&amp;pb=%211m7%218m6%211m3%211i14%212i8413%213i5385%212i6%213x4095%212m3%211e0%212sm%213i407105169%213m7%212sen%215e1105%2112m4%211e68%212m2%211sset%212sRoadmap%214e1%215m4%211e4%218m2%211e0%211e1%216m9%211e12%212i2%2126m1%214b1%2130m1%211f1.3953487873077393%2139b1%2144e1%2150e0%2123i4111425</title></head>
<body style="font-family: arial, sans-serif; background-color: #fff; color: #000; padding:20px; font-size:18px;" onload="e=document.getElementById('captcha');if(e){e.focus();}">
<div style="max-width:400px;">
<hr noshade size="1" style="color:#ccc; background-color:#ccc;"><br>
<form action="index" method="post">
<script src="https://www.google.com/recaptcha/api.js" async defer></script>
<div id="recaptcha" class="g-recaptcha" data-sitekey="6LfwuyUTAAAAAOAmoS0fdqijC2PbbdH4kjq62Y1b"></div>
<input type='hidden' name='q' value='EgRMrhJQGOutg9gFIhkA8aeDSwDPceOanzmawICV6f_Nz76f6RfJMgFy'><input type="hidden" name="continue" value="https://www.google.com/maps/preview/locationsharing/read?authuser=0&amp;hl=en&amp;gl=us&amp;pb=%211m7%218m6%211m3%211i14%212i8413%213i5385%212i6%213x4095%212m3%211e0%212sm%213i407105169%213m7%212sen%215e1105%2112m4%211e68%212m2%211sset%212sRoadmap%214e1%215m4%211e4%218m2%211e0%211e1%216m9%211e12%212i2%2126m1%214b1%2130m1%211f1.3953487873077393%2139b1%2144e1%2150e0%2123i4111425">
<input type="submit" name="submit" value="Submit" style="font-size:18px; padding:4px 0;"><br><br><br>
</form>
<hr noshade size="1" style="color:#ccc; background-color:#ccc;">

<div style="font-size:13px;">
<b>About this page</b><br><br>Our systems have detected unusual traffic from your computer network.  This page checks to see if it&#39;s really you sending the requests, and not a robot.  <a href="#" onclick="document.getElementById('infoDiv').style.display='block';">Why did this happen?</a><br><br>
<div id="infoDiv" style="display:none; background-color:#eee; padding:10px; margin:0 0 15px 0; line-height:1.4em;">
This page appears when Google automatically detects requests coming from your computer network which appear to be in violation of the <a href="//www.google.com/policies/terms/">Terms of Service</a>. The block will expire shortly after those requests stop.  In the meantime, solving the above CAPTCHA will let you continue to use our services.<br><br>This traffic may have been sent by malicious software, a browser plug-in, or a script that sends automated requests.  If you share your network connection, ask your administrator for help &mdash; a different computer using the same IP address may be responsible.  <a href="//support.google.com/websearch/answer/86640">Learn more</a><br><br>Sometimes you may be asked to solve the CAPTCHA if you are using advanced terms that robots are known to use, or sending requests very quickly.
</div>

IP address: X.X.X.X<br>Time: 2018-05-20T02:01:16Z<br>URL: https://www.google.com/maps/preview/locationsharing/read?authuser=0&amp;hl=en&amp;gl=us&amp;pb=%211m7%218m6%211m3%211i14%212i8413%213i5385%212i6%213x4095%212m3%211e0%212sm%213i407105169%213m7%212sen%215e1105%2112m4%211e68%212m2%211sset%212sRoadmap%214e1%215m4%211e4%218m2%211e0%211e1%216m9%211e12%212i2%2126m1%214b1%2130m1%211f1.3953487873077393%2139b1%2144e1%2150e0%2123i4111425<br>
</div>
</div>
</body>
</html>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 382, in _get_data
    data = json.loads(response.text.split("'", 1)[1])
  File "/usr/lib/python3.6/json/__init__.py", line 354, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.6/json/decoder.py", line 339, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python3.6/json/decoder.py", line 357, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
costastf commented 6 years ago

Could you please give v.2.0.6 version a try and report back? I have added a valid user agent with and hope that this will fix the random locking out issues.

callifo commented 6 years ago

Just had this issue occur for the first time after using it for a month or two.

2018-06-10 11:54:43 ERROR (SyncWorker_9) [locationsharinglib.Service] Unable to parse response :<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head><meta http-equiv="content-type" content="text/html; charset=utf-8"><meta name="viewport" content="initial-scale=1"><title>https://www.google.com/maps/preview/locationsharing/read?authuser=xxx</title></head>
<body style="font-family: arial, sans-serif; background-color: #fff; color: #000; padding:20px; font-size:18px;" onload="e=document.getElementById('captcha');if(e){e.focus();}">
<div style="max-width:400px;">
<hr noshade size="1" style="color:#ccc; background-color:#ccc;"><br>
<form action="index" method="post">
<script src="https://www.google.com/recaptcha/api.js" async defer></script>
<div id="recaptcha" class="g-recaptcha" data-sitekey="6LfwuyUTAAAAAOAmoS0fdqijC2PbbdH4kjq62Y1b"></div>
<input type='hidden' name='q' value='EgR5LUZxGOmX8tgFIhkA8aeDS4S_2bAiybk5Fx7asprnycQj3F1dMgFy'><input type="hidden" name="continue" value="https://www.google.com/maps/preview/locationsharing/read?authuser=xxx">
<input type="submit" name="submit" value="Submit" style="font-size:18px; padding:4px 0;"><br><br><br>
</form>
<hr noshade size="1" style="color:#ccc; background-color:#ccc;">

<div style="font-size:13px;">
<b>About this page</b><br><br>Our systems have detected unusual traffic from your computer network.  This page checks to see if it&#39;s really you sending the requests, and not a robot.  <a href="#" onclick="document.getElementById('infoDiv').style.display='block';">Why did this happen?</a><br><br>
<div id="infoDiv" style="display:none; background-color:#eee; padding:10px; margin:0 0 15px 0; line-height:1.4em;">
This page appears when Google automatically detects requests coming from your computer network which appear to be in violation of the <a href="//www.google.com/policies/terms/">Terms of Service</a>. The block will expire shortly after those requests stop.  In the meantime, solving the above CAPTCHA will let you continue to use our services.<br><br>This traffic may have been sent by malicious software, a browser plug-in, or a script that sends automated requests.  If you share your network connection, ask your administrator for help &mdash; a different computer using the same IP address may be responsible.  <a href="//support.google.com/websearch/answer/86640">Learn more</a><br><br>Sometimes you may be asked to solve the CAPTCHA if you are using advanced terms that robots are known to use, or sending requests very quickly.
</div>

IP address: 121.x.x.x<br>Time: 2018-06-10T02:24:42Z<br>URL: https://www.google.com/maps/preview/locationsharing/read?authuser=xxx<br>
</div>
</div>
</body>
</html>
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/locationsharinglib/locationsharinglib.py", line 386, in _get_data
    data = json.loads(response.text.split("'", 1)[1])
  File "/usr/local/lib/python3.6/json/__init__.py", line 354, in loads
    return _default_decoder.decode(s)
  File "/usr/local/lib/python3.6/json/decoder.py", line 339, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/local/lib/python3.6/json/decoder.py", line 357, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
(homeassistant) homeassistant@raspberrypi:~/.homeassistant$ pip list installed | grep location
locationsharinglib      2.0.7

Tried answering the captcha whilst logged in with the account and whilst it would clear it, the error would continue in HomeAssistant. Disabled polling for a few hours, and it returned to normal when re-enabled.

costastf commented 6 years ago

Not sure if this is actually solvable guys. The user agent is set and that clears the initial hurdle of being treated as a bot but if google has a rate limiting check that can go for months and it gets triggered the only thing that can be done is lower the polling interval. Sadly the sharing service is not really build for what we are using it, it is for actually letting someone know where we are so it does make sense that from google's side there is check that says something_polling_for_months > 2 = something_is_bot. Thoughts ?

dshokouhi commented 6 years ago

@costastf in my own case I have not seen this issue since 2.0.7 was released to home assistant. I only see the 500 error every now and then and but the component has been working pretty well for me.

costastf commented 6 years ago

Ok, then I am closing this. If we get any more info and there is something that can be done we can revisit.