[Freeswitch-users] Unable to call cisco from freeswitch/blubox

Sean Devoy sdevoy at bizfocused.com
Sat Mar 10 00:22:46 MSK 2012 

Hi Robbie,

 

I am no expert, but I can help move this along some.  The first error is
"2012-03-09 08:05:13.421692 [ERR] mod_sofia.c:3738 Invalid Gateway" which is
from the dial plan statement "bridge(sofia/gateway/trunk_1/${prepend}4000)"

 

FS doesn't seem to know what "trunk_1" is.  I had this and resolved it on my
FS (although it was to a VOIP provider gateway).  In your SIP configuration
(where you define things like port 5060) you must have a <gateways>
</gateways> section that must contain a <gateway name="trunk_1"></gateway>
entity.  Working out the params and variables for your gateway I cannot help
as I don't know call manager at all.

 

I had not defined my gateway WITHIN a sip interface, so FS didn't really
know how to get to it.  If you have it defined, you should see it in
./fs_cli with a "sofia status" command.

 

Hope that helps some.

 

Sean

 

 

From: Robbie A. Garrett [mailto:rgarrett at garrettnet.net] 
Sent: Friday, March 09, 2012 11:09 AM
To: freeswitch-users at lists.freeswitch.org
Subject: [Freeswitch-users] Unable to call cisco from freeswitch/blubox

 

Hi All,

 

My home use lab uses cisco call manager 8.0. My old setup was cisco call
manager to asterisk and then to google voice.  Since asterisk and google
voice are now broken; I'm looking to move in the direction of free switch. 

 

Currently My cisco call manager can call any extension on free switch and
leave voicemail's. When I add google talk to frees witch I'm able to call
from my cisco VoIP phone, through free switch, and to google.

 

My issue is that free switch is unable to call my cisco call manager.  Below
is an output of the log of a call from extension 2002 to extension 4000.
>From what I can tell is that free-switch is not even trying to talk to
10.0.1.99 (my call manger).  It's failing before it gets that far.

 

 

 

 

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:4353 Audio Codec Compare
[PCMU:0:8000:0:64000]/[G7221:115:32000:20:48000]

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:4353 Audio Codec Compare
[PCMU:0:8000:0:64000]/[G7221:107:16000:20:32000]

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:4353 Audio Codec Compare
[PCMU:0:8000:0:64000]/[G722:9:8000:20:64000]

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:4353 Audio Codec Compare
[PCMU:0:8000:0:64000]/[PCMU:0:8000:20:64000]

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:2721 Set Codec
sofia/sipinterface_1/peter_gibbons at bluebox PCMU/8000 20 ms 160 samples 64000
bits

2012-03-09 08:05:13.418262 [DEBUG] sofia_glue.c:4457 Set 2833 dtmf send/recv
payload to 101

2012-03-09 08:05:13.418262 [DEBUG] sofia.c:4732
(sofia/sipinterface_1/peter_gibbons at bluebox) State Change CS_NEW -> CS_INIT

2012-03-09 08:05:13.418262 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:318
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change CS_INIT

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:342
(sofia/sipinterface_1/peter_gibbons at bluebox) State INIT

2012-03-09 08:05:13.419735 [DEBUG] mod_sofia.c:83
sofia/sipinterface_1/peter_gibbons at bluebox SOFIA INIT

2012-03-09 08:05:13.419735 [DEBUG] mod_sofia.c:123
(sofia/sipinterface_1/peter_gibbons at bluebox) State Change CS_INIT ->
CS_ROUTING

2012-03-09 08:05:13.419735 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:342
(sofia/sipinterface_1/peter_gibbons at bluebox) State INIT going to sleep

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:318
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change CS_ROUTING

2012-03-09 08:05:13.419735 [DEBUG] switch_channel.c:1615
(sofia/sipinterface_1/peter_gibbons at bluebox) Callstate Change DOWN ->
RINGING

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:345
(sofia/sipinterface_1/peter_gibbons at bluebox) State ROUTING

2012-03-09 08:05:13.419735 [DEBUG] mod_sofia.c:146
sofia/sipinterface_1/peter_gibbons at bluebox SOFIA ROUTING

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:77
sofia/sipinterface_1/peter_gibbons at bluebox Standard ROUTING

2012-03-09 08:05:13.419735 [INFO] mod_dialplan_xml.c:331 Processing
peter_gibbons <peter_gibbons>->4000 in context context_1

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->conditioning_callerid] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (PASS)
[conditioning_callerid] ${internal_caller_id_number}(2002) =~ /^.+$/
break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(effective_caller_id_name=${internal_caller_id_name}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(effective_caller_id_number=${internal_caller_id_number}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->postroute_global] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Absolute Condition
[postroute_global]

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_numbe
r}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
hash(insert/${domain_name}-last_dial/global/${uuid}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->preanswer_gtalk] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[preanswer_gtalk] source(mod_sofia) =~ /^mod_dingaling$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_trunk_1_pattern_5] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (PASS)
[main_trunk_1_pattern_5] destination_number(4000) =~ /^(40[0-9]{2})$/
break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action set(prepend=) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (PASS)
[main_trunk_1_pattern_5] ${outbound_caller_id_number}(5555552002) =~ /^.+$/
break=never

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(effective_caller_id_name=${outbound_caller_id_name}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(effective_caller_id_number=${outbound_caller_id_number}) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
export(sip_cid_type=rpid) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (PASS)
[main_trunk_1_pattern_5] destination_number(4000) =~ /^(40[0-9]{2})$/
break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
set(failure_causes=NORMAL_CLEARING,ORIGINATOR_CANCEL,CRASH) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Action
bridge(sofia/gateway/trunk_1/${prepend}4000) 

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_6] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_6] destination_number(4000) =~ /^2006$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_5] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_5] destination_number(4000) =~ /^2005$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_4] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_4] destination_number(4000) =~ /^2004$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_3] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_3] destination_number(4000) =~ /^2003$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_2] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_2] destination_number(4000) =~ /^2002$/ break=on-false

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox parsing
[context_1->main_number_1] continue=true

Dialplan: sofia/sipinterface_1/peter_gibbons at bluebox Regex (FAIL)
[main_number_1] destination_number(4000) =~ /^2001$/ break=on-false

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:119
(sofia/sipinterface_1/peter_gibbons at bluebox) State Change CS_ROUTING ->
CS_EXECUTE

2012-03-09 08:05:13.419735 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:345
(sofia/sipinterface_1/peter_gibbons at bluebox) State ROUTING going to sleep

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:318
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change CS_EXECUTE

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:352
(sofia/sipinterface_1/peter_gibbons at bluebox) State EXECUTE

2012-03-09 08:05:13.419735 [DEBUG] mod_sofia.c:239
sofia/sipinterface_1/peter_gibbons at bluebox SOFIA EXECUTE

2012-03-09 08:05:13.419735 [DEBUG] switch_core_state_machine.c:157
sofia/sipinterface_1/peter_gibbons at bluebox Standard EXECUTE

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
set(effective_caller_id_name=Peter Gibbons)

2012-03-09 08:05:13.419735 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET
[effective_caller_id_name]=[Peter Gibbons]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
set(effective_caller_id_number=2002)

2012-03-09 08:05:13.419735 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET
[effective_caller_id_number]=[2002]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
hash(insert/10.0.1.3-spymap/peter_gibbons/bc1115e3-b592-454c-8813-a6a7fb2754
d4)

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
hash(insert/10.0.1.3-last_dial/peter_gibbons/4000)

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
hash(insert/10.0.1.3-last_dial/global/bc1115e3-b592-454c-8813-a6a7fb2754d4)

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox set(RFC2822_DATE=Fri, 09
Mar 2012 08:05:13 -0800)

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET [RFC2822_DATE]=[Fri, 09 Mar
2012 08:05:13 -0800]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox set(prepend=)

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET [prepend]=[UNDEF]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
set(effective_caller_id_name=Peter Gibbons)

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET
[effective_caller_id_name]=[Peter Gibbons]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
set(effective_caller_id_number=5555552002)

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET
[effective_caller_id_number]=[5555552002]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox export(sip_cid_type=rpid)

2012-03-09 08:05:13.421692 [DEBUG] switch_channel.c:933 EXPORT (export_vars)
[sip_cid_type]=[rpid]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
set(failure_causes=NORMAL_CLEARING,ORIGINATOR_CANCEL,CRASH)

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:1028
sofia/sipinterface_1/peter_gibbons at bluebox SET
[failure_causes]=[NORMAL_CLEARING,ORIGINATOR_CANCEL,CRASH]

EXECUTE sofia/sipinterface_1/peter_gibbons at bluebox
bridge(sofia/gateway/trunk_1/4000)

2012-03-09 08:05:13.421692 [DEBUG] switch_channel.c:890
sofia/sipinterface_1/peter_gibbons at bluebox EXPORTING[export_vars]
[sip_cid_type]=[rpid] to event

2012-03-09 08:05:13.421692 [ERR] mod_sofia.c:3738 Invalid Gateway

2012-03-09 08:05:13.421692 [NOTICE] mod_sofia.c:4060 Close Channel N/A
[CS_NEW]

2012-03-09 08:05:13.421692 [DEBUG] switch_core_state_machine.c:434 ()
Running State Change CS_DESTROY

2012-03-09 08:05:13.421692 [DEBUG] switch_core_state_machine.c:444 (N/A)
State DESTROY

2012-03-09 08:05:13.421692 [DEBUG] mod_sofia.c:361 N/A SOFIA DESTROY

2012-03-09 08:05:13.421692 [DEBUG] switch_core_state_machine.c:444 (N/A)
State DESTROY going to sleep

2012-03-09 08:05:13.421692 [ERR] switch_ivr_originate.c:2605 Cannot create
outgoing channel of type [sofia] cause: [INVALID_NUMBER_FORMAT]

2012-03-09 08:05:13.421692 [DEBUG] switch_ivr_originate.c:3413 Originate
Resulted in Error Cause: 28 [INVALID_NUMBER_FORMAT]

2012-03-09 08:05:13.421692 [INFO] mod_dptools.c:2579 Originate Failed.
Cause: INVALID_NUMBER_FORMAT

2012-03-09 08:05:13.421692 [DEBUG] mod_dptools.c:2610 Failure causes
[NORMAL_CLEARING,ORIGINATOR_CANCEL,CRASH]:  Cause: INVALID_NUMBER_FORMAT

2012-03-09 08:05:13.421692 [NOTICE] switch_core_state_machine.c:189
sofia/sipinterface_1/peter_gibbons at bluebox has executed the last dialplan
instruction, hanging up.

2012-03-09 08:05:13.421692 [DEBUG] switch_channel.c:2457
(sofia/sipinterface_1/peter_gibbons at bluebox) Callstate Change RINGING ->
HANGUP

2012-03-09 08:05:13.421692 [NOTICE] switch_core_state_machine.c:191 Hangup
sofia/sipinterface_1/peter_gibbons at bluebox [CS_EXECUTE] [NORMAL_CLEARING]

2012-03-09 08:05:13.421692 [DEBUG] switch_channel.c:2473 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [KILL]

2012-03-09 08:05:13.421692 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.421692 [DEBUG] switch_core_state_machine.c:352
(sofia/sipinterface_1/peter_gibbons at bluebox) State EXECUTE going to sleep

2012-03-09 08:05:13.421692 [DEBUG] switch_core_state_machine.c:318
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change CS_HANGUP

2012-03-09 08:05:13.423711 [DEBUG] switch_core_state_machine.c:539
(sofia/sipinterface_1/peter_gibbons at bluebox) State HANGUP

2012-03-09 08:05:13.423711 [DEBUG] mod_sofia.c:456 Channel
sofia/sipinterface_1/peter_gibbons at bluebox hanging up, cause:
NORMAL_CLEARING

2012-03-09 08:05:13.427318 [DEBUG] mod_sofia.c:518 Responding to INVITE
with: 480

2012-03-09 08:05:13.427318 [DEBUG] switch_core_state_machine.c:46
sofia/sipinterface_1/peter_gibbons at bluebox Standard HANGUP, cause:
NORMAL_CLEARING

2012-03-09 08:05:13.427318 [DEBUG] switch_core_state_machine.c:539
(sofia/sipinterface_1/peter_gibbons at bluebox) State HANGUP going to sleep

2012-03-09 08:05:13.427318 [DEBUG] switch_core_state_machine.c:337
(sofia/sipinterface_1/peter_gibbons at bluebox) State Change CS_HANGUP ->
CS_REPORTING

2012-03-09 08:05:13.427318 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.427318 [DEBUG] switch_core_state_machine.c:318
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change
CS_REPORTING

2012-03-09 08:05:13.427318 [DEBUG] switch_core_state_machine.c:599
(sofia/sipinterface_1/peter_gibbons at bluebox) State REPORTING

2012-03-09 08:05:13.586710 [DEBUG] switch_core_state_machine.c:53
sofia/sipinterface_1/peter_gibbons at bluebox Standard REPORTING, cause:
NORMAL_CLEARING

2012-03-09 08:05:13.586710 [DEBUG] switch_core_state_machine.c:599
(sofia/sipinterface_1/peter_gibbons at bluebox) State REPORTING going to sleep

2012-03-09 08:05:13.586710 [DEBUG] switch_core_state_machine.c:331
(sofia/sipinterface_1/peter_gibbons at bluebox) State Change CS_REPORTING ->
CS_DESTROY

2012-03-09 08:05:13.586710 [DEBUG] switch_core_session.c:1057 Send signal
sofia/sipinterface_1/peter_gibbons at bluebox [BREAK]

2012-03-09 08:05:13.586710 [DEBUG] switch_core_session.c:1224 Session 66
(sofia/sipinterface_1/peter_gibbons at bluebox) Locked, Waiting on external
entities

2012-03-09 08:05:13.586710 [NOTICE] switch_core_session.c:1242 Session 66
(sofia/sipinterface_1/peter_gibbons at bluebox) Ended

2012-03-09 08:05:13.586710 [NOTICE] switch_core_session.c:1244 Close Channel
sofia/sipinterface_1/peter_gibbons at bluebox [CS_DESTROY]

2012-03-09 08:05:13.588724 [DEBUG] switch_core_state_machine.c:431
(sofia/sipinterface_1/peter_gibbons at bluebox) Callstate Change HANGUP -> DOWN

2012-03-09 08:05:13.588724 [DEBUG] switch_core_state_machine.c:434
(sofia/sipinterface_1/peter_gibbons at bluebox) Running State Change CS_DESTROY

2012-03-09 08:05:13.588724 [DEBUG] switch_core_state_machine.c:444
(sofia/sipinterface_1/peter_gibbons at bluebox) State DESTROY

2012-03-09 08:05:13.588724 [DEBUG] mod_sofia.c:361
sofia/sipinterface_1/peter_gibbons at bluebox SOFIA DESTROY

2012-03-09 08:05:13.588724 [DEBUG] switch_core_state_machine.c:60
sofia/sipinterface_1/peter_gibbons at bluebox Standard DESTROY

2012-03-09 08:05:13.588724 [DEBUG] switch_core_state_machine.c:444
(sofia/sipinterface_1/peter_gibbons at bluebox) State DESTROY going to sleep

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20120309/3ee57e48/attachment-0001.html

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