2018-12-10 13:16:26.173249 [DEBUG] sofia.c:10044 IP 117.247.91.162 Rejected by acl "default". Falling back to Digest auth. 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [received][100] 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=7661455301 8001 8000 IN IP4 117.247.91.162 s=SIP Call c=IN IP4 117.247.91.162 t=0 0 m=audio 5008 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/7661455301@fs.beconnected.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels 2018-12-10 13:16:26.173249 [DEBUG] switch_core_codec.c:111 sofia/default/7661455301@fs.beconnected.co.za Original read codec set to G729:18 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4767 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101 recv payload to 101 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7507 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_NEW -> CS_INIT 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_INIT (Cur 2 Tot 7797) 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7661455301@fs.beconnected.co.za) State INIT 2018-12-10 13:16:26.173249 [DEBUG] mod_sofia.c:90 sofia/default/7661455301@fs.beconnected.co.za SOFIA INIT 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:40 sofia/default/7661455301@fs.beconnected.co.za Standard INIT 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_INIT -> CS_ROUTING 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7661455301@fs.beconnected.co.za) State INIT going to sleep 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_ROUTING (Cur 2 Tot 7797) 2018-12-10 13:16:26.173249 [DEBUG] switch_channel.c:2249 (sofia/default/7661455301@fs.beconnected.co.za) Callstate Change DOWN -> RINGING 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7661455301@fs.beconnected.co.za) State ROUTING 2018-12-10 13:16:26.173249 [DEBUG] mod_sofia.c:143 sofia/default/7661455301@fs.beconnected.co.za SOFIA ROUTING 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:236 sofia/default/7661455301@fs.beconnected.co.za Standard ROUTING 2018-12-10 13:16:26.173249 [INFO] mod_dialplan_xml.c:637 Processing 7661455301 <7661455301>->6835959900 in context default 2018-12-10 13:16:26.173249 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f83143cc970 Connected. 2018-12-10 13:16:26.173249 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard') 2018-12-10 13:16:26.193199 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [xml_handler] Params: 'Event-Name: REQUEST_PARAMS Core-UUID: ce67deb0-ce57-4faa-b8de-66c407c6216d FreeSWITCH-Hostname: fs FreeSWITCH-Switchname: fs FreeSWITCH-IPv4: 169.255.171.130 FreeSWITCH-IPv6: %3A%3A1 Event-Date-Local: 2018-12-10%2013%3A16%3A26 Event-Date-GMT: Mon,%2010%20Dec%202018%2011%3A16%3A26%20GMT Event-Date-Timestamp: 1544440586173249 Event-Calling-File: mod_dialplan_xml.c Event-Calling-Function: dialplan_xml_locate Event-Calling-Line-Number: 608 Event-Sequence: 131020 Channel-State: CS_ROUTING Channel-Call-State: RINGING Channel-State-Number: 2 Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765 Call-Direction: inbound Presence-Call-Direction: inbound Channel-HIT-Dialplan: true Channel-Presence-ID: 7661455301%40fs.beconnected.co.za Channel-Call-UUID: ffa90ab3-4098-4b77-a0e9-662d212b2765 Answer-State: ringing Channel-Read-Codec-Name: G729 Channel-Read-Codec-Rate: 8000 Channel-Read-Codec-Bit-Rate: 8000 Channel-Write-Codec-Name: G729 Channel-Write-Codec-Rate: 8000 Channel-Write-Codec-Bit-Rate: 8000 Caller-Direction: inbound Caller-Logical-Direction: inbound Caller-Username: 7661455301 Caller-Dialplan: XML Caller-Caller-ID-Name: 7661455301 Caller-Caller-ID-Number: 7661455301 Caller-Orig-Caller-ID-Name: 7661455301 Caller-Orig-Caller-ID-Number: 7661455301 Caller-Network-Addr: 117.247.91.162 Caller-ANI: 7661455301 Caller-Destination-Number: 6835959900 Caller-Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765 Caller-Source: mod_sofia Caller-Context: default Caller-Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za Caller-Profile-Index: 1 Caller-Profile-Created-Time: 1544440586173249 Caller-Channel-Created-Time: 1544440586173249 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: ffa90ab3-4098-4b77-a0e9-662d212b2765 variable_session_id: 7796 variable_sip_from_user: 7661455301 variable_sip_from_uri: 7661455301%40fs.beconnected.co.za variable_sip_from_host: fs.beconnected.co.za variable_video_media_flow: sendrecv variable_channel_name: sofia/default/7661455301%40fs.beconnected.co.za variable_sip_call_id: 1673991354-27987-24%40BJC.BGI.B.BGB variable_ep_codec_string: mod_bcg729.G729%408000h%4020i%408000b variable_sip_local_network_addr: 169.255.171.130 variable_sip_network_ip: 117.247.91.162 variable_sip_network_port: 27987 variable_sip_invite_stamp: 1544440586173249 variable_sip_received_ip: 117.247.91.162 variable_sip_received_port: 27987 variable_sip_via_protocol: udp variable_sip_authorized: true variable_Event-Name: REQUEST_PARAMS variable_Core-UUID: ce67deb0-ce57-4faa-b8de-66c407c6216d variable_FreeSWITCH-Hostname: fs variable_FreeSWITCH-Switchname: fs variable_FreeSWITCH-IPv4: 169.255.171.130 variable_FreeSWITCH-IPv6: %3A%3A1 variable_Event-Date-Local: 2018-12-10%2013%3A16%3A26 variable_Event-Date-GMT: Mon,%2010%20Dec%202018%2011%3A16%3A26%20GMT variable_Event-Date-Timestamp: 1544440586173249 variable_Event-Calling-File: sofia.c variable_Event-Calling-Function: sofia_handle_sip_i_invite variable_Event-Calling-Line-Number: 10096 variable_Event-Sequence: 131011 variable_sip_number_alias: 7661455301 variable_sip_auth_username: 7661455301 variable_sip_auth_realm: fs.beconnected.co.za variable_number_alias: 7661455301 variable_requested_user_name: 7661455301 variable_requested_domain_name: fs.beconnected.co.za variable_effective_caller_id_name: 7661455301 variable_effective_caller_id_number: 12334556 variable_sipcall: true variable_accountcode: 6835959900 variable_user_name: 7661455301 variable_domain_name: fs.beconnected.co.za variable_sip_from_user_stripped: 7661455301 variable_sip_from_tag: 156202635 variable_sofia_profile_name: default variable_recovery_profile_name: default variable_sip_P-Preferred-Identity: %227661455301%22%20%3Csip%3A7661455301%40fs.beconnected.co.za%3E variable_sip_cid_type: pid variable_sip_full_via: SIP/2.0/UDP%20117.247.91.162%3A27987%3Bbranch%3Dz9hG4bK932791135%3Brport%3D27987 variable_sip_from_display: 7661455301 variable_sip_full_from: %227661455301%22%20%3Csip%3A7661455301%40fs.beconnected.co.za%3E%3Btag%3D156202635 variable_sip_full_to: %3Csip%3A6835959900%40fs.beconnected.co.za%3E variable_sip_allow: INVITE,%20ACK,%20OPTIONS,%20CANCEL,%20BYE,%20SUBSCRIBE,%20NOTIFY,%20INFO,%20REFER,%20UPDATE,%20MESSAGE variable_sip_req_user: 6835959900 variable_sip_req_uri: 6835959900%40fs.beconnected.co.za variable_sip_req_host: fs.beconnected.co.za variable_sip_to_user: 6835959900 variable_sip_to_uri: 6835959900%40fs.beconnected.co.za variable_sip_to_host: fs.beconnected.co.za variable_sip_contact_user: 7661455301 variable_sip_contact_port: 27987 variable_sip_contact_uri: 7661455301%40117.247.91.162%3A27987 variable_sip_contact_host: 117.247.91.162 variable_sip_user_agent: Grandstream%20GXP1620%201.0.0.38 variable_sip_via_host: 117.247.91.162 variable_sip_via_port: 27987 variable_sip_via_rport: 27987 variable_max_forwards: 70 variable_presence_id: 7661455301%40fs.beconnected.co.za variable_sip_Privacy: none variable_switch_r_sdp: v%3D0%0D%0Ao%3D7661455301%208001%208000%20IN%20IP4%20117.247.91.162%0D%0As%3DSIP%20Call%0D%0Ac%3DIN%20IP4%20117.247.91.162%0D%0At%3D0%200%0D%0Am%3Daudio%205008%20RTP/AVP%2018%20101%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Dfmtp%3A18%20annexb%3Dno%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0Aa%3Dptime%3A20%0D%0A variable_rtp_use_codec_string: PCMA,PCMU,G729 variable_audio_media_flow: sendrecv variable_remote_media_ip: 117.247.91.162 variable_remote_media_port: 5008 variable_rtp_audio_recv_pt: 18 variable_rtp_use_codec_name: G729 variable_rtp_use_codec_fmtp: annexb%3Dno variable_rtp_use_codec_rate: 8000 variable_rtp_use_codec_ptime: 20 variable_rtp_use_codec_channels: 1 variable_rtp_last_audio_codec_string: G729%408000h%4020i%401c variable_read_codec: G729 variable_original_read_codec: G729 variable_read_rate: 8000 variable_original_read_rate: 8000 variable_write_codec: G729 variable_write_rate: 8000 variable_dtmf_type: rfc2833 variable_endpoint_disposition: RECEIVED variable_call_uuid: ffa90ab3-4098-4b77-a0e9-662d212b2765 Hunt-Direction: inbound Hunt-Logical-Direction: inbound Hunt-Username: 7661455301 Hunt-Dialplan: XML Hunt-Caller-ID-Name: 7661455301 Hunt-Caller-ID-Number: 7661455301 Hunt-Orig-Caller-ID-Name: 7661455301 Hunt-Orig-Caller-ID-Number: 7661455301 Hunt-Network-Addr: 117.247.91.162 Hunt-ANI: 7661455301 Hunt-Destination-Number: 6835959900 Hunt-Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765 Hunt-Source: mod_sofia Hunt-Context: default Hunt-Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za Hunt-Profile-Index: 1 Hunt-Profile-Created-Time: 1544440586173249 Hunt-Channel-Created-Time: 1544440586173249 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-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] section: dialplan 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] tag_name: 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_value: 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_name: 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 6835959900 2018-12-10 13:16:26.193199 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : 7661455301 / 12334556 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="6835959900" LIMIT 1 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="6835959900" limit 1 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : local 2018-12-10 13:16:26.193199 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 6835959900] 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '6835959900' OR routing_prefix = '683595990' OR routing_prefix = '68359599' OR routing_prefix = '6835959' OR routing_prefix = '683595' OR routing_prefix = '68359' OR routing_prefix = '6835' OR routing_prefix = '683' OR routing_prefix = '68' OR routing_prefix = '6' OR routing_prefix ='--') AND status = 0 limit 1 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "6835959900" OR id="6835959900") AND status=0 AND deleted=0 AND (expiry >= '2018-12-10 11:16:26' OR expiry = '0000-00-00 00:00:00') limit 1 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CALLERID_NUMBER] CALLERID :12334556 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CUSTOMER_ID] USERID :63 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CIDPOOL] CIDPOOL :0 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns = '^6835959900.*' OR patterns = '^683595990.*' OR patterns = '^68359599.*' OR patterns = '^6835959.*' OR patterns = '^683595.*' OR patterns = '^68359.*' OR patterns = '^6835.*' OR patterns = '^683.*' OR patterns = '^68.*' OR patterns = '^6.*' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information =================== 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 63 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 6835959900 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid] 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] ======================================================== 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="6835959900" limit 1 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = 6835959900 and status=0 LIMIT 1 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [fifo_agent_flag] fifo_agent_flag0 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET multidomain] Query :SELECT * FROM multidomain WHERE accountid = 63 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domainfs.beconnected.co.za 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Starts 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Ends 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] SIP ID : 127 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 127 limit 1 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] SIP Call forwarding Disable 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
2018-12-10 13:16:26.213193 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f83143cc970 released. Dialplan: sofia/default/7661455301@fs.beconnected.co.za parsing [default->6835959900] continue=false Dialplan: sofia/default/7661455301@fs.beconnected.co.za Regex (PASS) [6835959900] destination_number(6835959900) =~ /6835959900/ break=on-false Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_destination_number=6835959900) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action sched_hangup(+6000 normal_clearing) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(callstart=2018-12-10 11:16:26) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(hangup_after_bridge=true) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(continue_on_fail=TRUE) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(account_id=63) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(parent_id=0) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(entity_id=0) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(call_processed=internal) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(call_direction=local) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(accountname=default) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(origination_rates=ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(original_caller_id_name=7661455301) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(original_caller_id_number=12334556) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_caller_id_name=7661455301) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_caller_id_number=12334556) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(calltype=LOCAL) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(receiver_accid=63) Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action bridge([leg_timeout=30]user/6835959900@fs.beconnected.co.za) |--- Dialplan: Processing recursive conditions level:1 [6835959900_recur_1] require-nested=TRUE |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Regex (PASS) [6835959900_recur_1] ${cond(${user_data 6835959900@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action answer() |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action export(voicemail_alternate_greet_id=6835959900) |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action voicemail(default $${domain_name} 6835959900) 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:286 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_ROUTING -> CS_EXECUTE 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7661455301@fs.beconnected.co.za) State ROUTING going to sleep 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_EXECUTE (Cur 2 Tot 7797) 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7661455301@fs.beconnected.co.za) State EXECUTE 2018-12-10 13:16:26.213193 [DEBUG] mod_sofia.c:198 sofia/default/7661455301@fs.beconnected.co.za SOFIA EXECUTE 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:328 sofia/default/7661455301@fs.beconnected.co.za Standard EXECUTE EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_destination_number=6835959900) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_destination_number]=[6835959900] EXECUTE sofia/default/7661455301@fs.beconnected.co.za sched_hangup(+6000 normal_clearing) 2018-12-10 13:16:26.213193 [DEBUG] switch_scheduler.c:249 Added task 158 switch_ivr_schedule_hangup (ffa90ab3-4098-4b77-a0e9-662d212b2765) to run at 1544446586 EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(callstart=2018-12-10 11:16:26) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [callstart]=[2018-12-10 11:16:26] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(hangup_after_bridge=true) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [hangup_after_bridge]=[true] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(continue_on_fail=TRUE) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [continue_on_fail]=[TRUE] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(account_id=63) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [account_id]=[63] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(parent_id=0) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [parent_id]=[0] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(entity_id=0) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [entity_id]=[0] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(call_processed=internal) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [call_processed]=[internal] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(call_direction=local) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [call_direction]=[local] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(accountname=default) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [accountname]=[default] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(origination_rates=ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [origination_rates]=[ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(original_caller_id_name=7661455301) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [original_caller_id_name]=[7661455301] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(original_caller_id_number=12334556) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [original_caller_id_number]=[12334556] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_caller_id_name=7661455301) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_caller_id_name]=[7661455301] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_caller_id_number=12334556) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_caller_id_number]=[12334556] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(calltype=LOCAL) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [calltype]=[LOCAL] EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(receiver_accid=63) 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [receiver_accid]=[63] EXECUTE sofia/default/7661455301@fs.beconnected.co.za bridge([leg_timeout=30]user/6835959900@fs.beconnected.co.za) 2018-12-10 13:16:26.213193 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-12-10 13:16:26.213193 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-12-10 13:16:26.233192 [NOTICE] switch_channel.c:1104 New Channel sofia/default/6835959900@117.247.91.162:5060 [806f29a9-ef75-424a-bb7a-e8cb4155ffa0] 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:4819 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_NEW -> CS_INIT 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:2963 sofia/default/6835959900@117.247.91.162:5060 Setting leg timeout to 30 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_INIT (Cur 3 Tot 7798) 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:627 (sofia/default/6835959900@117.247.91.162:5060) State INIT 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:90 sofia/default/6835959900@117.247.91.162:5060 SOFIA INIT 2018-12-10 13:16:26.233192 [DEBUG] sofia_glue.c:1295 sofia/default/6835959900@117.247.91.162:5060 sending invite version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit Local SDP: v=0 o=FreeSWITCH 1544429808 1544429809 IN IP4 169.255.171.130 s=FreeSWITCH c=IN IP4 169.255.171.130 t=0 0 m=audio 10778 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:40 sofia/default/6835959900@117.247.91.162:5060 Standard INIT 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:48 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_INIT -> CS_ROUTING 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:627 (sofia/default/6835959900@117.247.91.162:5060) State INIT going to sleep 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_ROUTING (Cur 3 Tot 7798) 2018-12-10 13:16:26.233192 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [calling][0] 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:643 (sofia/default/6835959900@117.247.91.162:5060) State ROUTING 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:143 sofia/default/6835959900@117.247.91.162:5060 SOFIA ROUTING 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:67 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:643 (sofia/default/6835959900@117.247.91.162:5060) State ROUTING going to sleep 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 7798) 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:662 (sofia/default/6835959900@117.247.91.162:5060) State CONSUME_MEDIA 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:662 (sofia/default/6835959900@117.247.91.162:5060) State CONSUME_MEDIA going to sleep 2018-12-10 13:16:26.873246 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [proceeding][180] 2018-12-10 13:16:26.873246 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/6835959900@117.247.91.162:5060! 2018-12-10 13:16:26.873246 [DEBUG] switch_channel.c:3346 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change DOWN -> RINGING 2018-12-10 13:16:26.893191 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/7661455301@fs.beconnected.co.za! 2018-12-10 13:16:26.893191 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [early][180] 2018-12-10 13:16:26.893191 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/7661455301@fs.beconnected.co.za! 2018-12-10 13:16:28.253249 [NOTICE] switch_channel.c:1104 New Channel sofia/default/5081@169.255.171.130 [1534e618-fd5f-4149-92b0-265d35812406] 2018-12-10 13:16:28.253249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/5081@169.255.171.130) Running State Change CS_NEW (Cur 4 Tot 7799) 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:9873 sofia/default/5081@169.255.171.130 receiving invite from 37.49.231.120:62181 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:10044 IP 37.49.231.120 Rejected by acl "default". Falling back to Digest auth. 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:2334 detaching session 1534e618-fd5f-4149-92b0-265d35812406 2018-12-10 13:16:28.253249 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [0048221284837@169.255.171.130] from ip 37.49.231.120 2018-12-10 13:16:28.253249 [DEBUG] switch_core_state_machine.c:603 (sofia/default/5081@169.255.171.130) State NEW 2018-12-10 13:16:28.493218 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [completing][200] 2018-12-10 13:16:28.493218 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=root 1509274545 1509274545 IN IP4 117.247.91.162 s=Asterisk PBX 1.6.2.13 c=IN IP4 117.247.91.162 t=0 0 m=audio 10002 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 2018-12-10 13:16:28.513263 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [ready][200] 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/6835959900@117.247.91.162:5060 G729/8000 20 ms 160 samples 8000 bits 1 channels 2018-12-10 13:16:28.513263 [DEBUG] switch_core_codec.c:111 sofia/default/6835959900@117.247.91.162:5060 Original read codec set to G729:18 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4767 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf send payload to 101 recv payload to 101 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/6835959900@117.247.91.162:5060] 169.255.171.130 port 10778 -> 117.247.91.162 port 10002 codec: 18 ms: 20 2018-12-10 13:16:28.513263 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7179 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf send payload to 101 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7186 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf receive payload to 101 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7209 sofia/default/6835959900@117.247.91.162:5060 Set rtp dtmf delay to 40 2018-12-10 13:16:28.513263 [NOTICE] sofia.c:8218 Channel [sofia/default/6835959900@117.247.91.162:5060] has been answered 2018-12-10 13:16:28.513263 [DEBUG] switch_channel.c:3773 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change RINGING -> ACTIVE 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/7661455301@fs.beconnected.co.za] 169.255.171.130 port 18968 -> 117.247.91.162 port 5008 codec: 18 ms: 20 2018-12-10 13:16:28.533213 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7179 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7186 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf receive payload to 101 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7209 sofia/default/7661455301@fs.beconnected.co.za Set rtp dtmf delay to 40 2018-12-10 13:16:28.533213 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/7661455301@fs.beconnected.co.za: v=0 o=FreeSWITCH 1544421620 1544421621 IN IP4 169.255.171.130 s=FreeSWITCH c=IN IP4 169.255.171.130 t=0 0 m=audio 18968 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-12-10 13:16:28.533213 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [completed][200] 2018-12-10 13:16:28.533213 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/default/7661455301@fs.beconnected.co.za] has been answered 2018-12-10 13:16:28.533213 [DEBUG] switch_channel.c:3773 (sofia/default/7661455301@fs.beconnected.co.za) Callstate Change RINGING -> ACTIVE 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/6835959900@117.247.91.162:5060] 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:2963 sofia/default/6835959900@117.247.91.162:5060 Setting leg timeout to 30 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/6835959900@117.247.91.162:5060] 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-12-10 13:16:28.533213 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 7799) 2018-12-10 13:16:28.533213 [DEBUG] switch_core_state_machine.c:653 (sofia/default/6835959900@117.247.91.162:5060) State EXCHANGE_MEDIA 2018-12-10 13:16:28.533213 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA 2018-12-10 13:16:28.593211 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-12-10 13:16:28.773213 [WARNING] switch_core_media.c:2480 [CBR]: Asynchronous PTIME not supported, changing our end from 20 to 30 2018-12-10 13:16:28.773213 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [ready][200] 2018-12-10 13:16:28.793215 [DEBUG] switch_core_media.c:2959 Changing Codec from G729@20ms@8000hz to G729@30ms@8000hz 2018-12-10 13:16:28.793215 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [calling][0] 2018-12-10 13:16:28.833250 [DEBUG] switch_rtp.c:3986 RE-Starting timer [soft] 240 bytes per 30ms 2018-12-10 13:16:28.833250 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/6835959900@117.247.91.162:5060 G729/8000 30 ms 240 samples 8000 bits 1 channels 2018-12-10 13:16:28.833250 [DEBUG] switch_core_codec.c:123 sofia/default/6835959900@117.247.91.162:5060 Original read codec replaced with G729:18 2018-12-10 13:16:28.893208 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 320 bytes to accommodate 480->320 2018-12-10 13:16:29.013247 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-12-10 13:16:29.013247 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 480 bytes to accommodate 320->480 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [ready][200] 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=7661455301 8001 8001 IN IP4 117.247.91.162 s=SIP Call c=IN IP4 117.247.91.162 t=0 0 m=audio 5008 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4767 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101 recv payload to 101 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:8061 Processing updated SDP 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7661455301@fs.beconnected.co.za. 2018-12-10 13:16:32.253222 [NOTICE] switch_channel.c:1104 New Channel sofia/default/36005@169.255.171.130 [7f5a9ac0-623d-4f34-b914-be8b38416c12] 2018-12-10 13:16:32.253222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/36005@169.255.171.130) Running State Change CS_NEW (Cur 5 Tot 7800) 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:9873 sofia/default/36005@169.255.171.130 receiving invite from 158.69.126.203:51535 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:10044 IP 158.69.126.203 Rejected by acl "default". Falling back to Digest auth. 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:2334 detaching session 7f5a9ac0-623d-4f34-b914-be8b38416c12 2018-12-10 13:16:32.253222 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [900441492550028@169.255.171.130] from ip 158.69.126.203 2018-12-10 13:16:32.253222 [DEBUG] switch_core_state_machine.c:603 (sofia/default/36005@169.255.171.130) State NEW 2018-12-10 13:16:32.393220 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7222@169.255.171.130] from ip 46.166.151.168 2018-12-10 13:16:32.573247 [WARNING] sofia_reg.c:2906 Can't find user [7222@169.255.171.130] from 46.166.151.168 You must define a domain called '169.255.171.130' in your directory and add a user with the id="7222" attribute and you must configure your device to use the proper domain in it's authentication credentials. 2018-12-10 13:16:32.573247 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [7222@169.255.171.130] from ip 46.166.151.168 2018-12-10 13:16:33.273217 [NOTICE] switch_channel.c:1104 New Channel sofia/default/980001@169.255.171.130 [e3cb53a1-450d-4e20-82a2-7168186fd9c7] 2018-12-10 13:16:33.273217 [DEBUG] switch_core_state_machine.c:584 (sofia/default/980001@169.255.171.130) Running State Change CS_NEW (Cur 6 Tot 7801) 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:9873 sofia/default/980001@169.255.171.130 receiving invite from 37.49.231.131:53999 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:10044 IP 37.49.231.131 Rejected by acl "default". Falling back to Digest auth. 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:2334 detaching session e3cb53a1-450d-4e20-82a2-7168186fd9c7 2018-12-10 13:16:33.273217 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [000441158220041@169.255.171.130] from ip 37.49.231.131 2018-12-10 13:16:33.273217 [DEBUG] switch_core_state_machine.c:603 (sofia/default/980001@169.255.171.130) State NEW 2018-12-10 13:16:36.153245 [WARNING] switch_core_state_machine.c:687 460d13be-b2d8-4019-9ddb-e0f2f467d304 sofia/default/20001@169.255.171.130 Abandoned 2018-12-10 13:16:36.153245 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/default/20001@169.255.171.130 [CS_NEW] [WRONG_CALL_STATE] 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:584 (sofia/default/20001@169.255.171.130) Running State Change CS_HANGUP (Cur 6 Tot 7801) 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:850 (sofia/default/20001@169.255.171.130) Callstate Change DOWN -> HANGUP 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:852 (sofia/default/20001@169.255.171.130) State HANGUP 2018-12-10 13:16:36.153245 [DEBUG] mod_sofia.c:438 Channel sofia/default/20001@169.255.171.130 hanging up, cause: WRONG_CALL_STATE 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:60 sofia/default/20001@169.255.171.130 Standard HANGUP, cause: WRONG_CALL_STATE 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:852 (sofia/default/20001@169.255.171.130) State HANGUP going to sleep 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:619 (sofia/default/20001@169.255.171.130) State Change CS_HANGUP -> CS_REPORTING 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:584 (sofia/default/20001@169.255.171.130) Running State Change CS_REPORTING (Cur 6 Tot 7801) 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:938 (sofia/default/20001@169.255.171.130) State REPORTING 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:174 sofia/default/20001@169.255.171.130 Standard REPORTING, cause: WRONG_CALL_STATE 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:938 (sofia/default/20001@169.255.171.130) State REPORTING going to sleep 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:610 (sofia/default/20001@169.255.171.130) State Change CS_REPORTING -> CS_DESTROY 2018-12-10 13:16:36.153245 [DEBUG] switch_core_session.c:1665 Session 7797 (sofia/default/20001@169.255.171.130) Locked, Waiting on external entities 2018-12-10 13:16:36.153245 [NOTICE] switch_core_session.c:1683 Session 7797 (sofia/default/20001@169.255.171.130) Ended 2018-12-10 13:16:36.153245 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/20001@169.255.171.130 [CS_DESTROY] 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:741 (sofia/default/20001@169.255.171.130) Running State Change CS_DESTROY (Cur 5 Tot 7801) 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:751 (sofia/default/20001@169.255.171.130) State DESTROY 2018-12-10 13:16:36.153245 [DEBUG] mod_sofia.c:343 sofia/default/20001@169.255.171.130 SOFIA DESTROY 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:181 sofia/default/20001@169.255.171.130 Standard DESTROY 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:751 (sofia/default/20001@169.255.171.130) State DESTROY going to sleep 2018-12-10 13:16:36.293254 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7188363009@169.255.171.130] from ip 41.13.194.12 2018-12-10 13:16:36.333266 [WARNING] sofia_reg.c:2906 Can't find user [7188363009@169.255.171.130] from 41.13.194.12 You must define a domain called '169.255.171.130' in your directory and add a user with the id="7188363009" attribute and you must configure your device to use the proper domain in it's authentication credentials. 2018-12-10 13:16:36.333266 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [7188363009@169.255.171.130] from ip 41.13.194.12 2018-12-10 13:16:37.653222 [NOTICE] sofia.c:1012 Hangup sofia/default/6835959900@117.247.91.162:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/6835959900@117.247.91.162:5060] 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:653 (sofia/default/6835959900@117.247.91.162:5060) State EXCHANGE_MEDIA going to sleep 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_HANGUP (Cur 5 Tot 7801) 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:850 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change ACTIVE -> HANGUP 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:852 (sofia/default/6835959900@117.247.91.162:5060) State HANGUP 2018-12-10 13:16:37.653222 [DEBUG] mod_sofia.c:438 Channel sofia/default/6835959900@117.247.91.162:5060 hanging up, cause: NORMAL_CLEARING 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:60 sofia/default/6835959900@117.247.91.162:5060 Standard HANGUP, cause: NORMAL_CLEARING 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:852 (sofia/default/6835959900@117.247.91.162:5060) State HANGUP going to sleep 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:619 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_HANGUP -> CS_REPORTING 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_REPORTING (Cur 5 Tot 7801) 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:938 (sofia/default/6835959900@117.247.91.162:5060) State REPORTING 2018-12-10 13:16:37.653222 [INFO] mod_json_cdr.c:271 Process [806f29a9-ef75-424a-bb7a-e8cb4155ffa0.cdr.json] 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:706 sofia/default/6835959900@117.247.91.162:5060 ending bridge by request from write function 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/7661455301@fs.beconnected.co.za] 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:1712 sofia/default/6835959900@117.247.91.162:5060 skip receive message [UNBRIDGE] (channel is hungup already)