freeswitch@internal>
freeswitch@internal> recv 883 bytes from udp/[91.142.62.148]:61807 at 14:59:07.946390:
------------------------------------------------------------------------
INVITE sip:1001@35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport
Contact: <sip:1002@192.168.10.116:58927>
Max-Forwards: 70
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>
Content-Type: application/sdp
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 1 INVITE
Content-Length: 345
v=0
o=- 5366485179 20532 IN IP4 172.26.170.170
s=jxgxntt
c=IN IP4 192.168.10.116
t=0 0
m=audio 31210 RTP/AVP 0 8 9 3 102 101
a=rtpmap:101 telephone-event/8000
a=rtpmap:102 iLBC/8000
a=fmtp:101 0-15
a=fmtp:102 mode=20
a=ptime:20
a=sendrecv
m=video 45462 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
a=sendrecv
------------------------------------------------------------------------
send 357 bytes to udp/[91.142.62.148]:61807 at 14:59:07.946606:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 1 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:07.938192 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/1002@35.160.75.57 [304d65e2-c857-11e6-8125-fb2640f076da]
2016-12-22 14:59:07.938192 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:07.938192 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:07.938192 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_NEW
2016-12-22 14:59:07.938192 [DEBUG] sofia.c:8957 sofia/internal/1002@35.160.75.57 receiving invite from 91.142.62.148:61807 version: 1.4.23 64bit
2016-12-22 14:59:07.938192 [DEBUG] sofia.c:9124 IP 91.142.62.148 Rejected by acl "domains". Falling back to Digest auth.
send 860 bytes to udp/[91.142.62.148]:61807 at 14:59:07.947287:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=ce7yN682g53XB
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 1 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Proxy-Authenticate: Digest realm="35.160.75.57", nonce="304d6fba-c857-11e6-8126-fb2640f076da", algorithm=MD5, qop="auth"
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:07.938192 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:07.938192 [DEBUG] sofia.c:2065 detaching session 304d65e2-c857-11e6-8125-fb2640f076da
2016-12-22 14:59:07.938192 [WARNING] sofia_reg.c:1758 SIP auth challenge (INVITE) on sofia profile 'internal' for [1001@35.160.75.57] from ip 91.142.62.148
2016-12-22 14:59:07.938192 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1002@35.160.75.57) State NEW
send 860 bytes to udp/[91.142.62.148]:61807 at 14:59:08.446675:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=ce7yN682g53XB
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 1 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Proxy-Authenticate: Digest realm="35.160.75.57", nonce="304d6fba-c857-11e6-8126-fb2640f076da", algorithm=MD5, qop="auth"
Content-Length: 0
------------------------------------------------------------------------
recv 329 bytes from udp/[91.142.62.148]:61807 at 14:59:08.465485:
------------------------------------------------------------------------
ACK sip:1001@35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport
Max-Forwards: 70
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=ce7yN682g53XB
CSeq: 1 ACK
Content-Length: 0
------------------------------------------------------------------------
recv 1143 bytes from udp/[91.142.62.148]:61807 at 14:59:08.471303:
------------------------------------------------------------------------
INVITE sip:1001@35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKdY4bwnRzxuZZ3oE3;rport
Contact: <sip:1002@192.168.10.116:58927>
Max-Forwards: 70
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>
Content-Type: application/sdp
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 2 INVITE
Proxy-Authorization: Digest username="1002",realm="35.160.75.57",algorithm=MD5,uri="sip:1001@35.160.75.57",nonce="304d6fba-c857-11e6-8126-fb2640f076da",qop=auth,cnonce="b0d6df67c670924e0d5c2cdec81d1bc8",nc=00000001,response="021b2f72ab5229ed532afad393f9aa97"
Content-Length: 345
v=0
o=- 5366485179 20532 IN IP4 172.26.170.170
s=jxgxntt
c=IN IP4 192.168.10.116
t=0 0
m=audio 31210 RTP/AVP 0 8 9 3 102 101
a=rtpmap:101 telephone-event/8000
a=rtpmap:102 iLBC/8000
a=fmtp:101 0-15
a=fmtp:102 mode=20
a=ptime:20
a=sendrecv
m=video 45462 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
a=sendrecv
------------------------------------------------------------------------
send 357 bytes to udp/[91.142.62.148]:61807 at 14:59:08.471487:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKdY4bwnRzxuZZ3oE3;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 2 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:08.458219 [DEBUG] sofia.c:2173 Re-attaching to session 304d65e2-c857-11e6-8125-fb2640f076da
2016-12-22 14:59:08.458219 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.458219 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:8957 sofia/internal/1002@35.160.75.57 receiving invite from 91.142.62.148:61807 version: 1.4.23 64bit
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:9124 IP 91.142.62.148 Rejected by acl "domains". Falling back to Digest auth.
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:10222 Setting NAT mode based on nat.auto
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:6658 Channel sofia/internal/1002@35.160.75.57 entering state [received][100]
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:6668 Remote SDP:
v=0
o=- 5366485179 20532 IN IP4 172.26.170.170
s=jxgxntt
c=IN IP4 192.168.10.116
t=0 0
m=audio 31210 RTP/AVP 0 8 9 3 102 101
a=rtpmap:102 iLBC/8000
a=fmtp:102 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
m=video 45462 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
2016-12-22 14:59:08.478211 [DEBUG] sofia.c:6934 (sofia/internal/1002@35.160.75.57) State Change CS_NEW -> CS_INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1002@35.160.75.57) State INIT
2016-12-22 14:59:08.478211 [DEBUG] mod_sofia.c:87 sofia/internal/1002@35.160.75.57 SOFIA INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@35.160.75.57 Standard INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@35.160.75.57) State Change CS_INIT -> CS_ROUTING
2016-12-22 14:59:08.478211 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1002@35.160.75.57) State INIT going to sleep
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_ROUTING
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:2204 (sofia/internal/1002@35.160.75.57) Callstate Change DOWN -> RINGING
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1002@35.160.75.57) State ROUTING
2016-12-22 14:59:08.478211 [DEBUG] mod_sofia.c:123 sofia/internal/1002@35.160.75.57 SOFIA ROUTING
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1002@35.160.75.57 Standard ROUTING
2016-12-22 14:59:08.478211 [INFO] mod_dialplan_xml.c:635 Processing 1002 <1002>->1001 in context default
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1002@35.160.75.57 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 Action set(open=true)
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1002@35.160.75.57 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->redial] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->global] continue=true
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [global] ${default_password}(i-0d1b371d79afbe962) =~ /^1234$/ break=never
Dialplan: sofia/internal/1002@35.160.75.57 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
Dialplan: sofia/internal/1002@35.160.75.57 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=- 5366485179 20532 IN IP4 172.26.170.170
s=jxgxntt
c=IN IP4 192.168.10.116
t=0 0
m=audio 31210 RTP/AVP 0 8 9 3 102 101
a=rtpmap:102 iLBC/8000
a=fmtp:102 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
m=video 45462 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1002@35.160.75.57 Absolute Condition [global]
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->call_return] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->del-group] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->add-group] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1002@35.160.75.57 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1002@35.160.75.57 Action export(dialed_extension=1001)
Dialplan: sofia/internal/1002@35.160.75.57 Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/1002@35.160.75.57 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/1002@35.160.75.57 Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/1002@35.160.75.57 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1002@35.160.75.57 Action set(ringback=${us-ring})
Dialplan: sofia/internal/1002@35.160.75.57 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1002@35.160.75.57 Action set(call_timeout=30)
Dialplan: sofia/internal/1002@35.160.75.57 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1002@35.160.75.57 Action set(continue_on_fail=true)
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1002@35.160.75.57 Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1002@35.160.75.57 Action answer()
Dialplan: sofia/internal/1002@35.160.75.57 Action sleep(1000)
Dialplan: sofia/internal/1002@35.160.75.57 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1002@35.160.75.57) State Change CS_ROUTING -> CS_EXECUTE
2016-12-22 14:59:08.478211 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1002@35.160.75.57) State ROUTING going to sleep
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_EXECUTE
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1002@35.160.75.57) State EXECUTE
2016-12-22 14:59:08.478211 [DEBUG] mod_sofia.c:178 sofia/internal/1002@35.160.75.57 SOFIA EXECUTE
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1002@35.160.75.57 Standard EXECUTE
EXECUTE sofia/internal/1002@35.160.75.57 set(open=true)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [open]=[true]
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-spymap/1002/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial/1002/1001)
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial/global/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 export(RFC2822_DATE=Thu, 22 Dec 2016 14:59:08 +0000)
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 22 Dec 2016 14:59:08 +0000]
EXECUTE sofia/internal/1002@35.160.75.57 export(dialed_extension=1001)
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [dialed_extension]=[1001]
EXECUTE sofia/internal/1002@35.160.75.57 bind_meta_app(1 b s execute_extension::dx XML features)
2016-12-22 14:59:08.478211 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *1 execute_extension::dx XML features
EXECUTE sofia/internal/1002@35.160.75.57 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1002.2016-12-22-14-59-08.wav)
2016-12-22 14:59:08.478211 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1002.2016-12-22-14-59-08.wav
EXECUTE sofia/internal/1002@35.160.75.57 bind_meta_app(3 b s execute_extension::cf XML features)
2016-12-22 14:59:08.478211 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *3 execute_extension::cf XML features
EXECUTE sofia/internal/1002@35.160.75.57 bind_meta_app(4 b s execute_extension::att_xfer XML features)
2016-12-22 14:59:08.478211 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/1002@35.160.75.57 set(ringback=%(2000,4000,440,480))
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1002@35.160.75.57 set(transfer_ringback=local_stream://moh)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1002@35.160.75.57 set(call_timeout=30)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [call_timeout]=[30]
EXECUTE sofia/internal/1002@35.160.75.57 set(hangup_after_bridge=true)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1002@35.160.75.57 set(continue_on_fail=true)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-call_return/1001/1002)
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial_ext/1001/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 set(called_party_callgroup=techsupport)
2016-12-22 14:59:08.478211 [DEBUG] mod_dptools.c:1477 sofia/internal/1002@35.160.75.57 SET [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial_ext/techsupport/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial_ext/global/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 hash(insert/35.160.75.57-last_dial/techsupport/304d65e2-c857-11e6-8125-fb2640f076da)
EXECUTE sofia/internal/1002@35.160.75.57 bridge(user/1001@35.160.75.57)
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1221 sofia/internal/1002@35.160.75.57 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 22 Dec 2016 14:59:08 +0000] to event
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1221 sofia/internal/1002@35.160.75.57 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2016-12-22 14:59:08.478211 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1221 sofia/internal/1002@35.160.75.57 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 22 Dec 2016 14:59:08 +0000] to event
2016-12-22 14:59:08.478211 [DEBUG] switch_channel.c:1221 sofia/internal/1002@35.160.75.57 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2016-12-22 14:59:08.478211 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables
2016-12-22 14:59:08.478211 [DEBUG] switch_event.c:1698 Parsing variable [sip_invite_domain]=[35.160.75.57]
2016-12-22 14:59:08.478211 [DEBUG] switch_event.c:1698 Parsing variable [presence_id]=[1001@35.160.75.57]
2016-12-22 14:59:08.478211 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/1001@192.168.10.113:53834 [30a159ae-c857-11e6-8144-fb2640f076da]
2016-12-22 14:59:08.478211 [DEBUG] mod_sofia.c:4700 (sofia/internal/1001@192.168.10.113:53834) State Change CS_NEW -> CS_INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_INIT
2016-12-22 14:59:08.478211 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1001@192.168.10.113:53834) State INIT
2016-12-22 14:59:08.478211 [DEBUG] mod_sofia.c:87 sofia/internal/1001@192.168.10.113:53834 SOFIA INIT
2016-12-22 14:59:08.478211 [DEBUG] sofia_glue.c:1212 sip:1001@91.142.62.148:61814;rinstance=B840C22E Setting proxy route to sofia/internal/1001@192.168.10.113:53834
2016-12-22 14:59:08.478211 [DEBUG] sofia_glue.c:1241 sofia/internal/1001@192.168.10.113:53834 sending invite version: 1.4.23 64bit
Local SDP:
v=0
o=FreeSWITCH 1482391882 1482391883 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 26866 RTP/AVP 0 8 9 3 102 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=20; maxptime=20; samplerate=48000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 16652 RTP/AVP 103 34
a=rtpmap:103 H264/90000
a=rtpmap:34 H263/90000
send 1626 bytes to udp/[91.142.62.148]:61814 at 14:59:08.498290:
------------------------------------------------------------------------
INVITE sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bK6p71K0ygvg8Zg
Route: <sip:1001@91.142.62.148:61814>;rinstance=B840C22E
Max-Forwards: 69
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873310 INVITE
Contact: <sip:mod_sofia@35.160.75.57:5060>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 543
X-FS-Support: update_display,send_info
Remote-Party-ID: "Extension 1002" <sip:1002@35.160.75.57>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1482391882 1482391883 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 26866 RTP/AVP 0 8 9 3 102 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=20; maxptime=20; samplerate=48000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 16652 RTP/AVP 103 34
a=rtpmap:103 H264/90000
a=rtpmap:34 H263/90000
------------------------------------------------------------------------
2016-12-22 14:59:08.498406 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.10.113:53834 Standard INIT
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.10.113:53834) State Change CS_INIT -> CS_ROUTING
2016-12-22 14:59:08.498406 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1001@192.168.10.113:53834) State INIT going to sleep
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_ROUTING
2016-12-22 14:59:08.498406 [DEBUG] sofia.c:6658 Channel sofia/internal/1001@192.168.10.113:53834 entering state [calling][0]
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1001@192.168.10.113:53834) State ROUTING
2016-12-22 14:59:08.498406 [DEBUG] mod_sofia.c:123 sofia/internal/1001@192.168.10.113:53834 SOFIA ROUTING
2016-12-22 14:59:08.498406 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@192.168.10.113:53834) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-12-22 14:59:08.498406 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1001@192.168.10.113:53834) State ROUTING going to sleep
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_CONSUME_MEDIA
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1001@192.168.10.113:53834) State CONSUME_MEDIA
2016-12-22 14:59:08.498406 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1001@192.168.10.113:53834) State CONSUME_MEDIA going to sleep
recv 355 bytes from udp/[91.142.62.148]:61814 at 14:59:08.865760:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bK6p71K0ygvg8Zg;received=35.160.75.57
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873310 INVITE
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>
Content-Length: 0
------------------------------------------------------------------------
recv 528 bytes from udp/[91.142.62.148]:61814 at 14:59:08.904586:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bK6p71K0ygvg8Zg;received=35.160.75.57
Contact: <sip:1001@192.168.10.113:53834>
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873310 INVITE
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:08.898222 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.898222 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:08.898222 [DEBUG] sofia.c:6658 Channel sofia/internal/1001@192.168.10.113:53834 entering state [proceeding][180]
2016-12-22 14:59:08.898222 [NOTICE] sofia.c:6760 Ring-Ready sofia/internal/1001@192.168.10.113:53834!
2016-12-22 14:59:08.898222 [DEBUG] switch_channel.c:3297 (sofia/internal/1001@192.168.10.113:53834) Callstate Change DOWN -> RINGING
recv 329 bytes from udp/[91.142.62.148]:61807 at 14:59:08.919943:
------------------------------------------------------------------------
ACK sip:1001@35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKU64Zh5aN0fD1BuyV;rport
Max-Forwards: 70
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=ce7yN682g53XB
CSeq: 1 ACK
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:08.918210 [INFO] switch_ivr_originate.c:1193 Sending early media
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [iLBC:102:8000:20:0:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [iLBC:102:8000:20:0:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [iLBC:102:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [iLBC:102:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [iLBC:102:8000:20:0:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:2506 Set Codec sofia/internal/1002@35.160.75.57 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2016-12-22 14:59:08.918210 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@35.160.75.57 Original read codec set to PCMU:0
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:3942 Set 2833 dtmf send/recv payload to 101
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:4060 Video Codec Compare [H263:34]/[H264:97]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:4060 Video Codec Compare [H263:34]/[H263:34]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:4073 Video Codec Compare [H263:34] +++ is saved as a match
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:2326 Set VIDEO Codec sofia/internal/1002@35.160.75.57 H263/90000 0 ms
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/internal/1002@35.160.75.57] 172.31.32.166 port 21588 -> 192.168.10.116 port 31210 codec: 0 ms: 20
2016-12-22 14:59:08.918210 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 160 bytes per 20ms
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:5504 sofia/internal/1002@35.160.75.57 Set rtp dtmf delay to 40
2016-12-22 14:59:08.918210 [DEBUG] switch_rtp.c:3588 Not using a timer
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:5680 VIDEO RTP [sofia/internal/1002@35.160.75.57] 192.168.10.116:31984->192.168.10.116:45462 codec: 34 ms: 0 [SUCCESS]
2016-12-22 14:59:08.918210 [NOTICE] switch_core_media.c:4442 sofia/internal/1002@35.160.75.57 Starting Video thread
2016-12-22 14:59:08.918210 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1002@35.160.75.57!
2016-12-22 14:59:08.918210 [DEBUG] switch_channel.c:3419 (sofia/internal/1002@35.160.75.57) Callstate Change RINGING -> EARLY
2016-12-22 14:59:08.918210 [DEBUG] mod_sofia.c:2264 Ring SDP:
v=0
o=FreeSWITCH 1482397160 1482397161 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 21588 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 31984 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
send 1228 bytes to udp/[91.142.62.148]:61807 at 14:59:08.926064:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKdY4bwnRzxuZZ3oE3;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 2 INVITE
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 302
Remote-Party-ID: "1001" <sip:1001@35.160.75.57>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1482397160 1482397161 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 21588 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 31984 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
------------------------------------------------------------------------
2016-12-22 14:59:08.918210 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.918210 [DEBUG] sofia.c:6658 Channel sofia/internal/1002@35.160.75.57 entering state [early][183]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:08.918210 [DEBUG] switch_ivr_originate.c:1250 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2016-12-22 14:59:08.918210 [DEBUG] switch_core_codec.c:221 sofia/internal/1002@35.160.75.57 Push codec L16:100
2016-12-22 14:59:08.918210 [DEBUG] switch_ivr_originate.c:1318 Play Ringback Tone [%(2000,4000,440,480)]
2016-12-22 14:59:08.918210 [DEBUG] switch_core_media.c:4366 sofia/internal/1002@35.160.75.57 Video thread started. Echo is on
send 802 bytes to udp/[91.142.62.148]:61807 at 14:59:08.926683:
------------------------------------------------------------------------
INFO sip:1002@192.168.10.116:58927 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bK7Z0tNUFmSSyjc
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873310 INFO
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 175
<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>
------------------------------------------------------------------------
recv 452 bytes from udp/[91.142.62.148]:61807 at 14:59:09.466745:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bK7Z0tNUFmSSyjc;received=35.160.75.57
Contact: <sip:1002@192.168.10.116:58927>
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873310 INFO
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:09.458188 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:09.758224 [INFO] switch_rtp.c:5867 Auto Changing port from 192.168.10.116:31210 to 46.19.199.210:31210
2016-12-22 14:59:10.558192 [INFO] switch_rtp.c:5867 Auto Changing port from 192.168.10.116:45462 to 46.19.199.210:45462
recv 847 bytes from udp/[91.142.62.148]:61814 at 14:59:10.961401:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bK6p71K0ygvg8Zg;received=35.160.75.57
Contact: <sip:1001@192.168.10.113:53834>
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873310 INVITE
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Type: application/sdp
Content-Length: 291
v=0
o=- 0773657206 19259 IN IP4 172.26.170.170
s=elopowo
c=IN IP4 192.168.10.113
t=0 0
m=audio 33100 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
m=video 33726 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
a=sendrecv
------------------------------------------------------------------------
2016-12-22 14:59:10.958137 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.958137 [DEBUG] sofia.c:6658 Channel sofia/internal/1001@192.168.10.113:53834 entering state [completing][200]
2016-12-22 14:59:10.958137 [DEBUG] sofia.c:6668 Remote SDP:
v=0
o=- 773657206 19259 IN IP4 172.26.170.170
s=elopowo
c=IN IP4 192.168.10.113
t=0 0
m=audio 33100 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
m=video 33726 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
send 447 bytes to udp/[91.142.62.148]:61814 at 14:59:10.962528:
------------------------------------------------------------------------
ACK sip:1001@192.168.10.113:53834 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bK88SKQp0Qp2m5Q
Max-Forwards: 70
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873310 ACK
Contact: <sip:mod_sofia@35.160.75.57:5060>
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:10.958137 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.958137 [DEBUG] sofia.c:6658 Channel sofia/internal/1001@192.168.10.113:53834 entering state [ready][200]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:2506 Set Codec sofia/internal/1001@192.168.10.113:53834 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2016-12-22 14:59:10.958137 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.10.113:53834 Original read codec set to PCMU:0
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:3933 Set 2833 dtmf send payload to 101
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:4060 Video Codec Compare [H263:34]/[H264:97]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:4060 Video Codec Compare [H263:34]/[H263:34]
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:4073 Video Codec Compare [H263:34] +++ is saved as a match
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:2326 Set VIDEO Codec sofia/internal/1001@192.168.10.113:53834 H263/90000 0 ms
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/internal/1001@192.168.10.113:53834] 172.31.32.166 port 26866 -> 192.168.10.113 port 33100 codec: 0 ms: 20
2016-12-22 14:59:10.958137 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 160 bytes per 20ms
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:5504 sofia/internal/1001@192.168.10.113:53834 Set rtp dtmf delay to 40
2016-12-22 14:59:10.958137 [DEBUG] switch_rtp.c:3588 Not using a timer
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:5680 VIDEO RTP [sofia/internal/1001@192.168.10.113:53834] 192.168.10.113:16652->192.168.10.113:33726 codec: 34 ms: 0 [SUCCESS]
2016-12-22 14:59:10.958137 [NOTICE] switch_core_media.c:4442 sofia/internal/1001@192.168.10.113:53834 Starting Video thread
2016-12-22 14:59:10.958137 [DEBUG] switch_channel.c:3657 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:10.958137 [NOTICE] sofia.c:7525 Channel [sofia/internal/1001@192.168.10.113:53834] has been answered
2016-12-22 14:59:10.958137 [DEBUG] switch_channel.c:3711 (sofia/internal/1001@192.168.10.113:53834) Callstate Change RINGING -> ACTIVE
2016-12-22 14:59:10.958137 [DEBUG] switch_core_media.c:4366 sofia/internal/1001@192.168.10.113:53834 Video thread started. Echo is off
send 862 bytes to udp/[91.142.62.148]:61814 at 14:59:10.967435:
------------------------------------------------------------------------
INFO sip:1001@192.168.10.113:53834 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bK9HKcSHHUKBBrK
Max-Forwards: 70
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873311 INFO
Contact: <sip:mod_sofia@35.160.75.57:5060>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 175
<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>
------------------------------------------------------------------------
2016-12-22 14:59:10.978178 [DEBUG] switch_core_codec.c:246 sofia/internal/1002@35.160.75.57 Restore previous codec PCMU:0.
2016-12-22 14:59:10.978178 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/1002@35.160.75.57:
v=0
o=FreeSWITCH 1482397160 1482397162 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 21588 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 31984 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
send 1234 bytes to udp/[91.142.62.148]:61807 at 14:59:10.983100:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKdY4bwnRzxuZZ3oE3;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 2 INVITE
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Session-Expires: 120;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 302
Remote-Party-ID: "Outbound Call" <sip:1001@35.160.75.57>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1482397160 1482397161 IN IP4 35.160.75.57
s=FreeSWITCH
c=IN IP4 35.160.75.57
t=0 0
m=audio 21588 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 31984 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=1;QCIF=2;SQCIF=2
------------------------------------------------------------------------
2016-12-22 14:59:10.978178 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:10.978178 [DEBUG] sofia.c:6658 Channel sofia/internal/1002@35.160.75.57 entering state [completed][200]
2016-12-22 14:59:10.978178 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:10.978178 [NOTICE] switch_ivr_originate.c:3523 Channel [sofia/internal/1002@35.160.75.57] has been answered
2016-12-22 14:59:10.978178 [DEBUG] switch_channel.c:3711 (sofia/internal/1002@35.160.75.57) Callstate Change EARLY -> ACTIVE
2016-12-22 14:59:10.978178 [DEBUG] switch_ivr_originate.c:3581 Originate Resulted in Success: [sofia/internal/1001@192.168.10.113:53834]
2016-12-22 14:59:10.978178 [DEBUG] switch_ivr_originate.c:3581 Originate Resulted in Success: [sofia/internal/1001@192.168.10.113:53834]
2016-12-22 14:59:10.978178 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.978178 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:10.978178 [DEBUG] switch_ivr_bridge.c:1473 (sofia/internal/1001@192.168.10.113:53834) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2016-12-22 14:59:10.978178 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:10.978178 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_EXCHANGE_MEDIA
2016-12-22 14:59:10.978178 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1001@192.168.10.113:53834) State EXCHANGE_MEDIA
2016-12-22 14:59:10.978178 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA
send 802 bytes to udp/[91.142.62.148]:61807 at 14:59:10.986495:
------------------------------------------------------------------------
INFO sip:1002@192.168.10.116:58927 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bKaUc5tc2ygm1aF
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873311 INFO
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 175
<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>
------------------------------------------------------------------------
2016-12-22 14:59:11.018225 [DEBUG] switch_core_media.c:4373 sofia/internal/1002@35.160.75.57 Video thread paused. Echo is on
2016-12-22 14:59:11.038227 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed.
2016-12-22 14:59:11.038227 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed.
2016-12-22 14:59:11.038227 [DEBUG] switch_core_media.c:4373 sofia/internal/1001@192.168.10.113:53834 Video thread paused. Echo is off
recv 521 bytes from udp/[91.142.62.148]:61814 at 14:59:11.349382:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bK9HKcSHHUKBBrK;received=35.160.75.57
Contact: <sip:1001@192.168.10.113:53834>
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873311 INFO
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:11.338187 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
recv 348 bytes from udp/[91.142.62.148]:61807 at 14:59:11.379738:
------------------------------------------------------------------------
ACK sip:1001@35.160.75.57:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKAbOzSk717AXaSyHH;rport
Max-Forwards: 70
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 2 ACK
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:11.378191 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:11.378191 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:11.378191 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:11.378191 [DEBUG] sofia.c:6658 Channel sofia/internal/1002@35.160.75.57 entering state [ready][200]
2016-12-22 14:59:11.378191 [DEBUG] switch_core_session.c:979 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:11.378191 [DEBUG] switch_core_session.c:979 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
recv 452 bytes from udp/[91.142.62.148]:61807 at 14:59:11.403646:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bKaUc5tc2ygm1aF;received=35.160.75.57
Contact: <sip:1002@192.168.10.116:58927>
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873311 INFO
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:11.398259 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:11.958213 [INFO] switch_rtp.c:5867 Auto Changing port from 192.168.10.113:33726 to 46.19.199.210:33726
recv 556 bytes from udp/[91.142.62.148]:61814 at 14:59:11.981186:
------------------------------------------------------------------------
REGISTER sip:35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bKwlxEfQSuT9xMptbG;rport
Contact: <sip:1001@192.168.10.113:53834;rinstance=B840C22E>;expires=600;video
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=7A2373838CBF988908A5247F8C3350E2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>
Expires: 600
Call-ID: 298A4925D0727E7A0DBC5EF55270652DE8141158
CSeq: 11 REGISTER
Content-Length: 0
------------------------------------------------------------------------
send 648 bytes to udp/[91.142.62.148]:61814 at 14:59:11.981764:
------------------------------------------------------------------------
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bKwlxEfQSuT9xMptbG;rport=61814;received=91.142.62.148
From: <sip:1001@35.160.75.57>;tag=7A2373838CBF988908A5247F8C3350E2
To: <sip:1001@35.160.75.57>;tag=F9j9tQUD8Z6Ne
Call-ID: 298A4925D0727E7A0DBC5EF55270652DE8141158
CSeq: 11 REGISTER
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
WWW-Authenticate: Digest realm="35.160.75.57", nonce="32b50cfe-c857-11e6-814c-fb2640f076da", algorithm=MD5, qop="auth"
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:11.978204 [WARNING] sofia_reg.c:1758 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1001@35.160.75.57] from ip 91.142.62.148
recv 805 bytes from udp/[91.142.62.148]:61814 at 14:59:12.366352:
------------------------------------------------------------------------
REGISTER sip:35.160.75.57 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bK60RL5NU9pPPDTsa3;rport
Contact: <sip:1001@192.168.10.113:53834;rinstance=B840C22E>;expires=600;video
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=7A2373838CBF988908A5247F8C3350E2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>
Expires: 600
Call-ID: 298A4925D0727E7A0DBC5EF55270652DE8141158
CSeq: 12 REGISTER
Authorization: Digest username="1001",realm="35.160.75.57",algorithm=MD5,uri="sip:35.160.75.57",nonce="32b50cfe-c857-11e6-814c-fb2640f076da",qop=auth,cnonce="8805cf792e65ee7b56282054e6049ac3",nc=00000001,response="52a32d00e5e6ce9ad6c79c3fe9180e05"
Content-Length: 0
------------------------------------------------------------------------
send 657 bytes to udp/[91.142.62.148]:61814 at 14:59:12.367584:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bK60RL5NU9pPPDTsa3;rport=61814;received=91.142.62.148
From: <sip:1001@35.160.75.57>;tag=7A2373838CBF988908A5247F8C3350E2
To: <sip:1001@35.160.75.57>;tag=gjc2vjcH58v8S
Call-ID: 298A4925D0727E7A0DBC5EF55270652DE8141158
CSeq: 12 REGISTER
Contact: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;expires=600
Date: Thu, 22 Dec 2016 14:59:12 GMT
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
recv 731 bytes from udp/[91.142.62.148]:61807 at 14:59:24.415243:
------------------------------------------------------------------------
INFO sip:1001@35.160.75.57:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKJMSXAOFFlczmwm1Y;rport
Contact: <sip:1002@192.168.10.116:58927>
Max-Forwards: 70
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
Content-Type: application/media_control+xml
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 3 INFO
Content-Length: 146
<?xml version="1.0" encoding="utf-8" ?><media_control><vc_primitive><to_encoder><picture_fast_update/></to_encoder></vc_primitive></media_control>
------------------------------------------------------------------------
2016-12-22 14:59:24.398190 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.418206 [DEBUG] switch_core_session.c:979 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.418206 [DEBUG] sofia.c:8784 dispatched freeswitch event for INFO
send 513 bytes to udp/[91.142.62.148]:61807 at 14:59:24.423471:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKJMSXAOFFlczmwm1Y;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 3 INFO
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
send 833 bytes to udp/[91.142.62.148]:61814 at 14:59:24.423732:
------------------------------------------------------------------------
INFO sip:1001@192.168.10.113:53834 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bKB45Xv7j2DXQXa
Max-Forwards: 70
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873312 INFO
Contact: <sip:mod_sofia@35.160.75.57:5060>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 146
<?xml version="1.0" encoding="utf-8" ?><media_control><vc_primitive><to_encoder><picture_fast_update/></to_encoder></vc_primitive></media_control>
------------------------------------------------------------------------
recv 521 bytes from udp/[91.142.62.148]:61814 at 14:59:24.848185:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bKB45Xv7j2DXQXa;received=35.160.75.57
Contact: <sip:1001@192.168.10.113:53834>
From: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 100873312 INFO
To: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:24.838204 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
recv 596 bytes from udp/[91.142.62.148]:61814 at 14:59:24.905798:
------------------------------------------------------------------------
BYE sip:mod_sofia@35.160.75.57:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bKIzHlVYkgvga1ZwSq;rport
Contact: <sip:1001@192.168.10.113:53834>
Max-Forwards: 70
From: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 1 BYE
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:24.898188 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.918190 [NOTICE] sofia.c:952 Hangup sofia/internal/1001@192.168.10.113:53834 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2016-12-22 14:59:24.918190 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/1001@192.168.10.113:53834 [KILL]
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
send 581 bytes to udp/[91.142.62.148]:61814 at 14:59:24.924396:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.10.113:53834;branch=z9hG4bKIzHlVYkgvga1ZwSq;rport=61814;received=91.142.62.148
From: <sip:1001@192.168.10.113:53834;rinstance=B840C22E;received=91.142.62.148:61814>;tag=FE5DFD1A456A147EE3A2145487DF53FD
To: "Extension 1002" <sip:1002@35.160.75.57>;tag=e0SgSvaaBQg3j
Call-ID: 07ffcba1-42fa-1235-4aab-029d80950d35
CSeq: 1 BYE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:602 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:603 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:604 Ending video thread.
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:651 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:652 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:654 Ending video thread.
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:99 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:100 sofia/internal/1001@192.168.10.113:53834 video thread ended.
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:2906 sofia/internal/1001@192.168.10.113:53834 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
send 802 bytes to udp/[91.142.62.148]:61807 at 14:59:24.924990:
------------------------------------------------------------------------
INFO sip:1002@192.168.10.116:58927 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bKcDZpy235a6Dgp
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873312 INFO
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 175
<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>
------------------------------------------------------------------------
2016-12-22 14:59:24.918190 [DEBUG] switch_core_media.c:4376 sofia/internal/1001@192.168.10.113:53834 Video thread resumed Echo is off
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:2906 sofia/internal/1001@192.168.10.113:53834 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:665 BRIDGE THREAD DONE [sofia/internal/1001@192.168.10.113:53834]
2016-12-22 14:59:24.918190 [DEBUG] switch_ivr_bridge.c:695 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1001@192.168.10.113:53834) State EXCHANGE_MEDIA going to sleep
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_HANGUP
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1001@192.168.10.113:53834) Callstate Change ACTIVE -> HANGUP
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1001@192.168.10.113:53834) State HANGUP
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:2906 sofia/internal/1001@192.168.10.113:53834 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2016-12-22 14:59:24.918190 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1001@192.168.10.113:53834 hanging up, cause: NORMAL_CLEARING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.10.113:53834 Standard HANGUP, cause: NORMAL_CLEARING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1001@192.168.10.113:53834) State HANGUP going to sleep
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1001@192.168.10.113:53834) State Change CS_HANGUP -> CS_REPORTING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_REPORTING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1001@192.168.10.113:53834) State REPORTING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:2906 sofia/internal/1001@192.168.10.113:53834 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1001@192.168.10.113:53834 Standard REPORTING, cause: NORMAL_CLEARING
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1001@192.168.10.113:53834) State REPORTING going to sleep
2016-12-22 14:59:24.918190 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1001@192.168.10.113:53834) State Change CS_REPORTING -> CS_DESTROY
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.918190 [DEBUG] switch_core_session.c:1624 Session 9 (sofia/internal/1001@192.168.10.113:53834) Locked, Waiting on external entities
2016-12-22 14:59:24.918190 [DEBUG] switch_core_media.c:4415 sofia/internal/1001@192.168.10.113:53834 Video thread ended
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:584 sofia/internal/1001@192.168.10.113:53834 ending bridge by request from write function
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:602 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:603 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:604 Ending video thread.
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:651 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:652 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.938194 [DEBUG] switch_ivr_bridge.c:654 Ending video thread.
2016-12-22 14:59:24.958191 [DEBUG] switch_ivr_bridge.c:99 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.958191 [DEBUG] switch_ivr_bridge.c:100 sofia/internal/1002@35.160.75.57 video thread ended.
2016-12-22 14:59:24.958191 [DEBUG] switch_core_media.c:4376 sofia/internal/1002@35.160.75.57 Video thread resumed Echo is on
2016-12-22 14:59:24.958191 [DEBUG] switch_ivr_bridge.c:665 BRIDGE THREAD DONE [sofia/internal/1002@35.160.75.57]
2016-12-22 14:59:24.958191 [DEBUG] switch_ivr_bridge.c:695 Send signal sofia/internal/1001@192.168.10.113:53834 [BREAK]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.958191 [NOTICE] switch_ivr_bridge.c:1616 Hangup sofia/internal/1002@35.160.75.57 [CS_EXECUTE] [NORMAL_CLEARING]
2016-12-22 14:59:24.958191 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/1002@35.160.75.57 [KILL]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:2767 sofia/internal/1002@35.160.75.57 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1002@35.160.75.57) State EXECUTE going to sleep
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_HANGUP
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1002@35.160.75.57) Callstate Change ACTIVE -> HANGUP
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1002@35.160.75.57) State HANGUP
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:2906 sofia/internal/1002@35.160.75.57 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2016-12-22 14:59:24.958191 [DEBUG] mod_sofia.c:407 sofia/internal/1002@35.160.75.57 Overriding SIP cause 480 with 200 from the other leg
2016-12-22 14:59:24.958191 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1002@35.160.75.57 hanging up, cause: NORMAL_CLEARING
2016-12-22 14:59:24.958191 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/1002@35.160.75.57
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1002@35.160.75.57 Standard HANGUP, cause: NORMAL_CLEARING
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1002@35.160.75.57) State HANGUP going to sleep
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1002@35.160.75.57) State Change CS_HANGUP -> CS_REPORTING
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1002@35.160.75.57) Running State Change CS_REPORTING
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1002@35.160.75.57) State REPORTING
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:2906 sofia/internal/1002@35.160.75.57 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1002@35.160.75.57 Standard REPORTING, cause: NORMAL_CLEARING
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1002@35.160.75.57) State REPORTING going to sleep
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1002@35.160.75.57) State Change CS_REPORTING -> CS_DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1002@35.160.75.57 [BREAK]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_session.c:1624 Session 8 (sofia/internal/1002@35.160.75.57) Locked, Waiting on external entities
2016-12-22 14:59:24.958191 [NOTICE] switch_core_session.c:1642 Session 9 (sofia/internal/1001@192.168.10.113:53834) Ended
2016-12-22 14:59:24.958191 [NOTICE] switch_core_session.c:1646 Close Channel sofia/internal/1001@192.168.10.113:53834 [CS_DESTROY]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1001@192.168.10.113:53834) Running State Change CS_DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1001@192.168.10.113:53834) State DESTROY
2016-12-22 14:59:24.958191 [DEBUG] mod_sofia.c:323 sofia/internal/1001@192.168.10.113:53834 SOFIA DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1001@192.168.10.113:53834 Standard DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1001@192.168.10.113:53834) State DESTROY going to sleep
2016-12-22 14:59:24.958191 [DEBUG] switch_core_media.c:4415 sofia/internal/1002@35.160.75.57 Video thread ended
2016-12-22 14:59:24.958191 [NOTICE] switch_core_session.c:1642 Session 8 (sofia/internal/1002@35.160.75.57) Ended
2016-12-22 14:59:24.958191 [NOTICE] switch_core_session.c:1646 Close Channel sofia/internal/1002@35.160.75.57 [CS_DESTROY]
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1002@35.160.75.57) Running State Change CS_DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1002@35.160.75.57) State DESTROY
2016-12-22 14:59:24.958191 [DEBUG] mod_sofia.c:323 sofia/internal/1002@35.160.75.57 SOFIA DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1002@35.160.75.57 Standard DESTROY
2016-12-22 14:59:24.958191 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1002@35.160.75.57) State DESTROY going to sleep
recv 536 bytes from udp/[91.142.62.148]:61807 at 14:59:25.683221:
------------------------------------------------------------------------
BYE sip:1001@35.160.75.57:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKA3UU3bQyBLb5I5j8;rport
Contact: <sip:1002@192.168.10.116:58927>
Max-Forwards: 70
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 4 BYE
Content-Length: 0
------------------------------------------------------------------------
send 802 bytes to udp/[91.142.62.148]:61807 at 14:59:25.924928:
------------------------------------------------------------------------
INFO sip:1002@192.168.10.116:58927 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bKcDZpy235a6Dgp
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873312 INFO
Contact: <sip:1001@35.160.75.57:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: application/media_control+xml
Content-Length: 175
<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>
------------------------------------------------------------------------
recv 469 bytes from udp/[91.142.62.148]:61807 at 14:59:27.415716:
------------------------------------------------------------------------
SIP/2.0 481 Call Does Not Exist
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bKcDZpy235a6Dgp;received=35.160.75.57
Contact: <sip:1002@192.168.10.116:58927>
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873312 INFO
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
send 572 bytes to udp/[91.142.62.148]:61807 at 14:59:27.415936:
------------------------------------------------------------------------
BYE sip:1002@192.168.10.116:58927 SIP/2.0
Via: SIP/2.0/UDP 35.160.75.57;rport;branch=z9hG4bKDprF0Xm97e42H
Max-Forwards: 70
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873313 BYE
User-Agent: FreeSWITCH-mod_sofia/1.4.23~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
recv 536 bytes from udp/[91.142.62.148]:61807 at 14:59:27.649741:
------------------------------------------------------------------------
BYE sip:1001@35.160.75.57:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKA3UU3bQyBLb5I5j8;rport
Contact: <sip:1002@192.168.10.116:58927>
Max-Forwards: 70
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
User-Agent: Acrobits SDK (build 0; iOS; arm64-neon)
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 4 BYE
Content-Length: 0
------------------------------------------------------------------------
recv 451 bytes from udp/[91.142.62.148]:61807 at 14:59:27.861682:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 35.160.75.57;rport=5060;branch=z9hG4bKDprF0Xm97e42H;received=35.160.75.57
Contact: <sip:1002@192.168.10.116:58927>
From: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 100873313 BYE
To: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE, NOTIFY, MESSAGE
Supported: replaces, path
Content-Length: 0
------------------------------------------------------------------------
send 321 bytes to udp/[91.142.62.148]:61807 at 14:59:27.861988:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.10.116:58927;branch=z9hG4bKA3UU3bQyBLb5I5j8;rport=61807;received=91.142.62.148
From: <sip:1002@35.160.75.57>;tag=92531864719D9D5229855C1EA95219C2
To: <sip:1001@35.160.75.57>;tag=DQ0QQ1S6DetgQ
Call-ID: 14E5E54EF64EF3F74FF5B59F2EB87654D281A738
CSeq: 4 BYE
Content-Length: 0
------------------------------------------------------------------------