You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@trafficserver.apache.org by Shaun McGinnity <Sh...@owmobility.com> on 2012/07/30 19:13:25 UTC

Write failure from TSNetConnect

Hi,

I am using Traffic Server 3.2.0 on Redhat 6.3.

I am using TSNetConnect to create a 2-way communication channel to a separate process. I have noticed that eventually the write side of the channel will stop working although the read side still operates normally. I do not see any error or complete events raised to my continuation. I have checked that the return value from TSIOBufferWrite is as expected and I always re-enable the write continuation after each write.

A packet dump is shown below - client is port 45897, server is port 4868. This is taken after ~1 hour of traffic. Normal 2-way data exchange is observed until 17:13:42.461431 when data only comes from the server and TCP acks from the client. This continues until the connection is closed.

17:13:42.395642 IP myhost.4868 > myhost.45897: Flags [P.], seq 8300985:8301053, ack 3873523, win 11343, options [nop,nop,TS val 270071674 ecr 270071673], length 68
17:13:42.396175 IP myhost.45897 > myhost.4868: Flags [P.], seq 3873523:3873558, ack 8301053, win 265, options [nop,nop,TS val 270071674 ecr 270071674], length 35
17:13:42.396855 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301053:8301121, ack 3873558, win 11343, options [nop,nop,TS val 270071675 ecr 270071674], length 68
17:13:42.420982 IP myhost.45897 > myhost.4868: Flags [P.], seq 3873558:3873593, ack 8301121, win 265, options [nop,nop,TS val 270071699 ecr 270071675], length 35
17:13:42.421726 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301121:8301189, ack 3873593, win 11343, options [nop,nop,TS val 270071700 ecr 270071699], length 68
17:13:42.461431 IP myhost.45897 > myhost.4868: Flags [.], ack 8301189, win 265, options [nop,nop,TS val 270071740 ecr 270071700], length 0
17:13:46.375879 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301189:8301222, ack 3873593, win 11343, options [nop,nop,TS val 270075654 ecr 270071740], length 33
17:13:46.375900 IP myhost.45897 > myhost.4868: Flags [.], ack 8301222, win 265, options [nop,nop,TS val 270075654 ecr 270075654], length 0
17:13:46.380377 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301222:8301255, ack 3873593, win 11343, options [nop,nop,TS val 270075659 ecr 270075654], length 33
17:13:46.380395 IP myhost.45897 > myhost.4868: Flags [.], ack 8301255, win 265, options [nop,nop,TS val 270075659 ecr 270075659], length 0
17:13:46.382950 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301255:8301288, ack 3873593, win 11343, options [nop,nop,TS val 270075661 ecr 270075659], length 33
17:13:46.382975 IP myhost.45897 > myhost.4868: Flags [.], ack 8301288, win 265, options [nop,nop,TS val 270075661 ecr 270075661], length 0
17:13:46.385227 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301288:8301321, ack 3873593, win 11343, options [nop,nop,TS val 270075663 ecr 270075661], length 33
17:13:46.385247 IP myhost.45897 > myhost.4868: Flags [.], ack 8301321, win 265, options [nop,nop,TS val 270075663 ecr 270075663], length 0
17:13:46.387441 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301321:8301354, ack 3873593, win 11343, options [nop,nop,TS val 270075666 ecr 270075663], length 33
17:13:46.387459 IP myhost.45897 > myhost.4868: Flags [.], ack 8301354, win 265, options [nop,nop,TS val 270075666 ecr 270075666], length 0
17:13:46.389647 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301354:8301387, ack 3873593, win 11343, options [nop,nop,TS val 270075668 ecr 270075666], length 33
17:13:46.389665 IP myhost.45897 > myhost.4868: Flags [.], ack 8301387, win 265, options [nop,nop,TS val 270075668 ecr 270075668], length 0
17:13:46.391904 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301387:8301420, ack 3873593, win 11343, options [nop,nop,TS val 270075670 ecr 270075668], length 33
17:13:46.391927 IP myhost.45897 > myhost.4868: Flags [.], ack 8301420, win 265, options [nop,nop,TS val 270075670 ecr 270075670], length 0

I would appreciate any help to resolve this issue or any pointers to where I should start looking in the traffic server code.

Regards,

Shaun McGinnity

Re: Write failure from TSNetConnect

Posted by James Peach <jp...@apache.org>.
On 30/07/2012, at 10:13 AM, Shaun McGinnity <Sh...@owmobility.com> wrote:

> Hi,
> 
> I am using Traffic Server 3.2.0 on Redhat 6.3.
> 
> I am using TSNetConnect to create a 2-way communication channel to a separate process. I have noticed that eventually the write side of the channel will stop working although the read side still operates normally. I do not see any error or complete events raised to my continuation. I have checked that the return value from TSIOBufferWrite is as expected and I always re-enable the write continuation after each write.
> 
> A packet dump is shown below - client is port 45897, server is port 4868. This is taken after ~1 hour of traffic. Normal 2-way data exchange is observed until 17:13:42.461431 when data only comes from the server and TCP acks from the client. This continues until the connection is closed.
> 
> 17:13:42.395642 IP myhost.4868 > myhost.45897: Flags [P.], seq 8300985:8301053, ack 3873523, win 11343, options [nop,nop,TS val 270071674 ecr 270071673], length 68
> 17:13:42.396175 IP myhost.45897 > myhost.4868: Flags [P.], seq 3873523:3873558, ack 8301053, win 265, options [nop,nop,TS val 270071674 ecr 270071674], length 35
> 17:13:42.396855 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301053:8301121, ack 3873558, win 11343, options [nop,nop,TS val 270071675 ecr 270071674], length 68
> 17:13:42.420982 IP myhost.45897 > myhost.4868: Flags [P.], seq 3873558:3873593, ack 8301121, win 265, options [nop,nop,TS val 270071699 ecr 270071675], length 35
> 17:13:42.421726 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301121:8301189, ack 3873593, win 11343, options [nop,nop,TS val 270071700 ecr 270071699], length 68
> 17:13:42.461431 IP myhost.45897 > myhost.4868: Flags [.], ack 8301189, win 265, options [nop,nop,TS val 270071740 ecr 270071700], length 0
> 17:13:46.375879 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301189:8301222, ack 3873593, win 11343, options [nop,nop,TS val 270075654 ecr 270071740], length 33
> 17:13:46.375900 IP myhost.45897 > myhost.4868: Flags [.], ack 8301222, win 265, options [nop,nop,TS val 270075654 ecr 270075654], length 0
> 17:13:46.380377 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301222:8301255, ack 3873593, win 11343, options [nop,nop,TS val 270075659 ecr 270075654], length 33
> 17:13:46.380395 IP myhost.45897 > myhost.4868: Flags [.], ack 8301255, win 265, options [nop,nop,TS val 270075659 ecr 270075659], length 0
> 17:13:46.382950 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301255:8301288, ack 3873593, win 11343, options [nop,nop,TS val 270075661 ecr 270075659], length 33
> 17:13:46.382975 IP myhost.45897 > myhost.4868: Flags [.], ack 8301288, win 265, options [nop,nop,TS val 270075661 ecr 270075661], length 0
> 17:13:46.385227 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301288:8301321, ack 3873593, win 11343, options [nop,nop,TS val 270075663 ecr 270075661], length 33
> 17:13:46.385247 IP myhost.45897 > myhost.4868: Flags [.], ack 8301321, win 265, options [nop,nop,TS val 270075663 ecr 270075663], length 0
> 17:13:46.387441 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301321:8301354, ack 3873593, win 11343, options [nop,nop,TS val 270075666 ecr 270075663], length 33
> 17:13:46.387459 IP myhost.45897 > myhost.4868: Flags [.], ack 8301354, win 265, options [nop,nop,TS val 270075666 ecr 270075666], length 0
> 17:13:46.389647 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301354:8301387, ack 3873593, win 11343, options [nop,nop,TS val 270075668 ecr 270075666], length 33
> 17:13:46.389665 IP myhost.45897 > myhost.4868: Flags [.], ack 8301387, win 265, options [nop,nop,TS val 270075668 ecr 270075668], length 0
> 17:13:46.391904 IP myhost.4868 > myhost.45897: Flags [P.], seq 8301387:8301420, ack 3873593, win 11343, options [nop,nop,TS val 270075670 ecr 270075668], length 33
> 17:13:46.391927 IP myhost.45897 > myhost.4868: Flags [.], ack 8301420, win 265, options [nop,nop,TS val 270075670 ecr 270075670], length 0
> 
> I would appreciate any help to resolve this issue or any pointers to where I should start looking in the traffic server code.

Hi Sean,

There's really 2 ways you could approach this. The first is to start enabling debug tags; If you are luck the debug log output might give you a hint what is going on. I'd start with enabling all the tags and then trim it back until you have the useful set.

The second way is to try to reduce your plugin to the smallest reproducible case and file a bug at https://issues.apache.org/jira/browse/TS. If one of the ATS devs can reproduce, we should be able to knock up a fix for you. If you can post a binary packet trace, that's a lot easier to analyse than the text dump ...

cheers,
James

> 
> Regards,
> 
> Shaun McGinnity