users@grizzly.java.net

Re: Problems with pipelining requests

From: Jeanfrancois Arcand <Jeanfrancois.Arcand_at_Sun.COM>
Date: Tue, 16 Dec 2008 18:21:31 -0500

Can you sent the entire log? I need to see why some requests gets cancelled.

A+

Patrick Julien wrote:
> So now I have the number of read bytes. I'm posting some details here
> but still need to look at this to get a better understanding of what
> it's telling me:
>
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=151
> lim=151 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.657-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=151
> lim=151 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.657-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=151
> lim=151 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.657-0600|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;|Regis
> tering SocketChannel for keep alive
> java.nio.channels.SocketChannel[connected local=/98.129.48.81:8080
> remote=/70.81.117.210:55112]|#]
>
> [#|2008-12-16T17:18:23.682-0600|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=16;_ThreadName=SelectorThread-8080;|Handling
> OP_
> READ on SocketChannel java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112]|#]
>
> [#|2008-12-16T17:18:23.683-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> Preparing to read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer
> [pos=0 lim=4096 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.683-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> SocketState: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] bytesAvailable
> false|#]
>
> [#|2008-12-16T17:18:23.684-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=135
> 9 lim=4096 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.684-0600|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|Socke
> tChannel request linejava.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] is: R(
> /symposium/resources/micro
> BlogEntryEntities/165/)|#]
>
> [#|2008-12-16T17:18:23.685-0600|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|Socke
> tChannel headersjava.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] are: ===
> MimeHeaders ===
> host = services00.spectrumdt.com:8080
> user-agent = Mobile
> accept = application/json
> |#]
>
> [#|2008-12-16T17:18:23.705-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=135
> 9 lim=1359 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.706-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=135
> 9 lim=1359 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.706-0600|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|
> Have read using: java.nio.channels.SocketChannel[connected
> local=/98.129.48.81:8080 remote=/70.81.117.210:55112] using
> java.nio.HeapByteBuffer[pos=135
> 9 lim=1359 cap=4096]|#]
>
> [#|2008-12-16T17:18:23.707-0600|INFO|sun-appserver9.1|javax.enterprise.system.container.web|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;|Regis
> tering SocketChannel for keep alive
> java.nio.channels.SocketChannel[connected local=/98.129.48.81:8080
> remote=/70.81.117.210:55112]|#]
>
>
>
> On Tue, Dec 16, 2008 at 6:12 PM, Jeanfrancois Arcand
> <Jeanfrancois.Arcand_at_sun.com> wrote:
>> Hum....try that one (patch 4).
>>
>> Patrick Julien wrote:
>>> patch3 only contains the MAnIfest-INF directory :)
>>>
>>> On Tue, Dec 16, 2008 at 6:08 PM, Patrick Julien <pjulien_at_gmail.com> wrote:
>>>> yes
>>>>
>>>> On Tue, Dec 16, 2008 at 6:07 PM, Jeanfrancois Arcand
>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>> Patrick Julien wrote:
>>>>>> you're sure about this installation procedure? I don't have to remove
>>>>>> the jar (appserv-rt) file once it's unzipped?
>>>>> No you unzip the patch, and add its content to the appserv-rt.jar. Is
>>>>> that
>>>>> what you are doing?
>>>>>
>>>>>> On Tue, Dec 16, 2008 at 6:02 PM, Patrick Julien <pjulien_at_gmail.com>
>>>>>> wrote:
>>>>>>> Yes, Glassfish. No comet.
>>>>>>>
>>>>>>> On Tue, Dec 16, 2008 at 5:19 PM, Jeanfrancois Arcand
>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>> Hum that strange as I added read logs. Another try, hopefully that
>>>>>>>> one
>>>>>>>> works. You are using GF as it is right? No Comet?
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> Patrick Julien wrote:
>>>>>>>>> Even with this drop, I do not see any bytes being printed in the
>>>>>>>>> log.
>>>>>>>>>
>>>>>>>>> On Tue, Dec 16, 2008 at 2:24 PM, Jeanfrancois Arcand
>>>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>>>> Oups again.
>>>>>>>>>>
>>>>>>>>>> Patrick Julien wrote:
>>>>>>>>>>> This does not seem to be printing out bytes, you sure I have the
>>>>>>>>>>> right
>>>>>>>>>>> package? Or did the procedure change from the first one?
>>>>>>>>>>>
>>>>>>>>>>> On Tue, Dec 16, 2008 at 1:54 PM, Jeanfrancois Arcand
>>>>>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>>>>>> Salut,
>>>>>>>>>>>>
>>>>>>>>>>>> Patrick Julien wrote:
>>>>>>>>>>>>> OK, so here's the log, what's interesting here is that I can see
>>>>>>>>>>>>> that
>>>>>>>>>>>>> there is an attempt to handle an OP_READ but that is followed
>>>>>>>>>>>>> immediately by a socket close on the server.
>>>>>>>>>>>> Looks like there was no bytes available to read. I'm attaching a
>>>>>>>>>>>> new
>>>>>>>>>>>> patch
>>>>>>>>>>>> which will display the bytes read. maybe the client has trouble
>>>>>>>>>>>> sending
>>>>>>>>>>>> more
>>>>>>>>>>>> data?
>>>>>>>>>>>>
>>>>>>>>>>>> A+
>>>>>>>>>>>>
>>>>>>>>>>>> -- jeanfrancoois
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>> On Tue, Dec 16, 2008 at 11:56 AM, Jeanfrancois Arcand
>>>>>>>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>>>>>>>> My bad. Proper patch attached.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> -- Jeanfrancois
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Patrick Julien wrote:
>>>>>>>>>>>>>>> You sure about these instructions? This jar file only
>>>>>>>>>>>>>>> contains a
>>>>>>>>>>>>>>> META-INF directory.
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> On Tue, Dec 16, 2008 at 11:10 AM, Jeanfrancois Arcand
>>>>>>>>>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>>>>>>>>>> Salut,
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> I'm attaching the patch which add more logging (let's start
>>>>>>>>>>>>>>>> with
>>>>>>>>>>>>>>>> that
>>>>>>>>>>>>>>>> one).
>>>>>>>>>>>>>>>> Just do:
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> % cd ${glassfish.home}/lib
>>>>>>>>>>>>>>>> % unzip grizzly-1.0...
>>>>>>>>>>>>>>>> % cp appserv-rt.jar appserv-rt.jar.org
>>>>>>>>>>>>>>>> % jar uvf appserv-rt.jar com
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> restart and execute your test.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> A+
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> -- Jeanfrancois
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Jeanfrancois Arcand wrote:
>>>>>>>>>>>>>>>>> Salut,
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> Patrick Julien wrote:
>>>>>>>>>>>>>>>>>> On Mon, Dec 15, 2008 at 3:32 PM, Jeanfrancois Arcand
>>>>>>>>>>>>>>>>>> <Jeanfrancois.Arcand_at_sun.com> wrote:
>>>>>>>>>>>>>>>>>>> Patrick Julien wrote:
>>>>>>>>>>>>>>>>>>>>>> Add
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>> -Dcom.sun.enterprise.web.connector.grizzly.snoopEnabled=true
>>>>>>>>>>>>>>>>>>>>>> and
>>>>>>>>>>>>>>>>>>>>>> send
>>>>>>>>>>>>>>>>>>>>>> the log here. But I doubt you will find http pipelining
>>>>>>>>>>>>>>>>>>>>>> support
>>>>>>>>>>>>>>>>>>>>>> with
>>>>>>>>>>>>>>>>>>>>>> Tomcat
>>>>>>>>>>>>>>>>>>>>>> (the parser code here is from them)...I think Jetty
>>>>>>>>>>>>>>>>>>>>>> might
>>>>>>>>>>>>>>>>>>>>>> work,
>>>>>>>>>>>>>>>>>>>>>> but
>>>>>>>>>>>>>>>>>>>>>> I'm
>>>>>>>>>>>>>>>>>>>>>> clearly not sure....
>>>>>>>>>>>>>>>>>>>> Wait a minute, that doesn't compute for me. Both
>>>>>>>>>>>>>>>>>>>> glassfish
>>>>>>>>>>>>>>>>>>>> and
>>>>>>>>>>>>>>>>>>>> Tomcat
>>>>>>>>>>>>>>>>>>>> documentation refer to pipelining via the
>>>>>>>>>>>>>>>>>>>> "maxKeepAliveRequests"
>>>>>>>>>>>>>>>>>>>> property.
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> You can see it in the documentation of Tomcat here:
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> http://tomcat.apache.org/tomcat-6.0-doc/config/http.html
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> and for glassfish, here:
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> http://docs.sun.com/app/docs/doc/820-4507/abhco?a=view
>>>>>>>>>>>>>>>>>>> OK...http pipelining is not what I means :-) Http
>>>>>>>>>>>>>>>>>>> pipelining
>>>>>>>>>>>>>>>>>>> usually
>>>>>>>>>>>>>>>>>>> refer
>>>>>>>>>>>>>>>>>>> to the ability to sent multiple requests without waiting
>>>>>>>>>>>>>>>>>>> for
>>>>>>>>>>>>>>>>>>> the
>>>>>>>>>>>>>>>>>>> response.
>>>>>>>>>>>>>>>>>>> So you can send R1,R2,R3 in one chunk and then wait for un
>>>>>>>>>>>>>>>>>>> ordered
>>>>>>>>>>>>>>>>>>> response.
>>>>>>>>>>>>>>>>>>> I was under the impression you were talking about that
>>>>>>>>>>>>>>>>>>> behavior.
>>>>>>>>>>>>>>>>>> Yes, this is what I am talking about. Send 10 requests,
>>>>>>>>>>>>>>>>>> then
>>>>>>>>>>>>>>>>>> start
>>>>>>>>>>>>>>>>>> accepting responses.
>>>>>>>>>>>>>>>>> OK then the links are not related.
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> What you mean here based on the above link is the maximum
>>>>>>>>>>>>>>>>>>> number
>>>>>>>>>>>>>>>>>>> of
>>>>>>>>>>>>>>>>>>> requests
>>>>>>>>>>>>>>>>>>> a client can do on an open connection. The client does R1,
>>>>>>>>>>>>>>>>>>> wait
>>>>>>>>>>>>>>>>>>> for
>>>>>>>>>>>>>>>>>>> Res1,
>>>>>>>>>>>>>>>>>>> then Req2, wait for Req2, etc.
>>>>>>>>>>>>>>>>>> No, I really mean sending multiple requests and getting
>>>>>>>>>>>>>>>>>> back
>>>>>>>>>>>>>>>>>> responses
>>>>>>>>>>>>>>>>>> in one shot, if the documentation provided here means
>>>>>>>>>>>>>>>>>> something
>>>>>>>>>>>>>>>>>> different, than it most certainly fooled me.
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> Now I understand your issue. I think your request is
>>>>>>>>>>>>>>>>>>> invalid
>>>>>>>>>>>>>>>>>>> and
>>>>>>>>>>>>>>>>>>> Grizzly
>>>>>>>>>>>>>>>>>>> is
>>>>>>>>>>>>>>>>>>> waiting for more bytes. Is the snippet you wrote
>>>>>>>>>>>>>>>>>>> previously
>>>>>>>>>>>>>>>>>>> contains
>>>>>>>>>>>>>>>>>>> the
>>>>>>>>>>>>>>>>>>> entire request? I will try to reproduce the issue using
>>>>>>>>>>>>>>>>>>> that
>>>>>>>>>>>>>>>>>>> one
>>>>>>>>>>>>>>>>>>> and
>>>>>>>>>>>>>>>>>>> telnet.
>>>>>>>>>>>>>>>>>> No, as I said before, I am getting 2 to 4 responses then
>>>>>>>>>>>>>>>>>> nothing
>>>>>>>>>>>>>>>>>> from
>>>>>>>>>>>>>>>>>> the 10 requests. Just a long blocking read followed by a
>>>>>>>>>>>>>>>>>> disconnect.
>>>>>>>>>>>>>>>>> Ok let me instrument a patch for you to see what happening.
>>>>>>>>>>>>>>>>> I
>>>>>>>>>>>>>>>>> hope
>>>>>>>>>>>>>>>>> I
>>>>>>>>>>>>>>>>> don't
>>>>>>>>>>>>>>>>> have to drive to see the problem live (at least not today as
>>>>>>>>>>>>>>>>> I
>>>>>>>>>>>>>>>>> will
>>>>>>>>>>>>>>>>> need
>>>>>>>>>>>>>>>>> a
>>>>>>>>>>>>>>>>> boat :-)). Gives me 1 hour or so.
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> A+
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> -- Jeanfrancois
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> A+
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> -- jeanfrancois
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>>>>>>>>> To unsubscribe, e-mail:
>>>>>>>>>>>>>>>>>>>> users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>>>>> For additional commands, e-mail:
>>>>>>>>>>>>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>>>>>>>> To unsubscribe, e-mail:
>>>>>>>>>>>>>>>>>>> users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>>>> For additional commands, e-mail:
>>>>>>>>>>>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>>>>>> To unsubscribe, e-mail:
>>>>>>>>>>>>>>>>> users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>> For additional commands, e-mail:
>>>>>>>>>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>>>>> To unsubscribe, e-mail:
>>>>>>>>>>>>>>>> users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>> For additional commands, e-mail:
>>>>>>>>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>>> For additional commands, e-mail:
>>>>>>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> ------------------------------------------------------------------------
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>
>>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>>>>>
>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>>>
>>>>>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>
>>>>>>> --
>>>>>>> http://www.spectrumdt.com
>>>>>>> http://codepimps.org
>>>>>>>
>>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>
>>>>>
>>>>
>>>> --
>>>> http://www.spectrumdt.com
>>>> http://codepimps.org
>>>>
>>>
>>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>
>
>
>