2017-02-03 21:45:09.249294 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/02126130244@192.168.1.113] has been answered
2017-02-03 21:45:09.249294 [DEBUG] switch_channel.c:3772 (sofia/internal/02126130244@192.168.1.113) Callstate Change EARLY -> ACTIVE
2017-02-03 21:45:09.249294 [DEBUG] sofia.c:7041 Channel sofia/internal/02126130244@192.168.1.113 entering state [completed][200]
EXECUTE sofia/internal/02126130244@192.168.1.113 set(fifo_music=local_stream://moh)
2017-02-03 21:45:09.249294 [DEBUG] mod_dptools.c:1527 SET sofia/internal/02126130244@192.168.1.113 [fifo_music]=[local_stream://moh]
EXECUTE sofia/internal/02126130244@192.168.1.113 playback(ivr/ivr-hold_connect_call.wav)
2017-02-03 21:45:09.249294 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2017-02-03 21:45:09.269282 [DEBUG] sofia.c:7041 Channel sofia/internal/02126130244@192.168.1.113 entering state [ready][200]
2017-02-03 21:45:09.309305 [DEBUG] switch_rtp.c:6994 Correct audio ip/port confirmed.
2017-02-03 21:45:10.949282 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-hold_connect_call.wav
EXECUTE sofia/internal/02126130244@192.168.1.113 fifo(fifo1@192.168.1.231 in)
2017-02-03 21:45:10.949282 [DEBUG] mod_local_stream.c:866 Opening Stream [moh/8000] 8000hz
2017-02-03 21:45:10.949282 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2017-02-03 21:45:12.889291 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:12.889291 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:12.889291 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:12.889291 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:12.889291 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:12.889291 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:12.889291 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:14.889302 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:14.889302 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:14.889302 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:14.889302 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:14.889302 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:14.889302 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:14.889302 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:16.889280 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:16.889280 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:16.889280 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:16.889280 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:16.889280 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:16.889280 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:16.889280 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:18.889346 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:18.889346 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:18.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:18.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:18.889346 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:18.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:18.889346 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:20.889326 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:20.889326 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:20.889326 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:20.889326 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:20.889326 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:20.889326 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:20.889326 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:22.889343 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:22.889343 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:22.889343 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:22.889343 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:22.889343 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:22.889343 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:22.889343 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:24.889299 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:24.889299 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:24.889299 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1027@192.168.1.21:5060 [6184692f-cd82-4111-a96f-72f89223420c]
2017-02-03 21:45:24.889299 [DEBUG] mod_sofia.c:4808 (sofia/internal/1027@192.168.1.21:5060) State Change CS_NEW -> CS_INIT
2017-02-03 21:45:24.889299 [DEBUG] switch_ivr_originate.c:2953 sofia/internal/1027@192.168.1.21:5060 Setting leg timeout to 15
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_INIT (Cur 2 Tot 31)
2017-02-03 21:45:24.889299 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1027@192.168.1.21:5060) State INIT
2017-02-03 21:45:24.889299 [DEBUG] mod_sofia.c:90 sofia/internal/1027@192.168.1.21:5060 SOFIA INIT
2017-02-03 21:45:24.889299 [DEBUG] sofia_glue.c:1283 sofia/internal/1027@192.168.1.21:5060 sending invite version: 1.6.14 git a8d53fd 2017-01-12 17:48:02Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1486128762 1486128763 IN IP4 192.168.1.231
s=FreeSWITCH
c=IN IP4 192.168.1.231
t=0 0
m=audio 16962 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1027@192.168.1.21:5060 Standard INIT
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1027@192.168.1.21:5060) State Change CS_INIT -> CS_ROUTING
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1027@192.168.1.21:5060) State INIT going to sleep
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_ROUTING (Cur 2 Tot 31)
2017-02-03 21:45:24.889299 [DEBUG] sofia.c:7041 Channel sofia/internal/1027@192.168.1.21:5060 entering state [calling][0]
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1027@192.168.1.21:5060) State ROUTING
2017-02-03 21:45:24.889299 [DEBUG] mod_sofia.c:143 sofia/internal/1027@192.168.1.21:5060 SOFIA ROUTING
2017-02-03 21:45:24.889299 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1027@192.168.1.21:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1027@192.168.1.21:5060) State ROUTING going to sleep
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 31)
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1027@192.168.1.21:5060) State CONSUME_MEDIA
2017-02-03 21:45:24.889299 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1027@192.168.1.21:5060) State CONSUME_MEDIA going to sleep
2017-02-03 21:45:25.029283 [DEBUG] sofia.c:7041 Channel sofia/internal/1027@192.168.1.21:5060 entering state [proceeding][180]
2017-02-03 21:45:25.029283 [NOTICE] sofia.c:7149 Ring-Ready sofia/internal/1027@192.168.1.21:5060!
2017-02-03 21:45:25.029283 [DEBUG] switch_channel.c:3345 (sofia/internal/1027@192.168.1.21:5060) Callstate Change DOWN -> RINGING
2017-02-03 21:45:40.009278 [NOTICE] switch_ivr_originate.c:327 Hangup sofia/internal/1027@192.168.1.21:5060 [CS_CONSUME_MEDIA] [ALLOTTED_TIMEOUT]
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_HANGUP (Cur 2 Tot 31)
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1027@192.168.1.21:5060) Callstate Change RINGING -> HANGUP
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1027@192.168.1.21:5060) State HANGUP
2017-02-03 21:45:40.009278 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1027@192.168.1.21:5060 hanging up, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:40.009278 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/1027@192.168.1.21:5060
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1027@192.168.1.21:5060 Standard HANGUP, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1027@192.168.1.21:5060) State HANGUP going to sleep
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1027@192.168.1.21:5060) State Change CS_HANGUP -> CS_REPORTING
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_REPORTING (Cur 2 Tot 31)
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1027@192.168.1.21:5060) State REPORTING
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1027@192.168.1.21:5060 Standard REPORTING, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1027@192.168.1.21:5060) State REPORTING going to sleep
2017-02-03 21:45:40.009278 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1027@192.168.1.21:5060) State Change CS_REPORTING -> CS_DESTROY
2017-02-03 21:45:40.009278 [DEBUG] switch_core_session.c:1647 Session 31 (sofia/internal/1027@192.168.1.21:5060) Locked, Waiting on external entities
2017-02-03 21:45:40.029415 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 602 [ALLOTTED_TIMEOUT]
2017-02-03 21:45:40.029415 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [ALLOTTED_TIMEOUT]
2017-02-03 21:45:40.029415 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 602 [ALLOTTED_TIMEOUT]
2017-02-03 21:45:40.029415 [NOTICE] switch_core_session.c:1665 Session 31 (sofia/internal/1027@192.168.1.21:5060) Ended
2017-02-03 21:45:40.029415 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/1027@192.168.1.21:5060 [CS_DESTROY]
2017-02-03 21:45:40.029415 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_DESTROY (Cur 1 Tot 31)
2017-02-03 21:45:40.029415 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1027@192.168.1.21:5060) State DESTROY
2017-02-03 21:45:40.029415 [DEBUG] mod_sofia.c:343 sofia/internal/1027@192.168.1.21:5060 SOFIA DESTROY
2017-02-03 21:45:40.029415 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1027@192.168.1.21:5060 Standard DESTROY
2017-02-03 21:45:40.029415 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1027@192.168.1.21:5060) State DESTROY going to sleep
2017-02-03 21:45:41.889291 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:41.889291 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:41.889291 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1028@192.168.1.20:5060 [07622670-39f6-4f91-a948-3cc6354a8045]
2017-02-03 21:45:41.889291 [DEBUG] mod_sofia.c:4808 (sofia/internal/1028@192.168.1.20:5060) State Change CS_NEW -> CS_INIT
2017-02-03 21:45:41.889291 [DEBUG] switch_ivr_originate.c:2953 sofia/internal/1028@192.168.1.20:5060 Setting leg timeout to 15
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_INIT (Cur 2 Tot 32)
2017-02-03 21:45:41.889291 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1028@192.168.1.20:5060) State INIT
2017-02-03 21:45:41.889291 [DEBUG] mod_sofia.c:90 sofia/internal/1028@192.168.1.20:5060 SOFIA INIT
2017-02-03 21:45:41.889291 [DEBUG] sofia_glue.c:1283 sofia/internal/1028@192.168.1.20:5060 sending invite version: 1.6.14 git a8d53fd 2017-01-12 17:48:02Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1486122915 1486122916 IN IP4 192.168.1.231
s=FreeSWITCH
c=IN IP4 192.168.1.231
t=0 0
m=audio 22826 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1028@192.168.1.20:5060 Standard INIT
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1028@192.168.1.20:5060) State Change CS_INIT -> CS_ROUTING
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1028@192.168.1.20:5060) State INIT going to sleep
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_ROUTING (Cur 2 Tot 32)
2017-02-03 21:45:41.889291 [DEBUG] sofia.c:7041 Channel sofia/internal/1028@192.168.1.20:5060 entering state [calling][0]
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1028@192.168.1.20:5060) State ROUTING
2017-02-03 21:45:41.889291 [DEBUG] mod_sofia.c:143 sofia/internal/1028@192.168.1.20:5060 SOFIA ROUTING
2017-02-03 21:45:41.889291 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1028@192.168.1.20:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1028@192.168.1.20:5060) State ROUTING going to sleep
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 32)
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1028@192.168.1.20:5060) State CONSUME_MEDIA
2017-02-03 21:45:41.889291 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1028@192.168.1.20:5060) State CONSUME_MEDIA going to sleep
2017-02-03 21:45:42.029341 [DEBUG] sofia.c:7041 Channel sofia/internal/1028@192.168.1.20:5060 entering state [proceeding][180]
2017-02-03 21:45:42.029341 [NOTICE] sofia.c:7149 Ring-Ready sofia/internal/1028@192.168.1.20:5060!
2017-02-03 21:45:42.029341 [DEBUG] switch_channel.c:3345 (sofia/internal/1028@192.168.1.20:5060) Callstate Change DOWN -> RINGING
2017-02-03 21:45:57.009345 [NOTICE] switch_ivr_originate.c:327 Hangup sofia/internal/1028@192.168.1.20:5060 [CS_CONSUME_MEDIA] [ALLOTTED_TIMEOUT]
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_HANGUP (Cur 2 Tot 32)
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1028@192.168.1.20:5060) Callstate Change RINGING -> HANGUP
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1028@192.168.1.20:5060) State HANGUP
2017-02-03 21:45:57.009345 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1028@192.168.1.20:5060 hanging up, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:57.009345 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/1028@192.168.1.20:5060
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1028@192.168.1.20:5060 Standard HANGUP, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1028@192.168.1.20:5060) State HANGUP going to sleep
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1028@192.168.1.20:5060) State Change CS_HANGUP -> CS_REPORTING
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_REPORTING (Cur 2 Tot 32)
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1028@192.168.1.20:5060) State REPORTING
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1028@192.168.1.20:5060 Standard REPORTING, cause: ALLOTTED_TIMEOUT
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1028@192.168.1.20:5060) State REPORTING going to sleep
2017-02-03 21:45:57.009345 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1028@192.168.1.20:5060) State Change CS_REPORTING -> CS_DESTROY
2017-02-03 21:45:57.009345 [DEBUG] switch_core_session.c:1647 Session 32 (sofia/internal/1028@192.168.1.20:5060) Locked, Waiting on external entities
2017-02-03 21:45:57.029285 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 602 [ALLOTTED_TIMEOUT]
2017-02-03 21:45:57.029285 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [ALLOTTED_TIMEOUT]
2017-02-03 21:45:57.029285 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 602 [ALLOTTED_TIMEOUT]
2017-02-03 21:45:57.029285 [NOTICE] switch_core_session.c:1665 Session 32 (sofia/internal/1028@192.168.1.20:5060) Ended
2017-02-03 21:45:57.029285 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/1028@192.168.1.20:5060 [CS_DESTROY]
2017-02-03 21:45:57.029285 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1028@192.168.1.20:5060) Running State Change CS_DESTROY (Cur 1 Tot 32)
2017-02-03 21:45:57.029285 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1028@192.168.1.20:5060) State DESTROY
2017-02-03 21:45:57.029285 [DEBUG] mod_sofia.c:343 sofia/internal/1028@192.168.1.20:5060 SOFIA DESTROY
2017-02-03 21:45:57.029285 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1028@192.168.1.20:5060 Standard DESTROY
2017-02-03 21:45:57.029285 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1028@192.168.1.20:5060) State DESTROY going to sleep
2017-02-03 21:45:58.889336 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:58.889336 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:45:58.889336 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:58.889336 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:58.889336 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:45:58.889336 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:45:58.889336 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:00.889331 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:00.889331 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:00.889331 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:00.889331 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:00.889331 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:00.889331 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:00.889331 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:02.889292 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:02.889292 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:02.889292 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:02.889292 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:02.889292 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:02.889292 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:02.889292 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:04.889332 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:04.889332 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:04.889332 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:04.889332 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:04.889332 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:04.889332 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:04.889332 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:06.889285 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:06.889285 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:06.889285 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:06.889285 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:06.889285 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:06.889285 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:06.889285 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:08.889346 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:08.889346 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:08.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:08.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:08.889346 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:08.889346 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:08.889346 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2017-02-03 21:46:10.889294 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:10.889294 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-02-03 21:46:10.889294 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1027@192.168.1.21:5060 [1f8579ba-a30d-40a3-8187-b98e236d5f9c]
2017-02-03 21:46:10.889294 [DEBUG] mod_sofia.c:4808 (sofia/internal/1027@192.168.1.21:5060) State Change CS_NEW -> CS_INIT
2017-02-03 21:46:10.889294 [DEBUG] switch_ivr_originate.c:2953 sofia/internal/1027@192.168.1.21:5060 Setting leg timeout to 15
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_INIT (Cur 2 Tot 33)
2017-02-03 21:46:10.889294 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1027@192.168.1.21:5060) State INIT
2017-02-03 21:46:10.889294 [DEBUG] mod_sofia.c:90 sofia/internal/1027@192.168.1.21:5060 SOFIA INIT
2017-02-03 21:46:10.889294 [DEBUG] sofia_glue.c:1283 sofia/internal/1027@192.168.1.21:5060 sending invite version: 1.6.14 git a8d53fd 2017-01-12 17:48:02Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1486124290 1486124291 IN IP4 192.168.1.231
s=FreeSWITCH
c=IN IP4 192.168.1.231
t=0 0
m=audio 21480 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1027@192.168.1.21:5060 Standard INIT
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1027@192.168.1.21:5060) State Change CS_INIT -> CS_ROUTING
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1027@192.168.1.21:5060) State INIT going to sleep
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_ROUTING (Cur 2 Tot 33)
2017-02-03 21:46:10.889294 [DEBUG] sofia.c:7041 Channel sofia/internal/1027@192.168.1.21:5060 entering state [calling][0]
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1027@192.168.1.21:5060) State ROUTING
2017-02-03 21:46:10.889294 [DEBUG] mod_sofia.c:143 sofia/internal/1027@192.168.1.21:5060 SOFIA ROUTING
2017-02-03 21:46:10.889294 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1027@192.168.1.21:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1027@192.168.1.21:5060) State ROUTING going to sleep
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 33)
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1027@192.168.1.21:5060) State CONSUME_MEDIA
2017-02-03 21:46:10.889294 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1027@192.168.1.21:5060) State CONSUME_MEDIA going to sleep
2017-02-03 21:46:11.029290 [DEBUG] sofia.c:7041 Channel sofia/internal/1027@192.168.1.21:5060 entering state [proceeding][180]
2017-02-03 21:46:11.029290 [NOTICE] sofia.c:7149 Ring-Ready sofia/internal/1027@192.168.1.21:5060!
2017-02-03 21:46:11.029290 [DEBUG] switch_channel.c:3345 (sofia/internal/1027@192.168.1.21:5060) Callstate Change DOWN -> RINGING
2017-02-03 21:46:18.849310 [NOTICE] sofia.c:1012 Hangup sofia/internal/02126130244@192.168.1.113 [CS_EXECUTE] [NORMAL_CLEARING]
2017-02-03 21:46:18.849310 [DEBUG] switch_ivr_play_say.c:1942 done playing file local_stream://moh
2017-02-03 21:46:18.849310 [DEBUG] switch_core_session.c:2797 sofia/internal/02126130244@192.168.1.113 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/02126130244@192.168.1.113) State EXECUTE going to sleep
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/02126130244@192.168.1.113) Running State Change CS_HANGUP (Cur 2 Tot 33)
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/02126130244@192.168.1.113) Callstate Change ACTIVE -> HANGUP
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/02126130244@192.168.1.113) State HANGUP
2017-02-03 21:46:18.849310 [DEBUG] mod_sofia.c:438 Channel sofia/internal/02126130244@192.168.1.113 hanging up, cause: NORMAL_CLEARING
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:60 sofia/internal/02126130244@192.168.1.113 Standard HANGUP, cause: NORMAL_CLEARING
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/02126130244@192.168.1.113) State HANGUP going to sleep
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/02126130244@192.168.1.113) State Change CS_HANGUP -> CS_REPORTING
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/02126130244@192.168.1.113) Running State Change CS_REPORTING (Cur 2 Tot 33)
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/02126130244@192.168.1.113) State REPORTING
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:174 sofia/internal/02126130244@192.168.1.113 Standard REPORTING, cause: NORMAL_CLEARING
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/02126130244@192.168.1.113) State REPORTING going to sleep
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/02126130244@192.168.1.113) State Change CS_REPORTING -> CS_DESTROY
2017-02-03 21:46:18.849310 [DEBUG] switch_core_session.c:1647 Session 30 (sofia/internal/02126130244@192.168.1.113) Locked, Waiting on external entities
2017-02-03 21:46:18.849310 [NOTICE] switch_core_session.c:1665 Session 30 (sofia/internal/02126130244@192.168.1.113) Ended
2017-02-03 21:46:18.849310 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/02126130244@192.168.1.113 [CS_DESTROY]
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/02126130244@192.168.1.113) Running State Change CS_DESTROY (Cur 1 Tot 33)
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/02126130244@192.168.1.113) State DESTROY
2017-02-03 21:46:18.849310 [DEBUG] mod_sofia.c:343 sofia/internal/02126130244@192.168.1.113 SOFIA DESTROY
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:181 sofia/internal/02126130244@192.168.1.113 Standard DESTROY
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/02126130244@192.168.1.113) State DESTROY going to sleep
2017-02-03 21:46:18.849310 [NOTICE] switch_ivr_originate.c:3601 Hangup sofia/internal/1027@192.168.1.21:5060 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2017-02-03 21:46:18.849310 [DEBUG] switch_ivr_originate.c:3818 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2017-02-03 21:46:18.849310 [NOTICE] switch_ivr_originate.c:2841 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
2017-02-03 21:46:18.849310 [DEBUG] switch_ivr_originate.c:3829 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_HANGUP (Cur 1 Tot 33)
2017-02-03 21:46:18.849310 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1027@192.168.1.21:5060) Callstate Change RINGING -> HANGUP
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1027@192.168.1.21:5060) State HANGUP
2017-02-03 21:46:18.869278 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1027@192.168.1.21:5060 hanging up, cause: ORIGINATOR_CANCEL
2017-02-03 21:46:18.869278 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/1027@192.168.1.21:5060
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1027@192.168.1.21:5060 Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1027@192.168.1.21:5060) State HANGUP going to sleep
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1027@192.168.1.21:5060) State Change CS_HANGUP -> CS_REPORTING
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_REPORTING (Cur 1 Tot 33)
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1027@192.168.1.21:5060) State REPORTING
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1027@192.168.1.21:5060 Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1027@192.168.1.21:5060) State REPORTING going to sleep
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1027@192.168.1.21:5060) State Change CS_REPORTING -> CS_DESTROY
2017-02-03 21:46:18.869278 [DEBUG] switch_core_session.c:1647 Session 33 (sofia/internal/1027@192.168.1.21:5060) Locked, Waiting on external entities
2017-02-03 21:46:18.869278 [NOTICE] switch_core_session.c:1665 Session 33 (sofia/internal/1027@192.168.1.21:5060) Ended
2017-02-03 21:46:18.869278 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/1027@192.168.1.21:5060 [CS_DESTROY]
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1027@192.168.1.21:5060) Running State Change CS_DESTROY (Cur 0 Tot 33)
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1027@192.168.1.21:5060) State DESTROY
2017-02-03 21:46:18.869278 [DEBUG] mod_sofia.c:343 sofia/internal/1027@192.168.1.21:5060 SOFIA DESTROY
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1027@192.168.1.21:5060 Standard DESTROY
2017-02-03 21:46:18.869278 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1027@192.168.1.21:5060) State DESTROY going to sleep
freeswitch@Github>