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

Token issue #33

Closed
Nothing4You opened this issue Nov 14, 2016 · 13 comments
Closed

Token issue #33

Nothing4You opened this issue Nov 14, 2016 · 13 comments
Labels
question

Comments

@Nothing4You
Copy link

Hey there,

I just noticed this exception in my log, I don't know how to reproduce this though, hopefully it's enough info for you to see the issue already:

Traceback (most recent call last):
  File "./run.py", line 119, in <module>
    main()
  File "./run.py", line 114, in main
    sk.loop()
  File "./run.py", line 97, in loop
    self.cycle()
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 201, in cycle
    events = self.getEvents()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 112, in getEvents
    for json in self.conn.endpoints["self"].getEvents():
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 572, in getEvents
    auth=SkypeConnection.Auth.RegToken).json().get("eventMessages", [])
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 192, in __call__
    self.verifyToken(auth)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 336, in verifyToken
    self.getRegToken()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 444, in getRegToken
    self.verifyToken(self.Auth.SkypeToken)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 333, in verifyToken
    self.getSkypeToken()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 261, in getSkypeToken
    self.liveLogin(user, pwd)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 357, in liveLogin
    ppft = re.search(r"""<input.*?name="PPFT".*?value="(.*?)\"""", loginResp.text).group(1)
AttributeError: 'NoneType' object has no attribute 'group'
@Terrance
Copy link
Owner

Looks like you're running an older version of the code, the auth stuff has been refactored quite a bit lately. Though I suspect that won't help with this...

Are you using a Skype-only (username to login) or Microsoft (email, live: username prefix) account?

If you put SKPY_DEBUG_HTTP=1 in your environment, you'll get the raw HTTP responses -- can you copy/paste the last one before this happens? (https://login.skype.com/login/oauth/microsoft)

@Terrance
Copy link
Owner

Has this happened again since reporting?

I suppose if not easily reproducible, it may have just been a temporary hiccup on the server...

@Nothing4You
Copy link
Author

It has happened a few times over the days, I didn't get to implement proper logging including the raw http response logging yet though.

Regarding the skype-only question - it's a skype-only account, no live: prefix.

It seems after roughly two days the connection is being lost (script restarts itself after exiting):
[17.11.2016 07:10:48] xxx: Service available!
[19.11.2016 07:06:02] xxx: Service available!
[21.11.2016 07:01:28] xxx: Service available!

After the update the most recent error I had was this:

2016-11-21 07:03:58,083 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 22
2016-11-21 07:03:58,085 - INFO - Resetting dropped connection: login.skype.com
2016-11-21 07:03:58,196 - DEBUG - "GET /login/oauth/microsoft?client_id=xxx&redirect_uri=https%3A%2F%2Fweb.skype.com HTTP/1.1" 302 0
2016-11-21 07:03:58,199 - INFO - Resetting dropped connection: login.live.com
2016-11-21 07:03:58,883 - DEBUG - "GET /login.srf?wa=wsignin1.0&rpsnv=13&ct=xxx&rver=6.6.6577.0&wp=MBI_SSL&wreply=https%3A%2F%2Flw.skype.com%2Flogin%2Foauth%2Fproxy%3Fclient_id%3Dxxx%26redirect_uri%3Dh
ttps%253A%252F%252Fweb.skype.com%26site_name%3Dlw.skype.com&lc=xxx&id=xxx&mkt=en&uaid=xxx&cobrandid=xxx&client_flight=hsu%2Chlm%2Chld%2CReservedFlight33%2CReservedFlight67&psi=
skype HTTP/1.1" 200 1074
Traceback (most recent call last):
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 116, in getEvents
    for json in self.conn.endpoints["self"].getEvents():
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 573, in getEvents
    auth=SkypeConnection.Auth.RegToken).json().get("eventMessages", [])
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 192, in __call__
    self.verifyToken(auth)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 336, in verifyToken
    self.getRegToken()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 445, in getRegToken
    self.verifyToken(self.Auth.SkypeToken)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 333, in verifyToken
    self.getSkypeToken()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 261, in getSkypeToken
    self.liveLogin(user, pwd)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 361, in liveLogin
    raise SkypeApiException("Couldn't retrieve PPFT from login form")
skpy.core.SkypeApiException: Couldn't retrieve PPFT from login form

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./run.py", line 118, in <module>
    main()
  File "./run.py", line 115, in main
    sk.loop()
  File "./run.py", line 100, in loop
    self.cycle()
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 203, in cycle
    events = self.getEvents()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 78, in wrapper
    if isinstance(e.args[1], requests.Response) and e.args[1].status_code in codes:
IndexError: tuple index out of range
2016-11-21 07:03:59,665 - INFO - Starting new HTTPS connection (1): login.skype.com

@Terrance
Copy link
Owner

Terrance commented Nov 21, 2016 •
edited

The PPFT token comes before the username/password are entered, so I'm not sure how that's glitching out.

That said, it appears the flow has changed again since I wrote this code -- there now appears to be an annoying two-step flow where username decides the type of login on the next page. Maybe I need to update SkPy to match.

@Terrance
Copy link
Owner

So as far as I can tell, the user-then-password flow is purely client-side -- the PPFT retrieval and credential submission is all still the same... 🤔

@Terrance
Copy link
Owner

Terrance commented Dec 8, 2016

@Nothing4You Any luck reproducing with HTTP debug on?

@Nothing4You
Copy link
Author

Sorry it took this long, I just added logging SKPY_DEBUG_HTTP=1, so I should have results in 2 days.

@Nothing4You
Copy link
Author

So, finally.
It has become a daily reconnect by now by the way.

2016-12-28 13:16:28,832 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 22
2016-12-28 13:16:49,190 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 500 67
2016-12-28 13:16:49,596 - INFO - Starting new HTTPS connection (1): login.skype.com
2016-12-28 13:16:49,749 - DEBUG - "GET /login/oauth/microsoft?redirect_uri=https%3A%2F%2Fweb.skype.com&client_id=578134 HTTP/1.1" 302 0
2016-12-28 13:16:49,752 - INFO - Starting new HTTPS connection (1): login.live.com
2016-12-28 13:16:50,387 - DEBUG - "GET /login.srf?wa=wsignin1.0&rpsnv=13&ct=1482927409&rver=6.6.6577.0&wp=MBI_SSL&wreply=https%3A%2F%2Flw.skype.com%2Flogin%2Foauth%2Fproxy%3Fredirect_uri%3Dhttps%253A%252F%252Fweb.skype.com%26client_id%3D578134%26site_name%3Dlw.skype.com&lc=1033&id=293290&mkt=en&uaid=d62c30d5ff30acbee5b10afb3751e341&psi=skype&cobrandid=90010&client_flight=hsu%2CReservedFlight33%2CReservedFlight67 HTTP/1.1" 200 8139
2016-12-28 13:16:50,392 - INFO - Resetting dropped connection: login.live.com
2016-12-28 13:16:51,359 - DEBUG - "POST /ppsecure/post.srf?wa=wsignin1.0&wp=MBI_SSL&wreply=https%3A%2F%2Flw.skype.com%2Flogin%2Foauth%2Fproxy%3Fclient_id%3D578134%26site_name%3Dlw.skype.com%26redirect_uri%3Dhttps%253A%252F%252Fweb.skype.com%252F HTTP/1.1" 200 1071
2016-12-28 13:16:51,706 - DEBUG - "POST /login/microsoft?redirect_uri=https%3A%2F%2Fweb.skype.com&client_id=578134 HTTP/1.1" 200 4046
2016-12-28 13:16:51,711 - INFO - Starting new HTTPS connection (1): api.skype.com
2016-12-28 13:16:51,883 - DEBUG - "GET /users/self/profile HTTP/1.1" 200 339
2016-12-28 13:16:51,886 - INFO - Starting new HTTPS connection (1): client-s.gateway.messenger.live.com
2016-12-28 13:16:52,251 - DEBUG - "POST /v1/users/ME/endpoints HTTP/1.1" 201 2
2016-12-28 13:16:52,254 - INFO - Starting new HTTPS connection (1): db5-client-s.gateway.messenger.live.com
2016-12-28 13:16:52,435 - DEBUG - "PUT /v1/users/ME/endpoints/%7B34217dc8-45de-4e47-bfe5-c9fc9eb98b68%7D/presenceDocs/messagingService HTTP/1.1" 200 287
2016-12-28 13:16:52,475 - DEBUG - "GET /v1/users/ME/presenceDocs/messagingService?view=expanded HTTP/1.1" 200 368
2016-12-28 13:16:52,478 - INFO - Starting new HTTPS connection (1): flagsapi.skype.com
2016-12-28 13:16:52,656 - DEBUG - "GET /flags/v1 HTTP/1.1" 200 2
2016-12-28 13:16:52,704 - DEBUG - "GET /v1/users/ME/conversations/8:live:xxx?view=msnp24Equivalent HTTP/1.1" 200 404
2016-12-28 13:16:53,089 - DEBUG - "POST /v1/users/ME/conversations/8:live:xxx/messages HTTP/1.1" 201 37
2016-12-28 13:16:53,159 - DEBUG - "GET /users/self/profile HTTP/1.1" 200 339
2016-12-28 13:16:53,200 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions HTTP/1.1" 201 2
2016-12-28 13:16:53,255 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 1086
2016-12-28 13:16:53,303 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 2555
2016-12-28 13:17:31,451 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 22
2016-12-28 13:18:10,494 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 22
2016-12-28 13:18:49,105 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 22
2016-12-28 13:18:59,986 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 365
2016-12-28 13:19:00,055 - DEBUG - "POST /v1/users/ME/conversations/ALL/messages/1482927539945/ack HTTP/1.1" 201 2
2016-12-28 13:19:13,001 - DEBUG - "POST /v1/users/ME/endpoints/SELF/subscriptions/0/poll HTTP/1.1" 200 365
2016-12-28 13:19:13,044 - DEBUG - "POST /v1/users/ME/conversations/ALL/messages/1482927552930/ack HTTP/1.1" 201 2

The problem seems to be the following extracted from SKPY_DEBUG_HTTP:

<= [28/12 13:15:49] POST https://db5-client-s.gateway.messenger.live.com/v1/users/ME/endpoints/SELF/subscriptions/0/poll
{}
=> [28/12 13:16:28] 200
{}
<= [28/12 13:16:28] POST https://db5-client-s.gateway.messenger.live.com/v1/users/ME/endpoints/SELF/subscriptions/0/poll
{}
=> [28/12 13:16:49] 500
{'errorCode': 500, 'message': 'Failure due to: ServiceProxy_Timeout.'}
Traceback (most recent call last):
  File "./run.py", line 119, in <module>
    main()
  File "./run.py", line 116, in main
    sk.loop()
  File "./run.py", line 100, in loop
    self.cycle()
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 203, in cycle
    events = self.getEvents()
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 76, in wrapper
    return fn(self, *args, **kwargs)
  File "/usr/lib/python3.5/site-packages/skpy/main.py", line 116, in getEvents
    for json in self.conn.endpoints["self"].getEvents():
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 573, in getEvents
    auth=SkypeConnection.Auth.RegToken).json().get("eventMessages", [])
  File "/usr/lib/python3.5/site-packages/skpy/conn.py", line 214, in __call__
    raise SkypeApiException("{0} response from {1} {2}".format(resp.status_code, method, url), resp)
skpy.core.SkypeApiException: ('500 response from POST https://db5-client-s.gateway.messenger.live.com/v1/users/ME/endpoints/SELF/subscriptions/0/poll', <Response [500]>)

@Terrance
Copy link
Owner

It has become a daily reconnect by now by the way.

As in... exactly a day?

Sessions usually only last 24 hours (check sk.conn.tokenExpiry for the server-provided expiry times), so ServiceProxy_Timeout may just be down to that. You could try using SkypeConnection.refreshSkypeToken(), which may work to keep the session alive, though I haven't tested it with an expired session. I suspect it will need to be called before the expiry time.

I've set an event loop of my own running on a test account, so will see what happens to it tomorrow...

@Nothing4You
Copy link
Author

Yes, initially it was every 48 hours, now it's down to every 24 hours:

[21.12.2016 18:32:30] <botname>: Service available!
[22.12.2016 18:33:01] <botname>: Service available!
[23.12.2016 18:33:37] <botname>: Service available!
[24.12.2016 18:34:01] <botname>: Service available!
[25.12.2016 18:34:17] <botname>: Service available!
[26.12.2016 18:34:27] <botname>: Service available!
[27.12.2016 18:34:44] <botname>: Service available!

@Terrance
Copy link
Owner

Okay, mine expired, but the auth handler kicked in as the token was past expiry (except that failed due to a missing PPFT token instead). No 500 here. 😞

Can you check the expiry you get is indeed 24 hours? I'm curious how you had it working for 48 hours before, I've never had a token last longer than a day...

@Terrance
Copy link
Owner

refreshSkypeToken() appears to work even if the original token has already expired.

As far as I can tell, there is no way to refresh registration tokens, so I think you will have to reconnect and resubscribe to events when your token expires.

@Terrance
Copy link
Owner

I'll close this ticket now, given that there doesn't appear to be a way to refresh registration tokens.

You'll have to reconnect every 24 hours using SkypeConnection.getRegToken(), but you shouldn't need to reauthenticate as the Skype token can be refreshed.

@vrachieru vrachieru mentioned this issue Apr 9, 2018
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
question
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Nothing4You @Terrance