[Freeswitch-users] Outbound call not reaching destination - target on TLS

Michal Borkowski - MORCOM morcom at wiwat.pl
Fri Jan 31 20:59:27 MSK 2014


Hi,

I manage to solve most of the issues with FreeSwitch.
One main left only.....

I have mobile phone which is using CSipSimple

All on FreeSwitch set up and I can register the mobile with my extension.
I can call all destinations from the mobile (This is using TLS with all
security settings)
but I can not call that mobile. I was testing various codec sets in
CSipSimple - but nothing helped.
There must be something more.
I'm getting the error message that destination is incompatible.
Maybe looking to the log files sb would know the source of issue?
Sorry for long log....

=======

=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:michalb at 62.140.132.18:4203) State HANGUP going to sleep
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:michalb at 62.140.132.18:4203 Standard HANGUP, cause:
INCOMPATIBLE_DESTINATION
=> 2014-01-31 18:12:41.230255 [DEBUG] mod_sofia.c:506 Channel
sofia/internal/sip:michalb at 62.140.132.18:4203 hanging up, cause:
INCOMPATIBLE_DESTINATION
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:michalb at 62.140.132.18:4203) State HANGUP
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:michalb at 62.140.132.18:4203) Running State Change
CS_HANGUP
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_channel.c:3184 Send signal
sofia/internal/sip:michalb at 62.140.132.18:4203 [KILL]
=> 2014-01-31 18:12:41.230255 [NOTICE] sofia.c:6629 Hangup sofia/internal/
sip:michalb at 62.140.132.18:4203 [CS_CONSUME_MEDIA]
[INCOMPATIBLE_DESTINATION]
=> 2014-01-31 18:12:41.230255 [DEBUG] sofia.c:5785 Channel sofia/internal/
sip:michalb at 62.140.132.18:4203 entering state [terminated][488]
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:41.230255 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:michalb at 62.140.132.18:4203) State CONSUME_MEDIA going
to sleep
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:michalb at 62.140.132.18:4203) State CONSUME_MEDIA
=> 2014-01-31 18:12:38.600281 [DEBUG] sofia.c:5785 Channel sofia/internal/
sip:michalb at 62.140.132.18:4203 entering state [calling][0]
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:michalb at 62.140.132.18:4203) Running State Change
CS_CONSUME_MEDIA
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:michalb at 62.140.132.18:4203) State ROUTING going to
sleep
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:michalb at 62.140.132.18:4203) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
=> 2014-01-31 18:12:38.600281 [DEBUG] mod_sofia.c:150 sofia/internal/
sip:michalb at 62.140.132.18:4203 SOFIA ROUTING
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:michalb at 62.140.132.18:4203) State ROUTING
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:michalb at 62.140.132.18:4203) Running State Change
CS_ROUTING
=> 2014-01-31 18:12:38.600281 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:michalb at 62.140.132.18:4203) State INIT going to sleep
=> 2014-01-31 18:12:38.590255 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:38.590255 [DEBUG] mod_sofia.c:127 (sofia/internal/
sip:michalb at 62.140.132.18:4203) State Change CS_INIT -> CS_ROUTING
=>
=> a=sendrecv
=> a=ptime:20
=> a=fmtp:101 0-16
=> a=rtpmap:101 telephone-event/8000
=> a=fmtp:100 bitrate=48000
=> a=rtpmap:100 G7221/32000
=> a=fmtp:99 mode=30
=> a=rtpmap:99 iLBC/8000
=> a=rtpmap:98 SPEEX/8000
=> m=audio 28466 RTP/AVP 8 0 98 99 3 100 9 101 13
=> t=0 0
=> c=IN IP4 XXX.XXX.XXX.XXX
=> s=FreeSWITCH
=> o=FreeSWITCH 1391159892 1391159893 IN IP4 XXX.XXX.XXX.XXX
=> v=0
=> Local SDP:
=> 2014-01-31 18:12:38.590255 [DEBUG] sofia_glue.c:2738 sofia/internal/
sip:michalb at 62.140.132.18:4203 sending invite version: 1.2.18 git f6cd294
2014-01-29 16:39:03Z 32bit
=> 2014-01-31 18:12:38.590255 [DEBUG] sofia_glue.c:2710
sip:michalb at 62.140.132.18:4203;transport=TLS;ob Setting proxy route to
sofia/internal/sip:michalb at 62.140.132.18:4203
2014-01-31 18:12:38.590255 [DEBUG] sofia_glue.c:1093 STUN Success
[XXX.XXX.XXX.XXX]:[28466]
2014-01-31 18:12:38.260275 [INFO] switch_nat.c:590 NAT port mapping
disabled
2014-01-31 18:12:38.260275 [INFO] switch_nat.c:590 NAT port mapping
disabled
=> 2014-01-31 18:12:38.260275 [DEBUG] mod_sofia.c:87 sofia/internal/
sip:michalb at 62.140.132.18:4203 SOFIA INIT
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:michalb at 62.140.132.18:4203) State INIT
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:michalb at 62.140.132.18:4203) Running State Change
CS_INIT
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_ivr_originate.c:2782
sofia/internal/sip:michalb at 62.140.132.18:4203 Setting leg timeout to 30
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:michalb at 62.140.132.18:4203 [BREAK]
=> 2014-01-31 18:12:38.260275 [DEBUG] mod_sofia.c:5231 (sofia/internal/
sip:michalb at 62.140.132.18:4203) State Change CS_NEW -> CS_INIT
=> 2014-01-31 18:12:38.260275 [NOTICE] switch_channel.c:1052 New Channel
sofia/internal/sip:michalb at 62.140.132.18:4203 [=>]
2014-01-31 18:12:38.260275 [DEBUG] switch_event.c:1661 Parsing variable
[presence_id]=[michalb at 192.168.1.30]
2014-01-31 18:12:38.260275 [DEBUG] switch_event.c:1661 Parsing variable
[leg_timeout]=[30]
2014-01-31 18:12:38.260275 [DEBUG] switch_event.c:1661 Parsing variable
[sip_invite_domain]=[192.168.1.30]
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_ivr_originate.c:2069 Parsing
global variables
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars] [dialed_extension]=[1001] to event
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars]
[origination_callee_id_name]=[1001] to event
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars] [domain_name]=[192.168.1.30] to
event
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_ivr_originate.c:2069 Parsing
global variables
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars] [dialed_extension]=[1001] to event
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars]
[origination_callee_id_name]=[1001] to event
=> 2014-01-31 18:12:38.260275 [DEBUG] switch_channel.c:1198 sofia/internal/
lith at 192.168.1.30 EXPORTING[export_vars] [domain_name]=[192.168.1.30] to
event
=> EXECUTE sofia/internal/lith at 192.168.1.30 bridge(user/michalb at 192.168.1.30
)
=> EXECUTE sofia/internal/lith at 192.168.1.30hash(insert/192.168.1.30-last_dial//=>)
=> 2014-01-31 18:12:38.260275 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [called_party_call_group]=[UNDEF]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(called_party_call_group=)
=> EXECUTE sofia/internal/lith at 192.168.1.30hash(insert/192.168.1.30-last_dial_ext/1001/=>)
=> EXECUTE sofia/internal/lith at 192.168.1.30hash(insert/192.168.1.30-call_return/1001/lith)
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [continue_on_fail]=[true]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(continue_on_fail=true)
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [hangup_after_bridge]=[true]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(hangup_after_bridge=true)
=> 2014-01-31 18:12:38.250273 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*4 execute_extension::att_xfer XML features
=> EXECUTE sofia/internal/lith at 192.168.1.30 bind_meta_app(4 b s
execute_extension::att_xfer XML features)
=> 2014-01-31 18:12:38.250273 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*3 execute_extension::cf XML features
=> EXECUTE sofia/internal/lith at 192.168.1.30 bind_meta_app(3 b s
execute_extension::cf XML features)
=> 2014-01-31 18:12:38.250273 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*2
record_session::/usr/local/freeswitch/recordings/archive/2014/Jan/31/=>.wav
=> 2014-01-31 18:12:38.250273 [INFO] switch_ivr_async.c:3693 Bound A-Leg:
*2
record_session::/usr/local/freeswitch/recordings/archive/2014/Jan/31/=>.wav
=> EXECUTE sofia/internal/lith at 192.168.1.30 bind_meta_app(2 ab s
record_session::/usr/local/freeswitch/recordings/archive/2014/Jan/31/=>.wav)
=> 2014-01-31 18:12:38.250273 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*1 execute_extension::dx XML features
=> EXECUTE sofia/internal/lith at 192.168.1.30 bind_meta_app(1 b s
execute_extension::dx XML features)
=> 2014-01-31 18:12:38.250273 [INFO] mod_hash.c:202 Usage for
192.168.1.30_1001 is now 1/5
=> 2014-01-31 18:12:38.250273 [INFO] switch_limit.c:126 incr called:
192.168.1.30_1001 max:5, interval:0
=> EXECUTE sofia/internal/lith at 192.168.1.30 limit(hash 192.168.1.30 1001 5
)
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_channel.c:1244 EXPORT
(export_vars) [dialed_extension]=[1001]
=> EXECUTE sofia/internal/lith at 192.168.1.30 export(dialed_extension=1001)
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [dialed_extension]=[1001]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(dialed_extension=1001)
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [RFC2822_DATE]=[Fri, 31 Jan 2014 18:12:38 +0100]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(RFC2822_DATE=Fri, 31 Jan
2014 18:12:38 +0100)
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_channel.c:1244 EXPORT
(export_vars) [origination_callee_id_name]=[1001]
=> EXECUTE sofia/internal/lith at 192.168.1.30export(origination_callee_id_name=1001)
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_dptools.c:1402 sofia/internal/
lith at 192.168.1.30 SET [call_direction]=[local]
=> EXECUTE sofia/internal/lith at 192.168.1.30 set(call_direction=local)
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_state_machine.c:209
sofia/internal/lith at 192.168.1.30 Standard EXECUTE
=> 2014-01-31 18:12:38.250273 [DEBUG] mod_sofia.c:243 sofia/internal/
lith at 192.168.1.30 SOFIA EXECUTE
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_state_machine.c:478
(sofia/internal/lith at 192.168.1.30) State EXECUTE
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/lith at 192.168.1.30) Running State Change CS_EXECUTE
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/lith at 192.168.1.30) State ROUTING going to sleep
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/lith at 192.168.1.30 [BREAK]
=> 2014-01-31 18:12:38.250273 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/lith at 192.168.1.30) State Change CS_ROUTING -> CS_EXECUTE

======

And  - the remote clients are using TLS/SRTP/ZRTP (only on mobile phones)


Any idea why the mobile can not be reached?

Thanks in advance....

Michal
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140131/433ba05a/attachment-0001.html 


Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users mailing list