So I've added some logging into the messageSent and it's quite interesting
although not terrible helpful. For on the messageSent event isn't fired on
the first packet sent till after I've received the response from the client
to it.

15:00:21.130 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
CREATED
15:00:21.213 [NioProcessor-1] INFO  c.s.m.p.s.MyEncoder - Sending: [10, 53,
46, 53, 46, 50, 45, 109, 50, 0, 0, 0, 0, 0, 112, 119, 112, 119, 112, 119,
112, 119, 0, 1, 130, 33, 0, 0, 8, 0, 12, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 112,
119, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 109, 121, 115, 113,
108, 95, 100, 117, 109, 109, 121, 95, 112, 108, 117, 103, 105, 110, 0]
15:00:21.216 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
OPENED
15:00:21.220 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
SENT: HeapBuffer[pos=0 lim=76 cap=128: 48 00 00 00 0A 35 2E 35 2E 32 2D 6D
32 00 00 00...]
15:00:21.223 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
RECEIVED: HeapBuffer[pos=0 lim=66 cap=2048: 3E 00 00 01 85 A6 7F 00 00 00
00 01 04 00 00 00...]
15:00:21.224 [NioProcessor-1] DEBUG o.a.m.f.codec.ProtocolCodecFilter -
Processing a MESSAGE_RECEIVED for session 1
15:00:21.236 [NioProcessor-1] DEBUG c.s.m.p.s.MyDecoder - Decoding packet 1
with length 62
15:00:21.236 [NioProcessor-1] DEBUG c.s.m.p.s.MyHandler - Packet recieved
15:00:21.236 [NioProcessor-1] DEBUG c.s.m.p.s.MyHandler - Handshake response
15:00:29.893 [NioProcessor-1] DEBUG c.s.m.p.s.MyHandler - Send request
15:00:29.895 [NioProcessor-1] INFO  c.s.m.p.s.MyEncoder - Sending: [254,
109, 121, 115, 113, 108, 95, 110, 97, 116, 105, 118, 101, 95, 112, 97, 115,
115, 119, 111, 114, 100, 0, 112, 119, 112, 119, 112, 119, 112, 119, 112,
119, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 0]
15:00:29.895 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
SENT: HeapBuffer[pos=0 lim=0 cap=0: empty]
15:00:29.896 [NioProcessor-1] DEBUG c.s.m.p.s.MyHandler - Message sent:
[10, 53, 46, 53, 46, 50, 45, 109, 50, 0, 0, 0, 0, 0, 112, 119, 112, 119,
112, 119, 112, 119, 0, 1, 130, 33, 0, 0, 8, 0, 12, 0, 0, 0, 0, 0, 0, 0, 0,
0, 0, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 109, 121,
115, 113, 108, 95, 100, 117, 109, 109, 121, 95, 112, 108, 117, 103, 105,
110, 0]
15:00:29.897 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
SENT: HeapBuffer[pos=0 lim=48 cap=64: 2C 00 00 00 FE 6D 79 73 71 6C 5F 6E
61 74 69 76...]
15:00:29.898 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
SENT: HeapBuffer[pos=0 lim=0 cap=0: empty]
15:00:29.898 [NioProcessor-1] DEBUG c.s.m.p.s.MyHandler - Message sent:
[254, 109, 121, 115, 113, 108, 95, 110, 97, 116, 105, 118, 101, 95, 112,
97, 115, 115, 119, 111, 114, 100, 0, 112, 119, 112, 119, 112, 119, 112,
119, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 112, 119, 0]
15:00:29.900 [NioProcessor-1] INFO  o.a.m.filter.logging.LoggingFilter -
CLOSED

Sorry I can't show any more code than in the original message (although I
think I have everything Mina related there) as it's confidential.

Jennifer


On 3 April 2013 20:58, Emmanuel Lécharny <[email protected]> wrote:

> Le 4/3/13 9:50 PM, Jennifer Cumming a écrit :
> > The client is reporting an error that implies the server either closed
> the
> > connection or timed out. As I can see the packet being written in the
> > logging filter well before the timeout expires
> Are you receiving a messageSent event ? If not, that means the message
> has not been sent to the client (this event is generated when the full
> message has been written into the socket).
>
> > coupled with the closed log
> > message I have to assume it's the server closing the connection. I can't
> > really see what's going on in the internals of the client as it's 3rd
> party
> > so all I have are the error codes.
> At this point, you should first verify that the data exchanged between
> your server and the client are what you expect them to be. You can use
> Wireshark for that.
>
> On my side, it's rather difficult to tell you what can be wrong without
> seing the code...
> >
> >
> > On 3 April 2013 17:34, Emmanuel Lécharny <[email protected]> wrote:
> >
> >> Le 4/3/13 6:02 PM, Jennifer Cumming a écrit :
> >>> Added and nothing. exceptionCaught is not getting called. Even tried
> >>> putting a breakpoint in and debugging and it's not getting hit.
> >> Ok, at least, that says it's not an exception...
> >>
> >> Isn't it possible that your client closes the connection ?
> >>
> >> Btw, you should set the TcpNoDelay to true, unless you are sending a lot
> >> of data.
> >>
> >> --
> >> Regards,
> >> Cordialement,
> >> Emmanuel Lécharny
> >> www.iktek.com
> >>
> >>
>
>
> --
> Regards,
> Cordialement,
> Emmanuel Lécharny
> www.iktek.com
>
>

Reply via email to