[Freeswitch-users] SIP re-invite issue with session timers

David Bolen db3l.net at gmail.com
Sat Jul 23 03:29:59 MSD 2011


While testing some outbound T.38 fax calls, they were getting quickly
disconnected, and I found that I was running into problems related to
the session timer during the re-invite process.  I was wondering if
anyone else has run into anything similar?  I'm not sure if it's just
T.38 related, or would have occurred on any re-invite scenario.

In the trace below, I think my gateway (Flowroute) reacts a little
strangely since it appears to refuse a session timer that it itself
chose during the initial invite process (instead seeming to want to
flip who handles the refresh), but while odd, that's not necessarily
invalid, is it?  I also noticed that FreeSWITCH promoted the timer to
a requirement during the re-invite.  But the eventual call disconnect
seems due to FreeSWITCH never completing renegotiation - the last
thing it transmits is a 100 response.

Disabling session timers (enable-timer=false) in the profile gets
around the problem, but it seems like keeping the timers, if possible,
is preferable in terms of an additional safety net.

Any thoughts or suggestions would be welcome.  Does this appear
strictly a gateway side issue, or is something also not working
properly on the FreeSWITCH side?

-- David


Note: git-b1d1beb is the same as f1de377 from 7/16 plus one local
      change to mod_conference.  The dialed number has been replaced
      by 11111111111, my public switch address with 111.111.111.111,
      and I've excluded the Proxy-Authorization header throughout.

The initial call setup seems ok:

          - - - - - - - - - - - - - - - - - - - - - - - - -

send 1390 bytes to udp/[216.115.69.144]:5060 at 21:29:19.155730:
   ------------------------------------------------------------------------
   INVITE sip:11111111111 at sip.flowroute.com SIP/2.0
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport;branch=z9hG4bKK8mr3pcre4a2j
   Max-Forwards: 70
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349016 INVITE
   Contact: <sip:gw+flowroute at 111.111.111.111:5080;transport=udp;gw=flowroute>
   Expires: 600
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-b1d1beb 2011-07-18 23-08-16 -0400
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 213
   X-FS-Support: update_display
   Remote-Party-ID: <sip:0000000000 at sip.flowroute.com>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1311342219 1311342220 IN IP4 111.111.111.111
   s=FreeSWITCH
   c=IN IP4 111.111.111.111
   t=0 0
   m=audio 27940 RTP/AVP 9 0 8 3 101 13
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
recv 305 bytes from udp/[216.115.69.144]:5060 at 21:29:19.194573:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport=5080;branch=z9hG4bKK8mr3pcre4a2j
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349016 INVITE
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 687 bytes from udp/[216.115.69.144]:5060 at 21:29:19.839258:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport=5080;branch=z9hG4bKK8mr3pcre4a2j
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349016 INVITE
   Record-Route: <sip:216.115.69.133;lr>
   Record-Route: <sip:216.115.69.144;lr>
   Contact: <sip:+11111111111 at 67.16.125.60:5060;transport=udp>
   Content-Length: 184
   Content-Type: application/sdp
   
   v=0
   o=- 3829 19246 IN IP4 67.16.125.60
   s=-
   c=IN IP4 67.16.125.60
   t=0 0
   m=audio 50330 RTP/AVP 0 101
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   a=ptime:20
   a=maxptime:20
   ------------------------------------------------------------------------
recv 850 bytes from udp/[216.115.69.144]:5060 at 21:29:21.587130:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport=5080;branch=z9hG4bKK8mr3pcre4a2j
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349016 INVITE
   Record-Route: <sip:216.115.69.133;lr>
   Record-Route: <sip:216.115.69.144;lr>
   Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
   Contact: <sip:+11111111111 at 67.16.125.60:5060;transport=udp>
   Supported: timer,replaces
   Session-Expires: 10800;refresher=uas
   Content-Length: 184
   Content-Type: application/sdp
   
   v=0
   o=- 3829 19246 IN IP4 67.16.125.60
   s=-
   c=IN IP4 67.16.125.60
   t=0 0
   m=audio 50330 RTP/AVP 0 101
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   a=ptime:20
   a=maxptime:20
   ------------------------------------------------------------------------
send 826 bytes to udp/[216.115.69.144]:5060 at 21:29:21.587678:
   ------------------------------------------------------------------------
   ACK sip:+11111111111 at 67.16.125.60:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport;branch=z9hG4bKmHeH5HXUBD1me
   Route: <sip:216.115.69.144;lr>
   Route: <sip:216.115.69.133;lr>
   Max-Forwards: 70
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349016 ACK
   Contact: <sip:gw+flowroute at 111.111.111.111:5080;transport=udp;gw=flowroute>
   Content-Length: 0
   
   ------------------------------------------------------------------------

          - - - - - - - - - - - - - - - - - - - - - - - - -

The gateway appears to have specified a uas-refreshed session timer in
its 200 message.  Below, the re-invite happens for T.38.  Here I noticed
the new Require: timer option (with the session-expires from before),
which is rejected, then oddly the gateway re-invites but apparently
with a uac-refreshed timer.  FreeSWITCH then sends a 100, and nothing else.


          - - - - - - - - - - - - - - - - - - - - - - - - -

send 1638 bytes to udp/[216.115.69.144]:5060 at 21:29:22.108341:
   ------------------------------------------------------------------------
   INVITE sip:+11111111111 at 67.16.125.60:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport;branch=z9hG4bKNt796ceZ8NQ7S
   Route: <sip:216.115.69.144;lr>
   Route: <sip:216.115.69.133;lr>
   Max-Forwards: 70
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349017 INVITE
   Contact: <sip:gw+flowroute at 111.111.111.111:5080;transport=udp;gw=flowroute>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-b1d1beb 2011-07-18 23-08-16 -0400
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY
   Require: timer
   Supported: timer, precondition, path, replaces
   Session-Expires: 10800;refresher=uas
   Min-SE: 120
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 322
   X-FS-Support: update_display
   Remote-Party-ID: <sip:0000000000 at sip.flowroute.com>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1311342219 1311342221 IN IP4 111.111.111.111
   s=FreeSWITCH
   c=IN IP4 111.111.111.111
   t=0 0
   m=image 27940 udptl t38
   a=T38FaxVersion:0
   a=T38MaxBitRate:14400
   a=T38FaxFillBitRemoval
   a=T38FaxRateManagement:transferredTCF
   a=T38FaxMaxBuffer:2000
   a=T38FaxMaxDatagram:400
   a=T38FaxUdpEC:t38UDPRedundancy
   ------------------------------------------------------------------------
recv 330 bytes from udp/[216.115.69.144]:5060 at 21:29:22.147343:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport=5080;branch=z9hG4bKNt796ceZ8NQ7S
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349017 INVITE
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 338 bytes from udp/[216.115.69.144]:5060 at 21:29:22.170802:
   ------------------------------------------------------------------------
   SIP/2.0 420 Bad Extension
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport=5080;branch=z9hG4bKNt796ceZ8NQ7S
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349017 INVITE
   Unsupported: timer
   
   ------------------------------------------------------------------------
send 446 bytes to udp/[216.115.69.144]:5060 at 21:29:22.171034:
   ------------------------------------------------------------------------
   ACK sip:+11111111111 at 67.16.125.60:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 111.111.111.111:5080;rport;branch=z9hG4bKNt796ceZ8NQ7S
   Route: <sip:216.115.69.144;lr>
   Route: <sip:216.115.69.133;lr>
   Max-Forwards: 70
   From: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   To: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 15349017 ACK
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 1160 bytes from udp/[216.115.69.144]:5060 at 21:29:26.533911:
   ------------------------------------------------------------------------
   INVITE sip:gw+flowroute at 111.111.111.111:5080;transport=udp;gw=flowroute SIP/2.0
   Record-Route: <sip:216.115.69.144;lr>
   Record-Route: <sip:216.115.69.133;lr>
   From: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821;tag=SDvtmh399-gK0a9c4821
   To: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   Via: SIP/2.0/UDP 216.115.69.144;branch=z9hG4bK1dbe.2add7494aaa097ffa4b75892aba82f61.0
   Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bK1dbe.bbcd1cf6f99ecd7a297b5dc33dd676dd.0
   Via: SIP/2.0/UDP 67.16.125.60:5060;branch=z9hG4bKmthalp308g505g83r340sb0000hc3.1
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 4313 INVITE
   Max-Forwards: 67
   Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
   Contact: <sip:+11111111111 at 67.16.125.60:5060;transport=udp>
   Supported: timer,replaces
   Session-Expires: 10800;refresher=uac
   Min-SE: 90
   Content-Length: 172
   Content-Type: application/sdp
   
   v=0
   o=- 3829 19247 IN IP4 67.16.125.60
   s=-
   c=IN IP4 67.16.125.60
   t=0 0
   m=image 50330 udptl t38
   a=T38FaxRateManagement:transferredTCF
   a=T38FaxUdpEC:t38UDPRedundancy
   ------------------------------------------------------------------------
send 688 bytes to udp/[216.115.69.144]:5060 at 21:29:26.534587:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 216.115.69.144;branch=z9hG4bK1dbe.2add7494aaa097ffa4b75892aba82f61.0
   Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bK1dbe.bbcd1cf6f99ecd7a297b5dc33dd676dd.0
   Via: SIP/2.0/UDP 67.16.125.60:5060;branch=z9hG4bKmthalp308g505g83r340sb0000hc3.1
   Record-Route: <sip:216.115.69.144;lr>
   Record-Route: <sip:216.115.69.133;lr>
   From: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821;tag=SDvtmh399-gK0a9c4821
   To: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 4313 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-b1d1beb 2011-07-18 23-08-16 -0400
   Content-Length: 0
   
   ------------------------------------------------------------------------

             - - - - - - - - - - - - - - - - - - - - - - - - -

At this point the fax actually proceeds for a few seconds, but I get a BYE
after about 10 seconds:

             - - - - - - - - - - - - - - - - - - - - - - - - -

recv 708 bytes from udp/[216.115.69.144]:5060 at 21:29:36.285179:
   ------------------------------------------------------------------------
   BYE sip:gw+flowroute at 111.111.111.111:5080;transport=udp;gw=flowroute SIP/2.0
   Record-Route: <sip:216.115.69.144;lr>
   Record-Route: <sip:216.115.69.133;lr>
   From: <sip:11111111111 at sip.flowroute.com>;tag=SDvtmh399-gK0a9c4821;tag=SDvtmh399-gK0a9c4821
   To: "" <sip:XXXX at sip.flowroute.com;transport=udp>;tag=KcKN11gj6arQS
   Via: SIP/2.0/UDP 216.115.69.144;branch=z9hG4bKecbe.d96adce16997b042396d38106987a638.0
   Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bKecbe.75fcc1a3bc1f3a68e4c0241e8b6b0298.0
   Via: SIP/2.0/UDP 67.16.125.60:5060;branch=z9hG4bKmthalp308g505g83r340sd00001d3.1
   Call-ID: 7fe743c9-2f4c-122f-9790-f23c91931894
   CSeq: 4314 BYE
   Max-Forwards: 67
   Content-Length: 0
   
   ------------------------------------------------------------------------
             - - - - - - - - - - - - - - - - - - - - - - - - -




More information about the FreeSWITCH-users mailing list