[Serdev] TCP Blocking Connect issue

Mon Aug 23 06:26:52 UTC 2004

But the UA isn't crashed at this point.... remember that....

Client Logs in.
>serctl ul show support at 192.168.2.253
><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3546
I can make calls easily here... Invites ACK's etc work no problem

>Crash Client!!
>
>serctl ul show support at 192.168.2.253
><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3457

>Restart Client
I also re-login and the client is 'working' i.e not in a crash state...

>serctl ul show support at 192.168.2.253
><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3403
><sip:192.168.2.11:16501;transport=tcp>;q=0.00;expires=3585

It is here that the Invites work up until the ACK is sent.
i.e
T 192.168.2.28:1148 -> 192.168.2.253:5060 [AP]
  INVITE sip:support at 192.168.2.253 SIP/2.0..Via: SIP/2.0/TCP 
192.168.2.28:165
  32..Max-Forwards: 70..From: "HS User" 
<sip:test2 at 192.168.2.253>;tag=ac5d7c3
  9647143ed8365ef1c5faaaf16;epid=a98f8fc72f..To: 
<sip:support at 192.168.2.253>.
  .Call-ID: 793c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 
INVITE..Co
  ntact: 
<sip:test2 at 192.168.2.253:16532;maddr=192.168.2.28;transport=tcp>..Us
  er-Agent: RTC/1.2..Content-Type: application/sdp..Content-Length: 
742....v=
  0..o=- 0 0 IN IP4 192.168.2.28..s=session..c=IN IP4 
192.168.2.28..b=CT:1000
  ..t=0 0..m=audio 52464 RTP/AVP 97 111 112 6 0 8 4 5 3 
101..k=base64:T9o7c5c
  BES8WEd52rGPiaYNpkOJNC9kkt2Z0VsZLKso..a=rtpmap:97 
red/8000..a=rtpmap:111 SI
  REN/16000..a=fmtp:111 bitrate=16000..a=rtpmap:112 
G7221/16000..a=fmtp:112 b
  itrate=24000..a=rtpmap:6 DVI4/16000..a=rtpmap:0 PCMU/8000..a=rtpmap:8 
PCMA/
  8000..a=rtpmap:4 G723/8000..a=rtpmap:5 DVI4/8000..a=rtpmap:3 
GSM/8000..a=rt
  pmap:101 telephone-event/8000..a=fmtp:101 
0-16..a=encryption:optional..m=vi
  deo 6296 RTP/AVP 34 
31..k=base64:WUL8Q1eIhmhhaUQhOTO7puzhVkKkPEierIHY1araev
  c..a=rtpmap:34 H263/90000..a=rtpmap:31 
H261/90000..a=encryption:optional..m
  =application 1503 tcp msdata..a=sendonly..a=encryption:optional..

T 192.168.2.253:5060 -> 192.168.2.28:1148 [AP]
  SIP/2.0 100 trying -- your call is important to us..Via: SIP/2.0/TCP 
192.16
  8.2.28:16532..From: "HS User" 
<sip:test2 at 192.168.2.253>;tag=ac5d7c39647143e
  d8365ef1c5faaaf16;epid=a98f8fc72f..To: 
<sip:support at 192.168.2.253>..Call-ID
  : 793c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 
INVITE..Server: Si
  p EXpress router (0.8.14 (i386/linux))..Content-Length: 0..Warning: 
392 192
  .168.2.253:5060 "Noisy feedback tells:  pid=28376 
req_src_ip=192.168.2.28 r
  eq_src_port=1148 in_uri=sip:support at 192.168.2.253 
out_uri=sip:192.168.2.11:
  11822;transport=tcp via_cnt==1"....

T 192.168.2.253:34079 -> 192.168.2.11:16501 [AP]
  INVITE sip:192.168.2.11:16501;transport=tcp SIP/2.0..Record-Route: 
<sip:sup

port at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed8365ef1c5faaaf16;lr=o
  n>..Via: SIP/2.0/TCP 
192.168.2.253;branch=z9hG4bK7bf6.8c6651e.1;i=b..Via: S
  IP/2.0/TCP 192.168.2.28:16532..Max-Forwards: 69..From: "HS User" 
<sip:test2

@192.168.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc72f..To: <
  sip:support at 192.168.2.253>..Call-ID: 
793c8868bce64e82b7e097dd204d57f6 at 192.1
  68.2.28..CSeq: 1 INVITE..Contact: 
<sip:test2 at 192.168.2.253:16532;maddr=192.
  168.2.28;transport=tcp>..User-Agent: RTC/1.2..Content-Type: 
application/sdp
  ..Content-Length: 742....v=0..o=- 0 0 IN IP4 192.168.2.28..s=session..c=IN
  IP4 192.168.2.28..b=CT:1000..t=0 0..m=audio 52464 RTP/AVP 97 111 112 6 0 8
  4 5 3 
101..k=base64:T9o7c5cBES8WEd52rGPiaYNpkOJNC9kkt2Z0VsZLKso..a=rtpmap:9
  7 red/8000..a=rtpmap:111 SIREN/16000..a=fmtp:111 
bitrate=16000..a=rtpmap:11
  2 G7221/16000..a=fmtp:112 bitrate=24000..a=rtpmap:6 DVI4/16000..a=rtpmap:0
  PCMU/8000..a=rtpmap:8 PCMA/8000..a=rtpmap:4 G723/8000..a=rtpmap:5 
DVI4/8000
  ..a=rtpmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 
0-16..
  a=encryption:optional..m=video 6296 RTP/AVP 34 
31..k=base64:WUL8Q1eIhmhhaUQ
  hOTO7puzhVkKkPEierIHY1araevc..a=rtpmap:34 H263/90000..a=rtpmap:31 
H261/9000
  0..a=encryption:optional..m=application 1503 tcp 
msdata..a=sendonly..a=encr
  yption:optional..

T 192.168.2.11:16501 -> 192.168.2.253:34079 [AP]
  SIP/2.0 100 Trying..Via: SIP/2.0/TCP 
192.168.2.253;branch=z9hG4bK7bf6.8c665
  1e.1;i=b..Via: SIP/2.0/TCP 192.168.2.28:16532..From: "HS User" 
<sip:test2 at 1

92.168.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc72f..To: <si

p:support at 192.168.2.253>;tag=04445215ea6d4c70b7c5bdadd5db0598..Call-ID: 793
  c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 
INVITE..User-Agent: RTC
  /1.2..Content-Length: 0....

T 192.168.2.11:16501 -> 192.168.2.253:34079 [AP]
  SIP/2.0 180 Ringing..Via: SIP/2.0/TCP 
192.168.2.253;branch=z9hG4bK7bf6.8c66
  51e.1;i=b..Via: SIP/2.0/TCP 192.168.2.28:16532..From: "HS User" 
<sip:test2@

192.168.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc72f..To: <s

ip:support at 192.168.2.253>;tag=04445215ea6d4c70b7c5bdadd5db0598..Call-ID: 79
  3c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 INVITE..Record-Route:

<sip:support at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed8365ef1c5faaa
  f16;lr=on>..User-Agent: RTC/1.2..Content-Length: 0....

T 192.168.2.253:5060 -> 192.168.2.28:1148 [AP]
  SIP/2.0 180 Ringing..Via: SIP/2.0/TCP 192.168.2.28:16532..From: "HS 
User" <

sip:test2 at 192.168.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc7
  2f..To: 
<sip:support at 192.168.2.253>;tag=04445215ea6d4c70b7c5bdadd5db0598..C
  all-ID: 793c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 
INVITE..Reco
  rd-Route: 
<sip:support at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed836
  5ef1c5faaaf16;lr=on>..User-Agent: RTC/1.2..Content-Length: 0....

T 192.168.2.11:16501 -> 192.168.2.253:34079 [AP]
  SIP/2.0 200 OK..Via: SIP/2.0/TCP 
192.168.2.253;branch=z9hG4bK7bf6.8c6651e.1
  ;i=b..Via: SIP/2.0/TCP 192.168.2.28:16532..From: "HS User" 
<sip:test2 at 192.1
  68.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc72f..To: 
<sip:su
  pport at 192.168.2.253>;tag=04445215ea6d4c70b7c5bdadd5db0598..Call-ID: 
793c886
  8bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 INVITE..Record-Route: 
<sip:

support at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed8365ef1c5faaaf16;l
  r=on>..Contact: 
<sip:support at 192.168.2.253:16501;maddr=192.168.2.11;transpo
  rt=tcp>..User-Agent: RTC/1.2..Content-Type: 
application/sdp..Content-Length
  : 743....v=0..o=- 0 0 IN IP4 192.168.2.11..s=session..c=IN IP4 
192.168.2.11
  ..b=CT:1000..t=0 0..m=audio 45980 RTP/AVP 97 111 112 6 0 8 4 5 3 
101..k=bas
  e64:aeSWzmIeemoo30FyZ+vUDPNCVqVZgDBdJQT/pskKV1w..a=rtpmap:97 
red/8000..a=rt
  pmap:111 SIREN/16000..a=fmtp:111 bitrate=16000..a=rtpmap:112 
G7221/16000..a
  =fmtp:112 bitrate=24000..a=rtpmap:6 DVI4/16000..a=rtpmap:0 
PCMU/8000..a=rtp
  map:8 PCMA/8000..a=rtpmap:4 G723/8000..a=rtpmap:5 
DVI4/8000..a=rtpmap:3 GSM
  /8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 
0-16..a=encryption:opt
  ional..m=video 39830 RTP/AVP 34 
31..k=base64:1v9SA67mYcqsaBSFQP1hkbHkAVB4MC
  hL4LP+4wtS0ys..a=rtpmap:34 H263/90000..a=rtpmap:31 
H261/90000..a=encryption
  :optional..m=application 1503 tcp 
msdata..a=recvonly..a=encryption:optional
  ..

T 192.168.2.253:5060 -> 192.168.2.28:1148 [AP]
  SIP/2.0 200 OK..Via: SIP/2.0/TCP 192.168.2.28:16532..From: "HS User" 
<sip:t

est2 at 192.168.2.253>;tag=ac5d7c39647143ed8365ef1c5faaaf16;epid=a98f8fc72f..T
  o: 
<sip:support at 192.168.2.253>;tag=04445215ea6d4c70b7c5bdadd5db0598..Call-I
  D: 793c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..CSeq: 1 
INVITE..Record-Ro
  ute: 
<sip:support at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed8365ef1c
  5faaaf16;lr=on>..Contact: 
<sip:support at 192.168.2.253:16501;maddr=192.168.2.
  11;transport=tcp>..User-Agent: RTC/1.2..Content-Type: 
application/sdp..Cont
  ent-Length: 743....v=0..o=- 0 0 IN IP4 192.168.2.11..s=session..c=IN 
IP4 19
  2.168.2.11..b=CT:1000..t=0 0..m=audio 45980 RTP/AVP 97 111 112 6 0 8 4 5 3
  101..k=base64:aeSWzmIeemoo30FyZ+vUDPNCVqVZgDBdJQT/pskKV1w..a=rtpmap:97 
red/
  8000..a=rtpmap:111 SIREN/16000..a=fmtp:111 bitrate=16000..a=rtpmap:112 
G722
  1/16000..a=fmtp:112 bitrate=24000..a=rtpmap:6 DVI4/16000..a=rtpmap:0 
PCMU/8
  000..a=rtpmap:8 PCMA/8000..a=rtpmap:4 G723/8000..a=rtpmap:5 
DVI4/8000..a=rt
  pmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 
0-16..a=encr
  yption:optional..m=video 39830 RTP/AVP 34 
31..k=base64:1v9SA67mYcqsaBSFQP1h
  kbHkAVB4MChL4LP+4wtS0ys..a=rtpmap:34 H263/90000..a=rtpmap:31 
H261/90000..a=
  encryption:optional..m=application 1503 tcp 
msdata..a=recvonly..a=encryptio
  n:optional..

T 192.168.2.28:1148 -> 192.168.2.253:5060 [AP]
  ACK 
sip:support at 192.168.2.253;transport=tcp;ftag=ac5d7c39647143ed8365ef1c5f
  aaaf16;lr=on SIP/2.0..Via: SIP/2.0/TCP 
192.168.2.28:16532..Max-Forwards: 70
  ..From: "HS User" 
<sip:test2 at 192.168.2.253>;tag=ac5d7c39647143ed8365ef1c5fa
  aaf16;epid=a98f8fc72f..To: 
<sip:support at 192.168.2.253>;tag=04445215ea6d4c70
  b7c5bdadd5db0598..Call-ID: 
793c8868bce64e82b7e097dd204d57f6 at 192.168.2.28..C
  Seq: 1 ACK..Route: 
<sip:support at 192.168.2.253:16501;maddr=192.168.2.11;tran
  sport=tcp>..User-Agent: RTC/1.2..Content-Length: 0....

 From here it tries to (as assumed) ACK to 192.168.2.11:10227 and then 
falls down... instead of SER realising that 192.168.2.11:10227 doesn't 
exist and then trying 192.168.2.11:16501, it just fails.

Andrew

Jiri Kuthan wrote:

>At 06:41 AM 8/23/2004, Andrew Mee wrote:
>  
>
>>Umm... Ok I'm a little lost in your explanation, 
>>    
>>
>
>ACK must include ROUTE header field which forces SER to forward the
>request to a destination which is dead after the UAS crashed. -> it can't
>be delivered.
>
>  
>
>>I have followed the packets back and forth, there is no record route information that says contact this UA at specific port number in the packet headers. 
>>    
>>
>
>It should be there. Incoming ACK should have Route based on Record-Route
>from 200.
>
>  
>
>>So when it tries to Forward the ACK to the called UA from the Proxy, it fails because it (as assumed) uses an incorrect old port number and it has lost it's original TCP connection for whatever reason. Surely this ACK should be resent by the Proxy to the UA to the next ip:port combination it has a record of when it can't get through before it gives up on the call. I don't see how this is ok that the ACK is not delivered??
>>    
>>
>
>Well, if UA crashes, dialog state disappears. I don't see any use of delivering
>a message, which is a part of a dialog, which no longer exists. Read RFC3261 for
>normative reference. If a UAS wishes to be super-persistent, then after the crash
>it must completely reconstruct dialog state (otherwise subsequent rquests will
>be denied as out-of-dialog) and transport state (otherwise different port numbers
>will cause failed delivery).
>
>-jiri
>
>
>  
>
>>It seems the original INVITE method will find the correct port to send information on so it sets up the first part of the call.
>>
>>I'm hoping I haven't missed something here?
>>
>>Thanks
>>
>>Andrew
>>
>>Jiri Kuthan wrote:
>>
>>    
>>
>>>That's still a valid case -- forwarding of ACK should be governed by record-routing since it belongs to a dialog and should be forwarded
>>>to where 200 came from (which is dead now). Content of user location
>>>database shall have no impact on where to forward. In which case, it is
>>>ok that the ACK cannot be delivered.
>>>
>>>What you need to verify is that new initial request will get forwarded
>>>to the right place, even if some alternate destinations are no longer
>>>valid.
>>>
>>>-jiri
>>>
>>>
>>>At 04:40 AM 8/23/2004, Andrew Mee wrote:
>>>
>>>
>>>      
>>>
>>>>Yep, I just watched the crashed binding expire (it took an hour)
>>>>
>>>>Our previous tests do show that when I send an Invite that it only checks the first binding then stops... It does not check subsequent bindings. i.e..
>>>>serctl ul show support at 192.168.2.253
>>>><sip:192.168.2.11:14858;transport=tcp>;q=0.00;expires=1991 <-- Bad
>>>><sip:192.168.2.11:7308;transport=tcp>;q=0.00;expires=2911  <-- Bad
>>>><sip:192.168.2.11:11822;transport=tcp>;q=0.00;expires=3595 <-- Good
>>>>
>>>>test2 calls support
>>>>Ok does invite up to ACK to support (from debug)
>>>>13(13758) Sending:
>>>>ACK sip:192.168.2.11:14858;transport=tcp SIP/2.0
>>>>Record-Route: <sip:support at 192.168.2.253;transport=tcp;ftag=7790d6ca5a9c418da27c37a55ee9c94c;lr=on>
>>>>Via: SIP/2.0/TCP 192.168.2.253;branch=0;i=01
>>>>Via: SIP/2.0/TCP 192.168.2.28:16532
>>>>Max-Forwards: 69
>>>>From: "HS User" <sip:test2 at 192.168.2.253>;tag=7790d6ca5a9c418da27c37a55ee9c94c;epid=872603d44e
>>>>To: <sip:support at 192.168.2.253>;tag=4b2b9c668798498eb7e0e20a8c64c72d
>>>>Call-ID: a2a3e3fb7e3e4a4b92175ffdc68f04ec at 192.168.2.28
>>>>CSeq: 1 ACK
>>>>User-Agent: RTC/1.2
>>>>Content-Length: 0
>>>>
>>>>.
>>>>13(13758) orig. len=504, new_len=529, proto=2
>>>>13(13758) tcp_send: no open tcp connection found, opening new one
>>>>13(13758) ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused
>>>>13(13758) ERROR: tcpconn_connect: tcp_blocking_connect failed
>>>>13(13758) ERROR: tcp_send: connect failed
>>>>13(13758) msg_send: ERROR: tcp_send failed
>>>>13(13758) Warning: sl_send_reply: I won't send a reply for ACK!!
>>>>13(13758) ERROR: sl_reply_error used: Unfortunately error on sending to next hop occured (477/SL)
>>>>13(13758) DEBUG:destroy_avp_list: destroing list (nil)
>>>>13(13758) receive_msg: cleaning up
>>>>
>>>>But thendoesn't try next available binding.
>>>>
>>>>Andrew
>>>>
>>>>Jiri Kuthan wrote:
>>>>
>>>>  
>>>>
>>>>        
>>>>
>>>>>At 03:13 AM 8/23/2004, Andrew Mee wrote:
>>>>>
>>>>>
>>>>>    
>>>>>
>>>>>          
>>>>>
>>>>>>It seems your assumption is right!
>>>>>>
>>>>>>Client Logs in.
>>>>>>serctl ul show support at 192.168.2.253
>>>>>><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3546
>>>>>>
>>>>>>Crash Client!!
>>>>>>
>>>>>>serctl ul show support at 192.168.2.253
>>>>>><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3457
>>>>>>
>>>>>>Restart Client
>>>>>>
>>>>>>serctl ul show support at 192.168.2.253
>>>>>><sip:192.168.2.11:10227;transport=tcp>;q=0.00;expires=3403
>>>>>><sip:192.168.2.11:14858;transport=tcp>;q=0.00;expires=3585
>>>>>>
>>>>>>Ok the question now if the TCP connection cannot be made should it delete the not available connection and then try the next connection... or...
>>>>>>Should perhaps register delete existing entries and create new ones?
>>>>>>
>>>>>>      
>>>>>>            
>>>>>>
>>>>>The right way is to have the dead bindings expired. The question is:
>>>>>if one of the bindings is valid and active, does the INVITE to the
>>>>>address of record fail? That should not happen, SER should try those
>>>>>which are available. If that does happen, that would be a shortcoming.
>>>>>Can you verify that?
>>>>>
>>>>>Thanks,
>>>>>
>>>>>-jiri
>>>>>
>>>>>
>>>>>    
>>>>>          
>>>>>
>>>>_______________________________________________
>>>>Serdev mailing list
>>>>serdev at lists.iptel.org
>>>>http://lists.iptel.org/mailman/listinfo/serdev
>>>>  
>>>>        
>>>>
>>>--
>>>Jiri Kuthan            http://iptel.org/~jiri/ 
>>>
>>>      
>>>
>>-- 
>>Andrew Mee
>>
>>
>>
>>
>>
>>_______________________________________________
>>Serdev mailing list
>>serdev at lists.iptel.org
>>http://lists.iptel.org/mailman/listinfo/serdev
>>    
>>
>
>--
>Jiri Kuthan            http://iptel.org/~jiri/ 
>
>  
>

-- 
Andrew Mee