[squeak-dev] Weird Socket Timeouts

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

[squeak-dev] Weird Socket Timeouts

Jon Hylands

Hi everyone,

So, I've moved up to Squeak 3.10.2 (#7179). I'm still running the same VM
(3.10.6) on Windows XP.

I'm running into a weird delay issue with the new SocketStream class. I've
narrowed it down to Semaphore >> #waitTimeoutMSecs:

Here's the scenario: The client is sending 220 byte packets to the server,
about one every 50 ms. The server is basically buffering those, until the
4K buffer fills up. Looking at the stack, and with some logging, I can see
that it is pausing in Semaphore >> #waitTimeoutMSecs:. I hacked the caller
(Socket >> #waitForDataFor:ifClosed:ifTimedOut:) to pass something less
than 50 ms as the argument. In this case it passes 31.

I've added a couple log messages to the beginning and end of that method:

17154400 - entering Semaphore >> waitTimeoutMSecs: 31
17162095 - exiting Semaphore >> waitTimeoutMSecs:...

The method took 7695 ms to execute, which seems a little strange. That's
how long it took me to switch over to my client, and push the button to
start sending packets, and then send 15 or 20 packets.

Why isn't it timing out after 31 ms?

The context of this whole thing is calling a variant of SocketStream >>
#upTo: (one that doesn't wait for 100K of data). The packets are delimited
with a CR (13).

Am I using this wrong, or is there a problem here?

Thanks,
Jon

--------------------------------------------------------------
   Jon Hylands      [hidden email]      http://www.huv.com/jon

  Project: Micro Raptor (Small Biped Velociraptor Robot)
           http://www.huv.com/blog

Reply | Threaded
Open this post in threaded view
|

Re: [squeak-dev] Weird Socket Timeouts

Jon Hylands

Bump... Any help or suggestions out there for this?

On Wed, 17 Jun 2009 14:45:04 -0400, Jon Hylands <[hidden email]> wrote:

> Hi everyone,
>
> So, I've moved up to Squeak 3.10.2 (#7179). I'm still running the same VM
> (3.10.6) on Windows XP.
>
> I'm running into a weird delay issue with the new SocketStream class. I've
> narrowed it down to Semaphore >> #waitTimeoutMSecs:
>
> Here's the scenario: The client is sending 220 byte packets to the server,
> about one every 50 ms. The server is basically buffering those, until the
> 4K buffer fills up. Looking at the stack, and with some logging, I can see
> that it is pausing in Semaphore >> #waitTimeoutMSecs:. I hacked the caller
> (Socket >> #waitForDataFor:ifClosed:ifTimedOut:) to pass something less
> than 50 ms as the argument. In this case it passes 31.
>
> I've added a couple log messages to the beginning and end of that method:
>
> 17154400 - entering Semaphore >> waitTimeoutMSecs: 31
> 17162095 - exiting Semaphore >> waitTimeoutMSecs:...
>
> The method took 7695 ms to execute, which seems a little strange. That's
> how long it took me to switch over to my client, and push the button to
> start sending packets, and then send 15 or 20 packets.
>
> Why isn't it timing out after 31 ms?
>
> The context of this whole thing is calling a variant of SocketStream >>
> #upTo: (one that doesn't wait for 100K of data). The packets are delimited
> with a CR (13).
>
> Am I using this wrong, or is there a problem here?

--------------------------------------------------------------
   Jon Hylands      [hidden email]      http://www.huv.com/jon

  Project: Micro Raptor (Small Biped Velociraptor Robot)
           http://www.huv.com/blog

Reply | Threaded
Open this post in threaded view
|

Re: [squeak-dev] Weird Socket Timeouts

Jon Hylands
In reply to this post by Jon Hylands
On Wed, 17 Jun 2009 14:45:04 -0400, Jon Hylands <[hidden email]> wrote:

> The method took 7695 ms to execute, which seems a little strange. That's
> how long it took me to switch over to my client, and push the button to
> start sending packets, and then send 15 or 20 packets.
>
> Why isn't it timing out after 31 ms?
>
> The context of this whole thing is calling a variant of SocketStream >>
> #upTo: (one that doesn't wait for 100K of data). The packets are delimited
> with a CR (13).
>
> Am I using this wrong, or is there a problem here?

So, I found out what the problem is, with some greatly appreciated help
from Göran (who wrote this version of SocketStream). There were two issues.

First issue was a bug in the Delay code, which has been recorded in Mantis
a couple times in the past, but not harvested.

http://bugs.squeak.org/view.php?id=7060

Basically, the code to handle delays using an external semaphore was broken
in 3.9.

The second issue was something simpler - the class comment on SocketStream
says the following:

"SS can not be run unbuffered, since that seems unneeded. The option to
autoFlush is still available, with it set to true SocketStream (just like
OSS) will flush on its own on each nextPut:/nextPutAll:, otherwise flushing
it will have to be done manually but is done on close."

This is incorrect, as it turns out - what really happens when autoFlush is
set to true is that a flush is sent when the outgoing buffer is full,
which, as it turns out, is a 4KB buffer. So, this problem was actually on
the client side rather than the server side, and was easily fixed by using
nextPutAllFlush: instead of nextPutAll:

Thanks again to Göran for his help in this...

Later,
Jon

--------------------------------------------------------------
   Jon Hylands      [hidden email]      http://www.huv.com/jon

  Project: Micro Raptor (Small Biped Velociraptor Robot)
           http://www.huv.com/blog

Reply | Threaded
Open this post in threaded view
|

Re: [squeak-dev] Weird Socket Timeouts

Göran Krampe
Hi!

Jon Hylands wrote:

> "SS can not be run unbuffered, since that seems unneeded. The option to
> autoFlush is still available, with it set to true SocketStream (just like
> OSS) will flush on its own on each nextPut:/nextPutAll:, otherwise flushing
> it will have to be done manually but is done on close."
>
> This is incorrect, as it turns out - what really happens when autoFlush is
> set to true is that a flush is sent when the outgoing buffer is full,
> which, as it turns out, is a 4KB buffer. So, this problem was actually on
> the client side rather than the server side, and was easily fixed by using
> nextPutAllFlush: instead of nextPutAll:

Right, sorry for the confusion. We should fix so that it behaves like
the class comment says I think. I presume people either want it "super
auto" or "manual", not "almost auto" :)

> Thanks again to Göran for his help in this...

No problem!

regards, Göran