- FreeSWITCH-users - FreeSWITCH Mailing Lists

Invalid Application hash
by David Wafula 29 Mar '11

29 Mar '11

Hi all, Notice the last line in the log below when i dial 1001. This is from the latest git as of this morning. Any pointers? thanks. Dialplan: sofia/internal/1000(a)146.141.76.153 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(dialed_extension=1001) Dialplan: sofia/internal/1000(a)146.141.76.153 Action export(dialed_extension=1001) Dialplan: sofia/internal/1000(a)146.141.76.153 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1000(a)146.141.76.153 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1000(a)146.141.76.153 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(call_timeout=30) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(continue_on_fail=true) Dialplan: sofia/internal/1000(a)146.141.76.153 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1000(a)146.141.76.153 Action answer() Dialplan: sofia/internal/1000(a)146.141.76.153 Action sleep(1000) Dialplan: sofia/internal/1000(a)146.141.76.153 Action voicemail(default ${domain_name} ${dialed_extension}) 2010-10-25 10:47:47.193206 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/1000(a)146.141.76.153) State Change CS_ROUTING -> CS_EXECUTE 2010-10-25 10:47:47.193206 [DEBUG] switch_core_session.c:1057 Send signal sofia/internal/1000(a)146.141.76.153 [BREAK] 2010-10-25 10:47:47.193206 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/1000(a)146.141.76.153) State ROUTING going to sleep 2010-10-25 10:47:47.193206 [DEBUG] switch_core_state_machine.c:318 (sofia/internal/1000(a)146.141.76.153) Running State Change CS_EXECUTE 2010-10-25 10:47:47.193206 [DEBUG] switch_core_state_machine.c:352 (sofia/internal/1000(a)146.141.76.153) State EXECUTE 2010-10-25 10:47:47.193206 [DEBUG] mod_sofia.c:239 sofia/internal/ 1000(a)146.141.76.153 SOFIA EXECUTE 2010-10-25 10:47:47.193206 [DEBUG] switch_core_state_machine.c:157 sofia/internal/1000(a)146.141.76.153 Standard EXECUTE EXECUTE sofia/internal/1000(a)146.141.76.153 set(open=true) 2010-10-25 10:47:47.193206 [DEBUG] mod_dptools.c:1028 sofia/internal/ 1000(a)146.141.76.153 SET [open]=[true] 2010-10-25 10:47:47.193206 [ERR] switch_core_session.c:1807 Invalid Application hash -- David Wafula

3 3

Weird results with "show calls"
by Dave Bracken 28 Mar '11

28 Mar '11

I am just wondering what your thoughts are on this. When i use Delphi to originate a call to a softphone, and then do a "show calls", it shows zero calls. If o call one softphone to another, then it shows 1 call. Why is it not showing any info for a software originated call? anybody? Thanks in advance, Dave

2 1

Embarrassing Question: Local extension registering in the Public context on default configuration?
by A E [Gmail] 28 Mar '11

28 Mar '11

Hi All, I've used FS in the past to varying degrees but never as a PBX or a REGISTRAR and just to test basic config, I built and installed it and didn't change a damn thing. Had a softphone on the same internal network registered to it using the default password, but it seems to register itself in the public context when I'd have thought it'd register in default context so I can test all those pre-built extensions for an echo test, dumping channel variables etc. But they don't work as the call originated to say 5000 from extension 1000 goes into the public context which doesn't have 5000. What is going on? It's so embarrassing to ask such a simple question :( freeswitch@internal> sofia status profile internal 1000 ================================================================================================= Name internal Domain Name N/A Auto-NAT false DBName sofia_reg_internal Pres Hosts 192.168.3.101,192.168.3.101 Dialplan XML Context public Challenge Realm auto_from RTP-IP 192.168.3.101 SIP-IP 192.168.3.101 URL sip:mod_sofia@192.168.3.101:5060 BIND-URL sip:mod_sofia@192.168.3.101:5060 HOLD-MUSIC local_stream://moh OUTBOUND-PROXY N/A CODECS IN G7221@32000h,G7221@16000h,G722,BV32,PCMU,PCMA,GSM CODECS OUT G7221@32000h,G7221@16000h,G722,BV32,PCMU,PCMA,GSM TEL-EVENT 101 DTMF-MODE rfc2833 CNG 13 SESSION-TO 0 MAX-DIALOG 0 NOMEDIA false LATE-NEG false PROXY-MEDIA false AGGRESSIVENAT false STUN-ENABLED true STUN-AUTO-DISABLE false CALLS-IN 0 FAILED-CALLS-IN 0 CALLS-OUT 0 FAILED-CALLS-OUT 0 Registrations: ================================================================================================= Call-ID: ZDVjOThlZmZhN2JhOGMyYjA1MTUxMzliYzAwMzNhYjU. User: 1000(a)192.168.3.101 Contact: "FreeSWITCH 1000" <sip:1000@192.168.3.121:49950 ;rinstance=15dfcfcc0353b7c7;fs_nat=yes;fs_path=sip%3A1000%40192.168.3.121%3A49950%3Brinstance%3D15dfcfcc0353b7c7> Agent: Bria Professional release 2.4.3 stamp 50906 Status: Registered(UDP-NAT)(unknown) EXP(2011-03-26 02:18:52) EXPSECS(1146) Host: Solaris11Ex IP: 192.168.3.121 Port: 49950 Auth-User: 1000 Auth-Realm: 192.168.3.101 MWI-Account: 1000(a)192.168.3.101

4 10

Stopping uuid_record error
by Dave Bracken 28 Mar '11

28 Mar '11

I have figured out how to start recording using uuid_record, but when i try to stop the record, i get: -ERR Cannot stop record session! here is my code(with a sudo uuid in place here) api uuid_record 36dfdf636dfd6f36df start test.wav and to stop the record: api uuid_record 36dfdf636dfd6f36df stop test.wav the start one works fine, but the stop one does not. What am i missing here? Thanks in advance, Dave

3 3

CALL_REJECT on freeswitch
by Gourav Vohra 28 Mar '11

28 Mar '11

Does the call have to be rejected twice by the end user for calls to be transferred to voicemail on freeswitch? In my case I have to hit the reject button twice on the phone for calls to be transferred to voicemail. Thanks for your help.

2 1

mod_fifo & CID
by Yuriy Ivzhenko 28 Mar '11

28 Mar '11

Hi All, After upgrading to last Git (git-73ca862) i see changes in CID on calls to agents, generated by mod_fifo. If agent answer caller_profile.caller_id_name = "Outbound Call" caller_profile.caller_id_number = <agent number> If agent not answer caller_profile.caller_id_name = caller caller_id_name caller_profile.caller_id_number = caller caller_id_number (or origination_caller_id_name/number of set in agents dialstring) In old version, so it was always. Is this correct? It seems to me it should not depend on, answered the call or not.

3 5

transcoding GSM with a high ptime
by Dan Lane 28 Mar '11

28 Mar '11

I need to do a bit more work on this before I have enough information to submit a Jira but just on the off-chance anyone else has had this issue: We have handsets using GSM with 120ms ptime but when this gets transcoded to something else (for example 20ms PCMU) the resulting audio is choppy as though there was a timing error. We only experience this with GSM, 120ms packets to 20ms transcoding between other formats is fine. Has anyone else experienced this? I've experienced it on git-e7acd4d (our production kit) and f3c33c7 (due to become our next production kit) I'll continue to test it before submitting a Jira but I wanted to know if it was just us experiencing this. Regards, Dan

3 4

Getting RC=200 OK instead of RC=183 Session Progress // Reason: Q.850; cause=16; text="NORMAL_CLEARING"
by Melih Vardar 28 Mar '11

28 Mar '11

Hello, I am trying to call a softphone via a Java Applet application. I have a VPN and there is no proxy just Freeswitch between the 2 phones. Everything works fine with 2 SJPhones. But trying it with my Applet causes -> Reason: Q.850;cause=16;text="NORMAL_CLEARING". When I check the network traffic I see that after 100(Trying) comes directly 200(OK). By using SJPhone it is 183(Session Progress) after 100(Trying) and the connection is esablished for voice communication. I also attached the SIP outputs and the log from server ( generated with "sofia loglevel all 9" ). I have searched a lot of sites but I haven't found the problem. I appreciate any help, Thanks, Melih +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ INVITE sip:1000@xx.yy.zz.1 SIP/2.0 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 1 INVITE From: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 To: <sip:1000@xx.yy.zz.1> Via: SIP/2.0/UDP xx.yy.zz.66:4829;rport;branch=z9hG4bK89f52f6729c740781eac05ab4a1a99bb Max-Forwards: 70 Contact: <sip:1016@xx.yy.zz.66> User-Agent: JavaSoftPhone v1.0 Supported: replaces,norefersub,timer Content-Type: application/sdp Content-Length: 306 v=0 o=- 814489 815858 IN IP4 xx.yy.zz.66 s=JavaSoftPhone c=IN IP4 xx.yy.zz.66 t=0 0 m=audio 3454 RTP/AVP 0 3 4 5 101 c=IN IP4 xx.yy.zz.66 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:4 G723/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=setup:active a=sendrecv SIP/2.0 100 Trying Via: SIP/2.0/UDP xx.yy.zz.66:4829;rport=4829;branch=z9hG4bK89f52f6729c740781eac05ab4a1a99bb From: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 To: <sip:1000@xx.yy.zz.1> Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Content-Length: 0 SIP/2.0 200 OK Via: SIP/2.0/UDP xx.yy.zz.66:4829;rport=4829;branch=z9hG4bK89f52f6729c740781eac05ab4a1a99bb From: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 To: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 1 INVITE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Require: timer Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Session-Expires: 120;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 239 v=0 o=FreeSWITCH 1301299753 1301299754 IN IP4 xx.yy.zz.1 s=FreeSWITCH c=IN IP4 xx.yy.zz.1 t=0 0 m=audio 21030 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:20 ACK sip:1000@xx.yy.zz.1:5060;transport=udp SIP/2.0 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 1 ACK From: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 To: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ Via: SIP/2.0/UDP xx.yy.zz.66:4829;rport;branch=6b3a31302e352e352e36363a3438323 Max-Forwards: 70 Content-Length: 0 BYE sip:1016@xx.yy.zz.66 SIP/2.0 Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces *Reason: Q.850;cause=16;text="NORMAL_CLEARING"* Content-Length: 0 BYE sip:1016@xx.yy.zz.66 SIP/2.0 Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces *Reason: Q.850;cause=16;text="NORMAL_CLEARING"* Content-Length: 0 BYE sip:1016@xx.yy.zz.66 SIP/2.0 Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces *Reason: Q.850;cause=16;text="NORMAL_CLEARING"* Content-Length: 0 BYE sip:1016@xx.yy.zz.66 SIP/2.0 Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces *Reason: Q.850;cause=16;text="NORMAL_CLEARING"* Content-Length: 0 BYE sip:1016@xx.yy.zz.66 SIP/2.0 Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Contact: <sip:1000@xx.yy.zz.1:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-hacked Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces *Reason: Q.850;cause=16;text="NORMAL_CLEARING"* Content-Length: 0 SIP/2.0 200 OK Via: SIP/2.0/UDP xx.yy.zz.1;rport;branch=z9hG4bKUcjg7QjFeXSyB Max-Forwards: 70 From: <sip:1000@xx.yy.zz.1>;tag=HFr8848ZK8yjQ To: "My Name" <sip:1016@xx.yy.zz.1>;tag=3799 Call-ID: a830cf50124857e3ba148763920bf674(a)xx.yy.zz.66 CSeq: 10324328 BYE Content-Length: 0 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ freeswitch@internal> sofia status profile xx.yy.zz.1 ================================================================================================= Name xx.yy.zz.1 Domain Name N/A Alias Of internal DBName sofia_reg_internal Pres Hosts Dialplan XML Context public Challenge Realm auto_from RTP-IP xx.yy.zz.1 Ext-RTP-IP xx.yy.zz.1 SIP-IP xx.yy.zz.1 Ext-SIP-IP xx.yy.zz.1 URL sip:mod_sofia@xx.yy.zz.1:5060 BIND-URL sip:mod_sofia@xx.yy.zz.1:5060 HOLD-MUSIC local_stream://moh OUTBOUND-PROXY N/A CODECS G7221@32000h,G7221@16000h ,G722,PCMU,PCMA,GSM,speex@16000h@20i TEL-EVENT 101 DTMF-MODE rfc2833 CNG 13 SESSION-TO 0 MAX-DIALOG 0 NOMEDIA false LATE-NEG false PROXY-MEDIA false AGGRESSIVENAT false STUN-ENABLED true STUN-AUTO-DISABLE false CALLS-IN 483 FAILED-CALLS-IN 34 CALLS-OUT 1098 FAILED-CALLS-OUT 865 Registrations: ================================================================================================= ================================================================================================= freeswitch@internal> nta: timer J fired, terminate 401 response incoming_reclaim_all((nil), (nil), 0x4123cea0) nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/17 free nta: timer set next to 2192 ms nta: timer J fired, terminate 403 response incoming_reclaim_all((nil), (nil), 0x4123cea0) nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/16 free nta: timer not set tport_wakeup_pri(0x7028b0): events IN tport_recv_event(0x7028b0) tport_recv_iovec(0x7028b0) msg 0x11662d0 from (udp/xx.yy.zz.1:5060) has 364 bytes, veclen = 1 tport_deliver(0x7028b0): msg 0x11662d0 (364 bytes) from udp/xx.yy.zz.66:5060/sip next=(nil) nta: received REGISTER sip:xx.yy.zz.1:5060 SIP/2.0 (CSeq 1) nta: canonizing sip:xx.yy.zz.1:5060 with contact nta: REGISTER (1) going to a default leg nua: nua_stack_process_request: entering nua: nh_create: entering nua: nh_create_handle: entering nua: nua_stack_set_params: entering soa_clone(static::0x6efae0, 0x7154c0, 0x71df40) called soa_set_params(static::0x1148020, ...) called nua(0x71df40): event i_register 100 Trying nua: nua_application_event: entering nua: nua_respond: entering nua(0x71df40): sent signal r_respond nua: nua_handle_destroy: entering nua(0x71df40): sent signal r_destroy nua: nua_handle_magic: entering nua: nua_handle_destroy: entering nua(0x71df40): recv signal r_respond 401 Unauthorized nua: nua_stack_set_params: entering soa_set_params(static::0x1148020, ...) called tport_tsend(0x7028b0) tpn = UDP/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name UDP/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 628 bytes of 628 to udp/xx.yy.zz.66:4829 tport_vsend returned 628 nta: sent 401 Unauthorized for REGISTER (1) nta: timer set to 32000 ms nua(0x71df40): recv signal r_destroy nta_leg_destroy((nil)) soa_destroy(static::0x1148020) called freeswitch@internal> freeswitch@internal> freeswitch@internal> freeswitch@internal> tport_wakeup_pri(0x7028b0): events IN tport_recv_event(0x7028b0) tport_recv_iovec(0x7028b0) msg 0x768b30 from (udp/xx.yy.zz.1:5060) has 568 bytes, veclen = 1 tport_deliver(0x7028b0): msg 0x768b30 (568 bytes) from udp/xx.yy.zz.66:5060/sip next=(nil) nta: received REGISTER sip:xx.yy.zz.1:5060 SIP/2.0 (CSeq 2) nta: canonizing sip:xx.yy.zz.1:5060 with contact nta: REGISTER (2) going to a default leg nua: nua_stack_process_request: entering nua: nh_create: entering nua: nh_create_handle: entering nua: nua_stack_set_params: entering soa_clone(static::0x6efae0, 0x7154c0, 0x1118070) called soa_set_params(static::0x1148020, ...) called nua(0x1118070): event i_register 100 Trying nua: nua_application_event: entering nua: nua_respond: entering nua(0x1118070): sent signal r_respond nua(0x1118070): recv signal r_respond 200 OK nua: nua_stack_set_params: entering soa_set_params(static::0x1148020, ...) called tport_tsend(0x7028b0) tpn = UDP/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name UDP/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 551 bytes of 551 to udp/xx.yy.zz.66:4829 tport_vsend returned 551 nta: sent 200 OK for REGISTER (2) nua: nua_handle_destroy: entering nua(0x1118070): sent signal r_destroy nua: nua_handle_magic: entering nua: nua_handle_destroy: entering nua(0x1118070): recv signal r_destroy nta_leg_destroy((nil)) soa_destroy(static::0x1148020) called freeswitch@internal> freeswitch@internal> freeswitch@internal> freeswitch@internal> freeswitch@internal> tport_wakeup_pri(0x7028b0): events IN tport_recv_event(0x7028b0) tport_recv_iovec(0x7028b0) msg 0x1108a50 from (udp/xx.yy.zz.1:5060) has 744 bytes, veclen = 1 tport_deliver(0x7028b0): msg 0x1108a50 (744 bytes) from udp/xx.yy.zz.66:5060/sip next=(nil) nta: received INVITE sip:1000@xx.yy.zz.1 SIP/2.0 (CSeq 1) nta: canonizing sip:1000@xx.yy.zz.1 with contact nta: INVITE (1) going to a default leg nta: timer shortened to 200 ms nua: nua_stack_process_request: entering nua: nh_create: entering nua: nh_create_handle: entering nua: nua_stack_set_params: entering soa_clone(static::0x6efae0, 0x7154c0, 0x11170f0) called soa_set_params(static::0x1148020, ...) called nta_leg_tcreate(0x110a160) soa_init_offer_answer(static::0x1148020) called soa_set_remote_sdp(static::0x1148020, (nil), 0x117ad96, 306) called nua(0x11170f0): adding session usage tport_tsend(0x7028b0) tpn = UDP/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name UDP/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 328 bytes of 328 to udp/xx.yy.zz.66:4829 tport_vsend returned 328 nta: sent 100 Trying for INVITE (1) nua(0x11170f0): event i_invite 100 Trying nua(0x11170f0): call state changed: init -> received, received offer soa_get_remote_sdp(static::0x1148020, [0x4123c558], [0x4123c550], [(nil)]) called nua(0x11170f0): event i_state 100 Trying nua: nua_application_event: entering 2011-03-28 15:57:20.161392 [DEBUG] sofia.c:4671 IP xx.yy.zz.66 Approved by acl "domains[]". Access Granted. 2011-03-28 15:57:20.161392 [NOTICE] switch_channel.c:613 New Channel sofia/internal/1016(a)xx.yy.zz.1 [4c7785ba-5943-11e0-8c96-03c3bfaa409b] nua: nua_handle_bind: entering 2011-03-28 15:57:20.161392 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_NEW 2011-03-28 15:57:20.161392 [DEBUG] switch_core_state_machine.c:404 (sofia/internal/1016(a)xx.yy.zz.1) State NEW 2011-03-28 15:57:20.161392 [DEBUG] sofia.c:5408 Setting NAT mode based on nat.auto nua: nua_handle_magic: entering nua: nua_application_event: entering 2011-03-28 15:57:20.161392 [DEBUG] sofia.c:3334 Channel sofia/internal/1016(a)xx.yy.zz.1 entering state [received][100] 2011-03-28 15:57:20.161392 [DEBUG] sofia.c:3341 Remote SDP: v=0 o=- 652619 653988 IN IP4 xx.yy.zz.66 s=JavaSoftPhone c=IN IP4 xx.yy.zz.66 t=0 0 m=audio 1370 RTP/AVP 0 3 4 5 101 c=IN IP4 xx.yy.zz.66 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:4 G723/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=setup:active 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:3136 Audio Codec Compare [PCMU:0:8000:0]/[G7221:115:32000:20] 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:3136 Audio Codec Compare [PCMU:0:8000:0]/[G7221:107:16000:20] 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:3136 Audio Codec Compare [PCMU:0:8000:0]/[G722:9:8000:20] 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:3136 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:2094 Set Codec sofia/internal/1016(a)xx.yy.zz.1 PCMU/8000 20 ms 160 samples 2011-03-28 15:57:20.161392 [DEBUG] sofia_glue.c:3096 Set 2833 dtmf payload to 101 2011-03-28 15:57:20.161392 [DEBUG] sofia.c:3502 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_NEW -> CS_INIT 2011-03-28 15:57:20.161392 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] nua: nua_handle_magic: entering 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_INIT 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:422 (sofia/internal/1016(a)xx.yy.zz.1) State INIT 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:83 sofia/internal/1016(a)xx.yy.zz.1 SOFIA INIT 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:111 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_INIT -> CS_ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:422 (sofia/internal/1016(a)xx.yy.zz.1) State INIT going to sleep 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:425 (sofia/internal/1016(a)xx.yy.zz.1) State ROUTING 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:130 sofia/internal/1016(a)xx.yy.zz.1 SOFIA ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:78 sofia/internal/1016(a)xx.yy.zz.1 Standard ROUTING 2011-03-28 15:57:20.181410 [INFO] mod_dialplan_xml.c:391 Processing My Name->1000 in context public Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [public->unloop] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [public->outside_call] continue=true Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Absolute Condition [outside_call] Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(outside_call=true) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [public->call_debug] continue=true Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [public->public_extensions] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (PASS) [public_extensions] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action transfer(1000 XML default) 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:114 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_ROUTING -> CS_EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:425 (sofia/internal/1016(a)xx.yy.zz.1) State ROUTING going to sleep 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:432 (sofia/internal/1016(a)xx.yy.zz.1) State EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:173 sofia/internal/1016(a)xx.yy.zz.1 SOFIA EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:151 sofia/internal/1016(a)xx.yy.zz.1 Standard EXECUTE EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(outside_call=true) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [outside_call]=[true] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 transfer(1000 XML default) 2011-03-28 15:57:20.181410 [DEBUG] switch_ivr.c:1344 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_EXECUTE -> CS_ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.181410 [DEBUG] switch_ivr.c:1348 sofia/internal/1016(a)xx.yy.zz.1 receive message [TRANSFER] 2011-03-28 15:57:20.181410 [DEBUG] switch_core_session.c:630 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.181410 [NOTICE] switch_ivr.c:1350 Transfer sofia/internal/1016(a)xx.yy.zz.1 to XML[1000@default] 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:432 (sofia/internal/1016(a)xx.yy.zz.1) State EXECUTE going to sleep 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:425 (sofia/internal/1016(a)xx.yy.zz.1) State ROUTING 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:130 sofia/internal/1016(a)xx.yy.zz.1 SOFIA ROUTING 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:78 sofia/internal/1016(a)xx.yy.zz.1 Standard ROUTING 2011-03-28 15:57:20.181410 [INFO] mod_dialplan_xml.c:391 Processing My Name->1000 in context default Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->unloop] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->tod_example] continue=true Dialplan: day of week[2] =~ 2-6 (PASS) Dialplan: hour[15] =~ 9-18 (PASS) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(open=true) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [global-intercept] destination_number(1000) =~ /^886$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [group-intercept] destination_number(1000) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [intercept-ext] destination_number(1000) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->redial] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [redial] destination_number(1000) =~ /^870$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->global] continue=true Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Absolute Condition [global] Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [snom-demo-2] destination_number(1000) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [snom-demo-1] destination_number(1000) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^88(.*)$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^779$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->call_return] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [call_return] destination_number(1000) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->del-group] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [del-group] destination_number(1000) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->add-group] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [add-group] destination_number(1000) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [call-group-simo] destination_number(1000) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [call-group-order] destination_number(1000) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (FAIL) [extension-intercom] destination_number(1000) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Regex (PASS) [Local_Extension] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(dialed_extension=1000) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action export(dialed_extension=1000) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action bind_meta_app(2 b s record_session::/opt/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(call_timeout=30) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(continue_on_fail=true) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action answer() Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action sleep(1000) Dialplan: sofia/internal/1016(a)xx.yy.zz.1 Action voicemail(default ${domain_name} ${dialed_extension}) 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:114 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_ROUTING -> CS_EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:425 (sofia/internal/1016(a)xx.yy.zz.1) State ROUTING going to sleep 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:432 (sofia/internal/1016(a)xx.yy.zz.1) State EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] mod_sofia.c:173 sofia/internal/1016(a)xx.yy.zz.1 SOFIA EXECUTE 2011-03-28 15:57:20.181410 [DEBUG] switch_core_state_machine.c:151 sofia/internal/1016(a)xx.yy.zz.1 Standard EXECUTE EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(open=true) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [open]=[true] EXECUTE sofia/internal/1016@xx.yy.zz.1hash(insert/xx.yy.zz.1-spymap/1016/4c7785ba-5943-11e0-8c96-03c3bfaa409b) EXECUTE sofia/internal/1016(a)xx.yy.zz.1hash(insert/xx.yy.zz.1-last_dial/1016/1000) EXECUTE sofia/internal/1016@xx.yy.zz.1hash(insert/xx.yy.zz.1-last_dial/global/4c7785ba-5943-11e0-8c96-03c3bfaa409b) EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(dialed_extension=1000) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [dialed_extension]=[1000] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 export(dialed_extension=1000) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:886 EXPORT [dialed_extension]=[1000] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 bind_meta_app(1 b s execute_extension::dx XML features) 2011-03-28 15:57:20.181410 [INFO] switch_ivr_async.c:1835 Bound B-Leg: 1 execute_extension::dx XML features EXECUTE sofia/internal/1016(a)xx.yy.zz.1 bind_meta_app(2 b s record_session::/opt/freeswitch/recordings/1016.2011-03-28-15-57-20.wav) 2011-03-28 15:57:20.181410 [INFO] switch_ivr_async.c:1835 Bound B-Leg: 2 record_session::/opt/freeswitch/recordings/1016.2011-03-28-15-57-20.wav EXECUTE sofia/internal/1016(a)xx.yy.zz.1 bind_meta_app(3 b s execute_extension::cf XML features) 2011-03-28 15:57:20.181410 [INFO] switch_ivr_async.c:1835 Bound B-Leg: 3 execute_extension::cf XML features EXECUTE sofia/internal/1016(a)xx.yy.zz.1set(ringback=%(2000,4000,440.0,480.0)) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [ringback]=[%(2000,4000,440.0,480.0)] EXECUTE sofia/internal/1016@xx.yy.zz.1set(transfer_ringback=local_stream://moh) 2011-03-28 15:57:20.181410 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(call_timeout=30) 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [call_timeout]=[30] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(hangup_after_bridge=true) 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 set(continue_on_fail=true) 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [continue_on_fail]=[true] EXECUTE sofia/internal/1016(a)xx.yy.zz.1hash(insert/xx.yy.zz.1-call_return/1000/1016) EXECUTE sofia/internal/1016@xx.yy.zz.1hash(insert/xx.yy.zz.1-last_dial_ext/1000/4c7785ba-5943-11e0-8c96-03c3bfaa409b) EXECUTE sofia/internal/1016(a)xx.yy.zz.1set(called_party_callgroup=techsupport) 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:748 sofia/internal/1016(a)xx.yy.zz.1 SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1016@xx.yy.zz.1hash(insert/xx.yy.zz.1-last_dial/techsupport/4c7785ba-5943-11e0-8c96-03c3bfaa409b) EXECUTE sofia/internal/1016(a)xx.yy.zz.1 bridge(user/1000(a)xx.yy.zz.1) 2011-03-28 15:57:20.191371 [DEBUG] switch_ivr_originate.c:1047 variable string 0 = [presence_id=1000(a)xx.yy.zz.1] 2011-03-28 15:57:20.191371 [ERR] switch_ivr_originate.c:1531 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 2011-03-28 15:57:20.191371 [DEBUG] switch_ivr_originate.c:2170 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-03-28 15:57:20.191371 [ERR] switch_ivr_originate.c:1531 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED] 2011-03-28 15:57:20.191371 [DEBUG] switch_ivr_originate.c:2170 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED] 2011-03-28 15:57:20.191371 [INFO] mod_dptools.c:2114 Originate Failed. Cause: USER_NOT_REGISTERED 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:2141 Continue on fail [true]: Cause: USER_NOT_REGISTERED EXECUTE sofia/internal/1016(a)xx.yy.zz.1 answer() 2011-03-28 15:57:20.191371 [DEBUG] mod_dptools.c:649 sofia/internal/1016(a)xx.yy.zz.1 receive message [ANSWER] 2011-03-28 15:57:20.191371 [DEBUG] sofia_glue.c:2328 AUDIO RTP [sofia/internal/1016(a)xx.yy.zz.1] xx.yy.zz.1 port 17768 -> xx.yy.zz.66 port 1370 codec: 0 ms: 20 2011-03-28 15:57:20.191371 [DEBUG] switch_rtp.c:1155 Starting timer [soft] 160 bytes per 20ms 2011-03-28 15:57:20.201410 [DEBUG] mod_sofia.c:536 Local SDP sofia/internal/1016(a)xx.yy.zz.1: v=0 o=FreeSWITCH 1301302872 1301302873 IN IP4 xx.yy.zz.1 s=FreeSWITCH c=IN IP4 xx.yy.zz.1 t=0 0 m=audio 17768 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:20 a=sendrecv nua: nua_respond: entering nua(0x11170f0): sent signal r_respond 2011-03-28 15:57:20.201410 [DEBUG] switch_core_session.c:630 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:20.201410 [NOTICE] mod_dptools.c:649 Channel [sofia/internal/1016(a)xx.yy.zz.1] has been answered 2011-03-28 15:57:20.201410 [DEBUG] switch_channel.c:182 sofia/internal/1016(a)xx.yy.zz.1 receive message [AUDIO_SYNC] EXECUTE sofia/internal/1016(a)xx.yy.zz.1 sleep(1000) nua(0x11170f0): recv signal r_respond 200 OK nua: nua_stack_set_params: entering soa_set_params(static::0x1148020, ...) called soa_set_user_sdp(static::0x1148020, (nil), 0x7fb13c02316d, -1) called soa_set_capability_sdp(static::0x1148020, (nil), 0x7fb13c02316d, -1) called nua: nua_invite_server_respond: entering soa_generate_answer(static::0x1148020) called soa_static_offer_answer_action(0x1148020, soa_generate_answer): called soa_static(0x1148020, soa_generate_answer): generating local description soa_static(0x1148020, soa_generate_answer): upgrade with remote description soa_sdp_mode_set(0x4123caa0, 0x116ef80, ""): called soa_static(0x1148020, soa_generate_answer): storing local description soa_activate(static::0x1148020, (nil)) called soa_get_local_sdp(static::0x1148020, [(nil)], [0x4123cc90], [0x4123cc9c]) called tport_tsend(0x7028b0) tpn = UDP/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name UDP/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 1064 bytes of 1064 to udp/xx.yy.zz.66:4829 tport_vsend returned 1064 nta: sent 200 OK for INVITE (1) nua(0x11170f0): call state changed: received -> completed, sent answer soa_get_local_sdp(static::0x1148020, [0x4123cde8], [0x4123cde0], [(nil)]) called soa_get_params(static::0x1148020, ...) called nua(0x11170f0): event i_state 200 OK 2011-03-28 15:57:20.201410 [DEBUG] switch_channel.c:182 sofia/internal/1016(a)xx.yy.zz.1 receive message [AUDIO_SYNC] nua: nua_application_event: entering 2011-03-28 15:57:20.201410 [DEBUG] sofia.c:3334 Channel sofia/internal/1016(a)xx.yy.zz.1 entering state [completed][200] nua: nua_handle_magic: entering tport_wakeup_pri(0x7028b0): events IN tport_recv_event(0x7028b0) tport_recv_iovec(0x7028b0) msg 0x1125e50 from (udp/xx.yy.zz.1:5060) has 327 bytes, veclen = 1 tport_deliver(0x7028b0): msg 0x1125e50 (327 bytes) from udp/xx.yy.zz.66:5060/sip next=(nil) nta: received ACK sip:1000@xx.yy.zz.1:5060;transport=udp SIP/2.0 (CSeq 1) nta: ACK (1) is going to INVITE (1) nua: process_ack_or_cancel: entering soa_clear_remote_sdp(static::0x1148020) called nua(0x11170f0): event i_ack 200 OK nua(0x11170f0): call state changed: completed -> ready nua(0x11170f0): event i_state 200 OK nua(0x11170f0): event i_active 200 Call active nua(): refresh session after 88 seconds (in [88..88]) nua: nua_application_event: entering nua: nua_handle_magic: entering nua: nua_application_event: entering 2011-03-28 15:57:20.231367 [DEBUG] sofia.c:3334 Channel sofia/internal/1016(a)xx.yy.zz.1 entering state [ready][200] nua: nua_handle_magic: entering nua: nua_application_event: entering nua: nua_handle_magic: entering nta: timer set next to 4862 ms EXECUTE sofia/internal/1016(a)xx.yy.zz.1 voicemail(default xx.yy.zz.1 1000) 2011-03-28 15:57:21.201425 [DEBUG] mod_voicemail.c:788 [default] rwlock 2011-03-28 15:57:21.201425 [ERR] mod_voicemail.c:2927 Error creating /opt/freeswitch/storage/voicemail/default/xx.yy.zz.1/1000 2011-03-28 15:57:21.201425 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2011-03-28 15:57:21.201425 [ERR] switch_ivr_play_say.c:148 Can't find language tag. 2011-03-28 15:57:21.201425 [WARNING] switch_ivr_play_say.c:364 Macro [voicemail_goodbye] did not match any patterns 2011-03-28 15:57:21.201425 [NOTICE] switch_core_state_machine.c:179 Hangup sofia/internal/1016(a)xx.yy.zz.1 [CS_EXECUTE] [NORMAL_CLEARING] 2011-03-28 15:57:21.201425 [DEBUG] switch_channel.c:1726 Send signal sofia/internal/1016(a)xx.yy.zz.1 [KILL] 2011-03-28 15:57:21.201425 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/1016(a)xx.yy.zz.1) State HANGUP 2011-03-28 15:57:21.201425 [DEBUG] mod_sofia.c:338 Channel sofia/internal/1016(a)xx.yy.zz.1 hanging up, cause: NORMAL_CLEARING 2011-03-28 15:57:21.201425 [DEBUG] mod_sofia.c:376 Sending BYE to sofia/internal/1016(a)xx.yy.zz.1 nua: nua_bye: entering nua(0x11170f0): sent signal r_bye nua(0x11170f0): recv signal r_bye nua: nua_stack_set_params: entering soa_set_params(static::0x1148020, ...) called soa_terminate(static::0x1148020) called soa_init_offer_answer(static::0x1148020) called nta: selecting scheme sip tport_tsend(0x7028b0) tpn = udp/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name udp/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 604 bytes of 604 to udp/xx.yy.zz.66:4829 tport_vsend returned 604 nta: sent BYE (10324256) to udp/xx.yy.zz.66:4829 tport_pend(0x7028b0): pending 0x7fb1440d6100 for udp/xx.yy.zz.1:5060 (already 0) nta: timer shortened to 500 ms 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1016(a)xx.yy.zz.1 Standard HANGUP, cause: NORMAL_CLEARING 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/1016(a)xx.yy.zz.1) State HANGUP going to sleep 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:432 (sofia/internal/1016(a)xx.yy.zz.1) State EXECUTE going to sleep 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_HANGUP 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:538 handler already called, skipping state handler. 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_HANGUP -> CS_REPORTING 2011-03-28 15:57:21.201425 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_REPORTING 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/1016(a)xx.yy.zz.1) State REPORTING 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1016(a)xx.yy.zz.1 Standard REPORTING, cause: NORMAL_CLEARING 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/1016(a)xx.yy.zz.1) State REPORTING going to sleep 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:411 (sofia/internal/1016(a)xx.yy.zz.1) State Change CS_REPORTING -> CS_DESTROY 2011-03-28 15:57:21.201425 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1016(a)xx.yy.zz.1 [BREAK] 2011-03-28 15:57:21.201425 [DEBUG] switch_core_session.c:1069 Session 1582 (sofia/internal/1016(a)xx.yy.zz.1) Locked, Waiting on external entities 2011-03-28 15:57:21.201425 [NOTICE] switch_core_session.c:1087 Session 1582 (sofia/internal/1016(a)xx.yy.zz.1) Ended 2011-03-28 15:57:21.201425 [NOTICE] switch_core_session.c:1089 Close Channel sofia/internal/1016(a)xx.yy.zz.1 [CS_DESTROY] 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:497 (sofia/internal/1016(a)xx.yy.zz.1) Running State Change CS_DESTROY 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1016(a)xx.yy.zz.1) State DESTROY 2011-03-28 15:57:21.201425 [DEBUG] mod_sofia.c:255 sofia/internal/1016(a)xx.yy.zz.1 SOFIA DESTROY 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1016(a)xx.yy.zz.1 Standard DESTROY 2011-03-28 15:57:21.201425 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1016(a)xx.yy.zz.1) State DESTROY going to sleep nta: timer E fired, retransmit BYE (10324256) tport_release(0x7028b0): 0x7fb1440d6100 by 0x7fb144068530 with (nil) tport_tsend(0x7028b0) tpn = udp/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name udp/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 604 bytes of 604 to udp/xx.yy.zz.66:4829 tport_vsend returned 604 nta: resent BYE (10324256) to udp/xx.yy.zz.66:4829 tport_pend(0x7028b0): pending 0x7fb1440d6100 for udp/xx.yy.zz.1:5060 (already 0) nta_outgoing_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta: timer set next to 1000 ms nta: timer E fired, retransmit BYE (10324256) tport_release(0x7028b0): 0x7fb1440d6100 by 0x7fb144068530 with (nil) tport_tsend(0x7028b0) tpn = udp/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name udp/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 604 bytes of 604 to udp/xx.yy.zz.66:4829 tport_vsend returned 604 nta: resent BYE (10324256) to udp/xx.yy.zz.66:4829 tport_pend(0x7028b0): pending 0x7fb1440d6100 for udp/xx.yy.zz.1:5060 (already 0) nta_outgoing_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta: timer set next to 2000 ms nta: timer E fired, retransmit BYE (10324256) tport_release(0x7028b0): 0x7fb1440d6100 by 0x7fb144068530 with (nil) tport_tsend(0x7028b0) tpn = udp/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name udp/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 604 bytes of 604 to udp/xx.yy.zz.66:4829 tport_vsend returned 604 nta: resent BYE (10324256) to udp/xx.yy.zz.66:4829 tport_pend(0x7028b0): pending 0x7fb1440d6100 for udp/xx.yy.zz.1:5060 (already 0) nta_outgoing_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta: timer set next to 522 ms nta: timer I fired, terminate 200 response incoming_reclaim_all((nil), (nil), 0x4123cea0) nta_incoming_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/18 free nta: timer set next to 2738 ms nta: timer J fired, terminate 401 response incoming_reclaim_all((nil), (nil), 0x4123cea0) nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/17 free nta: timer set next to 730 ms nta: timer E fired, retransmit BYE (10324256) tport_release(0x7028b0): 0x7fb1440d6100 by 0x7fb144068530 with (nil) tport_tsend(0x7028b0) tpn = udp/xx.yy.zz.66:4829 tport_resolve addrinfo = xx.yy.zz.66:4829 tport_by_addrinfo(0x7028b0): not found by name udp/xx.yy.zz.66:4829 tport_vsend(0x7028b0): 604 bytes of 604 to udp/xx.yy.zz.66:4829 tport_vsend returned 604 nta: resent BYE (10324256) to udp/xx.yy.zz.66:4829 tport_pend(0x7028b0): pending 0x7fb1440d6100 for udp/xx.yy.zz.1:5060 (already 0) nta_outgoing_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta: timer set next to 4000 ms tport_wakeup_pri(0x7028b0): events IN tport_recv_event(0x7028b0) tport_recv_iovec(0x7028b0) msg 0x117e8c0 from (udp/xx.yy.zz.1:5060) has 283 bytes, veclen = 1 tport_deliver(0x7028b0): msg 0x117e8c0 (283 bytes) from udp/xx.yy.zz.66:5060/sip next=(nil) nta: received 200 OK for BYE (10324256) nta: 200 OK is going to a transaction nta_outgoing: RTT is 8366.26 ms tport_release(0x7028b0): 0x7fb1440d6100 by 0x7fb144068530 with 0x117e8c0 nua(0x11170f0): event r_bye 200 OK nua(0x11170f0): call state changed: terminating -> terminated nua(0x11170f0): event i_state 200 to BYE nua(0x11170f0): event i_terminated 200 to BYE nua(0x11170f0): removing session usage soa_destroy(static::0x1148020) called nta_leg_destroy(0x110a160) nua: terminated session 0x11170f0 nua: nua_application_event: entering nua: nua_handle_magic: entering nua: nua_application_event: entering nua: nua_handle_magic: entering nua: nua_handle_bind: entering nua: nua_application_event: entering nua: nua_handle_magic: entering nua: nua_handle_destroy: entering nua(0x11170f0): recv signal r_destroy nta_leg_destroy((nil)) nua(0x11170f0): sent signal r_destroy nta: timer set next to 1856 ms nta: timer K fired, terminate BYE (10324256) outgoing_reclaim_all((nil), (nil), 0x4123ce90) nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free nta: timer set next to 8799 ms

2 1

Link to skypopen
by Samuel 28 Mar '11

28 Mar '11

Hello, Could someone please give me the link to the static build of the stable Skype client (2.0.72) as specified in the wiki <http://wiki.freeswitch.org/wiki/Skypiax#SHORT_BLUEPRINT:_STEPS_NEEDED_TO_US…> Thanks Samuel

3 2

gsmopen and skypopen
by Giovanni Maruzzelli 28 Mar '11

28 Mar '11

Dear FreeSWITCHers, in the last weeks I've been too much busy, and I was not present in the community as I would have liked to be. I'll be much more present starting next week. I'm planning new features and more easy of installation for mod_skypopen. In the last month I saw some interest for gsmopen, that I was thinking to discontinue. This obviously is gratifying, and is pushing me to continue with gsmopen too, and make it more useful. Stay tuned starting next week ;). ciao, -giovanni -- Sincerely, Giovanni Maruzzelli Cell : +39-347-2665618

2 1