[Freeswitch-users] Strange problem with phones.

As I don't know what this problem is related to: FS or Phone, I will describe here. Testing mod_callcenter for real response to calls. There are about 7 VoIP phones from D-Link (DPH-150S/E/F1 and DPH-150S/F2A). Agents log in and out when they need. All is working but suddenly one phone (DPH-150S/E/F1) started to reject calls as it was from log (see log at the end). There is a lot of "entering state [terminated][480]" and "[CS_CONSUME_MEDIA] [NO_USER_RESPONSE]". The phone does not ring, but instead its missing call value on display is rising quickly, so is the missing call count in the callcenter's DB for that agent. The other phones where receiving calls normal. I looked on the management page of that phone and it was in state "Registered" to the FS. I tried to change the password to some erradic to unregister and set password back to register, and the problem persisted. I then reset phone to its factory defaults and restored settings from a backup file for this particular phone and account. And it get back to receive calls normally. The same happened later with other phone (DPH-150S/F2A). In matter of seconds, the missing calls value raised to hundreds. So I asked to disconnect that phone from power outlet and connect another free phone. The logging of "[CS_CONSUME_MEDIA] [NO_USER_RESPONSE]" stopped for that phone. So I don't know, this is a bug in FS or something with D-Link phone. This behavior must happen only when the agent presses "Reject" button on the phone, but its like the phone presses immediately this button for itself. Did someone encountered such problem with such phone or other phones? Log: 2012-11-05 20:38:41.208702 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Receiving 2012-11-05 20:38:41.208702 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.208702 [DEBUG] switch_ivr_originate.c:2433 Parsing session specific variables 2012-11-05 20:38:41.208702 [DEBUG] switch_event.c:1570 Parsing variable [call_timeout]=[10] 2012-11-05 20:38:41.208702 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.208702 [DEBUG] switch_event.c:1570 Parsing variable [sip_invite_domain]=[pbx01.domain.md] 2012-11-05 20:38:41.208702 [DEBUG] switch_event.c:1570 Parsing variable [presence_id]=[624@pbx01.domain.md] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [NOTICE] switch_channel.c:951 New Channel sofia/internal/sip:624@132.101.16.24:5060 [ebbcda11-e628-4fb4-a8c5-653b9c35f54e] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] mod_sofia.c:4880 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_NEW -> CS_INIT ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_session.c:490 sofia/internal/sip:624@132.101.16.24:5060 set UUID=ebbcda11-e628-4fb4-a8c5-653b9c35f54e ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_INIT ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] mod_sofia.c:86 sofia/internal/sip:624@132.101.16.24:5060 SOFIA INIT ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] sofia_glue.c:2637 Local SDP: ebbcda11-e628-4fb4-a8c5-653b9c35f54e v=0 ebbcda11-e628-4fb4-a8c5-653b9c35f54e o=FreeSWITCH 1352122361 1352122362 IN IP4 132.101.0.58 ebbcda11-e628-4fb4-a8c5-653b9c35f54e s=FreeSWITCH ebbcda11-e628-4fb4-a8c5-653b9c35f54e c=IN IP4 132.101.0.58 ebbcda11-e628-4fb4-a8c5-653b9c35f54e t=0 0 ebbcda11-e628-4fb4-a8c5-653b9c35f54e m=audio 18360 RTP/AVP 98 9 0 8 3 101 13 ebbcda11-e628-4fb4-a8c5-653b9c35f54e a=rtpmap:98 SPEEX/32000 ebbcda11-e628-4fb4-a8c5-653b9c35f54e a=rtpmap:101 telephone-event/8000 ebbcda11-e628-4fb4-a8c5-653b9c35f54e a=fmtp:101 0-16 ebbcda11-e628-4fb4-a8c5-653b9c35f54e a=ptime:20 ebbcda11-e628-4fb4-a8c5-653b9c35f54e a=sendrecv ebbcda11-e628-4fb4-a8c5-653b9c35f54e ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] mod_sofia.c:126 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_INIT -> CS_ROUTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT going to sleep ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_ROUTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_channel.c:1964 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change DOWN -> RINGING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] mod_sofia.c:149 sofia/internal/sip:624@132.101.16.24:5060 SOFIA ROUTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING going to sleep ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_CONSUME_MEDIA ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA going to sleep ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.208702 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [calling][0] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [terminated][480] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_channel.c:2950 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change RINGING -> HANGUP ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [NOTICE] sofia.c:7108 Hangup sofia/internal/sip:624@132.101.16.24:5060 [CS_CONSUME_MEDIA] [NO_USER_RESPONSE] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/sip:624@132.101.16.24:5060 [KILL] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_HANGUP ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.248617 [DEBUG] mod_sofia.c:483 Channel sofia/internal/sip:624@132.101.16.24:5060 hanging up, cause: NO_USER_RESPONSE 2012-11-05 20:38:41.248617 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] 2012-11-05 20:38:41.248617 [NOTICE] switch_ivr_originate.c:2599 Cannot create outgoing channel of type [user] cause: [NO_USER_RESPONSE] 2012-11-05 20:38:41.248617 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.248617 [DEBUG] mod_callcenter.c:1728 Agent 624@pbx01.domain.md Origination Canceled : NO_USER_RESPONSE ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:624@132.101.16.24:5060 Standard HANGUP, cause: NO_USER_RESPONSE ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP going to sleep ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_HANGUP -> CS_REPORTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_REPORTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:624@132.101.16.24:5060 Standard REPORTING, cause: NO_USER_RESPONSE ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING going to sleep ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_REPORTING -> CS_DESTROY ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_session.c:1415 Session 5700 (sofia/internal/sip:624@132.101.16.24:5060) Locked, Waiting on external entities ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [NOTICE] switch_core_session.c:1433 Session 5700 (sofia/internal/sip:624@132.101.16.24:5060) Ended ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/sip:624@132.101.16.24:5060 [CS_DESTROY] ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change HANGUP -> DOWN 2012-11-05 20:38:41.258623 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Waiting ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_DESTROY ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] mod_sofia.c:376 sofia/internal/sip:624@132.101.16.24:5060 SOFIA DESTROY ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:624@132.101.16.24:5060 Standard DESTROY ebbcda11-e628-4fb4-a8c5-653b9c35f54e 2012-11-05 20:38:41.258623 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY going to sleep d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.298620 [DEBUG] switch_core_session.c:1042 Send signal sofia/orange/022256999@192.168.0.5:5061 [BREAK] 2012-11-05 20:38:41.308625 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Receiving 2012-11-05 20:38:41.308625 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.308625 [DEBUG] switch_ivr_originate.c:2433 Parsing session specific variables 2012-11-05 20:38:41.308625 [DEBUG] switch_event.c:1570 Parsing variable [call_timeout]=[10] 2012-11-05 20:38:41.308625 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.308625 [DEBUG] switch_event.c:1570 Parsing variable [sip_invite_domain]=[pbx01.domain.md] 2012-11-05 20:38:41.308625 [DEBUG] switch_event.c:1570 Parsing variable [presence_id]=[624@pbx01.domain.md] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [NOTICE] switch_channel.c:951 New Channel sofia/internal/sip:624@132.101.16.24:5060 [b6eb501f-10c0-4138-ac95-51bc5abc572f] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] mod_sofia.c:4880 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_NEW -> CS_INIT b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_session.c:490 sofia/internal/sip:624@132.101.16.24:5060 set UUID=b6eb501f-10c0-4138-ac95-51bc5abc572f b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_INIT b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] mod_sofia.c:86 sofia/internal/sip:624@132.101.16.24:5060 SOFIA INIT b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] sofia_glue.c:2637 Local SDP: b6eb501f-10c0-4138-ac95-51bc5abc572f v=0 b6eb501f-10c0-4138-ac95-51bc5abc572f o=FreeSWITCH 1352117743 1352117744 IN IP4 132.101.0.58 b6eb501f-10c0-4138-ac95-51bc5abc572f s=FreeSWITCH b6eb501f-10c0-4138-ac95-51bc5abc572f c=IN IP4 132.101.0.58 b6eb501f-10c0-4138-ac95-51bc5abc572f t=0 0 b6eb501f-10c0-4138-ac95-51bc5abc572f m=audio 22978 RTP/AVP 98 9 0 8 3 101 13 b6eb501f-10c0-4138-ac95-51bc5abc572f a=rtpmap:98 SPEEX/32000 b6eb501f-10c0-4138-ac95-51bc5abc572f a=rtpmap:101 telephone-event/8000 b6eb501f-10c0-4138-ac95-51bc5abc572f a=fmtp:101 0-16 b6eb501f-10c0-4138-ac95-51bc5abc572f a=ptime:20 b6eb501f-10c0-4138-ac95-51bc5abc572f a=sendrecv b6eb501f-10c0-4138-ac95-51bc5abc572f b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] mod_sofia.c:126 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_INIT -> CS_ROUTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT going to sleep b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_ROUTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_channel.c:1964 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change DOWN -> RINGING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] mod_sofia.c:149 sofia/internal/sip:624@132.101.16.24:5060 SOFIA ROUTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING going to sleep b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_CONSUME_MEDIA b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA going to sleep b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.308625 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [calling][0] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.348625 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [terminated][480] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_channel.c:2950 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change RINGING -> HANGUP b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [NOTICE] sofia.c:7108 Hangup sofia/internal/sip:624@132.101.16.24:5060 [CS_CONSUME_MEDIA] [NO_USER_RESPONSE] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/sip:624@132.101.16.24:5060 [KILL] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_HANGUP 2012-11-05 20:38:41.358620 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] 2012-11-05 20:38:41.358620 [NOTICE] switch_ivr_originate.c:2599 Cannot create outgoing channel of type [user] cause: [NO_USER_RESPONSE] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP 2012-11-05 20:38:41.358620 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] mod_sofia.c:483 Channel sofia/internal/sip:624@132.101.16.24:5060 hanging up, cause: NO_USER_RESPONSE d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.358620 [DEBUG] mod_callcenter.c:1728 Agent 624@pbx01.domain.md Origination Canceled : NO_USER_RESPONSE b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:624@132.101.16.24:5060 Standard HANGUP, cause: NO_USER_RESPONSE b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP going to sleep b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_HANGUP -> CS_REPORTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_REPORTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:624@132.101.16.24:5060 Standard REPORTING, cause: NO_USER_RESPONSE b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING going to sleep b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_REPORTING -> CS_DESTROY b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_session.c:1415 Session 5701 (sofia/internal/sip:624@132.101.16.24:5060) Locked, Waiting on external entities b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [NOTICE] switch_core_session.c:1433 Session 5701 (sofia/internal/sip:624@132.101.16.24:5060) Ended b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/sip:624@132.101.16.24:5060 [CS_DESTROY] b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change HANGUP -> DOWN b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_DESTROY b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] mod_sofia.c:376 sofia/internal/sip:624@132.101.16.24:5060 SOFIA DESTROY b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:624@132.101.16.24:5060 Standard DESTROY b6eb501f-10c0-4138-ac95-51bc5abc572f 2012-11-05 20:38:41.358620 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY going to sleep 2012-11-05 20:38:41.358620 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Waiting 2012-11-05 20:38:41.408622 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Receiving 2012-11-05 20:38:41.408622 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.408622 [DEBUG] switch_ivr_originate.c:2433 Parsing session specific variables 2012-11-05 20:38:41.408622 [DEBUG] switch_event.c:1570 Parsing variable [call_timeout]=[10] 2012-11-05 20:38:41.408622 [DEBUG] switch_ivr_originate.c:2013 Parsing global variables 2012-11-05 20:38:41.408622 [DEBUG] switch_event.c:1570 Parsing variable [sip_invite_domain]=[pbx01.domain.md] 2012-11-05 20:38:41.408622 [DEBUG] switch_event.c:1570 Parsing variable [presence_id]=[624@pbx01.domain.md] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [NOTICE] switch_channel.c:951 New Channel sofia/internal/sip:624@132.101.16.24:5060 [b00f1fc8-c252-48d2-9065-8124d137d16c] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] mod_sofia.c:4880 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_NEW -> CS_INIT b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_session.c:490 sofia/internal/sip:624@132.101.16.24:5060 set UUID=b00f1fc8-c252-48d2-9065-8124d137d16c b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_INIT b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] mod_sofia.c:86 sofia/internal/sip:624@132.101.16.24:5060 SOFIA INIT b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] sofia_glue.c:2637 Local SDP: b00f1fc8-c252-48d2-9065-8124d137d16c v=0 b00f1fc8-c252-48d2-9065-8124d137d16c o=FreeSWITCH 1352123977 1352123978 IN IP4 132.101.0.58 b00f1fc8-c252-48d2-9065-8124d137d16c s=FreeSWITCH b00f1fc8-c252-48d2-9065-8124d137d16c c=IN IP4 132.101.0.58 b00f1fc8-c252-48d2-9065-8124d137d16c t=0 0 b00f1fc8-c252-48d2-9065-8124d137d16c m=audio 16744 RTP/AVP 98 9 0 8 3 101 13 b00f1fc8-c252-48d2-9065-8124d137d16c a=rtpmap:98 SPEEX/32000 b00f1fc8-c252-48d2-9065-8124d137d16c a=rtpmap:101 telephone-event/8000 b00f1fc8-c252-48d2-9065-8124d137d16c a=fmtp:101 0-16 b00f1fc8-c252-48d2-9065-8124d137d16c a=ptime:20 b00f1fc8-c252-48d2-9065-8124d137d16c a=sendrecv b00f1fc8-c252-48d2-9065-8124d137d16c b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] mod_sofia.c:126 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_INIT -> CS_ROUTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:624@132.101.16.24:5060) State INIT going to sleep b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_ROUTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_channel.c:1964 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change DOWN -> RINGING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] mod_sofia.c:149 sofia/internal/sip:624@132.101.16.24:5060 SOFIA ROUTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:624@132.101.16.24:5060) State ROUTING going to sleep b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_CONSUME_MEDIA b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:624@132.101.16.24:5060) State CONSUME_MEDIA going to sleep b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.408622 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [calling][0] d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.418617 [DEBUG] switch_ivr.c:605 sofia/orange/022256999@192.168.0.5:5061 Command Execute phrase(queue-position,1) d7a61a90-f498-41be-9017-0c821157e1e1 EXECUTE sofia/orange/022256999@192.168.0.5:5061 phrase(queue-position,1) d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.418617 [DEBUG] mod_dptools.c:2507 Execute queue-position(1) lang d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.418617 [DEBUG] switch_ivr_play_say.c:67 No language specified - Using [ro] d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.428626 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ro/queue-youarenext.wav] (ro:ro) d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.428626 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16@8000hz 1 channels 20ms b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] sofia.c:6308 Channel sofia/internal/sip:624@132.101.16.24:5060 entering state [terminated][480] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_channel.c:2950 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change RINGING -> HANGUP b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [NOTICE] sofia.c:7108 Hangup sofia/internal/sip:624@132.101.16.24:5060 [CS_CONSUME_MEDIA] [NO_USER_RESPONSE] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/sip:624@132.101.16.24:5060 [KILL] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_HANGUP b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] mod_sofia.c:483 Channel sofia/internal/sip:624@132.101.16.24:5060 hanging up, cause: NO_USER_RESPONSE 2012-11-05 20:38:41.458617 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] 2012-11-05 20:38:41.458617 [NOTICE] switch_ivr_originate.c:2599 Cannot create outgoing channel of type [user] cause: [NO_USER_RESPONSE] 2012-11-05 20:38:41.458617 [DEBUG] switch_ivr_originate.c:3516 Originate Resulted in Error Cause: 18 [NO_USER_RESPONSE] d7a61a90-f498-41be-9017-0c821157e1e1 2012-11-05 20:38:41.458617 [DEBUG] mod_callcenter.c:1728 Agent 624@pbx01.domain.md Origination Canceled : NO_USER_RESPONSE b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:624@132.101.16.24:5060 Standard HANGUP, cause: NO_USER_RESPONSE b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:624@132.101.16.24:5060) State HANGUP going to sleep b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_HANGUP -> CS_REPORTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_REPORTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:624@132.101.16.24:5060 Standard REPORTING, cause: NO_USER_RESPONSE b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:720 (sofia/internal/sip:624@132.101.16.24:5060) State REPORTING going to sleep b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:624@132.101.16.24:5060) State Change CS_REPORTING -> CS_DESTROY b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:624@132.101.16.24:5060 [BREAK] b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_session.c:1415 Session 5702 (sofia/internal/sip:624@132.101.16.24:5060) Locked, Waiting on external entities b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [NOTICE] switch_core_session.c:1433 Session 5702 (sofia/internal/sip:624@132.101.16.24:5060) Ended b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/sip:624@132.101.16.24:5060 [CS_DESTROY] 2012-11-05 20:38:41.458617 [DEBUG] mod_callcenter.c:1049 Updated Agent 624@pbx01.domain.md set state = Waiting b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:624@132.101.16.24:5060) Callstate Change HANGUP -> DOWN b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/sip:624@132.101.16.24:5060) Running State Change CS_DESTROY b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] mod_sofia.c:376 sofia/internal/sip:624@132.101.16.24:5060 SOFIA DESTROY b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:624@132.101.16.24:5060 Standard DESTROY b00f1fc8-c252-48d2-9065-8124d137d16c 2012-11-05 20:38:41.458617 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:624@132.101.16.24:5060) State DESTROY going to sleep -- Mimiko desu.