A potentially serious bug in KIO/kio_http and a possible patch ??

[Dawit A]

On Sunday, July 18, 2010 12:01:37 Maksim Orlovich wrote:
> You're right. Sorry. Should have looked at the entire context.
> 
> Anyway, this is definitely the sensible thing to do for 4.5; messing
> about with KIO::Connection and the like is way too risky.

Right... Specially when the current fix comes with added benefit of a small 
performance improvement (less signal emission)...

> Speaking of that... You mentioned it ended in ::send --- did it take
> the sendnow path, or the whole outgoingRequests queue?

Yes, it does. I actually discovered that KIO::Connection is also okay. For 
some unknown reason, the data seems to get lost once KIO::Connection sends it 
to the socket. Perhaps a recent change in Qt or KDE's socket classes is to 
blame ?? No idea... but I can tell you that Gmail chat used to work fine with 
kwebkitpart at some point in the recent past. If I can only recall with what 
versions of Qt and KDE, it would make this much easier I guess...

> That second bit looks really iffy to me, but I am not sure I am not just
> scapegoating it.

That is what I thought at first as well. However, that is not the problem at 
all. In fact, I added debug statements to specifically see if that was the 
problem and I did not see that code path, where the queuing is done, being hit 
hit even once during my tests ; so it is safe to say that is not the issue in 
this case.

> Anyway, it would be good if you could send me a bit more
> info on what the request looks like, as I would like to debug the lower-
> level KIO bits (who knows what else they might be messing up?)

I have attached a scrubbed version (with cookies removed) of the request debug 
statements for the that causes the Gmail chat failure. As you can see it is a 
simple GET request for checking the Gmail chat status (enabled/disabled) from 
the server. The 20 byte data returned by the server is the follows:

["b","chatenabled"]

That is it. Without my patch kio_http sends the returned response in a 3 (["b) 
and 17 byte ("chatenabled"]) message to the client. From the attached debug 
statement you can clearly see that the first 3 bytes makes it all the way up to 
the client where as every message succeeding it does not and hence the bug...

To make it easier for you, I have listed the meanings of the COMMAND codes 
printed out in the attached debug output:

COMMAND 10:		INF_TOTAL_SIZE
COMMAND 11:		INF_PROCESSED_SIZE
COMMAND 21:		INF_MIME_TYPE
COMMAND 26:		INF_INFOMESSAGE
COMMAND 27:		INF_META_DATA

COMMAND 100:		MSG_DATA
COMMAND 104:		MSG_FINISHED

> As for gmail chat inside khtml, it seems to need improvements in
> npruntime support in nspluginviewer/KParts::ScriptableExtension in
> khtml due to the Flash bits; I can't be 100% sure of whether it's the
> real cause or not, but I have to do that stuff anyway.

For me gmail with khtml does not get past the "Loading <email-address>" status 
message. After that is shown, I always get a blank page regardless of what 
user-agent string I use. I thought the flash bits are used only when you have 
chat sounds and advanced attachment features enabled ??

Anyhow, I will go ahead and commit my patch...

Regards,
Dawit A.

> On 7/17/10, Dawit A <adawit at kde.org> wrote:
> > On Saturday, July 17, 2010 12:19:31 Maksim Orlovich wrote:
> >> This patch looks wrong to me, as even in the limited case, you could
> >> potentially have the data that's already buffered fulfill the request
> >> entirely, can you not?
> > 
> > Nope and that is because in the limited case you already know the total
> > size of the content you are downloading ; so you actually know there is
> > still content left out there and readBuffered will do the right thing
> > and send the total bytes read in that case. I also made sure the patch
> > does not cause regression by checking if BR# 180631 works as before and
> > it does...
> > 
> > The issue that caused the bug (180631) which you provided a fix for is a
> > chunked transfer where you cannot not really know you have gotten the
> > whole data until you receive EOF from the socket. To be frank, the patch
> > is actually
> > a small performance improvement fix and not the actual bug fix for the
> > Gmail chat issue. The actual bug that causes that issue is somewhere in
> > the KIO::Connection class ; the point which the second portion of the
> > send data message never makes past. IOW, I actually discovered what
> > readBuffered does by
> > accident while hunting for the source of the chat issue...
> > 
> >> Will look at other stuff later in the evening... Though I must say I
> >> am impressed you could trace down anything gmail-related to such a low
> >> level.
> > 
> > Believe me it was not by choice and if I did not have the source code to
> > add a
> > lot of debug statements and see what is happening, I would never ever
> > have attempted this... Plus, I use Gmail chat  on occasions and nothing
> > is more motivating than when something you use breaks, right ;)
> > 
> > P.S. The patch I sent in the first email was incorrect. Make sure you try
> > the
> > second one I sent...
> > 
> > Regards,
> > Dawit A.
> > 
> >> On 7/17/10, Dawit A <adawit at kde.org> wrote:
> >> > Hi,
> >> > 
> >> > The attached patch makes it possible for HTTPProtocol::readBuffered
> >> > function to
> >> > behaves differently when called from readLimited. This patch is
> >> > intended to address the issue of the Gmail chat functionality no
> >> > longer working in kdewebkit based browsers.
> >> > 
> >> > Though the patch fully addresses the aforementioned bug, it really
> >> > does not fix
> >> > the actual cause of this bug. So what is the actual cause ?  Well when
> >> > you log
> >> > in to Gmail, a check is preformed to see if the chat functionality is
> >> > enabled
> >> > or not.  This is done through a simple GET request that returns a 20
> >> > byte
> >> > response. At that point kio_http has read the header and few bytes of
> >> > the
> >> > content as well, 3 bytes to be exact. kio_http stores these few bytes
> >> > of data
> >> > that are not part of the header in a buffer.
> >> > 
> >> > It then attempts to read the content and that is where the fun
> >> > starts... Because kio_http has received the actual size of the
> >> > content it is supposed to
> >> > read, it will use readLimited to get the content. readLimited in turn
> >> > calls readBuffered which, as a result of a fix for bug 180631, always
> >> > sends whatever
> >> > data was read ahead while retrieving the header above. This means the
> >> > 3 bytes
> >> > above will be sent to the client first in our case. After that
> >> > kio_http retrieves and attempts to send the remaining 17 bytes.
> >> > However, this last
> >> > portion never ever makes it to the client application. It seems to
> >> > disappear into the ether! Actually it never gets past
> >> > KIO::Connection::send and at this
> >> > point I cannot figure out why!
> >> > 
> >> > So why this patch then ?  Simple. If you followed what I attempted to
> >> > explain
> >> > above, you would see that it is very inefficient for kio_http to split
> >> > a 20 byte
> >> > data especially when it already knows the final size of the content it
> >> > is
> >> > supposed to retrieve from the server ; so addressing that through this
> >> > patch should be no brainer. The fact that the Gmail chat issue gets
> >> > fixed as a result
> >> > is only a bonus at this point.
> >> > 
> >> > And hence my request...
> >> > 
> >> > #1. Can someone using KHTML verify whether or not the Gmail chat
> >> > functionality
> >> > works for them ? I cannot get Gmail to work with KHTML here ; so I am
> >> > unable to do this myself.
> >> > 
> >> > #2. Can someone tell me if there is a scenario where sending two
> >> > MSG_DATA
> >> > requests in rapid succession might result in one of them being dropped
> >> > ?
> >> > 
> >> > #3. Any objections, concerns, suggestions etc about the patch are
> >> > welcome.
> >> > 
> >> > Regards,
> >> > Dawit A.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kio_gmail_chat_issue_debug_info.log
Type: text/x-log
Size: 10958 bytes
Desc: not available
URL: <http://mail.kde.org/pipermail/kde-core-devel/attachments/20100719/73f7fcf1/attachment.bin>