Opened 7 years ago

Closed 6 years ago

#567 closed баг (worksforme)

При отмене вызова пользователя, команда ГБ отправляется

Reported by: san Owned by: alx
Priority: major Milestone: 1 очередь
Component: MC04-SoftSwitch Keywords:
Cc:

Description

Если отменить вызов пользователя до истечения "задержки до ГБ", команда включения ГБ будет отправлена.
Привожу лог от эксперимента:

2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-01 15:23:30.335891 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/201@192.168.0.5:5060 [d69886fc-3b9e-496e-887f-e733d5e44083]
2017-06-01 15:23:30.335891 [DEBUG] mod_sofia.c:4818 (sofia/internal/201@192.168.0.5:5060) State Change CS_NEW -> CS_INIT
2017-06-01 15:23:30.335891 [DEBUG] switch_core_session.c:614 sofia/internal/201@192.168.0.5:5060 set UUID=d69886fc-3b9e-496e-887f-e733d5e44083
2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_INIT (Cur 2 Tot 56)
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@192.168.0.5:5060) State INIT
2017-06-01 15:23:30.335891 [NOTICE] switch_channel.c:1104 New Channel loopback/201@192.168.0.63/alarm-a [d145ea72-0da2-4b1d-9019-bcaa50cde7fc]
2017-06-01 15:23:30.335891 [DEBUG] mod_sofia.c:90 sofia/internal/201@192.168.0.5:5060 SOFIA INIT
2017-06-01 15:23:30.335891 [DEBUG] mod_loopback.c:158 loopback/201@192.168.0.63/alarm-a setup codec L16/8000/20
2017-06-01 15:23:30.335891 [NOTICE] switch_channel.c:1102 Rename Channel loopback/201@192.168.0.63/alarm-a->loopback/201@192.168.0.63-a [d145ea72-0da2-4b1d-9019-bcaa50cde7fc]
2017-06-01 15:23:30.335891 [DEBUG] mod_loopback.c:1174 (loopback/201@192.168.0.63-a) State Change CS_NEW -> CS_INIT
2017-06-01 15:23:30.335891 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:2975 loopback/201@192.168.0.63-a Setting leg delay start to 10
2017-06-01 15:23:30.335891 [DEBUG] sofia_glue.c:1295 sofia/internal/201@192.168.0.5:5060 sending invite version: 1.6.17 git 0fc0946 2017-04-17 14:21:08Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1496303324 1496303325 IN IP4 192.168.0.63
s=FreeSWITCH
c=IN IP4 192.168.0.63
t=0 0
m=audio 16486 RTP/AVP 0 8 18 102 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=rtpmap:102 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp-mux
a=rtcp:16486 IN IP4 192.168.0.63
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
m=video 27530 RTP/AVP 103 34
b=AS:2048
a=rtpmap:103 H264/90000
a=rtpmap:34 H263/90000
a=rtcp-mux
a=rtcp:27530 IN IP4 192.168.0.63
a=rtcp-fb:103 ccm fir
a=rtcp-fb:103 ccm tmmbr
a=rtcp-fb:103 nack
a=rtcp-fb:103 nack pli
a=rtcp-fb:34 ccm fir
a=rtcp-fb:34 ccm tmmbr
a=rtcp-fb:34 nack
a=rtcp-fb:34 nack pli

2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:40 sofia/internal/201@192.168.0.5:5060 Standard INIT
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/201@192.168.0.5:5060) State Change CS_INIT -> CS_ROUTING
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@192.168.0.5:5060) State INIT going to sleep
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_ROUTING (Cur 3 Tot 57)
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@192.168.0.5:5060) State ROUTING
2017-06-01 15:23:30.335891 [DEBUG] mod_sofia.c:143 sofia/internal/201@192.168.0.5:5060 SOFIA ROUTING
2017-06-01 15:23:30.335891 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/201@192.168.0.5:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@192.168.0.5:5060) State ROUTING going to sleep
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 57)
2017-06-01 15:23:30.335891 [DEBUG] sofia.c:7048 Channel sofia/internal/201@192.168.0.5:5060 entering state [calling][0]
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@192.168.0.5:5060) State CONSUME_MEDIA
2017-06-01 15:23:30.335891 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@192.168.0.5:5060) State CONSUME_MEDIA going to sleep
2017-06-01 15:23:30.395883 [DEBUG] sofia.c:7048 Channel sofia/internal/201@192.168.0.5:5060 entering state [proceeding][180]
2017-06-01 15:23:30.395883 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/201@192.168.0.5:5060!
2017-06-01 15:23:30.395883 [DEBUG] switch_channel.c:3345 (sofia/internal/201@192.168.0.5:5060) Callstate Change DOWN -> RINGING
2017-06-01 15:23:32.595858 [NOTICE] switch_ivr.c:4269 Hangup sofia/internal/201@192.168.0.5:5060 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_HANGUP (Cur 3 Tot 57)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/201@192.168.0.5:5060) Callstate Change RINGING -> HANGUP
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@192.168.0.5:5060) State HANGUP
2017-06-01 15:23:32.595858 [DEBUG] mod_sofia.c:438 Channel sofia/internal/201@192.168.0.5:5060 hanging up, cause: NORMAL_CLEARING
2017-06-01 15:23:32.595858 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/201@192.168.0.5:5060
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:60 sofia/internal/201@192.168.0.5:5060 Standard HANGUP, cause: NORMAL_CLEARING
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@192.168.0.5:5060) State HANGUP going to sleep
2017-06-01 15:23:32.595858 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-01 15:23:32.595858 [NOTICE] switch_channel.c:1104 New Channel loopback/201@192.168.0.63/answered-a [4de5c852-eebd-4d38-ab37-2826dc681e60]
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:158 loopback/201@192.168.0.63/answered-a setup codec L16/8000/20
2017-06-01 15:23:32.595858 [NOTICE] switch_channel.c:1102 Rename Channel loopback/201@192.168.0.63/answered-a->loopback/201@192.168.0.63-a [4de5c852-eebd-4d38-ab37-2826dc681e60]
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:1174 (loopback/201@192.168.0.63-a) State Change CS_NEW -> CS_INIT
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_INIT (Cur 4 Tot 58)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-a) State INIT
2017-06-01 15:23:32.595858 [NOTICE] switch_channel.c:1104 New Channel loopback/201@192.168.0.63-b [84b589f9-ba2d-4ed1-b0ee-9e3deea81568]
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:158 loopback/201@192.168.0.63-b setup codec L16/8000/20
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:276 (loopback/201@192.168.0.63-b) State Change CS_NEW -> CS_INIT
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:362 (loopback/201@192.168.0.63-a) State Change CS_INIT -> CS_ROUTING
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_INIT (Cur 5 Tot 59)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-a) State INIT going to sleep
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-b) State INIT
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:362 (loopback/201@192.168.0.63-b) State Change CS_INIT -> CS_ROUTING
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-b) State INIT going to sleep
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_ROUTING (Cur 5 Tot 59)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_ROUTING (Cur 5 Tot 59)
2017-06-01 15:23:32.595858 [DEBUG] switch_channel.c:2249 (loopback/201@192.168.0.63-b) Callstate Change DOWN -> RINGING
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-a) State ROUTING
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:394 loopback/201@192.168.0.63-a CHANNEL ROUTING
2017-06-01 15:23:32.595858 [DEBUG] switch_ivr_originate.c:67 (loopback/201@192.168.0.63-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-a) State ROUTING going to sleep
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 59)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-b) State ROUTING
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:394 loopback/201@192.168.0.63-b CHANNEL ROUTING
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:662 (loopback/201@192.168.0.63-a) State CONSUME_MEDIA
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:236 loopback/201@192.168.0.63-b Standard ROUTING
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:661 CHANNEL CONSUME_MEDIA
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:662 (loopback/201@192.168.0.63-a) State CONSUME_MEDIA going to sleep
2017-06-01 15:23:32.595858 [INFO] mod_dialplan_xml.c:637 Processing  <0000000000>->201@192.168.0.63 in context answered
Dialplan: loopback/201@192.168.0.63-b parsing [answered->Stop-alarm] continue=false
Dialplan: loopback/201@192.168.0.63-b Regex (PASS) [Stop-alarm] ${hash(select/alarms/${destination_number})}(1) =~ /1/ break=on-false
Dialplan: loopback/201@192.168.0.63-b Action hash(delete/alarms/${destination_number})
Dialplan: loopback/201@192.168.0.63-b Regex (PASS) [Stop-alarm] ${db(exists/alarms/${destination_number})}(true) =~ /^true$/ break=on-false
Dialplan: loopback/201@192.168.0.63-b Action set(host_oid=${db(select/alarms/${destination_number})})
Dialplan: loopback/201@192.168.0.63-b Action system(snmpset -v2c -cprivate -r2 -t1 ${host_oid} i 2)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:286 (loopback/201@192.168.0.63-b) State Change CS_ROUTING -> CS_EXECUTE
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-b) State ROUTING going to sleep
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_EXECUTE (Cur 5 Tot 59)
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:650 (loopback/201@192.168.0.63-b) State EXECUTE
2017-06-01 15:23:32.595858 [DEBUG] mod_loopback.c:436 loopback/201@192.168.0.63-b CHANNEL EXECUTE
2017-06-01 15:23:32.595858 [DEBUG] switch_core_state_machine.c:328 loopback/201@192.168.0.63-b Standard EXECUTE
EXECUTE loopback/201@192.168.0.63-b hash(delete/alarms/201@192.168.0.63)
EXECUTE loopback/201@192.168.0.63-b set(host_oid=192.168.0.245 .1.3.6.1.4.1.32109.1.1.0)
2017-06-01 15:23:32.595858 [DEBUG] mod_dptools.c:1530 SET loopback/201@192.168.0.63-b [host_oid]=[192.168.0.245 .1.3.6.1.4.1.32109.1.1.0]
EXECUTE loopback/201@192.168.0.63-b system(snmpset -v2c -cprivate -r2 -t1 192.168.0.245 .1.3.6.1.4.1.32109.1.1.0 i 2)
2017-06-01 15:23:32.595858 [NOTICE] mod_dptools.c:2102 Executing command: snmpset -v2c -cprivate -r2 -t1 192.168.0.245 .1.3.6.1.4.1.32109.1.1.0 i 2
2017-06-01 15:23:32.715856 [NOTICE] switch_core_state_machine.c:385 loopback/201@192.168.0.63-b has executed the last dialplan instruction, hanging up.
2017-06-01 15:23:32.715856 [NOTICE] switch_core_state_machine.c:387 Hangup loopback/201@192.168.0.63-b [CS_EXECUTE] [NORMAL_CLEARING]
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:650 (loopback/201@192.168.0.63-b) State EXECUTE going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_HANGUP (Cur 5 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:850 (loopback/201@192.168.0.63-b) Callstate Change RINGING -> HANGUP
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-b) State HANGUP
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:548 loopback/201@192.168.0.63-b CHANNEL HANGUP
2017-06-01 15:23:32.735870 [NOTICE] mod_loopback.c:564 Hangup loopback/201@192.168.0.63-a [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:60 loopback/201@192.168.0.63-b Standard HANGUP, cause: NORMAL_CLEARING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-b) State HANGUP going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_HANGUP (Cur 5 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:619 (loopback/201@192.168.0.63-b) State Change CS_HANGUP -> CS_REPORTING
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_REPORTING (Cur 5 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-b) State REPORTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:850 (loopback/201@192.168.0.63-a) Callstate Change DOWN -> HANGUP
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:174 loopback/201@192.168.0.63-b Standard REPORTING, cause: NORMAL_CLEARING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-b) State REPORTING going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-a) State HANGUP
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:548 loopback/201@192.168.0.63-a CHANNEL HANGUP
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:60 loopback/201@192.168.0.63-a Standard HANGUP, cause: NORMAL_CLEARING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-a) State HANGUP going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:619 (loopback/201@192.168.0.63-a) State Change CS_HANGUP -> CS_REPORTING
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_REPORTING (Cur 5 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:610 (loopback/201@192.168.0.63-b) State Change CS_REPORTING -> CS_DESTROY
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_session.c:1664 Session 59 (loopback/201@192.168.0.63-b) Locked, Waiting on external entities
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-a) State REPORTING
2017-06-01 15:23:32.735870 [NOTICE] switch_core_session.c:1682 Session 59 (loopback/201@192.168.0.63-b) Ended
2017-06-01 15:23:32.735870 [NOTICE] switch_core_session.c:1686 Close Channel loopback/201@192.168.0.63-b [CS_DESTROY]
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:174 loopback/201@192.168.0.63-a Standard REPORTING, cause: NORMAL_CLEARING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-a) State REPORTING going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:741 (loopback/201@192.168.0.63-b) Running State Change CS_DESTROY (Cur 4 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:610 (loopback/201@192.168.0.63-a) State Change CS_REPORTING -> CS_DESTROY
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_session.c:1664 Session 58 (loopback/201@192.168.0.63-a) Locked, Waiting on external entities
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-b) State DESTROY
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:181 loopback/201@192.168.0.63-b Standard DESTROY
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-b) State DESTROY going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
2017-06-01 15:23:32.735870 [NOTICE] switch_core_session.c:1682 Session 58 (loopback/201@192.168.0.63-a) Ended
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:783 Hangup Command with no Session originate(loopback/201@192.168.0.63/answered 0):
-ERR NORMAL_CLEARING

2017-06-01 15:23:32.735870 [NOTICE] switch_core_session.c:1686 Close Channel loopback/201@192.168.0.63-a [CS_DESTROY]
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/201@192.168.0.5:5060) State Change CS_HANGUP -> CS_REPORTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_REPORTING (Cur 3 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:741 (loopback/201@192.168.0.63-a) Running State Change CS_DESTROY (Cur 3 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@192.168.0.5:5060) State REPORTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-a) State DESTROY
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:181 loopback/201@192.168.0.63-a Standard DESTROY
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-a) State DESTROY going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:174 sofia/internal/201@192.168.0.5:5060 Standard REPORTING, cause: NORMAL_CLEARING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@192.168.0.5:5060) State REPORTING going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/201@192.168.0.5:5060) State Change CS_REPORTING -> CS_DESTROY
2017-06-01 15:23:32.735870 [DEBUG] switch_core_session.c:1664 Session 56 (sofia/internal/201@192.168.0.5:5060) Locked, Waiting on external entities
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_INIT (Cur 3 Tot 59)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-a) State INIT
2017-06-01 15:23:32.735870 [NOTICE] switch_channel.c:1104 New Channel loopback/201@192.168.0.63-b [5861e7ad-77d1-4cf7-bf24-3c60bd8357ea]
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:158 loopback/201@192.168.0.63-b setup codec L16/8000/20
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:276 (loopback/201@192.168.0.63-b) State Change CS_NEW -> CS_INIT
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:362 (loopback/201@192.168.0.63-a) State Change CS_INIT -> CS_ROUTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_INIT (Cur 4 Tot 60)
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-a) State INIT going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-b) State INIT
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:362 (loopback/201@192.168.0.63-b) State Change CS_INIT -> CS_ROUTING
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:627 (loopback/201@192.168.0.63-b) State INIT going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_ROUTING (Cur 4 Tot 60)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_ROUTING (Cur 4 Tot 60)
2017-06-01 15:23:32.735870 [DEBUG] switch_channel.c:2249 (loopback/201@192.168.0.63-b) Callstate Change DOWN -> RINGING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-a) State ROUTING
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:394 loopback/201@192.168.0.63-a CHANNEL ROUTING
2017-06-01 15:23:32.735870 [DEBUG] switch_ivr_originate.c:67 (loopback/201@192.168.0.63-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-a) State ROUTING going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 60)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-b) State ROUTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:662 (loopback/201@192.168.0.63-a) State CONSUME_MEDIA
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:394 loopback/201@192.168.0.63-b CHANNEL ROUTING
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:661 CHANNEL CONSUME_MEDIA
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:236 loopback/201@192.168.0.63-b Standard ROUTING
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:662 (loopback/201@192.168.0.63-a) State CONSUME_MEDIA going to sleep
2017-06-01 15:23:32.735870 [INFO] mod_dialplan_xml.c:637 Processing 0 <0>->201@192.168.0.63 in context alarm
Dialplan: loopback/201@192.168.0.63-b parsing [alarm->Alarm] continue=false
Dialplan: loopback/201@192.168.0.63-b Regex (PASS) [Alarm] ${db(exists/alarms/${destination_number})}(true) =~ /^true$/ break=on-false
Dialplan: loopback/201@192.168.0.63-b Action hash(insert/alarms/${destination_number}/1)
Dialplan: loopback/201@192.168.0.63-b Action set(host_oid=${db(select/alarms/${destination_number})})
Dialplan: loopback/201@192.168.0.63-b Action system(snmpset -v2c -cprivate -r2 -t1 ${host_oid} i 250)
Dialplan: loopback/201@192.168.0.63-b Action event(Event-Name=CUSTOM,Event-Subclass=alert::notify,User-Name=${destination_number},User-Domain=${domain_name})
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:286 (loopback/201@192.168.0.63-b) State Change CS_ROUTING -> CS_EXECUTE
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:643 (loopback/201@192.168.0.63-b) State ROUTING going to sleep
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_EXECUTE (Cur 4 Tot 60)
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:650 (loopback/201@192.168.0.63-b) State EXECUTE
2017-06-01 15:23:32.735870 [DEBUG] mod_loopback.c:436 loopback/201@192.168.0.63-b CHANNEL EXECUTE
2017-06-01 15:23:32.735870 [DEBUG] switch_core_state_machine.c:328 loopback/201@192.168.0.63-b Standard EXECUTE
EXECUTE loopback/201@192.168.0.63-b hash(insert/alarms/201@192.168.0.63/1)
EXECUTE loopback/201@192.168.0.63-b set(host_oid=192.168.0.245 .1.3.6.1.4.1.32109.1.1.0)
2017-06-01 15:23:32.735870 [DEBUG] mod_dptools.c:1530 SET loopback/201@192.168.0.63-b [host_oid]=[192.168.0.245 .1.3.6.1.4.1.32109.1.1.0]
EXECUTE loopback/201@192.168.0.63-b system(snmpset -v2c -cprivate -r2 -t1 192.168.0.245 .1.3.6.1.4.1.32109.1.1.0 i 250)
2017-06-01 15:23:32.735870 [NOTICE] mod_dptools.c:2102 Executing command: snmpset -v2c -cprivate -r2 -t1 192.168.0.245 .1.3.6.1.4.1.32109.1.1.0 i 250
EXECUTE loopback/201@192.168.0.63-b event(Event-Name=CUSTOM,Event-Subclass=alert::notify,User-Name=201@192.168.0.63,User-Domain=192.168.0.63)
2017-06-01 15:23:32.835866 [NOTICE] switch_core_state_machine.c:385 loopback/201@192.168.0.63-b has executed the last dialplan instruction, hanging up.
2017-06-01 15:23:32.835866 [NOTICE] switch_core_state_machine.c:387 Hangup loopback/201@192.168.0.63-b [CS_EXECUTE] [NORMAL_CLEARING]
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:650 (loopback/201@192.168.0.63-b) State EXECUTE going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_HANGUP (Cur 4 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:850 (loopback/201@192.168.0.63-b) Callstate Change RINGING -> HANGUP
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-b) State HANGUP
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:548 loopback/201@192.168.0.63-b CHANNEL HANGUP
2017-06-01 15:23:32.835866 [NOTICE] mod_loopback.c:564 Hangup loopback/201@192.168.0.63-a [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:60 loopback/201@192.168.0.63-b Standard HANGUP, cause: NORMAL_CLEARING
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-b) State HANGUP going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:619 (loopback/201@192.168.0.63-b) State Change CS_HANGUP -> CS_REPORTING
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-b) Running State Change CS_REPORTING (Cur 4 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_HANGUP (Cur 4 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-b) State REPORTING
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:174 loopback/201@192.168.0.63-b Standard REPORTING, cause: NORMAL_CLEARING
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-b) State REPORTING going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:850 (loopback/201@192.168.0.63-a) Callstate Change DOWN -> HANGUP
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:610 (loopback/201@192.168.0.63-b) State Change CS_REPORTING -> CS_DESTROY
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-b CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_session.c:1664 Session 60 (loopback/201@192.168.0.63-b) Locked, Waiting on external entities
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-a) State HANGUP
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:548 loopback/201@192.168.0.63-a CHANNEL HANGUP
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:60 loopback/201@192.168.0.63-a Standard HANGUP, cause: NORMAL_CLEARING
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1682 Session 60 (loopback/201@192.168.0.63-b) Ended
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:852 (loopback/201@192.168.0.63-a) State HANGUP going to sleep
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1686 Close Channel loopback/201@192.168.0.63-b [CS_DESTROY]
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:619 (loopback/201@192.168.0.63-a) State Change CS_HANGUP -> CS_REPORTING
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:584 (loopback/201@192.168.0.63-a) Running State Change CS_REPORTING (Cur 3 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:741 (loopback/201@192.168.0.63-b) Running State Change CS_DESTROY (Cur 3 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-a) State REPORTING
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:174 loopback/201@192.168.0.63-a Standard REPORTING, cause: NORMAL_CLEARING
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:938 (loopback/201@192.168.0.63-a) State REPORTING going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-b) State DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:181 loopback/201@192.168.0.63-b Standard DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-b) State DESTROY going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:610 (loopback/201@192.168.0.63-a) State Change CS_REPORTING -> CS_DESTROY
2017-06-01 15:23:32.835866 [DEBUG] mod_loopback.c:601 loopback/201@192.168.0.63-a CHANNEL KILL
2017-06-01 15:23:32.835866 [DEBUG] switch_core_session.c:1664 Session 57 (loopback/201@192.168.0.63-a) Locked, Waiting on external entities
2017-06-01 15:23:32.835866 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1682 Session 57 (loopback/201@192.168.0.63-a) Ended
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1686 Close Channel loopback/201@192.168.0.63-a [CS_DESTROY]
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1682 Session 56 (sofia/internal/201@192.168.0.5:5060) Ended
2017-06-01 15:23:32.835866 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/201@192.168.0.5:5060 [CS_DESTROY]
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:741 (loopback/201@192.168.0.63-a) Running State Change CS_DESTROY (Cur 1 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-a) State DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:181 loopback/201@192.168.0.63-a Standard DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/201@192.168.0.5:5060) Running State Change CS_DESTROY (Cur 1 Tot 60)
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (loopback/201@192.168.0.63-a) State DESTROY going to sleep
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@192.168.0.5:5060) State DESTROY
2017-06-01 15:23:32.835866 [DEBUG] mod_sofia.c:343 sofia/internal/201@192.168.0.5:5060 SOFIA DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:181 sofia/internal/201@192.168.0.5:5060 Standard DESTROY
2017-06-01 15:23:32.835866 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@192.168.0.5:5060) State DESTROY going to sleep

Change History (5)

comment:1 by alx, 6 years ago

Саша, если возможно, приложи конфиг, пожалуйста.

comment:2 by san, 6 years ago

Эксперимент был проведён на .0.63, если конфиг с того времени не поменялся, по крайней мере то что касается ГБ, можно посмотреть там, а ещё лучше повторить эксперимент, всё-таки год прошёл.

comment:3 by alx, 6 years ago

на .0.63 баг мне воспроизвести не удалось. Потому и просил конфиги...

comment:4 by san, 6 years ago

раз не воспроизводится, давай закроем, дополнительной информации у меня нет

comment:5 by alx, 6 years ago

Resolution: → worksforme
Status: new → closed
Note: See TracTickets for help on using tickets.