[Freeswitch-users] Call Dropping

18 Jun 2017

      Hi Guys

Using FreeSwitch with Radius linked to JeraSoft VCS billing system. 

I am sending a Call from a SIPP originator, through the FreeSwitch box and back out to another SIPP terminator scenario.
The call goes through ok, everything happens as it should, however the call immediately drops, I have done egrep’s of both sides of the call and the BYE is defiantly coming from Freeswitch for some reason but I cannot work out why. Anyone any ideas?
I am attaching the FreeSwitch logs plus the egrep’s
If I register zipper on my laptop to FS and make a call works fine.

2017-06-18 22:26:34.199519 [NOTICE] switch_channel.c:1104 New Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [15021010-8f64-439f-8dbb-1afe090c44a5]
2017-06-18 22:26:34.199519 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_NEW (Cur 1 Tot 67)
2017-06-18 22:26:34.199519 [DEBUG] sofia.c:9837 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 receiving invite from 185.35.228.51:5060 version: 1.6.18 git 6e79667 2017-06-12 21:14:49Z 64bit
2017-06-18 22:26:34.219492 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 entering state [received][100]
2017-06-18 22:26:34.219492 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=user1 53655765 2353687637 IN IP4 185.35.228.51
s=-
c=IN IP4 185.35.228.51
t=0 0
m=audio 6000 RTP/AVP 0
a=rtpmap:0 PCMU/8000

2017-06-18 22:26:34.219492 [DEBUG] sofia.c:7450 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State Change CS_NEW -> CS_INIT
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:603 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State NEW
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_INIT (Cur 1 Tot 67)
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State INIT
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:90 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 SOFIA INIT
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:40 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard INIT
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:48 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State Change CS_INIT -> CS_ROUTING
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State INIT going to sleep
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_ROUTING (Cur 1 Tot 67)
2017-06-18 22:26:34.219492 [DEBUG] switch_channel.c:2249 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Callstate Change DOWN -> RINGING
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State ROUTING
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:143 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 SOFIA ROUTING
2017-06-18 22:26:34.219492 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.228.40 == ^185\.35\.229\.30 
2017-06-18 22:26:34.219492 [INFO] mod_xml_radius.c:986 mod_xml_radius:  Accounting Start success
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:236 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard ROUTING
2017-06-18 22:26:34.219492 [INFO] mod_dialplan_xml.c:637 Processing sipp <sipp>->441554555666 in context public
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->unloop] continue=false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->outside_call] continue=true
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Absolute Condition [outside_call]
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(outside_call=true) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->call_debug] continue=true
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->rejections] continue=false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (FAIL) [rejections] ${radius_auth_result}() =~ /2/ break=on-false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->timedouts] continue=false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (FAIL) [timedouts] ${radius_auth_result}() =~ /1/ break=on-false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 parsing [public->JeraSoft VCS Routing] continue=false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Regex (PASS) [JeraSoft VCS Routing] destination_number(441554555666) =~ /^(.+)$/ break=on-false
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action export(nolocal:h323-call-origin=originate) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(sip_h_X-accountcode=${accountcode}) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(call_direction=outbound) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(hangup_after_bridge=true) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(continue_on_fail=true) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(inherit_codec=true) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(call_timeout=20) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(fail_on_single_reject=USER_BUSY) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(origination_caller_id_name=${sip_req_user}) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(origination_caller_id_number=${sip_from_user}) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action set(execute_on_answer=sched_hangup +${h323-credit-time} alloted_timeout) 
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action bridge({sip_invite_from_uri=sip:${sip_from_user}@${sip_network_ip}}sofia/external/${destination_number}@185.35.229.30:5060)
Dialplan: sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Action hangup(${bridge_hangup_cause}) 
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:286 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State Change CS_ROUTING -> CS_EXECUTE
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State ROUTING going to sleep
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_EXECUTE (Cur 1 Tot 67)
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State EXECUTE
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:198 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 SOFIA EXECUTE
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:328 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard EXECUTE
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(outside_call=true)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [outside_call]=[true]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 export(RFC2822_DATE=Sun, 18 Jun 2017 22:26:34 +0100)
2017-06-18 22:26:34.219492 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sun, 18 Jun 2017 22:26:34 +0100]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 export(nolocal:h323-call-origin=originate)
2017-06-18 22:26:34.219492 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [h323-call-origin]=[originate]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(sip_h_X-accountcode=)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [sip_h_X-accountcode]=[UNDEF]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(call_direction=outbound)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [call_direction]=[outbound]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(hangup_after_bridge=true)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [hangup_after_bridge]=[true]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(continue_on_fail=true)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [continue_on_fail]=[true]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(inherit_codec=true)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [inherit_codec]=[true]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(call_timeout=20)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [call_timeout]=[20]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(fail_on_single_reject=USER_BUSY)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [fail_on_single_reject]=[USER_BUSY]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(origination_caller_id_name=441554555666)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [origination_caller_id_name]=[441554555666]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(origination_caller_id_number=sipp)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [origination_caller_id_number]=[sipp]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 set(execute_on_answer=sched_hangup + alloted_timeout)
2017-06-18 22:26:34.219492 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [execute_on_answer]=[sched_hangup + alloted_timeout]
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 bridge({sip_invite_from_uri=sip:sipp@185.35.228.51}sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060)
2017-06-18 22:26:34.219492 [DEBUG] switch_channel.c:1250 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Sun, 18 Jun 2017 22:26:34 +0100] to event
2017-06-18 22:26:34.219492 [DEBUG] switch_channel.c:1250 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 EXPORTING[export_vars] [h323-call-origin]=[originate] to event
2017-06-18 22:26:34.219492 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-18 22:26:34.219492 [NOTICE] switch_channel.c:1104 New Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 [96c1a021-5195-41ce-b903-08b98816d70d]
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:4819 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State Change CS_NEW -> CS_INIT
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_INIT (Cur 2 Tot 68)
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:627 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State INIT
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:90 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 SOFIA INIT
2017-06-18 22:26:34.219492 [DEBUG] sofia_glue.c:1295 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 sending invite version: 1.6.18 git 6e79667 2017-06-12 21:14:49Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1497789362 1497789363 IN IP4 185.35.228.40
s=FreeSWITCH
c=IN IP4 185.35.228.40
t=0 0
m=audio 31832 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:40 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Standard INIT
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:48 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State Change CS_INIT -> CS_ROUTING
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:627 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State INIT going to sleep
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_ROUTING (Cur 2 Tot 68)
2017-06-18 22:26:34.219492 [DEBUG] sofia.c:7048 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 entering state [calling][0]
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:643 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State ROUTING
2017-06-18 22:26:34.219492 [DEBUG] mod_sofia.c:143 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 SOFIA ROUTING
2017-06-18 22:26:34.219492 [DEBUG] switch_ivr_originate.c:67 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-06-18 22:26:34.219492 [ERR] mod_xml_radius.c:930 Didn't match: 185.35.229.30:5060 == ^185\.35\.229\.30 
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:643 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State ROUTING going to sleep
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:584 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 68)
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:662 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State CONSUME_MEDIA
2017-06-18 22:26:34.219492 [DEBUG] switch_core_state_machine.c:662 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State CONSUME_MEDIA going to sleep
2017-06-18 22:26:34.259480 [DEBUG] sofia_glue.c:1295 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 sending invite version: 1.6.18 git 6e79667 2017-06-12 21:14:49Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1497789362 1497789364 IN IP4 185.35.228.40
s=FreeSWITCH
c=IN IP4 185.35.228.40
t=0 0
m=audio 31832 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2017-06-18 22:26:34.259480 [DEBUG] sofia.c:7048 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 entering state [calling][0]
2017-06-18 22:26:34.259480 [DEBUG] sofia.c:7048 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 entering state [proceeding][180]
2017-06-18 22:26:34.259480 [NOTICE] sofia.c:7156 Ring-Ready sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060!
2017-06-18 22:26:34.259480 [DEBUG] switch_channel.c:3346 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Callstate Change DOWN -> RINGING
2017-06-18 22:26:34.259480 [DEBUG] sofia.c:7048 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 entering state [completing][200]
2017-06-18 22:26:34.259480 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=user1 53655765 2353687637 IN IP4 185.35.228.48
s=-
c=IN IP4 185.35.228.48
t=0 0
m=audio 6000 RTP/AVP 0
a=rtpmap:0 PCMU/8000

2017-06-18 22:26:34.259480 [DEBUG] sofia.c:7048 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 entering state [ready][200]
2017-06-18 22:26:34.259480 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-06-18 22:26:34.259480 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-06-18 22:26:34.259480 [DEBUG] switch_core_media.c:3057 Set Codec sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-06-18 22:26:34.259480 [DEBUG] switch_core_codec.c:111 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Original read codec set to PCMU:0
2017-06-18 22:26:34.259480 [DEBUG] switch_core_media.c:4770 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
2017-06-18 22:26:34.259480 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060] 185.35.228.40 port 31832 -> 185.35.228.48 port 6000 codec: 0 ms: 20
2017-06-18 22:26:34.259480 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:7205 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Set rtp dtmf delay to 40
2017-06-18 22:26:34.279530 [NOTICE] sofia.c:8182 Channel [sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060] has been answered
2017-06-18 22:26:34.279530 [DEBUG] switch_channel.c:3773 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Callstate Change RINGING -> ACTIVE
2017-06-18 22:26:34.279530 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060!
2017-06-18 22:26:34.279530 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 entering state [early][180]
2017-06-18 22:26:34.279530 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060!
2017-06-18 22:26:34.279530 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 to PCMU@8000h@20i
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:3057 Set Codec sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-06-18 22:26:34.279530 [DEBUG] switch_core_codec.c:111 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Original read codec set to PCMU:0
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:4770 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060] 185.35.228.40 port 23728 -> 185.35.228.51 port 6000 codec: 0 ms: 20
2017-06-18 22:26:34.279530 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:7205 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Set rtp dtmf delay to 40
2017-06-18 22:26:34.279530 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060!
2017-06-18 22:26:34.279530 [DEBUG] switch_channel.c:3474 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Callstate Change RINGING -> EARLY
2017-06-18 22:26:34.279530 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060.
2017-06-18 22:26:34.279530 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060:
v=0
o=FreeSWITCH 1497797466 1497797467 IN IP4 185.35.228.40
s=FreeSWITCH
c=IN IP4 185.35.228.40
t=0 0
m=audio 23728 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=sendrecv

2017-06-18 22:26:34.279530 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060] has been answered
EXECUTE sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 sched_hangup(+ alloted_timeout)
2017-06-18 22:26:34.279530 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 entering state [completed][200]
2017-06-18 22:26:34.279530 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 entering state [ready][200]
2017-06-18 22:26:34.279530 [NOTICE] mod_dptools.c:1188 Hangup sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2017-06-18 22:26:34.279530 [DEBUG] switch_core_session.c:2814 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-06-18 22:26:34.279530 [DEBUG] switch_channel.c:3773 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Callstate Change EARLY -> ACTIVE
2017-06-18 22:26:34.279530 [DEBUG] switch_ivr_originate.c:3647 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 skip receive message [ANSWER_EVENT] (channel is hungup already)
2017-06-18 22:26:34.319525 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
2017-06-18 22:26:34.319525 [NOTICE] switch_ivr_originate.c:3938 Hangup sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:584 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_HANGUP (Cur 2 Tot 68)
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:850 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Callstate Change ACTIVE -> HANGUP
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:852 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State HANGUP
2017-06-18 22:26:34.319525 [DEBUG] mod_sofia.c:438 Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 hanging up, cause: ORIGINATOR_CANCEL
2017-06-18 22:26:34.319525 [INFO] mod_dptools.c:3418 Originate Failed.  Cause: ORIGINATOR_CANCEL
2017-06-18 22:26:34.319525 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:60 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:852 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State HANGUP going to sleep
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:619 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State Change CS_HANGUP -> CS_REPORTING
2017-06-18 22:26:34.319525 [DEBUG] switch_core_session.c:2814 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-06-18 22:26:34.319525 [DEBUG] switch_core_state_machine.c:584 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_REPORTING (Cur 2 Tot 68)
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State EXECUTE going to sleep
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_HANGUP (Cur 2 Tot 68)
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:938 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State REPORTING
2017-06-18 22:26:34.339569 [ERR] mod_xml_radius.c:930 Didn't match: 185.35.229.30 == ^185\.35\.229\.30 
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:850 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Callstate Change ACTIVE -> HANGUP
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:174 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:938 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State REPORTING going to sleep
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State HANGUP
2017-06-18 22:26:34.339569 [DEBUG] mod_sofia.c:438 Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 hanging up, cause: NORMAL_CLEARING
2017-06-18 22:26:34.339569 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:60 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard HANGUP, cause: NORMAL_CLEARING
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State HANGUP going to sleep
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:619 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State Change CS_HANGUP -> CS_REPORTING
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_REPORTING (Cur 2 Tot 68)
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State REPORTING
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:610 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State Change CS_REPORTING -> CS_DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_session.c:1664 Session 68 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Locked, Waiting on external entities
2017-06-18 22:26:34.339569 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.228.40 == ^185\.35\.229\.30 
2017-06-18 22:26:34.339569 [NOTICE] switch_core_session.c:1682 Session 68 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Ended
2017-06-18 22:26:34.339569 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 [CS_DESTROY]
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:741 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) Running State Change CS_DESTROY (Cur 1 Tot 68)
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:751 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State DESTROY
2017-06-18 22:26:34.339569 [DEBUG] mod_sofia.c:343 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 SOFIA DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:181 sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060 Standard DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:751 (sofia/external/441554555666@185.35.229.30 <mailto:sofia/external/441554555666@185.35.229.30>:5060) State DESTROY going to sleep
2017-06-18 22:26:34.339569 [INFO] mod_xml_radius.c:1044 mod_xml_radius:  Accounting Stop success
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:174 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard REPORTING, cause: NORMAL_CLEARING
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State REPORTING going to sleep
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:610 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State Change CS_REPORTING -> CS_DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_session.c:1664 Session 67 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Locked, Waiting on external entiti
2017-06-18 22:26:34.339569 [NOTICE] switch_core_session.c:1682 Session 67 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Ended
2017-06-18 22:26:34.339569 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 [CS_DESTROY]
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:741 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) Running State Change CS_DESTROY (Cur 0 Tot 68)
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State DESTROY
2017-06-18 22:26:34.339569 [DEBUG] mod_sofia.c:343 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 SOFIA DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:181 sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060 Standard DESTROY
2017-06-18 22:26:34.339569 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@185.35.228.51 <mailto:sofia/external/sipp@185.35.228.51>:5060) State DESTROY going to sleep

U 185.35.228.51:5060 -> 185.35.228.40:5080
INVITE sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080> SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.51:5060;branch=z9hG4bK-27036-1-0.
From: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
To: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 1 INVITE.
Contact: sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>.
Max-Forwards: 70.
Subject: Performance Test.
Content-Type: application/sdp.
Content-Length:   137.
.
v=0.
o=user1 53655765 2353687637 IN IP4 185.35.228.51.
s=-.
c=IN IP4 185.35.228.51.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.

#
U 185.35.228.40:5080 -> 185.35.228.51:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 185.35.228.51:5060;branch=z9hG4bK-27036-1-0.
From: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
To: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 1 INVITE.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Content-Length: 0.
.

#
U 185.35.228.40:5080 -> 185.35.228.51:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 185.35.228.51:5060;branch=z9hG4bK-27036-1-0.
From: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
To: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>;tag=91vp8601aS4Qp.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 1 INVITE.
Contact: <sip:441554555666@185.35.228.40:5080;transport=udp <sip:441554555666@185.35.228.40:5080;transport=udp>>.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Accept: application/sdp.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, refer.
Content-Length: 0.
Remote-Party-ID: "Outbound Call" <sip:441554555666@185.35.228.40 <sip:441554555666@185.35.228.40>>;party=calling;privacy=off;screen=no.
.

#
U 185.35.228.40:5080 -> 185.35.228.51:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 185.35.228.51:5060;branch=z9hG4bK-27036-1-0.
From: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
To: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>;tag=91vp8601aS4Qp.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 1 INVITE.
Contact: <sip:441554555666@185.35.228.40:5080;transport=udp <sip:441554555666@185.35.228.40:5080;transport=udp>>.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 166.
Remote-Party-ID: "Outbound Call" <sip:441554555666@185.35.228.40 <sip:441554555666@185.35.228.40>>;party=calling;privacy=off;screen=no.
.
v=0.
o=FreeSWITCH 1497797499 1497797500 IN IP4 185.35.228.40.
s=FreeSWITCH.
c=IN IP4 185.35.228.40.
t=0 0.
m=audio 25252 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.
a=ptime:20.

#
U 185.35.228.51:5060 -> 185.35.228.40:5080
ACK sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080> SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.51:5060;branch=z9hG4bK-27036-1-5.
From: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
To: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>;tag=91vp8601aS4Qp.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 1 ACK.
Contact: sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>.
Max-Forwards: 70.
Subject: Performance Test.
Content-Length: 0.
.

#
U 185.35.228.40:5080 -> 185.35.228.51:5060
BYE sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060> SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKUBe0HvDjHF1XN.
Max-Forwards: 70.
From: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>;tag=91vp8601aS4Qp.
To: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 108575311 BYE.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Supported: timer, path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.

#
U 185.35.228.51:5060 -> 185.35.228.40:5080
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKUBe0HvDjHF1XN.
From: 441554555666 <sip:441554555666@185.35.228.40:5080 <sip:441554555666@185.35.228.40:5080>>;tag=91vp8601aS4Qp.
To: sipp <sip:sipp@185.35.228.51:5060 <sip:sipp@185.35.228.51:5060>>;tag=27036SIPpTag001.
Call-ID: 1-27036@185.35.228.51 <mailto:1-27036@185.35.228.51>.
CSeq: 108575311 BYE.
Contact: <sip:185.35.228.51:5060;transport=UDP <sip:185.35.228.51:5060;transport=UDP>>.
Content-Length: 0.

NGREP of SIP messages from FS to terminator

U 185.35.228.40:5080 -> 185.35.228.48:5060
INVITE sip:441554555666@185.35.228.48:5060 SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKXX0HNjFSB1D3c.
Max-Forwards: 69.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575420 INVITE.
Contact: <sip:mod_sofia@185.35.228.40:5080>.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Supported: timer, path, replaces.
Allow-Events: talk, hold, conference, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 222.
X-FS-Support: update_display,send_info.
Remote-Party-ID: "sipp" <sip:sipp@185.35.228.40>;party=calling;screen=yes;privacy=off.
.
v=0.
o=FreeSWITCH 1497801741 1497801743 IN IP4 185.35.228.40.
s=FreeSWITCH.
c=IN IP4 185.35.228.40.
t=0 0.
m=audio 21228 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.

#
U 185.35.228.48:5060 -> 185.35.228.40:5080
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKXX0HNjFSB1D3c.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>;tag=31480SIPpTag018.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575420 INVITE.
Contact: <sip:185.35.228.48:5060;transport=UDP>.
Content-Length: 0.
.

#
U 185.35.228.48:5060 -> 185.35.228.40:5080
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKXX0HNjFSB1D3c.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>;tag=31480SIPpTag018.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575420 INVITE.
Contact: <sip:185.35.228.48:5060;transport=UDP>.
Content-Type: application/sdp.
Content-Length:   137.
.
v=0.
o=user1 53655765 2353687637 IN IP4 185.35.228.48.
s=-.
c=IN IP4 185.35.228.48.
t=0 0.
m=audio 6000 RTP/AVP 0.
a=rtpmap:0 PCMU/8000.

#
U 185.35.228.40:5080 -> 185.35.228.48:5060
ACK sip:185.35.228.48:5060;transport=UDP SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKy6SaQD0v893Nr.
Max-Forwards: 70.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>;tag=31480SIPpTag018.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575420 ACK.
Contact: <sip:mod_sofia@185.35.228.40:5080>.
Content-Length: 0.
.

#
U 185.35.228.40:5080 -> 185.35.228.48:5060
BYE sip:185.35.228.48:5060;transport=UDP SIP/2.0.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKZFK3r8g05jt8K.
Max-Forwards: 70.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>;tag=31480SIPpTag018.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575421 BYE.
User-Agent: FreeSWITCH-mod_sofia/1.6.18+git~20170612T211449Z~6e79667c0a~64bit.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Supported: timer, path, replaces.
Reason: SIP;cause=487;text="ORIGINATOR_CANCEL".
Content-Length: 0.
.

#
U 185.35.228.48:5060 -> 185.35.228.40:5080
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 185.35.228.40:5080;rport;branch=z9hG4bKZFK3r8g05jt8K.
From: "sipp" <sip:sipp@185.35.228.51>;tag=eFUjHeNKv5KNg.
To: <sip:441554555666@185.35.229.30:5060>;tag=31480SIPpTag018.
Call-ID: c755e7c8-cf13-1235-25a9-363165383663.
CSeq: 108575421 BYE.
Contact: <sip:185.35.228.48:5060;transport=UDP>.
Content-Length: 0.
.

[Freeswitch-users] Call Dropping

Joseph Waite