Bug 61848 - Exceeded rate limit not dealt with correctly
Summary: Exceeded rate limit not dealt with correctly
Status: RESOLVED FIXED
Alias: None
Product: kopete
Classification: Applications
Component: ICQ and AIM Plugins (show other bugs)
Version: unspecified
Platform: unspecified Linux
: NOR normal
Target Milestone: ---
Assignee: Matt Rogers
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2003-07-30 12:27 UTC by Till Gerken
Modified: 2003-10-17 07:39 UTC (History)
0 users

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Till Gerken 2003-07-30 12:27:48 UTC
Version:           0.6.90cvs >= 20030730 (using KDE 3.1.9)
Compiler:          gcc version 3.3.1 20030626 (Debian prerelease)
OS:          Linux (i686) release 2.4.20-pre11

When connecting to ICQ and getting a "rate limit exceeded" message, Oscar should stop the connection attempt and display a warning dialog. Right now it does not seem to stop the connection attempt.

Here is the debug output:

kopete (oscar): [void OscarConnection::slotConnected()] We are connected to ''
kopete (oscar): [void OscarSocket::OnBosConnect()] Connected to 205.188.12.40, port 5190
kopete (oscar): Bos server ack'ed us!  Sending auth cookie
kopete (oscar): [void OscarSocket::sendCookie()] SEND (CLI_COOKIE) Mhh, cookies, let's give one to the server
kopete (oscar): [void OscarSocket::parseServerReady(Buffer&)] RECV (SRV_FAMILIES), got list of families
kopete (oscar): [void OscarSocket::sendVersions(const WORD*, int)] SEND (CLI_FAMILIES)
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] RECV (SRV_RATE_LIMIT_WARN)
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] Rate limit hit (current level < limit level)
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] rate applies to classId 1
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] windowSize=80
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] clearLevel=2500
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] alertLevel=2000
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] limitLevel=1500
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] disconnectLevel=800
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] currentLevel=1124
kopete (oscar): [void OscarSocket::parseRateChange(Buffer&)] maxLevel=6000
kopete (oscar):  BUFFER ERROR: Buffer::getByte(): mBuf empty
kopete (oscar): Stopping reporting errors
Comment 1 Till Gerken 2003-07-30 12:37:14 UTC
There is another case where it correctly pops up a message saying that I most likely tried 
to reconnect to the server too fast and am now banned. In this case, the connecting 
animation does not stop and reconnecting is not possible until the next restart of Kopete. 
Not sure if these bugs are the same, but I will post the debug output here as well: 
 
kopete (oscar): [void OscarSocket::OnConnect()] Connected to login.icq.com, port 5190 
kopete (oscar): [void OscarSocket::OnConnect()] address() is 192.168.2.131 
mDirectIMMgr->address() is 192.168.2.131 
kopete (oscar): [void OscarSocket::OnConnAckReceived()] Called. 
kopete (oscar): [void OscarSocket::OnConnAckReceived()] ICQ-LOGIN, sending ICQ login 
kopete (oscar): [void OscarSocket::sendLoginICQ()] Sending ICQ login info... 
(CLI_COOKIE) 
kopete (oscar): [QCString OscarSocket::encodePasswordXOR()] 
kopete (oscar): [virtual void OscarSocket::slotRead()] Got connection close request, 
length=38 
kopete (oscar): contained TLVs: 
kopete (oscar): TLV(1) with length 6 
kopete (oscar): TLV(8) with length 2 
kopete (oscar): TLV(4) with length 18 
kopete (oscar): found TLV(1) [UIN], uin=389743 
kopete (oscar): [virtual void OscarSocket::slotRead()] found TLV(8) [ERROR] error= 24 
kopete (oscar): [virtual void OscarSocket::slotRead()] rate exceeded (maybe reconnecting 
too fast), server-ban for at least 10 mins!!! 
kopete (oscar): [void OscarAccount::slotError(QString, int)] accountId()='389743' 
errmsg=Server has blocked ICQ account 389743 for sending messages too quickly. Wait 
ten minutes and try again. If you continue to try, you will need to wait even longer., 
errorCode=0. 
kopete (oscar): [virtual void OscarSocket::doLogoff()] QSocket state wasn't idle, closing 
down socket... 
kopete (oscar): found TLV(4) [DESCRIPTION] reason=http://www.aol.com 
 
Comment 2 Matt Rogers 2003-09-24 22:03:50 UTC
The second comment is caused by the inital report, and occurs because the 
server actually sends us an error packet. I'm working on a horrible, terrible, 
hacky workaround for this (basically adding a sleep(1) when we're about 100 
points below the disconnect limit). Should have it in by the weekend.  I'll 
CCMAIL the bug report the commit and then you can try it out. 
Comment 3 Stefan Gehn 2003-09-24 22:20:40 UTC
replace that sleep by a bBlockSend variable and set that to false in a singleShot 
timer called after 100ms (or whatever time you prefer). 
Comment 4 Matt Rogers 2003-09-26 06:31:11 UTC
Subject: kdenetwork/kopete/protocols/oscar/oscarsocket

CVS commit by mattr: 

Fix for bug 61848 using a single shot timer that fires on current rate level
divided by 2 milliseconds.

CCMAIL: 61848-done@bugs.kde.org


  M +18 -1     oscarsocket.cpp   1.128
  M +8 -0      oscarsocket.h   1.78


--- kdenetwork/kopete/protocols/oscar/oscarsocket/oscarsocket.cpp  #1.127:1.128
@@ -57,4 +57,5 @@ OscarSocket::OscarSocket(const QString &
         mFileTransferMgr=0L;
         awaitingFirstPresenceBlock = OscarSocket::Waiting;
+        mBlockSend = false;
 
         socket()->enableWrite(false); // don't spam us with readyWrite() signals
@@ -120,4 +121,12 @@ DWORD OscarSocket::setIPv4Address(const 
 }
 
+void OscarSocket::slotToggleSend()
+{
+        if (mBlockSend)
+                mBlockSend = false;
+        else
+                mBlockSend = true;
+}
+
 void OscarSocket::slotConnected()
 {
@@ -566,5 +575,5 @@ void OscarSocket::sendBuf(Buffer &outbuf
 #endif
 
-        if(socket()->socketStatus() != KExtendedSocket::connected)
+        if(socket()->socketStatus() != KExtendedSocket::connected || mBlockSend)
                 kdDebug(14150) << k_funcinfo << "Socket is NOT open, can't write to it right now" << endl;
         else
@@ -2633,4 +2642,12 @@ void OscarSocket::parseRateChange(Buffer
         BYTE currentState = inbuf.getByte();
         kdDebug(14150) << k_funcinfo << "currentState=" << currentState << endl;
+
+        if (code == 0x0002) //we've been warned about exceeding the rate limit
+        {
+                slotToggleSend();
+                kdDebug(14150) << "Warning about the rate limit received. Waiting "
+                                                << currentLevel / 2 << "milliseconds" << endl;
+                QTimer::singleShot( currentLevel / 2, this, SLOT(slotToggleSend()));
+        }
 
 /*

--- kdenetwork/kopete/protocols/oscar/oscarsocket/oscarsocket.h  #1.77:1.78
@@ -842,4 +842,10 @@ class OscarSocket : public OscarConnecti
         void slotKeepaliveTimer();
 
+        /**
+         * Called by the singleshot timer that is set when we've reached
+         * the rate limit warning
+         */
+        void slotToggleSend();
+
         signals:
 
@@ -996,4 +1002,6 @@ class OscarSocket : public OscarConnecti
                 // Tells if we are connected to the server and ready to operate
                 bool isLoggedIn;
+                // Tells if we can send data to the server or not
+                bool mBlockSend;
 
                 /*


Comment 5 Till Gerken 2003-09-26 10:46:03 UTC
I tried exceeding the rate limit (go.icq.com is such a beautiful tool for that) 
and Kopete did not pop up a warning or anything, it simply kept spinning the 
flower while from the console it could clearly be seen that the server 
terminated the connection (it detected the rate limit, too). 
Comment 6 Stefan Gehn 2003-09-26 13:09:12 UTC
no really? Who would have guessed that, a bug that isn't marked as FIXED is still  
happening :P  
Comment 7 Stefan Gehn 2003-09-26 13:13:52 UTC
Also note that the patch from Matt does not fix this bug anyway, exceeding the 
rate does not mean sending slower makes it any better. 
 
1. The values of that rate-exceeded packet mean something but we don't know 
what they mean 
2. There are several limits, one means "send slower", but there's also the "I want 
you to disconnect now" limit 
Comment 8 Till Gerken 2003-09-26 13:50:26 UTC
According to the console output, the plugin actually notices that the server 
wants it to disconnect - I think the socket is even being closed. However, the 
plugin keeps sending data happily ever after. 
Comment 9 Matt Rogers 2003-09-26 17:53:12 UTC
hmm, the patch that I committed only did anything if we receieved a warning 
packet, so that's strike one. It also gobbled packets in the sending function 
beacuse instead of waiting for mBlockSend to be false, it just left the 
function, so that's strike two. No strike three yet, but i'm sure it'll be 
there when i put a better fix in later tonight or tomorrow.
Comment 10 Matt Rogers 2003-10-17 07:39:28 UTC
Subject: kdenetwork/kopete/protocols/oscar/oscarsocket

CVS commit by mattr: 

Fix bug 61848 by disconnecting when we've hit (or gone over) the disconnect
limit.  Also make the rate level detection slightly more intelligent and make
better use of it when determining how long we need to delay to keep from going
over the disconnect limit in the first place. 

CCMAIL: 61848-done@bugs.kde.org

(what a long message for such small changes)


  M +18 -6     oscarsocket.cpp   1.141


--- kdenetwork/kopete/protocols/oscar/oscarsocket/oscarsocket.cpp  #1.140:1.141
@@ -2812,10 +2812,22 @@ void OscarSocket::parseRateChange(Buffer
         kdDebug(14150) << "New Level is: " << newLevel << endl;
         
-        if (code == 0x0002) //we've been warned about exceeding the rate limit
+        if (currentLevel >= disconnectLevel)
+        {
+                emit protocolError(i18n("The account %1 will be disconnected for exceeding the rate limit." \
+                                        "Please wait approximately 10 minutes before reconnecting.")
+                                        .arg(mAccount->accountId()),0);
+
+                //let the account properly clean itself up
+                mAccount->disconnect();
+        }
+        else
+        {
+                if (code == 0x0002 || code == 0x0003)
         {
                 slotToggleSend();
                 kdDebug(14150) << "Warning about the rate limit received. Waiting "
-                                                << currentLevel / 2 << "milliseconds" << endl;
-                QTimer::singleShot( currentLevel / 2, this, SLOT(slotToggleSend()));
+                                                        << newLevel / 2 << "milliseconds" << endl;
+                        QTimer::singleShot( newLevel / 2, this, SLOT(slotToggleSend()));
+                }
         }