Hi John,
quite good analysis...
John C. Turnbull wrote:
> Hi Jeanfrancois,
>
> OK, I have a lot of new information that hopefully will allow us to finally
> get to the bottom of this problem.
>
> After running packet sniffers on both the server and client and also by
> running the netstat command, I have determined the following things:
>
> (1) The exact period of idle time seems to be much more than 10 minutes and
> more like an hour although I cannot be certain if this is fixed or
> pseudo-random.
> (2) The server is definitely sending data to the IP address of the client
> machine before and after the idle time.
> (3) The client machine is receiving data from the server's IP address before
> and after the idle time, even though it is not actually getting into the
> applet.
> (4) The server is using the same DataOutputStream to write the data before
> and after the idle time.
> (5) Before the idle time, the connections on the client look like this:
>
> TCP 10.1.1.3:63457 1.2.3.4:ssh ESTABLISHED InHost
> TCP 10.1.1.3:63940 1.2.3.4:8080 ESTABLISHED InHost
>
> Where 1.2.3.4 is the mock address of the server machine. That looks fine
> but I don't know why there's an SSH connection in there (perhaps you could
> explain that).
No idea for ssh...
Anyway, note that the port in the connection to the server's
> 8080 port is 63940.
>
> (6) Immediately after the idle time, the connections on the client look like
> this:
>
> TCP 10.1.1.3:63940 1.2.3.4:8080 ESTABLISHED InHost
> TCP 10.1.1.3:64892 1.2.3.4:8080 FIN_WAIT_1 InHost
> TCP 10.1.1.3:64898 1.2.3.4:8080 FIN_WAIT_1 InHost
>
> Note that we still have the original connection but now we have 2 new
> connections in FIN_WAIT_1 state (whatever that means) on different ports.
That means two connections have been closed, and the file descriptor
(socket) will eventually disappear.
>
> (7) Wireshark reveals that the packets of data arriving on the client after
> the idle time are directed to port 63494 which is not the port of any of the
> above connections. This must be why the applet is not receiving them as it
> is still established on a connection on port 63490.
But that's strange, because NIO (not Grizzly) cannot change the remote
port of SocketChannel. That means the connection has probably been
closed on the client side and reopened (with a new port). What is
puzzling me is Grizzly will wakes when the connection on the client side
is closed, and call onTerminate().
>
> So there you have it. Everything is functioning correctly except that the
> data after the idle time appears to be sent to the wrong port. I can't find
> any other anomaly.
Looks like there is a timeout, maybe from the Applet or the browser, and
the connection gets re-openned, hit your Servlet again and comet gets
re-enabled on that connection (because you are seeing some push). Can
you grab what is exchanged between the client and the server? I think
that's the only way we can find something.
Thanks!
-- Jeanfrancois
>
> Any ideas why the destination port is changing after the idle time? Can you
> spot anything else?
>
> Thanks,
>
> John
>
>
>> -----Original Message-----
>> From: Jeanfrancois.Arcand_at_Sun.COM [mailto:Jeanfrancois.Arcand_at_Sun.COM]
>> Sent: Wednesday, 23 January 2008 05:17
>> To: users_at_grizzly.dev.java.net
>> Subject: Re: Comet data into the bit bucket
>>
>> Hi John,
>>
>> John C. Turnbull wrote:
>>> Hi Jeanfrancois,
>>>
>>> I have discovered that when the problem occurs, there is no interrupt
>>> detected so it would appear that the connection is still open (which
>>> correlates with the fact that there are no EOF exceptions at either
>> end).
>>
>> Just in case, are you inside a firewall or a proxy? Can it be the proxy
>> that close the connection (I suspect not).
>>
>>> Hmm, so where do I go from here? The connection remains open but no
>> data is
>>> getting through.
>> From your CometHandler, invoking the
>> HttpServletResponse.getWriter().write(...) succeed, right? I guess you
>> should install wireshark or ngrep to see if the bytes are sent
>> properly.
>> This way we will know if the client or server has problems.
>>
>> Thanks
>>
>> -- Jeanfrancois
>>
>>> Thanks,
>>>
>>> John
>>>
>>>> -----Original Message-----
>>>> From: Jeanfrancois.Arcand_at_Sun.COM
>> [mailto:Jeanfrancois.Arcand_at_Sun.COM]
>>>> Sent: Wednesday, 23 January 2008 03:37
>>>> To: users_at_grizzly.dev.java.net
>>>> Subject: Re: Comet data into the bit bucket
>>>>
>>>> Hi John,
>>>>
>>>> John C. Turnbull wrote:
>>>>> Hi Jeanfrancois,
>>>>>
>>>>> Thanks for your reply. Comments inline.
>>>>>
>>>>>>> I have Comet working nicely between servlets and applets except
>> for
>>>>>> one
>>>>>>> thing.
>>>>>> Great!
>>>>> [JCT] Yes, indeed. I am very happy with Grizzly Comet :-)
>>>>>
>>>>>> For some reason, if a connection is left idle for several
>>>>>>> minutes then the data sent from the servlet seems to disappear
>> into
>>>>>> the
>>>>>>> ether somewhere.
>>>>>> Do you know how long exactly?
>>>>> [JCT] Not exactly but it's about 10 minutes.
>>>>>
>>>>>> Do you have a test case I can take a look at? Do you know if the
>>>>>> connection is still active (are you handling the
>>>>>> onInterrupt/onTerminate
>>>>>> method of the CometHandler)?
>>>>> [JCT] It is difficult to provide a test case at this stage but I
>> can
>>>> say
>>>>> that I am not doing anything with onInterrupt or onTerminate yet as
>> I
>>>> am not
>>>>> sure how these methods should be used. Is there documentation for
>>>> Comet
>>>>> somewhere? I mean something that gives a general outline of how
>>>> everything
>>>>> hangs together? It's a bit hit-or-miss for me at the moment and I
>> am
>>>>> finding things out by experimentation.
>>>> That's the general problem with Grizzly...lack of documentations.
>> The
>>>> only place I talk about it is here:
>>>>
>>>>
>> http://weblogs.java.net/blog/jfarcand/archive/2006/07/the_grizzly_com.h
>>>> tml
>>>>
>> https://grizzly.dev.java.net/nonav/xref/com/sun/grizzly/comet/CometHand
>>>> ler.html
>>>>
>>>> which is far from perfect. Mainly, the onInterrupt will be called by
>>>> Grizzly when the client close the connection or when the timeout
>>>> expires. The onTerminate will be called when you invoke
>>>> CometContext.notify(CometEvent.TERMINATE);
>>>>
>>>>>>> Any ideas what's actually happening here and where the data is
>>>> going?
>>>>>> Difficult to say. Are they any exceptions in the log (I guess
>> not).
>>>> Do
>>>>>> you know if the bytes are sent over the network? A tool like
>>>> wireshark
>>>>>> or ngrep could help determining if the server or the client have
>>>>>> problem.
>>>>> [JCT] I haven't used a packet sniffer to analyse the network yet
>> but
>>>> I do
>>>>> know that the server "believes" that the data has been transmitted
>> as
>>>> the
>>>>> DataOutputStream#size() method is reporting an ever-increasing
>> number
>>>> of
>>>>> transmitted bytes as the data is written and there are no
>> exceptions.
>>>>> [JCT] So perhaps the problem has something to do with the fact that
>> I
>>>> am not
>>>>> properly handling the interrupt or terminate events in the
>>>> CometHandler but
>>>>> I still don't know where the data is ending up. When I get a
>> chance
>>>> I will
>>>>> do some sniffing around for packets and try to see exactly what is
>>>> going on.
>>>>> [JCT] But, as I said, this is the only outstanding issue I have
>> with
>>>> my
>>>>> usage of Comet.
>>>> OK let's work on that :-) First thing to try is to output some trace
>>>> inside the onInterrupt to see if that method gets invoked.
>>>>
>>>> Thanks!
>>>>
>>>> -- Jeanfrancois
>>>>
>>>>> Thanks,
>>>>>
>>>>> -JCT
>>>>>
>>>>> -------------------------------------------------------------------
>> --
>>>>> 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
>