From Joshua Young, 7 Years ago, written in Plain Text.
- go back
Embed
Viewing differences between and video record test output
  1. freeswitch@freeswitch>
  2. recv 1170 bytes from udp/[192.168.1.213]:5060 at 18:47:12.095185:
  3.    ------------------------------------------------------------------------
  4.    INVITE sip:1001@192.168.1.8;user=phone SIP/2.0
  5.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK20c45d64e8611c93
  6.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  7.    To: <sip:1001@192.168.1.8;user=phone>
  8.    Contact: <sip:1010@192.168.1.213:5060;transport=udp;user=phone>
  9.    Supported: replaces, timer, path
  10.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  11.    CSeq: 12674 INVITE
  12.    User-Agent: Grandstream GXV3000 1.2.3.7
  13.    Max-Forwards: 70
  14.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  15.    Content-Type: application/sdp
  16.    Content-Length: 577
  17.  
  18.    v=0
  19.    o=1010 8000 8000 IN IP4 192.168.1.213
  20.    s=SIP Call
  21.    c=IN IP4 192.168.1.213
  22.    t=0 0
  23.    m=audio 5004 RTP/AVP 0 8 4 18 3 2
  24.    a=sendrecv
  25.    a=rtpmap:0 PCMU/8000
  26.    a=rtpmap:8 PCMA/8000
  27.    a=rtpmap:4 G723/8000
  28.    a=rtpmap:18 G729/8000
  29.    a=rtpmap:3 GSM/8000
  30.    a=rtpmap:2 G726-32/8000
  31.    a=ptime:20
  32.    m=video 5006 RTP/AVP 99 34 103
  33.    a=sendrecv
  34.    a=rtpmap:99 H264/90000
  35.    a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  36.    a=rtpmap:34 H263/90000
  37.    a=fmtp:34 CIF=2 MaxBR=1280
  38.    a=rtpmap:103 H263-1998/90000
  39.    a=fmtp:103 CIF=2 MaxBR=1280
  40.    a=framerate:15
  41.    ------------------------------------------------------------------------
  42. send 345 bytes to udp/[192.168.1.213]:5060 at 18:47:12.095733:
  43.    ------------------------------------------------------------------------
  44.    SIP/2.0 100 Trying
  45.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK20c45d64e8611c93
  46.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  47.    To: <sip:1001@192.168.1.8;user=phone>
  48.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  49.    CSeq: 12674 INVITE
  50.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  51.    Content-Length: 0
  52.  
  53.    ------------------------------------------------------------------------
  54. 2017-05-08 18:47:12.088131 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1010@192.168.1.8 [870e01be-202b-4efb-971a-3a5c695b3fbc]
  55. 2017-05-08 18:47:12.088131 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_NEW (Cur 1 Tot 17)
  56. 2017-05-08 18:47:12.088131 [DEBUG] sofia.c:9834 sofia/internal/1010@192.168.1.8 receiving invite from 192.168.1.213:5060 version: 1.6.17 -34-0fc0946 64bit
  57. 2017-05-08 18:47:12.088131 [DEBUG] sofia.c:10005 IP 192.168.1.213 Rejected by acl "domains". Falling back to Digest auth.
  58. send 847 bytes to udp/[192.168.1.213]:5060 at 18:47:12.097608:
  59.    ------------------------------------------------------------------------
  60.    SIP/2.0 407 Proxy Authentication Required
  61.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK20c45d64e8611c93
  62.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  63.    To: <sip:1001@192.168.1.8;user=phone>;tag=DpgKjQ6SN56tD
  64.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  65.    CSeq: 12674 INVITE
  66.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  67.    Accept: application/sdp
  68.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  69.    Supported: timer, path, replaces
  70.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  71.    Proxy-Authenticate: Digest realm="192.168.1.8", nonce="17336329-8f64-49ab-a570-29b61951bb71", algorithm=MD5, qop="auth"
  72.    Content-Length: 0
  73.  
  74.    ------------------------------------------------------------------------
  75. 2017-05-08 18:47:12.088131 [DEBUG] sofia.c:2334 detaching session 870e01be-202b-4efb-971a-3a5c695b3fbc
  76. 2017-05-08 18:47:12.098181 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1010@192.168.1.8) State NEW
  77. recv 538 bytes from udp/[192.168.1.213]:5060 at 18:47:12.100254:
  78.    ------------------------------------------------------------------------
  79.    ACK sip:1001@192.168.1.8;user=phone SIP/2.0
  80.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK20c45d64e8611c93
  81.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  82.    To: <sip:1001@192.168.1.8;user=phone>;tag=DpgKjQ6SN56tD
  83.    Contact: <sip:1010@192.168.1.213:5060;transport=udp;user=phone>
  84.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  85.    CSeq: 12674 ACK
  86.    User-Agent: Grandstream GXV3000 1.2.3.7
  87.    Max-Forwards: 70
  88.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  89.    Content-Length: 0
  90.  
  91.    ------------------------------------------------------------------------
  92. recv 1431 bytes from udp/[192.168.1.213]:5060 at 18:47:12.102192:
  93.    ------------------------------------------------------------------------
  94.    INVITE sip:1001@192.168.1.8;user=phone SIP/2.0
  95.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bKc7a637844fe10960
  96.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  97.    To: <sip:1001@192.168.1.8;user=phone>
  98.    Contact: <sip:1010@192.168.1.213:5060;transport=udp;user=phone>
  99.    Supported: replaces, timer, path
  100.    Proxy-Authorization: Digest username="1010", realm="192.168.1.8", algorithm=MD5, uri="sip:1001@192.168.1.8;user=phone", qop=auth, nc=00000001, cnonce="6482f0d5e6f12940", nonce="17336329-8f64-49ab-a570-29b61951bb71", response="c024ac1f5e0ccc59d82c73d3397a30ad"
  101.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  102.    CSeq: 12675 INVITE
  103.    User-Agent: Grandstream GXV3000 1.2.3.7
  104.    Max-Forwards: 70
  105.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  106.    Content-Type: application/sdp
  107.    Content-Length: 577
  108.  
  109.    v=0
  110.    o=1010 8000 8001 IN IP4 192.168.1.213
  111.    s=SIP Call
  112.    c=IN IP4 192.168.1.213
  113.    t=0 0
  114.    m=audio 5004 RTP/AVP 0 8 4 18 3 2
  115.    a=sendrecv
  116.    a=rtpmap:0 PCMU/8000
  117.    a=rtpmap:8 PCMA/8000
  118.    a=rtpmap:4 G723/8000
  119.    a=rtpmap:18 G729/8000
  120.    a=rtpmap:3 GSM/8000
  121.    a=rtpmap:2 G726-32/8000
  122.    a=ptime:20
  123.    m=video 5006 RTP/AVP 99 34 103
  124.    a=sendrecv
  125.    a=rtpmap:99 H264/90000
  126.    a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  127.    a=rtpmap:34 H263/90000
  128.    a=fmtp:34 CIF=2 MaxBR=1280
  129.    a=rtpmap:103 H263-1998/90000
  130.    a=fmtp:103 CIF=2 MaxBR=1280
  131.    a=framerate:15
  132.    ------------------------------------------------------------------------
  133. send 345 bytes to udp/[192.168.1.213]:5060 at 18:47:12.102693:
  134.    ------------------------------------------------------------------------
  135.    SIP/2.0 100 Trying
  136.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bKc7a637844fe10960
  137.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  138.    To: <sip:1001@192.168.1.8;user=phone>
  139.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  140.    CSeq: 12675 INVITE
  141.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  142.    Content-Length: 0
  143.  
  144.    ------------------------------------------------------------------------
  145. 2017-05-08 18:47:12.098181 [DEBUG] sofia.c:2442 Re-attaching to session 870e01be-202b-4efb-971a-3a5c695b3fbc
  146. 2017-05-08 18:47:12.118205 [DEBUG] sofia.c:9834 sofia/internal/1010@192.168.1.8 receiving invite from 192.168.1.213:5060 version: 1.6.17 -34-0fc0946 64bit
  147. 2017-05-08 18:47:12.118205 [DEBUG] sofia.c:10005 IP 192.168.1.213 Rejected by acl "domains". Falling back to Digest auth.
  148. 2017-05-08 18:47:12.118205 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [received][100]
  149. 2017-05-08 18:47:12.118205 [DEBUG] sofia.c:7058 Remote SDP:
  150. v=0
  151. o=1010 8000 8001 IN IP4 192.168.1.213
  152. s=SIP Call
  153. c=IN IP4 192.168.1.213
  154. t=0 0
  155. m=audio 5004 RTP/AVP 0 8 4 18 3 2
  156. a=rtpmap:0 PCMU/8000
  157. a=rtpmap:8 PCMA/8000
  158. a=rtpmap:4 G723/8000
  159. a=rtpmap:18 G729/8000
  160. a=rtpmap:3 GSM/8000
  161. a=rtpmap:2 G726-32/8000
  162. a=ptime:20
  163. m=video 5006 RTP/AVP 99 34 103
  164. a=rtpmap:99 H264/90000
  165. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  166. a=rtpmap:34 H263/90000
  167. a=fmtp:34 CIF=2 MaxBR=1280
  168. a=rtpmap:103 H263-1998/90000
  169. a=fmtp:103 CIF=2 MaxBR=1280
  170. a=framerate:15
  171.  
  172. 2017-05-08 18:47:12.118205 [DEBUG] sofia.c:7450 (sofia/internal/1010@192.168.1.8) State Change CS_NEW -> CS_INIT
  173. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_INIT (Cur 1 Tot 17)
  174. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.1.8) State INIT
  175. 2017-05-08 18:47:12.118205 [DEBUG] mod_sofia.c:90 sofia/internal/1010@192.168.1.8 SOFIA INIT
  176. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1010@192.168.1.8 Standard INIT
  177. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1010@192.168.1.8) State Change CS_INIT -> CS_ROUTING
  178. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.1.8) State INIT going to sleep
  179. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_ROUTING (Cur 1 Tot 17)
  180. 2017-05-08 18:47:12.118205 [DEBUG] switch_channel.c:2249 (sofia/internal/1010@192.168.1.8) Callstate Change DOWN -> RINGING
  181. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.1.8) State ROUTING
  182. 2017-05-08 18:47:12.118205 [DEBUG] mod_sofia.c:143 sofia/internal/1010@192.168.1.8 SOFIA ROUTING
  183. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1010@192.168.1.8 Standard ROUTING
  184. 2017-05-08 18:47:12.118205 [INFO] mod_dialplan_xml.c:637 Processing 1010 <1010>->1001 in context default
  185. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->unloop] continue=false
  186. Dialplan: sofia/internal/1010@192.168.1.8 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  187. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  188. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->tod_example] continue=true
  189. Dialplan: sofia/internal/1010@192.168.1.8 Date/Time Match (PASS) [tod_example] break=on-false
  190. Dialplan: sofia/internal/1010@192.168.1.8 Action set(open=true)
  191. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->holiday_example] continue=true
  192. Dialplan: sofia/internal/1010@192.168.1.8 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  193. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->global-intercept] continue=false
  194. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
  195. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->group-intercept] continue=false
  196. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
  197. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->intercept-ext] continue=false
  198. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
  199. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->redial] continue=false
  200. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
  201. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->global] continue=true
  202. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  203. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${default_password}() =~ /^1234$/ break=never
  204. Dialplan: sofia/internal/1010@192.168.1.8 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
  205. Dialplan: sofia/internal/1010@192.168.1.8 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  206. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  207. o=1010 8000 8001 IN IP4 192.168.1.213
  208. s=SIP Call
  209. c=IN IP4 192.168.1.213
  210. t=0 0
  211. m=audio 5004 RTP/AVP 0 8 4 18 3 2
  212. a=rtpmap:0 PCMU/8000
  213. a=rtpmap:8 PCMA/8000
  214. a=rtpmap:4 G723/8000
  215. a=rtpmap:18 G729/8000
  216. a=rtpmap:3 GSM/8000
  217. a=rtpmap:2 G726-32/8000
  218. a=ptime:20
  219. m=video 5006 RTP/AVP 99 34 103
  220. a=rtpmap:99 H264/90000
  221. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  222. a=rtpmap:34 H263/90000
  223. a=fmtp:34 CIF=2 MaxBR=1280
  224. a=rtpmap:103 H263-1998/90000
  225. a=fmtp:103 CIF=2 MaxBR=1280
  226. a=framerate:15
  227. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  228. Dialplan: sofia/internal/1010@192.168.1.8 Absolute Condition [global]
  229. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  230. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  231. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  232. Dialplan: sofia/internal/1010@192.168.1.8 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  233. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->snom-demo-2] continue=false
  234. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
  235. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->snom-demo-1] continue=false
  236. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
  237. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->eavesdrop] continue=false
  238. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  239. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->eavesdrop] continue=false
  240. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
  241. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call_return] continue=false
  242. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
  243. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->del-group] continue=false
  244. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
  245. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->add-group] continue=false
  246. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
  247. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call-group-simo] continue=false
  248. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
  249. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call-group-order] continue=false
  250. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
  251. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->extension-intercom] continue=false
  252. Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
  253. Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->Local_Extension] continue=false
  254. Dialplan: sofia/internal/1010@192.168.1.8 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
  255. Dialplan: sofia/internal/1010@192.168.1.8 Action export(dialed_extension=1001)
  256. Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(1 b s execute_extension::dx XML features)
  257. Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.mp4)
  258. Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(3 b s execute_extension::cf XML features)
  259. Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  260. Dialplan: sofia/internal/1010@192.168.1.8 Action set(ringback=${us-ring})
  261. Dialplan: sofia/internal/1010@192.168.1.8 Action set(transfer_ringback=local_stream://moh)
  262. Dialplan: sofia/internal/1010@192.168.1.8 Action set(call_timeout=30)
  263. Dialplan: sofia/internal/1010@192.168.1.8 Action set(hangup_after_bridge=true)
  264. Dialplan: sofia/internal/1010@192.168.1.8 Action set(continue_on_fail=true)
  265. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  266. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  267. Dialplan: sofia/internal/1010@192.168.1.8 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  268. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  269. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  270. Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  271. Dialplan: sofia/internal/1010@192.168.1.8 Action set(record_file_name=/var/lib/freeswitch/recordings/${strftime(%Y-%m-%d-%H-%M-%S)}_${uuid}.mp4) INLINE
  272. EXECUTE sofia/internal/1010@192.168.1.8 set(record_file_name=/var/lib/freeswitch/recordings/2017-05-08-18-47-12_870e01be-202b-4efb-971a-3a5c695b3fbc.mp4)
  273. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [record_file_name]=[/var/lib/freeswitch/recordings/2017-05-08-18-47-12_870e01be-202b-4efb-971a-3a5c695b3fbc.mp4]
  274. Dialplan: sofia/internal/1010@192.168.1.8 Action record_session(${record_file_name})
  275. Dialplan: sofia/internal/1010@192.168.1.8 Action bridge(user/${dialed_extension}@${domain_name})
  276. Dialplan: sofia/internal/1010@192.168.1.8 Action answer()
  277. Dialplan: sofia/internal/1010@192.168.1.8 Action sleep(1000)
  278. Dialplan: sofia/internal/1010@192.168.1.8 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  279. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1010@192.168.1.8) State Change CS_ROUTING -> CS_EXECUTE
  280. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.1.8) State ROUTING going to sleep
  281. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_EXECUTE (Cur 1 Tot 17)
  282. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1010@192.168.1.8) State EXECUTE
  283. 2017-05-08 18:47:12.118205 [DEBUG] mod_sofia.c:198 sofia/internal/1010@192.168.1.8 SOFIA EXECUTE
  284. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1010@192.168.1.8 Standard EXECUTE
  285. EXECUTE sofia/internal/1010@192.168.1.8 set(open=true)
  286. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [open]=[true]
  287. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-spymap/1010/870e01be-202b-4efb-971a-3a5c695b3fbc)
  288. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/1010/1001)
  289. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/global/870e01be-202b-4efb-971a-3a5c695b3fbc)
  290. EXECUTE sofia/internal/1010@192.168.1.8 export(RFC2822_DATE=Mon, 08 May 2017 18:47:12 -0400)
  291. 2017-05-08 18:47:12.118205 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 08 May 2017 18:47:12 -0400]
  292. EXECUTE sofia/internal/1010@192.168.1.8 export(dialed_extension=1001)
  293. 2017-05-08 18:47:12.118205 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1001]
  294. EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(1 b s execute_extension::dx XML features)
  295. 2017-05-08 18:47:12.118205 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *1 execute_extension::dx XML features
  296. EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/1010.2017-05-08-18-47-12.mp4)
  297. 2017-05-08 18:47:12.118205 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/1010.2017-05-08-18-47-12.mp4
  298. EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(3 b s execute_extension::cf XML features)
  299. 2017-05-08 18:47:12.118205 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *3 execute_extension::cf XML features
  300. EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  301. 2017-05-08 18:47:12.118205 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *4 execute_extension::att_xfer XML features
  302. EXECUTE sofia/internal/1010@192.168.1.8 set(ringback=%(2000,4000,440,480))
  303. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [ringback]=[%(2000,4000,440,480)]
  304. EXECUTE sofia/internal/1010@192.168.1.8 set(transfer_ringback=local_stream://moh)
  305. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [transfer_ringback]=[local_stream://moh]
  306. EXECUTE sofia/internal/1010@192.168.1.8 set(call_timeout=30)
  307. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [call_timeout]=[30]
  308. EXECUTE sofia/internal/1010@192.168.1.8 set(hangup_after_bridge=true)
  309. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [hangup_after_bridge]=[true]
  310. EXECUTE sofia/internal/1010@192.168.1.8 set(continue_on_fail=true)
  311. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [continue_on_fail]=[true]
  312. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-call_return/1001/1010)
  313. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/1001/870e01be-202b-4efb-971a-3a5c695b3fbc)
  314. EXECUTE sofia/internal/1010@192.168.1.8 set(called_party_callgroup=techsupport)
  315. 2017-05-08 18:47:12.118205 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [called_party_callgroup]=[techsupport]
  316. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/techsupport/870e01be-202b-4efb-971a-3a5c695b3fbc)
  317. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/global/870e01be-202b-4efb-971a-3a5c695b3fbc)
  318. EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/techsupport/870e01be-202b-4efb-971a-3a5c695b3fbc)
  319. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_session.c:2646 Application record_session Requires media! pre_answering channel sofia/internal/1010@192.168.1.8
  320. 2017-05-08 18:47:12.118205 [INFO] switch_core_session.c:2648 Sending early media
  321. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  322. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  323. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  324. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  325. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  326. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  327. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  328. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  329. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  330. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  331. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[opus:116:48000:20:0:1]
  332. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1]
  333. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
  334. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
  335. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  336. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  337. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  338. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  339. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  340. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  341. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  342. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  343. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1]
  344. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1]
  345. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  346. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  347. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1010@192.168.1.8 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  348. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_codec.c:111 sofia/internal/1010@192.168.1.8 Original read codec set to PCMU:0
  349. 2017-05-08 18:47:12.118205 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  350. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4754 sofia/internal/1010@192.168.1.8 Set 2833 dtmf send payload to 101 recv payload to 101
  351. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[VP8:99]
  352. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[H264:99]
  353. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4969 Video Codec Compare [H264:99] +++ is saved as a match
  354. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[H263:34]
  355. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[VP8:99]
  356. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[H264:99]
  357. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[H263:34]
  358. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4969 Video Codec Compare [H263:34] +++ is saved as a match
  359. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[VP8:99]
  360. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
  361. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
  362. 2017-05-08 18:47:12.128215 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  363. 2017-05-08 18:47:12.128215 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  364. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:2866 Set VIDEO Codec sofia/internal/1010@192.168.1.8 H264/90000 0 ms
  365. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1010@192.168.1.8] 192.168.1.8 port 17500 -> 192.168.1.213 port 5004 codec: 0 ms: 20
  366. 2017-05-08 18:47:12.128215 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
  367. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:7166 sofia/internal/1010@192.168.1.8 Set 2833 dtmf send payload to 101
  368. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:7173 sofia/internal/1010@192.168.1.8 Set 2833 dtmf receive payload to 101
  369. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:7196 sofia/internal/1010@192.168.1.8 Set rtp dtmf delay to 40
  370. 2017-05-08 18:47:12.128215 [DEBUG] switch_rtp.c:4107 Starting video timer.
  371. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:7385 VIDEO RTP [sofia/internal/1010@192.168.1.8] 192.168.1.8:18138->192.168.1.213:5006 codec: 99 ms: 0 [SUCCESS]
  372. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:5990 sofia/internal/1010@192.168.1.8 Starting Video thread
  373. 2017-05-08 18:47:12.128215 [DEBUG] switch_core_media.c:5856 sofia/internal/1010@192.168.1.8 Video thread started. Echo is off
  374. 2017-05-08 18:47:12.128215 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1010@192.168.1.8!
  375. 2017-05-08 18:47:12.128215 [DEBUG] switch_channel.c:3473 (sofia/internal/1010@192.168.1.8) Callstate Change RINGING -> EARLY
  376. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/1010@192.168.1.8.
  377. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_media.c:7243 Video params are unchanged for sofia/internal/1010@192.168.1.8.
  378. 2017-05-08 18:47:12.138439 [DEBUG] mod_sofia.c:2363 Ring SDP:
  379. v=0
  380. o=FreeSWITCH 1494266132 1494266133 IN IP4 192.168.1.8
  381. s=FreeSWITCH
  382. c=IN IP4 192.168.1.8
  383. t=0 0
  384. m=audio 17500 RTP/AVP 0 101
  385. a=rtpmap:0 PCMU/8000
  386. a=rtpmap:101 telephone-event/8000
  387. a=fmtp:101 0-16
  388. a=ptime:20
  389. a=sendrecv
  390. m=video 18138 RTP/AVP 99
  391. b=AS:1024
  392. a=rtpmap:99 H264/90000
  393. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  394.  
  395. send 1292 bytes to udp/[192.168.1.213]:5060 at 18:47:12.139040:
  396.    ------------------------------------------------------------------------
  397.    SIP/2.0 183 Session Progress
  398.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bKc7a637844fe10960
  399.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  400.    To: <sip:1001@192.168.1.8;user=phone>;tag=eZ9BmjQXjeXDS
  401.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  402.    CSeq: 12675 INVITE
  403.    Contact: <sip:1001@192.168.1.8:5060;transport=udp>
  404.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  405.    Accept: application/sdp
  406.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  407.    Supported: timer, path, replaces
  408.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  409.    Content-Type: application/sdp
  410.    Content-Disposition: session
  411.    Content-Length: 380
  412.    Remote-Party-ID: "1001" <sip:1001@192.168.1.8>;party=calling;privacy=off;screen=no
  413.  
  414.    v=0
  415.    o=FreeSWITCH 1494266132 1494266133 IN IP4 192.168.1.8
  416.    s=FreeSWITCH
  417.    c=IN IP4 192.168.1.8
  418.    t=0 0
  419.    m=audio 17500 RTP/AVP 0 101
  420.    a=rtpmap:0 PCMU/8000
  421.    a=rtpmap:101 telephone-event/8000
  422.    a=fmtp:101 0-16
  423.    a=ptime:20
  424.    m=video 18138 RTP/AVP 99
  425.    b=AS:1024
  426.    a=rtpmap:99 H264/90000
  427.    a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  428.    ------------------------------------------------------------------------
  429. 2017-05-08 18:47:12.138439 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [early][183]
  430. EXECUTE sofia/internal/1010@192.168.1.8 record_session(/var/lib/freeswitch/recordings/2017-05-08-18-47-12_870e01be-202b-4efb-971a-3a5c695b3fbc.mp4)
  431. 2017-05-08 18:47:12.138439 [DEBUG] avformat.c:1735 sample rate: 8000, channels: 2
  432. 2017-05-08 18:47:12.138439 [DEBUG] avformat.c:1840 use video codec: [28] h264 (H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10)
  433. 2017-05-08 18:47:12.138439 [WARNING] avformat.c:513 Codec [aac] is experimental feature in libavcodec, never mind
  434. 2017-05-08 18:47:12.138439 [ERR] avformat.c:521 Could not open audio codec [aac], error: Invalid argument
  435. 2017-05-08 18:47:12.138439 [ERR] switch_ivr_async.c:2550 Error opening /var/lib/freeswitch/recordings/2017-05-08-18-47-12_870e01be-202b-4efb-971a-3a5c695b3fbc.mp4
  436. EXECUTE sofia/internal/1010@192.168.1.8 bridge(user/1001@192.168.1.8)
  437. 2017-05-08 18:47:12.138439 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 08 May 2017 18:47:12 -0400] to event
  438. 2017-05-08 18:47:12.138439 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [dialed_extension]=[1001] to event
  439. 2017-05-08 18:47:12.138439 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  440. 2017-05-08 18:47:12.138439 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 08 May 2017 18:47:12 -0400] to event
  441. 2017-05-08 18:47:12.138439 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [dialed_extension]=[1001] to event
  442. 2017-05-08 18:47:12.138439 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  443. 2017-05-08 18:47:12.138439 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.1.161:5060 [4bee329f-42cf-4d54-b658-8c90a6ced178]
  444. 2017-05-08 18:47:12.138439 [DEBUG] mod_sofia.c:4818 (sofia/internal/1001@192.168.1.161:5060) State Change CS_NEW -> CS_INIT
  445. 2017-05-08 18:47:12.138439 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  446. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_INIT (Cur 2 Tot 18)
  447. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.1.161:5060) State INIT
  448. 2017-05-08 18:47:12.138439 [DEBUG] mod_sofia.c:90 sofia/internal/1001@192.168.1.161:5060 SOFIA INIT
  449. 2017-05-08 18:47:12.138439 [DEBUG] sofia_glue.c:1295 sofia/internal/1001@192.168.1.161:5060 sending invite version: 1.6.17 -34-0fc0946 64bit
  450. Local SDP:
  451. v=0
  452. o=FreeSWITCH 1494262960 1494262961 IN IP4 192.168.1.8
  453. s=FreeSWITCH
  454. c=IN IP4 192.168.1.8
  455. t=0 0
  456. m=audio 20672 RTP/AVP 0 101
  457. a=rtpmap:0 PCMU/8000
  458. a=rtpmap:101 telephone-event/8000
  459. a=fmtp:101 0-16
  460. a=ptime:20
  461. a=sendrecv
  462. m=video 24210 RTP/AVP 102
  463. b=AS:1024
  464. a=rtpmap:102 H264/90000
  465. a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  466. a=rtcp-fb:102 ccm fir
  467. a=rtcp-fb:102 ccm tmmbr
  468. a=rtcp-fb:102 nack
  469. a=rtcp-fb:102 nack pli
  470.  
  471. send 1457 bytes to udp/[192.168.1.161]:5060 at 18:47:12.144377:
  472.    ------------------------------------------------------------------------
  473.    INVITE sip:1001@192.168.1.161:5060;transport=udp;user=phone SIP/2.0
  474.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKrpytB1FaHgeta
  475.    Max-Forwards: 69
  476.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  477.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>
  478.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  479.    CSeq: 106805752 INVITE
  480.    Contact: <sip:mod_sofia@192.168.1.8:5060>
  481.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  482.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  483.    Supported: timer, path, replaces
  484.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  485.    Content-Type: application/sdp
  486.    Content-Disposition: session
  487.    Content-Length: 475
  488.    X-FS-Support: update_display,send_info
  489.    Remote-Party-ID: "Extension 1010" <sip:1010@192.168.1.8>;party=calling;screen=yes;privacy=off
  490.  
  491.    v=0
  492.    o=FreeSWITCH 1494262960 1494262961 IN IP4 192.168.1.8
  493.    s=FreeSWITCH
  494.    c=IN IP4 192.168.1.8
  495.    t=0 0
  496.    m=audio 20672 RTP/AVP 0 101
  497.    a=rtpmap:0 PCMU/8000
  498.    a=rtpmap:101 telephone-event/8000
  499.    a=fmtp:101 0-16
  500.    a=ptime:20
  501.    m=video 24210 RTP/AVP 102
  502.    b=AS:1024
  503.    a=rtpmap:102 H264/90000
  504.    a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  505.    a=rtcp-fb:102 ccm fir
  506.    a=rtcp-fb:102 ccm tmmbr
  507.    a=rtcp-fb:102 nack
  508.    a=rtcp-fb:102 nack pli
  509.    ------------------------------------------------------------------------
  510. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.1.161:5060 Standard INIT
  511. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.1.161:5060) State Change CS_INIT -> CS_ROUTING
  512. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.1.161:5060) State INIT going to sleep
  513. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_ROUTING (Cur 2 Tot 18)
  514. 2017-05-08 18:47:12.138439 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [calling][0]
  515. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.1.161:5060) State ROUTING
  516. 2017-05-08 18:47:12.138439 [DEBUG] mod_sofia.c:143 sofia/internal/1001@192.168.1.161:5060 SOFIA ROUTING
  517. 2017-05-08 18:47:12.138439 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@192.168.1.161:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  518. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.1.161:5060) State ROUTING going to sleep
  519. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 18)
  520. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@192.168.1.161:5060) State CONSUME_MEDIA
  521. 2017-05-08 18:47:12.138439 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@192.168.1.161:5060) State CONSUME_MEDIA going to sleep
  522. recv 342 bytes from udp/[192.168.1.161]:5060 at 18:47:12.148794:
  523.    ------------------------------------------------------------------------
  524.    SIP/2.0 100 Trying
  525.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKrpytB1FaHgeta
  526.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  527.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>
  528.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  529.    CSeq: 106805752 INVITE
  530.    User-Agent: Grandstream GXV3000 1.2.3.7
  531.    Content-Length: 0
  532.  
  533.    ------------------------------------------------------------------------
  534. recv 516 bytes from udp/[192.168.1.161]:5060 at 18:47:12.148851:
  535.    ------------------------------------------------------------------------
  536.    SIP/2.0 180 Ringing
  537.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKrpytB1FaHgeta
  538.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  539.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>;tag=89d037d35ba61306
  540.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  541.    CSeq: 106805752 INVITE
  542.    User-Agent: Grandstream GXV3000 1.2.3.7
  543.    Contact: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>
  544.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  545.    Content-Length: 0
  546.  
  547.    ------------------------------------------------------------------------
  548. 2017-05-08 18:47:12.148168 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [proceeding][180]
  549. 2017-05-08 18:47:12.148168 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/1001@192.168.1.161:5060!
  550. 2017-05-08 18:47:12.148168 [DEBUG] switch_channel.c:3345 (sofia/internal/1001@192.168.1.161:5060) Callstate Change DOWN -> RINGING
  551. 2017-05-08 18:47:12.148168 [INFO] avcodec.c:1069 initializing encoder 352x288
  552. 2017-05-08 18:47:12.148168 [DEBUG] avcodec.c:831 NVENC HW CODEC NOT PRESENT
  553. 2017-05-08 18:47:12.168487 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  554. 2017-05-08 18:47:12.168487 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  555. 2017-05-08 18:47:12.168487 [DEBUG] switch_core_codec.c:223 sofia/internal/1010@192.168.1.8 Push codec L16:100
  556. 2017-05-08 18:47:12.168487 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)]
  557. 2017-05-08 18:47:12.728143 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
  558. recv 924 bytes from udp/[192.168.1.161]:5060 at 18:47:15.520142:
  559.    ------------------------------------------------------------------------
  560.    SIP/2.0 200 OK
  561.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKrpytB1FaHgeta
  562.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  563.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>;tag=89d037d35ba61306
  564.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  565.    CSeq: 106805752 INVITE
  566.    User-Agent: Grandstream GXV3000 1.2.3.7
  567.    Contact: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>
  568.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  569.    Content-Type: application/sdp
  570.    Supported: replaces, timer, 100rel, path
  571.    Content-Length: 338
  572.  
  573.    v=0
  574.    o=1001 8000 8000 IN IP4 192.168.1.161
  575.    s=SIP Call
  576.    c=IN IP4 192.168.1.161
  577.    t=0 0
  578.    m=audio 5004 RTP/AVP 0
  579.    a=sendrecv
  580.    a=rtpmap:0 PCMU/8000
  581.    a=ptime:20
  582.    m=video 5006 RTP/AVP 102
  583.    a=sendrecv
  584.    a=rtpmap:102 H264/90000
  585.    a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Eco==
  586.    a=framerate:15
  587.    ------------------------------------------------------------------------
  588. 2017-05-08 18:47:15.518405 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [completing][200]
  589. 2017-05-08 18:47:15.518405 [DEBUG] sofia.c:7058 Remote SDP:
  590. v=0
  591. o=1001 8000 8000 IN IP4 192.168.1.161
  592. s=SIP Call
  593. c=IN IP4 192.168.1.161
  594. t=0 0
  595. m=audio 5004 RTP/AVP 0
  596. a=rtpmap:0 PCMU/8000
  597. a=ptime:20
  598. m=video 5006 RTP/AVP 102
  599. a=rtpmap:102 H264/90000
  600. a=fmtp:102 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Eco==
  601. a=framerate:15
  602.  
  603. send 426 bytes to udp/[192.168.1.161]:5060 at 18:47:15.521583:
  604.    ------------------------------------------------------------------------
  605.    ACK sip:1001@192.168.1.161:5060;transport=udp;user=phone SIP/2.0
  606.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKSZQKDv0DeS4cp
  607.    Max-Forwards: 70
  608.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  609.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>;tag=89d037d35ba61306
  610.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  611.    CSeq: 106805752 ACK
  612.    Contact: <sip:mod_sofia@192.168.1.8:5060>
  613.    Content-Length: 0
  614.  
  615.    ------------------------------------------------------------------------
  616. 2017-05-08 18:47:15.518405 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [ready][200]
  617. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  618. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  619. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1001@192.168.1.161:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  620. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.1.161:5060 Original read codec set to PCMU:0
  621. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
  622. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4754 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  623. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:102]/[H264:99]
  624. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4980 No matches with FTMP, fallback to ignoring FMTP
  625. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:102]/[H264:99]
  626. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4988 No matches with inherit_codec, fallback to ignoring PT
  627. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:102]/[H264:99]
  628. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:4969 Video Codec Compare [H264:102] +++ is saved as a match
  629. 2017-05-08 18:47:15.518405 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  630. 2017-05-08 18:47:15.518405 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
  631. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:2866 Set VIDEO Codec sofia/internal/1001@192.168.1.161:5060 H264/90000 0 ms
  632. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1001@192.168.1.161:5060] 192.168.1.8 port 20672 -> 192.168.1.161 port 5004 codec: 0 ms: 20
  633. 2017-05-08 18:47:15.518405 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
  634. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:7166 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf send payload to 101
  635. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:7173 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf receive payload to 101
  636. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:7196 sofia/internal/1001@192.168.1.161:5060 Set rtp dtmf delay to 40
  637. 2017-05-08 18:47:15.518405 [DEBUG] switch_rtp.c:4107 Starting video timer.
  638. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:7385 VIDEO RTP [sofia/internal/1001@192.168.1.161:5060] 192.168.1.8:24210->192.168.1.161:5006 codec: 102 ms: 0 [SUCCESS]
  639. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:5990 sofia/internal/1001@192.168.1.161:5060 Starting Video thread
  640. 2017-05-08 18:47:15.518405 [DEBUG] switch_core_media.c:5856 sofia/internal/1001@192.168.1.161:5060 Video thread started. Echo is off
  641. 2017-05-08 18:47:15.528399 [NOTICE] sofia.c:8182 Channel [sofia/internal/1001@192.168.1.161:5060] has been answered
  642. 2017-05-08 18:47:15.528399 [DEBUG] switch_channel.c:3772 (sofia/internal/1001@192.168.1.161:5060) Callstate Change RINGING -> ACTIVE
  643. 2017-05-08 18:47:15.528399 [DEBUG] switch_core_codec.c:248 sofia/internal/1010@192.168.1.8 Restore previous codec PCMU:0.
  644. 2017-05-08 18:47:15.528399 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/1010@192.168.1.8.
  645. 2017-05-08 18:47:15.528399 [DEBUG] switch_core_media.c:7243 Video params are unchanged for sofia/internal/1010@192.168.1.8.
  646. 2017-05-08 18:47:15.528399 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1010@192.168.1.8:
  647. v=0
  648. o=FreeSWITCH 1494266132 1494266134 IN IP4 192.168.1.8
  649. s=FreeSWITCH
  650. c=IN IP4 192.168.1.8
  651. t=0 0
  652. m=audio 17500 RTP/AVP 0 101
  653. a=rtpmap:0 PCMU/8000
  654. a=rtpmap:101 telephone-event/8000
  655. a=fmtp:101 0-16
  656. a=ptime:20
  657. a=sendrecv
  658. m=video 18138 RTP/AVP 99
  659. b=AS:1024
  660. a=rtpmap:99 H264/90000
  661. a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  662.  
  663. send 1262 bytes to udp/[192.168.1.213]:5060 at 18:47:15.534586:
  664.    ------------------------------------------------------------------------
  665.    SIP/2.0 200 OK
  666.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bKc7a637844fe10960
  667.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  668.    To: <sip:1001@192.168.1.8;user=phone>;tag=eZ9BmjQXjeXDS
  669.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  670.    CSeq: 12675 INVITE
  671.    Contact: <sip:1001@192.168.1.8:5060;transport=udp>
  672.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  673.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  674.    Supported: timer, path, replaces
  675.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  676.    Content-Type: application/sdp
  677.    Content-Disposition: session
  678.    Content-Length: 380
  679.    Remote-Party-ID: "Outbound Call" <sip:1001@192.168.1.8>;party=calling;privacy=off;screen=no
  680.  
  681.    v=0
  682.    o=FreeSWITCH 1494266132 1494266133 IN IP4 192.168.1.8
  683.    s=FreeSWITCH
  684.    c=IN IP4 192.168.1.8
  685.    t=0 0
  686.    m=audio 17500 RTP/AVP 0 101
  687.    a=rtpmap:0 PCMU/8000
  688.    a=rtpmap:101 telephone-event/8000
  689.    a=fmtp:101 0-16
  690.    a=ptime:20
  691.    m=video 18138 RTP/AVP 99
  692.    b=AS:1024
  693.    a=rtpmap:99 H264/90000
  694.    a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecs==
  695.    ------------------------------------------------------------------------
  696. 2017-05-08 18:47:15.528399 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [completed][200]
  697. 2017-05-08 18:47:15.528399 [NOTICE] switch_ivr_originate.c:3632 Channel [sofia/internal/1010@192.168.1.8] has been answered
  698. 2017-05-08 18:47:15.528399 [DEBUG] switch_channel.c:3772 (sofia/internal/1010@192.168.1.8) Callstate Change EARLY -> ACTIVE
  699. 2017-05-08 18:47:15.528399 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1001@192.168.1.161:5060]
  700. 2017-05-08 18:47:15.538525 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1001@192.168.1.161:5060]
  701. 2017-05-08 18:47:15.538525 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/1001@192.168.1.161:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  702. 2017-05-08 18:47:15.538525 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 18)
  703. 2017-05-08 18:47:15.538525 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1001@192.168.1.161:5060) State EXCHANGE_MEDIA
  704. 2017-05-08 18:47:15.538525 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  705. recv 807 bytes from udp/[192.168.1.213]:5060 at 18:47:15.541516:
  706.    ------------------------------------------------------------------------
  707.    ACK sip:1001@192.168.1.8:5060;transport=udp SIP/2.0
  708.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK64e49523bb65cc10
  709.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  710.    To: <sip:1001@192.168.1.8;user=phone>;tag=eZ9BmjQXjeXDS
  711.    Contact: <sip:1010@192.168.1.213:5060;transport=udp;user=phone>
  712.    Proxy-Authorization: Digest username="1010", realm="192.168.1.8", algorithm=MD5, uri="sip:1001@192.168.1.8;user=phone", qop=auth, nc=00000001, cnonce="6482f0d5e6f12940", nonce="17336329-8f64-49ab-a570-29b61951bb71", response="c024ac1f5e0ccc59d82c73d3397a30ad"
  713.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  714.    CSeq: 12675 ACK
  715.    User-Agent: Grandstream GXV3000 1.2.3.7
  716.    Max-Forwards: 70
  717.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  718.    Content-Length: 0
  719.  
  720.    ------------------------------------------------------------------------
  721. 2017-05-08 18:47:15.538525 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [ready][200]
  722. 2017-05-08 18:47:15.548212 [INFO] avcodec.c:1069 initializing encoder 352x288
  723. 2017-05-08 18:47:15.548212 [DEBUG] avcodec.c:831 NVENC HW CODEC NOT PRESENT
  724. 2017-05-08 18:47:15.558464 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
  725. 2017-05-08 18:47:15.578168 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  726. 2017-05-08 18:47:15.588136 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
  727. 2017-05-08 18:47:15.608132 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
  728. recv 770 bytes from udp/[192.168.1.213]:5060 at 18:47:20.369674:
  729.    ------------------------------------------------------------------------
  730.    BYE sip:1001@192.168.1.8:5060;transport=udp SIP/2.0
  731.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK669382f230c735f6
  732.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  733.    To: <sip:1001@192.168.1.8;user=phone>;tag=eZ9BmjQXjeXDS
  734.    Proxy-Authorization: Digest username="1010", realm="192.168.1.8", algorithm=MD5, uri="sip:1001@192.168.1.8:5060", qop=auth, nc=00000002, cnonce="b9967c47e7b7ae61", nonce="17336329-8f64-49ab-a570-29b61951bb71", response="432ef820aa76ac4f9e5402e61785d654"
  735.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  736.    CSeq: 12676 BYE
  737.    User-Agent: Grandstream GXV3000 1.2.3.7
  738.    Max-Forwards: 70
  739.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  740.    Reason: SIP ;text="Onhook event"
  741.    Content-Length: 0
  742.  
  743.    ------------------------------------------------------------------------
  744. 2017-05-08 18:47:20.368279 [NOTICE] sofia.c:1012 Hangup sofia/internal/1010@192.168.1.8 [CS_EXECUTE] [NORMAL_CLEARING]
  745. send 500 bytes to udp/[192.168.1.213]:5060 at 18:47:20.373269:
  746.    ------------------------------------------------------------------------
  747.    SIP/2.0 200 OK
  748.    Via: SIP/2.0/UDP 192.168.1.213:5060;branch=z9hG4bK669382f230c735f6
  749.    From: <sip:1010@192.168.1.8;user=phone>;tag=e6075687f1077b96
  750.    To: <sip:1001@192.168.1.8;user=phone>;tag=eZ9BmjQXjeXDS
  751.    Call-ID: b4d0de557e560071b0932e454933e794@192.168.1.213
  752.    CSeq: 12676 BYE
  753.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  754.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  755.    Supported: timer, path, replaces
  756.    Content-Length: 0
  757.  
  758.    ------------------------------------------------------------------------
  759. 2017-05-08 18:47:20.368279 [DEBUG] switch_ivr_bridge.c:726 Ending video thread.
  760. 2017-05-08 18:47:20.368279 [DEBUG] switch_ivr_bridge.c:776 Ending video thread.
  761. 2017-05-08 18:47:20.368279 [DEBUG] switch_ivr_bridge.c:155 sofia/internal/1010@192.168.1.8 video thread ended.
  762. 2017-05-08 18:47:20.368279 [DEBUG] switch_core_media.c:11605 sofia/internal/1010@192.168.1.8 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
  763. 2017-05-08 18:47:20.368279 [DEBUG] switch_core_media.c:5957 sofia/internal/1010@192.168.1.8 Video thread ended
  764. 2017-05-08 18:47:20.378523 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1010@192.168.1.8]
  765. 2017-05-08 18:47:20.378523 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/1010@192.168.1.8 ending bridge by request from write function
  766. 2017-05-08 18:47:20.378523 [DEBUG] switch_ivr_bridge.c:726 Ending video thread.
  767. 2017-05-08 18:47:20.378523 [DEBUG] switch_ivr_bridge.c:776 Ending video thread.
  768. 2017-05-08 18:47:20.418129 [DEBUG] switch_ivr_bridge.c:155 sofia/internal/1001@192.168.1.161:5060 video thread ended.
  769. 2017-05-08 18:47:20.418129 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1001@192.168.1.161:5060]
  770. 2017-05-08 18:47:20.418129 [NOTICE] switch_ivr_bridge.c:891 Hangup sofia/internal/1001@192.168.1.161:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  771. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1001@192.168.1.161:5060) State EXCHANGE_MEDIA going to sleep
  772. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_HANGUP (Cur 2 Tot 18)
  773. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.1.161:5060) Callstate Change ACTIVE -> HANGUP
  774. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.1.161:5060) State HANGUP
  775. 2017-05-08 18:47:20.418129 [DEBUG] mod_sofia.c:432 sofia/internal/1001@192.168.1.161:5060 Overriding SIP cause 480 with 200 from the other leg
  776. 2017-05-08 18:47:20.418129 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1001@192.168.1.161:5060 hanging up, cause: NORMAL_CLEARING
  777. 2017-05-08 18:47:20.418129 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/1001@192.168.1.161:5060
  778. send 618 bytes to udp/[192.168.1.161]:5060 at 18:47:20.427103:
  779.    ------------------------------------------------------------------------
  780.    BYE sip:1001@192.168.1.161:5060;transport=udp;user=phone SIP/2.0
  781.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKt8gcFQHHB2tZH
  782.    Max-Forwards: 70
  783.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  784.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>;tag=89d037d35ba61306
  785.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  786.    CSeq: 106805753 BYE
  787.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  788.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  789.    Supported: timer, path, replaces
  790.    Reason: SIP;text="Onhook event"
  791.    Content-Length: 0
  792.  
  793.    ------------------------------------------------------------------------
  794. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.1.161:5060 Standard HANGUP, cause: NORMAL_CLEARING
  795. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.1.161:5060) State HANGUP going to sleep
  796. 2017-05-08 18:47:20.418129 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@192.168.1.161:5060) State Change CS_HANGUP -> CS_REPORTING
  797. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_REPORTING (Cur 2 Tot 18)
  798. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.1.161:5060) State REPORTING
  799. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.1.161:5060 Standard REPORTING, cause: NORMAL_CLEARING
  800. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.1.161:5060) State REPORTING going to sleep
  801. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@192.168.1.161:5060) State Change CS_REPORTING -> CS_DESTROY
  802. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_session.c:1664 Session 18 (sofia/internal/1001@192.168.1.161:5060) Locked, Waiting on external entities
  803. recv 550 bytes from udp/[192.168.1.161]:5060 at 18:47:20.429720:
  804.    ------------------------------------------------------------------------
  805.    SIP/2.0 200 OK
  806.    Via: SIP/2.0/UDP 192.168.1.8;rport;branch=z9hG4bKt8gcFQHHB2tZH
  807.    From: "Extension 1010" <sip:1010@192.168.1.8>;tag=F824ND80FQK0m
  808.    To: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>;tag=89d037d35ba61306
  809.    Call-ID: 1dbfdc70-aee3-1235-77b2-080027de30fb
  810.    CSeq: 106805753 BYE
  811.    User-Agent: Grandstream GXV3000 1.2.3.7
  812.    Contact: <sip:1001@192.168.1.161:5060;transport=udp;user=phone>
  813.    Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE
  814.    Supported: replaces, timer, 100rel, path
  815.    Content-Length: 0
  816.  
  817.    ------------------------------------------------------------------------
  818. 2017-05-08 18:47:20.428558 [DEBUG] switch_ivr_bridge.c:1702 sofia/internal/1010@192.168.1.8 skip receive message [UNBRIDGE] (channel is hungup already)
  819. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_session.c:2814 sofia/internal/1010@192.168.1.8 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  820. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1010@192.168.1.8) State EXECUTE going to sleep
  821. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_HANGUP (Cur 2 Tot 18)
  822. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1010@192.168.1.8) Callstate Change ACTIVE -> HANGUP
  823. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.1.8) State HANGUP
  824. 2017-05-08 18:47:20.428558 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1010@192.168.1.8 hanging up, cause: NORMAL_CLEARING
  825. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1010@192.168.1.8 Standard HANGUP, cause: NORMAL_CLEARING
  826. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.1.8) State HANGUP going to sleep
  827. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1010@192.168.1.8) State Change CS_HANGUP -> CS_REPORTING
  828. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_REPORTING (Cur 2 Tot 18)
  829. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.1.8) State REPORTING
  830. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1010@192.168.1.8 Standard REPORTING, cause: NORMAL_CLEARING
  831. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.1.8) State REPORTING going to sleep
  832. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1010@192.168.1.8) State Change CS_REPORTING -> CS_DESTROY
  833. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_session.c:1664 Session 17 (sofia/internal/1010@192.168.1.8) Locked, Waiting on external entities
  834. 2017-05-08 18:47:20.428558 [NOTICE] switch_core_session.c:1682 Session 17 (sofia/internal/1010@192.168.1.8) Ended
  835. 2017-05-08 18:47:20.428558 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1010@192.168.1.8 [CS_DESTROY]
  836. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1010@192.168.1.8) Running State Change CS_DESTROY (Cur 1 Tot 18)
  837. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.1.8) State DESTROY
  838. 2017-05-08 18:47:20.428558 [DEBUG] mod_sofia.c:343 sofia/internal/1010@192.168.1.8 SOFIA DESTROY
  839. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1010@192.168.1.8 Standard DESTROY
  840. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.1.8) State DESTROY going to sleep
  841. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_media.c:5957 sofia/internal/1001@192.168.1.161:5060 Video thread ended
  842. 2017-05-08 18:47:20.428558 [NOTICE] switch_core_session.c:1682 Session 18 (sofia/internal/1001@192.168.1.161:5060) Ended
  843. 2017-05-08 18:47:20.428558 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1001@192.168.1.161:5060 [CS_DESTROY]
  844. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_DESTROY (Cur 0 Tot 18)
  845. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.1.161:5060) State DESTROY
  846. 2017-05-08 18:47:20.428558 [DEBUG] mod_sofia.c:343 sofia/internal/1001@192.168.1.161:5060 SOFIA DESTROY
  847. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.1.161:5060 Standard DESTROY
  848. 2017-05-08 18:47:20.428558 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.1.161:5060) State DESTROY going to sleep
  849. recv 766 bytes from udp/[192.168.1.47]:62774 at 18:47:38.010823:
  850.    ------------------------------------------------------------------------
  851.    REGISTER sip:192.168.1.8:5060;transport=UDP SIP/2.0
  852.    Via: SIP/2.0/UDP 192.168.1.47:62774;branch=z9hG4bK-524287-1---ddbd420316564882;rport
  853.    Max-Forwards: 70
  854.    Contact: <sip:1008@192.168.1.47:62774;rinstance=c02f003471180104;transport=UDP>
  855.    To: <sip:1008@192.168.1.8:5060;transport=UDP>
  856.    From: <sip:1008@192.168.1.8:5060;transport=UDP>;tag=15c4215a
  857.    Call-ID: ZjdLSPb86MPCiU4PQSdWkg..
  858.    CSeq: 39 REGISTER
  859.    Expires: 60
  860.    User-Agent: Zoiper rv2.8.30
  861.    Authorization: Digest username="1008",realm="192.168.1.8",nonce="fcb0f64a-833c-4244-ac93-44e02e26b3c5",uri="sip:192.168.1.8:5060;transport=UDP",response="cd6d197c53f27f9116a6c12c6d5ea168",cnonce="f5780d160aa7584404dd6bf0ee8e0714",nc=00000026,qop=auth,algorithm=MD5
  862.    Allow-Events: presence, kpml, talk
  863.    Content-Length: 0
  864.  
  865.    ------------------------------------------------------------------------
  866. send 641 bytes to udp/[192.168.1.47]:62774 at 18:47:38.012546:
  867.    ------------------------------------------------------------------------
  868.    SIP/2.0 200 OK
  869.    Via: SIP/2.0/UDP 192.168.1.47:62774;branch=z9hG4bK-524287-1---ddbd420316564882;rport=62774
  870.    From: <sip:1008@192.168.1.8:5060;transport=UDP>;tag=15c4215a
  871.    To: <sip:1008@192.168.1.8:5060;transport=UDP>;tag=gHvXQ8r4c09jg
  872.    Call-ID: ZjdLSPb86MPCiU4PQSdWkg..
  873.    CSeq: 39 REGISTER
  874.    Contact: <sip:1008@192.168.1.47:62774;rinstance=c02f003471180104;transport=UDP>;expires=60
  875.    Date: Mon, 08 May 2017 22:47:38 GMT
  876.    User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
  877.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  878.    Supported: timer, path, replaces
  879.    Content-Length: 0
  880.  
  881.    ------------------------------------------------------------------------
  882. freeswitch@freeswitch>
  883.