Netty large messages not going through. INTEREST_CHANGED event thrown twice

0
votes

I have a server working on Netty. The client sends some handshake messages and the server replies. These are small messages and there is no issue with these.

However, when the server tries to send some large messages (each 131139 bytes in size), it seems like they are being been sent, the ChannelFuture's isSuccess() returns true and getCause() returns null. However, the client never gets the full message, only the first 4097 bytes of the first message. After 4 or 5 messages, netty stops trying to send new messages.

I am reading the channel's isWritable() before sending a message (it always returns true). The next message is attempted only when the operationComplete of the ChannelFutureListener is fired. After the message is written to the channel, the log shows the "INTEREST_CHANGED" event is thrown twice and the isWritable changes to false and then immediately to true. But the message never reaches the client.

 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 0
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: true
 INFO [New I/O worker #7] (HashSender.java:16) - Message Successfully sent. Channel isDone: true, success: true, cancelled: false, error: null
 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 1
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: false
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: true
 INFO [New I/O worker #7] (HashSender.java:16) - Message Successfully sent. Channel isDone: true, success: true, cancelled: false, error: null
 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 2
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: false
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: true
 INFO [New I/O worker #7] (HashSender.java:16) - Message Successfully sent. Channel isDone: true, success: true, cancelled: false, error: null
 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 3
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: false
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: true
 INFO [New I/O worker #7] (HashSender.java:16) - Message Successfully sent. Channel isDone: true, success: true, cancelled: false, error: null
 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 4
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: false
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: true
 INFO [New I/O worker #7] (HashSender.java:16) - Message Successfully sent. Channel isDone: true, success: true, cancelled: false, error: null
 INFO [New I/O worker #7] (HashSender.java:33) - Attempting send a message: 5
 INFO [New I/O worker #7] (HashSender.java:68) - Is channel writable: true
 INFO [New I/O worker #7] (FrameLengthPrepender.java:46) - outgoing packet lenght: 131139
 INFO [New I/O worker #7] (ClientHandler.java:32) - [id: 0xdbb48b90, /192.168.0.3:60105 => /192.168.0.4:25025] INTEREST_CHANGED
 INFO [New I/O worker #7] (ClientHandler.java:33) - Is channel writable: false

Can anyone please tell me why the messages are not going through?

Update: Its actually 4097 bytes of the first message. I didn't count the first 4 bytes that mark the packet length.

Update: If the outgoing packet length is less than or equal to 4097 bytes, everything works smoothly. Netty breaks only when the packets are larger than 4097 bytes. Its 4097, not 4096. Does it ring a bell?

1
javanetty
The channel interest change events are nothing to worry about. Netty 3.x maintains an internal write buffer with a high water mark for each channel. This represents the amount of data waiting to be flushed to operating system buffers. If the outstanding data exceeds this value then the channel is set to non-writable. The default value is 64K so your large message immediately triggers the channel interest change event. Netty then sets the channel to writable again once data has been flushed to the system buffers. I think the message is being sent. Can you provide details of the client? – johnstlr
The client is written in c++. Its a very mature code, and I am re-writing the server (which was originally blocking instead of asynchronous). I am pretty sure whenever large messages are sent, the client gets only the first 4093 bytes of the first message. – Tarandeep Gill
Update: Its actually 4097 bytes of the first message. I didn't count the first 4 bytes that mark the packet length. – Tarandeep Gill
I ran some more experiments, and found out that, if the outgoing packet length is less than or equal to 4097 bytes, everything works smoothly. Netty breaks only when the packets are larger than 4097 bytes. Its 4097, not 4096. Does it ring a bell? – Tarandeep Gill

1 Answers

1
votes

Ok, my bad. The problem was on the client side. There was an infinite loop on the thread reading the socket, so the incoming data was not being processed.