Meanwhile, I'm analyzing the logs myself and here's something that looks suspicious 2013-07-03 11:14:05.026852 [DEBUG] sofia_glue.c:1220 Local SDP: v=0 o=FreeSWITCH 1372826251 1372826252 IN IP4 *192.168.119.50* s=FreeSWITCH c=IN IP4 *192.168.119.50* t=0 0 m=audio 16594 RTP/AVP 0 8 3 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv In the SDP message there's a local freeswitch machine IP (192.168.119.50), but this IP is private, invisible to the outside world. The machine is in a DMZ, accessible through a public IP 89.75.189.46. So, maybe this is the problem - SDP information sent to the freeconet gateway contains an incorrect IP address for audio stream? If so, could you tell me how to configure a correct 'public' IP for FS? Thanks RG On Wed, Jul 3, 2013 at 11:23 AM, Rafal Gwizdala <rafal.gwizdala@gmail.com>wrote:
Hi, I'm trying to originate a call to an external endpoint (a mobile phone) through a gateway (freeconet.pl) service and I'm getting intermittent 'NORMAL_UNSPECIFIED' errors. The command will randomly succeed or fail with the following result.
originate {call_timeout=60,origination_uuid=d399361f-56a1-4c7c-acd8-447a6e1ea742}sofia/gateway/freeconet/ 602415455 6668 Event: FAILURE, Body: -ERR NORMAL_UNSPECIFIED
The destination extension (6668) is an IVR service based on mod_httapi, but I don't think this is related to my application as there are no httapi calls made. The 'freeconet' gateway is REGED. Corresponding freeswitch log is below. Can you please help me figure out what's going on?
Best regards Rafal
2013-07-03 11:14:05.016851 [DEBUG] switch_ivr_originate.c:2050 Parsing global variables 2013-07-03 11:14:05.016851 [DEBUG] switch_event.c:1617 Parsing variable [call_timeout]=[60] 2013-07-03 11:14:05.016851 [DEBUG] switch_event.c:1617 Parsing variable [origination_uuid]=[d399361f-56a1-4c7c-acd8-447a6e1ea742] 2013-07-03 11:14:05.016851 [NOTICE] switch_channel.c:1030 New Channel sofia/external/602415455 [d399361f-56a1-4c7c-acd8-447a6e1ea742] 2013-07-03 11:14:05.016851 [DEBUG] mod_sofia.c:4420 (sofia/external/ 602415455) State Change CS_NEW -> CS_INIT 2013-07-03 11:14:05.016851 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.016851 [DEBUG] switch_core_session.c:583 sofia/external/602415455 set UUID=d399361f-56a1-4c7c-acd8-447a6e1ea742 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:416 (sofia/external/602415455) Running State Change CS_INIT 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:455 (sofia/external/602415455) State INIT 2013-07-03 11:14:05.026852 [DEBUG] mod_sofia.c:87 sofia/external/602415455SOFIA INIT 2013-07-03 11:14:05.026852 [DEBUG] sofia_glue.c:1220 Local SDP: v=0 o=FreeSWITCH 1372826251 1372826252 IN IP4 192.168.119.50 s=FreeSWITCH c=IN IP4 192.168.119.50 t=0 0 m=audio 16594 RTP/AVP 0 8 3 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
2013-07-03 11:14:05.026852 [DEBUG] mod_sofia.c:114 (sofia/external/ 602415455) State Change CS_INIT -> CS_ROUTING 2013-07-03 11:14:05.026852 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:455 (sofia/external/602415455) State INIT going to sleep 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:416 (sofia/external/602415455) Running State Change CS_ROUTING 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:471 (sofia/external/602415455) State ROUTING 2013-07-03 11:14:05.026852 [DEBUG] mod_sofia.c:137 sofia/external/602415455 SOFIA ROUTING 2013-07-03 11:14:05.026852 [DEBUG] switch_ivr_originate.c:67 (sofia/external/602415455) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2013-07-03 11:14:05.026852 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:471 (sofia/external/602415455) State ROUTING going to sleep 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:416 (sofia/external/602415455) Running State Change CS_CONSUME_MEDIA 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:490 (sofia/external/602415455) State CONSUME_MEDIA 2013-07-03 11:14:05.026852 [DEBUG] switch_core_state_machine.c:490 (sofia/external/602415455) State CONSUME_MEDIA going to sleep 2013-07-03 11:14:05.036853 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.036853 [DEBUG] sofia.c:5764 Channel sofia/external/602415455 entering state [calling][0] 2013-07-03 11:14:05.096861 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.096861 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.096861 [DEBUG] sofia.c:5764 Channel sofia/external/602415455 entering state [calling][0] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] sofia.c:5764 Channel sofia/external/602415455 entering state [terminated][904] 2013-07-03 11:14:05.126865 [NOTICE] sofia.c:6572 Hangup sofia/external/602415455 [CS_CONSUME_MEDIA] [NORMAL_UNSPECIFIED] 2013-07-03 11:14:05.126865 [DEBUG] switch_channel.c:3135 Send signal sofia/external/602415455 [KILL] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:416 (sofia/external/602415455) Running State Change CS_HANGUP 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:679 (sofia/external/602415455) State HANGUP 2013-07-03 11:14:05.126865 [DEBUG] mod_sofia.c:463 Channel sofia/external/602415455 hanging up, cause: NORMAL_UNSPECIFIED 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:48 sofia/external/602415455 Standard HANGUP, cause: NORMAL_UNSPECIFIED 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:679 (sofia/external/602415455) State HANGUP going to sleep 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:692 (sofia/external/602415455) Callstate Change DOWN -> HANGUP 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:447 (sofia/external/602415455) State Change CS_HANGUP -> CS_REPORTING 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:416 (sofia/external/602415455) Running State Change CS_REPORTING 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:764 (sofia/external/602415455) State REPORTING 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:92 sofia/external/602415455 Standard REPORTING, cause: NORMAL_UNSPECIFIED 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:764 (sofia/external/602415455) State REPORTING going to sleep 2013-07-03 11:14:05.126865 [DEBUG] switch_core_state_machine.c:441 (sofia/external/602415455) State Change CS_REPORTING -> CS_DESTROY 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/602415455 [BREAK] 2013-07-03 11:14:05.126865 [DEBUG] switch_core_session.c:1549 Session 85 (sofia/external/602415455) Locked, Waiting on external entities 2013-07-03 11:14:05.146867 [DEBUG] switch_ivr_originate.c:3622 Originate Resulted in Error Cause: 31 [NORMAL_UNSPECIFIED] 2013-07-03 11:14:05.146867 [NOTICE] switch_core_session.c:1567 Session 85 (sofia/external/602415455) Ended 2013-07-03 11:14:05.146867 [NOTICE] switch_core_session.c:1571 Close Channel sofia/external/602415455 [CS_DESTROY] 2013-07-03 11:14:05.146867 [DEBUG] switch_core_state_machine.c:566 (sofia/external/602415455) Callstate Change HANGUP -> DOWN 2013-07-03 11:14:05.146867 [DEBUG] switch_core_state_machine.c:569 (sofia/external/602415455) Running State Change CS_DESTROY 2013-07-03 11:14:05.146867 [DEBUG] switch_core_state_machine.c:579 (sofia/external/602415455) State DESTROY 2013-07-03 11:14:05.146867 [DEBUG] mod_sofia.c:373 sofia/external/602415455 SOFIA DESTROY 2013-07-03 11:14:05.146867 [DEBUG] switch_core_state_machine.c:99 sofia/external/602415455 Standard DESTROY 2013-07-03 11:14:05.146867 [DEBUG] switch_core_state_machine.c:579 (sofia/external/602415455) State DESTROY going to sleep