SOLVED Busy here

Status
Not open for further replies.
K

krooney

Member
Jun 18, 2018
172
16
18
I have an issue with one DID that if i receive more than 1 call at a time it rings busy. I have near 100 DID's and its the only one causing this issue.
Spoke to provider and they say its not them. I have Main static trunk with 30 channels.if i assign a different DID it works fine on that domain.

SIP2.0 486 Busy here
is the reply.

Please help!
Thanks!
 
  • Like
Reactions: falk
K

krooney

Member
Jun 18, 2018
172
16
18
@JamesBorne

Yes deleted and added back same thing

2019/10/25 16:09:30.775367 209.58.101.236:5060 -> X.X.X.X:5080
SIP/2.0 100 Trying
Via:SIP/2.0/UDP X.X.X.X:5080;branch=z9hG4bK306tj8Qm2QjyD;rport
From:"Lemtel"<sip:514XXXXXXX@X.X.X.X>;tag=7X8NZFX7FX4am
To:<sip:514XXXXXXX@iristel.net>
Call-ID:321be87d-7206-1238-9991-621f5adf6bc3
CSeq:11463293 INVITE
Content-Length:0


2019/10/25 16:09:30.780860 209.58.101.236:5060 -> X.X.X.X:5080
SIP/2.0 486 Busy here
Via:SIP/2.0/UDP X.X.X.X:5080;branch=z9hG4bK306tj8Qm2QjyD;rport
From:"Lemtel"<sip:514XXXXXXX@X.X.X.X>;tag=7X8NZFX7FX4am
To:<sip:514XXXXXXX4@iristel.net>;tag=652521450-1572034170778
Call-ID:321be87d-7206-1238-9991-621f5adf6bc3
CSeq:11463293 INVITE
Allow-Events:bw-call-completion
Content-Length:0


2019/10/25 16:09:30.780964 X.X.X.X:5080 -> 209.58.101.236:5060
ACK sip:514XXXXXXX@iristel.net SIP/2.0
Via: SIP/2.0/UDP X.X.X.X:5080;rport;branch=z9hG4bK306tj8Qm2QjyD
Max-Forwards: 69
From: "Lemtel" <sip:514XXXXXXX@X.X.X.X>;tag=7X8NZFX7FX4am
To: <sip:514XXXXXXX@iristel.net>;tag=652521450-1572034170778
Call-ID: 321be87d-7206-1238-9991-621f5adf6bc3
CSeq: 11463293 ACK
Content-Length: 0
 
J

JamesBorne

Active Member
Jan 24, 2019
294
57
28
Australia
That's not the log.
Find the call in /var/log/freeswitch/freeswitch.log. We need to know why Freeswitch is sending BUSY, not that it is sending busy.
 
K

krooney

Member
Jun 18, 2018
172
16
18
@JamesBorne

2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:40 sofia/external/5147620004 Standard INIT
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:48 (sofia/external/5147620004) State Change CS_INIT -> CS_ROUTING
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:628 (sofia/external/5147620004) State INIT going to sleep
2019-10-29 18:22:37.675409 [DEBUG] switch_ivr_async.c:1636 No silence detection configured; assuming start of speech
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_ROUTING (Cur 5 Tot 6113)
2019-10-29 18:22:37.675409 [DEBUG] sofia.c:7290 Channel sofia/external/5147620004 entering state [calling][0]
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:644 (sofia/external/5147620004) State ROUTING
2019-10-29 18:22:37.675409 [DEBUG] mod_sofia.c:154 sofia/external/5147620004 SOFIA ROUTING
2019-10-29 18:22:37.675409 [DEBUG] switch_ivr_originate.c:67 (sofia/external/5147620004) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:644 (sofia/external/5147620004) State ROUTING going to sleep
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 6113)
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:663 (sofia/external/5147620004) State CONSUME_MEDIA
2019-10-29 18:22:37.675409 [DEBUG] switch_core_state_machine.c:663 (sofia/external/5147620004) State CONSUME_MEDIA going to sleep
2019-10-29 18:22:37.695416 [DEBUG] sofia.c:7290 Channel sofia/external/5147620004 entering state [terminated][486]
2019-10-29 18:22:37.695416 [NOTICE] sofia.c:8523 Hangup sofia/external/5147620004 [CS_CONSUME_MEDIA] [USER_BUSY]
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_HANGUP (Cur 5 Tot 6113)
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:848 (sofia/external/5147620004) Callstate Change DOWN -> HANGUP
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5147620004) State HANGUP
2019-10-29 18:22:37.695416 [DEBUG] mod_sofia.c:460 Channel sofia/external/5147620004 hanging up, cause: USER_BUSY
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:60 sofia/external/5147620004 Standard HANGUP, cause: USER_BUSY
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5147620004) State HANGUP going to sleep
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:620 (sofia/external/5147620004) State Change CS_HANGUP -> CS_REPORTING
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_REPORTING (Cur 5 Tot 6113)
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:936 (sofia/external/5147620004) State REPORTING
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:174 sofia/external/5147620004 Standard REPORTING, cause: USER_BUSY
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:936 (sofia/external/5147620004) State REPORTING going to sleep
2019-10-29 18:22:37.695416 [DEBUG] switch_core_state_machine.c:611 (sofia/external/5147620004) State Change CS_REPORTING -> CS_DESTROY
2019-10-29 18:22:37.695416 [DEBUG] switch_core_session.c:1726 Session 6113 (sofia/external/5147620004) Locked, Waiting on external entities
2019-10-29 18:22:37.715412 [DEBUG] switch_ivr_originate.c:3949 Originate Resulted in Error Cause: 17 [USER_BUSY]
2019-10-29 18:22:37.715412 [NOTICE] switch_core_session.c:1744 Session 6113 (sofia/external/5147620004) Ended
2019-10-29 18:22:37.715412 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/5147620004 [CS_DESTROY]
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:739 (sofia/external/5147620004) Running State Change CS_DESTROY (Cur 4 Tot 6113)
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:749 (sofia/external/5147620004) State DESTROY
2019-10-29 18:22:37.715412 [DEBUG] mod_sofia.c:365 sofia/external/5147620004 SOFIA DESTROY
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:181 sofia/external/5147620004 Standard DESTROY
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:749 (sofia/external/5147620004) State DESTROY going to sleep
2019-10-29 18:22:37.715412 [INFO] mod_dptools.c:3631 Originate Failed. Cause: USER_BUSY
2019-10-29 18:22:37.715412 [NOTICE] switch_core_state_machine.c:386 sofia/internal/275@X.X.X.X has executed the last dialplan instruction, hanging up.
2019-10-29 18:22:37.715412 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/internal/275@X.X.X.X [CS_EXECUTE] [NORMAL_CLEARING]
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/275@X.X.X.X
) State EXECUTE going to sleep
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_HANGUP (Cur 4 Tot 6113)
2019-10-29 18:22:37.715412 [DEBUG] switch_ivr_async.c:1441 Stop recording file /var/lib/freeswitch/recordings/X.X.X.X/archive/2019/Oct/29/45d15826-e3c8-4af9-9a4b-6014bfc3dd16.wav
2019-10-29 18:22:37.715412 [DEBUG] switch_ivr_async.c:1516 Channel is hung up
2019-10-29 18:22:37.715412 [DEBUG] switch_core_media_bug.c:1289 Removing BUG from sofia/internal/275@X.X.X.X
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/275@X.X.X.X) Callstate Change EARLY -> HANGUP
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/275@X.X.X.X) State HANGUP
2019-10-29 18:22:37.715412 [DEBUG] mod_sofia.c:454 sofia/internal/275@X.X.X.X Overriding SIP cause 480 with 486 from the other leg
2019-10-29 18:22:37.715412 [DEBUG] mod_sofia.c:460 Channel sofia/internal/275@X.X.X.X hanging up, cause: NORMAL_CLEARING
2019-10-29 18:22:37.715412 [DEBUG] mod_sofia.c:605 Responding to INVITE with: 486
tel
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:60 sofia/internal/275@X.X.X.X Standard HANGUP, cause: NORMAL_CLEARING
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/275@X.X.X.X) State HANGUP going to sleep
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/275@X.X.X.X) State Change CS_HANGUP -> CS_REPORTING
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_REPORTING (Cur 4 Tot 6113)
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/275@X.X.X.X) State REPORTING
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:174 sofia/internal/275@X.X.X.X Standard REPORTING, cause: NORMAL_CLEARING
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/275@X.X.X.X) State REPORTING going to sleep
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/275@X.X.X.X) State Change CS_REPORTING -> CS_DESTROY
2019-10-29 18:22:37.715412 [DEBUG] switch_core_session.c:1726 Session 6112 (sofia/internal/275@X.X.X.X) Locked, Waiting on external entities
2019-10-29 18:22:37.715412 [NOTICE] switch_core_session.c:1744 Session 6112 (sofia/internal/275@X.X.X.X) Ended
2019-10-29 18:22:37.715412 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/275@X.X.X.X [CS_DESTROY]
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/275@X.X.X.X) Running State Change CS_DESTROY (Cur 3 Tot 6113)
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/275@X.X.X.X) State DESTROY
2019-10-29 18:22:37.715412 [DEBUG] mod_sofia.c:365 sofia/internal/275@X.X.X.X SOFIA DESTROY
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:181 sofia/internal/275@X.X.X.X Standard DESTROY
2019-10-29 18:22:37.715412 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/275@X.X.X.X) State DESTROY going to sleep
 
K

krooney

Member
Jun 18, 2018
172
16
18
@DigitalDaz would you have an idea of what my issue is. Can only receive one call at a time no matter what i do delete destination and recreate, Assign to different domain on same server same issue cant figure out whats going on provider says its not them.

Thanks in advance

54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_media.c:3834 Set Codec sofia/internal/275@X.X.X.X PCMU/8000 20 ms 160 samples 64000 bits 1 channels
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_codec.c:111 sofia/internal/275@X.X.X.X Original read codec set to PCMU:0
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_media.c:5849 Set telephone-event payload to 101@8000
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_media.c:5907 sofia/internal/275@X.X.X.X Set 2833 dtmf send payload to 101 recv payload to 101
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] sofia.c:7724 (sofia/internal/275@X.X.X.X) State Change CS_NEW -> CS_INIT
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_INIT (Cur 6 Tot 6230)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/275@X.X.X.X) State INIT
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_sofia.c:93 sofia/internal/275@X.X.X.X SOFIA INIT
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:40 sofia/internal/275@X.X.X.X Standard INIT
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/275@X.X.X.X) State Change CS_INIT -> CS_ROUTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/275@X.X.X.X) State INIT going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_ROUTING (Cur 6 Tot 6230)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_channel.c:2332 (sofia/internal/275@X.X.X.X) Callstate Change DOWN -> RINGING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/275@X.X.X.X) State ROUTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_sofia.c:154 sofia/internal/275@X.X.X.X SOFIA ROUTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:236 sofia/internal/275@X.X.X.X Standard ROUTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [INFO] mod_dialplan_xml.c:637 Processing 275 <275>->5147620004 in context X.X.X.X
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->user_exists] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_exists] () =~ // break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(user_exists=false)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [user_exists]=[false]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(from_user_exists=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [from_user_exists]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->caller-details] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(caller_destination=${destination_number}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(caller_destination=5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [caller_destination]=[5147620004]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(caller_id_name=${caller_id_name}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(caller_id_name=275)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [caller_id_name]=[275]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(caller_id_number=${caller_id_number})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->call-direction] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X ANTI-Action export(call_direction=local) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X export(call_direction=local)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->variables] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [variables] destination_number(5147620004) =~ /park+101/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->variables] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [variables] () =~ // break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action export(origination_callee_id_name=${destination_number})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->French_Extension] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [French_Extension] username(275) =~ /223/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->is_loopback] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->user_record] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${user_record}(all) =~ /^all$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_session=true) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_session=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_session]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_record}(all) =~ /^inbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_record}(all) =~ /^outbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${user_record}(all) =~ /^local$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(from_user_record=all)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [from_user_record]=[all]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_session=true) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_session=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_session]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_path=/var/lib/freeswitch/recordings/X.X.X.X/archive/2019/Oct/29)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_path]=[/var/lib/freeswitch/recordings/X.X.X.X/archive/2019/Oct/29]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_name=${uuid}.${record_ext}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_name=b26c7fcd-54fa-4671-8a48-85e14b6604f1.wav)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_name]=[b26c7fcd-54fa-4671-8a48-85e14b6604f1.wav]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(recording_follow_transfer=true) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(recording_follow_transfer=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [recording_follow_transfer]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_append=true) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_append=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_append]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(record_in_progress=true) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(record_in_progress=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [record_in_progress]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(${uuid_record ${uuid} start ${record_path}/${record_name}})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->redial] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [redial] destination_number(5147620004) =~ /^(redial|\*870)$/ break=on-true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [redial] () =~ // break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->speed_dial] continue=false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [speed_dial] destination_number(5147620004) =~ /^\*0(.*)$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->default_caller_id] continue=true
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(emergency_caller_id_name=)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [emergency_caller_id_name]=[UNDEF]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(emergency_caller_id_number=)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [emergency_caller_id_number]=[UNDEF]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(5144942888) =~ /^$/ break=never
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->voip.ms.9.12-20] continue=false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [voip.ms.9.12-20] ${user_exists}(false) =~ /false/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [voip.ms.9.12-20] destination_number(5147620004) =~ /^9(\d{12,20})$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->IRISTEL.911] continue=false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [IRISTEL.911] ${user_exists}(false) =~ /false/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [IRISTEL.911] ${toll_allow}() =~ /true/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->IRISTEL.International] continue=false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [IRISTEL.International] ${user_exists}(false) =~ /false/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (FAIL) [IRISTEL.International] destination_number(5147620004) =~ /^(\d{12,20})$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X parsing [X.X.X.X->IRISTEL.1d10] continue=false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [IRISTEL.1d10] ${user_exists}(false) =~ /false/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Regex (PASS) [IRISTEL.1d10] destination_number(5147620004) =~ /^\+?1?(\d{10})$/ break=on-false
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(sip_h_X-accountcode=${accountcode})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action export(call_direction=outbound)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action unset(call_timeout)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(hangup_after_bridge=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(effective_caller_id_name=${outbound_caller_id_name})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(effective_caller_id_number=${outbound_caller_id_number})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(inherit_codec=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(ignore_display_updates=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(callee_id_number=5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action set(continue_on_fail=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action sleep(${sleep})
b26c7fcd-54fa-4671-8a48-85e14b6604f1 Dialplan: sofia/internal/275@X.X.X.X Action bridge(sofia/gateway/9d3695ec-e6b8-4980-ac70-770eb9183b8f/5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/275@X.X.X.X) State Change CS_ROUTING -> CS_EXECUTE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/275@X.X.X.X) State ROUTING going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_EXECUTE (Cur 6 Tot 6230)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/275@X.X.X.X) State EXECUTE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_sofia.c:209 sofia/internal/275@X.X.X.X SOFIA EXECUTE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_core_state_machine.c:329 sofia/internal/275@X.X.X.X Standard EXECUTE
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(caller_id_number=275)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [caller_id_number]=[275]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X export(origination_callee_id_name=5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[5147620004]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(RFC2822_DATE=Tue, 29 Oct 2019 19:41:57 -0400)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.655438 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [RFC2822_DATE]=[Tue, 29 Oct 2019 19:41:57 -0400]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [INFO] switch_ivr_async.c:2640 Sending early media
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_core_media.c:8658 AUDIO RTP [sofia/internal/275@X.X.X.X] X.X.X.X port 27842 -> 10.10.5.73 port 5012 codec: 0 ms: 20
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_core_media.c:8972 sofia/internal/275@X.X.X.X Set 2833 dtmf send payload to 101
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_core_media.c:8979 sofia/internal/275@X.X.X.X Set 2833 dtmf receive payload to 101
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_core_media.c:9002 sofia/internal/275@X.X.X.X Set rtp dtmf delay to 40
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] mod_sofia.c:2600 Ring SDP:
b26c7fcd-54fa-4671-8a48-85e14b6604f1 v=0
b26c7fcd-54fa-4671-8a48-85e14b6604f1 o=FreeSWITCH 1572364675 1572364676 IN IP4 X.X.X.X
b26c7fcd-54fa-4671-8a48-85e14b6604f1 s=FreeSWITCH
b26c7fcd-54fa-4671-8a48-85e14b6604f1 c=IN IP4 X.X.X.X
b26c7fcd-54fa-4671-8a48-85e14b6604f1 t=0 0
b26c7fcd-54fa-4671-8a48-85e14b6604f1 m=audio 27842 RTP/AVP 0 101
b26c7fcd-54fa-4671-8a48-85e14b6604f1 a=rtpmap:0 PCMU/8000
b26c7fcd-54fa-4671-8a48-85e14b6604f1 a=rtpmap:101 telephone-event/8000
b26c7fcd-54fa-4671-8a48-85e14b6604f1 a=fmtp:101 0-16
b26c7fcd-54fa-4671-8a48-85e14b6604f1 a=ptime:20
b26c7fcd-54fa-4671-8a48-85e14b6604f1 a=sendrecv
b26c7fcd-54fa-4671-8a48-85e14b6604f1
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [NOTICE] mod_sofia.c:2603 Pre-Answer sofia/internal/275@X.X.X.X!
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.755412 [DEBUG] switch_channel.c:3565 (sofia/internal/275@X.X.X.X) Callstate Change RINGING -> EARLY
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_ivr_async.c:1347 Record session sample rate: 8000 -> 8000
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to sofia/internal/275@X.X.X.X
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] sofia.c:7290 Channel sofia/internal/275@X.X.X.X entering state [early][183]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(+OK Success
b26c7fcd-54fa-4671-8a48-85e14b6604f1 )
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [+OK Success
b26c7fcd-54fa-4671-8a48-85e14b6604f1 ]=[UNDEF]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X hash(insert/X.X.X.X-last_dial/275/5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(sip_h_X-accountcode=X.X.X.X)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [sip_h_X-accountcode]=[X.X.X.X]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X export(call_direction=outbound)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[outbound]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X unset(call_timeout)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1817 UNSET [call_timeout]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(hangup_after_bridge=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [hangup_after_bridge]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(effective_caller_id_name=Lemtel)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [effective_caller_id_name]=[Lemtel]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(effective_caller_id_number=5144942888)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [effective_caller_id_number]=[5144942888]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(inherit_codec=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [inherit_codec]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(ignore_display_updates=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [ignore_display_updates]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(callee_id_number=5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [callee_id_number]=[5147620004]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X set(continue_on_fail=true)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_dptools.c:1672 SET sofia/internal/275@X.X.X.X [continue_on_fail]=[true]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X sleep(0)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 EXECUTE [depth=0] sofia/internal/275@X.X.X.X bridge(sofia/gateway/9d3695ec-e6b8-4980-ac70-770eb9183b8f/5147620004)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_channel.c:1264 sofia/internal/275@X.X.X.X EXPORTING[export_vars] [domain_name]=[X.X.X.X] to event
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_channel.c:1264 sofia/internal/275@X.X.X.X EXPORTING[export_vars] [call_direction]=[outbound] to event
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_channel.c:1264 sofia/internal/275@X.X.X.X EXPORTING[export_vars] [origination_callee_id_name]=[5147620004] to event
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_channel.c:1264 sofia/internal/275@X.X.X.X EXPORTING[export_vars] [call_direction]=[outbound] to event
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [NOTICE] switch_channel.c:1118 New Channel sofia/external/5147620004 [ceb74db9-22a0-493e-a8e1-876e0b34cf11]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] mod_sofia.c:5080 sofia/external/5147620004 setting variable [sip_cid_type]=[Pid]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] mod_sofia.c:5096 (sofia/external/5147620004) State Change CS_NEW -> CS_INIT
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_INIT (Cur 7 Tot 6231)
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:628 (sofia/external/5147620004) State INIT
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] mod_sofia.c:93 sofia/external/5147620004 SOFIA INIT
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] sofia_glue.c:1618 sofia/external/5147620004 sending invite version: 1.10.1 -release-12-f9990221e6 64bit
ceb74db9-22a0-493e-a8e1-876e0b34cf11 Local SDP:
ceb74db9-22a0-493e-a8e1-876e0b34cf11 v=0
ceb74db9-22a0-493e-a8e1-876e0b34cf11 o=FreeSWITCH 1572368569 1572368570 IN IP4 X.X.X.X
ceb74db9-22a0-493e-a8e1-876e0b34cf11 s=FreeSWITCH
ceb74db9-22a0-493e-a8e1-876e0b34cf11 c=IN IP4 X.X.X.X
ceb74db9-22a0-493e-a8e1-876e0b34cf11 t=0 0
ceb74db9-22a0-493e-a8e1-876e0b34cf11 m=audio 23948 RTP/AVP 0 8 9 101 13
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=rtpmap:0 PCMU/8000
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=rtpmap:8 PCMA/8000
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=rtpmap:9 G722/8000
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=rtpmap:101 telephone-event/8000
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=fmtp:101 0-16
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=rtpmap:13 CN/8000
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=ptime:20
ceb74db9-22a0-493e-a8e1-876e0b34cf11 a=sendrecv
ceb74db9-22a0-493e-a8e1-876e0b34cf11
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:40 sofia/external/5147620004 Standard INIT
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:48 (sofia/external/5147620004) State Change CS_INIT -> CS_ROUTING
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:628 (sofia/external/5147620004) State INIT going to sleep
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_ROUTING (Cur 7 Tot 6231)
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] sofia.c:7290 Channel sofia/external/5147620004 entering state [calling][0]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:644 (sofia/external/5147620004) State ROUTING
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] mod_sofia.c:154 sofia/external/5147620004 SOFIA ROUTING
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_ivr_originate.c:67 (sofia/external/5147620004) State Change CS_ROUTING -> CS_CONSUME_MEDIA
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:644 (sofia/external/5147620004) State ROUTING going to sleep
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_CONSUME_MEDIA (Cur 7 Tot 6231)
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:663 (sofia/external/5147620004) State CONSUME_MEDIA
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.775402 [DEBUG] switch_core_state_machine.c:663 (sofia/external/5147620004) State CONSUME_MEDIA going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.775402 [DEBUG] switch_ivr_async.c:1636 No silence detection configured; assuming start of speech
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] sofia.c:7290 Channel sofia/external/5147620004 entering state [terminated][486]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [NOTICE] sofia.c:8523 Hangup sofia/external/5147620004 [CS_CONSUME_MEDIA] [USER_BUSY]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_HANGUP (Cur 7 Tot 6231)
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:848 (sofia/external/5147620004) Callstate Change DOWN -> HANGUP
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5147620004) State HANGUP
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] mod_sofia.c:460 Channel sofia/external/5147620004 hanging up, cause: USER_BUSY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:60 sofia/external/5147620004 Standard HANGUP, cause: USER_BUSY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5147620004) State HANGUP going to sleep
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:620 (sofia/external/5147620004) State Change CS_HANGUP -> CS_REPORTING
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:585 (sofia/external/5147620004) Running State Change CS_REPORTING (Cur 7 Tot 6231)
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:936 (sofia/external/5147620004) State REPORTING
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:174 sofia/external/5147620004 Standard REPORTING, cause: USER_BUSY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:936 (sofia/external/5147620004) State REPORTING going to sleep
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:611 (sofia/external/5147620004) State Change CS_REPORTING -> CS_DESTROY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_session.c:1726 Session 6231 (sofia/external/5147620004) Locked, Waiting on external entities
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [DEBUG] switch_ivr_originate.c:3949 Originate Resulted in Error Cause: 17 [USER_BUSY]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [NOTICE] switch_core_session.c:1744 Session 6231 (sofia/external/5147620004) Ended
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/5147620004 [CS_DESTROY]
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:739 (sofia/external/5147620004) Running State Change CS_DESTROY (Cur 6 Tot 6231)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [INFO] mod_dptools.c:3631 Originate Failed. Cause: USER_BUSY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:749 (sofia/external/5147620004) State DESTROY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] mod_sofia.c:365 sofia/external/5147620004 SOFIA DESTROY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:181 sofia/external/5147620004 Standard DESTROY
ceb74db9-22a0-493e-a8e1-876e0b34cf11 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:749 (sofia/external/5147620004) State DESTROY going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [NOTICE] switch_core_state_machine.c:386 sofia/internal/275@X.X.X.X has executed the last dialplan instruction, hanging up.
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/internal/275@X.X.X.X [CS_EXECUTE] [NORMAL_CLEARING]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/275@X.X.X.X) State EXECUTE going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_HANGUP (Cur 6 Tot 6231)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.795401 [DEBUG] switch_ivr_async.c:1441 Stop recording file /var/lib/freeswitch/recordings/X.X.X.X/archive/2019/Oct/29/b26c7fcd-54fa-4671-8a48-85e14b6604f1.wav
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_ivr_async.c:1516 Channel is hung up
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_media_bug.c:1289 Removing BUG from sofia/internal/275@X.X.X.X
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/275@X.X.X.X) Callstate Change EARLY -> HANGUP
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/275@X.X.X.X) State HANGUP
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] mod_sofia.c:454 sofia/internal/275@X.X.X.X Overriding SIP cause 480 with 486 from the other leg
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] mod_sofia.c:460 Channel sofia/internal/275@X.X.X.X hanging up, cause: NORMAL_CLEARING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] mod_sofia.c:605 Responding to INVITE with: 486
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:60 sofia/internal/275@X.X.X.X Standard HANGUP, cause: NORMAL_CLEARING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/275@X.X.X.X) State HANGUP going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/275@X.X.X.X) State Change CS_HANGUP -> CS_REPORTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/275@X.X.X.X) Running State Change CS_REPORTING (Cur 6 Tot 6231)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/275@X.X.X.X) State REPORTING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:174 sofia/internal/275@X.X.X.X Standard REPORTING, cause: NORMAL_CLEARING
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/275@X.X.X.X) State REPORTING going to sleep
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/275@X.X.X.X) State Change CS_REPORTING -> CS_DESTROY
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_session.c:1726 Session 6230 (sofia/internal/275@X.X.X.X) Locked, Waiting on external entities
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [NOTICE] switch_core_session.c:1744 Session 6230 (sofia/internal/275@X.X.X.X) Ended
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/275@X.X.X.X [CS_DESTROY]
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/275@X.X.X.X) Running State Change CS_DESTROY (Cur 5 Tot 6231)
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/275@X.X.X.X) State DESTROY
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] mod_sofia.c:365 sofia/internal/275@X.X.X.X SOFIA DESTROY
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:181 sofia/internal/275@X.X.X.X Standard DESTROY
b26c7fcd-54fa-4671-8a48-85e14b6604f1 2019-10-29 19:41:57.815469 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/275@X.X.X.X) State DESTROY going to sleep
2019-10-29 19:41:58.255466 [WARNING] sofia_reg.c:1793 SIP auth challenge (INVITE) on sofia profile 'internal' for [park+*101@X.X.X.X] from ip 70.51.180.59
f6074e0e-6009-4ca2-b557-97c731737a9f 2019-10-29 19:42:02.055425 [NOTICE] sofia.c:1084 Hangup sofia/internal/302@X.X.X.X [CS_EXECUTE] [NORMAL_CLEARING]
a560af0f-8b71-4679-bcfe-e7eaf9387cc4 2019-10-29 19:42:02.055425 [DEBUG] switch_ivr_bridge.c:824 sofia/internal/302@X.X.X.X ending bridge by request from wr
 
Status
Not open for further replies.
Top Bottom