1. Team,
2.        I need the originator caller ID to be maintained during the entire call session.
3.  
4. I have pasted the config and traces below :
5.  
6. Gateway Config
7.  
8. <include>
9.    <gateway name="CUCM">
10.      <param name="proxy" value="192.168.168.211"/>
11.      <param name="register" value="true"/>
12.      <param name="caller-id-in-from" value="true"/> <!--Most gateways seem to want this-->
13.       <param name="username" value="3034"/>
14.       <param name="auth-username" value="fs"/>
15.      <param name="password" value="1234"/>
16.    </gateway>
17. </include>
18.  
19. Dial plan config
20.  
21. <extension name="outbound">
22. <condition field="destination_number"expression="^(3003)$">
23. <action application="set" data="RECORD_TITLE=Recording ${destination_number} ${c                                                                                        aller_id_number} ${strftime(%Y-%m-%d %H:%M)}"/>
24. <action application="set" data="RECORD_COPYRIGHT=(c) 2011"/>
25. <action application="set" data="RECORD_SOFTWARE=FreeSWITCH"/>
26. <action application="set" data="RECORD_ARTIST=FreeSWITCH"/>
27. <action application="set" data="RECORD_COMMENT=FreeSWITCH"/>
28. <action application="set" data="RECORD_DATE=${strftime(%Y-%m-%d %H:%M)}"/>
29. <action application="set" data="RECORD_STEREO=true"/>
30. <action application="record_session" data="/usr/local/freeswitch/recording/external/${                                                                                        strftime(%Y-%m-%d-%H-%M-%S)}_${destination_number}_${caller_id_number}.wav"/>
31. <action application="export" data="nolocal:absolute_codec_string=PCMA,PCMU"/>
32. <action application="set" data="effective_caller_id_number=${caller_id_number}"/>
33. <action application="set" data="effective_caller_id_name=${caller_id_number}"/>
34. <action application="bridge"data="sofia/gateway/CUCM/$1"/>
35. </condition>
36. </extension>
37.  
38. Issue :
39. 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.
40.  
41. Below is the trace for the test call
42.  
43. 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)
44.  
45. in 3003 i get the caller ID as 5559 but i want the calller ID to be 3097
46.  
47.  
48.  
49.  
50.  
51.  
52.  
53.  
54.  
55.  
56.  
57.  
58. recv 1543 bytes from udp/[192.168.168.211]:5080 at 16:19:42.410561:
59.    ------------------------------------------------------------------------
60.    INVITE sip:5559@192.168.168.99:5080 SIP/2.0
61.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814
62.    From: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
63.    To: <sip:5559@192.168.168.99>
64.    Date: Thu, 22 Feb 2018 10:49:43 GMT
65.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
66.    Supported: timer,resource-priority,replaces
67.    Min-SE:  1800
68.    User-Agent: Cisco-CUCM11.5
69.    Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
70.    CSeq: 101 INVITE
71.    Expires: 180
72.    Allow-Events: presence, kpml
73.    Supported: X-cisco-srtp-fallback,X-cisco-original-called
74.    Call-Info: <sip:192.168.168.211:5080>;method="NOTIFY;Event=telephone-event;Duration=500"
75.    Session-ID: 000033c100105000a000b888e3e4db15;remote=00000000000000000000000000000000
76.    Cisco-Guid: 0363528960-0000065536-0000000226-3551045824
77.    P-Charging-Vector: icid-value="15AB030000010000000000E1D3A8A8C0";icid-generated-at=tacucmpub;orig-ioi="IMS Inter Operator Identification"
78.    Session-Expires:  1800
79.    P-Asserted-Identity: "User3" <sip:3097@192.168.168.211>
80.    Remote-Party-ID: "User3" <sip:3097@192.168.168.211>;party=calling;screen=yes;privacy=off
81.    Contact: <sip:3097@192.168.168.211:5080>;+u.sip!devicename.ccm.cisco.com="jabber4";bfcp
82.    Max-Forwards: 69
83.    Content-Type: application/sdp
84.    Content-Length: 207
85.  
86.    v=0
87.    o=CiscoSystemsCCM-SIP 18740 1 IN IP4 192.168.168.211
88.    s=SIP Call
89.    c=IN IP4 192.168.168.211
90.    t=0 0
91.    m=audio 25252 RTP/AVP 0 101
92.    a=rtpmap:0 PCMU/8000
93.    a=rtpmap:101 telephone-event/8000
94.    a=fmtp:101 0-15
95.    ------------------------------------------------------------------------
96. send 391 bytes to udp/[192.168.168.211]:5080 at 16:19:42.410982:
97.    ------------------------------------------------------------------------
98.    SIP/2.0 100 Trying
99.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814
100.    From: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
101.    To: <sip:5559@192.168.168.99>
102.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
103.    CSeq: 101 INVITE
104.    User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit
105.    Content-Length: 0
106.  
107.    ------------------------------------------------------------------------
108. 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]
109. 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)
110. 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
111. 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [received][100]
112. 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7058 Remote SDP:
113. v=0
114. o=CiscoSystemsCCM-SIP 18740 1 IN IP4 192.168.168.211
115. s=SIP Call
116. c=IN IP4 192.168.168.211
117. t=0 0
118. m=audio 25252 RTP/AVP 0 101
119. a=rtpmap:0 PCMU/8000
120. a=rtpmap:101 telephone-event/8000
121. a=fmtp:101 0-15
122.  
123. 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7450 (sofia/external/3097@192.168.168.211) State Change CS_NEW -> CS_INIT
124. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:603 (sofia/external/3097@192.168.168.211) State NEW
125. 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)
126. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3097@192.168.168.211) State INIT
127. 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:90 sofia/external/3097@192.168.168.211 SOFIA INIT
128. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:40 sofia/external/3097@192.168.168.211 Standard INIT
129. 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
130. 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
131. 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)
132. 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:2249 (sofia/external/3097@192.168.168.211) Callstate Change DOWN -> RINGING
133. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3097@192.168.168.211) State ROUTING
134. 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:143 sofia/external/3097@192.168.168.211 SOFIA ROUTING
135. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:236 sofia/external/3097@192.168.168.211 Standard ROUTING
136. 2018-02-22 16:19:42.410742 [INFO] mod_dialplan_xml.c:637 Processing User3 <3097>->5559 in context public
137. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->unloop] continue=false
138. Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
139. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
140. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outside_call] continue=true
141. Dialplan: sofia/external/3097@192.168.168.211 Absolute Condition [outside_call]
142. Dialplan: sofia/external/3097@192.168.168.211 Action set(outside_call=true)
143. Dialplan: sofia/external/3097@192.168.168.211 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
144. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->call_debug] continue=true
145. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
146. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_extensions] continue=false
147. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_extensions] destination_number(5559) =~ /^(10[01][0-9])$/ break=on-false
148. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_did] continue=false
149. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_did] destination_number(5559) =~ /^(38013801)$/ break=on-false
150. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->5559] continue=false
151. Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [5559] destination_number(5559) =~ /5559$/ break=on-false
152. Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_number=5551231234)
153. Dialplan: sofia/external/3097@192.168.168.211 Action javascript(/usr/local/freeswitch/scripts/Transfer_test_1.js)
154. 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
155. 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
156. 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)
157. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:650 (sofia/external/3097@192.168.168.211) State EXECUTE
158. 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:198 sofia/external/3097@192.168.168.211 SOFIA EXECUTE
159. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_state_machine.c:328 sofia/external/3097@192.168.168.211 Standard EXECUTE
160. EXECUTE sofia/external/3097@192.168.168.211 set(outside_call=true)
161. 2018-02-22 16:19:42.410742 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [outside_call]=[true]
162. EXECUTE sofia/external/3097@192.168.168.211 export(RFC2822_DATE=Thu, 22 Feb 2018 16:19:42 +0530)
163. 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]
164. EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_number=5551231234)
165. 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]
166. EXECUTE sofia/external/3097@192.168.168.211 javascript(/usr/local/freeswitch/scripts/Transfer_test_1.js)
167. 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:4 <---------------Inside JS ---------------->
168. 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:10 ------------------------End Transfer JS--------------------
169. 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]
170. 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]
171. 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]
172. 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
173. 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]
174. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4349 Set telephone-event payload to 101@8000
175. 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
176. 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
177. 2018-02-22 16:19:42.410742 [DEBUG] switch_core_media.c:4692 Set telephone-event payload to 101@8000
178. 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
179. 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
180. 2018-02-22 16:19:42.410742 [DEBUG] switch_rtp.c:4107 Starting timer [soft] 160 bytes per 20ms
181. 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
182. 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
183. 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
184. 2018-02-22 16:19:42.410742 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/3097@192.168.168.211!
185. 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:3473 (sofia/external/3097@192.168.168.211) Callstate Change RINGING -> EARLY
186. 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.
187. 2018-02-22 16:19:42.410742 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/3097@192.168.168.211:
188. v=0
189. o=FreeSWITCH 1519270534 1519270535 IN IP4 192.168.168.99
190. s=FreeSWITCH
191. c=IN IP4 192.168.168.99
192. t=0 0
193. m=audio 26048 RTP/AVP 0 101
194. a=rtpmap:0 PCMU/8000
195. a=rtpmap:101 telephone-event/8000
196. a=fmtp:101 0-16
197. a=ptime:20
198. a=sendrecv
199.  
200. 2018-02-22 16:19:42.410742 [NOTICE] fssession.cpp:1168 Channel [sofia/external/3097@192.168.168.211] has been answered
201. send 1049 bytes to udp/[192.168.168.211]:5080 at 16:19:42.423840:
202.    ------------------------------------------------------------------------
203.    SIP/2.0 200 OK
204.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227e7389f814
205.    From: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
206.    To: <sip:5559@192.168.168.99>;tag=655ryS7mS3pHa
207.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
208.    CSeq: 101 INVITE
209.    Contact: <sip:5559@192.168.168.99:5080;transport=udp>
210.    User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit
211.    Accept: application/sdp
212.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
213.    Require: timer
214.    Supported: timer, path, replaces
215.    Allow-Events: talk, hold, conference, refer
216.    Session-Expires: 1800;refresher=uac
217.    Content-Type: application/sdp
218.    Content-Disposition: session
219.    Content-Length: 224
220.    P-Asserted-Identity: "5559" <sip:5559@192.168.168.99>
221.  
222.    v=0
223.    o=FreeSWITCH 1519270534 1519270535 IN IP4 192.168.168.99
224.    s=FreeSWITCH
225.    c=IN IP4 192.168.168.99
226.    t=0 0
227.    m=audio 26048 RTP/AVP 0 101
228.    a=rtpmap:0 PCMU/8000
229.    a=rtpmap:101 telephone-event/8000
230.    a=fmtp:101 0-16
231.    a=ptime:20
232.    ------------------------------------------------------------------------
233. 2018-02-22 16:19:42.410742 [DEBUG] switch_channel.c:3772 (sofia/external/3097@192.168.168.211) Callstate Change EARLY -> ACTIVE
234. 2018-02-22 16:19:42.410742 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [completed][200]
235. 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:13 ------------------------Caller ID -> 3097  --------------------
236. 2018-02-22 16:19:42.410742 [NOTICE] Transfer_test_1.js:7 <---------------Play File Method: ---------------->
237. 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
238. 2018-02-22 16:19:42.410742 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
239. 2018-02-22 16:19:42.410742 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
240. recv 476 bytes from udp/[192.168.168.211]:5080 at 16:19:42.426364:
241.    ------------------------------------------------------------------------
242.    ACK sip:5559@192.168.168.99:5080;transport=udp SIP/2.0
243.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK227f3f9662b2
244.    From: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
245.    To: <sip:5559@192.168.168.99>;tag=655ryS7mS3pHa
246.    Date: Thu, 22 Feb 2018 10:49:43 GMT
247.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
248.    User-Agent: Cisco-CUCM11.5
249.    Max-Forwards: 70
250.    CSeq: 101 ACK
251.    Allow-Events: presence, kpml
252.    Content-Length: 0
253.  
254.    ------------------------------------------------------------------------
255. 2018-02-22 16:19:42.430799 [DEBUG] sofia.c:7048 Channel sofia/external/3097@192.168.168.211 entering state [ready][200]
256. 2018-02-22 16:19:42.470741 [DEBUG] switch_rtp.c:7247 Correct audio ip/port confirmed.
257. 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
258. EXECUTE sofia/external/3097@192.168.168.211 set(origination_caller_id_number=3097)
259. 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]
260. EXECUTE sofia/external/3097@192.168.168.211 execute_extension(3003)
261. 2018-02-22 16:19:46.870747 [INFO] mod_dialplan_xml.c:637 Processing User3 <3097>->3003 in context public
262. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->unloop] continue=false
263. Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
264. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
265. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outside_call] continue=true
266. Dialplan: sofia/external/3097@192.168.168.211 Absolute Condition [outside_call]
267. Dialplan: sofia/external/3097@192.168.168.211 Action set(outside_call=true)
268. Dialplan: sofia/external/3097@192.168.168.211 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
269. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->call_debug] continue=true
270. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
271. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_extensions] continue=false
272. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_extensions] destination_number(3003) =~ /^(10[01][0-9])$/ break=on-false
273. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->public_did] continue=false
274. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [public_did] destination_number(3003) =~ /^(38013801)$/ break=on-false
275. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->5559] continue=false
276. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [5559] destination_number(3003) =~ /5559$/ break=on-false
277. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->UNKNOWN] continue=false
278. Dialplan: sofia/external/3097@192.168.168.211 Regex (FAIL) [UNKNOWN] destination_number(3003) =~ /7777$/ break=on-false
279. Dialplan: sofia/external/3097@192.168.168.211 parsing [public->outbound] continue=false
280. Dialplan: sofia/external/3097@192.168.168.211 Regex (PASS) [outbound] destination_number(3003) =~ /^(3003)$/ break=on-false
281. 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)})
282. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_COPYRIGHT=(c) 2011)
283. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_SOFTWARE=FreeSWITCH)
284. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_ARTIST=FreeSWITCH)
285. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_COMMENT=FreeSWITCH)
286. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)})
287. Dialplan: sofia/external/3097@192.168.168.211 Action set(RECORD_STEREO=true)
288. 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)
289. Dialplan: sofia/external/3097@192.168.168.211 Action export(nolocal:absolute_codec_string=PCMA,PCMU)
290. Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_number=${caller_id_number})
291. Dialplan: sofia/external/3097@192.168.168.211 Action set(effective_caller_id_name=${caller_id_number})
292. Dialplan: sofia/external/3097@192.168.168.211 Action bridge(sofia/gateway/CUCM/3003)
293. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(outside_call=true)
294. EXECUTE sofia/external/3097@192.168.168.211 set(outside_call=true)
295. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [outside_call]=[true]
296. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
297. EXECUTE sofia/external/3097@192.168.168.211 export(RFC2822_DATE=Thu, 22 Feb 2018 16:19:46 +0530)
298. 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]
299. 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)})
300. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_TITLE=Recording 3003  2018-02-22 16:19)
301. 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]
302. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_COPYRIGHT=(c) 2011)
303. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_COPYRIGHT=(c) 2011)
304. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_COPYRIGHT]=[(c) 2011]
305. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_SOFTWARE=FreeSWITCH)
306. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_SOFTWARE=FreeSWITCH)
307. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_SOFTWARE]=[FreeSWITCH]
308. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_ARTIST=FreeSWITCH)
309. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_ARTIST=FreeSWITCH)
310. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_ARTIST]=[FreeSWITCH]
311. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_COMMENT=FreeSWITCH)
312. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_COMMENT=FreeSWITCH)
313. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_COMMENT]=[FreeSWITCH]
314. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)})
315. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_DATE=2018-02-22 16:19)
316. 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]
317. 2018-02-22 16:19:46.870747 [NOTICE] switch_core_session.c:2913 Execute set(RECORD_STEREO=true)
318. EXECUTE sofia/external/3097@192.168.168.211 set(RECORD_STEREO=true)
319. 2018-02-22 16:19:46.870747 [DEBUG] mod_dptools.c:1530 SET sofia/external/3097@192.168.168.211 [RECORD_STEREO]=[true]
320. 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)
321. EXECUTE sofia/external/3097@192.168.168.211 record_session(/usr/local/freeswitch/recording/external/_3003_3097.wav)
322. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_media_bug.c:945 Attaching BUG to sofia/external/3097@192.168.168.211
323. 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute export(nolocal:absolute_codec_string=PCMA,PCMU)
324. EXECUTE sofia/external/3097@192.168.168.211 export(nolocal:absolute_codec_string=PCMA,PCMU)
325. 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[PCMA,PCMU]
326. 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute set(effective_caller_id_number=${caller_id_number})
327. EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_number=3097)
328. 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]
329. 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute set(effective_caller_id_name=${caller_id_number})
330. EXECUTE sofia/external/3097@192.168.168.211 set(effective_caller_id_name=3097)
331. 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]
332. 2018-02-22 16:19:46.890742 [NOTICE] switch_core_session.c:2913 Execute bridge(sofia/gateway/CUCM/3003)
333. EXECUTE sofia/external/3097@192.168.168.211 bridge(sofia/gateway/CUCM/3003)
334. 2018-02-22 16:19:46.890742 [DEBUG] switch_channel.c:1823 (sofia/external/3097@192.168.168.211) Callstate Change ACTIVE -> RING_WAIT
335. 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
336. 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
337. 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
338. 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
339. 2018-02-22 16:19:46.890742 [NOTICE] switch_channel.c:1104 New Channel sofia/external/3003 [3a5457d9-173b-4fab-998d-9efec6d6d3f5]
340. 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:4819 (sofia/external/3003) State Change CS_NEW -> CS_INIT
341. 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)
342. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3003) State INIT
343. 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:90 sofia/external/3003 SOFIA INIT
344. 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
345. Local SDP:
346. v=0
347. o=FreeSWITCH 1519265822 1519265823 IN IP4 192.168.168.99
348. s=FreeSWITCH
349. c=IN IP4 192.168.168.99
350. t=0 0
351. m=audio 30764 RTP/AVP 8 0 101
352. a=rtpmap:8 PCMA/8000
353. a=rtpmap:0 PCMU/8000
354. a=rtpmap:101 telephone-event/8000
355. a=fmtp:101 0-16
356. a=ptime:20
357. a=sendrecv
358.  
359. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:40 sofia/external/3003 Standard INIT
360. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:48 (sofia/external/3003) State Change CS_INIT -> CS_ROUTING
361. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3003) State INIT going to sleep
362. 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)
363. send 1205 bytes to udp/[192.168.168.211]:5060 at 16:19:46.900854:
364.    ------------------------------------------------------------------------
365.    INVITE sip:3003@192.168.168.211 SIP/2.0
366.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD
367.    Max-Forwards: 68
368.    From: "3097" <sip:3097@192.168.168.99>;tag=7eZH0mrrpcD4N
369.    To: <sip:3003@192.168.168.211>
370.    Call-ID: f0947313-9260-1236-51bb-000c295030a8
371.    CSeq: 119312229 INVITE
372.    Contact: <sip:gw+CUCM@192.168.168.99:5080;transport=udp;gw=CUCM>
373.    User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit
374.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
375.    Supported: timer, path, replaces
376.    Allow-Events: talk, hold, conference, refer
377.    Content-Type: application/sdp
378.    Content-Disposition: session
379.    Content-Length: 248
380.    P-Charging-Vector: icid-value="15AB030000010000000000E1D3A8A8C0";icid-generated-at=tacucmpub;orig-ioi="IMS Inter Operator Identification"
381.    X-FS-Support: update_display,send_info
382.    Remote-Party-ID: "3097" <sip:3097@192.168.168.99>;party=calling;screen=yes;privacy=off
383.  
384.    v=0
385.    o=FreeSWITCH 1519265822 1519265823 IN IP4 192.168.168.99
386.    s=FreeSWITCH
387.    c=IN IP4 192.168.168.99
388.    t=0 0
389. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3003) State ROUTING
390.    m=audio 30764 RTP/AVP 8 0 101
391.    a=rtpmap:8 PCMA/8000
392.    a=rtpmap:0 PCMU/8000
393. 2018-02-22 16:19:46.890742 [DEBUG] mod_sofia.c:143 sofia/external/3003 SOFIA ROUTING
394.    a=rtpmap:101 telephone-event/8000
395.    a=fmtp:101 0-16
396.    a=ptime:20
397.    ------------------------------------------------------------------------
398. 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_originate.c:67 (sofia/external/3003) State Change CS_ROUTING -> CS_CONSUME_MEDIA
399. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3003) State ROUTING going to sleep
400. 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)
401. 2018-02-22 16:19:46.890742 [DEBUG] sofia.c:7048 Channel sofia/external/3003 entering state [calling][0]
402. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:662 (sofia/external/3003) State CONSUME_MEDIA
403. 2018-02-22 16:19:46.890742 [DEBUG] switch_core_state_machine.c:662 (sofia/external/3003) State CONSUME_MEDIA going to sleep
404. 2018-02-22 16:19:46.890742 [DEBUG] switch_ivr_async.c:1500 No silence detection configured; assuming start of speech
405. 2018-02-22 16:19:47.190732 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
406. recv 335 bytes from udp/[192.168.168.211]:5060 at 16:19:47.218210:
407.    ------------------------------------------------------------------------
408.    SIP/2.0 100 Trying
409.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD
410.    From: "3097" <sip:3097@192.168.168.99>;tag=7eZH0mrrpcD4N
411.    To: <sip:3003@192.168.168.211>
412.    Date: Thu, 22 Feb 2018 10:49:48 GMT
413.    Call-ID: f0947313-9260-1236-51bb-000c295030a8
414.    CSeq: 119312229 INVITE
415.    Allow-Events: presence
416.    Content-Length: 0
417.  
418.    ------------------------------------------------------------------------
419. recv 422 bytes from udp/[192.168.168.211]:5060 at 16:19:47.222307:
420.    ------------------------------------------------------------------------
421.    SIP/2.0 403 Forbidden
422.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD
423.    From: "3097" <sip:3097@192.168.168.99>;tag=7eZH0mrrpcD4N
424.    To: <sip:3003@192.168.168.211>;tag=1141683192
425.    Date: Thu, 22 Feb 2018 10:49:48 GMT
426.    Call-ID: f0947313-9260-1236-51bb-000c295030a8
427.    CSeq: 119312229 INVITE
428.    Allow-Events: presence
429.    Server: Cisco-CUCM11.5
430.    Warning: 399 tacucmpub "Unknown calling DN"
431.    Content-Length: 0
432.  
433.    ------------------------------------------------------------------------
434. send 322 bytes to udp/[192.168.168.211]:5060 at 16:19:47.222539:
435.    ------------------------------------------------------------------------
436.    ACK sip:3003@192.168.168.211 SIP/2.0
437.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK068yyH59Ne5jD
438.    Max-Forwards: 68
439.    From: "3097" <sip:3097@192.168.168.99>;tag=7eZH0mrrpcD4N
440.    To: <sip:3003@192.168.168.211>;tag=1141683192
441.    Call-ID: f0947313-9260-1236-51bb-000c295030a8
442.    CSeq: 119312229 ACK
443.    Content-Length: 0
444.  
445.    ------------------------------------------------------------------------
446. 2018-02-22 16:19:47.210800 [DEBUG] sofia.c:7048 Channel sofia/external/3003 entering state [terminated][403]
447. 2018-02-22 16:19:47.210800 [NOTICE] sofia.c:8237 Hangup sofia/external/3003 [CS_CONSUME_MEDIA] [CALL_REJECTED]
448. 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)
449. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:850 (sofia/external/3003) Callstate Change DOWN -> HANGUP
450. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3003) State HANGUP
451. 2018-02-22 16:19:47.210800 [DEBUG] mod_sofia.c:438 Channel sofia/external/3003 hanging up, cause: CALL_REJECTED
452. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:60 sofia/external/3003 Standard HANGUP, cause: CALL_REJECTED
453. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3003) State HANGUP going to sleep
454. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:619 (sofia/external/3003) State Change CS_HANGUP -> CS_REPORTING
455. 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)
456. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3003) State REPORTING
457. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:174 sofia/external/3003 Standard REPORTING, cause: CALL_REJECTED
458. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3003) State REPORTING going to sleep
459. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_state_machine.c:610 (sofia/external/3003) State Change CS_REPORTING -> CS_DESTROY
460. 2018-02-22 16:19:47.210800 [DEBUG] switch_core_session.c:1664 Session 357 (sofia/external/3003) Locked, Waiting on external entities
461. 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_originate.c:3847 Originate Resulted in Error Cause: 21 [CALL_REJECTED]
462. 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1682 Session 357 (sofia/external/3003) Ended
463. 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/3003 [CS_DESTROY]
464. 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)
465. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3003) State DESTROY
466. 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:343 sofia/external/3003 SOFIA DESTROY
467. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:181 sofia/external/3003 Standard DESTROY
468. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3003) State DESTROY going to sleep
469. 2018-02-22 16:19:47.230733 [DEBUG] switch_channel.c:2047 (sofia/external/3097@192.168.168.211) Callstate Change RING_WAIT -> ACTIVE
470. 2018-02-22 16:19:47.230733 [INFO] mod_dptools.c:3418 Originate Failed.  Cause: CALL_REJECTED
471. 2018-02-22 16:19:47.230733 [NOTICE] switch_channel.c:4822 Hangup sofia/external/3097@192.168.168.211 [CS_EXECUTE] [CALL_REJECTED]
472. 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)
473. 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)
474. 2018-02-22 16:19:47.230733 [NOTICE] Transfer_test_1.js:19 Script exited with info []
475. 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)
476. 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
477. 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)
478. 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_async.c:1316 Stop recording file /usr/local/freeswitch/recording/external/_3003_3097.wav
479. 2018-02-22 16:19:47.230733 [DEBUG] switch_ivr_async.c:1380 Channel is hung up
480. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_media_bug.c:1294 Removing BUG from sofia/external/3097@192.168.168.211
481. 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
482. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3097@192.168.168.211) State HANGUP
483. 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
484. 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
485. 2018-02-22 16:19:47.230733 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/3097@192.168.168.211
486. 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
487. 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
488. 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
489. 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)
490. send 628 bytes to udp/[192.168.168.211]:5080 at 16:19:47.248647:
491.    ------------------------------------------------------------------------
492.    BYE sip:3097@192.168.168.211:5080 SIP/2.0
493.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK1F2Q0cpDKQU5r
494.    Max-Forwards: 70
495.    From: <sip:5559@192.168.168.99>;tag=655ryS7mS3pHa
496.    To: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
497.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
498.    CSeq: 119312229 BYE
499.    User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit
500.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
501.    Supported: timer, path, replaces
502.    Reason: Q.850;cause=21;text="CALL_REJECTED"
503.    Content-Length: 0
504.  
505.    ------------------------------------------------------------------------
506. 2018-02-22 16:19:47.230733 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3097@192.168.168.211) State REPORTING
507. 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
508. 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
509. 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
510. 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
511. 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1682 Session 356 (sofia/external/3097@192.168.168.211) Ended
512. 2018-02-22 16:19:47.230733 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/3097@192.168.168.211 [CS_DESTROY]
513. 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)
514. 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3097@192.168.168.211) State DESTROY
515. 2018-02-22 16:19:47.250735 [DEBUG] mod_sofia.c:343 sofia/external/3097@192.168.168.211 SOFIA DESTROY
516. 2018-02-22 16:19:47.250735 [DEBUG] switch_core_state_machine.c:181 sofia/external/3097@192.168.168.211 Standard DESTROY
517. 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
518. recv 396 bytes from udp/[192.168.168.211]:5080 at 16:19:47.262493:
519.    ------------------------------------------------------------------------
520.    SIP/2.0 200 OK
521.    Via: SIP/2.0/UDP 192.168.168.99:5080;rport;branch=z9hG4bK1F2Q0cpDKQU5r
522.    From: <sip:5559@192.168.168.99>;tag=655ryS7mS3pHa
523.    To: "User3" <sip:3097@192.168.168.211>;tag=18740~80bcd6de-d43b-4906-962e-9ebb5636d039-19614505
524.    Date: Thu, 22 Feb 2018 10:49:48 GMT
525.    Call-ID: 15ab0300-a8e1a047-208b-d3a8a8c0@192.168.168.211
526.    Server: Cisco-CUCM11.5
527.    CSeq: 119312229 BYE
528.    Content-Length: 0
529.  
530.    ------------------------------------------------------------------------
531. recv 394 bytes from udp/[192.168.168.211]:5080 at 16:20:00.984200:
532.    ------------------------------------------------------------------------
533.    OPTIONS sip:192.168.168.99:5080 SIP/2.0
534.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK2284628990d6
535.    From: <sip:192.168.168.211>;tag=1042369939
536.    To: <sip:192.168.168.99>
537.    Date: Thu, 22 Feb 2018 10:50:02 GMT
538.    Call-ID: 20fe2e80-a8e1a05a-208d-d3a8a8c0@192.168.168.211
539.    User-Agent: Cisco-CUCM11.5
540.    CSeq: 101 OPTIONS
541.    Contact: <sip:192.168.168.211:5080>
542.    Max-Forwards: 0
543.    Content-Length: 0
544.  
545.    ------------------------------------------------------------------------
546. send 607 bytes to udp/[192.168.168.211]:5080 at 16:20:00.984545:
547.    ------------------------------------------------------------------------
548.    SIP/2.0 200 OK
549.    Via: SIP/2.0/UDP 192.168.168.211:5080;branch=z9hG4bK2284628990d6
550.    From: <sip:192.168.168.211>;tag=1042369939
551.    To: <sip:192.168.168.99>;tag=8Qra2F9UKN3pH
552.    Call-ID: 20fe2e80-a8e1a05a-208d-d3a8a8c0@192.168.168.211
553.    CSeq: 101 OPTIONS
554.    Contact: <sip:gw+CUCM@192.168.168.99:5080;transport=udp;gw=CUCM>
555.    User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170526T224125Z~f17ac2feb2~32bit
556.    Accept: application/sdp
557.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
558.    Supported: timer, path, replaces
559.    Allow-Events: talk, hold, conference, refer
560.    Content-Length: 0
561.  
562.    ------------------------------------------------------------------------
563. freeswitch@fs01> /exit
564.  
565.