August 2013 - FreeSWITCH-users - FreeSWITCH Mailing Lists

Freeswitch with Digium T316 timed out, T316 timed out,
by Rajat toshniwal 11 Aug '13

11 Aug '13

Hi I am trying to deploy freeswitch with Digium TE121 card for my office setup, but it is continuously showing Signaling is up and channels are down except D channel. Our Architecture is like We have freeswitch installed with libpri1.4 and Dahdi. I am from India and here we are having E1 trunk. Dahdi Configuration is cat system.conf # Autogenerated by /usr/sbin/dahdi_genconf on Wed Aug 7 19:39:07 2013 # If you edit this file and execute /usr/sbin/dahdi_genconf again, # your manual changes will be LOST. # Dahdi Configuration File # # This file is parsed by the Dahdi Configurator, dahdi_cfg # # Span 1: WCT1/0 "Wildcard TE121 Card 0" (MASTER) span=1,1,0,ccs,hdb3,crc4 # termtype: te bchan=1-15,17-31 dchan=16 echocanceller=mg2,1-15,17-31 # Global data loadzone = uk defaultzone = uk cat modules # Autogenerated by /usr/sbin/dahdi_genconf (Dahdi::Config::Gen::Modules) on Wed Aug 7 19:37:48 2013 # If you edit this file and execute /usr/sbin/dahdi_genconf again, # your manual changes will be LOST. wcte12xp # Xorcom Astribank Devices xpp_usb dahdi_hardware pci:0000:02:08.0 wcte12xp+ d161:8000 Wildcard TE121 dahdi_scan [1] active=yes alarms=OK description=Wildcard TE121 Card 0 name=WCT1/0 manufacturer=Digium devicetype=Wildcard TE121 (VPMOCT032) location=PCI Bus 02 Slot 09 basechan=1 totchans=31 irq=0 type=digital-E1 syncsrc=1 lbo=0 db (CSU)/0-133 feet (DSX-1) coding_opts=AMI,HDB3 framing_opts=CCS,CRC4 coding=HDB3 framing=CCS/CRC4 Card is properly installed and recognized by Dahdi Freetdm is compiled with libpri and configuration is like cat /usr/local/freeswitch/conf/freetdm.conf [general] cpu_monitor => yes cpu_monitoring_interval => 2000 ; monitor usage every 2 seconds cpu_set_alarm_threshold => 90 ; whenever 90% of global CPU usage is reached, trigger the alarm. cpu_reset_alarm_threshold => 80 ; when the CPU usage decreases at 80%, clear the alarm. cpu_alarm_action => reject,warn ; Start rejecting calls when the CPU alarm is triggered and also print warnings. [span zt myDAHDISpan] trunk_type => E1 group => g1 b-channel => 1-15 d-channel => 16 b-channel => 17-31 cat /usr/local/freeswitch/conf/autoload_configs/freetdm.conf.xml <configuration name="freetdm.conf" description="FreeTDM Configuration"> <settings> <param name="debug" value="1"/> </settings> <libpri_spans> <span name="myDAHDISpan">  <param name="switch" value="euroisdn"/> <param name="node" value="cpe"/> <param name="dialect" value="q931"/> <param name="debug" value="all"/> <param name="dialplan" value="XML"/> <param name="context" value="public"/> <param name="l1" value="alaw"/> </span> </libpri_spans> </configuration> Freeswitch logs are showing 2013-08-08 15:38:18.613848 [WARNING] ftmod_libpri.c:1975 [s1c10][1:10] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.613848 [WARNING] ftmod_libpri.c:1975 [s1c11][1:11] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.613848 [WARNING] ftmod_libpri.c:1975 [s1c12][1:12] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.613848 [WARNING] ftmod_libpri.c:1975 [s1c13][1:13] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c14][1:14] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c15][1:15] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c17][1:17] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c18][1:18] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c19][1:19] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c20][1:20] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c21][1:21] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c22][1:22] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c23][1:23] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c24][1:24] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c25][1:25] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c26][1:26] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c27][1:27] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c28][1:28] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c29][1:29] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c30][1:30] -- T316 timed out, resending RESTART request 2013-08-08 15:38:18.633847 [WARNING] ftmod_libpri.c:1975 [s1c31][1:31] -- T316 timed out, resending RESTART request 2013-08-08 15:38:23.673847 [WARNING] ftdm_io.c:3022 [s1c5][1:5] Channel not opened, proceeding anyway 2013-08-08 15:38:48.613848 [WARNING] ftmod_libpri.c:1975 [s1c6][1:6] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.613848 [WARNING] ftmod_libpri.c:1975 [s1c7][1:7] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c8][1:8] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c9][1:9] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c10][1:10] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c11][1:11] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c12][1:12] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c13][1:13] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c14][1:14] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c15][1:15] -- T316 timed out, resending RESTART request 2013-08-08 15:38:48.633850 [WARNING] ftmod_libpri.c:1975 [s1c17][1:17] -- T316 timed out, resending RESTART request Libpri logs are showing 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > DL-DATA request 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Protocol Discriminator: Q.931 (8) len=13 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI=0 Call Ref: len= 2 (reference 0/0x0) (Sent from originator) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Message Type: RESTART (70) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] TEI=0 Transmitting N(S)=4, window is open V(A)=2 K=7 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI: 0 State 7(Multi-frame established) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > V(A)=2, V(S)=4, V(R)=6 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > T200_id=8192, N200=3, T203_id=0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [ 00 01 08 0c 08 02 00 00 46 18 03 a9 83 8d 79 01 80 ] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Informational frame: 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > SAPI: 00 C/R: 0 EA: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI: 000 EA: 1 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > N(S): 004 0: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > N(R): 006 P: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > 13 bytes of data 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Protocol Discriminator: Q.931 (8) len=13 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI=0 Call Ref: len= 2 (reference 0/0x0) (Sent from originator) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Message Type: RESTART (70) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [18 03 a9 83 8d] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > ChanSel: As indicated in following octets 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Ext: 1 Coding: 0 Number Specified Channel Type: 3 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Ext: 1 Channel: 13 Type: CPE] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [79 01 80] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Restart Indicator (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] 2013-08-08 15:41:18.633844 [DEBUG] lpwrap_pri.c:199 [s1c16][1:16] -- Starting timer 0x2678478 with timeout 30000 ms 2013-08-08 15:41:18.633844 [WARNING] ftmod_libpri.c:1975 [s1c14][1:14] -- T316 timed out, resending RESTART request 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > DL-DATA request 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Protocol Discriminator: Q.931 (8) len=13 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI=0 Call Ref: len= 2 (reference 0/0x0) (Sent from originator) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Message Type: RESTART (70) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] TEI=0 Transmitting N(S)=5, window is open V(A)=2 K=7 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI: 0 State 7(Multi-frame established) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > V(A)=2, V(S)=5, V(R)=6 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > K=7, RC=0, l3_initiated=0, reject_except=0, ack_pend=0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > T200_id=8192, N200=3, T203_id=0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [ 00 01 0a 0c 08 02 00 00 46 18 03 a9 83 8e 79 01 80 ] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Informational frame: 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > SAPI: 00 C/R: 0 EA: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI: 000 EA: 1 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > N(S): 005 0: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > N(R): 006 P: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > 13 bytes of data 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Protocol Discriminator: Q.931 (8) len=13 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > TEI=0 Call Ref: len= 2 (reference 0/0x0) (Sent from originator) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Message Type: RESTART (70) 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [18 03 a9 83 8e] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > ChanSel: As indicated in following octets 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Ext: 1 Coding: 0 Number Specified Channel Type: 3 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Ext: 1 Channel: 14 Type: CPE] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > [79 01 80] 2013-08-08 15:41:18.633844 [DEBUG] ftmod_libpri.c:134 [s1c16][1:16] > Restart Indicator (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] 2013-08-08 15:41:18.633844 [DEBUG] lpwrap_pri.c:199 [s1c16][1:16] -- Starting timer 0x26784d8 with timeout 30000 ms 2013-08-08 15:41:18.633844 [WARNING] ftmod_libpri.c:1975 [s1c15][1:15] -- T316 timed out, resending RESTART request ftdm dump 1 n (where n is from 1 to 15 and 17 to 31) is showing state as down freeswitch@dst1> ftdm dump 1 1 span_id: 1 chan_id: n physical_span_id: 1 physical_chan_id: n physical_status: ok physical_status_red: 0 physical_status_yellow: 0 physical_status_rai: 0 physical_status_blue: 0 physical_status_ais: 0 physical_status_general: 0 signaling_status: UP type: B state: DOWN last_state: RESTART txgain: 0.00 rxgain: 0.00 cid_date: cid_name: cid_num: ani: aniII: dnis: rdnis: cause: NONE session: (none) I have tried many configurations, but I am not able to fix that issue , If I put my Pri line into panasonic PBX, it is working properly. Kindly help me in solving this issue. Regards Rajat Toshniwal ---------------------------------------------------------------------------------- Disclaimer: The information contained in this communication is confidential, private, proprietary, or otherwise privileged and is intended only for the use of the addressee. Unauthorized use, disclosure, distribution or copying is strictly prohibited and may be unlawful. If you have received this communication in error, please delete this message and notify the sender immediately - Samin TekMindz India Pvt. Ltd. ----------------------------------------------------------------------------------

1 3

Problem with separating inline dialplan apps
by afshin afzali 11 Aug '13

11 Aug '13

Hi Guys, I use this command originate loopback/answer,park/context_1/inline &transfer(2001) over a inbound event socket. Problem is that server takes just loopback/answer part for new channel: [NOTICE] switch_channel.c:1030 New Channel loopback/answer-a [0eb8f17c-ff50-11e2-97ec-d950156f6aef] and then try park for new channel! [ERR] switch_core_session.c:496 Could not locate channel type park When I submit same command over CLI (just added a \ before comma) it works fine. appreciate all, afshin

2 2

Remote Extension Registered but can't make/receive any call
by crazygabry 10 Aug '13

10 Aug '13

Hello every body, i'm a new freepbx user and i'm trying to configured a freeswitch server hosted in the cloud. I can register my softphone but i can't do anything: when i try to make a call i receive an error from the CLI that says INVALID_PROFILE. Can someone help me? Thanks in advice crazygabry P.S. that's what i see on CLI ( XXX.XXX.XXX is my local ip and YYY.YYY.YYY is the freeswitch IP) 2013-08-09 22:28:10.070676 [NOTICE] switch_channel.c:1030 New Channel sofia/external/1100@YYY.YYY.YYY.YYY:9060 [dc15c333-fa2c-4055-a56e-f466279c8aae] 2013-08-09 22:28:10.070676 [DEBUG] switch_core_session.c:999 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.070676 [DEBUG] switch_core_session.c:999 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.070676 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_NEW 2013-08-09 22:28:10.070676 [DEBUG] switch_core_state_machine.c:433 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State NEW 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5727 Channel sofia/external/1100@YYY.YYY.YYY.YYY:9060 entering state [received][100] 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5740 Remote SDP: v=0 o=3cxVCE 303008025 298674930 IN IP4 XXX.XXX.XXX.XXX s=3cxVCE Audio Call c=IN IP4 XXX.XXX.XXX.XXX t=0 0 m=audio 40046 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 m=video 40004 RTP/AVP 34 c=IN IP4 XXX.XXX.XXX.XXX a=rtpmap:34 H263/90000 a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=1 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5954 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State Change CS_NEW -> CS_INIT 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_INIT 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:454 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State INIT 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:87 sofia/external/1100@YYY.YYY.YYY.YYY:9060 SOFIA INIT 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:127 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State Change CS_INIT -> CS_ROUTING 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:454 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State INIT going to sleep 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_ROUTING 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:2111 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Callstate Change DOWN -> RINGING 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:470 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State ROUTING 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:150 sofia/external/1100@YYY.YYY.YYY.YYY:9060 SOFIA ROUTING 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:117 sofia/external/1100@YYY.YYY.YYY.YYY:9060 Standard ROUTING 2013-08-09 22:28:10.090709 [INFO] mod_dialplan_xml.c:558 Processing Gwen <1100>->1000 in context public Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 parsing [public->unloop] continue=false Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 parsing [public->outside_call] continue=true Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Absolute Condition [outside_call] Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Action set(outside_call=true) Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 parsing [public->call_debug] continue=true Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 parsing [public->public_extensions] continue=false Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Regex (PASS) [public_extensions] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/1100@YYY.YYY.YYY.YYY:9060 Action bridge(sofia/doublenat/1000%172.29.5.7 ) 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:167 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State Change CS_ROUTING -> CS_EXECUTE 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:470 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State ROUTING going to sleep 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_EXECUTE 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:477 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State EXECUTE 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:243 sofia/external/1100@YYY.YYY.YYY.YYY:9060 SOFIA EXECUTE 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:209 sofia/external/1100@YYY.YYY.YYY.YYY:9060 Standard EXECUTE EXECUTE sofia/external/1100@YYY.YYY.YYY.YYY:9060 set(outside_call=true) 2013-08-09 22:28:10.090709 [DEBUG] mod_dptools.c:1393 sofia/external/1100@YYY.YYY.YYY.YYY:9060 SET [outside_call]=[true] EXECUTE sofia/external/1100@YYY.YYY.YYY.YYY:9060 export(RFC2822_DATE=Fri, 09 Aug 2013 22:28:10 +0000) 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:1222 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 09 Aug 2013 22:28:10 +0000] EXECUTE sofia/external/1100@YYY.YYY.YYY.YYY:9060 bridge(sofia/doublenat/1000%172.29.5.7 ) 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:1176 sofia/external/1100@YYY.YYY.YYY.YYY:9060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 09 Aug 2013 22:28:10 +0000] to event 2013-08-09 22:28:10.090709 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables 2013-08-09 22:28:10.090709 [ERR] mod_sofia.c:5024 Invalid Profile 2013-08-09 22:28:10.090709 [NOTICE] mod_sofia.c:5325 Close Channel N/A [CS_NEW] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:568 () Running State Change CS_DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (N/A) State DESTROY 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:397 N/A SOFIA DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (N/A) State DESTROY going to sleep 2013-08-09 22:28:10.110663 [NOTICE] switch_ivr_originate.c:2661 Cannot create outgoing channel of type [sofia] cause: [INVALID_PROFILE] 2013-08-09 22:28:10.110663 [DEBUG] switch_ivr_originate.c:3632 Originate Resulted in Error Cause: 611 [INVALID_PROFILE] 2013-08-09 22:28:10.110663 [INFO] mod_dptools.c:3192 Originate Failed. Cause: INVALID_PROFILE 2013-08-09 22:28:10.110663 [NOTICE] switch_channel.c:4573 Hangup sofia/external/1100@YYY.YYY.YYY.YYY:9060 [CS_EXECUTE] [INVALID_PROFILE] 2013-08-09 22:28:10.110663 [DEBUG] switch_channel.c:3130 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [KILL] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:2740 sofia/external/1100@YYY.YYY.YYY.YYY:9060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:477 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State EXECUTE going to sleep 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_HANGUP 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:678 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State HANGUP 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:504 Channel sofia/external/1100@YYY.YYY.YYY.YYY:9060 hanging up, cause: INVALID_PROFILE 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:638 Responding to INVITE with: 502 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:48 sofia/external/1100@YYY.YYY.YYY.YYY:9060 Standard HANGUP, cause: INVALID_PROFILE 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:678 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State HANGUP going to sleep 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:689 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Callstate Change RINGING -> HANGUP 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:446 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State Change CS_HANGUP -> CS_REPORTING 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:415 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_REPORTING 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:761 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State REPORTING 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:92 sofia/external/1100@YYY.YYY.YYY.YYY:9060 Standard REPORTING, cause: INVALID_PROFILE 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:761 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State REPORTING going to sleep 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:440 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State Change CS_REPORTING -> CS_DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal sofia/external/1100@YYY.YYY.YYY.YYY:9060 [BREAK] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1542 Session 26 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Locked, Waiting on external entities 2013-08-09 22:28:10.110663 [NOTICE] switch_core_session.c:1560 Session 26 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Ended 2013-08-09 22:28:10.110663 [NOTICE] switch_core_session.c:1564 Close Channel sofia/external/1100@YYY.YYY.YYY.YYY:9060 [CS_DESTROY] 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:565 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Callstate Change HANGUP -> DOWN 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:568 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) Running State Change CS_DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State DESTROY 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:397 sofia/external/1100@YYY.YYY.YYY.YYY:9060 SOFIA DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:99 sofia/external/1100@YYY.YYY.YYY.YYY:9060 Standard DESTROY 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (sofia/external/1100@YYY.YYY.YYY.YYY:9060) State DESTROY going to sleep -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Remote-Extension-Registered-b… Sent from the freeswitch-users mailing list archive at Nabble.com.

2 1

OpenWRT Router changes public IP to it's private IP
by Brian Foster 10 Aug '13

10 Aug '13

We've got an openwrt router at a site, it's private IP is 10.0.0.1. Whenever we get an inbound call on the external profile (and probably outbound calls to, haven't checked yet), it changes the contact IP to the router's private IP, so that every call we get looks like it's coming from thr router. We've had some intermittent audio problems recently and we're trying to narrow things down a bit. Is this the expected behavior for NAT? Sorry might seem like a dumb question, but my job entails much more than keeping the company's server's happy and I'm starting to lose my grip and I'm definitely not experienced with NAT. All of my routers in the past have given FS the public IP of the contacting server. I have web servers behind the same NAT and doing the same thing, showing the private IP of the router instead of showing the public IP of the client. So I know it's not an issue with FS. Just wanted to see if anyone has exoerienced this before. Makes it difficult to use fail2ban on my servers, as it continually jails my router. Thank you, Brian Foster Project Manager/Owner's Rep. Davri Investments, Inc. O: 317-787-2686 x2102 M: 317-600-9753 E: bdfoster(a)davri.com Indianapolis, Indiana Sent from a mobile device.

4 8

Call at once and XML-CDR
by Stuart Mills 09 Aug '13

09 Aug '13

Hi, Got a question regarding call at once combined with xml-cdr logging. The problem I seem to get is when I try sending calls to 2 destinations and 1 call gets answered, so that wins the race, the xml-cdr logging seems to be a little confused. In the app_log I’m getting logging up to the point of the dial string, then nothing after that for the a-leg. What seems to happen is the rest of the app_log gets written to the cdr file of the bleg that answered the call first. Is this by design or a bug in the xml-cdr logging? Thanks, Stuart

9 23

One way audio to CME
by Peter 09 Aug '13

09 Aug '13

I currently have successful two way calls (signalling and media) in the following setup External Linphone --> Freeswitch --> Freeswitch SBC -> Router -> Kamailio --> Internal Linphone However, when I try to call a Cisco handset that is registered to CUCM9 via CME in the following config: External Linphone --> Freeswitch --> Freeswitch SBC -> Router -> CME -> CUCM9 --> Cisco handset The call signalling appears to be working fine and I can successfully initiate a call from each end, but the only RTP stream that is working is from the external Linphone client to the Cisco handset. Note that CME is being used as a CUBE device, so all SIP and RTP goes via it. Looking at the RTP debugs on CME I can see the problem is that the "Media Dest Addr" is getting set to the external side of the FS SBC rather than the internal IP address. I tried setting adding: <action application="set" data="disable_rtp_auto_adjust="true" /> to the dialplan on the SBC, but it made no difference. Any suggestions as to what to check next? Thanks Peter

3 11

FS behind NAT
by Vincent Xia 08 Aug '13

08 Aug '13

im having my FS box behind NAT, the network topology is something like: IP PHONE A(Public IP)<------->NAT<------>FS(Private IP, with a public IP)<------->IP PHONE B(Private IP) i was trying to have IP PHONE B able to make call to IP PHONE A and have two-way talk. with the default FS configuration when IP PHONE B calls IP PHONE A, there's only one-way talk, A can hear B but B cannot hear A. then i decided to use stun by modifying: vars.xml <X-PRE-PROCESS cmd="set" data="external_rtp_ip=stun:stun.freeswitch.org"/> // this is the default config <X-PRE-PROCESS cmd="set" data="external_sip_ip=stun:stun.freeswitch.org"/> // this is the default config internal.xml <param name="ext-rtp-ip" value="stun:stun.freeswtich.org"/> <param name="ext-sip-ip" value="stun:stun.freeswtich.org"/> external.xml <param name="ext-rtp-ip" value="stun:stun.freeswtich.org"/> <param name="ext-sip-ip" value="stun:stun.freeswtich.org"/> but while restarting FS, there's error reporting: 2013-08-08 10:33:58.933096 [ERR] sofia_glue.c:1043 STUN Failed! stun.freeswitch.org:3478 [Bind Error!] 2013-08-08 10:33:58.933096 [ERR] sofia.c:4074 Failed to get external ip. 2013-08-08 10:33:58.934072 [NOTICE] sofia.c:4754 Started Profile external [sofia_reg_external] ... 2013-08-08 10:34:00.859927 [ERR] sofia_glue.c:1043 STUN Failed! stun.freeswitch.org:3478 [Bind Error!] 2013-08-08 10:34:00.859927 [ERR] sofia.c:4074 Failed to get external ip. 2013-08-08 10:34:00.860904 [NOTICE] sofia.c:4754 Started Profile internal [sofia_reg_internal] so am i still missing some configuration or anything else was wrong?

3 2

Bypass_media_after_bridge doesn't works
by Carlo Dimaggio 08 Aug '13

08 Aug '13

Hi all, I have an installation with several phones (yealink) behind NAT and freeswitch withaggressive-nat-detection=true in internal SIP Profile. In dialplan I set bypass_media_after_bridgein order to eliminate on-way audio problems (and use less bandwidth), but I'm encountering a strange issue. When I call two extensions, sometimes freeswitch bypassthe media between them (so the SDP sent by freeswitch have the private IP) and sometimes freeswitch send the SDP with the NAT IP(in this case there is no audio). What could be the problem? Is this a bug or my misconfiguration? Best regards, Carlo Dimaggio

2 2

[CRIT] switch_core_session.c:1705 Thread Failure!
by Nikolay Rogoshchenkov 07 Aug '13

07 Aug '13

Could you please explain what this mean in FreeSwitch log??? ---------------------------------------------------------------------- *[...]* *2013-08-07 23:40:48.011687 [CRIT] switch_core_session.c:1705 Thread Failure!* *2013-08-07 23:40:48.011687 [CRIT] switch_core_session.c:1665 LUKE: I'm hit, but not bad.* *2013-08-07 23:40:48.011687 [CRIT] switch_core_session.c:1666 LUKE'S VOICE: Artoo, see what you can do with it. Hang on back there....* *Green laserfire moves past the beeping little robot as his head turns. After a few beeps and a twist of his mechanical arm,* *Artoo reduces the max sessions to 101 thus, saving the switch from certain doom.* *2013-08-07 23:40:48.031685 [CRIT] switch_core_session.c:1705 Thread Failure!* *2013-08-07 23:40:48.031685 [CRIT] switch_core_session.c:1665 LUKE: I'm hit, but not bad.* *2013-08-07 23:40:48.031685 [CRIT] switch_core_session.c:1666 LUKE'S VOICE: Artoo, see what you can do with it. Hang on back there....* *Green laserfire moves past the beeping little robot as his head turns. After a few beeps and a twist of his mechanical arm,* *Artoo reduces the max sessions to 101 thus, saving the switch from certain doom.* *2013-08-07 23:40:48.041688 [CRIT] switch_core_session.c:1705 Thread Failure!* *[...]* *2013-08-07 23:55:38.141571 [CRIT] switch_core_session.c:1705 Thread Failure!* *2013-08-07 23:55:38.151578 [CRIT] switch_core_session.c:1705 Thread Failure!* *2013-08-07 23:55:38.171584 [CRIT] switch_core_session.c:1705 Thread Failure!* *[..]* ---------------------------------------------------------------------- It is not funny, at that moment freeswitch consumes 98% of CPU time, and did not response at all. PS: (Version 1.5.5b git 8d005a4 2013-07-22 14:41:01Z) @FreeBSD 8.2-RELEASE (x64) -- Nikolay

3 3

error connecting softphone
by Ashish Mishra 07 Aug '13

07 Aug '13

hi i have installed x-lite softphone on my windows 8 pc (on which freeswitch is not installed) through LAN i have connected a ubuntu machine on which is installed when i am trying to add a user on x-lite softphone with domain as the ip of the ubuntu machine and and user id as 1005 and password as 1234, as i click ok button the softphone gives me an error saying that cannot enable user... thank you Ashish Mishra

2 1