Cannot Receive Incoming call [CS_NEW] [WRONG_CALL_STATE] Abandonded
Hello, i cannot figure out this problem. The incoming call is detailed by FS in Debug, but it doesn’t process throw DialPlan. Mi server IP is 165.227.33.23 and the incoming call is throw 64.34.236.149 as you can see. i get this behaviour: 0595a3c8 2018-01-04 12:18:14.294341 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/34600083765@64.34.236.149 [0595a3c8-a696-46b9-addd-0eb3a9f0a2a3] 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_NEW (Cur 4 Tot 2448) 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:9873 sofia/internal/34600083765@64.34.236.149 receiving invite from 64.34.236.149:5060 version: 1.6.19 -36-7a77e0b 64bit 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:10044 IP 64.34.236.149 Rejected by acl "domains". Falling back to Digest auth. nua_stack.c:573 nua_stack_signal() nua(0x7f3c180f5900): recv signal r_respond 407 Proxy Authentication Required 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/34600083765@64.34.236.149) State NEW send 858 bytes to udp/[64.34.236.149]:5060 at 12:18:14.306835: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 64.34.236.149:5060;branch=z9hG4bK6dcba8c3 From: "34600083765" <sip:34600083765@64.34.236.149>;tag=as134ae412 To: <sip:5508813053301091@165.227.33.23:5060>;tag=2HZXytpDN07tN Call-ID: 7d898457242fdb9e02387bd91238036b@64.34.236.149:5060 CSeq: 102 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="64.34.236.149", nonce="9e208456-94e6-4cff-9ed9-e4abcf1075aa", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (102) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f3c180f5900): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7f3c180f5900): call state changed: received -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f3c180f5900): event i_state 407 Proxy Authentication Required nua_stack.c:271 nua_stack_event() nua(0x7f3c180f5900): event i_terminated 407 Proxy Authentication Required 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:2334 detaching session 0595a3c8-a696-46b9-addd-0eb3a9f0a2a3 nua_stack.c:569 nua_stack_signal() nua(0x7f3c180f5900): recv signal r_destroy recv 437 bytes from udp/[64.34.236.149]:5060 at 12:18:14.318108: ------------------------------------------------------------------------ ACK sip:5508813053301091@165.227.33.23:5060 SIP/2.0 Via: SIP/2.0/UDP 64.34.236.149:5060;branch=z9hG4bK6dcba8c3 Max-Forwards: 70 From: "34600083765" <sip:34600083765@64.34.236.149>;tag=as134ae412 To: <sip:5508813053301091@165.227.33.23:5060>;tag=2HZXytpDN07tN Contact: <sip:34600083765@64.34.236.149:5060> Call-ID: 7d898457242fdb9e02387bd91238036b@64.34.236.149:5060 CSeq: 102 ACK User-Agent: Tech Call Flow Content-Length: 0 ------------------------------------------------------------------------ nta.c:2880 agent_recv_request() nta: received ACK sip:5508813053301091@165.227.33.23:5060 SIP/2.0 (CSeq 102) nta.c:3019 agent_recv_request() nta: ACK (102) is going to INVITE (102) nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/7 term, 1/8 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/7 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/5 term, 1/6 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/4 term, 1/5 free nta.c:7159 _nta_incoming_timer() nta: timer J fired, terminate 401 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/4 free nta.c:7159 _nta_incoming_timer() nta: timer J fired, terminate 403 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/3 free 6dcaead6 2018-01-04 12:18:20.814342 [WARNING] switch_core_state_machine.c:687 6dcaead6-8ea6-416a-8656-bca9ce8038a7 sofia/internal/34600083765@64.34.236.149 Abandoned 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/34600083765@64.34.236.149 [CS_NEW] [WRONG_CALL_STATE] 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_HANGUP (Cur 4 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/34600083765@64.34.236.149) Callstate Change DOWN -> HANGUP 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/34600083765@64.34.236.149) State HANGUP 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] mod_sofia.c:438 Channel sofia/internal/34600083765@64.34.236.149 hanging up, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:60 sofia/internal/34600083765@64.34.236.149 Standard HANGUP, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/34600083765@64.34.236.149) State HANGUP going to sleep 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/34600083765@64.34.236.149) State Change CS_HANGUP -> CS_REPORTING 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_REPORTING (Cur 4 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/34600083765@64.34.236.149) State REPORTING 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:174 sofia/internal/34600083765@64.34.236.149 Standard REPORTING, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/34600083765@64.34.236.149) State REPORTING going to sleep 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/34600083765@64.34.236.149) State Change CS_REPORTING -> CS_DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_session.c:1665 Session 2445 (sofia/internal/34600083765@64.34.236.149) Locked, Waiting on external entities 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_session.c:1683 Session 2445 (sofia/internal/34600083765@64.34.236.149) Ended 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/34600083765@64.34.236.149 [CS_DESTROY] 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_DESTROY (Cur 3 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/34600083765@64.34.236.149) State DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] mod_sofia.c:343 sofia/internal/34600083765@64.34.236.149 SOFIA DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:181 sofia/internal/34600083765@64.34.236.149 Standard DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/34600083765@64.34.236.149) State DESTROY going to sleep
From what I can see you are probably receiving the call at the "internal" sip profile (port 5060). That profile requires authentication for incoming calls. You would better receive the call at the "external" profile (port 5080), which purposeful do not ask for authentication for incoming calls.
Bottom line: configure your provider (or ask them) to send you calls at port 5080 (if the port is not specified, they will send the call to 5060, wrong port in your case). -giovanni On 4 January 2018 at 13:22, Raimundo Pérez Nieves < raimundo.perez.cuba@gmail.com> wrote:
Hello,
i cannot figure out this problem. The incoming call is detailed by FS in Debug, but it doesn’t process throw DialPlan. Mi server IP is 165.227.33.23 and the incoming call is throw 64.34.236.149 as you can see. i get this behaviour:
0595a3c8 2018-01-04 12:18:14.294341 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/34600083765@64.34.236.149 [0595a3c8-a696-46b9-addd- 0eb3a9f0a2a3] 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_NEW (Cur 4 Tot 2448) 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:9873 sofia/internal/ 34600083765@64.34.236.149 receiving invite from 64.34.236.149:5060 version: 1.6.19 -36-7a77e0b 64bit 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:10044 IP 64.34.236.149 Rejected by acl "domains". Falling back to Digest auth. nua_stack.c:573 nua_stack_signal() nua(0x7f3c180f5900): recv signal r_respond 407 Proxy Authentication Required 0595a3c8 2018-01-04 12:18:14.294341 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/34600083765@64.34.236.149) State NEW send 858 bytes to udp/[64.34.236.149]:5060 at 12:18:14.306835: ------------------------------------------------------------ ------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 64.34.236.149:5060;branch=z9hG4bK6dcba8c3 From: "34600083765" <sip:34600083765@64.34.236.149>;tag=as134ae412 To: <sip:5508813053301091@165.227.33.23:5060>;tag=2HZXytpDN07tN Call-ID: 7d898457242fdb9e02387bd91238036b@64.34.236.149:5060 CSeq: 102 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19-36-7a77e0b~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="64.34.236.149", nonce="9e208456-94e6-4cff-9ed9-e4abcf1075aa", algorithm=MD5, qop="auth" Content-Length: 0
------------------------------------------------------------ ------------ nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (102) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f3c180f5900): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7f3c180f5900): call state changed: received -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f3c180f5900): event i_state 407 Proxy Authentication Required nua_stack.c:271 nua_stack_event() nua(0x7f3c180f5900): event i_terminated 407 Proxy Authentication Required 2018-01-04 12:18:14.294341 [DEBUG] sofia.c:2334 detaching session 0595a3c8-a696-46b9-addd-0eb3a9f0a2a3 nua_stack.c:569 nua_stack_signal() nua(0x7f3c180f5900): recv signal r_destroy recv 437 bytes from udp/[64.34.236.149]:5060 at 12:18:14.318108: ------------------------------------------------------------ ------------ ACK sip:5508813053301091@165.227.33.23:5060 SIP/2.0 Via: SIP/2.0/UDP 64.34.236.149:5060;branch=z9hG4bK6dcba8c3 Max-Forwards: 70 From: "34600083765" <sip:34600083765@64.34.236.149>;tag=as134ae412 To: <sip:5508813053301091@165.227.33.23:5060>;tag=2HZXytpDN07tN Contact: <sip:34600083765@64.34.236.149:5060> Call-ID: 7d898457242fdb9e02387bd91238036b@64.34.236.149:5060 CSeq: 102 ACK User-Agent: Tech Call Flow Content-Length: 0
------------------------------------------------------------ ------------ nta.c:2880 agent_recv_request() nta: received ACK sip:5508813053301091@165.227.33.23:5060 SIP/2.0 (CSeq 102) nta.c:3019 agent_recv_request() nta: ACK (102) is going to INVITE (102) nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/7 term, 1/8 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/6 term, 1/7 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/5 term, 1/6 free nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/4 term, 1/5 free nta.c:7159 _nta_incoming_timer() nta: timer J fired, terminate 401 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/4 free nta.c:7159 _nta_incoming_timer() nta: timer J fired, terminate 403 response nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/3 free 6dcaead6 2018-01-04 12:18:20.814342 [WARNING] switch_core_state_machine.c:687 6dcaead6-8ea6-416a-8656-bca9ce8038a7 sofia/internal/34600083765@64. 34.236.149 Abandoned 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/34600083765@64.34.236.149 [CS_NEW] [WRONG_CALL_STATE] 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_HANGUP (Cur 4 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/34600083765@64.34.236.149) Callstate Change DOWN -> HANGUP 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/34600083765@64.34.236.149) State HANGUP 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] mod_sofia.c:438 Channel sofia/internal/34600083765@64.34.236.149 hanging up, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:60 sofia/internal/34600083765@64.34.236.149 Standard HANGUP, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/34600083765@64.34.236.149) State HANGUP going to sleep 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/34600083765@64.34.236.149) State Change CS_HANGUP -> CS_REPORTING 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_REPORTING (Cur 4 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/34600083765@64.34.236.149) State REPORTING 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:174 sofia/internal/34600083765@64.34.236.149 Standard REPORTING, cause: WRONG_CALL_STATE 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/34600083765@64.34.236.149) State REPORTING going to sleep 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/34600083765@64.34.236.149) State Change CS_REPORTING -> CS_DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_session.c:1665 Session 2445 (sofia/internal/34600083765@64.34.236.149) Locked, Waiting on external entities 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_session.c:1683 Session 2445 (sofia/internal/34600083765@64.34.236.149) Ended 6dcaead6 2018-01-04 12:18:20.814342 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/34600083765@64.34.236.149 [CS_DESTROY] 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/34600083765@64.34.236.149) Running State Change CS_DESTROY (Cur 3 Tot 2448) 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/34600083765@64.34.236.149) State DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] mod_sofia.c:343 sofia/internal/ 34600083765@64.34.236.149 SOFIA DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:181 sofia/internal/34600083765@64.34.236.149 Standard DESTROY 6dcaead6 2018-01-04 12:18:20.814342 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/34600083765@64.34.236.149) State DESTROY going to sleep
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Sincerely, Giovanni Maruzzelli OpenTelecom.IT cell: +39 347 266 56 18
participants (2)
-
Giovanni Maruzzelli
-
Raimundo Pérez Nieves