[Freeswitch-users] Issues with stripping Nortel extra SIP data
DJB International
djbinter at gmail.com
Fri Feb 28 22:47:07 MSK 2014
Try
<action application="set" data="sip_copy_multipart=false"/>
On Fri, Feb 28, 2014 at 6:13 AM, Joel White <joelewhite at gmail.com> wrote:
> Here is the Siptrace From the Asterisk (Stripping the extra characters
> before the @ ) to the FS
>
>
> freeswitch at internal> sofia global siptrace on
> +OK Global siptrace on
> recv 834 bytes from udp/[10.20.30.140]:5060 at 13:51:07.042727:
> ------------------------------------------------------------------------
> INVITE sip:57331 at 10.20.30.123:5080 SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK71ed3030
> Max-Forwards: 70
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>
> Contact: <sip:52321 at 10.20.30.140:5060>
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 102 INVITE
> User-Agent: Asterisk PBX 1.8.13.1~dfsg1-3+deb7u3
> Date: Fri, 28 Feb 2014 13:51:10 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
> INFO, PUBLISH
> Supported: replaces, timer
> Content-Type: application/sdp
> Content-Length: 250
>
> v=0
> o=root 262113027 262113027 IN IP4 10.20.30.140
> s=Asterisk PBX 1.8.13.1~dfsg1-3+deb7u3
> c=IN IP4 10.20.30.140
> t=0 0
> m=audio 11924 RTP/AVP 0 101
>
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=sendrecv
> ------------------------------------------------------------------------
> send 349 bytes to udp/[10.20.30.140]:5060 at 13:51:07.043438:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK71ed3030
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 102 INVITE
>
> User-Agent:
> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 985 bytes to udp/[10.20.30.140]:5060 at 13:51:07.050345:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK71ed3030
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>;tag=4eBX30941mX7Q
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 102 INVITE
> Contact: <sip:57331 at 10.20.30.123:5080;transport=udp>
>
> User-Agent:
> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY
> Supported: timer, path, replaces
> Allow-Events: talk, hold, conference, refer
> Content-Type: application/sdp
> Content-Disposition: session
> Content-Length: 222
> Remote-Party-ID: "57331" <sip:57331 at 10.20.30.123
> >;party=calling;privacy=off;screen=no
>
> v=0
> o=FreeSWITCH 1393576015 1393576016 IN IP4 10.20.30.123
>
> s=FreeSWITCH
> c=IN IP4 10.20.30.123
> t=0 0
> m=audio 19452 RTP/AVP 0 101
>
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> ------------------------------------------------------------------------
> recv 429 bytes from udp/[10.20.30.140]:5060 at 13:51:07.051392:
> ------------------------------------------------------------------------
> ACK sip:57331 at 10.20.30.123:5080;transport=udp SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK5cc9b7f1
> Max-Forwards: 70
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>;tag=4eBX30941mX7Q
> Contact: <sip:52321 at 10.20.30.140:5060>
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 102 ACK
> User-Agent: Asterisk PBX 1.8.13.1~dfsg1-3+deb7u3
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 1123 bytes to udp/[10.20.30.151]:5060 at 13:51:10.622223:
>
> ------------------------------------------------------------------------
> INVITE sip:57331 at 10.20.30.151 SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> Max-Forwards: 68
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: <sip:57331 at 10.20.30.151>
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
> CSeq: 56461671 INVITE
>
> Contact: <sip:mod_sofia at 10.20.30.123:5060>
> User-Agent:
> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, path, replaces
> Allow-Events: talk, hold, conference, presence, dialog, line-seize,
> call-info, sla, include-session-description, presence.winfo,
> message-summary, refer
> Content-Type: application/sdp
> Content-Disposition: session
> Content-Length: 203
> X-FS-Support: update_display,send_info
> Remote-Party-ID: "52321" <sip:52321 at 10.20.30.123
> >;party=calling;screen=yes;privacy=off
>
> v=0
> o=FreeSWITCH 1393572016 1393572017 IN IP4 10.20.30.123
>
> s=FreeSWITCH
> c=IN IP4 10.20.30.123
> t=0 0
> m=audio 23454 RTP/AVP 0 101 13
>
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> ------------------------------------------------------------------------
> recv 417 bytes from udp/[10.20.30.151]:5060 at 13:51:10.631809:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=DBC84228-8FD7AFC7
> CSeq: 56461671 INVITE
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
>
> Contact: <sip:57331 at 10.20.30.151>
> User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.6.0314
> Accept-Language: en
> Content-Length: 0
>
> ------------------------------------------------------------------------
> recv 454 bytes from udp/[10.20.30.151]:5060 at 13:51:10.703141:
> ------------------------------------------------------------------------
> SIP/2.0 180 Ringing
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=DBC84228-8FD7AFC7
> CSeq: 56461671 INVITE
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
>
> Contact: <sip:57331 at 10.20.30.151>
> User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.6.0314
> Allow-Events: talk,hold,conference
>
> Accept-Language: en
> Content-Length: 0
>
> ------------------------------------------------------------------------
> recv 462 bytes from udp/[10.20.30.140]:5060 at 13:51:17.335771:
> ------------------------------------------------------------------------
> BYE sip:57331 at 10.20.30.123:5080;transport=udp SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK5a3cf3d8
> Max-Forwards: 70
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>;tag=4eBX30941mX7Q
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 103 BYE
> User-Agent: Asterisk PBX 1.8.13.1~dfsg1-3+deb7u3
> X-Asterisk-HangupCause: Normal Clearing
> X-Asterisk-HangupCauseCode: 16
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 484 bytes to udp/[10.20.30.140]:5060 at 13:51:17.348404:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK5a3cf3d8
> From: "52321" <sip:52321 at 10.20.30.140>;tag=as78102a82
> To: <sip:57331 at 10.20.30.123:5080>;tag=4eBX30941mX7Q
> Call-ID: 601f874e379507e644893ee939a29315 at 10.20.30.140:5060
> CSeq: 103 BYE
>
> User-Agent:
> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY
> Supported: timer, path, replaces
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 428 bytes to udp/[10.20.30.151]:5060 at 13:51:17.353751:
> ------------------------------------------------------------------------
> CANCEL sip:57331 at 10.20.30.151 SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> Max-Forwards: 68
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: <sip:57331 at 10.20.30.151>
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
> CSeq: 56461671 CANCEL
> Reason: SIP;cause=487;text="ORIGINATOR_CANCEL"
> Content-Length: 0
> X-Asterisk-HangupCause: Normal Clearing
> X-Asterisk-HangupCauseCode: 16
>
> ------------------------------------------------------------------------
> recv 391 bytes from udp/[10.20.30.151]:5060 at 13:51:17.359753:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
>
> To: "Joel White" <sip:57331 at 10.20.30.151>
> CSeq: 56461671 CANCEL
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
>
> Contact: <sip:57331 at 10.20.30.151>
> User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.6.0314
> Accept-Language: en
> Content-Length: 0
>
> ------------------------------------------------------------------------
> recv 428 bytes from udp/[10.20.30.151]:5060 at 13:51:17.362819:
> ------------------------------------------------------------------------
> SIP/2.0 487 Request Cancelled
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=DBC84228-8FD7AFC7
> CSeq: 56461671 INVITE
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
>
> Contact: <sip:57331 at 10.20.30.151>
> User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.6.0314
> Accept-Language: en
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 336 bytes to udp/[10.20.30.151]:5060 at 13:51:17.363074:
>
> ------------------------------------------------------------------------
> ACK sip:57331 at 10.20.30.151 SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKvmFyHKHH6FD7p
> Max-Forwards: 68
> From: "52321" <sip:52321 at 10.20.30.123>;tag=X2SKc1QUtmHNm
> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=DBC84228-8FD7AFC7
> Call-ID: 38be43c7-1b22-1232-d8b6-d243871458ea
> CSeq: 56461671 ACK
> Content-Length: 0
>
> ------------------------------------------------------------------------
> recv 540 bytes from udp/[10.20.30.140]:5060 at 13:51:29.477899:
> ------------------------------------------------------------------------
> OPTIONS sip:10.20.30.123 SIP/2.0
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK3a2e0e2e
> Max-Forwards: 70
> From: "asterisk" <sip:asterisk at 10.20.30.140>;tag=as6211ed46
> To: <sip:10.20.30.123>
> Contact: <sip:asterisk at 10.20.30.140:5060>
> Call-ID: 120e2bb047c767435da235fe4869e8d8 at 10.20.30.140:5060
> CSeq: 102 OPTIONS
> User-Agent: Asterisk PBX 1.8.13.1~dfsg1-3+deb7u3
> Date: Fri, 28 Feb 2014 13:51:32 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
> INFO, PUBLISH
> Supported: replaces, timer
> Content-Length: 0
>
> ------------------------------------------------------------------------
> send 588 bytes to udp/[10.20.30.140]:5060 at 13:51:29.478511:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 10.20.30.140:5060;branch=z9hG4bK3a2e0e2e
> From: "asterisk" <sip:asterisk at 10.20.30.140>;tag=as6211ed46
> To: <sip:10.20.30.123>;tag=5Q4N5Ut8yXKtK
> Call-ID: 120e2bb047c767435da235fe4869e8d8 at 10.20.30.140:5060
> CSeq: 102 OPTIONS
> Contact: <sip:10.20.30.123:5080>
>
> User-Agent:
> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
> REGISTER, REFER, NOTIFY
> Supported: timer, path, replaces
> Allow-Events: talk, hold, conference, refer
> Content-Length: 0
>
> ------------------------------------------------------------------------
>
>
>
> On Fri, Feb 28, 2014 at 9:11 AM, Joel White <joelewhite at gmail.com> wrote:
>
>> Here is the Siptrace coming from the Nortel to FS
>>
>> +OK log level console [0]
>> freeswitch at internal> sofia global siptrace on
>> +OK Global siptrace on
>> recv 2230 bytes from udp/[10.20.30.121]:5060 at 13:40:16.646438:
>>
>> ------------------------------------------------------------------------
>> INVITE sip:57331;phone-context=location.systemname at sip.nortel.net:5080;maddr=10.20.30.123;transport=udp;user=phone;x-nt-redirect=redirect-server
>> SIP/2.0
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 1 INVITE
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1c7-6e065518
>> Max-Forwards: 70
>> Supported: 100rel,x-nortel-sipvc,replaces
>> User-Agent: Nortel CS1000 SIP GW release_7.0 version_ssLinux-7.00.20
>> P-Asserted-Identity: <sip:52321;phone-context=
>> location.systemname at sip.nortel.net;user=phone>
>> Privacy: none
>> History-Info: <sip:57331;phone-context=
>> location.systemname at sip.nortel.net;user=phone>;index=1
>> x-nt-corr-id: 0001e65a082a171c02 at 00c08b0bbfdc-e4e16711
>> Contact:
>> <sip:52321;phone-context=location.systemname at sip.nortel.net:5060
>> ;maddr=10.20.30.121;transport=udp;user=phone>
>> Allow:
>> INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
>> Content-Type: multipart/mixed;boundary=unique-boundary-1
>> Content-Length: 1008
>>
>> --unique-boundary-1
>> Content-Type: application/sdp
>>
>> v=0
>> o=- 270184 1 IN IP4 10.20.30.121
>> s=-
>> c=IN IP4 10.20.30.122
>> t=0 0
>> m=audio 5252 RTP/AVP 0 8 18 101 111
>> c=IN IP4 10.20.30.122
>>
>> a=fmtp:18 annexb=no
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-15
>> a=rtpmap:111 X-nt-inforeq/8000
>> a=ptime:20
>> a=sendrecv
>>
>> --unique-boundary-1
>> Content-Type:
>> application/x-nt-mcdn-frag-hex;version=ssLinux-7.00.20;base=x2611
>> Content-Disposition: signal;handling=optional
>>
>> 05000002
>> 0107130081900000a200
>> 09090f00e9a0830001008000
>> 1315070011fa0f00a10d02010102020100cc040000754a00
>> 1e0403008183
>> 460e01000a0001000100010000000000
>> 4a1c01001800010000000000000023617137990004000000000025230100
>> --unique-boundary-1
>> Content-Type: application/x-nt-esn5-frag-hex
>> Content-Disposition: signal;handling=optional
>>
>> 103
>> --unique-boundary-1
>> Content-Type:
>> application/x-nt-epid-frag-hex;version=ssLinux-7.00.20;base=x2611
>> Content-Disposition: signal;handling=optional
>>
>> 011201
>> 80:17:7d:4e:b2:38
>> --unique-boundary-1--
>>
>> ------------------------------------------------------------------------
>> send 490 bytes to udp/[10.20.30.121]:5060 at 13:40:16.647161:
>>
>> ------------------------------------------------------------------------
>> SIP/2.0 100 Trying
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1c7-6e065518
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 1 INVITE
>> User-Agent:
>> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>> send 1207 bytes to udp/[10.20.30.121]:5060 at 13:40:16.654280:
>>
>> ------------------------------------------------------------------------
>> SIP/2.0 200 OK
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1c7-6e065518
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 1 INVITE
>> Contact: <sip:57331;phone-context=location.systemname at 10.20.30.123:5080
>> ;transport=udp>
>> User-Agent:
>> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
>> Accept: application/sdp
>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>> REGISTER, REFER, NOTIFY
>> Supported: timer, path, replaces
>> Allow-Events: talk, hold, conference, refer
>> Content-Type: application/sdp
>> Content-Disposition: session
>> Content-Length: 222
>> P-Asserted-Identity: "57331;phone-context=location.systemname"
>> <sip:57331;phone-context=location.systemname at sip.nortel.net>
>>
>> v=0
>> o=FreeSWITCH 1393568474 1393568475 IN IP4 10.20.30.123
>>
>> s=FreeSWITCH
>> c=IN IP4 10.20.30.123
>> t=0 0
>> m=audio 26342 RTP/AVP 0 101
>>
>> a=rtpmap:0 PCMU/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=ptime:20
>>
>> ------------------------------------------------------------------------
>> recv 855 bytes from udp/[10.20.30.121]:5060 at 13:40:16.657553:
>>
>> ------------------------------------------------------------------------
>> ACK sip:57331;phone-context=location.systemname at 10.20.30.123:5080;transport=udp
>> SIP/2.0
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 1 ACK
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1d3-5012ca8a
>> Max-Forwards: 70
>> User-Agent: Nortel CS1000 SIP GW release_7.0 version_ssLinux-7.00.20
>> x-nt-corr-id: 0001e65a082a171c02 at 00c08b0bbfdc-e4e16711
>> Contact:
>> <sip:52321;phone-context=location.systemname at sip.nortel.net:5060
>> ;maddr=10.20.30.121;transport=udp;user=phone>
>> Allow:
>> INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>> recv 905 bytes from udp/[10.20.30.121]:5060 at 13:40:16.658829:
>>
>> ------------------------------------------------------------------------
>> OPTIONS sip:57331;phone-context=location.systemname at 10.20.30.123:5080;transport=udp
>> SIP/2.0
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 2 OPTIONS
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1d5-82ef650
>> Max-Forwards: 70
>> Supported: 100rel,x-nortel-sipvc,replaces
>> User-Agent: Nortel CS1000 SIP GW release_7.0 version_ssLinux-7.00.20
>> x-nt-corr-id: 0001e65a082a171c02 at 00c08b0bbfdc-e4e16711
>> Contact:
>> <sip:52321;phone-context=location.systemname at sip.nortel.net:5060
>> ;maddr=10.20.30.121;transport=udp;user=phone>
>> Allow:
>> INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>> send 1041 bytes to udp/[10.20.30.121]:5060 at 13:40:16.674438:
>>
>> ------------------------------------------------------------------------
>> SIP/2.0 200 OK
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5f0-aaf3b1d5-82ef650
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 2 OPTIONS
>> Contact: <sip:57331;phone-context=location.systemname at 10.20.30.123:5080
>> ;transport=udp>
>> User-Agent:
>> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
>> Accept: application/sdp
>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>> REGISTER, REFER, NOTIFY
>> Supported: timer, path, replaces
>> Allow-Events: talk, hold, conference, refer
>> Content-Type: application/sdp
>> Content-Length: 218
>>
>> v=0
>> o=FreeSWITCH 1393568474 1393568475 IN IP4 10.20.30.123
>>
>> s=FreeSWITCH
>> c=IN IP4 10.20.30.123
>> t=0 0
>> m=audio 0 RTP/AVP 0 101
>>
>> a=rtpmap:0 PCMU/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=ptime:20
>>
>> ------------------------------------------------------------------------
>> send 2373 bytes to udp/[10.20.30.151]:5060 at 13:40:20.244041:
>>
>> ------------------------------------------------------------------------
>> INVITE sip:57331 at 10.20.30.151 SIP/2.0
>> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKSS3Kc2y6eNaFm
>> Max-Forwards: 68
>> From: "52321;phone-context=location.systemname"
>> <sip:52321;phone-context=location.systemname at 10.20.30.123
>> >;tag=K8vUtjFrQUjtg
>> To: <sip:57331 at 10.20.30.151>
>> Call-ID: b5166f21-1b20-1232-d8b6-d243871458ea
>> CSeq: 56461346 INVITE
>> Contact: <sip:mod_sofia at 10.20.30.123:5060>
>> User-Agent:
>> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
>> Supported: timer, path, replaces
>> Allow-Events: talk, hold, conference, presence, dialog, line-seize,
>> call-info, sla, include-session-description, presence.winfo,
>> message-summary, refer
>> Privacy: none
>> Content-Type:
>> multipart/mixed;boundary=ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Length: 1250
>> x-nt-corr-id: 0001e65a082a171c02 at 00c08b0bbfdc-e4e16711
>> X-FS-Support: update_display,send_info
>> P-Asserted-Identity: "52321;phone-context=location.systemname"
>> <sip:52321;phone-context=location.systemname at 10.20.30.123>
>>
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Type: application/sdp
>> Content-Length: 262
>>
>> v=0
>> o=- 270184 1 IN IP4 10.20.30.121
>> s=-
>> c=IN IP4 10.20.30.122
>> t=0 0
>> m=audio 5252 RTP/AVP 0 8 18 101 111
>> c=IN IP4 10.20.30.122
>>
>> a=fmtp:18 annexb=no
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-15
>> a=rtpmap:111 X-nt-inforeq/8000
>> a=ptime:20
>> a=sendrecv
>>
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Type: application/x-nt-mcdn-frag-hex
>> Content-Length: 217
>>
>> 05000002
>> 0107130081900000a200
>> 09090f00e9a0830001008000
>> 1315070011fa0f00a10d02010102020100cc040000754a00
>> 1e0403008183
>> 460e01000a0001000100010000000000
>> 4a1c01001800010000000000000023617137990004000000000025230100
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Type: application/x-nt-esn5-frag-hex
>> Content-Length: 4
>>
>> 103
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Type: application/x-nt-epid-frag-hex
>> Content-Length: 26
>>
>> 011201
>> 80:17:7d:4e:b2:38
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d
>> Content-Type: application/sdp
>> Content-Length: 208
>>
>> v=0
>> o=FreeSWITCH 1393575650 1393575651 IN IP4 10.20.30.123
>>
>> s=FreeSWITCH
>> c=IN IP4 10.20.30.123
>> t=0 0
>> m=audio 19170 RTP/AVP 0 8 101 13
>>
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=ptime:20
>> a=sendrecv
>>
>> --ddb7d988-a07d-11e3-9b14-09241ec9370d--
>>
>> ------------------------------------------------------------------------
>> recv 506 bytes from udp/[10.20.30.151]:5060 at 13:40:20.257663:
>>
>> ------------------------------------------------------------------------
>> SIP/2.0 415 Unsupported Media Type
>> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKSS3Kc2y6eNaFm
>> From: "52321;phone-context=location.systemname"
>> <sip:52321;phone-context=location.systemname at 10.20.30.123
>> >;tag=K8vUtjFrQUjtg
>> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=AC57CD1-9FDEC368
>> CSeq: 56461346 INVITE
>> Call-ID: b5166f21-1b20-1232-d8b6-d243871458ea
>> Contact: <sip:57331 at 10.20.30.151>
>> User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.6.0314
>> Accept-Language: en
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>> send 409 bytes to udp/[10.20.30.151]:5060 at 13:40:20.257909:
>>
>> ------------------------------------------------------------------------
>> ACK sip:57331 at 10.20.30.151 SIP/2.0
>> Via: SIP/2.0/UDP 10.20.30.123;rport;branch=z9hG4bKSS3Kc2y6eNaFm
>> Max-Forwards: 68
>> From: "52321;phone-context=location.systemname"
>> <sip:52321;phone-context=location.systemname at 10.20.30.123
>> >;tag=K8vUtjFrQUjtg
>> To: "Joel White" <sip:57331 at 10.20.30.151>;tag=AC57CD1-9FDEC368
>> Call-ID: b5166f21-1b20-1232-d8b6-d243871458ea
>> CSeq: 56461346 ACK
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>> recv 1068 bytes from udp/[10.20.30.121]:5060 at 13:40:28.637828:
>>
>> ------------------------------------------------------------------------
>> BYE sip:57331;phone-context=location.systemname at 10.20.30.123:5080;transport=udp
>> SIP/2.0
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 3 BYE
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5fc-aaf3e09e-75565f26
>> Max-Forwards: 70
>> Supported: 100rel,x-nortel-sipvc,replaces
>> User-Agent: Nortel CS1000 SIP GW release_7.0 version_ssLinux-7.00.20
>> x-nt-corr-id: 0001e65a082a171c02 at 00c08b0bbfdc-e4e16711
>> Allow:
>> INVITE,ACK,BYE,REGISTER,REFER,NOTIFY,CANCEL,PRACK,OPTIONS,INFO,SUBSCRIBE,UPDATE
>> Content-Type: application/sdp
>> Content-Length: 261
>>
>> v=0
>> o=- 270184 1 IN IP4 10.20.30.121
>> s=-
>> c=IN IP4 10.20.30.122
>> t=0 0
>> m=audio 5252 RTP/AVP 0 8 18 101 111
>> c=IN IP4 10.20.30.122
>>
>> a=fmtp:18 annexb=no
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-15
>> a=rtpmap:111 X-nt-inforeq/8000
>> a=ptime:20
>> a=sendrecv
>>
>> ------------------------------------------------------------------------
>> send 625 bytes to udp/[10.20.30.121]:5060 at 13:40:28.648789:
>>
>> ------------------------------------------------------------------------
>> SIP/2.0 200 OK
>> Via: SIP/2.0/UDP 10.20.30.121:5060
>> ;branch=z9hG4bK-aed5fc-aaf3e09e-75565f26
>> From: <sip:52321;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=2ffc578-a0b6f0a-13c4-55013-aed5f0-7c8d636b-aed5f0
>> To: <sip:57331;phone-context=location.systemname at sip.nortel.net
>> ;user=phone>;tag=tme5Hj11yUycm
>> Call-ID: 4c26298-a0b6f0a-13c4-55013-aed5f0-13370bf5-aed5f0
>> CSeq: 3 BYE
>> User-Agent:
>> FreeSWITCH-mod_sofia/1.2.22+git~20140224T012236Z~aabf813ae1~64bit
>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>> REGISTER, REFER, NOTIFY
>> Supported: timer, path, replaces
>> Content-Length: 0
>>
>>
>> ------------------------------------------------------------------------
>>
>>
>>
>> On Thu, Feb 27, 2014 at 3:42 PM, Brian West <brian at freeswitch.org> wrote:
>>
>>> sofia global siptrace on
>>>
>>> That will help me a little more.
>>>
>>> --
>>> Brian West
>>> brian at freeswitch.org
>>> FreeSWITCH Solutions, LLC
>>> PO BOX 2531
>>> Brookfield, WI 53008-2531
>>> Twitter: @FreeSWITCH , @briankwest
>>> http://www.freeswitchbook.com
>>> http://www.freeswitchcookbook.com
>>>
>>> T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST
>>> iNUM: +883 5100 1420 9001
>>> ISN: 410*543
>>> Skype:briankwest
>>> PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> On Feb 27, 2014, at 2:23 PM, Joel White <joelewhite at gmail.com> wrote:
>>>
>>> > I did add a line to the public incoming xml that uses the Say command
>>> to repeat back what $1 variable is set to. I figured it might help me in
>>> debugging
>>> >
>>> >
>>> >
>>> > +OK log level debug [7]
>>> > 2014-02-27 15:13:05.086534 [NOTICE] switch_channel.c:1050 New Channel
>>> sofia/external/23673 [910ede7a-9feb-11e3-9a55-09241ec9370d]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_NEW
>>> > 2014-02-27 15:13:05.086534 [DEBUG] sofia.c:7868 sofia/external/23673
>>> receiving invite from 10.111.11.10:5060 version: 1.2.22 git aabf813
>>> 2014-02-24 01:22:36Z 64bit
>>> > 2014-02-27 15:13:05.086534 [DEBUG] sofia.c:5811 Channel
>>> sofia/external/23673 entering state [received][100]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] sofia.c:5824 Remote SDP:
>>> > v=0
>>> > o=- 269323 1 IN IP4 10.111.11.10
>>> > s=-
>>> > c=IN IP4 10.111.11.17
>>> > t=0 0
>>> > m=audio 5218 RTP/AVP 0 8 18 101 111
>>> > c=IN IP4 10.111.11.17
>>> > a=fmtp:18 annexb=no
>>> > a=rtpmap:101 telephone-event/8000
>>> > a=fmtp:101 0-15
>>> > a=rtpmap:111 X-nt-inforeq/8000
>>> > a=ptime:20
>>> >
>>> > 2014-02-27 15:13:05.086534 [DEBUG] sofia.c:6071 (sofia/external/23673)
>>> State Change CS_NEW -> CS_INIT
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:434
>>> (sofia/external/23673) State NEW
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_INIT
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:455
>>> (sofia/external/23673) State INIT
>>> > 2014-02-27 15:13:05.086534 [DEBUG] mod_sofia.c:87 sofia/external/23673
>>> SOFIA INIT
>>> > 2014-02-27 15:13:05.086534 [DEBUG] mod_sofia.c:127
>>> (sofia/external/23673) State Change CS_INIT -> CS_ROUTING
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:455
>>> (sofia/external/23673) State INIT going to sleep
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_ROUTING
>>> > 2014-02-27 15:13:05.086534 [DEBUG] switch_channel.c:2163
>>> (sofia/external/23673) Callstate Change DOWN -> RINGING
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/external/23673) State ROUTING
>>> > 2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:150
>>> sofia/external/23673 SOFIA ROUTING
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:117
>>> sofia/external/23673 Standard ROUTING
>>> > 2014-02-27 15:13:05.106494 [INFO] mod_dialplan_xml.c:558 Processing
>>> 23673;phone-context=location.systemname
>>> <23673;phone-context=location.systemname>->28365;phone-context=location.systemname
>>> in context public
>>> > Dialplan: sofia/external/23673 parsing [public->unloop] continue=false
>>> > Dialplan: sofia/external/23673 Regex (PASS) [unloop]
>>> ${unroll_loops}(true) =~ /^true$/ break=on-false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [unloop]
>>> ${sip_looped_call}() =~ /^true$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [public->outside_call]
>>> continue=true
>>> > Dialplan: sofia/external/23673 Absolute Condition [outside_call]
>>> > Dialplan: sofia/external/23673 Action set(outside_call=true)
>>> > Dialplan: sofia/external/23673 Action
>>> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
>>> > Dialplan: sofia/external/23673 parsing [public->call_debug]
>>> continue=true
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [call_debug]
>>> ${call_debug}(false) =~ /^true$/ break=never
>>> > Dialplan: sofia/external/23673 parsing [public->public_extensions]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [public_extensions]
>>> destination_number(28365;phone-context=location.systemname) =~
>>> /^([456][0-9][0-9][0-9]/d?)$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing
>>> [public->public_did_mgw00_inbound] continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [public_did_mgw00_inbound]
>>> destination_number(28365;phone-context=location.systemname) =~ /^(\d{5})$/
>>> break=on-false
>>> > Dialplan: sofia/external/23673 parsing
>>> [public->public_did_nortel_inbound] continue=false
>>> > Dialplan: sofia/external/23673 Regex (PASS)
>>> [public_did_nortel_inbound]
>>> destination_number(28365;phone-context=location.systemname) =~
>>> /^(\d{5});(.*)$/ break=on-false
>>> > Dialplan: sofia/external/23673 Action answer()
>>> > Dialplan: sofia/external/23673 Action say(en number iterated 28365)
>>> > Dialplan: sofia/external/23673 Action sleep(1000)
>>> > Dialplan: sofia/external/23673 Action set(domain_name=10.20.30.123)
>>> > Dialplan: sofia/external/23673 Action transfer(28365 XML default)
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:167
>>> (sofia/external/23673) State Change CS_ROUTING -> CS_EXECUTE
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/external/23673) State ROUTING going to sleep
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_EXECUTE
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:478
>>> (sofia/external/23673) State EXECUTE
>>> > 2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:243
>>> sofia/external/23673 SOFIA EXECUTE
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:209
>>> sofia/external/23673 Standard EXECUTE
>>> > EXECUTE sofia/external/23673 set(outside_call=true)
>>> > 2014-02-27 15:13:05.106494 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [outside_call]=[true]
>>> > EXECUTE sofia/external/23673 export(RFC2822_DATE=Thu, 27 Feb 2014
>>> 15:13:05 -0500)
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:1242 EXPORT
>>> (export_vars) [RFC2822_DATE]=[Thu, 27 Feb 2014 15:13:05 -0500]
>>> > EXECUTE sofia/external/23673 answer()
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5282 Audio Codec
>>> Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5282 Audio Codec
>>> Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3190 Set Codec
>>> sofia/external/23673 PCMU/8000 20 ms 160 samples 64000 bits
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_codec.c:111
>>> sofia/external/23673 Original read codec set to PCMU:0
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf
>>> send/recv payload to 101
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3449 AUDIO RTP
>>> [sofia/external/23673] 10.20.30.123 port 20854 -> 10.111.11.17 port 5218
>>> codec: 0 ms: 20
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_rtp.c:2033 Starting timer
>>> [soft] 160 bytes per 20ms
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf
>>> send payload to 101
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf
>>> receive payload to 101
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3749
>>> sofia/external/23673 Set rtp dtmf delay to 40
>>> > 2014-02-27 15:13:05.106494 [NOTICE] sofia_glue.c:4360 Pre-Answer
>>> sofia/external/23673!
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:3367
>>> (sofia/external/23673) Callstate Change RINGING -> EARLY
>>> > 2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:866 Local SDP
>>> sofia/external/23673:
>>> > v=0
>>> > o=FreeSWITCH 1393511131 1393511132 IN IP4 10.20.30.123
>>> > s=FreeSWITCH
>>> > c=IN IP4 10.20.30.123
>>> > t=0 0
>>> > m=audio 20854 RTP/AVP 0 101
>>> > a=rtpmap:0 PCMU/8000
>>> > a=rtpmap:101 telephone-event/8000
>>> > a=fmtp:101 0-16
>>> > a=ptime:20
>>> > a=sendrecv
>>> >
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] sofia.c:5811 Channel
>>> sofia/external/23673 entering state [completed][200]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:871 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [NOTICE] mod_dptools.c:1225 Channel
>>> [sofia/external/23673] has been answered
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:3646
>>> (sofia/external/23673) Callstate Change EARLY -> ACTIVE
>>> > EXECUTE sofia/external/23673 say(en number iterated 28365)
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:05.126485 [DEBUG] sofia.c:5811 Channel
>>> sofia/external/23673 entering state [ready][200]
>>> > 2014-02-27 15:13:05.126485 [DEBUG] switch_ivr_play_say.c:1314 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>> > 2014-02-27 15:13:05.226537 [DEBUG] switch_rtp.c:3749 Correct ip/port
>>> confirmed.
>>> > 2014-02-27 15:13:07.666516 [DEBUG] switch_ivr_play_say.c:1717 done
>>> playing file
>>> file_string://digits/2.wav!digits/8.wav!digits/3.wav!digits/6.wav!digits/5.wav
>>> > EXECUTE sofia/external/23673 sleep(1000)
>>> > EXECUTE sofia/external/23673 set(domain_name=10.20.30.123)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [domain_name]=[10.20.30.123]
>>> > EXECUTE sofia/external/23673 transfer(28365 XML default)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_ivr.c:1832
>>> (sofia/external/23673) State Change CS_EXECUTE -> CS_ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:871 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [NOTICE] switch_ivr.c:1839 Transfer
>>> sofia/external/23673 to XML[28365 at default]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:478
>>> (sofia/external/23673) State EXECUTE going to sleep
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:2163
>>> (sofia/external/23673) Callstate Change ACTIVE -> RINGING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/external/23673) State ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:150
>>> sofia/external/23673 SOFIA ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:117
>>> sofia/external/23673 Standard ROUTING
>>> > 2014-02-27 15:13:08.666549 [INFO] mod_dialplan_xml.c:558 Processing
>>> 23673;phone-context=location.systemname
>>> <23673;phone-context=location.systemname>->28365 in context default
>>> > Dialplan: sofia/external/23673 parsing [default->unloop] continue=false
>>> > Dialplan: sofia/external/23673 Regex (PASS) [unloop]
>>> ${unroll_loops}(true) =~ /^true$/ break=on-false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [unloop]
>>> ${sip_looped_call}() =~ /^true$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->tod_example]
>>> continue=true
>>> > Dialplan: sofia/external/23673 Date/Time Match (PASS) [tod_example]
>>> break=on-false
>>> > Dialplan: sofia/external/23673 Action set(open=true)
>>> > Dialplan: sofia/external/23673 parsing [default->tod_brevard]
>>> continue=true
>>> > Dialplan: sofia/external/23673 Date/Time Match (PASS) [tod_brevard]
>>> break=on-false
>>> > Dialplan: sofia/external/23673 Action set(open=true)
>>> > Dialplan: sofia/external/23673 parsing [default->holiday_example]
>>> continue=true
>>> > Dialplan: sofia/external/23673 Date/TimeMatch (FAIL) [holiday_example]
>>> break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->global-intercept]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [global-intercept]
>>> destination_number(28365) =~ /^886$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->group-intercept]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [group-intercept]
>>> destination_number(28365) =~ /^\*8$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->intercept-ext]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [intercept-ext]
>>> destination_number(28365) =~ /^\*\*(\d+)$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->redial] continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [redial]
>>> destination_number(28365) =~ /^(redial|870)$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->global] continue=true
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [global]
>>> ${call_debug}(false) =~ /^true$/ break=never
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [global]
>>> ${sip_has_crypto}() =~
>>> /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [global]
>>> ${endpoint_disposition}(ANSWER) =~ /^(DELAYED NEGOTIATION)/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->eavesdrop]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [eavesdrop]
>>> destination_number(28365) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->eavesdrop]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [eavesdrop]
>>> destination_number(28365) =~ /^779$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->call_return]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [call_return]
>>> destination_number(28365) =~ /^\*69$|^869$|^lcr$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->del-group]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [del-group]
>>> destination_number(28365) =~ /^80(\d{2})$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->add-group]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [add-group]
>>> destination_number(28365) =~ /^81(\d{2})$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->call-group-simo]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [call-group-simo]
>>> destination_number(28365) =~ /^82(\d{2})$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->call-group-order]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [call-group-order]
>>> destination_number(28365) =~ /^83(\d{2})$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing [default->extension-intercom]
>>> continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [extension-intercom]
>>> destination_number(28365) =~ /^8([456][0-9][0-9][0-9][0-9])$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing
>>> [default->Local_Extension_4_digit] continue=false
>>> > Dialplan: sofia/external/23673 Regex (FAIL) [Local_Extension_4_digit]
>>> destination_number(28365) =~ /^(10[01][0-9])$/ break=on-false
>>> > Dialplan: sofia/external/23673 parsing
>>> [default->Local_Extension_5_digit] continue=false
>>> > Dialplan: sofia/external/23673 Regex (PASS) [Local_Extension_5_digit]
>>> destination_number(28365) =~ /^(5[0-9][0-9][0-9][0-9])$/ break=on-false
>>> > Dialplan: sofia/external/23673 Action export(dialed_extension=28365)
>>> > Dialplan: sofia/external/23673 Action bind_meta_app(1 b s
>>> execute_extension::dx XML features)
>>> > Dialplan: sofia/external/23673 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/external/23673 Action bind_meta_app(3 b s
>>> execute_extension::cf XML features)
>>> > Dialplan: sofia/external/23673 Action bind_meta_app(4 b s
>>> execute_extension::att_xfer XML features)
>>> > Dialplan: sofia/external/23673 Action set(ringback=${us-ring})
>>> > Dialplan: sofia/external/23673 Action
>>> set(transfer_ringback=local_stream://moh)
>>> > Dialplan: sofia/external/23673 Action set(call_timeout=30)
>>> > Dialplan: sofia/external/23673 Action set(hangup_after_bridge=true)
>>> > Dialplan: sofia/external/23673 Action set(continue_on_fail=true)
>>> > Dialplan: sofia/external/23673 Action
>>> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
>>> > Dialplan: sofia/external/23673 Action
>>> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
>>> > Dialplan: sofia/external/23673 Action
>>> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
>>> var callgroup)})
>>> > Dialplan: sofia/external/23673 Action
>>> hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
>>> > Dialplan: sofia/external/23673 Action
>>> hash(insert/${domain_name}-last_dial_ext/global/${uuid})
>>> > Dialplan: sofia/external/23673 Action
>>> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
>>> > Dialplan: sofia/external/23673 Action bridge(user/${dialed_extension}@
>>> ${domain_name})
>>> > Dialplan: sofia/external/23673 Action answer()
>>> > Dialplan: sofia/external/23673 Action sleep(1000)
>>> > Dialplan: sofia/external/23673 Action
>>> bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:167
>>> (sofia/external/23673) State Change CS_ROUTING -> CS_EXECUTE
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/external/23673) State ROUTING going to sleep
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_EXECUTE
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:2165
>>> (sofia/external/23673) Callstate Change RINGING -> ACTIVE
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:478
>>> (sofia/external/23673) State EXECUTE
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:243
>>> sofia/external/23673 SOFIA EXECUTE
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:209
>>> sofia/external/23673 Standard EXECUTE
>>> > EXECUTE sofia/external/23673 set(open=true)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [open]=[true]
>>> > EXECUTE sofia/external/23673 set(open=true)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [open]=[true]
>>> > EXECUTE sofia/external/23673 export(dialed_extension=28365)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1242 EXPORT
>>> (export_vars) [dialed_extension]=[28365]
>>> > EXECUTE sofia/external/23673 bind_meta_app(1 b s execute_extension::dx
>>> XML features)
>>> > 2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
>>> *1 execute_extension::dx XML features
>>> > EXECUTE sofia/external/23673 bind_meta_app(2 b s
>>> record_session::/usr/local/freeswitch/recordings/23673;phone-context=location.systemname.2014-02-27-15-13-08.wav)
>>> > 2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
>>> *2
>>> record_session::/usr/local/freeswitch/recordings/23673;phone-context=location.systemname.2014-02-27-15-13-08.wav
>>> > EXECUTE sofia/external/23673 bind_meta_app(3 b s execute_extension::cf
>>> XML features)
>>> > 2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
>>> *3 execute_extension::cf XML features
>>> > EXECUTE sofia/external/23673 bind_meta_app(4 b s
>>> execute_extension::att_xfer XML features)
>>> > 2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
>>> *4 execute_extension::att_xfer XML features
>>> > EXECUTE sofia/external/23673 set(ringback=%(2000,4000,440,480))
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [ringback]=[%(2000,4000,440,480)]
>>> > EXECUTE sofia/external/23673 set(transfer_ringback=local_stream://moh)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [transfer_ringback]=[local_stream://moh]
>>> > EXECUTE sofia/external/23673 set(call_timeout=30)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [call_timeout]=[30]
>>> > EXECUTE sofia/external/23673 set(hangup_after_bridge=true)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [hangup_after_bridge]=[true]
>>> > EXECUTE sofia/external/23673 set(continue_on_fail=true)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [continue_on_fail]=[true]
>>> > EXECUTE sofia/external/23673 hash(insert/10.20.30.123-call_return/
>>> 28365/23673;phone-context=location.systemname)
>>> > EXECUTE sofia/external/23673
>>> hash(insert/10.20.30.123-last_dial_ext/28365/910ede7a-9feb-11e3-9a55-09241ec9370d)
>>> > EXECUTE sofia/external/23673 set(called_party_callgroup=techsupport)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402
>>> sofia/external/23673 SET [called_party_callgroup]=[techsupport]
>>> > EXECUTE sofia/external/23673
>>> hash(insert/10.20.30.123-last_dial_ext/techsupport/910ede7a-9feb-11e3-9a55-09241ec9370d)
>>> > EXECUTE sofia/external/23673
>>> hash(insert/10.20.30.123-last_dial_ext/global/910ede7a-9feb-11e3-9a55-09241ec9370d)
>>> > EXECUTE sofia/external/23673
>>> hash(insert/10.20.30.123-last_dial/techsupport/910ede7a-9feb-11e3-9a55-09241ec9370d)
>>> > EXECUTE sofia/external/23673 bridge(user/28365 at 10.20.30.123)
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1763
>>> (sofia/external/23673) Callstate Change ACTIVE -> RING_WAIT
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
>>> 2014 15:13:05 -0500] to event
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
>>> event
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:2069 Parsing
>>> global variables
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
>>> 2014 15:13:05 -0500] to event
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
>>> event
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:2069 Parsing
>>> global variables
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_event.c:1661 Parsing
>>> variable [sip_invite_domain]=[10.20.30.123]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_event.c:1661 Parsing
>>> variable [presence_id]=[28365 at 10.20.30.123]
>>> > 2014-02-27 15:13:08.666549 [NOTICE] switch_channel.c:1050 New Channel
>>> sofia/internal/sip:28365 at 10.20.30.121[93309eb4-9feb-11e3-9a76-09241ec9370d]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5230 (sofia/internal/
>>> sip:28365 at 10.20.30.121) State Change CS_NEW -> CS_INIT
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5300 [zrtp_passthru]
>>> Setting a-leg inherit_codec=true
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5303 [zrtp_passthru]
>>> Setting b-leg absolute_codec_string='PCMU at 8000h@20i at 64000b,PCMA at 8000h
>>> @20i at 64000b'
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_INIT
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:455
>>> (sofia/internal/sip:28365 at 10.20.30.121) State INIT
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:87 sofia/internal/
>>> sip:28365 at 10.20.30.121 SOFIA INIT
>>> > 2014-02-27 15:13:08.666549 [DEBUG] sofia_glue.c:2744 sofia/internal/
>>> sip:28365 at 10.20.30.121 sending invite version: 1.2.22 git aabf813
>>> 2014-02-24 01:22:36Z 64bit
>>> > Local SDP:
>>> > v=0
>>> > o=FreeSWITCH 1393508912 1393508913 IN IP4 10.20.30.123
>>> > s=FreeSWITCH
>>> > c=IN IP4 10.20.30.123
>>> > t=0 0
>>> > m=audio 23076 RTP/AVP 0 8 101 13
>>> > a=rtpmap:101 telephone-event/8000
>>> > a=fmtp:101 0-16
>>> > a=ptime:20
>>> > a=sendrecv
>>> >
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:127 (sofia/internal/
>>> sip:28365 at 10.20.30.121) State Change CS_INIT -> CS_ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:455
>>> (sofia/internal/sip:28365 at 10.20.30.121) State INIT going to sleep
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] sofia.c:5811 Channel sofia/internal/
>>> sip:28365 at 10.20.30.121 entering state [calling][0]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/internal/sip:28365 at 10.20.30.121) State ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:150 sofia/internal/
>>> sip:28365 at 10.20.30.121 SOFIA ROUTING
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:67
>>> (sofia/internal/sip:28365 at 10.20.30.121) State Change CS_ROUTING ->
>>> CS_CONSUME_MEDIA
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
>>> (sofia/internal/sip:28365 at 10.20.30.121) State ROUTING going to sleep
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change
>>> CS_CONSUME_MEDIA
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:490
>>> (sofia/internal/sip:28365 at 10.20.30.121) State CONSUME_MEDIA
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:490
>>> (sofia/internal/sip:28365 at 10.20.30.121) State CONSUME_MEDIA going to
>>> sleep
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] sofia.c:5811 Channel sofia/internal/
>>> sip:28365 at 10.20.30.121 entering state [terminated][415]
>>> > 2014-02-27 15:13:08.686500 [NOTICE] sofia.c:6655 Hangup sofia/internal/
>>> sip:28365 at 10.20.30.121 [CS_CONSUME_MEDIA] [SERVICE_NOT_IMPLEMENTED]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_channel.c:3186 Send signal
>>> sofia/internal/sip:28365 at 10.20.30.121 [KILL]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_HANGUP
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:678
>>> (sofia/internal/sip:28365 at 10.20.30.121) Callstate Change DOWN -> HANGUP
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:680
>>> (sofia/internal/sip:28365 at 10.20.30.121) State HANGUP
>>> > 2014-02-27 15:13:08.686500 [DEBUG] mod_sofia.c:506 Channel
>>> sofia/internal/sip:28365 at 10.20.30.121 hanging up, cause:
>>> SERVICE_NOT_IMPLEMENTED
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:48
>>> sofia/internal/sip:28365 at 10.20.30.121 Standard HANGUP, cause:
>>> SERVICE_NOT_IMPLEMENTED
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:680
>>> (sofia/internal/sip:28365 at 10.20.30.121) State HANGUP going to sleep
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:447
>>> (sofia/internal/sip:28365 at 10.20.30.121) State Change CS_HANGUP ->
>>> CS_REPORTING
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change
>>> CS_REPORTING
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:764
>>> (sofia/internal/sip:28365 at 10.20.30.121) State REPORTING
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:92
>>> sofia/internal/sip:28365 at 10.20.30.121 Standard REPORTING, cause:
>>> SERVICE_NOT_IMPLEMENTED
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:764
>>> (sofia/internal/sip:28365 at 10.20.30.121) State REPORTING going to sleep
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:441
>>> (sofia/internal/sip:28365 at 10.20.30.121) State Change CS_REPORTING ->
>>> CS_DESTROY
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
>>> > 2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1559 Session
>>> 2 (sofia/internal/sip:28365 at 10.20.30.121) Locked, Waiting on external
>>> entities
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_ivr_originate.c:3657
>>> Originate Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_channel.c:1967
>>> (sofia/external/23673) Callstate Change RING_WAIT -> ACTIVE
>>> > 2014-02-27 15:13:08.706527 [NOTICE] switch_ivr_originate.c:2670 Cannot
>>> create outgoing channel of type [user] cause: [SERVICE_NOT_IMPLEMENTED]
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_ivr_originate.c:3657
>>> Originate Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]
>>> > 2014-02-27 15:13:08.706527 [INFO] mod_dptools.c:3201 Originate Failed.
>>> Cause: SERVICE_NOT_IMPLEMENTED
>>> > EXECUTE sofia/external/23673 answer()
>>> > EXECUTE sofia/external/23673 sleep(1000)
>>> > 2014-02-27 15:13:08.706527 [NOTICE] switch_core_session.c:1577 Session
>>> 2 (sofia/internal/sip:28365 at 10.20.30.121) Ended
>>> > 2014-02-27 15:13:08.706527 [NOTICE] switch_core_session.c:1581 Close
>>> Channel sofia/internal/sip:28365 at 10.20.30.121 [CS_DESTROY]
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:566
>>> (sofia/internal/sip:28365 at 10.20.30.121) Callstate Change HANGUP -> DOWN
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:569
>>> (sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_DESTROY
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:579
>>> (sofia/internal/sip:28365 at 10.20.30.121) State DESTROY
>>> > 2014-02-27 15:13:08.706527 [DEBUG] mod_sofia.c:399 sofia/internal/
>>> sip:28365 at 10.20.30.121 SOFIA DESTROY
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:99
>>> sofia/internal/sip:28365 at 10.20.30.121 Standard DESTROY
>>> > 2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:579
>>> (sofia/internal/sip:28365 at 10.20.30.121) State DESTROY going to sleep
>>> > EXECUTE sofia/external/23673 bridge(loopback/app=voicemail:default
>>> 10.20.30.123 28365)
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1763
>>> (sofia/external/23673) Callstate Change ACTIVE -> RING_WAIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
>>> 2014 15:13:05 -0500] to event
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1196
>>> sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
>>> event
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_ivr_originate.c:2069 Parsing
>>> global variables
>>> > 2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1050 New Channel
>>> loopback/app=voicemail:default 10.20.30.123 28365-a
>>> [93cd50f6-9feb-11e3-9a7f-09241ec9370d]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:157
>>> loopback/app=voicemail:default 10.20.30.123 28365-a setup codec PCMU/8000/20
>>> > 2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1048 Rename
>>> Channel loopback/app=voicemail:default 10.20.30.123
>>> 28365-a->loopback/voicemail-a [93cd50f6-9feb-11e3-9a7f-09241ec9370d]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:1158
>>> (loopback/voicemail-a) State Change CS_NEW -> CS_INIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_INIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
>>> (loopback/voicemail-a) State INIT
>>> > 2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1050 New Channel
>>> loopback/voicemail-b [93cd7874-9feb-11e3-9a83-09241ec9370d]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:157
>>> loopback/voicemail-b setup codec PCMU/8000/20
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:272
>>> (loopback/voicemail-b) State Change CS_NEW -> CS_INIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:357
>>> (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
>>> (loopback/voicemail-a) State INIT going to sleep
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
>>> (loopback/voicemail-a) State ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:389
>>> loopback/voicemail-a CHANNEL ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_ivr_originate.c:67
>>> (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
>>> (loopback/voicemail-a) State ROUTING going to sleep
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:490
>>> (loopback/voicemail-a) State CONSUME_MEDIA
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:648 CHANNEL
>>> CONSUME_MEDIA
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:490
>>> (loopback/voicemail-a) State CONSUME_MEDIA going to sleep
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-b) Running State Change CS_INIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
>>> (loopback/voicemail-b) State INIT
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:357
>>> (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
>>> (loopback/voicemail-b) State INIT going to sleep
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-b) Running State Change CS_ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:2163
>>> (loopback/voicemail-b) Callstate Change DOWN -> RINGING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
>>> (loopback/voicemail-b) State ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:389
>>> loopback/voicemail-b CHANNEL ROUTING
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:408
>>> (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
>>> (loopback/voicemail-b) State ROUTING going to sleep
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-b) Running State Change CS_EXECUTE
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:478
>>> (loopback/voicemail-b) State EXECUTE
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:431
>>> loopback/voicemail-b CHANNEL EXECUTE
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:209
>>> loopback/voicemail-b Standard EXECUTE
>>> > EXECUTE loopback/voicemail-b pre_answer()
>>> > 2014-02-27 15:13:09.706545 [NOTICE] mod_loopback.c:945 Pre-Answer
>>> loopback/voicemail-a!
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3363 Send signal
>>> sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3367
>>> (loopback/voicemail-a) Callstate Change DOWN -> EARLY
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:871 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:09.706545 [NOTICE] mod_dptools.c:1260 Pre-Answer
>>> loopback/voicemail-b!
>>> > 2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3367
>>> (loopback/voicemail-b) Callstate Change RINGING -> EARLY
>>> > EXECUTE loopback/voicemail-b voicemail(default 10.20.30.123 28365)
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_ivr_originate.c:3513
>>> Originate Resulted in Success: [loopback/voicemail-a]
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_channel.c:1967
>>> (sofia/external/23673) Callstate Change RING_WAIT -> ACTIVE
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:871 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:871 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_ivr_bridge.c:1429
>>> (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA
>>> > 2014-02-27 15:13:09.726502 [DEBUG] switch_core_state_machine.c:481
>>> (loopback/voicemail-a) State EXCHANGE_MEDIA
>>> > 2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:610 CHANNEL LOOPBACK
>>> > 2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:70 No
>>> language specified - Using [en]
>>> > 2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:251 Handle
>>> play-file:[voicemail/vm-person.wav] (en:en)
>>> > 2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:1314 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>> > 2014-02-27 15:13:11.206539 [DEBUG] switch_ivr_play_say.c:1717 done
>>> playing file
>>> /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
>>> > 2014-02-27 15:13:11.306570 [DEBUG] switch_ivr_play_say.c:251 Handle
>>> say:[28365] (en:en)
>>> > 2014-02-27 15:13:11.306570 [DEBUG] switch_ivr_play_say.c:1314 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>> > 2014-02-27 15:13:13.866518 [DEBUG] switch_ivr_play_say.c:1717 done
>>> playing file
>>> file_string://digits/5.wav!digits/7.wav!digits/3.wav!digits/3.wav!digits/1.wav
>>> > 2014-02-27 15:13:13.966519 [DEBUG] switch_ivr_play_say.c:251 Handle
>>> play-file:[voicemail/vm-not_available.wav] (en:en)
>>> > 2014-02-27 15:13:13.966519 [DEBUG] switch_ivr_play_say.c:1314 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>> > 2014-02-27 15:13:14.946549 [DEBUG] switch_ivr_play_say.c:1717 done
>>> playing file
>>> /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
>>> > 2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:70 No
>>> language specified - Using [en]
>>> > 2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:251 Handle
>>> play-file:[voicemail/vm-record_message.wav] (en:en)
>>> > 2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:1314 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>> > 2014-02-27 15:13:15.646531 [DEBUG] switch_core_session.c:1016 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:15.666534 [NOTICE] sofia.c:737 Hangup
>>> sofia/external/23673 [CS_EXECUTE] [NORMAL_CLEARING]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
>>> sofia/external/23673 [KILL]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:633 BRIDGE
>>> THREAD DONE [sofia/external/23673]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:661 Send signal
>>> loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:557
>>> sofia/external/23673 ending bridge by request from write function
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:633 BRIDGE
>>> THREAD DONE [loopback/voicemail-a]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:661 Send signal
>>> sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:15.666534 [NOTICE] switch_ivr_bridge.c:722 Hangup
>>> loopback/voicemail-a [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
>>> loopback/voicemail-a [KILL]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:481
>>> (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:678
>>> (loopback/voicemail-a) Callstate Change EARLY -> HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
>>> (loopback/voicemail-a) State HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:535
>>> loopback/voicemail-a CHANNEL HANGUP
>>> > 2014-02-27 15:13:15.666534 [NOTICE] mod_loopback.c:551 Hangup
>>> loopback/voicemail-b [CS_EXECUTE] [ORIGINATOR_CANCEL]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
>>> loopback/voicemail-b [KILL]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:48
>>> loopback/voicemail-a Standard HANGUP, cause: ORIGINATOR_CANCEL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
>>> (loopback/voicemail-a) State HANGUP going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:447
>>> (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-a) Running State Change CS_REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
>>> (loopback/voicemail-a) State REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:92
>>> loopback/voicemail-a Standard REPORTING, cause: ORIGINATOR_CANCEL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
>>> (loopback/voicemail-a) State REPORTING going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:441
>>> (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-a [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-a CHANNEL KILL
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1559 Session
>>> 3 (loopback/voicemail-a) Locked, Waiting on external entities
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:1530
>>> sofia/external/23673 skip receive message [UNBRIDGE] (channel is hungup
>>> already)
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:2810
>>> sofia/external/23673 skip receive message [APPLICATION_EXEC_COMPLETE]
>>> (channel is hungup already)
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:478
>>> (sofia/external/23673) State EXECUTE going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:678
>>> (sofia/external/23673) Callstate Change ACTIVE -> HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
>>> (sofia/external/23673) State HANGUP
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:500
>>> sofia/external/23673 Overriding SIP cause 480 with 415 from the other leg
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:506 Channel
>>> sofia/external/23673 hanging up, cause: NORMAL_CLEARING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:48
>>> sofia/external/23673 Standard HANGUP, cause: NORMAL_CLEARING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
>>> (sofia/external/23673) State HANGUP going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:447
>>> (sofia/external/23673) State Change CS_HANGUP -> CS_REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
>>> (sofia/external/23673) Running State Change CS_REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
>>> (sofia/external/23673) State REPORTING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:92
>>> sofia/external/23673 Standard REPORTING, cause: NORMAL_CLEARING
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
>>> (sofia/external/23673) State REPORTING going to sleep
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:441
>>> (sofia/external/23673) State Change CS_REPORTING -> CS_DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send
>>> signal sofia/external/23673 [BREAK]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1559 Session
>>> 1 (sofia/external/23673) Locked, Waiting on external entities
>>> > 2014-02-27 15:13:15.666534 [NOTICE] switch_core_session.c:1577 Session
>>> 1 (sofia/external/23673) Ended
>>> > 2014-02-27 15:13:15.666534 [NOTICE] switch_core_session.c:1581 Close
>>> Channel sofia/external/23673 [CS_DESTROY]
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:566
>>> (sofia/external/23673) Callstate Change HANGUP -> DOWN
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:569
>>> (sofia/external/23673) Running State Change CS_DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:579
>>> (sofia/external/23673) State DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:399
>>> sofia/external/23673 SOFIA DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:99
>>> sofia/external/23673 Standard DESTROY
>>> > 2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:579
>>> (sofia/external/23673) State DESTROY going to sleep
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_ivr_play_say.c:1717 done
>>> playing file
>>> /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:2810
>>> loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
>>> (channel is hungup already)
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:478
>>> (loopback/voicemail-b) State EXECUTE going to sleep
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-b) Running State Change CS_HANGUP
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:678
>>> (loopback/voicemail-b) Callstate Change EARLY -> HANGUP
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:680
>>> (loopback/voicemail-b) State HANGUP
>>> > 2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:535
>>> loopback/voicemail-b CHANNEL HANGUP
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:48
>>> loopback/voicemail-b Standard HANGUP, cause: ORIGINATOR_CANCEL
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:680
>>> (loopback/voicemail-b) State HANGUP going to sleep
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:447
>>> (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:415
>>> (loopback/voicemail-b) Running State Change CS_REPORTING
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:764
>>> (loopback/voicemail-b) State REPORTING
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:92
>>> loopback/voicemail-b Standard REPORTING, cause: ORIGINATOR_CANCEL
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:764
>>> (loopback/voicemail-b) State REPORTING going to sleep
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:441
>>> (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1351 Send
>>> signal loopback/voicemail-b [BREAK]
>>> > 2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:588
>>> loopback/voicemail-b CHANNEL KILL
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1559 Session
>>> 4 (loopback/voicemail-b) Locked, Waiting on external entities
>>> > 2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1577 Session
>>> 4 (loopback/voicemail-b) Ended
>>> > 2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1581 Close
>>> Channel loopback/voicemail-b [CS_DESTROY]
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:566
>>> (loopback/voicemail-b) Callstate Change HANGUP -> DOWN
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:569
>>> (loopback/voicemail-b) Running State Change CS_DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
>>> (loopback/voicemail-b) State DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:99
>>> loopback/voicemail-b Standard DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
>>> (loopback/voicemail-b) State DESTROY going to sleep
>>> > 2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1577 Session
>>> 3 (loopback/voicemail-a) Ended
>>> > 2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1581 Close
>>> Channel loopback/voicemail-a [CS_DESTROY]
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:566
>>> (loopback/voicemail-a) Callstate Change HANGUP -> DOWN
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:569
>>> (loopback/voicemail-a) Running State Change CS_DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
>>> (loopback/voicemail-a) State DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:99
>>> loopback/voicemail-a Standard DESTROY
>>> > 2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
>>> (loopback/voicemail-a) State DESTROY going to sleep
>>> >
>>> >
>>> _________________________________________________________________________
>>> > Professional FreeSWITCH Consulting Services:
>>> > consulting at freeswitch.org
>>> > http://www.freeswitchsolutions.com
>>> >
>>> >
>>> >
>>> >
>>> > Official FreeSWITCH Sites
>>> > http://www.freeswitch.org
>>> > http://wiki.freeswitch.org
>>> > http://www.cluecon.com
>>> >
>>> > FreeSWITCH-users mailing list
>>> > FreeSWITCH-users at lists.freeswitch.org
>>> > http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> > UNSUBSCRIBE:
>>> http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> > http://www.freeswitch.org
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>>
>>>
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140228/8b7266d7/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users
mailing list