Team, I need the originator caller ID to be maintained during the entire call session. I have pasted the config and traces below : Gateway Config Dial plan config Issue : Scenario: I receive a call from CUCM , the IVR script in the freeswitch processes  the call and sends it back to CUCM , the originator caller ID has to be maintained during the entire session .... but I get the caller ID as the IVR extn of freeswitch. Below is the trace for the test call Test call : Call made by CUCM extn 3097(cucm) to 5559(freeswitch IVR extn) freeswitch plays the IVR and transfers the call to extn 3003(CUCM Extn) in 3003 i get the caller ID as 5559 but i want the calller ID to be 3097 recv 1543 bytes from udp/[192.168.168.211]:5080 at 16:19:42.410561: ------------------------------------------------------------------------ INVITE sip:5559@192.168.168.99:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814 From: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 To: Date: Thu, 22 Feb 2018 10:49:43 GMT Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 Supported: timer,resource-priority,replaces Min-SE: 1800 User-Agent: Cisco-CUCM11.5 Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY CSeq: 101 INVITE Expires: 180 Allow-Events: presence, kpml Supported: X-cisco-srtp-fallback,X-cisco-original-called Call-Info: ;method="NOTIFY;Event=telephone-event;Duration=500" Session-ID: 000033c100105000a000b888e3e4db15;remote=00000000000000000000000000000000 Cisco-Guid: 0363528960-0000065536-0000000226-3551045824 P-Charging-Vector: icid-value="15AB030000010000000000E1D3A8A8C0";icid-generated-at=tacucmpub;orig-ioi="IMS Inter Operator Identification" Session-Expires: 1800 P-Asserted-Identity: "User3" Remote-Party-ID: "User3" ;party=calling;screen=yes;privacy=off Contact: ;+u.sip!devicename.ccm.cisco.com="jabber4";bfcp Max-Forwards: 69 Content-Type: application/sdp Content-Length: 207 v=0 o=CiscoSystemsCCM-SIP 18740 1 IN IP4 192.168.168.211 s=SIP Call c=IN IP4 192.168.168.211 t=0 0 m=audio 25252 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ------------------------------------------------------------------------ send 391 bytes to udp/[192.168.168.211]:5080 at 16:19:42.410982: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814 From: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 To: Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 CSeq: 101 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit Content-Length: 0 ------------------------------------------------------------------------ 2018-02-22 16:19:42.410742 [NOTICE] switch_channel.c:1104 New Channel sofia/external/3097@192.168.168.211 [f92a2dd5-39e7-4aae-b02d-26803d77593a] 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_NEW (Cur 1 Tot 356) 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:9834 sofia/external/3097@192.168.168.211 receiving invite from 192.168.168.211:5080 version: 1.6.17 git f17ac2f 2017-05-26 22:41:25Z 32bit 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [received][100] 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=CiscoSystemsCCM-SIP 18740 1 IN IP4 192.168.168.211 s=SIP Call c=IN IP4 192.168.168.211 t=0 0 m=audio 25252 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7450 (sofia/external/3097@192.168.168.211) State Change CS_NEW -> CS_INIT 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:603 (sofia/external/3097@192.168.168.211) State NEW 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_INIT (Cur 1 Tot 356) 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3097@192.168.168.211) State INIT 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:90 sofia/external/3097@192.168.168.211 SOFIA INIT 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:40 sofia/external/3097@192.168.168.211 Standard INIT 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:48 (sofia/external/3097@192.168.168.211) State Change CS_INIT -> CS_ROUTING 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3097@192.168.168.211) State INIT going to sleep 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_ROUTING (Cur 1 Tot 356) 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:2249 (sofia/external/3097@192.168.168.211) Callstate Change DOWN -> RINGING 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3097@192.168.168.211) State ROUTING 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:143 sofia/external/3097@192.168.168.211 SOFIA ROUTING 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:236 sofia/external/3097@192.168.168.211 Standard ROUTING 2018-02-22 16:19:42.410742 [INFO] mod_dialplan_xml.c:637 Processing User3 <3097>->5559 in context public Dialplan: sofia/external/3097@192.168.168.211 parsing [public->unloop] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outside_call] continue=true Dialplan: sofia/external/3097@192.168.168.211 Absolute Condition [outside_call] Dialplan: sofia/external/3097@192.168.168.211 Action set(outside_call=true) Dialplan: sofia/external/3097@192.168.168.211 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/3097@192.168.168.211 parsing [public->call_debug] continue=true Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_extensions] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_extensions] destination_number(5559) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_did] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_did] destination_number(5559) =~ /^(38013801)$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->5559] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [5559] destination_number(5559) =~ /5559$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_number=5551231234) Dialplan: sofia/external/3097@192.168.168.211 Action javascript(/usr/local/freeswitch/scripts/Transfer_test_1.js) 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:286 (sofia/external/3097@192.168.168.211) State Change CS_ROUTING -> CS_EXECUTE 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3097@192.168.168.211) State ROUTING going to sleep 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_EXECUTE (Cur 1 Tot 356) 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:650 (sofia/external/3097@192.168.168.211) State EXECUTE 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:198 sofia/external/3097@192.168.168.211 SOFIA EXECUTE 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:328 sofia/external/3097@192.168.168.211 Standard EXECUTE EXECUTE sofia/external/3097@192.168.168.211 set(outside_call=true) 2018-02-22 16:19:42.410742 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [outside_call]=[true] EXECUTE sofia/external/3097@192.168.168.211 export(RFC2822_DATE=Thu, 22 Feb 2018 16:19:42 +0530) 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 22 Feb 2018 16:19:42 +0530] EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_number=5551231234) 2018-02-22 16:19:42.410742 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [effective_caller_id_number]=[5551231234] EXECUTE sofia/external/3097@192.168.168.211 javascript(/usr/local/freeswitch/scripts/Transfer_test_1.js) 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:4 <---------------Inside JS ----------------> 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:10 ------------------------End Transfer JS-------------------- 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4488 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4349 Set telephone-event payload to 101@8000 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:3057 Set Codec sofia/external/3097@192.168.168.211 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2018-02-22 16:19:42.410742 [DEBUG] switch_core_codec.c:111 sofia/external/3097@192.168.168.211 Original read codec set to PCMU:0 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4692 Set telephone-event payload to 101@8000 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4751 sofia/external/3097@192.168.168.211 Set 2833 dtmf send payload to 101 recv payload to 101 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:6862 AUDIO RTP [sofia/external/3097@192.168.168.211] 192.168.168.99 port 26048 -> 192.168.168.211 port 25252 codec: 0 ms: 20 2018-02-22 16:19:42.410742 [DEBUG] switch_rtp.c:4107 Starting timer [soft] 160 bytes per 20ms 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:7163 sofia/external/3097@192.168.168.211 Set 2833 dtmf send payload to 101 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:7170 sofia/external/3097@192.168.168.211 Set 2833 dtmf receive payload to 101 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:7193 sofia/external/3097@192.168.168.211 Set rtp dtmf delay to 40 2018-02-22 16:19:42.410742 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/3097@192.168.168.211! 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:3473 (sofia/external/3097@192.168.168.211) Callstate Change RINGING -> EARLY 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:6845 Audio params are unchanged for sofia/external/3097@192.168.168.211. 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/3097@192.168.168.211: v=0 o=FreeSWITCH 1519270534 1519270535 IN IP4 192.168.168.99 s=FreeSWITCH c=IN IP4 192.168.168.99 t=0 0 m=audio 26048 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 2018-02-22 16:19:42.410742 [NOTICE] fssession.cpp:1168 Channel [sofia/external/3097@192.168.168.211] has been answered send 1049 bytes to udp/[192.168.168.211]:5080 at 16:19:42.423840: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814 From: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 To: ;tag=655ryS7mS3pHa Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Require: timer Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Session-Expires: 1800;refresher=uac Content-Type: application/sdp Content-Disposition: session Content-Length: 224 P-Asserted-Identity: "5559" v=0 o=FreeSWITCH 1519270534 1519270535 IN IP4 192.168.168.99 s=FreeSWITCH c=IN IP4 192.168.168.99 t=0 0 m=audio 26048 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:3772 (sofia/external/3097@192.168.168.211) Callstate Change EARLY -> ACTIVE 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [completed][200] 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:13 ------------------------Caller ID -> 3097 -------------------- 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:7 <---------------Play File Method: ----------------> 2018-02-22 16:19:42.410742 [DEBUG] switch_core_file.c:342 File /usr/local/freeswitch/sounds/en/us/callie/ivr/EagleHills/English/Welcome.wav sample rate 44100 doesn't match requested rate 8000 2018-02-22 16:19:42.410742 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur. 2018-02-22 16:19:42.410742 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms recv 476 bytes from udp/[192.168.168.211]:5080 at 16:19:42.426364: ------------------------------------------------------------------------ ACK sip:5559@192.168.168.99:5080;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227f3f9662b2 From: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 To: ;tag=655ryS7mS3pHa Date: Thu, 22 Feb 2018 10:49:43 GMT Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 User-Agent: Cisco-CUCM11.5 Max-Forwards: 70 CSeq: 101 ACK Allow-Events: presence, kpml Content-Length: 0 ------------------------------------------------------------------------ 2018-02-22 16:19:42.430799 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [ready][200] 2018-02-22 16:19:42.470741 [DEBUG] switch_rtp.c:7247 Correct audio ip/port confirmed. 2018-02-22 16:19:46.870747 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/EagleHills/English/Welcome.wav EXECUTE sofia/external/3097@192.168.168.211 set(origination_caller_id_number=3097) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [origination_caller_id_number]=[3097] EXECUTE sofia/external/3097@192.168.168.211 execute_extension(3003) 2018-02-22 16:19:46.870747 [INFO] mod_dialplan_xml.c:637 Processing User3 <3097>->3003 in context public Dialplan: sofia/external/3097@192.168.168.211 parsing [public->unloop] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outside_call] continue=true Dialplan: sofia/external/3097@192.168.168.211 Absolute Condition [outside_call] Dialplan: sofia/external/3097@192.168.168.211 Action set(outside_call=true) Dialplan: sofia/external/3097@192.168.168.211 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/3097@192.168.168.211 parsing [public->call_debug] continue=true Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_extensions] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_extensions] destination_number(3003) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_did] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_did] destination_number(3003) =~ /^(38013801)$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->5559] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [5559] destination_number(3003) =~ /5559$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->UNKNOWN] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [UNKNOWN] destination_number(3003) =~ /7777$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outbound] continue=false Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [outbound] destination_number(3003) =~ /^(3003)$/ break=on-false Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_TITLE=Recording ${destination_number} ${c aller_id_number} ${strftime(%Y-%m-%d %H:%M)}) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_COPYRIGHT=(c) 2011) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_SOFTWARE=FreeSWITCH) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_ARTIST=FreeSWITCH) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_COMMENT=FreeSWITCH) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)}) Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_STEREO=true) Dialplan: sofia/external/3097@192.168.168.211 Action record_session(/usr/local/freeswitch/recording/external/${ strftime(%Y-%m-%d-%H-%M-%S)}_${destination_number}_${caller_id_number}.wav) Dialplan: sofia/external/3097@192.168.168.211 Action export(nolocal:absolute_codec_string=PCMA,PCMU) Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_number=${caller_id_number}) Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_name=${caller_id_number}) Dialplan: sofia/external/3097@192.168.168.211 Action bridge(sofia/gateway/CUCM/3003) 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(outside_call=true) EXECUTE sofia/external/3097@192.168.168.211 set(outside_call=true) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [outside_call]=[true] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) EXECUTE sofia/external/3097@192.168.168.211 export(RFC2822_DATE=Thu, 22 Feb 2018 16:19:46 +0530) 2018-02-22 16:19:46.870747 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 22 Feb 2018 16:19:46 +0530] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_TITLE=Recording ${destination_number} ${c aller_id_number} ${strftime(%Y-%m-%d %H:%M)}) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_TITLE=Recording 3003 2018-02-22 16:19) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_TITLE]=[Recording 3003 2018-02-22 16:19] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_COPYRIGHT=(c) 2011) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_COPYRIGHT=(c) 2011) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_COPYRIGHT]=[(c) 2011] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_SOFTWARE=FreeSWITCH) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_SOFTWARE=FreeSWITCH) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_SOFTWARE]=[FreeSWITCH] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_ARTIST=FreeSWITCH) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_ARTIST=FreeSWITCH) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_ARTIST]=[FreeSWITCH] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_COMMENT=FreeSWITCH) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_COMMENT=FreeSWITCH) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_COMMENT]=[FreeSWITCH] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)}) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_DATE=2018-02-22 16:19) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_DATE]=[2018-02-22 16:19] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_STEREO=true) EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_STEREO=true) 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_STEREO]=[true] 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute record_session(/usr/local/freeswitch/recording/external/${ strftime(%Y-%m-%d-%H-%M-%S)}_${destination_number}_${caller_id_number}.wav) EXECUTE sofia/external/3097@192.168.168.211 record_session(/usr/local/freeswitch/recording/external/_3003_3097.wav) 2018-02-22 16:19:46.890742 [DEBUG] switch_core_media_bug.c:945 Attaching BUG to sofia/external/3097@192.168.168.211 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute export(nolocal:absolute_codec_string=PCMA,PCMU) EXECUTE sofia/external/3097@192.168.168.211 export(nolocal:absolute_codec_string=PCMA,PCMU) 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[PCMA,PCMU] 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute set(effective_caller_id_number=${caller_id_number}) EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_number=3097) 2018-02-22 16:19:46.890742 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [effective_caller_id_number]=[3097] 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute set(effective_caller_id_name=${caller_id_number}) EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_name=3097) 2018-02-22 16:19:46.890742 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [effective_caller_id_name]=[3097] 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute bridge(sofia/gateway/CUCM/3003) EXECUTE sofia/external/3097@192.168.168.211 bridge(sofia/gateway/CUCM/3003) 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1823 (sofia/external/3097@192.168.168.211) Callstate Change ACTIVE -> RING_WAIT 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1250 sofia/external/3097@192.168.168.211 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 22 Feb 2018 16:19:46 +0530] to event 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1250 sofia/external/3097@192.168.168.211 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 22 Feb 2018 16:19:46 +0530] to event 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1250 sofia/external/3097@192.168.168.211 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,PCMU] to event 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-02-22 16:19:46.890742 [NOTICE] switch_channel.c:1104 New Channel sofia/external/3003 [3a5457d9-173b-4fab-998d-9efec6d6d3f5] 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:4819 (sofia/external/3003) State Change CS_NEW -> CS_INIT 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3003) Running State Change CS_INIT (Cur 2 Tot 357) 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3003) State INIT 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:90 sofia/external/3003 SOFIA INIT 2018-02-22 16:19:46.890742 [DEBUG] sofia_glue.c:1295 sofia/external/3003 sending invite version: 1.6.17 git f17ac2f 2017-05-26 22:41:25Z 32bit Local SDP: v=0 o=FreeSWITCH 1519265822 1519265823 IN IP4 192.168.168.99 s=FreeSWITCH c=IN IP4 192.168.168.99 t=0 0 m=audio 30764 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:40 sofia/external/3003 Standard INIT 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:48 (sofia/external/3003) State Change CS_INIT -> CS_ROUTING 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3003) State INIT going to sleep 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3003) Running State Change CS_ROUTING (Cur 2 Tot 357) send 1205 bytes to udp/[192.168.168.211]:5060 at 16:19:46.900854: ------------------------------------------------------------------------ INVITE sip:3003@192.168.168.211 SIP/2.0 Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD Max-Forwards: 68 From: "3097" ;tag=7eZH0mrrpcD4N To: Call-ID: f0947313-9260-1236-51bb-000c295030a8 CSeq: 119312229 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit 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: 248 P-Charging-Vector: icid-value="15AB030000010000000000E1D3A8A8C0";icid-generated-at=tacucmpub;orig-ioi="IMS Inter Operator Identification" X-FS-Support: update_display,send_info Remote-Party-ID: "3097" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1519265822 1519265823 IN IP4 192.168.168.99 s=FreeSWITCH c=IN IP4 192.168.168.99 t=0 0 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3003) State ROUTING m=audio 30764 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:143 sofia/external/3003 SOFIA ROUTING a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_originate.c:67 (sofia/external/3003) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3003) State ROUTING going to sleep 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3003) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 357) 2018-02-22 16:19:46.890742 [DEBUG] sofia.c:7048 Channel sofia/external/3003 entering state [calling][0] 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:662 (sofia/external/3003) State CONSUME_MEDIA 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:662 (sofia/external/3003) State CONSUME_MEDIA going to sleep 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_async.c:1500 No silence detection configured; assuming start of speech 2018-02-22 16:19:47.190732 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0 recv 335 bytes from udp/[192.168.168.211]:5060 at 16:19:47.218210: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD From: "3097" ;tag=7eZH0mrrpcD4N To: Date: Thu, 22 Feb 2018 10:49:48 GMT Call-ID: f0947313-9260-1236-51bb-000c295030a8 CSeq: 119312229 INVITE Allow-Events: presence Content-Length: 0 ------------------------------------------------------------------------ recv 422 bytes from udp/[192.168.168.211]:5060 at 16:19:47.222307: ------------------------------------------------------------------------ SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD From: "3097" ;tag=7eZH0mrrpcD4N To: ;tag=1141683192 Date: Thu, 22 Feb 2018 10:49:48 GMT Call-ID: f0947313-9260-1236-51bb-000c295030a8 CSeq: 119312229 INVITE Allow-Events: presence Server: Cisco-CUCM11.5 Warning: 399 tacucmpub "Unknown calling DN" Content-Length: 0 ------------------------------------------------------------------------ send 322 bytes to udp/[192.168.168.211]:5060 at 16:19:47.222539: ------------------------------------------------------------------------ ACK sip:3003@192.168.168.211 SIP/2.0 Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD Max-Forwards: 68 From: "3097" ;tag=7eZH0mrrpcD4N To: ;tag=1141683192 Call-ID: f0947313-9260-1236-51bb-000c295030a8 CSeq: 119312229 ACK Content-Length: 0 ------------------------------------------------------------------------ 2018-02-22 16:19:47.210800 [DEBUG] sofia.c:7048 Channel sofia/external/3003 entering state [terminated][403] 2018-02-22 16:19:47.210800 [NOTICE] sofia.c:8237 Hangup sofia/external/3003 [CS_CONSUME_MEDIA] [CALL_REJECTED] 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3003) Running State Change CS_HANGUP (Cur 2 Tot 357) 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:850 (sofia/external/3003) Callstate Change DOWN -> HANGUP 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3003) State HANGUP 2018-02-22 16:19:47.210800 [DEBUG] mod_sofia.c:438 Channel sofia/external/3003 hanging up, cause: CALL_REJECTED 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:60 sofia/external/3003 Standard HANGUP, cause: CALL_REJECTED 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3003) State HANGUP going to sleep 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:619 (sofia/external/3003) State Change CS_HANGUP -> CS_REPORTING 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3003) Running State Change CS_REPORTING (Cur 2 Tot 357) 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3003) State REPORTING 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:174 sofia/external/3003 Standard REPORTING, cause: CALL_REJECTED 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3003) State REPORTING going to sleep 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:610 (sofia/external/3003) State Change CS_REPORTING -> CS_DESTROY 2018-02-22 16:19:47.210800 [DEBUG] switch_core_session.c:1664 Session 357 (sofia/external/3003) Locked, Waiting on external entities 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_originate.c:3847 Originate Resulted in Error Cause: 21 [CALL_REJECTED] 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1682 Session 357 (sofia/external/3003) Ended 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/3003 [CS_DESTROY] 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:741 (sofia/external/3003) Running State Change CS_DESTROY (Cur 1 Tot 357) 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3003) State DESTROY 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:343 sofia/external/3003 SOFIA DESTROY 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:181 sofia/external/3003 Standard DESTROY 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3003) State DESTROY going to sleep 2018-02-22 16:19:47.230733 [DEBUG] switch_channel.c:2047 (sofia/external/3097@192.168.168.211) Callstate Change RING_WAIT -> ACTIVE 2018-02-22 16:19:47.230733 [INFO] mod_dptools.c:3418 Originate Failed. Cause: CALL_REJECTED 2018-02-22 16:19:47.230733 [NOTICE] switch_channel.c:4822 Hangup sofia/external/3097@192.168.168.211 [CS_EXECUTE] [CALL_REJECTED] 2018-02-22 16:19:47.230733 [DEBUG] switch_core_session.c:2814 sofia/external/3097@192.168.168.211 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-02-22 16:19:47.230733 [DEBUG] switch_core_session.c:2814 sofia/external/3097@192.168.168.211 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-02-22 16:19:47.230733 [NOTICE] Transfer_test_1.js:19 Script exited with info [] 2018-02-22 16:19:47.230733 [DEBUG] switch_core_session.c:2814 sofia/external/3097@192.168.168.211 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:650 (sofia/external/3097@192.168.168.211) State EXECUTE going to sleep 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_HANGUP (Cur 1 Tot 357) 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_async.c:1316 Stop recording file /usr/local/freeswitch/recording/external/_3003_3097.wav 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_async.c:1380 Channel is hung up 2018-02-22 16:19:47.230733 [DEBUG] switch_core_media_bug.c:1294 Removing BUG from sofia/external/3097@192.168.168.211 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:850 (sofia/external/3097@192.168.168.211) Callstate Change ACTIVE -> HANGUP 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3097@192.168.168.211) State HANGUP 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:432 sofia/external/3097@192.168.168.211 Overriding SIP cause 603 with 403 from the other leg 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:438 Channel sofia/external/3097@192.168.168.211 hanging up, cause: CALL_REJECTED 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/3097@192.168.168.211 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:60 sofia/external/3097@192.168.168.211 Standard HANGUP, cause: CALL_REJECTED 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3097@192.168.168.211) State HANGUP going to sleep 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:619 (sofia/external/3097@192.168.168.211) State Change CS_HANGUP -> CS_REPORTING 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3097@192.168.168.211) Running State Change CS_REPORTING (Cur 1 Tot 357) send 628 bytes to udp/[192.168.168.211]:5080 at 16:19:47.248647: ------------------------------------------------------------------------ BYE sip:3097@192.168.168.211:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK1F2Q0cpDKQU5r Max-Forwards: 70 From: ;tag=655ryS7mS3pHa To: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 CSeq: 119312229 BYE User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Reason: Q.850;cause=21;text="CALL_REJECTED" Content-Length: 0 ------------------------------------------------------------------------ 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3097@192.168.168.211) State REPORTING 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:174 sofia/external/3097@192.168.168.211 Standard REPORTING, cause: CALL_REJECTED 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3097@192.168.168.211) State REPORTING going to sleep 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:610 (sofia/external/3097@192.168.168.211) State Change CS_REPORTING -> CS_DESTROY 2018-02-22 16:19:47.230733 [DEBUG] switch_core_session.c:1664 Session 356 (sofia/external/3097@192.168.168.211) Locked, Waiting on external entities 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1682 Session 356 (sofia/external/3097@192.168.168.211) Ended 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/3097@192.168.168.211 [CS_DESTROY] 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:741 (sofia/external/3097@192.168.168.211) Running State Change CS_DESTROY (Cur 0 Tot 357) 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3097@192.168.168.211) State DESTROY 2018-02-22 16:19:47.250735 [DEBUG] mod_sofia.c:343 sofia/external/3097@192.168.168.211 SOFIA DESTROY 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:181 sofia/external/3097@192.168.168.211 Standard DESTROY 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3097@192.168.168.211) State DESTROY going to sleep recv 396 bytes from udp/[192.168.168.211]:5080 at 16:19:47.262493: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK1F2Q0cpDKQU5r From: ;tag=655ryS7mS3pHa To: "User3" ;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505 Date: Thu, 22 Feb 2018 10:49:48 GMT Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211 Server: Cisco-CUCM11.5 CSeq: 119312229 BYE Content-Length: 0 ------------------------------------------------------------------------ recv 394 bytes from udp/[192.168.168.211]:5080 at 16:20:00.984200: ------------------------------------------------------------------------ OPTIONS sip:192.168.168.99:5080 SIP/2.0 Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK2284628990d6 From: ;tag=1042369939 To: Date: Thu, 22 Feb 2018 10:50:02 GMT Call-ID: 20fe2e80-a8e1a05a-208d-d3a8a8c0@192.168.168.211 User-Agent: Cisco-CUCM11.5 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 ------------------------------------------------------------------------ send 607 bytes to udp/[192.168.168.211]:5080 at 16:20:00.984545: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK2284628990d6 From: ;tag=1042369939 To: ;tag=8Qra2F9UKN3pH Call-ID: 20fe2e80-a8e1a05a-208d-d3a8a8c0@192.168.168.211 CSeq: 101 OPTIONS Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit 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 ------------------------------------------------------------------------ freeswitch@fs01> /exit