closing tcp socket

[Arash Abghari]

Hi Arsen,

I have a problem and I am not sure where the problem is either in the server side or client side. I am sending SIP packets over TCP not UDP using a Dialogic client to the UniMRCP server. Assume that the source port (client side) is 8062 and destination port (server side) is 8060. I establish a session, send some requests like DIFINE-GRAMMAR and RECOGNIZE and at last a BYE. Upon receiving the 200 OK, I close the tcp socket and exit the client application, but server is still running. Now the problem is I am not able to establish a new session using the same src port (8062). I have to restart the server then I am able to establish a session. It seems that server has not yet released the socket. I tracked it down by using a sniffer. When the client close the socket, it sends a FIN-ACK packet to the server and server responds with only an ACK which I believe it should have responded with a FIN-ACK not an ACK. What do you think? is it a bug or I am doing something wrong?

Thanks,

Arash

[Arsen Chaloyan]

Hi Arash,

If I understand you right, you have both SIP and MRCPv2 connections over TCP. The issue you observed relates to SIP/TCP connection, but not MRCPv2/TCP. If so, see below.

On Wed, Mar 11, 2009 at 12:26 AM, Arash Abghari <arash....@gmail.com> wrote:

Hi Arsen,

I have a problem and I am not sure where the problem is either in the server side or client side. I am sending SIP packets over TCP not UDP using a Dialogic client to the UniMRCP server. Assume that the source port (client side) is 8062 and destination port (server side) is 8060.

Are you sure your client always uses bounded 8062 port for TCP connect, typically SIP user agent may listen on 8062 port but connect through unbound TCP ports (let OS decide what port to use).

I establish a session, send some requests like DIFINE-GRAMMAR and RECOGNIZE and at last a BYE. Upon receiving the 200 OK, I close the tcp socket and exit the client application, but server is still running. Now the problem is I am not able to establish a new session using the same src port (8062).

It smells like typical TCP Time-Wait issue. Your client should set REUSEADDR socket option to be able to bind to the same port on next start immediately or you have to wait for Time-wait to expiry. It depends on OS and may be up to 4 min.

I have to restart the server then I am able to establish a session. It seems that server has not yet released the socket. I tracked it down by using a sniffer. When the client close the socket, it sends a FIN-ACK packet to the server and server responds with only an ACK which I believe it should have responded with a FIN-ACK not an ACK. What do you think? is it a bug or I am doing something wrong?

Server sooner or later MUST respond with FIN-ACK, however a few ACK packets can be sent in the interim, till server finally closes the socket. I've just checked on my side, it works as intended. If you provide server logs and network capture, probably I'll be able to identify what is going on more closely.

HTH,
Arsen.

Thanks,

Arash

[Arash Abghari]

Hi Arsen,

Sorry for late response.

If I understand you right, you have both SIP and MRCPv2 connections over TCP. The issue you observed relates to SIP/TCP connection, but not MRCPv2/TCP. If so, see below.

  yes, you're right. 

Are you sure your client always uses bounded 8062 port for TCP connect, typically SIP user agent may listen on 8062 port but connect through unbound TCP ports (let OS decide what port to use).

  I can either select the source port or let OS decide, but since you mentioned that let me ask you a question. What is the difference between the port that SIP is listening to and the source port of TCP connection (form client point of view)? I think they are seme. I mean the server will respond to the client where the dest port of the respond packet is the source port of the  received packet. For example, When I monitor the connection between UniMRCP server and UniMRCP client in case of MRCPv2/TCP, server never sends any thing to 8062 although it is defined in the client conf file as client port instead it is sending to whatever the source port is which is decided by the OS of client side and in  case of my client (Dialogic), SIP stack is listening to this port (source post of TCP packet).

Server sooner or later MUST respond with FIN-ACK, however a few ACK packets can be sent in the interim, till server finally closes the socket. I've just checked on my side, it works as intended. If you provide server logs and network capture, probably I'll be able to identify what is going on more closely.

I  waited for 4 mins but nothing happend , I mean , I didn't recieve any FIN-ACK but it could be a problem at my side since yours working properly.

I have another problem. After sending RECOGNIZE packet , as soon as I recieve IN-PROGRESS, I start sending audio data through RTP where the source port is 4000 and the des port is whatever the UniMRCP server tells me  for example 5000. But the server is not recieving any thing and it return RECOGNITION-COMPLETE with "no-input-timeout". When I monitor the network everything seems ok. I can not figure out where the problem is. So how can I send you the network capture I mean in which format? I already attached the log  for the server.

Thanks,

Arash

[Arsen Chaloyan]

Hi Arash,
my comments below

On Wed, Mar 11, 2009 at 11:09 PM, Arash Abghari <arash....@gmail.com> wrote:

Hi Arsen,

Sorry for late response.

If I understand you right, you have both SIP and MRCPv2 connections over TCP. The issue you observed relates to SIP/TCP connection, but not MRCPv2/TCP. If so, see below.

  yes, you're right. 

Are you sure your client always uses bounded 8062 port for TCP connect, typically SIP user agent may listen on 8062 port but connect through unbound TCP ports (let OS decide what port to use).

  I can either select the source port or let OS decide, but since you mentioned that let me ask you a question. What is the difference between the port that SIP is listening to and the source port of TCP connection (form client point of view)?

Server listens on socket and is waiting for incoming connections to accept. Client is trying to connect to server through listening socket. As far as TCP is connection oriented protocol it doesn't matter what the actual source port of connected socket is.
From other hand, SIP is designed as peer-to-peer protocol, where each SIP user agent should both originate and accept incoming SIP dialogs. That's why SIP ua should listen on a port to accept incoming requests, but at the same time should be able to connect to other peers. Thus TCP listening port and connected port cannot be the same for a SIP peer.
In MRCPv2 scope, listening TCP port is meaningless for client, as MRCP peer is either client or server. From this point of view, MRCP is much alike MEGACO, MGCP and the same RTSP protocols, however RFC writers actively force SIP to outplay those protocols and even be used where it wasn't intended originally.
 

I think they are seme. I mean the server will respond to the client where the dest port of the respond packet is the source port of the  received packet. For example, When I monitor the connection between UniMRCP server and UniMRCP client in case of MRCPv2/TCP, server never sends any thing to 8062 although it is defined in the client conf file as client port instead it is sending to whatever the source port is which is decided by the OS of client side and in  case of my client (Dialogic), SIP stack is listening to this port (source post of TCP packet).

Server sooner or later MUST respond with FIN-ACK, however a few ACK packets can be sent in the interim, till server finally closes the socket. I've just checked on my side, it works as intended. If you provide server logs and network capture, probably I'll be able to identify what is going on more closely.

I  waited for 4 mins but nothing happend , I mean , I didn't recieve any FIN-ACK but it could be a problem at my side since yours working properly.

What OS doesn your UniMRCP server run on?
Use "netstat -na" to monitor connections on your hosts.

I have another problem. After sending RECOGNIZE packet , as soon as I recieve IN-PROGRESS, I start sending audio data through RTP where the source port is 4000 and the des port is whatever the UniMRCP server tells me  for example 5000. But the server is not recieving any thing and it return RECOGNITION-COMPLETE with "no-input-timeout". When I monitor the network everything seems ok. I can not figure out where the problem is.

Strange, as I see server received only 4 RTP packets from client
2009-03-11 13:46:29:532020 [INFO]   Close RTP Receive 192.168.1.93:5000 <- 192.168.1.90:4000 [r:4 l:0 j:380]

 

So how can I send you the network capture I mean in which format? I already attached the log  for the server.

Any format Wireshark can read, pcap format will do. Please upload logs and network capture for the same MRCP session.

Regards,
Arsen

Thanks,

Arash

2009-03-11 13:46:10:284344 [NOTICE] UniMRCP Server [0.5.0]
2009-03-11 13:46:10:284344 [INFO]   APR [1.3.3]
2009-03-11 13:46:10:284344 [NOTICE] Create MRCP Server
2009-03-11 13:46:10:284344 [NOTICE] Create MRCP Resource Factory [2]
2009-03-11 13:46:10:284344 [NOTICE] Register Synthesizer Resource
2009-03-11 13:46:10:284344 [NOTICE] Register Recognizer Resource
2009-03-11 13:46:10:284344 [INFO]   Register Resource Factory
2009-03-11 13:46:10:284344 [INFO]   Register Codec [PCMU]
2009-03-11 13:46:10:284344 [INFO]   Register Codec [PCMA]
2009-03-11 13:46:10:284344 [INFO]   Register Codec [L16]
2009-03-11 13:46:10:284344 [NOTICE] Open Config File [../conf/unimrcpserver.xml]
2009-03-11 13:46:10:294358 [NOTICE] Create Sofia SIP [1.12.10] Agent 192.168.1.93:8060 udp,tcp
2009-03-11 13:46:10:294358 [INFO]   Register Signaling Agent [SIP-Agent-1]
2009-03-11 13:46:10:294358 [NOTICE] Create UniRTSP Agent 192.168.1.93:1554 [100]
2009-03-11 13:46:10:294358 [INFO]   Register Signaling Agent [RTSP-Agent-1]
2009-03-11 13:46:10:294358 [NOTICE] Create TCP/MRCPv2 Connection Agent 192.168.1.93:1544 [100]
2009-03-11 13:46:10:294358 [INFO]   Register Connection Agent [MRCPv2-Agent-1]
2009-03-11 13:46:10:294358 [NOTICE] Create Media Processing Engine
2009-03-11 13:46:10:294358 [INFO]   Register Media Engine [Media-Engine-1]
2009-03-11 13:46:10:304372 [NOTICE] Create RTP Termination Factory 192.168.1.93:[5000,6000]
2009-03-11 13:46:10:304372 [INFO]   Register RTP Termination Factory [RTP-Factory-1]
2009-03-11 13:46:10:304372 [INFO]   Register Plugin [../plugin/demosynth.dll] [Demo-Synth-1]
2009-03-11 13:46:10:304372 [INFO]   Register Resource Engine [Demo-Synth-1]
2009-03-11 13:46:10:304372 [INFO]   Register Plugin [../plugin/demorecog.dll] [Demo-Recog-1]
2009-03-11 13:46:10:314387 [INFO]   Register Resource Engine [Demo-Recog-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile signaling-agent [SIP-Agent-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile connection-agent [MRCPv2-Agent-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile media-engine [Media-Engine-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile rtp-factory [RTP-Factory-1]
2009-03-11 13:46:10:314387 [NOTICE] Create Profile [MRCPv2-Default]
2009-03-11 13:46:10:314387 [INFO]   Assign Resource Engine [speechsynth] [Demo-Synth-1]
2009-03-11 13:46:10:314387 [INFO]   Assign Resource Engine [speechrecog] [Demo-Recog-1]
2009-03-11 13:46:10:314387 [INFO]   Register Profile [MRCPv2-Default]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile signaling-agent [RTSP-Agent-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile media-engine [Media-Engine-1]
2009-03-11 13:46:10:314387 [INFO]   Loading Profile rtp-factory [RTP-Factory-1]
2009-03-11 13:46:10:314387 [NOTICE] Create Profile [MRCPv1-Default]
2009-03-11 13:46:10:314387 [INFO]   Assign Resource Engine [speechsynth] [Demo-Synth-1]
2009-03-11 13:46:10:314387 [INFO]   Assign Resource Engine [speechrecog] [Demo-Recog-1]
2009-03-11 13:46:10:314387 [INFO]   Register Profile [MRCPv1-Default]
2009-03-11 13:46:10:314387 [INFO]   Start Server Task
>2009-03-11 13:46:10:314387 [INFO]   Start Media Processing Engine
2009-03-11 13:46:10:364459 [INFO]   Open Resource Engines
2009-03-11 13:46:10:364459 [INFO]   Receive SIP Event [nua_r_set_params] Status 200 OK
2009-03-11 13:46:10:364459 [INFO]   On Server Task Start
2009-03-11 13:46:23:643553 [INFO]   Receive SIP Event [nua_i_invite] Status 100 Trying
2009-03-11 13:46:23:653568 [INFO]   Receive SIP Event [nua_i_state] Status 100 Trying
2009-03-11 13:46:23:653568 [NOTICE] SIP Call State [received]
2009-03-11 13:46:23:653568 [INFO]   Found Profile [MRCPv2-Default]
2009-03-11 13:46:23:653568 [INFO]   Remote SDP
v=0

o=openMrcpSip 33580 337654 IN IP4 192.168.1.90

s=-

c=IN IP4 192.168.1.90

t=0 0

m=application 9 TCP/MRCPv2 1

a=setup:active

a=connection:new

a=resource:speechrecog

a=cmid:1

m=audio 4000 RTP/AVP 0 96

a=rtpmap:0 PCMU/8000

a=rtpmap:96 telephone-event/8000

a=sendonly

a=mid:1


2009-03-11 13:46:23:653568 [NOTICE] Add Session <63c1449961d68d47>
2009-03-11 13:46:23:653568 [INFO]   Receive Offer <63c1449961d68d47> [c:1 a:1 v:0]
2009-03-11 13:46:23:653568 [INFO]   Add Control Channel <63c1449961d68d47@speechrecog> to Pending Connection [1]
2009-03-11 13:46:23:653568 [INFO]   Open RTP Receive 192.168.1.93:5000 <- 192.168.1.90:4000 playout [50 ms]
2009-03-11 13:46:23:653568 [INFO]   Send Answer <63c1449961d68d47> [c:1 a:1 v:0] Status OK
2009-03-11 13:46:23:653568 [INFO]   Local SDP
v=0

o=UniMRCPServer 0 0 IN IP4 192.168.1.93

s=-

c=IN IP4 192.168.1.93

t=0 0

m=application 1544 TCP/MRCPv2 1

a=setup:passive

a=connection:new

a=channel:63c1449961d68d47@speechrecog

a=cmid:1

m=audio 5000 RTP/AVP 0

a=rtpmap:0 PCMU/8000

a=recvonly

a=mid:1


2009-03-11 13:46:23:813798 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK
2009-03-11 13:46:23:813798 [NOTICE] SIP Call State [completed]
2009-03-11 13:46:23:823812 [NOTICE] Accepted TCP/MRCPv2 Connection 192.168.1.90:1849
2009-03-11 13:46:23:833827 [INFO]   Receive SIP Event [nua_i_ack] Status 200 OK
2009-03-11 13:46:23:833827 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK
2009-03-11 13:46:23:833827 [NOTICE] SIP Call State [ready]
2009-03-11 13:46:23:833827 [INFO]   Receive SIP Event [nua_i_active] Status 200 Call active
2009-03-11 13:46:23:984043 [INFO]   Receive MRCPv2 Stream [432 bytes]
MRCP/2.0 432 DEFINE-GRAMMAR 1003

Channel-Identifier: 63c1449961d68d47@speechrecog

Content-Type: application/grammar+xml

Content-Id: gra...@form.store

Content-Length: 254



<?xml version="1.0"?>   <grammar xmlns="http://www.w3.org/2001/06/grammar" xml:lang="en-US" version="1.0" mode="voice" root="digit">      <rule id="digit">             <one-of>                  <item>one</item>                <item>two</item>                <item>three</item>            </one-of>         </rule>       </grammar>
2009-03-11 13:46:23:984043 [INFO]   Move Control Channel <63c1449961d68d47@speechrecog> to Connection [1]
2009-03-11 13:46:23:984043 [INFO]   Process DEFINE-GRAMMAR Request [1003]
2009-03-11 13:46:23:984043 [INFO]   Process DEFINE-GRAMMAR Response [1003]
2009-03-11 13:46:23:984043 [INFO]   Send MRCPv2 Stream [116 bytes]
MRCP/2.0 116 1003 200 COMPLETE

Channel-Identifier: 63c1449961d68d47@speechrecog

Completion-Cause: 000 success




2009-03-11 13:46:24:094201 [INFO]   Receive MRCPv2 Stream [206 bytes]
MRCP/2.0 206 RECOGNIZE 1004

Cancel-If-Queue: false

Channel-Identifier: 63c1449961d68d47@speechrecog

Content-Type: text/uri-list

Start-Input-Timers: true

Content-Length: 26



session:gra...@form.store
2009-03-11 13:46:24:094201 [INFO]   Process RECOGNIZE Request [1004]
2009-03-11 13:46:24:094201 [INFO]   Process RECOGNIZE Response [1004]
2009-03-11 13:46:24:094201 [INFO]   State Transition IDLE -> RECOGNIZING
2009-03-11 13:46:24:094201 [INFO]   Send MRCPv2 Stream [87 bytes]
MRCP/2.0 87 1004 200 IN-PROGRESS

Channel-Identifier: 63c1449961d68d47@speechrecog




2009-03-11 13:46:29:451905 [INFO]   Detected Noinput
2009-03-11 13:46:29:451905 [INFO]   Process RECOGNITION-COMPLETE Event [1004]
2009-03-11 13:46:29:451905 [INFO]   State Transition RECOGNIZING -> RECOGNIZED
2009-03-11 13:46:29:451905 [INFO]   Send MRCPv2 Stream [141 bytes]
MRCP/2.0 141 RECOGNITION-COMPLETE 1004 COMPLETE

Channel-Identifier: 63c1449961d68d47@speechrecog

Completion-Cause: 002 no-input-timeout




2009-03-11 13:46:29:522006 [INFO]   Receive SIP Event [nua_i_bye] Status 200 Session Terminated
2009-03-11 13:46:29:522006 [INFO]   Receive SIP Event [nua_i_state] Status 200 Session Terminated
2009-03-11 13:46:29:522006 [NOTICE] SIP Call State [terminated]
2009-03-11 13:46:29:522006 [INFO]   Receive Terminate Request <63c1449961d68d47>
2009-03-11 13:46:29:522006 [INFO]   Remove Control Channel <63c1449961d68d47@speechrecog> [0]
2009-03-11 13:46:29:522006 [NOTICE] Remove Session <63c1449961d68d47>
2009-03-11 13:46:29:522006 [INFO]   Receive SIP Event [nua_i_terminated] Status 200 Session Terminated
2009-03-11 13:46:29:532020 [INFO]   Close RTP Receive 192.168.1.93:5000 <- 192.168.1.90:4000 [r:4 l:0 j:380]
2009-03-11 13:46:29:532020 [INFO]   Send Terminate Response <63c1449961d68d47>
2009-03-11 13:46:29:532020 [NOTICE] Destroy Session

[Arash Abghari]

Hi Arsen,

Please find the attached. I provided you with both server log and Wireshark pcap file. By the way, I am running both server and client on a Win XP SP2.

Thanks,

Arash

[Arash Abghari]

Hi Arsen,

Please add filter "ip.addr == 192.168.1.93" to the Wireshark to make things clear.

Thanks,

Arash

[Arsen Chaloyan]

Hi Arash,

> I am running both server and client on a Win XP SP2.

This indeed makes difference. When I said it worked on my side, I ran UniMRCP server on Linux box. Today I've tried just the same on WinXP and should confirm that issue exists. TCP socket remains in CLOSE_WAIT state infinitely. The problem is in Sofia-SIP tport layer, only Windows implementation is affected. I have no enough time to digg into much, but finally this issue has to be reported to Sofia-SIP devs to be fixed. I'll do that when investigate the problem enough.

> But the server is not recieving any thing and it return RECOGNITION-COMPLETE with "no-input-timeout". When I monitor the network everything seems ok. I can not figure out where the problem is.

The problem is in RTP stream originated from your client. Pay attention to RTP timestamps and inter-arrival interval. I would say there is no inter-arival interval at all. Seems all the RTP packets were sent at once.
Wireshark has builtin capabilities, which can help you out.

Statistics -> RTP -> Show All Streams
Statistics -> VoIP Calls

HTH,
Arsen.

[Arash Abghari]

Hi Arsen,

Thanks a lot for your help. As you said the problem was no inter-arrival interval. I added some delay and it's working know.Now the Dialogic MRCP/v2 client is working with UniMRCP server but I have fixed several bugs in the client code, so if any body needs the fixed code I can provide with the code.

Thanks,

Arash

[Arsen Chaloyan]

Hi Arash,
Nice to see you got it working.

It's long time I have been thinking of creating an area on UniMRCP web dedicated to interoperability. Hopefully I'll come up with that resource soon, then I'll expect you and other users to share interop results, required configuration, remaining issues there.

Stay tuned and thanks for reporting the issue.
Arsen.

[acha...@gmail.com]

Hi Arash,
I narrowed down the issue you originally reported and submitted it to
Sofia-SIP's dev list a while ago.
Yesterday the fix was committed into Sofia-SIP's repository.

I submitted all the related information to
http://code.google.com/p/unimrcp/issues/detail?id=25
in case you or others want to have it fixed before the next Sofia-SIP
release.

Regards,
Arsen.

On Mar 12, 11:35 pm, Arsen Chaloyan <achalo...@gmail.com> wrote:
> Hi Arash,
> Nice to see you got it working.
>
> It's long time I have been thinking of creating an area on UniMRCP web
> dedicated to interoperability. Hopefully I'll come up with that resource
> soon, then I'll expect you and other users to share interop results,
> required configuration, remaining issues there.
>
> Stay tuned and thanks for reporting the issue.
> Arsen.
>

> On Thu, Mar 12, 2009 at 6:02 PM, Arash Abghari <arash.abgh...@gmail.com>wrote:
>
>
>
>
>
> > Hi Arsen,
>
> > Thanks a lot for your help. As you said the problem was no inter-arrival
> > interval. I added some delay and it's working know.Now the Dialogic MRCP/v2
> > client is working with UniMRCP server but I have fixed several bugs in the
> > client code, so if any body needs the fixed code I can provide with the
> > code.
>
> > Thanks,
>
> > Arash
>

> > On Thu, Mar 12, 2009 at 8:45 AM, Arsen Chaloyan <achalo...@gmail.com>wrote:
>
> >> Hi Arash,
>
> >> > I am running both server and client on a Win XP SP2.
> >> This indeed makes difference. When I said it worked on my side, I ran
> >> UniMRCP server on Linux box. Today I've tried just the same on WinXP and
> >> should confirm that issue exists. TCP socket remains in CLOSE_WAIT state
> >> infinitely. The problem is in Sofia-SIP tport layer, only Windows
> >> implementation is affected. I have no enough time to digg into much, but
> >> finally this issue has to be reported to Sofia-SIP devs to be fixed. I'll do
> >> that when investigate the problem enough.
>
> >> > But the server is not recieving any thing and it return
> >> RECOGNITION-COMPLETE with "no-input-timeout". When I monitor the network
> >> everything seems ok. I can not figure out where the problem is.
> >> The problem is in RTP stream originated from your client. Pay attention to
> >> RTP timestamps and inter-arrival interval. I would say there is no
> >> inter-arival interval at all. Seems all the RTP packets were sent at once.
> >> Wireshark has builtin capabilities, which can help you out.
>
> >> Statistics -> RTP -> Show All Streams
> >> Statistics -> VoIP Calls
>
> >> HTH,
> >> Arsen.
>

> >> On Thu, Mar 12, 2009 at 3:50 AM, Arash Abghari <arash.abgh...@gmail.com>wrote:
>
> >>> Hi Arsen,
>
> >>> Please add filter "ip.addr == 192.168.1.93" to the Wireshark to make
> >>> things clear.
>
> >>> Thanks,
>
> >>> Arash
>

> >>> On Wed, Mar 11, 2009 at 5:38 PM, Arash Abghari <arash.abgh...@gmail.com>wrote:
>
> >>>> Hi Arsen,
>
> >>>> Please find the attached. I provided you with both server log and
> >>>> Wireshark pcap file. By the way, I am running both server and client on a
> >>>> Win XP SP2.
>
> >>>> Thanks,
>
> >>>> Arash
>

> ...
>
> read more »

[Arash Abghari]

Hi Arsen,

Thanks for letting us know that the problem is fixed now.

Regards,

Arash