1. 2017-04-28 09:02:12.761114 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /var/log/freeswitch/cdr-csv/1002.csv
2. 2017-04-28 09:02:12.761114 [NOTICE] mod_logfile.c:192 New log started.
3. recv 604 bytes from udp/[192.168.1.104]:5060 at 09:02:26.780895:
4.    ------------------------------------------------------------------------
5.    INVITE sip:1002@172.17.0.3:5080 SIP/2.0
6.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0
7.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
8.    To: <sip:1002@172.17.0.3:5080>
9.    Call-ID: 1-5963@192.168.1.104
10.    CSeq: 2 INVITE
11.    Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
12.    Max-Forwards: 70
13.    Subject: Performance Test
14.    Session-Expires: 1800
15.    Min-SE: 900
16.    Content-Length:   215
17.    
18.    v=0
19.    o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
20.    s=Basic Session
21.    c=IN IP4 192.168.1.104
22.    t=0 0
23.    m=audio 6000 RTP/AVP 0 8 18 99
24.    a=rtpmap:99 telephone-event/8000
25.    a=fmtp:99 0-15
26.    a=fmtp:18 annexb=yes
27.    ------------------------------------------------------------------------
28. send 287 bytes to udp/[192.168.1.104]:5060 at 09:02:26.781391:
29.    ------------------------------------------------------------------------
30.    SIP/2.0 100 Trying
31.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0
32.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
33.    To: <sip:1002@172.17.0.3:5080>
34.    Call-ID: 1-5963@192.168.1.104
35.    CSeq: 2 INVITE
36.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
37.    Content-Length: 0
38.    
39.    ------------------------------------------------------------------------
40. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.771120 [NOTICE] switch_channel.c:1104 New Channel sofia/external/sipp@192.168.1.104:5060 [b67498b9-31db-433a-b901-5c12546ffc1a]
41. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_NEW (Cur 1 Tot 11)
42. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] sofia.c:9834 sofia/external/sipp@192.168.1.104:5060 receiving invite from 192.168.1.104:5060 version: 1.6.17 -34-0fc0946 64bit
43. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [received][100]
44. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] sofia.c:7058 Remote SDP:
45. b67498b9-31db-433a-b901-5c12546ffc1a v=0
46. b67498b9-31db-433a-b901-5c12546ffc1a o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
47. b67498b9-31db-433a-b901-5c12546ffc1a s=Basic Session
48. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 192.168.1.104
49. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
50. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 6000 RTP/AVP 0 8 18 99
51. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:18 annexb=yes
52. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
53. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-15
54. b67498b9-31db-433a-b901-5c12546ffc1a
55. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] sofia.c:7450 (sofia/external/sipp@192.168.1.104:5060) State Change CS_NEW -> CS_INIT
56. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:603 (sofia/external/sipp@192.168.1.104:5060) State NEW
57. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_INIT (Cur 1 Tot 11)
58. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@192.168.1.104:5060) State INIT
59. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_sofia.c:90 sofia/external/sipp@192.168.1.104:5060 SOFIA INIT
60. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:40 sofia/external/sipp@192.168.1.104:5060 Standard INIT
61. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:48 (sofia/external/sipp@192.168.1.104:5060) State Change CS_INIT -> CS_ROUTING
62. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@192.168.1.104:5060) State INIT going to sleep
63. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_ROUTING (Cur 1 Tot 11)
64. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_channel.c:2249 (sofia/external/sipp@192.168.1.104:5060) Callstate Change DOWN -> RINGING
65. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING
66. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_sofia.c:143 sofia/external/sipp@192.168.1.104:5060 SOFIA ROUTING
67. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:236 sofia/external/sipp@192.168.1.104:5060 Standard ROUTING
68. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [INFO] mod_dialplan_xml.c:637 Processing sipp <sipp>->1002 in context public
69. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->unloop] continue=false
70. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
71. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
72. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->outside_call] continue=true
73. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Absolute Condition [outside_call]
74. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(outside_call=true)
75. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
76. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->call_debug] continue=true
77. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never
78. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action info()
79. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->public_extensions] continue=false
80. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [public_extensions] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false
81. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action transfer(1002 XML default)
82. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:286 (sofia/external/sipp@192.168.1.104:5060) State Change CS_ROUTING -> CS_EXECUTE
83. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING going to sleep
84. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_EXECUTE (Cur 1 Tot 11)
85. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE
86. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_sofia.c:198 sofia/external/sipp@192.168.1.104:5060 SOFIA EXECUTE
87. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:328 sofia/external/sipp@192.168.1.104:5060 Standard EXECUTE
88. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(outside_call=true)
89. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [outside_call]=[true]
90. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 export(RFC2822_DATE=Fri, 28 Apr 2017 09:02:26 +0000)
91. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000]
92. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 info()
93. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [INFO] mod_dptools.c:1743 CHANNEL_DATA:
94. b67498b9-31db-433a-b901-5c12546ffc1a Channel-State: [CS_EXECUTE]
95. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Call-State: [RINGING]
96. b67498b9-31db-433a-b901-5c12546ffc1a Channel-State-Number: [4]
97. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
98. b67498b9-31db-433a-b901-5c12546ffc1a Unique-ID: [b67498b9-31db-433a-b901-5c12546ffc1a]
99. b67498b9-31db-433a-b901-5c12546ffc1a Call-Direction: [inbound]
100. b67498b9-31db-433a-b901-5c12546ffc1a Presence-Call-Direction: [inbound]
101. b67498b9-31db-433a-b901-5c12546ffc1a Channel-HIT-Dialplan: [true]
102. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Call-UUID: [b67498b9-31db-433a-b901-5c12546ffc1a]
103. b67498b9-31db-433a-b901-5c12546ffc1a Answer-State: [ringing]
104. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Direction: [inbound]
105. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Logical-Direction: [inbound]
106. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Username: [sipp]
107. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Dialplan: [XML]
108. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Caller-ID-Name: [sipp]
109. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Caller-ID-Number: [sipp]
110. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Orig-Caller-ID-Name: [sipp]
111. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Orig-Caller-ID-Number: [sipp]
112. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Network-Addr: [192.168.1.104]
113. b67498b9-31db-433a-b901-5c12546ffc1a Caller-ANI: [sipp]
114. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Destination-Number: [1002]
115. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Unique-ID: [b67498b9-31db-433a-b901-5c12546ffc1a]
116. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Source: [mod_sofia]
117. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Context: [public]
118. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
119. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Profile-Index: [1]
120. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Profile-Created-Time: [1493370146782570]
121. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Created-Time: [1493370146782570]
122. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Answered-Time: [0]
123. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Progress-Time: [0]
124. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Progress-Media-Time: [0]
125. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Hangup-Time: [0]
126. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Transfer-Time: [0]
127. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Resurrect-Time: [0]
128. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Bridged-Time: [0]
129. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Last-Hold: [0]
130. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Hold-Accum: [0]
131. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Screen-Bit: [true]
132. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Privacy-Hide-Name: [false]
133. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Privacy-Hide-Number: [false]
134. b67498b9-31db-433a-b901-5c12546ffc1a variable_direction: [inbound]
135. b67498b9-31db-433a-b901-5c12546ffc1a variable_uuid: [b67498b9-31db-433a-b901-5c12546ffc1a]
136. b67498b9-31db-433a-b901-5c12546ffc1a variable_session_id: [11]
137. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_user: [sipp]
138. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_port: [5060]
139. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_uri: [sipp@192.168.1.104:5060]
140. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_host: [192.168.1.104]
141. b67498b9-31db-433a-b901-5c12546ffc1a variable_video_media_flow: [sendrecv]
142. b67498b9-31db-433a-b901-5c12546ffc1a variable_audio_media_flow: [sendrecv]
143. b67498b9-31db-433a-b901-5c12546ffc1a variable_channel_name: [sofia/external/sipp@192.168.1.104:5060]
144. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_call_id: [1-5963@192.168.1.104]
145. b67498b9-31db-433a-b901-5c12546ffc1a variable_ep_codec_string: [CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b]
146. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_local_network_addr: [172.17.0.3]
147. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_network_ip: [192.168.1.104]
148. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_network_port: [5060]
149. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_received_ip: [192.168.1.104]
150. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_received_port: [5060]
151. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_protocol: [udp]
152. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_user_stripped: [sipp]
153. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_tag: [1]
154. b67498b9-31db-433a-b901-5c12546ffc1a variable_sofia_profile_name: [external]
155. b67498b9-31db-433a-b901-5c12546ffc1a variable_recovery_profile_name: [external]
156. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_via: [SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0]
157. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_display: [sipp]
158. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_from: [sipp <sip:sipp@192.168.1.104:5060>;tag=1]
159. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_to: [<sip:1002@172.17.0.3:5080>]
160. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_user: [1002]
161. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_port: [5080]
162. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_uri: [1002@172.17.0.3:5080]
163. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_host: [172.17.0.3]
164. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_user: [1002]
165. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_port: [5080]
166. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_uri: [1002@172.17.0.3:5080]
167. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_host: [172.17.0.3]
168. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_params: [transport=udp]
169. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_user: [sipp]
170. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_port: [5060]
171. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_uri: [sipp@192.168.1.104:5060]
172. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_host: [192.168.1.104]
173. b67498b9-31db-433a-b901-5c12546ffc1a variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
174. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_subject: [Performance Test]
175. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_host: [192.168.1.104]
176. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_port: [5060]
177. b67498b9-31db-433a-b901-5c12546ffc1a variable_max_forwards: [70]
178. b67498b9-31db-433a-b901-5c12546ffc1a variable_switch_r_sdp: [v=0
179. b67498b9-31db-433a-b901-5c12546ffc1a o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
180. b67498b9-31db-433a-b901-5c12546ffc1a s=Basic Session
181. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 192.168.1.104
182. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
183. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 6000 RTP/AVP 0 8 18 99
184. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:18 annexb=yes
185. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
186. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-15
187. b67498b9-31db-433a-b901-5c12546ffc1a ]
188. b67498b9-31db-433a-b901-5c12546ffc1a variable_endpoint_disposition: [DELAYED NEGOTIATION]
189. b67498b9-31db-433a-b901-5c12546ffc1a variable_DP_MATCH: [ARRAY::1002|:1002]
190. b67498b9-31db-433a-b901-5c12546ffc1a variable_call_uuid: [b67498b9-31db-433a-b901-5c12546ffc1a]
191. b67498b9-31db-433a-b901-5c12546ffc1a variable_outside_call: [true]
192. b67498b9-31db-433a-b901-5c12546ffc1a variable_RFC2822_DATE: [Fri, 28 Apr 2017 09:02:26 +0000]
193. variable_export_vars: [RFC2822_DATE]
194. variable_current_application: [info]
195.  
196.  
197.  
198. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 transfer(1002 XML default)
199. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_ivr.c:2165 (sofia/external/sipp@192.168.1.104:5060) State Change CS_EXECUTE -> CS_ROUTING
200. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/sipp@192.168.1.104:5060 to XML[1002@default]
201. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE going to sleep
202. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_ROUTING (Cur 1 Tot 11)
203. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING
204. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_sofia.c:143 sofia/external/sipp@192.168.1.104:5060 SOFIA ROUTING
205. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:236 sofia/external/sipp@192.168.1.104:5060 Standard ROUTING
206. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [INFO] mod_dialplan_xml.c:637 Processing sipp <sipp>->1002 in context default
207. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->unloop] continue=false
208. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
209. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
210. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->tod_example] continue=true
211. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Date/Time Match (PASS) [tod_example] break=on-false
212. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(open=true)
213. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->holiday_example] continue=true
214. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Date/TimeMatch (FAIL) [holiday_example] break=on-false
215. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->global-intercept] continue=false
216. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false
217. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->group-intercept] continue=false
218. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false
219. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->intercept-ext] continue=false
220. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false
221. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->redial] continue=false
222. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false
223. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->global] continue=true
224. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [global] ${call_debug}(true) =~ /^true$/ break=never
225. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action info()
226. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
227. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
228. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
229. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${switch_r_sdp}(v=0
230. b67498b9-31db-433a-b901-5c12546ffc1a o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
231. b67498b9-31db-433a-b901-5c12546ffc1a s=Basic Session
232. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 192.168.1.104
233. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
234. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 6000 RTP/AVP 0 8 18 99
235. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:18 annexb=yes
236. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
237. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-15
238. b67498b9-31db-433a-b901-5c12546ffc1a ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
239. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Absolute Condition [global]
240. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
241. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
242. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial/global/${uuid})
243. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
244. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->snom-demo-2] continue=false
245. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false
246. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->snom-demo-1] continue=false
247. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false
248. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->eavesdrop] continue=false
249. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
250. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->eavesdrop] continue=false
251. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false
252. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call_return] continue=false
253. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false
254. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->del-group] continue=false
255. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false
256. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->add-group] continue=false
257. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false
258. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call-group-simo] continue=false
259. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false
260. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call-group-order] continue=false
261. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false
262. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->extension-intercom] continue=false
263. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false
264. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->Local_Extension] continue=false
265. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false
266. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action export(dialed_extension=1002)
267. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(1 b s execute_extension::dx XML features)
268. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
269. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(3 b s execute_extension::cf XML features)
270. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
271. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(call_timeout=30)
272. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(hangup_after_bridge=true)
273. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(continue_on_fail=true)
274. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
275. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
276. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
277. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
278. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
279. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
280. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(3pcc_always_gen_sdp=true)
281. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bridge(user/${dialed_extension}@${domain_name})
282. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action answer()
283. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action sleep(1000)
284. b67498b9-31db-433a-b901-5c12546ffc1a Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
285. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:286 (sofia/external/sipp@192.168.1.104:5060) State Change CS_ROUTING -> CS_EXECUTE
286. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING going to sleep
287. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_EXECUTE (Cur 1 Tot 11)
288. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE
289. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_sofia.c:198 sofia/external/sipp@192.168.1.104:5060 SOFIA EXECUTE
290. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_core_state_machine.c:328 sofia/external/sipp@192.168.1.104:5060 Standard EXECUTE
291. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(open=true)
292. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [open]=[true]
293. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 info()
294. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [INFO] mod_dptools.c:1743 CHANNEL_DATA:
295. b67498b9-31db-433a-b901-5c12546ffc1a Channel-State: [CS_EXECUTE]
296. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Call-State: [RINGING]
297. b67498b9-31db-433a-b901-5c12546ffc1a Channel-State-Number: [4]
298. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
299. b67498b9-31db-433a-b901-5c12546ffc1a Unique-ID: [b67498b9-31db-433a-b901-5c12546ffc1a]
300. b67498b9-31db-433a-b901-5c12546ffc1a Call-Direction: [inbound]
301. b67498b9-31db-433a-b901-5c12546ffc1a Presence-Call-Direction: [inbound]
302. b67498b9-31db-433a-b901-5c12546ffc1a Channel-HIT-Dialplan: [true]
303. b67498b9-31db-433a-b901-5c12546ffc1a Channel-Call-UUID: [b67498b9-31db-433a-b901-5c12546ffc1a]
304. b67498b9-31db-433a-b901-5c12546ffc1a Answer-State: [ringing]
305. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Direction: [inbound]
306. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Logical-Direction: [inbound]
307. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Username: [sipp]
308. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Dialplan: [XML]
309. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Caller-ID-Name: [sipp]
310. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Caller-ID-Number: [sipp]
311. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Orig-Caller-ID-Name: [sipp]
312. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Orig-Caller-ID-Number: [sipp]
313. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Network-Addr: [192.168.1.104]
314. b67498b9-31db-433a-b901-5c12546ffc1a Caller-ANI: [sipp]
315. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Destination-Number: [1002]
316. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Unique-ID: [b67498b9-31db-433a-b901-5c12546ffc1a]
317. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Source: [mod_sofia]
318. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Transfer-Source: [1493370146:2180249a-d415-4991-8c10-41e208af4467:bl_xfer:1002/default/XML]
319. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Context: [default]
320. b67498b9-31db-433a-b901-5c12546ffc1a Caller-RDNIS: [1002]
321. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
322. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Profile-Index: [2]
323. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Profile-Created-Time: [1493370146782570]
324. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Created-Time: [1493370146782570]
325. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Answered-Time: [0]
326. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Progress-Time: [0]
327. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Progress-Media-Time: [0]
328. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Hangup-Time: [0]
329. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Transfer-Time: [0]
330. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Resurrect-Time: [0]
331. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Bridged-Time: [0]
332. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Last-Hold: [0]
333. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Channel-Hold-Accum: [0]
334. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Screen-Bit: [true]
335. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Privacy-Hide-Name: [false]
336. b67498b9-31db-433a-b901-5c12546ffc1a Caller-Privacy-Hide-Number: [false]
337. b67498b9-31db-433a-b901-5c12546ffc1a variable_direction: [inbound]
338. b67498b9-31db-433a-b901-5c12546ffc1a variable_uuid: [b67498b9-31db-433a-b901-5c12546ffc1a]
339. b67498b9-31db-433a-b901-5c12546ffc1a variable_session_id: [11]
340. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_user: [sipp]
341. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_port: [5060]
342. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_uri: [sipp@192.168.1.104:5060]
343. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_host: [192.168.1.104]
344. b67498b9-31db-433a-b901-5c12546ffc1a variable_video_media_flow: [sendrecv]
345. b67498b9-31db-433a-b901-5c12546ffc1a variable_audio_media_flow: [sendrecv]
346. b67498b9-31db-433a-b901-5c12546ffc1a variable_channel_name: [sofia/external/sipp@192.168.1.104:5060]
347. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_call_id: [1-5963@192.168.1.104]
348. b67498b9-31db-433a-b901-5c12546ffc1a variable_ep_codec_string: [CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b]
349. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_local_network_addr: [172.17.0.3]
350. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_network_ip: [192.168.1.104]
351. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_network_port: [5060]
352. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_received_ip: [192.168.1.104]
353. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_received_port: [5060]
354. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_protocol: [udp]
355. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_user_stripped: [sipp]
356. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_tag: [1]
357. b67498b9-31db-433a-b901-5c12546ffc1a variable_sofia_profile_name: [external]
358. b67498b9-31db-433a-b901-5c12546ffc1a variable_recovery_profile_name: [external]
359. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_via: [SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0]
360. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_from_display: [sipp]
361. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_from: [sipp <sip:sipp@192.168.1.104:5060>;tag=1]
362. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_full_to: [<sip:1002@172.17.0.3:5080>]
363. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_user: [1002]
364. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_port: [5080]
365. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_uri: [1002@172.17.0.3:5080]
366. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_req_host: [172.17.0.3]
367. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_user: [1002]
368. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_port: [5080]
369. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_uri: [1002@172.17.0.3:5080]
370. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_to_host: [172.17.0.3]
371. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_params: [transport=udp]
372. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_user: [sipp]
373. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_port: [5060]
374. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_uri: [sipp@192.168.1.104:5060]
375. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_contact_host: [192.168.1.104]
376. b67498b9-31db-433a-b901-5c12546ffc1a variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
377. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_subject: [Performance Test]
378. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_host: [192.168.1.104]
379. b67498b9-31db-433a-b901-5c12546ffc1a variable_sip_via_port: [5060]
380. b67498b9-31db-433a-b901-5c12546ffc1a variable_switch_r_sdp: [v=0
381. b67498b9-31db-433a-b901-5c12546ffc1a o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
382. b67498b9-31db-433a-b901-5c12546ffc1a s=Basic Session
383. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 192.168.1.104
384. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
385. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 6000 RTP/AVP 0 8 18 99
386. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:18 annexb=yes
387. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
388. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-15
389. b67498b9-31db-433a-b901-5c12546ffc1a ]
390. b67498b9-31db-433a-b901-5c12546ffc1a variable_endpoint_disposition: [DELAYED NEGOTIATION]
391. b67498b9-31db-433a-b901-5c12546ffc1a variable_outside_call: [true]
392. b67498b9-31db-433a-b901-5c12546ffc1a variable_RFC2822_DATE: [Fri, 28 Apr 2017 09:02:26 +0000]
393. b67498b9-31db-433a-b901-5c12546ffc1a variable_export_vars: [RFC2822_DATE]
394. variable_max_forwards: [69]
395. variable_transfer_history: [1493370146:2180249a-d415-4991-8c10-41e208af4467:bl_xfer:1002/default/XML]
396. variable_transfer_source: [1493370146:2180249a-d415-4991-8c10-41e208af4467:bl_xfer:1002/default/XML]
397. variable_DP_MATCH: [ARRAY::1002|:1002]
398. variable_call_uuid: [b67498b9-31db-433a-b901-5c12546ffc1a]
399. variable_open: [true]
400. variable_current_application: [info]
401.  
402.  
403.  
404. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-spymap/sipp/b67498b9-31db-433a-b901-5c12546ffc1a)
405. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial/sipp/1002)
406. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial/global/b67498b9-31db-433a-b901-5c12546ffc1a)
407. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 export(RFC2822_DATE=Fri, 28 Apr 2017 09:02:26 +0000)
408. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000]
409. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 export(dialed_extension=1002)
410. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.782570 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1002]
411. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(1 b s execute_extension::dx XML features)
412. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *1 execute_extension::dx XML features
413. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/sipp.2017-04-28-09-02-26.wav)
414. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/sipp.2017-04-28-09-02-26.wav
415. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(3 b s execute_extension::cf XML features)
416. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *3 execute_extension::cf XML features
417. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(4 b s execute_extension::att_xfer XML features)
418. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *4 execute_extension::att_xfer XML features
419. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(call_timeout=30)
420. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [call_timeout]=[30]
421. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(hangup_after_bridge=true)
422. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [hangup_after_bridge]=[true]
423. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(continue_on_fail=true)
424. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [continue_on_fail]=[true]
425. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-call_return/1002/sipp)
426. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/1002/b67498b9-31db-433a-b901-5c12546ffc1a)
427. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(called_party_callgroup=techsupport)
428. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [called_party_callgroup]=[techsupport]
429. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/techsupport/b67498b9-31db-433a-b901-5c12546ffc1a)
430. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/global/b67498b9-31db-433a-b901-5c12546ffc1a)
431. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial/techsupport/b67498b9-31db-433a-b901-5c12546ffc1a)
432. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 set(3pcc_always_gen_sdp=true)
433. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [3pcc_always_gen_sdp]=[true]
434. b67498b9-31db-433a-b901-5c12546ffc1a EXECUTE sofia/external/sipp@192.168.1.104:5060 bridge(user/1002@172.17.0.3)
435. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000] to event
436. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000] to event
437. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
438. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
439. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000] to event
440. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 09:02:26 +0000] to event
441. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
442. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
443. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@172.17.0.1:15060 [597aefe7-3040-4d8a-9ddf-c0a0a02eb028]
444. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] mod_sofia.c:4818 (sofia/internal/1002@172.17.0.1:15060) State Change CS_NEW -> CS_INIT
445. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_INIT (Cur 2 Tot 12)
446. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.791102 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
447. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@172.17.0.1:15060) State INIT
448. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] mod_sofia.c:90 sofia/internal/1002@172.17.0.1:15060 SOFIA INIT
449. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] sofia_glue.c:1295 sofia/internal/1002@172.17.0.1:15060 sending invite version: 1.6.17 -34-0fc0946 64bit
450. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 Local SDP:
451. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 v=0
452. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 o=FreeSWITCH 1493346454 1493346455 IN IP4 172.17.0.3
453. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 s=FreeSWITCH
454. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 c=IN IP4 172.17.0.3
455. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 t=0 0
456. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 m=audio 23692 RTP/AVP 0 8 101
457. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=rtpmap:0 PCMU/8000
458. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=rtpmap:8 PCMA/8000
459. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=rtpmap:101 telephone-event/8000
460. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=fmtp:101 0-16
461. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=ptime:20
462. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=sendrecv
463. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028
464. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@172.17.0.1:15060 Standard INIT
465. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@172.17.0.1:15060) State Change CS_INIT -> CS_ROUTING
466. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@172.17.0.1:15060) State INIT going to sleep
467. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_ROUTING (Cur 2 Tot 12)
468. send 1172 bytes to udp/[172.17.0.1]:15060 at 09:02:26.796066:
469.    ------------------------------------------------------------------------
470.    INVITE sip:1002@172.17.0.1:15060;transport=udp SIP/2.0
471.    Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKNcyrH6SD8Bcgc
472.    Max-Forwards: 68
473.    From: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
474.    To: <sip:1002@172.17.0.1:15060;transport=udp>
475.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
476.    CSeq: 106349009 INVITE
477.    Contact: <sip:mod_sofia@172.17.0.3:5060>
478.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
479.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
480.    Supported: timer, path, replaces
481.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
482.    Content-Type: application/sdp
483.    Content-Disposition: session
484.    Content-Length: 240
485.    X-FS-Support: update_display,send_info
486.    Remote-Party-ID: "sipp" <sip:sipp@172.17.0.3>;party=calling;screen=yes;privacy=off
487.    
488.    v=0
489.    o=FreeSWITCH 1493346454 1493346455 IN IP4 172.17.0.3
490.    s=FreeSWITCH
491.    c=IN IP4 172.17.0.3
492.    t=0 0
493.    m=audio 23692 RTP/AVP 0 8 101
494.    a=rtpmap:0 PCMU/8000
495.    a=rtpmap:8 PCMA/8000
496.    a=rtpmap:101 telephone-event/8000
497.    a=fmtp:101 0-16
498.    a=ptime:20
499.    ------------------------------------------------------------------------
500. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [calling][0]
501. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@172.17.0.1:15060) State ROUTING
502. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] mod_sofia.c:143 sofia/internal/1002@172.17.0.1:15060 SOFIA ROUTING
503. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1002@172.17.0.1:15060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
504. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@172.17.0.1:15060) State ROUTING going to sleep
505. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 12)
506. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@172.17.0.1:15060) State CONSUME_MEDIA
507. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.791102 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@172.17.0.1:15060) State CONSUME_MEDIA going to sleep
508. recv 257 bytes from udp/[172.17.0.1]:15060 at 09:02:26.823639:
509.    ------------------------------------------------------------------------
510.    SIP/2.0 100 Trying
511.    Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKNcyrH6SD8Bcgc
512.    From: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
513.    To: <sip:1002@172.17.0.1:15060;transport=udp>
514.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
515.    CSeq: 106349009 INVITE
516.    
517.    ------------------------------------------------------------------------
518. recv 348 bytes from udp/[172.17.0.1]:15060 at 09:02:26.842451:
519.    ------------------------------------------------------------------------
520.    SIP/2.0 180 Ringing
521.    Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKNcyrH6SD8Bcgc
522.    From: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
523.    To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=dHv2qIq
524.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
525.    CSeq: 106349009 INVITE
526.    User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
527.    Supported: replaces, outbound
528.    
529.    ------------------------------------------------------------------------
530. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.841111 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [proceeding][180]
531. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.841111 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/1002@172.17.0.1:15060!
532. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:26.841111 [DEBUG] switch_channel.c:3345 (sofia/internal/1002@172.17.0.1:15060) Callstate Change DOWN -> RINGING
533. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.851101 [NOTICE] mod_sofia.c:2272 Ring-Ready sofia/external/sipp@192.168.1.104:5060!
534. send 634 bytes to udp/[192.168.1.104]:5060 at 09:02:26.857032:
535.    ------------------------------------------------------------------------
536.    SIP/2.0 180 Ringing
537.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0
538.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
539.    To: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
540.    Call-ID: 1-5963@192.168.1.104
541.    CSeq: 2 INVITE
542.    Contact: <sip:1002@172.17.0.3:5080;transport=udp>
543.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
544.    Accept: application/sdp
545.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
546.    Supported: timer, path, replaces
547.    Allow-Events: talk, hold, conference, refer
548.    Content-Length: 0
549.    Remote-Party-ID: "1002" <sip:1002@172.17.0.3>;party=calling;privacy=off;screen=no
550.    
551.    ------------------------------------------------------------------------
552. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.851101 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [early][180]
553. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:26.851101 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/external/sipp@192.168.1.104:5060!
554. recv 744 bytes from udp/[172.17.0.1]:15060 at 09:02:33.267901:
555.    ------------------------------------------------------------------------
556.    SIP/2.0 200 Ok
557.    Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKNcyrH6SD8Bcgc
558.    From: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
559.    To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=dHv2qIq
560.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
561.    CSeq: 106349009 INVITE
562.    User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
563.    Supported: replaces, outbound
564.    Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
565.    Contact: <sip:1002@172.17.0.1:15060;transport=udp>;+sip.instance="<urn:uuid:7762182d-541d-4148-a234-ca1f236a6606>"
566.    Content-Type: application/sdp
567.    Content-Length: 142
568.    
569.    v=0
570.    o=1002 2302 3120 IN IP4 172.17.0.1
571.    s=Talk
572.    c=IN IP4 172.17.0.1
573.    t=0 0
574.    m=audio 7078 RTP/AVP 0 8 101
575.    a=rtpmap:101 telephone-event/8000
576.    ------------------------------------------------------------------------
577. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [completing][200]
578. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] sofia.c:7058 Remote SDP:
579. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 v=0
580. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 o=1002 2302 3120 IN IP4 172.17.0.1
581. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 s=Talk
582. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 c=IN IP4 172.17.0.1
583. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 t=0 0
584. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 m=audio 7078 RTP/AVP 0 8 101
585. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 a=rtpmap:101 telephone-event/8000
586. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028
587. send 378 bytes to udp/[172.17.0.1]:15060 at 09:02:33.269338:
588.    ------------------------------------------------------------------------
589.    ACK sip:1002@172.17.0.1:15060;transport=udp SIP/2.0
590.    Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKpNQHK1aH5m22Q
591.    Max-Forwards: 70
592.    From: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
593.    To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=dHv2qIq
594.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
595.    CSeq: 106349009 ACK
596.    Contact: <sip:mod_sofia@172.17.0.3:5060>
597.    Content-Length: 0
598.    
599.    ------------------------------------------------------------------------
600. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [ready][200]
601. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
602. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
603. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
604. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
605. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
606. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
607. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
608. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1002@172.17.0.1:15060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
609. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@172.17.0.1:15060 Original read codec set to PCMU:0
610. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
611. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:4754 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf send payload to 101 recv payload to 101
612. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1002@172.17.0.1:15060] 172.17.0.3 port 23692 -> 172.17.0.1 port 7078 codec: 0 ms: 20
613. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.261129 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
614. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.271108 [DEBUG] switch_core_media.c:7166 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf send payload to 101
615. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.271108 [DEBUG] switch_core_media.c:7173 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf receive payload to 101
616. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.271108 [DEBUG] switch_core_media.c:7196 sofia/internal/1002@172.17.0.1:15060 Set rtp dtmf delay to 40
617. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.271108 [NOTICE] sofia.c:8182 Channel [sofia/internal/1002@172.17.0.1:15060] has been answered
618. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.271108 [DEBUG] switch_channel.c:3772 (sofia/internal/1002@172.17.0.1:15060) Callstate Change RINGING -> ACTIVE
619. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
620. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
621. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
622. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
623. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
624. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
625. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
626. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
627. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
628. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
629. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
630. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
631. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
632. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
633. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 99@8000
634. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:3056 Set Codec sofia/external/sipp@192.168.1.104:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
635. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_codec.c:111 sofia/external/sipp@192.168.1.104:5060 Original read codec set to PCMU:0
636. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 99@8000
637. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:4754 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 99 recv payload to 99
638. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/external/sipp@192.168.1.104:5060] 172.17.0.3 port 21658 -> 192.168.1.104 port 6000 codec: 0 ms: 20
639. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.281116 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
640. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_core_media.c:7166 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 99
641. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_core_media.c:7173 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf receive payload to 99
642. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_core_media.c:7196 sofia/external/sipp@192.168.1.104:5060 Set rtp dtmf delay to 40
643. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/sipp@192.168.1.104:5060!
644. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_channel.c:3473 (sofia/external/sipp@192.168.1.104:5060) Callstate Change RINGING -> EARLY
645. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/external/sipp@192.168.1.104:5060.
646. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/sipp@192.168.1.104:5060:
647. b67498b9-31db-433a-b901-5c12546ffc1a v=0
648. b67498b9-31db-433a-b901-5c12546ffc1a o=FreeSWITCH 1493348495 1493348496 IN IP4 172.17.0.3
649. b67498b9-31db-433a-b901-5c12546ffc1a s=FreeSWITCH
650. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 172.17.0.3
651. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
652. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 21658 RTP/AVP 0 99
653. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:0 PCMU/8000
654. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
655. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-16
656. b67498b9-31db-433a-b901-5c12546ffc1a a=ptime:20
657. b67498b9-31db-433a-b901-5c12546ffc1a a=sendrecv
658. b67498b9-31db-433a-b901-5c12546ffc1a
659. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [NOTICE] switch_ivr_originate.c:3632 Channel [sofia/external/sipp@192.168.1.104:5060] has been answered
660. send 926 bytes to udp/[192.168.1.104]:5060 at 09:02:33.292962:
661.    ------------------------------------------------------------------------
662.    SIP/2.0 200 OK
663.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-0
664.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
665.    To: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
666.    Call-ID: 1-5963@192.168.1.104
667.    CSeq: 2 INVITE
668.    Contact: <sip:1002@172.17.0.3:5080;transport=udp>
669.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
670.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
671.    Supported: timer, path, replaces
672.    Allow-Events: talk, hold, conference, refer
673.    Session-Expires: 1800;refresher=uas
674.    Content-Type: application/sdp
675.    Content-Disposition: session
676.    Content-Length: 213
677.    Remote-Party-ID: "Outbound Call" <sip:1002@172.17.0.3>;party=calling;privacy=off;screen=no
678.    
679.    v=0
680.    o=FreeSWITCH 1493348495 1493348496 IN IP4 172.17.0.3
681.    s=FreeSWITCH
682.    c=IN IP4 172.17.0.3
683.    t=0 0
684.    m=audio 21658 RTP/AVP 0 99
685.    a=rtpmap:0 PCMU/8000
686.    a=rtpmap:99 telephone-event/8000
687.    a=fmtp:99 0-16
688.    a=ptime:20
689.    ------------------------------------------------------------------------
690. recv 414 bytes from udp/[192.168.1.104]:5060 at 09:02:33.293255:
691.    ------------------------------------------------------------------------
692.    ACK sip:1002@172.17.0.3:5080;transport=udp SIP/2.0
693.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-5
694.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
695.    To: sut <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
696.    Call-ID: 1-5963@192.168.1.104
697.    CSeq: 2 ACK
698.    Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
699.    Max-Forwards: 70
700.    Subject: Performance Test
701.    Content-Type: application/sdp
702.    Content-Length:     0
703.    
704.    ------------------------------------------------------------------------
705. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_channel.c:3772 (sofia/external/sipp@192.168.1.104:5060) Callstate Change EARLY -> ACTIVE
706. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [completed][200]
707. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [ready][200]
708. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1002@172.17.0.1:15060]
709. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.291105 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1002@172.17.0.1:15060]
710. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.291105 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/1002@172.17.0.1:15060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
711. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.291105 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 12)
712. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.291105 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1002@172.17.0.1:15060) State EXCHANGE_MEDIA
713. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.291105 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
714. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:33.321105 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
715. recv 636 bytes from udp/[192.168.1.104]:5060 at 09:02:33.796706:
716.    ------------------------------------------------------------------------
717.    INVITE sip:1002@172.17.0.3:5080;transport=udp SIP/2.0
718.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-7
719.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
720.    To: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
721.    Call-ID: 1-5963@192.168.1.104
722.    CSeq: 4 INVITE
723.    Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
724.    Max-Forwards: 70
725.    Subject: Performance Test
726.    Session-Expires: 1800
727.    Min-SE: 900
728.    Content-Length:   215
729.    
730.    v=0
731.    o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
732.    s=Basic Session
733.    c=IN IP4 192.168.1.104
734.    t=0 0
735.    m=audio 6000 RTP/AVP 0 8 18 99
736.    a=rtpmap:99 telephone-event/8000
737.    a=fmtp:99 0-15
738.    a=fmtp:18 annexb=yes
739.    ------------------------------------------------------------------------
740. send 305 bytes to udp/[192.168.1.104]:5060 at 09:02:33.796975:
741.    ------------------------------------------------------------------------
742.    SIP/2.0 100 Trying
743.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-7
744.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
745.    To: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
746.    Call-ID: 1-5963@192.168.1.104
747.    CSeq: 4 INVITE
748.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
749.    Content-Length: 0
750.    
751.    ------------------------------------------------------------------------
752. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [received][100]
753. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] sofia.c:7055 Duplicate SDP
754. b67498b9-31db-433a-b901-5c12546ffc1a v=0
755. b67498b9-31db-433a-b901-5c12546ffc1a o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
756. b67498b9-31db-433a-b901-5c12546ffc1a s=Basic Session
757. b67498b9-31db-433a-b901-5c12546ffc1a c=IN IP4 192.168.1.104
758. b67498b9-31db-433a-b901-5c12546ffc1a t=0 0
759. b67498b9-31db-433a-b901-5c12546ffc1a m=audio 6000 RTP/AVP 0 8 18 99
760. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:18 annexb=yes
761. b67498b9-31db-433a-b901-5c12546ffc1a a=rtpmap:99 telephone-event/8000
762. b67498b9-31db-433a-b901-5c12546ffc1a a=fmtp:99 0-15
763. b67498b9-31db-433a-b901-5c12546ffc1a
764. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
765. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
766. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
767. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
768. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
769. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
770. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
771. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
772. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
773. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
774. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
775. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
776. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
777. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
778. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 99@8000
779. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 99@8000
780. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.801109 [DEBUG] switch_core_media.c:4754 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 99 recv payload to 99
781. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.811106 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/external/sipp@192.168.1.104:5060.
782. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.811106 [DEBUG] sofia.c:7963 Processing updated SDP
783. send 814 bytes to udp/[192.168.1.104]:5060 at 09:02:33.811351:
784.    ------------------------------------------------------------------------
785.    SIP/2.0 200 OK
786.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-7
787.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
788.    To: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
789.    Call-ID: 1-5963@192.168.1.104
790.    CSeq: 4 INVITE
791.    Contact: <sip:1002@172.17.0.3:5080;transport=udp>
792.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
793.    Accept: application/sdp
794.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
795.    Supported: timer, path, replaces
796.    Session-Expires: 1800;refresher=uas
797.    Content-Type: application/sdp
798.    Content-Disposition: session
799.    Content-Length: 213
800.    
801.    v=0
802.    o=FreeSWITCH 1493348495 1493348496 IN IP4 172.17.0.3
803.    s=FreeSWITCH
804.    c=IN IP4 172.17.0.3
805.    t=0 0
806.    m=audio 21658 RTP/AVP 0 99
807.    a=rtpmap:0 PCMU/8000
808.    a=rtpmap:99 telephone-event/8000
809.    a=fmtp:99 0-16
810.    a=ptime:20
811.    ------------------------------------------------------------------------
812. recv 415 bytes from udp/[192.168.1.104]:5060 at 09:02:33.811696:
813.    ------------------------------------------------------------------------
814.    ACK sip:1002@172.17.0.3:5080;transport=udp SIP/2.0
815.    Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-5963-1-11
816.    From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
817.    To: sut <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
818.    Call-ID: 1-5963@192.168.1.104
819.    CSeq: 4 ACK
820.    Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
821.    Max-Forwards: 70
822.    Subject: Performance Test
823.    Content-Type: application/sdp
824.    Content-Length:     0
825.    
826.    ------------------------------------------------------------------------
827. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.821101 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [completed][200]
828. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:33.821101 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [ready][200]
829. recv 331 bytes from udp/[172.17.0.1]:15060 at 09:02:41.915681:
830.    ------------------------------------------------------------------------
831.    BYE sip:mod_sofia@172.17.0.3:5060 SIP/2.0
832.    Via: SIP/2.0/UDP 172.17.0.1:15060;branch=z9hG4bK.Wz0dMShp9;rport
833.    From: <sip:1002@172.17.0.1>;tag=dHv2qIq
834.    To: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
835.    CSeq: 111 BYE
836.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
837.    Max-Forwards: 70
838.    User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
839.    
840.    ------------------------------------------------------------------------
841. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.921103 [NOTICE] sofia.c:1012 Hangup sofia/internal/1002@172.17.0.1:15060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
842. send 466 bytes to udp/[172.17.0.1]:15060 at 09:02:41.931136:
843.    ------------------------------------------------------------------------
844.    SIP/2.0 200 OK
845.    Via: SIP/2.0/UDP 172.17.0.1:15060;branch=z9hG4bK.Wz0dMShp9;rport=15060
846.    From: <sip:1002@172.17.0.1>;tag=dHv2qIq
847.    To: "sipp" <sip:sipp@172.17.0.3>;tag=rBaDXZQ0NQpvD
848.    Call-ID: 3e0d7216-a694-1235-0e9b-0242ac110003
849.    CSeq: 111 BYE
850.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
851.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
852.    Supported: timer, path, replaces
853.    Content-Length: 0
854.    
855.    ------------------------------------------------------------------------
856. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1002@172.17.0.1:15060]
857. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1002@172.17.0.1:15060) State EXCHANGE_MEDIA going to sleep
858. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_HANGUP (Cur 2 Tot 12)
859. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1002@172.17.0.1:15060) Callstate Change ACTIVE -> HANGUP
860. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@172.17.0.1:15060) State HANGUP
861. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1002@172.17.0.1:15060 hanging up, cause: NORMAL_CLEARING
862. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1002@172.17.0.1:15060 Standard HANGUP, cause: NORMAL_CLEARING
863. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@172.17.0.1:15060) State HANGUP going to sleep
864. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1002@172.17.0.1:15060) State Change CS_HANGUP -> CS_REPORTING
865. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_REPORTING (Cur 2 Tot 12)
866. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@172.17.0.1:15060) State REPORTING
867. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1002@172.17.0.1:15060 Standard REPORTING, cause: NORMAL_CLEARING
868. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@172.17.0.1:15060) State REPORTING going to sleep
869. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1002@172.17.0.1:15060) State Change CS_REPORTING -> CS_DESTROY
870. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.931100 [DEBUG] switch_core_session.c:1664 Session 12 (sofia/internal/1002@172.17.0.1:15060) Locked, Waiting on external entities
871. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.941125 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/sipp@192.168.1.104:5060]
872. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.941125 [NOTICE] switch_ivr_bridge.c:1751 Hangup sofia/external/sipp@192.168.1.104:5060 [CS_EXECUTE] [NORMAL_CLEARING]
873. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.941125 [NOTICE] switch_core_session.c:1682 Session 12 (sofia/internal/1002@172.17.0.1:15060) Ended
874. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.941125 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1002@172.17.0.1:15060 [CS_DESTROY]
875. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_session.c:2814 sofia/external/sipp@192.168.1.104:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
876. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE going to sleep
877. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_HANGUP (Cur 1 Tot 12)
878. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_DESTROY (Cur 1 Tot 12)
879. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@172.17.0.1:15060) State DESTROY
880. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.951145 [DEBUG] mod_sofia.c:343 sofia/internal/1002@172.17.0.1:15060 SOFIA DESTROY
881. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:850 (sofia/external/sipp@192.168.1.104:5060) Callstate Change ACTIVE -> HANGUP
882. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1002@172.17.0.1:15060 Standard DESTROY
883. 597aefe7-3040-4d8a-9ddf-c0a0a02eb028 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@172.17.0.1:15060) State DESTROY going to sleep
884. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@192.168.1.104:5060) State HANGUP
885. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] mod_sofia.c:432 sofia/external/sipp@192.168.1.104:5060 Overriding SIP cause 480 with 200 from the other leg
886. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] mod_sofia.c:438 Channel sofia/external/sipp@192.168.1.104:5060 hanging up, cause: NORMAL_CLEARING
887. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/sipp@192.168.1.104:5060
888. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:60 sofia/external/sipp@192.168.1.104:5060 Standard HANGUP, cause: NORMAL_CLEARING
889. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@192.168.1.104:5060) State HANGUP going to sleep
890. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:619 (sofia/external/sipp@192.168.1.104:5060) State Change CS_HANGUP -> CS_REPORTING
891. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_REPORTING (Cur 1 Tot 12)
892. send 541 bytes to udp/[192.168.1.104]:5060 at 09:02:41.951802:
893.    ------------------------------------------------------------------------
894.    BYE sip:sipp@192.168.1.104:5060;transport=udp SIP/2.0
895.    Via: SIP/2.0/UDP 172.17.0.3:5080;rport;branch=z9hG4bKpeQKpe3tN1Fpj
896.    Max-Forwards: 70b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@192.168.1.104:5060) State REPORTING
897.  
898.    From: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
899.    To: sipp <sip:sipp@192.168.1.104:5060>;tag=1
900.    Call-ID: 1-5963@192.168.1.104
901.    CSeq: 106349016 BYE
902.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
903.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
904.    Supported: timer, path, replaces
905.    Reason: Q.850;cause=16;text="NORMAL_CLEARING"
906.    Content-Length: 0
907.    
908.    ------------------------------------------------------------------------
909. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:174 sofia/external/sipp@192.168.1.104:5060 Standard REPORTING, cause: NORMAL_CLEARING
910. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@192.168.1.104:5060) State REPORTING going to sleep
911. recv 255 bytes from udp/[192.168.1.104]:5060 at 09:02:41.951994:
912.    ------------------------------------------------------------------------
913.    SIP/2.0 200 OK
914.    Via: SIP/2.0/UDP 172.17.0.3:5080;rport;branch=z9hG4bKpeQKpe3tN1Fpj
915.    From: <sip:1002@172.17.0.3:5080>;tag=pp114H3H8549c
916.    To: sipp <sip:sipp@192.168.1.104:5060>;tag=1
917.    Call-ID: 1-5963@192.168.1.104
918.    CSeq: 106349016 BYE
919.    Content-Length: 0
920.    
921.    ------------------------------------------------------------------------
922. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:610 (sofia/external/sipp@192.168.1.104:5060) State Change CS_REPORTING -> CS_DESTROY
923. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_session.c:1664 Session 11 (sofia/external/sipp@192.168.1.104:5060) Locked, Waiting on external entities
924. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [NOTICE] switch_core_session.c:1682 Session 11 (sofia/external/sipp@192.168.1.104:5060) Ended
925. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/sipp@192.168.1.104:5060 [CS_DESTROY]
926. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:741 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_DESTROY (Cur 0 Tot 12)
927. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@192.168.1.104:5060) State DESTROY
928. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] mod_sofia.c:343 sofia/external/sipp@192.168.1.104:5060 SOFIA DESTROY
929. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:181 sofia/external/sipp@192.168.1.104:5060 Standard DESTROY
930. b67498b9-31db-433a-b901-5c12546ffc1a 2017-04-28 09:02:41.951145 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@192.168.1.104:5060) State DESTROY going to sleep
931. 2017-04-28 09:02:51.461114 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /var/log/freeswitch/cdr-csv/Master.csv
932.