[Freeswitch-users] SIPp issues - seems FS doesn't understand ACK message

Tihomir Culjaga tculjaga at gmail.com
Mon Aug 24 10:19:01 PDT 2009


Hello,

I've been with freeswittch for a while now.. and i can say it is worth
developing it.

anyhow i got into a strange issue... I'm tryng to see what load FS on my
server can take. The Call flow is like this:

SIPp                   FS

INVITE -------->
           <------- 100 Trying
           <------- 302 Moved Temporary
ACK    --------->



I use a dummy dialplan for that. All custom functions i've build are
disabled and i'm not using it here. Also custom modules are not loaded as
well.


   <extension name="ServiceLookup">
      <condition field="destination_number" expression="(^300030)(.*)">
         <!--action application="lookup_service_destination" data="in
${caller_id_number:6:16}, in ${caller_id_number:0:6}, in $2, i
n $1, in pgw01.ot.hr:5060, out red_contact, out authResult"/-->
         <action application="log" data="INFO ########################
ServiceLookup ########################\n"/>
         <action application="log" data="INFO ########################
contact = '${red_contact}' ##############\n"/>
         <action application="log" data="INFO ########################
CallerNum = '${caller_id_number:6:16}' ##########\n"/>
         <action application="log" data="INFO ########################
RADIUS auth = '${authResult}' ##########\n"/>
         <action application="execute_extension" data="doRedirect XML
public"/>
        </condition>
   </extension>


   <extension name="doRedirect">
      <condition field="destination_number" expression="^doRedirect$"/>
      <condition field="${authResult}" expression="^0$|^60$">
         <action application="log" data="INFO ########################
RADIUS auth OK!!!' ##########\n"/>
         <!--action application="redirect" data="sip:${red_contact}"/-->
         <!--action application="answer"/-->
         <action application="redirect" data="
sip:12345616094191500 at pgw01.ot.hr:5060"/>
         <!--anti-action application="answer"/-->
         <!--anti-action application="sleep" data="2000"/-->
         <action application="hangup" data="USER_BUSY"/>
         <anti-action application="redirect" data="
sip:12345616094191500 at pgw01.ot.hr:5060"/>
         <anti-action application="log" data="INFO ########################
RADIUS auth NOK!! ##########\n"/>
         <!--anti-action application="respond" data="403 Forbidden"/-->
         <anti-action application="hangup" data="USER_BUSY"/>
      </condition>
   </extension>


When i place a call from x-lite everything works fine ... x-lite sends an
invite, gets SIP 302 and ACKs it correctly... FS is happy.

When i place a call from SIPp i have the same scenario except FS seems not
understand ACK message from SIPp and re-sends SIP 302 multiple times untill
it gives up.


I beleive this is due to 302 resend issue but; when i load FS with 100 CPS,
i can see high CPU usage (just one thread taking most load... the rest does
almost nothing) on FS. Also, starting from 40 CPS there is a big delay in
receiving SIP 302 messages meaning i've sent 6000 calls and so far only for
half of them got 302 response.


Does anybody have a clue ?





Here is a trace taken on FS for calls originated from SIPp (sipp -sn uac
10.4.4.251 -sf uac_redirect.xml -s 30003016094191500 -trace_err -r 1 -rp 100
-trace_msg -inf test.txt -m 1 -l 4000):

freeswitch at l01sipindir1> recv 573 bytes from udp/[10.4.4.252]:5060 at
16:44:26.527236:
   ------------------------------------------------------------------------
   INVITE sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>SIP/2.0
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport
   Max-Forwards: 70
   Contact: <sip:22222238515000403 at 10.4.4.252<sip%3A22222238515000403 at 10.4.4.252>
>
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Max-Forwards: 70
   Subject: Performance Test
   Content-Type: application/sdp
   Content-Length:   131

   v=0
   o=user1 53655765 2353687637 IN IP4 10.4.4.252
   s=-
   c=IN IP4 10.4.4.252
   t=0 0
   m=audio 6000 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   ------------------------------------------------------------------------
send 328 bytes to udp/[10.4.4.252]:5060 at 16:44:26.527566:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Content-Length: 0

   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:26.535582:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   To: "30003016094191500"
<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0

   ------------------------------------------------------------------------
recv 383 bytes from udp/[10.4.4.252]:5060 at 16:44:26.535809:
   ------------------------------------------------------------------------
   ACK sip:30003016094191500 at 10.4.4.251:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.4.4.252:5060;branch=z9hG4bK-6962-1-3;rport
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 ACK
   Contact: sip:sipp at 10.4.4.252:5060
   Max-Forwards: 70
   Subject: Performance Test
   Content-Length: 0

   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:27.037070:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   To: "30003016094191500"
<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0

   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:28.037063:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251<sip%3A22222238515000403 at 10.4.4.251>
>;tag=1
   To: "30003016094191500"
<sip:30003016094191500 at 10.4.4.251<sip%3A30003016094191500 at 10.4.4.251>
>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE,
NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0


Tihomir.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20090824/ef7ebc73/attachment-0002.html 
-------------- next part --------------
freeswitch at l01sipindir1> recv 573 bytes from udp/[10.4.4.252]:5060 at 16:44:26.527236:
   ------------------------------------------------------------------------
   INVITE sip:30003016094191500 at 10.4.4.251 SIP/2.0
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport
   Max-Forwards: 70
   Contact: <sip:22222238515000403 at 10.4.4.252>
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Max-Forwards: 70
   Subject: Performance Test
   Content-Type: application/sdp
   Content-Length:   131
   
   v=0
   o=user1 53655765 2353687637 IN IP4 10.4.4.252
   s=-
   c=IN IP4 10.4.4.252
   t=0 0
   m=audio 6000 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   ------------------------------------------------------------------------
send 328 bytes to udp/[10.4.4.252]:5060 at 16:44:26.527566:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:44:26.525364 [NOTICE] switch_channel.c:602 New Channel sofia/internal/22222238515000403 at 10.4.4.251 [62a395f8-90cd-11de-99d5-cb0c6bd8522b]
2009-08-24 18:44:26.533096 [INFO] mod_dialplan_xml.c:315 Processing 22222238515000403->30003016094191500 in context public
2009-08-24 18:44:26.533096 [INFO] mod_dptools.c:932 ######################## ServiceLookup ########################\n
2009-08-24 18:44:26.533096 [INFO] mod_dptools.c:932 ######################## contact = '' ##############\n
2009-08-24 18:44:26.533096 [INFO] mod_dptools.c:932 ######################## CallerNum = '38515000403' ##########\n
2009-08-24 18:44:26.533096 [INFO] mod_dptools.c:932 ######################## RADIUS auth = '' ##########\n
2009-08-24 18:44:26.533096 [INFO] mod_dialplan_xml.c:315 Processing 22222238515000403->doRedirect in context public
2009-08-24 18:44:26.533096 [NOTICE] switch_core_session.c:1576 Execute redirect(sip:12345616094191500 at pgw01.ot.hr:5060)
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:26.535582:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 383 bytes from udp/[10.4.4.252]:5060 at 16:44:26.535809:
   ------------------------------------------------------------------------
   ACK sip:30003016094191500 at 10.4.4.251:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.4.4.252:5060;branch=z9hG4bK-6962-1-3;rport
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 ACK
   Contact: sip:sipp at 10.4.4.252:5060
   Max-Forwards: 70
   Subject: Performance Test
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:44:26.533096 [NOTICE] sofia.c:3863 Hangup sofia/internal/22222238515000403 at 10.4.4.251 [CS_EXECUTE] [NORMAL_UNSPECIFIED]
2009-08-24 18:44:26.537029 [NOTICE] switch_core_session.c:1086 Session 3 (sofia/internal/22222238515000403 at 10.4.4.251) Ended
2009-08-24 18:44:26.537029 [NOTICE] switch_core_session.c:1088 Close Channel sofia/internal/22222238515000403 at 10.4.4.251 [CS_DESTROY]
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:27.037070:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:28.037063:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:30.037065:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:34.037063:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:38.037068:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:42.037064:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:46.037064:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:50.037066:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:54.037067:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 722 bytes to udp/[10.4.4.252]:5060 at 16:44:58.037067:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.4.4.252;branch=z9hG4bK-6962-1-0;rport=5060
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=1
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=Hr4mHDUeBSNyH
   Call-ID: 1-6962 at 10.4.4.252
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
-------------- next part --------------
freeswitch at l01sipindir1> 
freeswitch at l01sipindir1> 
freeswitch at l01sipindir1> recv 855 bytes from udp/[10.1.14.30]:27454 at 16:42:56.522659:
   ------------------------------------------------------------------------
   INVITE sip:30003016094191500 at 10.4.4.251 SIP/2.0
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-b9056b2ac55b4e54-1---d8754z-;rport
   Max-Forwards: 70
   Contact: <sip:22222238515000403 at 10.1.14.30:27454>
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 1 INVITE
   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
   Content-Type: application/sdp
   User-Agent: X-Lite release 1103k stamp 53621
   Content-Length: 258
   
   v=0
   o=- 0 2 IN IP4 10.1.14.30
   s=CounterPath X-Lite 3.0
   c=IN IP4 10.1.14.30
   t=0 0
   m=audio 44488 RTP/AVP 107 0 8 101
   a=alt:1 1 : 5KgV8ECY o9MWrE7h 10.1.14.30 44488
   a=fmtp:101 0-15
   a=rtpmap:107 BV32/16000
   a=rtpmap:101 telephone-event/8000
   a=sendrecv
   ------------------------------------------------------------------------
send 396 bytes to udp/[10.1.14.30]:27454 at 16:42:56.523076:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-b9056b2ac55b4e54-1---d8754z-;rport=27454
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:42:56.521041 [NOTICE] switch_channel.c:602 New Channel sofia/internal/22222238515000403 at 10.4.4.251 [2cfdfdbc-90cd-11de-99d5-cb0c6bd8522b]
2009-08-24 18:42:56.529053 [CONSOLE] sofia_presence.c:680 Event Thread Started
2009-08-24 18:42:56.529053 [INFO] mod_dialplan_xml.c:315 Processing 22222238515000403->30003016094191500 in context public
2009-08-24 18:42:56.529053 [INFO] mod_dptools.c:932 ######################## ServiceLookup ########################\n
2009-08-24 18:42:56.529053 [INFO] mod_dptools.c:932 ######################## contact = '' ##############\n
2009-08-24 18:42:56.529053 [INFO] mod_dptools.c:932 ######################## CallerNum = '38515000403' ##########\n
2009-08-24 18:42:56.529053 [INFO] mod_dptools.c:932 ######################## RADIUS auth = '' ##########\n
2009-08-24 18:42:56.529053 [INFO] mod_dialplan_xml.c:315 Processing 22222238515000403->doRedirect in context public
2009-08-24 18:42:56.529053 [NOTICE] switch_core_session.c:1576 Execute redirect(sip:12345616094191500 at pgw01.ot.hr:5060)
send 790 bytes to udp/[10.1.14.30]:27454 at 16:42:56.531535:
   ------------------------------------------------------------------------
   SIP/2.0 302 Moved Temporarily
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-b9056b2ac55b4e54-1---d8754z-;rport=27454
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=F6H3DQS7g78ra
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 1 INVITE
   Contact: <sip:12345616094191500 at pgw01.ot.hr:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces2009-08-24 18:42:56.529053 [NOTICE] switch_core_session.c:1576 Execute log(INFO ######################## RADIUS auth NOK!! ##########\n)

   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:42:56.529053 [NOTICE] sofia.c:3863 Hangup sofia/internal/22222238515000403 at 10.4.4.251 [CS_EXECUTE] [NORMAL_UNSPECIFIED]
2009-08-24 18:42:56.529053 [INFO] mod_dptools.c:932 ######################## RADIUS auth NOK!! ##########\n
2009-08-24 18:42:56.529053 [NOTICE] switch_core_session.c:1086 Session 1 (sofia/internal/22222238515000403 at 10.4.4.251) Ended
2009-08-24 18:42:56.529053 [NOTICE] switch_core_session.c:1088 Close Channel sofia/internal/22222238515000403 at 10.4.4.251 [CS_DESTROY]
recv 379 bytes from udp/[10.1.14.30]:27454 at 16:42:56.533966:
   ------------------------------------------------------------------------
   ACK sip:30003016094191500 at 10.4.4.251 SIP/2.0
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-b9056b2ac55b4e54-1---d8754z-;rport
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=F6H3DQS7g78ra
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 1 ACK
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 861 bytes from udp/[10.1.14.30]:27454 at 16:42:56.638930:
   ------------------------------------------------------------------------
   INVITE sip:12345616094191500 at pgw01.ot.hr:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-213d2e12ad57b353-1---d8754z-;rport
   Max-Forwards: 70
   Contact: <sip:22222238515000403 at 10.1.14.30:27454>
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 2 INVITE
   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
   Content-Type: application/sdp
   User-Agent: X-Lite release 1103k stamp 53621
   Content-Length: 258
   
   v=0
   o=- 0 2 IN IP4 10.1.14.30
   s=CounterPath X-Lite 3.0
   c=IN IP4 10.1.14.30
   t=0 0
   m=audio 44488 RTP/AVP 107 0 8 101
   a=alt:1 1 : 5KgV8ECY o9MWrE7h 10.1.14.30 44488
   a=fmtp:101 0-15
   a=rtpmap:107 BV32/16000
   a=rtpmap:101 telephone-event/8000
   a=sendrecv
   ------------------------------------------------------------------------
send 396 bytes to udp/[10.1.14.30]:27454 at 16:42:56.639220:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-213d2e12ad57b353-1---d8754z-;rport=27454
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   To: "30003016094191500"<sip:30003016094191500 at 10.4.4.251>
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 2 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:42:56.637047 [NOTICE] switch_channel.c:602 New Channel sofia/internal/22222238515000403 at 10.4.4.251 [2d0fb3fe-90cd-11de-99d5-cb0c6bd8522b]
2009-08-24 18:42:56.641071 [INFO] mod_dialplan_xml.c:315 Processing 22222238515000403->12345616094191500 in context public
2009-08-24 18:42:56.641071 [INFO] switch_core_state_machine.c:136 No Route, Aborting
2009-08-24 18:42:56.641071 [NOTICE] switch_core_state_machine.c:137 Hangup sofia/internal/22222238515000403 at 10.4.4.251 [CS_ROUTING] [NO_ROUTE_DESTINATION]
send 782 bytes to udp/[10.1.14.30]:27454 at 16:42:56.642591:
   ------------------------------------------------------------------------
   SIP/2.0 404 Not Found
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-213d2e12ad57b353-1---d8754z-;rport=27454
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=gFBvFjaBegZBp
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 2 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-exported
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Reason: Q.850;cause=3;text="NO_ROUTE_DESTINATION"
   Content-Length: 0
   
   ------------------------------------------------------------------------
2009-08-24 18:42:56.641071 [NOTICE] switch_core_session.c:1086 Session 2 (sofia/internal/22222238515000403 at 10.4.4.251) Ended
2009-08-24 18:42:56.641071 [NOTICE] switch_core_session.c:1088 Close Channel sofia/internal/22222238515000403 at 10.4.4.251 [CS_DESTROY]
recv 385 bytes from udp/[10.1.14.30]:27454 at 16:42:56.646734:
   ------------------------------------------------------------------------
   ACK sip:12345616094191500 at pgw01.ot.hr:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.1.14.30:27454;branch=z9hG4bK-d8754z-213d2e12ad57b353-1---d8754z-;rport
   To: "30003016094191500" <sip:30003016094191500 at 10.4.4.251>;tag=gFBvFjaBegZBp
   From: "22222238515000403"<sip:22222238515000403 at 10.4.4.251>;tag=a669bf79
   Call-ID: ZjBmNWQwN2EzZjNmZmM0MzUxMDRlMTkyNjM2MzQ2MTc.
   CSeq: 2 ACK
   Content-Length: 0
   
   ------------------------------------------------------------------------
-------------- next part --------------
A non-text attachment was scrubbed...
Name: uac_redirect.xml
Type: text/xml
Size: 3927 bytes
Desc: not available
Url : http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20090824/ef7ebc73/attachment-0002.xml 
-------------- next part --------------
SEQUENTIAL
22222238515000403;22222238515000403


More information about the FreeSWITCH-users mailing list