[Freeswitch-users] Intermittent 'NORMAL_UNSPECIFIED' errors when originating a call throug a gateway

Rafal Gwizdala rafal.gwizdala at gmail.com
Wed Jul 3 13:53:46 MSD 2013


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 at 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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130703/200d4a84/attachment-0001.html 


Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list