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