2018-08-30 10:00:27.294099 [DEBUG] sofia.c:11168 Setting NAT mode based on nat.auto
2018-08-30 10:00:27.294099 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@tekart.dayo.com.ng entering state [received][100]
2018-08-30 10:00:27.294099 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 13180096828185127 1 IN IP4 192.168.43.205
s=X-Lite release 5.3.1 stamp 92361
c=IN IP4 192.168.43.205
t=0 0
m=audio 50648 RTP/AVP 9 8 120 0
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
2018-08-30 10:00:27.294099 [DEBUG] sofia.c:7486 (sofia/internal/1000@tekart.dayo.com.ng) State Change CS_NEW -> CS_INIT
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_INIT (Cur 2 Tot 1932)
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@tekart.dayo.com.ng) State INIT
2018-08-30 10:00:27.294099 [DEBUG] mod_sofia.c:90 sofia/internal/1000@tekart.dayo.com.ng SOFIA INIT
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@tekart.dayo.com.ng Standard INIT
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@tekart.dayo.com.ng) State Change CS_INIT -> CS_ROUTING
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@tekart.dayo.com.ng) State INIT going to sleep
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_ROUTING (Cur 2 Tot 1932)
2018-08-30 10:00:27.294099 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@tekart.dayo.com.ng) Callstate Change DOWN -> RINGING
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@tekart.dayo.com.ng) State ROUTING
2018-08-30 10:00:27.294099 [DEBUG] mod_sofia.c:143 sofia/internal/1000@tekart.dayo.com.ng SOFIA ROUTING
2018-08-30 10:00:27.294099 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@tekart.dayo.com.ng Standard ROUTING
2018-08-30 10:00:27.294099 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1010 in context tekart.dayo.com.ng
2018-08-30 10:00:27.294099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
'Event-Name: REQUEST_PARAMS
Core-UUID: f339f992-3aa5-448d-8aca-5fd7e6c3b677
FreeSWITCH-Hostname: test-fs-001
FreeSWITCH-Switchname: test-fs-001
FreeSWITCH-IPv4: 139.162.188.90
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2018-08-30%2010%3A00%3A27
Event-Date-GMT: Thu,%2030%20Aug%202018%2010%3A00%3A27%20GMT
Event-Date-Timestamp: 1535623227294099
Event-Calling-File: mod_dialplan_xml.c
Event-Calling-Function: dialplan_xml_locate
Event-Calling-Line-Number: 608
Event-Sequence: 28349
Channel-State: CS_ROUTING
Channel-Call-State: RINGING
Channel-State-Number: 2
Channel-Name: sofia/internal/1000%40tekart.dayo.com.ng
Unique-ID: cd187882-801d-45e0-b9b6-6065e09debb8
Call-Direction: inbound
Presence-Call-Direction: inbound
Channel-HIT-Dialplan: true
Channel-Presence-ID: 1000%40tekart.dayo.com.ng
Channel-Call-UUID: cd187882-801d-45e0-b9b6-6065e09debb8
Answer-State: ringing
Caller-Direction: inbound
Caller-Logical-Direction: inbound
Caller-Username: 1000
Caller-Dialplan: XML
Caller-Caller-ID-Name: 1000
Caller-Caller-ID-Number: 1000
Caller-Orig-Caller-ID-Name: 1000
Caller-Orig-Caller-ID-Number: 1000
Caller-Network-Addr: 197.210.173.34
Caller-ANI: 1000
Caller-Destination-Number: 1010
Caller-Unique-ID: cd187882-801d-45e0-b9b6-6065e09debb8
Caller-Source: mod_sofia
Caller-Context: tekart.dayo.com.ng
Caller-Channel-Name: sofia/internal/1000%40tekart.dayo.com.ng
Caller-Profile-Index: 1
Caller-Profile-Created-Time: 1535623227294099
Caller-Channel-Created-Time: 1535623227294099
Caller-Channel-Answered-Time: 0
Caller-Channel-Progress-Time: 0
Caller-Channel-Progress-Media-Time: 0
Caller-Channel-Hangup-Time: 0
Caller-Channel-Transfer-Time: 0
Caller-Channel-Resurrect-Time: 0
Caller-Channel-Bridged-Time: 0
Caller-Channel-Last-Hold: 0
Caller-Channel-Hold-Accum: 0
Caller-Screen-Bit: true
Caller-Privacy-Hide-Name: false
Caller-Privacy-Hide-Number: false
variable_direction: inbound
variable_uuid: cd187882-801d-45e0-b9b6-6065e09debb8
variable_session_id: 1932
variable_sip_from_user: 1000
variable_sip_from_uri: 1000%40tekart.dayo.com.ng
variable_sip_from_host: tekart.dayo.com.ng
variable_video_media_flow: sendrecv
variable_audio_media_flow: sendrecv
variable_channel_name: sofia/internal/1000%40tekart.dayo.com.ng
variable_sip_call_id: 92361NTUyMzI1ZWE0YWJiMDM2NzI3YTZlNjZmOGMyZDhiNGM
variable_ep_codec_string: mod_spandsp.G722%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b,mod_opus.opus%4048000h%4020i%402c,CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b
variable_sip_local_network_addr: 139.162.188.90
variable_sip_network_ip: 197.210.173.34
variable_sip_network_port: 63691
variable_sip_invite_stamp: 1535623226724129
variable_sip_received_ip: 197.210.173.34
variable_sip_received_port: 63691
variable_sip_via_protocol: udp
variable_sip_authorized: true
variable_Event-Name: REQUEST_PARAMS
variable_Core-UUID: f339f992-3aa5-448d-8aca-5fd7e6c3b677
variable_FreeSWITCH-Hostname: test-fs-001
variable_FreeSWITCH-Switchname: test-fs-001
variable_FreeSWITCH-IPv4: 139.162.188.90
variable_FreeSWITCH-IPv6: %3A%3A1
variable_Event-Date-Local: 2018-08-30%2010%3A00%3A26
variable_Event-Date-GMT: Thu,%2030%20Aug%202018%2010%3A00%3A26%20GMT
variable_Event-Date-Timestamp: 1535623226724129
variable_Event-Calling-File: sofia.c
variable_Event-Calling-Function: sofia_handle_sip_i_invite
variable_Event-Calling-Line-Number: 10096
variable_Event-Sequence: 28341
variable_sip_number_alias: 1000
variable_sip_auth_username: 1000
variable_sip_auth_realm: tekart.dayo.com.ng
variable_number_alias: 1000
variable_requested_user_name: 1000
variable_requested_domain_name: tekart.dayo.com.ng
variable_domain_uuid: None
variable_user_id: 3
variable_extension_uuid: d5bd2432-d3bc-413a-8dac-032df74a6f06
variable_call_timeout: 30
variable_caller_id_name: 1000
variable_caller_id_number: 1000
variable_presence_id: 1000%40tekart.dayo.com.ng
variable_user_context: tekart.dayo.com.ng
variable_bypass_media: false
variable_export_vars: domain_name
variable_user_name: 1000
variable_domain_name: tekart.dayo.com.ng
variable_sip_from_user_stripped: 1000
variable_sip_from_tag: f3994a54
variable_sofia_profile_name: internal
variable_recovery_profile_name: internal
variable_sip_full_via: SIP/2.0/UDP%20192.168.43.205%3A63691%3Bbranch%3Dz9hG4bK-524287-1---bf52ae2515eda022%3Brport%3D63691%3Breceived%3D197.210.173.34
variable_sip_from_display: 1000
variable_sip_full_from: %221000%22%20%3Csip%3A1000%40tekart.dayo.com.ng%3E%3Btag%3Df3994a54
variable_sip_full_to: %3Csip%3A1010%40tekart.dayo.com.ng%3E
variable_sip_allow: SUBSCRIBE,%20NOTIFY,%20INVITE,%20ACK,%20CANCEL,%20BYE,%20REFER,%20INFO,%20OPTIONS,%20MESSAGE
variable_sip_req_user: 1010
variable_sip_req_uri: 1010%40tekart.dayo.com.ng
variable_sip_req_host: tekart.dayo.com.ng
variable_sip_to_user: 1010
variable_sip_to_uri: 1010%40tekart.dayo.com.ng
variable_sip_to_host: tekart.dayo.com.ng
variable_sip_contact_user: 1000
variable_sip_contact_port: 63691
variable_sip_contact_uri: 1000%40192.168.43.205%3A63691
variable_sip_contact_host: 192.168.43.205
variable_rtp_use_codec_string: OPUS,G722,PCMU,PCMA,VP8
variable_sip_user_agent: X-Lite%20release%205.3.1%20stamp%2092361
variable_sip_via_host: 192.168.43.205
variable_sip_via_port: 63691
variable_sip_via_rport: 63691
variable_max_forwards: 70
variable_sip_nat_detected: true
variable_switch_r_sdp: v%3D0%0D%0Ao%3D-%2013180096828185127%201%20IN%20IP4%20192.168.43.205%0D%0As%3DX-Lite%20release%205.3.1%20stamp%2092361%0D%0Ac%3DIN%20IP4%20192.168.43.205%0D%0At%3D0%200%0D%0Am%3Daudio%2050648%20RTP/AVP%209%208%20120%200%0D%0Aa%3Drtpmap%3A120%20opus/48000/2%0D%0Aa%3Dfmtp%3A120%20useinbandfec%3D1%3B%20usedtx%3D1%3B%20maxaveragebitrate%3D64000%0D%0A
variable_endpoint_disposition: DELAYED%20NEGOTIATION
variable_call_uuid: cd187882-801d-45e0-b9b6-6065e09debb8
Hunt-Direction: inbound
Hunt-Logical-Direction: inbound
Hunt-Username: 1000
Hunt-Dialplan: XML
Hunt-Caller-ID-Name: 1000
Hunt-Caller-ID-Number: 1000
Hunt-Orig-Caller-ID-Name: 1000
Hunt-Orig-Caller-ID-Number: 1000
Hunt-Network-Addr: 197.210.173.34
Hunt-ANI: 1000
Hunt-Destination-Number: 1010
Hunt-Unique-ID: cd187882-801d-45e0-b9b6-6065e09debb8
Hunt-Source: mod_sofia
Hunt-Context: tekart.dayo.com.ng
Hunt-Channel-Name: sofia/internal/1000%40tekart.dayo.com.ng
Hunt-Profile-Index: 1
Hunt-Profile-Created-Time: 1535623227294099
Hunt-Channel-Created-Time: 1535623227294099
Hunt-Channel-Answered-Time: 0
Hunt-Channel-Progress-Time: 0
Hunt-Channel-Progress-Media-Time: 0
Hunt-Channel-Hangup-Time: 0
Hunt-Channel-Transfer-Time: 0
Hunt-Channel-Resurrect-Time: 0
Hunt-Channel-Bridged-Time: 0
Hunt-Channel-Last-Hold: 0
Hunt-Channel-Hold-Accum: 0
Hunt-Screen-Bit: true
Hunt-Privacy-Hide-Name: false
Hunt-Privacy-Hide-Number: false
'
2018-08-30 10:00:27.294099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: dialplan
2018-08-30 10:00:27.294099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name:
2018-08-30 10:00:27.294099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name:
2018-08-30 10:00:27.294099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value:
2018-08-30 10:00:27.324093 [ALERT] mod_verto.c:5329 EVENT BROADCAST presence.1000@tekart.dayo.com.ng {
"data": {
"channelCallState": "RINGING",
"originalChannelCallState": "DOWN",
"channelState": "CS_ROUTING",
"callerUserName": "1000",
"callerIDName": "1000",
"callerIDNumber": "1000",
"channelUUID": "cd187882-801d-45e0-b9b6-6065e09debb8",
"presenceCallDirection": "inbound",
"channelPresenceID": "1000@tekart.dayo.com.ng"
},
"eventChannel": "presence.1000@tekart.dayo.com.ng"
}
2018-08-30 10:00:27.864114 [NOTICE] switch_cpp.cpp:1365 [xml]:
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->dayo] continue=true
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (PASS) [dayo] destination_number(1010) =~ /^\d{4}$/ break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Action export(domain_name=${context})
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Action bridge(user/${destination_number}@${domain_name})
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->user_exists] continue=true
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Action set(user_exists=${user_exists id ${destination_number} ${domain_name}})
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [user_exists] ${user_exists}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->call-direction] continue=true
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/1000@tekart.dayo.com.ng ANTI-Action set(call_direction=local)
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->hold_music] continue=false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [hold_music] destination_number(1010) =~ /^\*9664$/ break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->freeswitch_conference] continue=false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [freeswitch_conference] destination_number(1010) =~ /^\*9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->local_extension] continue=true
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [local_extension] ${user_exists}() =~ /true/ break=on-false
Dialplan: sofia/internal/1000@tekart.dayo.com.ng parsing [tekart.dayo.com.ng->12005] continue=true
Dialplan: sofia/internal/1000@tekart.dayo.com.ng Regex (FAIL) [12005] destination_number(1010) =~ /^(12005)$/ break=on-false
2018-08-30 10:00:27.874099 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@tekart.dayo.com.ng) State Change CS_ROUTING -> CS_EXECUTE
2018-08-30 10:00:27.874099 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@tekart.dayo.com.ng) State ROUTING going to sleep
2018-08-30 10:00:27.874099 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_EXECUTE (Cur 2 Tot 1932)
2018-08-30 10:00:27.874099 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@tekart.dayo.com.ng) State EXECUTE
2018-08-30 10:00:27.874099 [DEBUG] mod_sofia.c:198 sofia/internal/1000@tekart.dayo.com.ng SOFIA EXECUTE
2018-08-30 10:00:27.874099 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@tekart.dayo.com.ng Standard EXECUTE
EXECUTE sofia/internal/1000@tekart.dayo.com.ng export(domain_name=tekart.dayo.com.ng)
2018-08-30 10:00:27.874099 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [domain_name]=[tekart.dayo.com.ng]
EXECUTE sofia/internal/1000@tekart.dayo.com.ng bridge(user/1010@tekart.dayo.com.ng)
2018-08-30 10:00:27.874099 [DEBUG] switch_channel.c:1250 sofia/internal/1000@tekart.dayo.com.ng EXPORTING[export_vars] [domain_name]=[tekart.dayo.com.ng] to event
2018-08-30 10:00:27.874099 [DEBUG] switch_channel.c:1250 sofia/internal/1000@tekart.dayo.com.ng EXPORTING[export_vars] [domain_name]=[tekart.dayo.com.ng] to event
2018-08-30 10:00:27.874099 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-30 10:00:27.874099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
'Event-Name: REQUEST_PARAMS
Core-UUID: f339f992-3aa5-448d-8aca-5fd7e6c3b677
FreeSWITCH-Hostname: test-fs-001
FreeSWITCH-Switchname: test-fs-001
FreeSWITCH-IPv4: 139.162.188.90
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2018-08-30%2010%3A00%3A27
Event-Date-GMT: Thu,%2030%20Aug%202018%2010%3A00%3A27%20GMT
Event-Date-Timestamp: 1535623227874099
Event-Calling-File: mod_dptools.c
Event-Calling-Function: user_outgoing_channel
Event-Calling-Line-Number: 4167
Event-Sequence: 28356
as_channel: true
action: user_call
export_vars: domain_name,domain_name
domain_name: tekart.dayo.com.ng
key: id
user: 1010
domain: tekart.dayo.com.ng
'
2018-08-30 10:00:27.874099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: directory
2018-08-30 10:00:27.874099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name: domain
2018-08-30 10:00:27.874099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name: name
2018-08-30 10:00:27.874099 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value: tekart.dayo.com.ng
2018-08-30 10:00:28.434104 [NOTICE] switch_cpp.cpp:1365 [xml]:
2018-08-30 10:00:28.444092 [DEBUG] switch_channel.c:1250 sofia/internal/1000@tekart.dayo.com.ng EXPORTING[export_vars] [domain_name]=[tekart.dayo.com.ng] to event
2018-08-30 10:00:28.444092 [DEBUG] switch_channel.c:1250 sofia/internal/1000@tekart.dayo.com.ng EXPORTING[export_vars] [domain_name]=[tekart.dayo.com.ng] to event
2018-08-30 10:00:28.444092 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-30 10:00:28.444092 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2018-08-30 10:00:28.444092 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
2018-08-30 10:00:28.444092 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 [41f39aee-4cfc-4782-be62-546edc3cef7c]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_INIT (Cur 3 Tot 1933)
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State INIT
2018-08-30 10:00:28.444092 [CRIT] switch_channel.c:1436 Invalid data (${local_media_ip} contains a variable)
2018-08-30 10:00:28.444092 [CRIT] switch_channel.c:1436 Invalid data (${advertised_media_ip} contains a variable)
2018-08-30 10:00:28.444092 [CRIT] switch_channel.c:1436 Invalid data (${local_video_ip} contains a variable)
2018-08-30 10:00:28.444092 [CRIT] switch_channel.c:1436 Invalid data (${rtp_local_sdp_str} contains a variable)
2018-08-30 10:00:28.444092 [DEBUG] mod_verto.c:2229 Local verto.invite SDP verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071:
v=0
o=FreeSWITCH 1535593920 1535593921 IN IP4 $${local_ip_v4}
s=FreeSWITCH
c=IN IP4 $${local_ip_v4}
t=0 0
a=msid-semantic: WMS ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN
m=audio 29308 RTP/SAVPF 9 8 102 0 103
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:0 PCMU/8000
a=rtpmap:103 opus/48000/2
a=fmtp:103 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=fingerprint:sha-256 6F:3C:B0:AA:DD:12:17:A7:F0:26:56:8C:5F:B2:F5:A1:DF:2A:0B:87:EF:F6:07:14:53:DB:A4:F8:81:01:D2:5F
a=setup:actpass
a=rtcp-mux
a=rtcp:29308 IN IP4 $${local_ip_v4}
a=ssrc:463787340 cname:7dtvIsRBJb2AlD8p
a=ssrc:463787340 msid:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN a0
a=ssrc:463787340 mslabel:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN
a=ssrc:463787340 label:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrNa0
a=ice-ufrag:PnR7zzOrg4NFG4iE
a=ice-pwd:8C0HUH8uJ1UVuTaa6S8whMOo
a=candidate:7096455128 1 udp 659136 $${local_ip_v4} 29308 typ host generation 0
a=candidate:7096455128 2 udp 659136 $${local_ip_v4} 29308 typ host generation 0
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
m=video 29310 RTP/SAVPF 104
b=AS:1024
a=rtpmap:104 VP8/90000
a=fingerprint:sha-256 6F:3C:B0:AA:DD:12:17:A7:F0:26:56:8C:5F:B2:F5:A1:DF:2A:0B:87:EF:F6:07:14:53:DB:A4:F8:81:01:D2:5F
a=setup:actpass
a=rtcp-mux
a=rtcp:29310 IN IP4 $${local_ip_v4}
a=rtcp-fb:104 ccm fir
a=rtcp-fb:104 ccm tmmbr
a=rtcp-fb:104 nack
a=rtcp-fb:104 nack pli
a=ssrc:3990963918 cname:7dtvIsRBJb2AlD8p
a=ssrc:3990963918 msid:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN v0
a=ssrc:3990963918 mslabel:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN
a=ssrc:3990963918 label:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrNv0
a=ice-ufrag:xbhifuaNFvcnA94Z
a=ice-pwd:GD9Yw1gpQhh2qLSON0WSkXwP
a=candidate:7628899082 1 udp 659136 $${local_ip_v4} 29310 typ host generation 0
a=candidate:7628899082 2 udp 659135 $${local_ip_v4} 29310 typ host generation 0
a=end-of-candidates
2018-08-30 10:00:28.444092 [NOTICE] mod_verto.c:2329 Ring-Ready verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071!
2018-08-30 10:00:28.444092 [DEBUG] switch_channel.c:3346 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Callstate Change DOWN -> RINGING
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:40 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 Standard INIT
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State Change CS_INIT -> CS_ROUTING
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State INIT going to sleep
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_ROUTING (Cur 3 Tot 1933)
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State ROUTING
2018-08-30 10:00:28.444092 [DEBUG] mod_rtc.c:89 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 RTC ROUTING
2018-08-30 10:00:28.444092 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State ROUTING going to sleep
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 1933)
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State CONSUME_MEDIA
2018-08-30 10:00:28.444092 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State CONSUME_MEDIA going to sleep
2018-08-30 10:00:28.444092 [ALERT] mod_verto.c:5329 EVENT BROADCAST presence.1010@tekart.dayo.com.ng {
"data": {
"channelCallState": "RINGING",
"originalChannelCallState": "DOWN",
"channelState": "CS_INIT",
"callerUserName": "1000",
"callerIDName": "1000",
"callerIDNumber": "1000",
"calleeIDName": "Dayo",
"calleeIDNumber": "1010",
"channelUUID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"presenceCallDirection": "outbound",
"channelPresenceID": "1010@tekart.dayo.com.ng"
},
"eventChannel": "presence.1010@tekart.dayo.com.ng"
}
2018-08-30 10:00:28.444092 [INFO] switch_ivr_originate.c:1215 Sending early media
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1000@tekart.dayo.com.ng G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-30 10:00:28.444092 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@tekart.dayo.com.ng Original read codec set to G722:9
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:4774 No 2833 in SDP. Disable 2833 dtmf and switch to INFO
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1000@tekart.dayo.com.ng] 139.162.188.90 port 25702 -> 192.168.43.205 port 50648 codec: 9 ms: 20
2018-08-30 10:00:28.444092 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:7210 sofia/internal/1000@tekart.dayo.com.ng Set rtp dtmf delay to 40
2018-08-30 10:00:28.444092 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@tekart.dayo.com.ng!
2018-08-30 10:00:28.444092 [DEBUG] switch_channel.c:3474 (sofia/internal/1000@tekart.dayo.com.ng) Callstate Change RINGING -> EARLY
2018-08-30 10:00:28.444092 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/1000@tekart.dayo.com.ng.
2018-08-30 10:00:28.444092 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1535597526 1535597527 IN IP4 139.162.188.90
s=FreeSWITCH
c=IN IP4 139.162.188.90
t=0 0
m=audio 25702 RTP/AVP 9
a=rtpmap:9 G722/8000
a=ptime:20
a=sendrecv
2018-08-30 10:00:28.444092 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@tekart.dayo.com.ng entering state [early][183]
2018-08-30 10:00:28.444092 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@16000hz 1 channel 20ms
2018-08-30 10:00:28.444092 [DEBUG] switch_core_codec.c:223 sofia/internal/1000@tekart.dayo.com.ng Push codec L16:100
2018-08-30 10:00:28.444092 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)]
2018-08-30 10:00:28.444092 [ALERT] mod_verto.c:5329 EVENT BROADCAST presence.1000@tekart.dayo.com.ng {
"data": {
"channelCallState": "EARLY",
"originalChannelCallState": "RINGING",
"channelState": "CS_EXECUTE",
"callerUserName": "1000",
"callerIDName": "1000",
"callerIDNumber": "1000",
"channelUUID": "cd187882-801d-45e0-b9b6-6065e09debb8",
"presenceCallDirection": "inbound",
"channelPresenceID": "1000@tekart.dayo.com.ng"
},
"eventChannel": "presence.1000@tekart.dayo.com.ng"
}
2018-08-30 10:00:28.454089 [ALERT] mod_verto.c:604 WRITE 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"id": 13,
"method": "verto.invite",
"params": {
"callID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"sdp": "v=0\r\no=FreeSWITCH 1535593920 1535593921 IN IP4 $${local_ip_v4}\r\ns=FreeSWITCH\r\nc=IN IP4 $${local_ip_v4}\r\nt=0 0\r\na=msid-semantic: WMS ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN\r\nm=audio 29308 RTP/SAVPF 9 8 102 0 103\r\na=rtpmap:9 G722/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:102 opus/48000/2\r\na=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:103 opus/48000/2\r\na=fmtp:103 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40\r\na=fingerprint:sha-256 6F:3C:B0:AA:DD:12:17:A7:F0:26:56:8C:5F:B2:F5:A1:DF:2A:0B:87:EF:F6:07:14:53:DB:A4:F8:81:01:D2:5F\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:29308 IN IP4 $${local_ip_v4}\r\na=ssrc:463787340 cname:7dtvIsRBJb2AlD8p\r\na=ssrc:463787340 msid:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN a0\r\na=ssrc:463787340 mslabel:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN\r\na=ssrc:463787340 label:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrNa0\r\na=ice-ufrag:PnR7zzOrg4NFG4iE\r\na=ice-pwd:8C0HUH8uJ1UVuTaa6S8whMOo\r\na=candidate:7096455128 1 udp 659136 $${local_ip_v4} 29308 typ host generation 0\r\na=candidate:7096455128 2 udp 659136 $${local_ip_v4} 29308 typ host generation 0\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\nm=video 29310 RTP/SAVPF 104\r\nb=AS:1024\r\na=rtpmap:104 VP8/90000\r\na=fingerprint:sha-256 6F:3C:B0:AA:DD:12:17:A7:F0:26:56:8C:5F:B2:F5:A1:DF:2A:0B:87:EF:F6:07:14:53:DB:A4:F8:81:01:D2:5F\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:29310 IN IP4 $${local_ip_v4}\r\na=rtcp-fb:104 ccm fir\r\na=rtcp-fb:104 ccm tmmbr\r\na=rtcp-fb:104 nack\r\na=rtcp-fb:104 nack pli\r\na=ssrc:3990963918 cname:7dtvIsRBJb2AlD8p\r\na=ssrc:3990963918 msid:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN v0\r\na=ssrc:3990963918 mslabel:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrN\r\na=ssrc:3990963918 label:ovVQxF8w2ruB0jKIdmpCslRQ2RpvyMrNv0\r\na=ice-ufrag:xbhifuaNFvcnA94Z\r\na=ice-pwd:GD9Yw1gpQhh2qLSON0WSkXwP\r\na=candidate:7628899082 1 udp 659136 $${local_ip_v4} 29310 typ host generation 0\r\na=candidate:7628899082 2 udp 659135 $${local_ip_v4} 29310 typ host generation 0\r\na=end-of-candidates\r\n",
"caller_id_name": "1000",
"caller_id_number": "1000",
"callee_id_name": "Dayo",
"callee_id_number": "1010",
"display_direction": "outbound"
}
}]
2018-08-30 10:00:28.664107 [ALERT] mod_verto.c:1384 READ 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"id": 13,
"result": {
"method": "verto.invite"
}
}]
2018-08-30 10:00:28.944151 [INFO] switch_rtp.c:7268 Auto Changing audio port from 192.168.43.205:50648 to 197.210.173.34:50648
2018-08-30 10:00:34.464282 [WARNING] switch_core_state_machine.c:687 93011244-be51-4d46-9bb4-5360f3d7c251 sofia/internal/301@139.162.188.90 Abandoned
2018-08-30 10:00:34.464282 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/301@139.162.188.90 [CS_NEW] [WRONG_CALL_STATE]
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/301@139.162.188.90) Running State Change CS_HANGUP (Cur 3 Tot 1933)
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/301@139.162.188.90) Callstate Change DOWN -> HANGUP
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/301@139.162.188.90) State HANGUP
2018-08-30 10:00:34.464282 [DEBUG] mod_sofia.c:438 Channel sofia/internal/301@139.162.188.90 hanging up, cause: WRONG_CALL_STATE
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:60 sofia/internal/301@139.162.188.90 Standard HANGUP, cause: WRONG_CALL_STATE
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/301@139.162.188.90) State HANGUP going to sleep
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/301@139.162.188.90) State Change CS_HANGUP -> CS_REPORTING
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/301@139.162.188.90) Running State Change CS_REPORTING (Cur 3 Tot 1933)
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/301@139.162.188.90) State REPORTING
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:174 sofia/internal/301@139.162.188.90 Standard REPORTING, cause: WRONG_CALL_STATE
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/301@139.162.188.90) State REPORTING going to sleep
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/301@139.162.188.90) State Change CS_REPORTING -> CS_DESTROY
2018-08-30 10:00:34.464282 [DEBUG] switch_core_session.c:1665 Session 1931 (sofia/internal/301@139.162.188.90) Locked, Waiting on external entities
2018-08-30 10:00:34.464282 [NOTICE] switch_core_session.c:1683 Session 1931 (sofia/internal/301@139.162.188.90) Ended
2018-08-30 10:00:34.464282 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/301@139.162.188.90 [CS_DESTROY]
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/301@139.162.188.90) Running State Change CS_DESTROY (Cur 2 Tot 1933)
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/301@139.162.188.90) State DESTROY
2018-08-30 10:00:34.464282 [DEBUG] mod_sofia.c:343 sofia/internal/301@139.162.188.90 SOFIA DESTROY
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:181 sofia/internal/301@139.162.188.90 Standard DESTROY
2018-08-30 10:00:34.464282 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/301@139.162.188.90) State DESTROY going to sleep
2018-08-30 10:00:36.974158 [ALERT] mod_verto.c:1384 READ 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"method": "verto.answer",
"params": {
"sdp": "v=0\r\no=- 6623213443728101624 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=msid-semantic: WMS agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo\r\nm=audio 9 RTP/SAVPF 9 8 102 0\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:8Kjv\r\na=ice-pwd:HX0GfWf+boz0NiBE3bLyH5fb\r\na=ice-options:trickle\r\na=fingerprint:sha-256 AC:E9:80:1B:C6:F6:22:4B:08:FE:0D:7C:49:4E:DB:56:C0:FF:48:3B:15:32:3C:73:D7:B7:89:19:A9:12:15:E5\r\na=setup:active\r\na=mid:audio\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:9 G722/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:102 opus/48000/2\r\na=fmtp:102 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1\r\na=rtpmap:0 PCMU/8000\r\na=ssrc:2262968536 cname:Yiz8JWeDWN9phn7e\r\na=ssrc:2262968536 msid:agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo af3cca82-c6a5-45ce-b586-090f10d11034\r\na=ssrc:2262968536 mslabel:agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo\r\na=ssrc:2262968536 label:af3cca82-c6a5-45ce-b586-090f10d11034\r\nm=video 9 RTP/SAVPF 104\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:csHP\r\na=ice-pwd:cURMSx0Q/1hMZFs6vZcCGqnU\r\na=ice-options:trickle\r\na=fingerprint:sha-256 AC:E9:80:1B:C6:F6:22:4B:08:FE:0D:7C:49:4E:DB:56:C0:FF:48:3B:15:32:3C:73:D7:B7:89:19:A9:12:15:E5\r\na=setup:active\r\na=mid:video\r\na=recvonly\r\na=rtcp-mux\r\na=rtpmap:104 VP8/90000\r\na=rtcp-fb:104 ccm fir\r\na=rtcp-fb:104 nack\r\na=rtcp-fb:104 nack pli\r\n",
"dialogParams": {
"useStereo": true,
"screenShare": false,
"useCamera": "none",
"useMic": "default",
"useSpeak": "default",
"tag": "webcam",
"localTag": null,
"login": "1010@tekart.dayo.com.ng",
"videoParams": {
"minWidth": 160,
"minHeight": 120,
"maxWidth": 160,
"maxHeight": 120,
"minFrameRate": 15
},
"callID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"caller_id_name": "1000",
"caller_id_number": "1000",
"callee_id_name": "Dayo",
"callee_id_number": "1010",
"display_direction": "outbound",
"wantVideo": true,
"remote_caller_id_name": "1000",
"remote_caller_id_number": "1000"
},
"sessid": "d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071"
},
"id": 29
}]
2018-08-30 10:00:36.974158 [DEBUG] mod_verto.c:2689 Remote SDP verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071:
v=0
o=- 6623213443728101624 2 IN IP4 127.0.0.1
s=-
t=0 0
a=msid-semantic: WMS agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo
m=audio 9 RTP/SAVPF 9 8 102 0
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:8Kjv
a=ice-pwd:HX0GfWf+boz0NiBE3bLyH5fb
a=ice-options:trickle
a=fingerprint:sha-256 AC:E9:80:1B:C6:F6:22:4B:08:FE:0D:7C:49:4E:DB:56:C0:FF:48:3B:15:32:3C:73:D7:B7:89:19:A9:12:15:E5
a=setup:active
a=mid:audio
a=sendrecv
a=rtcp-mux
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1
a=rtpmap:0 PCMU/8000
a=ssrc:2262968536 cname:Yiz8JWeDWN9phn7e
a=ssrc:2262968536 msid:agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo af3cca82-c6a5-45ce-b586-090f10d11034
a=ssrc:2262968536 mslabel:agPMoxGKUmKC2r1CWvzGeIMtHLwWNWPBklXo
a=ssrc:2262968536 label:af3cca82-c6a5-45ce-b586-090f10d11034
m=video 9 RTP/SAVPF 104
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:csHP
a=ice-pwd:cURMSx0Q/1hMZFs6vZcCGqnU
a=ice-options:trickle
a=fingerprint:sha-256 AC:E9:80:1B:C6:F6:22:4B:08:FE:0D:7C:49:4E:DB:56:C0:FF:48:3B:15:32:3C:73:D7:B7:89:19:A9:12:15:E5
a=setup:active
a=mid:video
a=recvonly
a=rtcp-mux
a=rtpmap:104 VP8/90000
a=rtcp-fb:104 ccm fir
a=rtcp-fb:104 nack
a=rtcp-fb:104 nack pli
2018-08-30 10:00:36.974158 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
'Event-Name: REQUEST_PARAMS
Core-UUID: f339f992-3aa5-448d-8aca-5fd7e6c3b677
FreeSWITCH-Hostname: test-fs-001
FreeSWITCH-Switchname: test-fs-001
FreeSWITCH-IPv4: 139.162.188.90
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2018-08-30%2010%3A00%3A36
Event-Date-GMT: Thu,%2030%20Aug%202018%2010%3A00%3A36%20GMT
Event-Date-Timestamp: 1535623236974158
Event-Calling-File: switch_xml.c
Event-Calling-Function: switch_xml_locate_user
Event-Calling-Line-Number: 2109
Event-Sequence: 28383
key: id
user: 1010
domain: tekart.dayo.com.ng
'
2018-08-30 10:00:36.974158 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: directory
2018-08-30 10:00:36.974158 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name: domain
2018-08-30 10:00:36.974158 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name: name
2018-08-30 10:00:36.974158 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value: tekart.dayo.com.ng
2018-08-30 10:00:37.594155 [NOTICE] switch_cpp.cpp:1365 [xml]:
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:102:48000:20:0:2]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:2]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3061 Set Codec verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-30 10:00:37.594155 [DEBUG] switch_core_codec.c:111 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 Original read codec set to G722:9
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3523 Searching for rtp candidate.
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3523 Searching for rtcp candidate.
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3567 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 no suitable candidates found.
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4774 No 2833 in SDP. Disable 2833 dtmf and switch to INFO
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4950 Video Codec Compare [VP8:104]/[VP8:99]
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:4982 Video Codec Compare [VP8:104] +++ is saved as a match
2018-08-30 10:00:37.594155 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-08-30 10:00:37.594155 [DEBUG] switch_vpx.c:631 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:2871 Set VIDEO Codec verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 VP8/90000 0 ms
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3523 Searching for rtp candidate.
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3523 Searching for rtcp candidate.
2018-08-30 10:00:37.594155 [DEBUG] switch_core_media.c:3567 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 no suitable candidates found.
2018-08-30 10:00:37.594155 [ALERT] mod_verto.c:604 WRITE 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"id": 29,
"error": {
"message": "CODEC ERROR",
"code": -32002
}
}]
2018-08-30 10:00:37.784119 [ALERT] mod_verto.c:1384 READ 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"method": "verto.bye",
"params": {
"dialogParams": {
"useStereo": true,
"screenShare": false,
"useCamera": "none",
"useMic": "default",
"useSpeak": "default",
"tag": "webcam",
"localTag": null,
"login": "1010@tekart.dayo.com.ng",
"videoParams": {
"minWidth": 160,
"minHeight": 120,
"maxWidth": 160,
"maxHeight": 120,
"minFrameRate": 15
},
"callID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"caller_id_name": "1000",
"caller_id_number": "1000",
"callee_id_name": "Dayo",
"callee_id_number": "1010",
"display_direction": "outbound",
"wantVideo": true,
"remote_caller_id_name": "1000",
"remote_caller_id_number": "1000"
},
"sessid": "d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071"
},
"id": 30
}]
2018-08-30 10:00:37.784119 [NOTICE] mod_verto.c:2785 Hangup verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
2018-08-30 10:00:37.794091 [ALERT] mod_verto.c:604 WRITE 197.210.65.10:63551 [{
"jsonrpc": "2.0",
"id": 30,
"result": {
"callID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"message": "CALL ENDED",
"causeCode": 16,
"cause": "NORMAL_CLEARING",
"sessid": "d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071"
}
}]
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_HANGUP (Cur 2 Tot 1933)
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Callstate Change RINGING -> HANGUP
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State HANGUP
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:60 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 Standard HANGUP, cause: NORMAL_CLEARING
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State HANGUP going to sleep
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State Change CS_HANGUP -> CS_REPORTING
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_REPORTING (Cur 2 Tot 1933)
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State REPORTING
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:174 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 Standard REPORTING, cause: NORMAL_CLEARING
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State REPORTING going to sleep
2018-08-30 10:00:37.794091 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State Change CS_REPORTING -> CS_DESTROY
2018-08-30 10:00:37.794091 [DEBUG] switch_core_session.c:1665 Session 1933 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Locked, Waiting on external entities
2018-08-30 10:00:37.794091 [ALERT] mod_verto.c:5329 EVENT BROADCAST presence.1010@tekart.dayo.com.ng {
"data": {
"channelCallState": "HANGUP",
"originalChannelCallState": "RINGING",
"channelState": "CS_HANGUP",
"callerUserName": "1000",
"callerIDName": "1000",
"callerIDNumber": "1000",
"calleeIDName": "Dayo",
"calleeIDNumber": "1010",
"channelUUID": "41f39aee-4cfc-4782-be62-546edc3cef7c",
"presenceCallDirection": "outbound",
"channelPresenceID": "1010@tekart.dayo.com.ng"
},
"eventChannel": "presence.1010@tekart.dayo.com.ng"
}
2018-08-30 10:00:37.804098 [DEBUG] switch_core_codec.c:248 sofia/internal/1000@tekart.dayo.com.ng Restore previous codec G722:9.
2018-08-30 10:00:37.804098 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
2018-08-30 10:00:37.804098 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [NORMAL_CLEARING]
2018-08-30 10:00:37.804098 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
2018-08-30 10:00:37.804098 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_CLEARING
2018-08-30 10:00:37.804098 [NOTICE] switch_channel.c:4844 Hangup sofia/internal/1000@tekart.dayo.com.ng [CS_EXECUTE] [NORMAL_CLEARING]
2018-08-30 10:00:37.804098 [DEBUG] switch_core_session.c:2815 sofia/internal/1000@tekart.dayo.com.ng skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@tekart.dayo.com.ng) State EXECUTE going to sleep
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_HANGUP (Cur 2 Tot 1933)
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@tekart.dayo.com.ng) Callstate Change EARLY -> HANGUP
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@tekart.dayo.com.ng) State HANGUP
2018-08-30 10:00:37.804098 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1000@tekart.dayo.com.ng hanging up, cause: NORMAL_CLEARING
2018-08-30 10:00:37.804098 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@tekart.dayo.com.ng Standard HANGUP, cause: NORMAL_CLEARING
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@tekart.dayo.com.ng) State HANGUP going to sleep
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@tekart.dayo.com.ng) State Change CS_HANGUP -> CS_REPORTING
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_REPORTING (Cur 2 Tot 1933)
2018-08-30 10:00:37.804098 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@tekart.dayo.com.ng) State REPORTING
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@tekart.dayo.com.ng Standard REPORTING, cause: NORMAL_CLEARING
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@tekart.dayo.com.ng) State REPORTING going to sleep
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@tekart.dayo.com.ng) State Change CS_REPORTING -> CS_DESTROY
2018-08-30 10:00:37.814097 [DEBUG] switch_core_session.c:1665 Session 1932 (sofia/internal/1000@tekart.dayo.com.ng) Locked, Waiting on external entities
2018-08-30 10:00:37.814097 [NOTICE] switch_core_session.c:1683 Session 1932 (sofia/internal/1000@tekart.dayo.com.ng) Ended
2018-08-30 10:00:37.814097 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1000@tekart.dayo.com.ng [CS_DESTROY]
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@tekart.dayo.com.ng) Running State Change CS_DESTROY (Cur 1 Tot 1933)
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@tekart.dayo.com.ng) State DESTROY
2018-08-30 10:00:37.814097 [DEBUG] mod_sofia.c:343 sofia/internal/1000@tekart.dayo.com.ng SOFIA DESTROY
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@tekart.dayo.com.ng Standard DESTROY
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@tekart.dayo.com.ng) State DESTROY going to sleep
2018-08-30 10:00:37.814097 [NOTICE] switch_core_session.c:1683 Session 1933 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Ended
2018-08-30 10:00:37.814097 [NOTICE] switch_core_session.c:1687 Close Channel verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 [CS_DESTROY]
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) Running State Change CS_DESTROY (Cur 0 Tot 1933)
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State DESTROY
2018-08-30 10:00:37.814097 [DEBUG] mod_rtc.c:132 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 RTC DESTROY
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:181 verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071 Standard DESTROY
2018-08-30 10:00:37.814097 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/d620b6c4-56d7-6dfd-b19f-f6d3dbd9f071) State DESTROY going to sleep
2018-08-30 10:00:37.814097 [ALERT] mod_verto.c:5329 EVENT BROADCAST presence.1000@tekart.dayo.com.ng {
"data": {
"channelCallState": "HANGUP",
"originalChannelCallState": "EARLY",
"channelState": "CS_HANGUP",
"callerUserName": "1000",
"callerIDName": "1000",
"callerIDNumber": "1000",
"channelUUID": "cd187882-801d-45e0-b9b6-6065e09debb8",
"presenceCallDirection": "inbound",
"channelPresenceID": "1000@tekart.dayo.com.ng"
},
"eventChannel": "presence.1000@tekart.dayo.com.ng"
}