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" }