Experiencing a reproduceable deadlock/race condition between GDCAsyncSocket client & EventMachine server. Is my protocol / expectation naive?

[Mike Laurence]

Hello everyone,

My team has been experiencing a very puzzling networking issue but
tonight we finally narrowed it down. Our project is an MMO, so we send
a decent amount of data from server to client (1k+ per second), and
just a little from client to server. After connection, within one to
five minutes, the server outbound buffer piles up and the client's
incoming buffer piles up. The client can no longer effectively receive
data, but the server still receives it fine.

However, this problem disappears (at least after a dozen times
testing) when I NSLog some debug info in the socket read method. It's
almost as if the act of logging, which introduces a miniscule delay in
between each socket read method, allows the client to catch up,
whereas if it's left out it can't ever catch up.

Also strange is that we can't reproduce this problem when only one
connection is active on the server, but when a second or third person
connects they often experience it.

Here is my socket read method. The "debugNetwork" flag, when enabled,
is what runs NSLog and thus "saves" us from this issue.

==========================================================

- (void) socket:(GCDAsyncSocket*)sock didReadData:(NSData*)data
withTag:(long)tag {
if (debugNetwork)
NSLog(@"Socket read data with tag: %ld and length: %lu", tag,
data.length);

switch (tag) {
case 0:
messageIdent = *(const UInt8*)[data bytes];
[sock readDataToLength:4 withTimeout:-1 tag:1];
break;
case 1: {
UInt32 len = *(const UInt32*)[data bytes];
if (len > 0) {
[sock readDataToLength:len withTimeout:-1 tag:2];
}
else
NSLog(@"CRITICAL ERROR: Invalid message length %u", len);
break;
}
case 2: {
if (debugNetwork)
NSLog(@"Read message with length: %lu", [data length]);
[self parseMessage:messageIdent data:data];

// Prepare to read next message ident packet (start over at tag
0)
[sock readDataToLength:1 withTimeout:-1 tag:0];
break;
}
default:
NSLog(@"CRITICAL ERROR: Invalid socket tag %ld", tag);
break;
}
}

========================================

The protocol is:
- Receives one byte which identifies the message ID
- Receive 4 bytes which represent an integer which is the length of
the message [len]
- Receive [len] bytes and parse the message

Some of our messages are large-ish, as big as 6k, however EventMachine
is supposed to break that up under the hood (I think).

Any insight would be *greatly, greatly* appreciated. This issue has
been a humungous thorn in our sides, and we really need to get this
stuff working for the upcoming GDC conference :-D

Regards,
Mike Laurence