suurjaak / Skyperious

Skype chat history tool
Other
350 stars 36 forks source link

Error syncing from Skype online service #123

Closed rpodric closed 3 months ago

rpodric commented 9 months ago

I've noticed that v5.5 (on Win11) now throws some errors at the conclusion of a sync, which luckily it does still do despite this happening. I'm pretty sure that when I started using v5.5 when it came out that it didn't do this, but it has happened consistently since at least least month, so I think this has to do with a change on the server side. I'm not sure if it mentions the rate limit part of it each time, but at least some of these errors are produced each time.

Error syncing from Skype online service.:

Traceback (most recent call last): File "skpy\user.py", line 353, in getitem File "skpy\core.py", line 138, in getitem KeyError: '+18008693667'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "skyperious\workers.py", line 856, in run File "skyperious\live.py", line 738, in populate File "skyperious\live.py", line 827, in populate_chats File "skyperious\live.py", line 867, in process_chat File "skpy\util.py", line 142, in userObj File "skpy\user.py", line 355, in getitem File "skpy\user.py", line 421, in user File "skpy\conn.py", line 248, in call skpy.core.SkypeAuthException: ('Auth rate limit exceeded', <Response [429]>)

suurjaak commented 9 months ago

Have not been able to observe this myself yet.

But looks like the current rate limiting needs to be added to more places.

Can you try this version: https://erki.lap.ee/stuff/skyperious_5.5.1.dev6_x64.exe and report how it fares?

rpodric commented 9 months ago

That one had only a little to do, which maybe determines the absence of the rate limit. It's good that you don't see it, which maybe suggests something quirky with my db.

Error syncing from Skype online service.:

Traceback (most recent call last): File "skyperious\workers.py", line 856, in run File "skyperious\live.py", line 745, in populate File "skyperious\live.py", line 834, in populate_chats File "skyperious\live.py", line 912, in process_chat File "skyperious\live.py", line 198, in build_msg_cache File "skyperious\skypedata.py", line 664, in get_conversations File "skyperious\skypedata.py", line 664, in File "skyperious\skypedata.py", line 643, in AttributeError: 'NoneType' object has no attribute 'get'

suurjaak commented 9 months ago

This new error would indeed point more towards something strange with your database file.

What happens if you create a new Skype database, populated from Skype online service?

rpodric commented 9 months ago

OK, so I did that. over a few hours (I'm not sure how it could be any more rate-limited than that), and It resulted in a file almost exactly the same size (about 38MB), which was surprising given that I thought the old one had been bloated in the way databases can be with a lot of additions over time (whereas the new one would be compacted).

But none of that mattered, so it wasn't the database. Must have something to do with what it's syncing, which is mainly two very large contacts and several tiny ones (and, annoyingly, some phone numbers for no apparent reason).

Error syncing from Skype online service.:

Traceback (most recent call last): File "skpy\user.py", line 353, in getitem File "skpy\core.py", line 138, in getitem KeyError: '+18005557585'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "skyperious\workers.py", line 856, in run File "skyperious\live.py", line 745, in populate File "skyperious\live.py", line 834, in populate_chats File "skyperious\live.py", line 875, in process_chat File "skyperious\live.py", line 260, in reqattr File "skyperious\live.py", line 245, in request File "skpy\util.py", line 142, in userObj File "skpy\user.py", line 355, in getitem File "skpy\user.py", line 421, in user File "skpy\conn.py", line 248, in call skpy.core.SkypeAuthException: ('Auth rate limit exceeded', <Response [429]>)

suurjaak commented 8 months ago

Can you try the following:

Does it get to printing the chat user?

rpodric commented 8 months ago

No, I get an unexpected error when doing the first of those three, so I didn't do the rest:

An unexpected error has occurred:

      Traceback (most recent call last):
        File "code.py", line 90, in runcode
        File "<input>", line 1, in <module>
      AttributeError: 'NoneType' object has no attribute 'chats'

What is the surest possible command I can execute to ensure any command works?

suurjaak commented 8 months ago

That error would indicate that you did not log in to Skype.

rpodric commented 8 months ago

Oh, sorry. I was using the new database to do this so the PW wasn't cached as I hadn't used it yet. I did click "Log in" but didn't notice that the area below was grayed out.

Better results now, I guess. It probably should say "None" at the end like that since a phone number intended for calling isn't going to have an associated chat.

print(chat) [SkypeSingleChat] Id: 4:+118005557585 Alerts: True UserId: +18005557585 print(chat.user) None

suurjaak commented 8 months ago

Results are good in that the chat entry does actually exist.

But it's still strange why is it running into rate limits.. And specifically for this one operation.

Can you try one more thing:

Warning: the sync will take a lot longer.

rpodric commented 8 months ago

Do you have any phone number "chats" among your chats? If not, that's one possible reason why you're not seeing a problem, though they've always been there for me, so this isn't anything new.

I'll give what you mentioned a try. What is the existing rate limit, out of curiosity? And what is the scale?

suurjaak commented 8 months ago

Yep, I have various phone number contacts in my Skype, some only used for calls, others for SMSes as well; have yet to encounter such errors :(

Current rate limits in Skyperious are 30 requests per 2 seconds (RATE_LIMIT and RATE_WINDOW). If you like, you can experiment with tweaking either.

Current rate logic simply waits a bit if there have been 30 requests within the last 2 seconds. Based from your experience, I may have to add a delay before every request. But it's very strange that nobody has encountered this issue before.

rpodric commented 8 months ago

Do you think that entire traceback pertains to the rate limit line, which comes at the very end?

I'm thinking now this might relate to volume. Is your database at least 38MB? I just tried syncing a Skype account I don't use much. It, of course, finished up quickly, but it also did so without errors. Its database is 0.25MB.

suurjaak commented 8 months ago

Yes, I think the traceback is about the rate limit line. The KeyError is from trying to get the chat user from already retrieved data, and when that fails, it tries to retrieve it from Skype server (https://github.com/Terrance/SkPy/blob/master/skpy/user.py#L353 if you're interested).

My own account history is multiple times larger than that, dating back 20 years. But the key factor here may be that I have not been using Skype that much in recent times, so Skyperious simply does not have much to query. Around how many messages do you have in the last 6 months?

rpodric commented 8 months ago

I'm just talking the database derived from online though, which cannot go back further than Apr 2017. That's the one which is now 38MB. I have a separate database for everything before that. It sounds like you might have a single database encompassing your historical data and everything since, which makes a lot of sense, but either I didn't know how to do that or I decided to play it safe and keep them separate, I don't recall.

There are about 3,000 messages combined between two chats in the last 6 months, according to the statistics.

rpodric commented 8 months ago

RATE_LIMIT = 5 worked, but it's so slow that I'm not sure that it's really practical for initial syncs (differential or selective ones may be another story). I guess the issue is a combination of rate and volume, but that never used to be a problem, so something must have changed on their end. You use a high rate but don't see a problem because of low volume.

Also, we should keep in mind that while the errors may look bad, I've never seen the sync fail, it all seems to be there.

suurjaak commented 8 months ago

Aha, so it is a rate limit issue still. How long did the sync take?

It's frustrating that I can't ever seem to hit the limit myself even when I effectively disable rate limiting. It did 1100+ requests in ~6 minutes, no errors. Or when I chose to sync older chats as well, 2700+ requests in ~10 minutes, no errors.

Maybe the Skype online service starts applying harsher limits on callers that have already hit the limit once..

But I will ruminate on this a bit. It must be possible to have a solution that works, and is not dog-slow. I will get back to you with a version to test, if that's okay with you.

rpodric commented 8 months ago

It took about 24 hours. That makes for a 38MB db. It's about 130K messages.

When you say requests, is that the same as the message count? Or maybe it's a stat I just haven't seen yet?

If necessary, I could get the main person I communicate with to also try it. He wouldn't have as much but I'd estimate about two thirds of what I do, and consistently over the full 6.5 years, too. Also a very different geographical area, on the chance that the Skype server randomly being used might be involved.

Sure, happy to help however I can.

suurjaak commented 8 months ago

It took about 24 hours.

Ouch!

By requests, I mean queries to the Skype server; like retrieving a list of recent chats, retrieving a list of recent messages in a chat, retrieving information on a contact, etc. One request can return multiple messages, but a chat with many messages will need many requests, as the messages are returned in limited batches. When syncing a chat, Skyperious queries its recent messages until no more are returned, or it starts encountering messages already in the database.

Asking your chat partner to try the sync is not necessary, but would certainly be a useful data point here.

rpodric commented 8 months ago

I had him update to 5.5 and do a sync, which he hadn't done since January so there were about 10K messages in the main chat to download and several much smaller ones, including phone numbers.

It worked without incident, so there goes the theory that it relates purely to volume. It seems to be volume plus something else, whether it's the server being hit or whatever else.

suurjaak commented 3 months ago

Apologies for sitting on this issue so long.

The newly released Skyperious v5.6 has more rate-limiting on live sync which might help with your issue. It also exposes the various rate settings in the program options window (File -> Advanced options) - the ones starting with LiveSync like LiveSyncRateLimit.

Let me know if your issue still persists.

rpodric commented 3 months ago

No problem, thanks. I actually should have reported back before now, because after a while the problem subsided--without changing rate-limiting. Coupled with your never seeing the problem, this does suggest some kind of roving account-centric issue on the server side, much like certain Skype issues (like the inability to send messages suddenly) that strike certain accounts but not others before they vanish.

I see that the setting you mentioned in v5.6 is on 5, which is that ultra-slow one that you had me try before. Yet when I did a sync with v5.6 just now (no problems) it didn't seem that slow, though it was only about a week's worth as opposed to everything, so it was a little hard to tell. Is the 5 now the equivalent of the 5 that I tried in the last version? And for reference, what was it set to in the old version, if I wanted to experiment at that speed again?

suurjaak commented 3 months ago

Excellent, glad to hear the problem was temporary. Indeed it sounds like it was some account-specific limiting on the server side.

The setting at value 5, LiveSyncAuthRateLimitDelay, is not the same one I had you try (that one become LiveSyncRateWindow and retained its value of 2). LiveSyncAuthRateLimitDelay is a new setting I introduced, this one kicks in only when the server response explicitly says that there have been too many requests.