November 2010 - FreeSWITCH-users - FreeSWITCH Mailing Lists

IMPORTANT: If you use "verbose events" then read this
by Michael Collins 18 Nov '10

18 Nov '10

Guys, Just an FYI for those of you who use verbose events in your event programming... Tony fixed a bug recently: http://jira.freeswitch.org/browse/FS-2851 The commit is here: http://fisheye.freeswitch.org/changelog/freeswitch.git/?cs=180f58a677a2ef49… If you have no clue what verbose events are for then you can probably ignore this. :) -MC

1 0

Shared Line exprience with Polycom - how to get it to work
by Peter Steinbach 18 Nov '10

18 Nov '10

Hello, we followed the advices in http://wiki.freeswitch.org/wiki/Shared_Line_Appearance and set <param name="manage-shared-appearance" value="true"/> in the internal profile. Also presence handling is enabled. In the Polycom phone settings we set reg.1.type="shared" reg.1.bargeInEnabled="1" reg.1.callsPerLineKey="1" according to the wiki and the Polycom documentation In phone1.cfg we set divert.1.sharedDisabled="0" and in sip.cfg we set call.shared.disableDivert="1" reg.1.bargeInEnabled="1" When we call the destination number, - both phones ring - we pick up one phone - other phone stops ringing - we press "hold" on the active phone - nothings happens to the other phone Are we doing something wrong here? We work with Polycom FW 3.2.3 and Freeswitch GIT compiled last friday. Strange is, that Freeswitch shows a number of error messages related to SQL (we use ODBC), although all SQL statements are valid and can be sucessfully executed on the MySQL CLI. Also we do see records in sip_dialogs but not a single record in sip_presence. Any hints? What did you do to get this working? Here are the error messages from freeswitch.log ================================== 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:721 STATE SQL update sip_dialogs set call_info='appearance-index=1',call_info_state='idle' where hostname='mydomain.org' and uuid='d80df99a-ece4-11df-ab6f-f761d81a6b8a' 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:728 PROCESS PRESENCE EVENT 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1925 PRES SQL select sip_from_user,sip_from_host,call_info,call_info_state,uuid from sip_dialogs where hostname='mydomain.org' and sip_from_user='4702' and sip_from_host='mydomain.org' 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1946 PRES SQL select call_id,expires,sub_to_user,sub_to_host,event from sip_subscriptions where expires > -1 and hostname='mydomain.org' and sub_to_user='4702' and sub_to_host='mydomain.org' and (event='call-info' or event='line-seize') 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[a1859461-5362d6a6-c25a8bff(a)172.xx.xx.xx] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412326] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[536c87c6-b366418f-2260bca4(a)172.21.20.194] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412332] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.329549 [ERR] sofia_presence.c:1961 CLEAR SQL delete from sip_dialogs where sip_from_user='4702' and sip_from_host='mydomain.org' and call_info_state='seized' 2010-11-10 17:09:13.330530 [ERR] sofia_presence.c:721 STATE SQL update sip_dialogs set call_info='appearance-index=1',call_info_state='idle' where hostname='mydomain.org' and uuid='d80df99a-ece4-11df-ab6f-f761d81a6b8a' 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:728 PROCESS PRESENCE EVENT 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1925 PRES SQL select sip_from_user,sip_from_host,call_info,call_info_state,uuid from sip_dialogs where hostname='mydomain.org' and sip_from_user='4702' and sip_from_host='mydomain.org' 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1946 PRES SQL select call_id,expires,sub_to_user,sub_to_host,event from sip_subscriptions where expires > -1 and hostname='mydomain.org' and sub_to_user='4702' and sub_to_host='mydomain.org' and (event='call-info' or event='line-seize') 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[a1859461-5362d6a6-c25a8bff(a)172.xx.xx.xx] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412326] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[536c87c6-b366418f-2260bca4(a)172.21.20.194] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412332] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.331511 [ERR] sofia_presence.c:1961 CLEAR SQL delete from sip_dialogs where sip_from_user='4702' and sip_from_host='mydomain.org' and call_info_state='seized' 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:721 STATE SQL update sip_dialogs set call_info='appearance-index=1',call_info_state='idle' where hostname='mydomain.org' and uuid='d80df99a-ece4-11df-ab6f-f761d81a6b8a' 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:728 PROCESS PRESENCE EVENT 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1925 PRES SQL select sip_from_user,sip_from_host,call_info,call_info_state,uuid from sip_dialogs where hostname='mydomain.org' and sip_from_user='4702' and sip_from_host='mydomain.org' 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1946 PRES SQL select call_id,expires,sub_to_user,sub_to_host,event from sip_subscriptions where expires > -1 and hostname='mydomain.org' and sub_to_user='4702' and sub_to_host='mydomain.org' and (event='call-info' or event='line-seize') 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[a1859461-5362d6a6-c25a8bff(a)172.xx.xx.xx] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412326] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 0 [call_id]=[536c87c6-b366418f-2260bca4(a)172.21.20.194] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 1 [expires]=[1289412332] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 2 [sub_to_user]=[4702] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 3 [sub_to_host]=[mydomain.org] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1773 SLA3: 4 [event]=[call-info] 2010-11-10 17:09:13.332492 [ERR] sofia_presence.c:1961 CLEAR SQL delete from sip_dialogs where sip_from_user='4702' and sip_from_host='mydomain.org' and call_info_state='seized' -- With kind regards Peter Steinbach Telefaks Services GmbH Theo-Geisel-Strasse 25 D 61250 Usingen, Germany mailto:lists@telefaks.de Internet: www.telefaks.de

3 7

False extension at auto atendant
by Isti 18 Nov '10

18 Nov '10

Hi, I have set up an auto atendant where it is allowed to dial an extension directly. The problem: If I hear the music I choose "120". --> The extension is not found. If I check the log I find that actually "11220" was searched. This extension does not exist. Can you somebody tell me, why "120" will be recognised and searched as "11220". I have called from my mobile phone. The extensionnumber was chosen with this. I have typed the digits pretty fast. These ware definitly not typed double. Thank you for the ideas. With kind regards, I.

2 2

web2phone
by budi wibowo 18 Nov '10

18 Nov '10

hi i'm looking for web2phone application that can work with any sip server including freeswitch any info is appreciated regards budi

2 1

failed to wait for I/O
by Troy Anderson 18 Nov '10

18 Nov '10

We have an installation with a dual PRI and lots of call volume. Among many successful calls each day, we have been experiencing a one or two dropped per day, and they always coincide with a "failed to wait for I/O" warning from mod_freetdm. I have attempted to track down the root cause in the source and by poring over the logs, but cannot figure it out. I have included the redacted logs here. The log file in question is 10MB and has lots of call data that doesn't relate - I know I risked removing something important, but I tried to put in all the data related to this call. I appreciate any insights or advice on tracking this down. Here are the logs for the call from SIP extension 903 to 1239xxxxxxx via PRI span 1, channel 20. The WARNING is near the end: EXECUTE sofia/internal/903@192.168.1.20:5060 bridge(freetdm/1/A/1239xxxxxxx) 2010-11-05 10:18:21.094993 [DEBUG] switch_core_session.c:1919 sofia/internal/903@192.168.1.20:5060 receive message [APPLICATION_EXEC] 2010-11-05 10:18:21.094993 [INFO] ftmod_zt.c:636 Setting echo cancel to 64 taps for 1:20 2010-11-05 10:18:21.094993 [DEBUG] mod_freetdm.c:377 Set codec PCMU 20ms 2010-11-05 10:18:21.094993 [DEBUG] mod_freetdm.c:1334 Connect outbound channel FreeTDM/1:20/1239xxxxxxx 2010-11-05 10:18:21.094993 [NOTICE] switch_channel.c:784 New Channel FreeTDM/1:20/1239xxxxxxx [4d47f77d-6591-40c1-94e5-73da4e5e157a] 2010-11-05 10:18:21.094993 [DEBUG] mod_freetdm.c:1348 (FreeTDM/1:20/1239xxxxxxx) State Change CS_NEW -> CS_INIT 2010-11-05 10:18:21.094993 [DEBUG] switch_core_session.c:1057 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:21.094993 [DEBUG] ftmod_libpri.c:92 [s1c20][1:20] Changed state from DOWN to DIALING 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:318 (FreeTDM/1:20/1239xxxxxxx) Running State Change CS_INIT 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:342 (FreeTDM/1:20/1239xxxxxxx) State INIT 2010-11-05 10:18:21.095991 [DEBUG] mod_freetdm.c:405 (FreeTDM/1:20/1239xxxxxxx) State Change CS_INIT -> CS_ROUTING 2010-11-05 10:18:21.095991 [DEBUG] switch_core_session.c:1057 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:342 (FreeTDM/1:20/1239xxxxxxx) State INIT going to sleep 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:318 (FreeTDM/1:20/1239xxxxxxx) Running State Change CS_ROUTING 2010-11-05 10:18:21.095991 [DEBUG] switch_channel.c:1615 (FreeTDM/1:20/1239xxxxxxx) Callstate Change DOWN -> RINGING 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:345 (FreeTDM/1:20/1239xxxxxxx) State ROUTING 2010-11-05 10:18:21.095991 [DEBUG] mod_freetdm.c:428 FreeTDM/1:20/1239xxxxxxx CHANNEL ROUTING 2010-11-05 10:18:21.095991 [DEBUG] switch_ivr_originate.c:66 (FreeTDM/1:20/1239xxxxxxx) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-11-05 10:18:21.095991 [DEBUG] switch_core_session.c:1057 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:345 (FreeTDM/1:20/1239xxxxxxx) State ROUTING going to sleep 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:318 (FreeTDM/1:20/1239xxxxxxx) Running State Change CS_CONSUME_MEDIA 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:364 (FreeTDM/1:20/1239xxxxxxx) State CONSUME_MEDIA 2010-11-05 10:18:21.095991 [DEBUG] switch_core_state_machine.c:364 (FreeTDM/1:20/1239xxxxxxx) State CONSUME_MEDIA going to sleep 2010-11-05 10:18:21.097993 [DEBUG] switch_ivr_originate.c:1079 sofia/internal/903@192.168.1.20:5060 receive message [PROGRESS] 2010-11-05 10:18:21.101999 [INFO] switch_ivr_originate.c:1079 Sending early media 2010-11-05 10:18:21.101999 [DEBUG] sofia_glue.c:2961 AUDIO RTP [sofia/internal/903@192.168.1.20:5060] 192.168.1.20 port 17872 -> 192.168.1.194 port 3000 codec: 0 ms: 30 2010-11-05 10:18:21.101999 [DEBUG] switch_rtp.c:1418 Starting timer [soft] 240 bytes per 30ms 2010-11-05 10:18:21.104067 [DEBUG] sofia_glue.c:3179 Set 2833 dtmf send payload to 101 2010-11-05 10:18:21.104067 [DEBUG] sofia_glue.c:3184 Set 2833 dtmf receive payload to 101 2010-11-05 10:18:21.104067 [DEBUG] mod_sofia.c:2169 Ring SDP: v=0 o=FreeSWITCH 1288948829 1288948830 IN IP4 192.168.1.20 s=FreeSWITCH c=IN IP4 192.168.1.20 t=0 0 m=audio 17872 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 a=sendrecv 2010-11-05 10:18:21.104067 [NOTICE] mod_sofia.c:2172 Pre-Answer sofia/internal/903@192.168.1.20:5060! 2010-11-05 10:18:21.104067 [DEBUG] switch_channel.c:2544 (sofia/internal/903@192.168.1.20:5060) Callstate Change RINGING -> EARLY 2010-11-05 10:18:21.104067 [DEBUG] switch_core_session.c:676 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:21.104067 [DEBUG] switch_ivr_originate.c:1128 Raw Codec Activation Success L16@8000hz 1 channel 30ms 2010-11-05 10:18:21.104067 [DEBUG] switch_core_codec.c:116 sofia/internal/903@192.168.1.20:5060 Push codec L16:10 2010-11-05 10:18:21.104067 [DEBUG] switch_ivr_originate.c:1193 Play Ringback Tone [%(2000,4000,440.0,480.0)] 2010-11-05 10:18:21.104994 [DEBUG] sofia.c:4564 Channel sofia/internal/903@192.168.1.20:5060 skipping state [early][183] 2010-11-05 10:18:21.109994 [DEBUG] switch_core_io.c:723 sofia/internal/903@192.168.1.20:5060 receive message [TRANSCODING_NECESSARY] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:466 1:20 STATE [DIALING] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 -- Making new call for cref 34100 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > DL-DATA request 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Protocol Discriminator: Q.931 (8) len=52 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent from originator) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Message Type: SETUP (5) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 TEI=0 Transmitting N(S)=121, window is open V(A)=121 K=7 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > V(A)=121, V(S)=121, V(R)=15 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [ 00 01 f2 1e 08 02 05 34 05 04 03 80 90 a2 18 03 a1 83 94 28 07 b1 41 20 57 61 72 64 6c 0c 00 81 37 30 36 33 34 38 34 33 30 38 70 0c 80 31 32 33 39 36 34 32 38 36 38 37 ] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Informational frame: 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > SAPI: 00 C/R: 0 EA: 0 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > TEI: 000 EA: 1 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > N(S): 121 0: 0 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > N(R): 015 P: 0 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > 52 bytes of data 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Protocol Discriminator: Q.931 (8) len=52 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent from originator) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Message Type: SETUP (5) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [04 03 80 90 a2] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > User information layer 1: u-Law (34) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [18 03 a1 83 94] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > ChanSel: As indicated in following octets 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Ext: 1 Coding: 0 Number Specified Channel Type: 3 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Ext: 1 Channel: 20 Type: CPE] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [28 07 b1 41 20 57 61 72 64] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Display (len= 7) Charset: 31 [ A Ward ] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [6c 0c 00 81 37 30 36 33 34 38 34 33 30 38] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Calling Number (len=14) [ Ext: 0 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Presentation: Presentation permitted, user number passed network screening (1) '706xxxxxxx' ] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > [70 0c 80 31 32 33 39 36 34 32 38 36 38 37] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 > Called Number (len=14) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) '1239xxxxxxx' ] 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 -- Stopping T203 timer 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 -- Starting T200 timer 2010-11-05 10:18:21.145993 [DEBUG] ftmod_libpri.c:143 q931.c:4959 q931_setup: Call 34100 enters state 1 (Call Initiated). Hold state: Idle 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < V(A)=121, V(S)=122, V(R)=15 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < T200_id=1, N200=3, T203_id=0 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < [ 00 01 01 f4 ] 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < Supervisory frame: 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < SAPI: 00 C/R: 0 EA: 0 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < TEI: 000 EA: 1 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < N(R): 122 P/F: 0 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 < 0 bytes of data 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 -- Got ACK for N(S)=121 to (but not including) N(S)=122 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 -- ACKing N(S)=121, txqueue head is N(S)=-1 (-1 is empty, -2 is not transmitted) 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 -- Stopping T200 timer 2010-11-05 10:18:21.168073 [DEBUG] ftmod_libpri.c:143 -- Starting T203 timer 2010-11-05 10:18:21.169069 [DEBUG] ftmod_libpri.c:143 Done handling message for SAPI/TEI=0/0 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < V(A)=122, V(S)=122, V(R)=15 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < [ 02 01 1e f4 08 02 85 34 02 18 03 a9 83 94 ] 2010-11-05 10:18:21.293134 [DEBUG] ftmod_libpri.c:143 < Informational frame: 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < TEI: 000 EA: 1 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < N(S): 015 0: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < N(R): 122 P: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < 10 bytes of data 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < Protocol Discriminator: Q.931 (8) len=10 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent to originator) 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < Message Type: CALL PROCEEDING (2) 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < [18 03 a9 83 94] 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < ChanSel: As indicated in following octets 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < Ext: 1 Coding: 0 Number Specified Channel Type: 3 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 < Ext: 1 Channel: 20 Type: CPE] 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 Received message for call 0x2aaac801ff90 on 0x8e45f70 TEI/SAPI 0/0, call->pri is 0x8e45f70 TEI/SAPI 0/0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 -- Processing IE 24 (cs0, Channel Identification) 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 q931.c:6998 post_handle_q931_message: Call 34100 enters state 3 (Outgoing Call Proceeding). Hold state: Idle 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 -- Got ACK for N(S)=122 to (but not including) N(S)=122 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 -- T200 requested to stop when not started 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 T203 requested to start without stopping first 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 -- Starting T203 timer 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > V(A)=122, V(S)=122, V(R)=16 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > [ 02 01 01 20 ] 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > Supervisory frame: 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > TEI: 000 EA: 1 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > N(R): 016 P/F: 0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 > 0 bytes of data 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:143 Done handling message for SAPI/TEI=0/0 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:757 -- Proceeding on channel 1:20 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:758 [s1c20][1:20] Changed state from DIALING to PROGRESS_MEDIA 2010-11-05 10:18:21.294064 [DEBUG] ftmod_libpri.c:466 1:20 STATE [PROGRESS_MEDIA] 2010-11-05 10:18:21.294064 [DEBUG] mod_freetdm.c:2048 got clear channel sig [PROGRESS_MEDIA] 2010-11-05 10:18:21.294064 [NOTICE] mod_freetdm.c:2097 Pre-Answer FreeTDM/1:20/1239xxxxxxx! 2010-11-05 10:18:21.294064 [DEBUG] switch_channel.c:2544 (FreeTDM/1:20/1239xxxxxxx) Callstate Change RINGING -> EARLY 2010-11-05 10:18:21.294064 [DEBUG] switch_channel.c:2588 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:21.320116 [DEBUG] switch_core_codec.c:141 sofia/internal/903@192.168.1.20:5060 Restore previous codec PCMU:0. 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr_originate.c:3333 Originate Resulted in Success: [FreeTDM/1:20/1239xxxxxxx] 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr.c:196 FreeTDM/1:20/1239xxxxxxx receive message [AUDIO_SYNC] 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr.c:196 sofia/internal/903@192.168.1.20:5060 receive message [AUDIO_SYNC] 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr_bridge.c:1175 FreeTDM/1:20/1239xxxxxxx receive message [BRIDGE] 2010-11-05 10:18:21.320116 [DEBUG] switch_core_session.c:676 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr_bridge.c:1182 sofia/internal/903@192.168.1.20:5060 receive message [BRIDGE] 2010-11-05 10:18:21.320116 [DEBUG] switch_core_session.c:676 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:21.320116 [DEBUG] switch_ivr_bridge.c:1226 (FreeTDM/1:20/1239xxxxxxx) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2010-11-05 10:18:21.320116 [DEBUG] switch_core_session.c:1057 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:21.320116 [DEBUG] switch_core_state_machine.c:318 (FreeTDM/1:20/1239xxxxxxx) Running State Change CS_EXCHANGE_MEDIA 2010-11-05 10:18:21.320116 [DEBUG] switch_core_state_machine.c:355 (FreeTDM/1:20/1239xxxxxxx) State EXCHANGE_MEDIA 2010-11-05 10:18:21.320116 [DEBUG] mod_freetdm.c:569 CHANNEL EXCHANGE_MEDIA 2010-11-05 10:18:21.340108 [DEBUG] switch_core_io.c:723 sofia/internal/903@192.168.1.20:5060 receive message [TRANSCODING_NECESSARY] 2010-11-05 10:18:21.340108 [DEBUG] switch_core_io.c:970 Engaging Write Buffer at 480 bytes to accommodate 320->480 2010-11-05 10:18:21.410086 [DEBUG] switch_rtp.c:2544 Correct ip/port confirmed. 2010-11-05 10:18:21.410086 [DEBUG] switch_core_io.c:723 FreeTDM/1:20/1239xxxxxxx receive message [TRANSCODING_NECESSARY] 2010-11-05 10:18:21.410086 [DEBUG] switch_core_io.c:970 Engaging Write Buffer at 320 bytes to accommodate 480->320 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < V(A)=122, V(S)=122, V(R)=16 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < [ 02 01 20 f4 08 02 85 34 01 1e 02 82 88 ] 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < Informational frame: 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < TEI: 000 EA: 1 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < N(S): 016 0: 0 2010-11-05 10:18:23.093023 [DEBUG] ftmod_libpri.c:143 < N(R): 122 P: 0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < 9 bytes of data 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < Protocol Discriminator: Q.931 (8) len=9 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent to originator) 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < Message Type: ALERTING (1) 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < [1e 02 82 88] 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2) 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 < Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 Received message for call 0x2aaac801ff90 on 0x8e45f70 TEI/SAPI 0/0, call->pri is 0x8e45f70 TEI/SAPI 0/0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 -- Processing IE 30 (cs0, Progress Indicator) 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 q931.c:6888 post_handle_q931_message: Call 34100 enters state 4 (Call Delivered). Hold state: Idle 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 -- Got ACK for N(S)=122 to (but not including) N(S)=122 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 -- T200 requested to stop when not started 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 T203 requested to start without stopping first 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 -- Starting T203 timer 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > V(A)=122, V(S)=122, V(R)=17 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > [ 02 01 01 22 ] 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > Supervisory frame: 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > TEI: 000 EA: 1 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > N(R): 017 P/F: 0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 > 0 bytes of data 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:143 Done handling message for SAPI/TEI=0/0 2010-11-05 10:18:23.094018 [DEBUG] ftmod_libpri.c:782 -- Ringing on channel 1:20 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < V(A)=122, V(S)=122, V(R)=17 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < [ 02 01 22 f4 08 02 85 34 07 ] 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < Informational frame: 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < TEI: 000 EA: 1 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < N(S): 017 0: 0 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < N(R): 122 P: 0 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < 5 bytes of data 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < Protocol Discriminator: Q.931 (8) len=5 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent to originator) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 < Message Type: CONNECT (7) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 Received message for call 0x2aaac801ff90 on 0x8e45f70 TEI/SAPI 0/0, call->pri is 0x8e45f70 TEI/SAPI 0/0 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 q931.c:6919 post_handle_q931_message: Call 34100 enters state 10 (Active). Hold state: Idle 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > DL-DATA request 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > Protocol Discriminator: Q.931 (8) len=5 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent from originator) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > Message Type: CONNECT ACKNOWLEDGE (15) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 TEI=0 Transmitting N(S)=122, window is open V(A)=122 K=7 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:32.293205 [DEBUG] ftmod_libpri.c:143 > V(A)=122, V(S)=122, V(R)=18 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > T200_id=0, N200=3, T203_id=1 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > [ 00 01 f4 24 08 02 05 34 0f ] 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > Informational frame: 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > SAPI: 00 C/R: 0 EA: 0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > TEI: 000 EA: 1 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > N(S): 122 0: 0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > N(R): 018 P: 0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > 5 bytes of data 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > Protocol Discriminator: Q.931 (8) len=5 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > TEI=0 Call Ref: len= 2 (reference 1332/0x534) (Sent from originator) 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > Message Type: CONNECT ACKNOWLEDGE (15) 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 -- Stopping T203 timer 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 -- Starting T200 timer 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > V(A)=122, V(S)=123, V(R)=18 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > T200_id=1, N200=3, T203_id=0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > [ 02 01 01 24 ] 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > Supervisory frame: 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > SAPI: 00 C/R: 1 EA: 0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > TEI: 000 EA: 1 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > N(R): 018 P/F: 0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 > 0 bytes of data 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:143 Done handling message for SAPI/TEI=0/0 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:732 -- Answer on channel 1:20 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:733 [s1c20][1:20] Changed state from PROGRESS_MEDIA to UP 2010-11-05 10:18:32.294210 [DEBUG] ftmod_libpri.c:466 1:20 STATE [UP] 2010-11-05 10:18:32.294210 [DEBUG] mod_freetdm.c:2048 got clear channel sig [UP] 2010-11-05 10:18:32.294210 [DEBUG] switch_channel.c:2694 (FreeTDM/1:20/1239xxxxxxx) Callstate Change EARLY -> ACTIVE 2010-11-05 10:18:32.294210 [DEBUG] switch_channel.c:2706 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:32.294210 [NOTICE] mod_freetdm.c:2083 Channel [FreeTDM/1:20/1239xxxxxxx] has been answered 2010-11-05 10:18:32.294210 [DEBUG] switch_channel.c:2778 FreeTDM/1:20/1239xxxxxxx receive message [AUDIO_SYNC] 2010-11-05 10:18:32.294210 [DEBUG] ftdm_io.c:2613 [s1c20][1:20] Enabled software DTMF detector 2010-11-05 10:18:32.300188 [DEBUG] switch_ivr_bridge.c:398 sofia/internal/903@192.168.1.20:5060 receive message [ANSWER] 2010-11-05 10:18:32.309133 [DEBUG] mod_sofia.c:680 Local SDP sofia/internal/903@192.168.1.20:5060: v=0 o=FreeSWITCH 1288948829 1288948831 IN IP4 192.168.1.20 s=FreeSWITCH c=IN IP4 192.168.1.20 t=0 0 m=audio 17872 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 a=sendrecv 2010-11-05 10:18:32.309133 [DEBUG] switch_core_session.c:676 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:32.309133 [DEBUG] switch_channel.c:2694 (sofia/internal/903@192.168.1.20:5060) Callstate Change EARLY -> ACTIVE 2010-11-05 10:18:32.309133 [DEBUG] sofia.c:4569 Channel sofia/internal/903@192.168.1.20:5060 entering state [completed][200] 2010-11-05 10:18:32.309133 [NOTICE] switch_ivr_bridge.c:398 Channel [sofia/internal/903@192.168.1.20:5060] has been answered 2010-11-05 10:18:32.310131 [DEBUG] switch_channel.c:2778 sofia/internal/903@192.168.1.20:5060 receive message [AUDIO_SYNC] 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < TEI: 0 State 7(Multi-frame established) 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < V(A)=122, V(S)=123, V(R)=18 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < K=7, RC=0, l3initiated=0, reject_except=0, ack_pend=0 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < T200_id=1, N200=3, T203_id=0 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < [ 00 01 01 f6 ] 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < Supervisory frame: 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < SAPI: 00 C/R: 0 EA: 0 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < TEI: 000 EA: 1 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < N(R): 123 P/F: 0 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 < 0 bytes of data 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 -- Got ACK for N(S)=122 to (but not including) N(S)=123 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 -- ACKing N(S)=122, txqueue head is N(S)=-1 (-1 is empty, -2 is not transmitted) 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 -- Stopping T200 timer 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 -- Starting T203 timer 2010-11-05 10:18:32.310131 [DEBUG] ftmod_libpri.c:143 Done handling message for SAPI/TEI=0/0 2010-11-05 10:18:32.505128 [DEBUG] sofia.c:4569 Channel sofia/internal/903@192.168.1.20:5060 entering state [ready][200] 2010-11-05 10:18:32.510132 [DEBUG] switch_core_session.c:738 Send signal FreeTDM/1:20/1239xxxxxxx [BREAK] 2010-11-05 10:18:32.510132 [DEBUG] switch_core_session.c:738 Send signal sofia/internal/903@192.168.1.20:5060 [BREAK] 2010-11-05 10:18:32.520128 [DEBUG] switch_ivr_bridge.c:133 FreeTDM/1:20/1239xxxxxxx receive message [DISPLAY] 2010-11-05 10:18:32.540207 [DEBUG] switch_ivr_bridge.c:133 sofia/internal/903@192.168.1.20:5060 receive message [DISPLAY] 2010-11-05 10:18:32.540207 [DEBUG] sofia.c:4569 Channel sofia/internal/903@192.168.1.20:5060 entering state [calling][0] 2010-11-05 10:18:32.707131 [DEBUG] sofia.c:4569 Channel sofia/internal/903@192.168.1.20:5060 entering state [ready][200] 2010-11-05 10:18:32.707131 [DEBUG] sofia.c:4580 Remote SDP: v=0 o=MxSIP 0 1 IN IP4 192.168.1.194 s=SIP Call c=IN IP4 192.168.1.194 t=0 0 m=audio 3000 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=silenceSupp:off - - - - a=ptime:30 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[G7221:115:32000:20:48000] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[G7221:107:16000:20:32000] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[G722:9:8000:20:64000] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[PCMU:0:8000:20:64000] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[PCMA:8:8000:20:64000] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4353 Audio Codec Compare [PCMU:0:8000:30:64000]/[GSM:3:8000:20:13200] 2010-11-05 10:18:32.707131 [DEBUG] sofia_glue.c:4406 Substituting codec PCMU@30i@8000h 2010-11-05 10:18:32.708248 [DEBUG] sofia_glue.c:2654 Already using PCMU 2010-11-05 10:18:32.708248 [DEBUG] sofia_glue.c:4457 Set 2833 dtmf send/recv payload to 101 2010-11-05 10:18:32.708248 [DEBUG] sofia.c:5027 Processing updated SDP 2010-11-05 10:18:32.708248 [DEBUG] sofia_glue.c:2946 Audio params are unchanged for sofia/internal/903@192.168.1.20:5060. *** Snip 12213 lines that do not have the phone number, extension, nor PRI reference number in them (other calls) *** 2010-11-05 10:20:05.562219 [DEBUG] sofia.c:5421 Process REFER to [903(a)192.168.1.20] *** Snip 6775 lines that do not have the phone number, extension, nor PRI reference number in them (other calls) *** 2010-11-05 10:20:08.331307 [DEBUG] sofia.c:5421 Process REFER to [903(a)192.168.1.20] *** Snip 15859 lines that do not have the phone number, extension, nor PRI reference number in them (other calls) *** 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:20/1239xxxxxxx ending bridge by request from read function 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:564 BRIDGE THREAD DONE [FreeTDM/1:20/1239xxxxxxx] 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:22/14345286762 ending bridge by request from read function 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:19/4843 ending bridge by request from read function 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:564 BRIDGE THREAD DONE [FreeTDM/1:22/14345286762] 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:564 BRIDGE THREAD DONE [FreeTDM/1:19/4843] 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/405@192.168.1.20:5060 [BREAK] 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/sip:410@192.168.1.179:5060 [BREAK] 2010-11-05 10:20:59.890996 [DEBUG] switch_utils.c:631 Emailed file [/tmp/mail.12889668575391] to [award(a)tribetrans.com] 2010-11-05 10:20:59.890996 [DEBUG] switch_channel.c:2457 (FreeTDM/1:22/14345286762) Callstate Change ACTIVE -> HANGUP 2010-11-05 10:20:59.890996 [DEBUG] mod_voicemail.c:2581 Sending message to award(a)tribetrans.com 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:17/4843 ending bridge by request from read function 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:564 BRIDGE THREAD DONE [FreeTDM/1:17/4843] 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/sip:506@192.168.1.169:5060 [BREAK] 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:15/15085868226 ending bridge by request from read function 2010-11-05 10:20:59.890996 [NOTICE] switch_ivr_bridge.c:636 Hangup FreeTDM/1:22/14345286762 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2010-11-05 10:20:59.890996 [WARNING] mod_freetdm.c:660 failed to wait for I/O 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:483 FreeTDM/1:18/16786171267 ending bridge by request from read function 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:564 BRIDGE THREAD DONE [FreeTDM/1:15/15085868226] 2010-11-05 10:20:59.890996 [DEBUG] switch_ivr_bridge.c:584 Send signal sofia/internal/509@192.168.1.20:5060 [BREAK] 2010-11-05 10:20:59.890996 [DEBUG] switch_channel.c:2457 (FreeTDM/1:15/15085868226) Callstate Change ACTIVE -> HANGUP 2010-11-05 10:20:59.890996 [DEBUG] switch_channel.c:2473 Send signal FreeTDM/1:22/14345286762 [KILL]

3 8

mod_ldap and mod_xml_ldap application?
by Johnson 17 Nov '10

17 Nov '10

Hi all, I just plan to store my contact numbers into my white list directory, LDAP database. Is someone to know how to use these two modules in Freeswitch? Which one is more reliable and functional? There is few documents supported the modules in this community. Any more detail information is much appreciated . -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/mod-ldap-and-mod-xml-ldap-app… Sent from the freeswitch-users mailing list archive at Nabble.com.

2 2

Web interface (or a client application) to controlling calls, conferences, fifos, faxes, etc.
by Tóth Róbert 17 Nov '10

17 Nov '10

Hello I am finding a web interface (or a client application) to: - controlling existing calls (kill, spy, intercept, transfer to another extension, etc.) - controlling conferences (throw out sb, invite sb, volume control, lock, pin code, etc) - controlling fifos (listing, pick up sb, ordering, hang up sb, etc) - send faxes, managing received faxes - view call detail records and play recorded sessions (if recorded) As i see, FreePBX and FusionPBX are good to configuring FS, they are for system administrators. Do you know an interface for everyday system users? Is there a system for this? thx Rob

4 3

FreeSWITCH Conference Call Today
by Michael Collins 17 Nov '10

17 Nov '10

Hello all, It's Wednesday so that means FreeSWITCH conference call! Here's the agenda: http://wiki.freeswitch.org/wiki/FS_weekly_2010_11_17 We have a lot of little things to discuss, plus DRK is planning on stopping by to talk more about his fun .NET stuff! Talk to you soon. -MC

1 0

Sending UPDATE to a conference.
by M. Ranganathan 17 Nov '10

17 Nov '10

Hello, I would like to know if FreeSWTICH would support sending an in-Dialog UPDATE to a conference in progress for the purpose of media codec renegotiation while the conference is in progress. I work for Avaya. We are using FreeSWITCH in our Avaya SCS project. Thank you in advance for your help. Ranga -- M. Ranganathan

1 0

freetdm context not defined error
by ovvenkat 17 Nov '10

17 Nov '10

Hi to all, I am using following freetdm configuration file *freetdm.conf.xml* <config_profiles> <profile name="my_pri1"> <param name="outbound-called-ton" value="unknown"/> <param name="outbound-called-npi" value="unknown"/> <param name="outbound-rdnis-ton" value="unknown"/> <param name="outbound-rdnis-npi" value="unknown"/> <param name="outbound-calling-ton" value="unknown"/> <param name="outbound-calling-npi" value="unknown"/> <param name="switchtype" value="euroisdn" /> <param name="interface" value="cpe"/> </profile> </config_profiles> <sangoma_pri_spans> <span name="wp1" cfgprofile="my_pri1"> <param name="mode" value="user"/> <param name="context" value="default"/> <param name="dialplan" value="XML"/> </span> </sangoma_pri_spans> I can do outbound call. when I am trying to handle the incoming call, from PRI line call is not landing, When I check the fs_cli log files, it says that, 2010-11-17 02:10:16.853170 [INFO] mod_dialplan_xml.c:331 Processing <1234012480>->1100 in context 2010-11-17 02:10:16.853170 [WARNING] mod_dialplan_xml.c:361 Context not found 2010-11-17 02:10:16.853170 [INFO] switch_core_state_machine.c:142 No Route, Aborting 2010-11-17 02:10:16.853170 [DEBUG] switch_channel.c:2457 (FreeTDM/1:6/1100) Callstate Change RINGING -> HANGUP 2010-11-17 02:10:16.853170 [NOTICE] switch_core_state_machine.c:143 Hangup FreeTDM/1:6/1100 [CS_ROUTING] [NO_ROUTE_DESTINATION] Its not taking the context which is defined in the above configuration file. If I call 1100 from, sip phone call is landing properly. As of now, I have added my dial plan inside the /usr/local/freeswitch/conf/dialplan/default.xml. Previously it was working fine. After updating latest wanpipe and git version of freeSwitch, It stopped working. Any help would be appreciated. -- If you have come to help me, you are wasting your time. If you have come to because your liberation is bound up in mine, we can work together. Regards Venkatesan OV.

4 5