[Freeswitch-users] session-api - How to continue with A-leg after bridge-timeout?

Thu Mar 8 21:31:18 MSK 2012

Hello!

I have written a DB-based routing-script to be able to configure
complex and dynamic call-behaviours but i'm currently stuck with
scenarious where different call-channels are merged(att_xfer,
intercept, et al), as my script fails with these scenarious.

I'm testing using a simplified version of the script(nxo_test.py) to
understand the mechanism behind those scenarious and now i'm at a
point where i no longer know the proper tools to handle these
situations. Here's what is happening:

This is the test-script in pseudocode:

> SRC=A
> DEST=B
> log("Test1")
> sleep(1000)
> log("Test2")
> sleep(1000)
> log("Test3")
> bridge([origination_caller_id_number="${SRC}"]user/${DEST}@${domain_name})
> log("Test4")
> sleep(1000)
> "log" "Test5"
> sleep(1000)
> "log" "Test6"

A dials B. The call enters the default context where the test-script
is called, the first steps are executed and the bridge is initiated.

B picks up the call, the following (truncated) channel-uuids exist at
this point:
"a7c4"(A->)
"a7cc"(->B)

B then initiates an attended transfer to C, which follows the same
path and script as the first call(But the call is bridged to C instead
of B this time). Two new channels are set up - uuid's "a7d5"(B->) and
"a7dd"(->C)

B immediately transfers the call before C has picked up.

Channel "a7cc"(->B) is killed by att_xfer while Channel "a7c4"(A->)
finishes the script(The remaining Steps Test3-Test5 are executed) and
is then automatically parked in endless_playback by att_xfer, waiting
for C to pick up.

C lets it ring until the timeout of 15s ends, "a7c4" and "a7dd" are
hung up while a7d5 continues as a ZOMBIE-channel, trying to execute
the remaining steps in the script(The "sleep"-commands fail due to the
zombie-state).

And this is where i'm stuck - i would like channel "a7c4" to not get
hung up but to continue with the steps which "a7d5" could no longer
execute. Is there some way to prevent a7c4 from getting hung up when
the ATTENDED_TRANSFER to C fails? Algorithmically i can figure out how
the remaining steps can get memorised and executed, i just don't know
how to prevent "a7c4" from getting hung up and beeing transfer to a
place where i can still work with it :-/ I can't use the HangupHook
either, as a7c4 is already in zombie-state at that point.

For reference, i've attached the test-script and a freeswitch-log of
the call above.

I hope someone can lead me on the right track...

Best regards
Christian
-------------- next part --------------
   ------------------------------------------------------------------------
recv 861 bytes from udp/[10.3.0.22]:5060 at 17:34:05.594085:
   ------------------------------------------------------------------------
   INVITE sip:30 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bK8ad4759287A067FB
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>
   CSeq: 1 INVITE
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Supported: 100rel,replaces
   Allow-Events: talk,hold,conference
   Max-Forwards: 70
   Content-Type: application/sdp
   Content-Length: 241

   v=0
   o=- 1167627581 1167627581 IN IP4 10.3.0.22
   s=Polycom IP Phone
   c=IN IP4 10.3.0.22
   t=0 0
   a=sendrecv
   m=audio 2262 RTP/AVP 9 0 8 127
   a=rtpmap:9 G722/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:127 telephone-event/8000
   ------------------------------------------------------------------------
send 333 bytes to udp/[10.3.0.22]:5060 at 17:34:05.595235:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bK8ad4759287A067FB
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:05.592923 [DEBUG] sofia.c:7559 IP 10.3.0.22 Rejected by acl "domains". Falling back to Digest auth.
2012-03-08 18:34:05.592923 [WARNING] sofia_reg.c:1422 SIP auth challenge (INVITE) on sofia profile 'internal' for [30 at 10.3.0.4] from ip 10.3.0.22
send 816 bytes to udp/[10.3.0.22]:5060 at 17:34:05.598758:
   ------------------------------------------------------------------------
   SIP/2.0 407 Proxy Authentication Required
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bK8ad4759287A067FB
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>;tag=Bvv69Ze2ttHyB
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Proxy-Authenticate: Digest realm="10.3.0.4", nonce="e73b92aa-6944-11e1-a7c3-a55c2ebde3ff", algorithm=MD5, qop="auth"
   Content-Length: 0

   ------------------------------------------------------------------------
recv 535 bytes from udp/[10.3.0.22]:5060 at 17:34:05.608337:
   ------------------------------------------------------------------------
   ACK sip:30 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bK8ad4759287A067FB
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>;tag=Bvv69Ze2ttHyB
   CSeq: 1 ACK
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
recv 1115 bytes from udp/[10.3.0.22]:5060 at 17:34:05.611505:
   ------------------------------------------------------------------------
   INVITE sip:30 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKacba9efF22172C0
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>
   CSeq: 2 INVITE
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Supported: 100rel,replaces
   Allow-Events: talk,hold,conference
   Proxy-Authorization: Digest username="10", realm="10.3.0.4", nonce="e73b92aa-6944-11e1-a7c3-a55c2ebde3ff", qop=auth, cnonce="eRH+crsyq6cDpwa", nc=00000001, uri="sip:30 at 10.3.0.4:5060;user=phone", response="a3d381aceaa4551a5eabcb39b426928d", algorithm=MD5
   Max-Forwards: 70
   Content-Type: application/sdp
   Content-Length: 241

   v=0
   o=- 1167627581 1167627581 IN IP4 10.3.0.22
   s=Polycom IP Phone
   c=IN IP4 10.3.0.22
   t=0 0
   a=sendrecv
   m=audio 2262 RTP/AVP 9 0 8 127
   a=rtpmap:9 G722/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:127 telephone-event/8000
   ------------------------------------------------------------------------
send 332 bytes to udp/[10.3.0.22]:5060 at 17:34:05.612619:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKacba9efF22172C0
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 2 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:05.612916 [DEBUG] sofia.c:7559 IP 10.3.0.22 Rejected by acl "domains". Falling back to Digest auth.
2012-03-08 18:34:05.612916 [NOTICE] switch_channel.c:926 New Channel sofia/internal/10 at 10.3.0.4 [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_NEW
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/10 at 10.3.0.4) State NEW
2012-03-08 18:34:05.612916 [DEBUG] sofia.c:5526 Channel sofia/internal/10 at 10.3.0.4 entering state [received][100]
2012-03-08 18:34:05.612916 [DEBUG] sofia.c:5537 Remote SDP:
v=0
o=- 1167627581 1167627581 IN IP4 10.3.0.22
s=Polycom IP Phone
c=IN IP4 10.3.0.22
t=0 0
a=sendrecv
m=audio 2262 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000

2012-03-08 18:34:05.612916 [DEBUG] sofia_glue.c:4865 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-08 18:34:05.612916 [DEBUG] sofia_glue.c:2982 Set Codec sofia/internal/10 at 10.3.0.4 G722/8000 20 ms 160 samples 64000 bits
2012-03-08 18:34:05.612916 [DEBUG] switch_core_codec.c:111 sofia/internal/10 at 10.3.0.4 Original read codec set to G722:9
2012-03-08 18:34:05.612916 [DEBUG] sofia_glue.c:4986 Set 2833 dtmf send/recv payload to 127
2012-03-08 18:34:05.612916 [DEBUG] sofia.c:5749 (sofia/internal/10 at 10.3.0.4) State Change CS_NEW -> CS_INIT
2012-03-08 18:34:05.612916 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_INIT
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/10 at 10.3.0.4) State INIT
2012-03-08 18:34:05.612916 [DEBUG] mod_sofia.c:85 sofia/internal/10 at 10.3.0.4 SOFIA INIT
2012-03-08 18:34:05.612916 [DEBUG] mod_sofia.c:125 (sofia/internal/10 at 10.3.0.4) State Change CS_INIT -> CS_ROUTING
2012-03-08 18:34:05.612916 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/10 at 10.3.0.4) State INIT going to sleep
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_ROUTING
2012-03-08 18:34:05.612916 [DEBUG] switch_channel.c:1886 (sofia/internal/10 at 10.3.0.4) Callstate Change DOWN -> RINGING
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/10 at 10.3.0.4) State ROUTING
2012-03-08 18:34:05.612916 [DEBUG] mod_sofia.c:148 sofia/internal/10 at 10.3.0.4 SOFIA ROUTING
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:104 sofia/internal/10 at 10.3.0.4 Standard ROUTING
2012-03-08 18:34:05.612916 [INFO] mod_dialplan_xml.c:485 Processing A <10>->30 in context default
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->nxo_enable_chefsec] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [nxo_enable_chefsec] destination_number(30) =~ /^\*95(\d{0,7})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [group-intercept] destination_number(30) =~ /^\*82$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [intercept-ext] destination_number(30) =~ /^\*81(\d+)$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->nxo_single_intercom_with_two_way_audio] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [nxo_single_intercom_with_two_way_audio] destination_number(30) =~ /^\*01(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->nxo_group_intercom] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [nxo_group_intercom] destination_number(30) =~ /^\*02(\d{0,7})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->Outbound to PSTN 11 Digits] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [Outbound to PSTN 11 Digits] destination_number(30) =~ /^(1[2-9][0-9]{2}[2-9]{7})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->del-group] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [del-group] destination_number(30) =~ /^\*\*50(\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->add-group] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [add-group] destination_number(30) =~ /^\*\*51(\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [call-group-simo] destination_number(30) =~ /^\*52(\d{2,4})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [call-group-order] destination_number(30) =~ /^\*53(\d{2,4})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->nb_conferences] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [nb_conferences] destination_number(30) =~ /^\*(30\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->wb_conferences] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [wb_conferences] destination_number(30) =~ /^\*(31\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->uwb_conferences] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [uwb_conferences] destination_number(30) =~ /^\*(32\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [cdquality_conferences] destination_number(30) =~ /^\*(33\d{2})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->global_directory] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [global_directory] destination_number(30) =~ /^\*77(\d{1,3})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->redirect_now] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [redirect_now] destination_number(30) =~ /^\*21(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->redirect_timeout] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [redirect_timeout] destination_number(30) =~ /^\*22(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->redirect_busy] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [redirect_busy] destination_number(30) =~ /^\*23(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->call_privacy] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [call_privacy] destination_number(30) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->call_privacy] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [call_privacy] destination_number(30) =~ /^\*60$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->send_to_voicemail] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [send_to_voicemail] destination_number(30) =~ /^\*99(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->vmain] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [vmain] destination_number(30) =~ /^vmain$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->vmain1] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [vmain1] destination_number(30) =~ /^vmain1$|^\*97$|^97$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->vmain2] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [vmain2] destination_number(30) =~ /^vmain2$|^\*98$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->redirect_now] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (FAIL) [redirect_now] destination_number(30) =~ /^\*35$/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 parsing [default->Local_Extension_test] continue=false
Dialplan: sofia/internal/10 at 10.3.0.4 Regex (PASS) [Local_Extension_test] destination_number(30) =~ /(^\d{2,7}$)/ break=on-false
Dialplan: sofia/internal/10 at 10.3.0.4 Action set(dialed_extension=30) 
Dialplan: sofia/internal/10 at 10.3.0.4 Action export(dialed_extension=30) 
Dialplan: sofia/internal/10 at 10.3.0.4 Action python(nxo_test) 
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/10 at 10.3.0.4) State Change CS_ROUTING -> CS_EXECUTE
2012-03-08 18:34:05.612916 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/10 at 10.3.0.4) State ROUTING going to sleep
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_EXECUTE
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE
2012-03-08 18:34:05.612916 [DEBUG] mod_sofia.c:241 sofia/internal/10 at 10.3.0.4 SOFIA EXECUTE
2012-03-08 18:34:05.612916 [DEBUG] switch_core_state_machine.c:192 sofia/internal/10 at 10.3.0.4 Standard EXECUTE
EXECUTE sofia/internal/10 at 10.3.0.4 set(dialed_extension=30)
2012-03-08 18:34:05.633001 [DEBUG] mod_dptools.c:1281 sofia/internal/10 at 10.3.0.4 SET [dialed_extension]=[30]
EXECUTE sofia/internal/10 at 10.3.0.4 export(dialed_extension=30)
2012-03-08 18:34:05.633001 [DEBUG] switch_channel.c:1093 EXPORT (export_vars) [dialed_extension]=[30]
EXECUTE sofia/internal/10 at 10.3.0.4 python(nxo_test)
2012-03-08 18:34:05.633001 [NOTICE] mod_python.c:212 Invoking py module: nxo_test
2012-03-08 18:34:05.652944 [DEBUG] mod_python.c:281 Call python script 
2012-03-08 18:34:05.652944 [INFO] switch_cpp.cpp:1227 TEST: Destination-extension 30
send 1326 bytes to udp/[10.3.0.25]:5060 at 17:34:05.792382:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKptUaH731cyvgm
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   CSeq: 185332666 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1156
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="403" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1334 bytes to udp/[10.3.0.26]:5060 at 17:34:05.793468:
   ------------------------------------------------------------------------
   NOTIFY sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKQ3m3j2m596j3F
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   CSeq: 185332667 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1156
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="403" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 406 bytes from udp/[10.3.0.25]:5060 at 17:34:05.799132:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKptUaH731cyvgm
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   CSeq: 185332666 NOTIFY
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 414 bytes from udp/[10.3.0.26]:5060 at 17:34:05.799603:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKQ3m3j2m596j3F
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   CSeq: 185332667 NOTIFY
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
EXECUTE sofia/internal/10 at 10.3.0.4 set(continue_on_fail=true)
2012-03-08 18:34:06.232952 [DEBUG] mod_dptools.c:1281 sofia/internal/10 at 10.3.0.4 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/10 at 10.3.0.4 set(hangup_after_bridge=true)
2012-03-08 18:34:06.232952 [DEBUG] mod_dptools.c:1281 sofia/internal/10 at 10.3.0.4 SET [hangup_after_bridge]=[true]
2012-03-08 18:34:06.232952 [WARNING] switch_cpp.cpp:1227 TEST 1 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:07.232931 [WARNING] switch_cpp.cpp:1227 TEST 2 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:08.232934 [WARNING] switch_cpp.cpp:1227 TEST 3 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
EXECUTE sofia/internal/10 at 10.3.0.4 info()
2012-03-08 18:34:09.252934 [INFO] mod_dptools.c:1439 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/10 at 10.3.0.4]
Unique-ID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Presence-ID: [10 at 10.3.0.4]
Channel-Call-UUID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Answer-State: [ringing]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Read-Codec-Bit-Rate: [64000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Channel-Write-Codec-Bit-Rate: [64000]
Caller-Direction: [inbound]
Caller-Username: [10]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [A]
Caller-Caller-ID-Number: [10]
Caller-Network-Addr: [10.3.0.22]
Caller-ANI: [10]
Caller-Destination-Number: [30]
Caller-Unique-ID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/10 at 10.3.0.4]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1331228045612916]
Caller-Channel-Created-Time: [1331228045612916]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
variable_session_id: [9]
variable_sip_local_network_addr: [10.3.0.4]
variable_sip_network_ip: [10.3.0.22]
variable_sip_network_port: [5060]
variable_sip_received_ip: [10.3.0.22]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_number_alias: [10]
variable_sip_auth_username: [10]
variable_sip_auth_realm: [10.3.0.4]
variable_number_alias: [10]
variable_user_name: [10]
variable_domain_name: [10.3.0.4]
variable_record_stereo: [true]
variable_default_gateway: [fonira]
variable_default_areacode: [01]
variable_transfer_fallback_extension: [operator]
variable_toll_allow: [local,domestic,international,vas]
variable_accountcode: [10]
variable_user_context: [default]
variable_effective_caller_id_name: [A ]
variable_effective_caller_id_number: [10]
variable_outbound_caller_id_name: [A ]
variable_outbound_caller_id_number: [1997156010]
variable_callgroup: [intercept]
variable_sip_from_user: [10]
variable_sip_from_uri: [10 at 10.3.0.4]
variable_sip_from_host: [10.3.0.4]
variable_sip_from_user_stripped: [10]
variable_sip_from_tag: [B0C14C18-E7DC6BB1]
variable_sofia_profile_name: [internal]
variable_sip_full_via: [SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKacba9efF22172C0]
variable_sip_from_display: [A]
variable_sip_full_from: ["A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1]
variable_sip_full_to: [<sip:30 at 10.3.0.4;user=phone>]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [30]
variable_sip_req_port: [5060]
variable_sip_req_uri: [30 at 10.3.0.4:5060]
variable_sip_req_host: [10.3.0.4]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [30]
variable_sip_to_uri: [30 at 10.3.0.4]
variable_sip_to_host: [10.3.0.4]
variable_sip_contact_user: [10]
variable_sip_contact_uri: [10 at 10.3.0.22]
variable_sip_contact_host: [10.3.0.22]
variable_channel_name: [sofia/internal/10 at 10.3.0.4]
variable_sip_call_id: [c64e932c-3eca2965-da54ee6 at 10.3.0.22]
variable_sip_user_agent: [PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933]
variable_sip_via_host: [10.3.0.22]
variable_max_forwards: [70]
variable_presence_id: [10 at 10.3.0.4]
variable_switch_r_sdp: [v=0
o=- 1167627581 1167627581 IN IP4 10.3.0.22
s=Polycom IP Phone
c=IN IP4 10.3.0.22
t=0 0
a=sendrecv
m=audio 2262 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
]
variable_remote_media_ip: [10.3.0.22]
variable_remote_media_port: [2262]
variable_sip_audio_recv_pt: [9]
variable_sip_use_codec_name: [G722]
variable_sip_use_codec_rate: [8000]
variable_sip_use_codec_ptime: [20]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_endpoint_disposition: [RECEIVED]
variable_DP_MATCH: [ARRAY::30|:30]
variable_call_uuid: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
variable_dialed_extension: [30]
variable_export_vars: [dialed_extension]
variable_continue_on_fail: [true]
variable_hangup_after_bridge: [true]
variable_current_application: [info]

EXECUTE sofia/internal/10 at 10.3.0.4 bridge([leg_timeout=15][origination_caller_id_number=10]user/30 at 10.3.0.4)
2012-03-08 18:34:09.252934 [DEBUG] switch_channel.c:1047 sofia/internal/10 at 10.3.0.4 EXPORTING[export_vars] [dialed_extension]=[30] to event
2012-03-08 18:34:09.252934 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables
2012-03-08 18:34:09.252934 [DEBUG] switch_ivr_originate.c:2299 Parsing session specific variables
2012-03-08 18:34:09.252934 [DEBUG] switch_event.c:1522 Parsing variable [leg_timeout]=[15]
2012-03-08 18:34:09.252934 [DEBUG] switch_event.c:1522 Parsing variable [origination_caller_id_number]=[10]
2012-03-08 18:34:09.252934 [DEBUG] switch_channel.c:1047 sofia/internal/10 at 10.3.0.4 EXPORTING[export_vars] [dialed_extension]=[30] to event
2012-03-08 18:34:09.252934 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables
2012-03-08 18:34:09.252934 [DEBUG] switch_event.c:1522 Parsing variable [presence_id]=[30 at 10.3.0.4]
2012-03-08 18:34:09.252934 [NOTICE] switch_channel.c:926 New Channel sofia/internal/sip:30 at 10.3.0.26 [e96bae48-6944-11e1-a7cc-a55c2ebde3ff]
2012-03-08 18:34:09.252934 [DEBUG] mod_sofia.c:4673 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_NEW -> CS_INIT
2012-03-08 18:34:09.252934 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.252934 [DEBUG] switch_ivr_originate.c:2561 sofia/internal/sip:30 at 10.3.0.26 Setting leg timeout to 15
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_INIT
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:30 at 10.3.0.26) State INIT
2012-03-08 18:34:09.252934 [DEBUG] mod_sofia.c:85 sofia/internal/sip:30 at 10.3.0.26 SOFIA INIT
2012-03-08 18:34:09.252934 [DEBUG] mod_sofia.c:125 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_INIT -> CS_ROUTING
2012-03-08 18:34:09.252934 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:30 at 10.3.0.26) State INIT going to sleep
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_ROUTING
2012-03-08 18:34:09.252934 [DEBUG] switch_channel.c:1886 (sofia/internal/sip:30 at 10.3.0.26) Callstate Change DOWN -> RINGING
send 1255 bytes to udp/[10.3.0.26]:5060 at 17:34:09.271864:
   ------------------------------------------------------------------------
   INVITE sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKrcevmX586F9NB
   Max-Forwards: 69
   From: "A " <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: <sip:30 at 10.3.0.26>
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 25277960 INVITE
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 369
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "A " <sip:10 at 10.3.0.4>;party=calling;screen=yes;privacy=off

   v=0
   o=FreeSWITCH 1331211599 1331211600 IN IP4 10.3.0.4
   s=FreeSWITCH
   c=IN IP4 10.3.0.4
   t=0 0
   m=audio 16450 RTP/AVP 9 0 8 3 101 13
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   m=video 16418 RTP/AVP 98 99 100 34 31
   a=rtpmap:98 H264/90000
   a=rtpmap:99 H263-2000/90000
   a=rtpmap:100 H263-1998/90000
   a=rtpmap:34 H263/90000
   a=rtpmap:31 H261/90000
   ------------------------------------------------------------------------
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:30 at 10.3.0.26) State ROUTING
2012-03-08 18:34:09.252934 [DEBUG] mod_sofia.c:148 sofia/internal/sip:30 at 10.3.0.26 SOFIA ROUTING
2012-03-08 18:34:09.252934 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-03-08 18:34:09.252934 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:30 at 10.3.0.26) State ROUTING going to sleep
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_CONSUME_MEDIA
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:30 at 10.3.0.26) State CONSUME_MEDIA
2012-03-08 18:34:09.252934 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:30 at 10.3.0.26) State CONSUME_MEDIA going to sleep
2012-03-08 18:34:09.252934 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.252934 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [calling][0]
recv 413 bytes from udp/[10.3.0.26]:5060 at 17:34:09.279527:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKrcevmX586F9NB
   From: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   CSeq: 25277960 INVITE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1323 bytes to udp/[10.3.0.22]:5060 at 17:34:09.314994:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKSN7mprpc4rZ8p
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   CSeq: 185332668 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3315
   Content-Type: application/dialog-info+xml
   Content-Length: 509

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="511" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1321 bytes to udp/[10.3.0.25]:5060 at 17:34:09.318770:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKty0DrK7F11NUj
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   CSeq: 185332669 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3315
   Content-Type: application/dialog-info+xml
   Content-Length: 509

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="511" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:09.320972:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKSN7mprpc4rZ8p
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   CSeq: 185332668 NOTIFY
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1333 bytes to udp/[10.3.0.27]:5060 at 17:34:09.323875:
   ------------------------------------------------------------------------
   NOTIFY sip:31 at 10.3.0.27 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKU7S6SerKyacee
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   CSeq: 185332670 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3315
   Content-Type: application/dialog-info+xml
   Content-Length: 509

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="511" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 405 bytes from udp/[10.3.0.25]:5060 at 17:34:09.324463:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKty0DrK7F11NUj
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   CSeq: 185332669 NOTIFY
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 417 bytes from udp/[10.3.0.27]:5060 at 17:34:09.328816:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKU7S6SerKyacee
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   CSeq: 185332670 NOTIFY
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   Contact: <sip:31 at 10.3.0.27>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 450 bytes from udp/[10.3.0.26]:5060 at 17:34:09.330485:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKrcevmX586F9NB
   From: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   CSeq: 25277960 INVITE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Allow-Events: talk,hold,conference
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:09.312952 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.312952 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:09.352961 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [proceeding][180]
2012-03-08 18:34:09.352961 [NOTICE] sofia.c:5618 Ring-Ready sofia/internal/sip:30 at 10.3.0.26!
2012-03-08 18:34:09.352961 [NOTICE] mod_sofia.c:2514 Ring-Ready sofia/internal/10 at 10.3.0.4!
send 797 bytes to udp/[10.3.0.22]:5060 at 17:34:09.373141:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKacba9efF22172C0
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 2 INVITE
   Contact: <sip:30 at 10.3.0.4:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   Remote-Party-ID: "Outbound Call" <30>;party=calling;privacy=off;screen=no

   ------------------------------------------------------------------------
2012-03-08 18:34:09.352961 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:09.374533 [DEBUG] sofia.c:5526 Channel sofia/internal/10 at 10.3.0.4 entering state [early][180]
2012-03-08 18:34:09.374533 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:09.374533 [NOTICE] switch_ivr_originate.c:483 Ring Ready sofia/internal/10 at 10.3.0.4!
recv 915 bytes from udp/[10.3.0.26]:5060 at 17:34:10.190061:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKrcevmX586F9NB
   From: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   CSeq: 25277960 INVITE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   Supported: 100rel,replaces
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Type: application/sdp
   Content-Length: 347

   v=0
   o=- 1167627586 1167627586 IN IP4 10.3.0.26
   s=Polycom IP Phone
   c=IN IP4 10.3.0.26
   t=0 0
   m=audio 2234 RTP/AVP 9 127
   a=rtpmap:9 G722/8000
   a=rtpmap:127 telephone-event/8000
   m=video 0 RTP/AVP 98 99 100 34 31
   a=rtpmap:98 H264/90000
   a=rtpmap:99 H263-2000/90000
   a=rtpmap:100 H263-1998/90000
   a=rtpmap:34 H263/90000
   a=rtpmap:31 H261/90000
   ------------------------------------------------------------------------
2012-03-08 18:34:10.172931 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.172931 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.192945 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [completing][200]
2012-03-08 18:34:10.192945 [DEBUG] sofia.c:5537 Remote SDP:
v=0
o=- 1167627586 1167627586 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 10.3.0.26
t=0 0
m=audio 2234 RTP/AVP 9 127
a=rtpmap:9 G722/8000
a=rtpmap:127 telephone-event/8000
m=video 0 RTP/AVP 98 99 100 34 31
a=rtpmap:98 H264/90000
a=rtpmap:99 H263-2000/90000
a=rtpmap:100 H263-1998/90000
a=rtpmap:34 H263/90000
a=rtpmap:31 H261/90000

send 336 bytes to udp/[10.3.0.26]:5060 at 17:34:10.201818:
   ------------------------------------------------------------------------
   ACK sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKvgKZU98pUK20S
   Max-Forwards: 70
   From: "A " <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 25277960 ACK
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:10.192945 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.192945 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.192945 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [ready][200]
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:4865 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:2982 Set Codec sofia/internal/sip:30 at 10.3.0.26 G722/8000 20 ms 160 samples 64000 bits
2012-03-08 18:34:10.192945 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:30 at 10.3.0.26 Original read codec set to G722:9
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:4979 Set 2833 dtmf send payload to 127
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:3234 AUDIO RTP [sofia/internal/sip:30 at 10.3.0.26] 10.3.0.4 port 16450 -> 10.3.0.26 port 2234 codec: 9 ms: 20
2012-03-08 18:34:10.192945 [DEBUG] switch_rtp.c:1661 Starting timer [soft] 160 bytes per 20ms
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:3498 Set 2833 dtmf send payload to 127
2012-03-08 18:34:10.192945 [DEBUG] sofia_glue.c:3504 Set 2833 dtmf receive payload to 101
2012-03-08 18:34:10.192945 [DEBUG] switch_channel.c:3190 (sofia/internal/sip:30 at 10.3.0.26) Callstate Change RINGING -> ACTIVE
2012-03-08 18:34:10.192945 [DEBUG] switch_channel.c:3202 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.192945 [NOTICE] sofia.c:6238 Channel [sofia/internal/sip:30 at 10.3.0.26] has been answered
2012-03-08 18:34:10.212964 [DEBUG] sofia_glue.c:3234 AUDIO RTP [sofia/internal/10 at 10.3.0.4] 10.3.0.4 port 16420 -> 10.3.0.22 port 2262 codec: 9 ms: 20
2012-03-08 18:34:10.212964 [DEBUG] switch_rtp.c:1661 Starting timer [soft] 160 bytes per 20ms
2012-03-08 18:34:10.212964 [DEBUG] sofia_glue.c:3498 Set 2833 dtmf send payload to 127
2012-03-08 18:34:10.212964 [DEBUG] sofia_glue.c:3504 Set 2833 dtmf receive payload to 127
2012-03-08 18:34:10.212964 [DEBUG] mod_sofia.c:750 Local SDP sofia/internal/10 at 10.3.0.4:
v=0
o=FreeSWITCH 1331211630 1331211631 IN IP4 10.3.0.4
s=FreeSWITCH
c=IN IP4 10.3.0.4
t=0 0
m=audio 16420 RTP/AVP 9 127
a=rtpmap:9 G722/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2012-03-08 18:34:10.212964 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.212964 [DEBUG] switch_channel.c:3190 (sofia/internal/10 at 10.3.0.4) Callstate Change RINGING -> ACTIVE
send 1069 bytes to udp/[10.3.0.22]:5060 at 17:34:10.220245:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKacba9efF22172C0
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 2 INVITE
   Contact: <sip:30 at 10.3.0.4:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 239
   Remote-Party-ID: "Outbound Call" <30>;party=calling;privacy=off;screen=no

   v=0
   o=FreeSWITCH 1331211630 1331211631 IN IP4 10.3.0.4
   s=FreeSWITCH
   c=IN IP4 10.3.0.4
   t=0 0
   m=audio 16420 RTP/AVP 9 127
   a=rtpmap:9 G722/80002012-03-08 18:34:10.212964 [NOTICE] switch_ivr_originate.c:3209 Channel [sofia/internal/10 at 10.3.0.4] has been answered

   a=rtpmap:127 telephone-event/8000
   a=fmtp:127 0-16
   a=silenceSupp:off - - - -
   a=ptime:20
   ------------------------------------------------------------------------
2012-03-08 18:34:10.212964 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.212964 [DEBUG] sofia.c:5526 Channel sofia/internal/10 at 10.3.0.4 entering state [completed][200]
2012-03-08 18:34:10.212964 [DEBUG] switch_ivr_originate.c:3266 Originate Resulted in Success: [sofia/internal/sip:30 at 10.3.0.26]
2012-03-08 18:34:10.212964 [DEBUG] switch_ivr_originate.c:2561 sofia/internal/sip:30 at 10.3.0.26 Setting leg timeout to 15
2012-03-08 18:34:10.212964 [DEBUG] switch_ivr_originate.c:3266 Originate Resulted in Success: [sofia/internal/sip:30 at 10.3.0.26]
recv 538 bytes from udp/[10.3.0.22]:5060 at 17:34:10.229645:
   ------------------------------------------------------------------------
   ACK sip:30 at 10.3.0.4:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKe8d47063D608BAD4
   From: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   To: <sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ
   CSeq: 2 ACK
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:10.212964 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.212964 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.212964 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.212964 [DEBUG] sofia.c:5526 Channel sofia/internal/10 at 10.3.0.4 entering state [ready][200]
2012-03-08 18:34:10.232988 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.232988 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:10.232988 [DEBUG] switch_ivr_bridge.c:1328 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2012-03-08 18:34:10.232988 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.232988 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_EXCHANGE_MEDIA
2012-03-08 18:34:10.232988 [DEBUG] switch_core_state_machine.c:420 (sofia/internal/sip:30 at 10.3.0.26) State EXCHANGE_MEDIA
2012-03-08 18:34:10.232988 [DEBUG] mod_sofia.c:578 SOFIA EXCHANGE_MEDIA
2012-03-08 18:34:10.232988 [DEBUG] switch_core_session.c:791 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:10.232988 [DEBUG] switch_core_session.c:791 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
send 1325 bytes to udp/[10.3.0.25]:5060 at 17:34:10.284271:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKXScrX4StrvrKN
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   CSeq: 185332671 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3314
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="512" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1337 bytes to udp/[10.3.0.27]:5060 at 17:34:10.287919:
   ------------------------------------------------------------------------
   NOTIFY sip:31 at 10.3.0.27 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKy25gZZayN5e6g
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   CSeq: 185332672 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3314
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="512" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 405 bytes from udp/[10.3.0.25]:5060 at 17:34:10.289984:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKXScrX4StrvrKN
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   CSeq: 185332671 NOTIFY
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1327 bytes to udp/[10.3.0.22]:5060 at 17:34:10.292085:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKZBZ90tU1je5rc
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   CSeq: 185332673 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3314
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="512" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 417 bytes from udp/[10.3.0.27]:5060 at 17:34:10.294071:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKy25gZZayN5e6g
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   CSeq: 185332672 NOTIFY
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   Contact: <sip:31 at 10.3.0.27>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:10.295560 [DEBUG] switch_rtp.c:3205 Correct ip/port confirmed.
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:10.306207:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKZBZ90tU1je5rc
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   CSeq: 185332673 NOTIFY
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1326 bytes to udp/[10.3.0.25]:5060 at 17:34:10.321415:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK0mr22Nc5FQUBr
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   CSeq: 185332674 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1151
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="404" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1334 bytes to udp/[10.3.0.26]:5060 at 17:34:10.325110:
   ------------------------------------------------------------------------
   NOTIFY sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK1XHU4gX8c0HyK
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   CSeq: 185332675 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1151
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="404" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 406 bytes from udp/[10.3.0.25]:5060 at 17:34:10.327746:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK0mr22Nc5FQUBr
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   CSeq: 185332674 NOTIFY
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 414 bytes from udp/[10.3.0.26]:5060 at 17:34:10.330727:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK1XHU4gX8c0HyK
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   CSeq: 185332675 NOTIFY
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:10.332940 [DEBUG] switch_rtp.c:3205 Correct ip/port confirmed.
recv 986 bytes from udp/[10.3.0.26]:5060 at 17:34:12.188618:
   ------------------------------------------------------------------------
   INVITE sip:mod_sofia at 10.3.0.4:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKb0c085088B8047EB
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   CSeq: 1 INVITE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Supported: 100rel,replaces
   Allow-Events: talk,hold,conference
   Max-Forwards: 70
   Content-Type: application/sdp
   Content-Length: 345

   v=0
   o=- 1167627586 1167627587 IN IP4 10.3.0.26
   s=Polycom IP Phone
   c=IN IP4 0.0.0.0
   t=0 0
   m=audio 2234 RTP/AVP 9 101
   a=rtpmap:9 G722/8000
   a=rtpmap:101 telephone-event/8000
   m=video 0 RTP/AVP 98 99 100 34 31
   a=rtpmap:98 H264/90000
   a=rtpmap:99 H263-2000/90000
   a=rtpmap:100 H263-1998/90000
   a=rtpmap:34 H263/90000
   a=rtpmap:31 H261/90000
   ------------------------------------------------------------------------
send 358 bytes to udp/[10.3.0.26]:5060 at 17:34:12.189427:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKb0c085088B8047EB
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:12.172933 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.172933 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.192941 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [received][100]
2012-03-08 18:34:12.192941 [DEBUG] sofia.c:5537 Remote SDP:
v=0
o=- 1167627586 1167627587 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 0.0.0.0
t=0 0
m=audio 2234 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=sendonly
m=video 0 RTP/AVP 98 99 100 34 31
a=rtpmap:98 H264/90000
a=rtpmap:99 H263-2000/90000
a=rtpmap:100 H263-1998/90000
a=rtpmap:34 H263/90000
a=rtpmap:31 H261/90000

2012-03-08 18:34:12.192941 [DEBUG] switch_channel.c:1560 (sofia/internal/sip:30 at 10.3.0.26) Callstate Change ACTIVE -> HELD
2012-03-08 18:34:12.192941 [DEBUG] switch_core_session.c:1012 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:12.212935 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
send 1322 bytes to udp/[10.3.0.22]:5060 at 17:34:12.251628:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK26am6Beca97gF
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   CSeq: 185332676 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3312
   Content-Type: application/dialog-info+xml
   Content-Length: 508

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="513" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="no"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1320 bytes to udp/[10.3.0.25]:5060 at 17:34:12.252624:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK3F4c86yF7Hy3a
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   CSeq: 185332677 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3312
   Content-Type: application/dialog-info+xml
   Content-Length: 508

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="513" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="no"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1332 bytes to udp/[10.3.0.27]:5060 at 17:34:12.257830:
   ------------------------------------------------------------------------
   NOTIFY sip:31 at 10.3.0.27 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK4rX591FK4tmpp
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   CSeq: 185332678 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3312
   Content-Type: application/dialog-info+xml
   Content-Length: 508

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="513" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="no"/>
   </target>
   </local>
   <remote>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 405 bytes from udp/[10.3.0.25]:5060 at 17:34:12.259955:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK3F4c86yF7Hy3a
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   CSeq: 185332677 NOTIFY
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:12.260542:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK26am6Beca97gF
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   CSeq: 185332676 NOTIFY
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 417 bytes from udp/[10.3.0.27]:5060 at 17:34:12.264011:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK4rX591FK4tmpp
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   CSeq: 185332678 NOTIFY
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   Contact: <sip:31 at 10.3.0.27>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:12.392939 [DEBUG] switch_ivr.c:591 sofia/internal/10 at 10.3.0.4 Command Execute playback(local_stream://moh)
EXECUTE sofia/internal/10 at 10.3.0.4 playback(local_stream://moh)
2012-03-08 18:34:12.392939 [DEBUG] mod_local_stream.c:421 Opening Stream [moh/16000] 16000hz
2012-03-08 18:34:12.392939 [DEBUG] switch_ivr_play_say.c:1306 Codec Activated L16 at 16000hz 1 channels 20ms
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:4865 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:2916 Already using G722
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:4979 Set 2833 dtmf send payload to 101
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:3223 Audio params changed for sofia/internal/sip:30 at 10.3.0.26 from 10.3.0.26:2234 to 0.0.0.0:2234
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:3234 AUDIO RTP [sofia/internal/sip:30 at 10.3.0.26] 10.3.0.4 port 16450 -> 0.0.0.0 port 2234 codec: 9 ms: 20
2012-03-08 18:34:12.432933 [DEBUG] sofia_glue.c:3275 AUDIO RTP CHANGING DEST TO: [0.0.0.0:2234]
2012-03-08 18:34:12.432933 [DEBUG] sofia.c:6034 Processing updated SDP
send 937 bytes to udp/[10.3.0.26]:5060 at 17:34:12.446972:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKb0c085088B8047EB
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 1 INVITE
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 297

   v=0
   o=FreeSWITCH 1331211599 1331211601 IN IP4 10.3.0.4
   s=FreeSWITCH
   c=IN IP4 10.3.0.4
   t=0 0
   m=audio 16450 RTP/AVP 9 101
   a=rtpmap:9 G722/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=recvonly
   a=silenceSupp:off - - - -
   a=ptime:20
   m=video 0 RTP/AVP 98
   a=rtpmap:98 H264/90000
   ------------------------------------------------------------------------
2012-03-08 18:34:12.432933 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.452935 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [completed][200]
recv 537 bytes from udp/[10.3.0.26]:5060 at 17:34:12.455260:
   ------------------------------------------------------------------------
   ACK sip:mod_sofia at 10.3.0.4:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKe85649e7EEFB8C2
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   CSeq: 1 ACK
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:12.452935 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.452935 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.452935 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:12.472932 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:30 at 10.3.0.26 entering state [ready][200]
recv 869 bytes from udp/[10.3.0.26]:5060 at 17:34:14.406913:
   ------------------------------------------------------------------------
   INVITE sip:20 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK460db7754D408CC0
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>
   CSeq: 1 INVITE
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Supported: 100rel,replaces
   Allow-Events: talk,hold,conference
   Max-Forwards: 70
   Content-Type: application/sdp
   Content-Length: 241

   v=0
   o=- 1167627590 1167627590 IN IP4 10.3.0.26
   s=Polycom IP Phone
   c=IN IP4 10.3.0.26
   t=0 0
   a=sendrecv
   m=audio 2236 RTP/AVP 9 0 8 127
   a=rtpmap:9 G722/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:127 telephone-event/8000
   ------------------------------------------------------------------------
send 341 bytes to udp/[10.3.0.26]:5060 at 17:34:14.407711:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK460db7754D408CC0
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:14.392941 [DEBUG] sofia.c:7559 IP 10.3.0.26 Rejected by acl "domains". Falling back to Digest auth.
2012-03-08 18:34:14.392941 [WARNING] sofia_reg.c:1422 SIP auth challenge (INVITE) on sofia profile 'internal' for [20 at 10.3.0.4] from ip 10.3.0.26
send 824 bytes to udp/[10.3.0.26]:5060 at 17:34:14.412500:
   ------------------------------------------------------------------------
   SIP/2.0 407 Proxy Authentication Required
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK460db7754D408CC0
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=eQ8gFH1cjNmpe
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Proxy-Authenticate: Digest realm="10.3.0.4", nonce="ec7c3b52-6944-11e1-a7d4-a55c2ebde3ff", algorithm=MD5, qop="auth"
   Content-Length: 0

   ------------------------------------------------------------------------
recv 543 bytes from udp/[10.3.0.26]:5060 at 17:34:14.420731:
   ------------------------------------------------------------------------
   ACK sip:20 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK460db7754D408CC0
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=eQ8gFH1cjNmpe
   CSeq: 1 ACK
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
recv 1124 bytes from udp/[10.3.0.26]:5060 at 17:34:14.423632:
   ------------------------------------------------------------------------
   INVITE sip:20 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>
   CSeq: 2 INVITE
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Supported: 100rel,replaces
   Allow-Events: talk,hold,conference
   Proxy-Authorization: Digest username="30", realm="10.3.0.4", nonce="ec7c3b52-6944-11e1-a7d4-a55c2ebde3ff", qop=auth, cnonce="XJz4HrL/160QNgt", nc=00000001, uri="sip:20 at 10.3.0.4:5060;user=phone", response="5aa06aa91b7e6941539ee02b96a22789", algorithm=MD5
   Max-Forwards: 70
   Content-Type: application/sdp
   Content-Length: 241

   v=0
   o=- 1167627590 1167627590 IN IP4 10.3.0.26
   s=Polycom IP Phone
   c=IN IP4 10.3.0.26
   t=0 0
   a=sendrecv
   m=audio 2236 RTP/AVP 9 0 8 127
   a=rtpmap:9 G722/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:127 telephone-event/8000
   ------------------------------------------------------------------------
send 341 bytes to udp/[10.3.0.26]:5060 at 17:34:14.424685:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 2 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:14.412921 [DEBUG] sofia.c:7559 IP 10.3.0.26 Rejected by acl "domains". Falling back to Digest auth.
2012-03-08 18:34:14.432937 [NOTICE] switch_channel.c:926 New Channel sofia/internal/30 at 10.3.0.4 [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_NEW
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/30 at 10.3.0.4) State NEW
2012-03-08 18:34:14.432937 [DEBUG] sofia.c:5526 Channel sofia/internal/30 at 10.3.0.4 entering state [received][100]
2012-03-08 18:34:14.432937 [DEBUG] sofia.c:5537 Remote SDP:
v=0
o=- 1167627590 1167627590 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 10.3.0.26
t=0 0
a=sendrecv
m=audio 2236 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000

2012-03-08 18:34:14.432937 [DEBUG] sofia_glue.c:4865 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-08 18:34:14.432937 [DEBUG] sofia_glue.c:2982 Set Codec sofia/internal/30 at 10.3.0.4 G722/8000 20 ms 160 samples 64000 bits
2012-03-08 18:34:14.432937 [DEBUG] switch_core_codec.c:111 sofia/internal/30 at 10.3.0.4 Original read codec set to G722:9
2012-03-08 18:34:14.432937 [DEBUG] sofia_glue.c:4986 Set 2833 dtmf send/recv payload to 127
2012-03-08 18:34:14.432937 [DEBUG] sofia.c:5749 (sofia/internal/30 at 10.3.0.4) State Change CS_NEW -> CS_INIT
2012-03-08 18:34:14.432937 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_INIT
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/30 at 10.3.0.4) State INIT
2012-03-08 18:34:14.432937 [DEBUG] mod_sofia.c:85 sofia/internal/30 at 10.3.0.4 SOFIA INIT
2012-03-08 18:34:14.432937 [DEBUG] mod_sofia.c:125 (sofia/internal/30 at 10.3.0.4) State Change CS_INIT -> CS_ROUTING
2012-03-08 18:34:14.432937 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/30 at 10.3.0.4) State INIT going to sleep
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_ROUTING
2012-03-08 18:34:14.432937 [DEBUG] switch_channel.c:1886 (sofia/internal/30 at 10.3.0.4) Callstate Change DOWN -> RINGING
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/30 at 10.3.0.4) State ROUTING
2012-03-08 18:34:14.432937 [DEBUG] mod_sofia.c:148 sofia/internal/30 at 10.3.0.4 SOFIA ROUTING
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:104 sofia/internal/30 at 10.3.0.4 Standard ROUTING
2012-03-08 18:34:14.432937 [INFO] mod_dialplan_xml.c:485 Processing B <30>->20 in context default
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->nxo_enable_chefsec] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [nxo_enable_chefsec] destination_number(20) =~ /^\*95(\d{0,7})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [group-intercept] destination_number(20) =~ /^\*82$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [intercept-ext] destination_number(20) =~ /^\*81(\d+)$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->nxo_single_intercom_with_two_way_audio] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [nxo_single_intercom_with_two_way_audio] destination_number(20) =~ /^\*01(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->nxo_group_intercom] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [nxo_group_intercom] destination_number(20) =~ /^\*02(\d{0,7})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->Outbound to PSTN 11 Digits] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [Outbound to PSTN 11 Digits] destination_number(20) =~ /^(1[2-9][0-9]{2}[2-9]{7})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->del-group] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [del-group] destination_number(20) =~ /^\*\*50(\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->add-group] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [add-group] destination_number(20) =~ /^\*\*51(\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [call-group-simo] destination_number(20) =~ /^\*52(\d{2,4})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [call-group-order] destination_number(20) =~ /^\*53(\d{2,4})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->nb_conferences] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [nb_conferences] destination_number(20) =~ /^\*(30\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->wb_conferences] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [wb_conferences] destination_number(20) =~ /^\*(31\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->uwb_conferences] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [uwb_conferences] destination_number(20) =~ /^\*(32\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [cdquality_conferences] destination_number(20) =~ /^\*(33\d{2})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->global_directory] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [global_directory] destination_number(20) =~ /^\*77(\d{1,3})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->redirect_now] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [redirect_now] destination_number(20) =~ /^\*21(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->redirect_timeout] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [redirect_timeout] destination_number(20) =~ /^\*22(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->redirect_busy] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [redirect_busy] destination_number(20) =~ /^\*23(\d{0,20})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->call_privacy] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [call_privacy] destination_number(20) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->call_privacy] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [call_privacy] destination_number(20) =~ /^\*60$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->send_to_voicemail] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [send_to_voicemail] destination_number(20) =~ /^\*99(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->vmain] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [vmain] destination_number(20) =~ /^vmain$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->vmain1] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [vmain1] destination_number(20) =~ /^vmain1$|^\*97$|^97$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->vmain2] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [vmain2] destination_number(20) =~ /^vmain2$|^\*98$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->redirect_now] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (FAIL) [redirect_now] destination_number(20) =~ /^\*35$/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 parsing [default->Local_Extension_test] continue=false
Dialplan: sofia/internal/30 at 10.3.0.4 Regex (PASS) [Local_Extension_test] destination_number(20) =~ /(^\d{2,7}$)/ break=on-false
Dialplan: sofia/internal/30 at 10.3.0.4 Action set(dialed_extension=20) 
Dialplan: sofia/internal/30 at 10.3.0.4 Action export(dialed_extension=20) 
Dialplan: sofia/internal/30 at 10.3.0.4 Action python(nxo_test) 
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/30 at 10.3.0.4) State Change CS_ROUTING -> CS_EXECUTE
2012-03-08 18:34:14.432937 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/30 at 10.3.0.4) State ROUTING going to sleep
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_EXECUTE
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/30 at 10.3.0.4) State EXECUTE
2012-03-08 18:34:14.432937 [DEBUG] mod_sofia.c:241 sofia/internal/30 at 10.3.0.4 SOFIA EXECUTE
2012-03-08 18:34:14.432937 [DEBUG] switch_core_state_machine.c:192 sofia/internal/30 at 10.3.0.4 Standard EXECUTE
EXECUTE sofia/internal/30 at 10.3.0.4 set(dialed_extension=20)
2012-03-08 18:34:14.432937 [DEBUG] mod_dptools.c:1281 sofia/internal/30 at 10.3.0.4 SET [dialed_extension]=[20]
EXECUTE sofia/internal/30 at 10.3.0.4 export(dialed_extension=20)
2012-03-08 18:34:14.432937 [DEBUG] switch_channel.c:1093 EXPORT (export_vars) [dialed_extension]=[20]
EXECUTE sofia/internal/30 at 10.3.0.4 python(nxo_test)
2012-03-08 18:34:14.452987 [NOTICE] mod_python.c:212 Invoking py module: nxo_test
2012-03-08 18:34:14.452987 [DEBUG] mod_python.c:281 Call python script 
2012-03-08 18:34:14.452987 [INFO] switch_cpp.cpp:1227 TEST: Destination-extension 20
send 1327 bytes to udp/[10.3.0.22]:5060 at 17:34:14.522894:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK51pyBX0p13a9H
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   CSeq: 185332679 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3310
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="514" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="20">sip:20 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1325 bytes to udp/[10.3.0.25]:5060 at 17:34:14.523907:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK6agQDrHtyc1UD
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   CSeq: 185332680 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3310
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="514" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="20">sip:20 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1337 bytes to udp/[10.3.0.27]:5060 at 17:34:14.524901:
   ------------------------------------------------------------------------
   NOTIFY sip:31 at 10.3.0.27 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK7K9FFK2XUNQeS
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   CSeq: 185332681 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3310
   Content-Type: application/dialog-info+xml
   Content-Length: 513

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="514" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:30 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="20">sip:20 at 10.3.0.4</identity>
   <target uri="sip:**30 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:14.530514:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK51pyBX0p13a9H
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   CSeq: 185332679 NOTIFY
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 417 bytes from udp/[10.3.0.27]:5060 at 17:34:14.530992:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK7K9FFK2XUNQeS
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   CSeq: 185332681 NOTIFY
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   Contact: <sip:31 at 10.3.0.27>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 405 bytes from udp/[10.3.0.25]:5060 at 17:34:14.531364:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK6agQDrHtyc1UD
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   CSeq: 185332680 NOTIFY
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
EXECUTE sofia/internal/30 at 10.3.0.4 set(continue_on_fail=true)
2012-03-08 18:34:14.952961 [DEBUG] mod_dptools.c:1281 sofia/internal/30 at 10.3.0.4 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/30 at 10.3.0.4 set(hangup_after_bridge=true)
2012-03-08 18:34:14.952961 [DEBUG] mod_dptools.c:1281 sofia/internal/30 at 10.3.0.4 SET [hangup_after_bridge]=[true]
2012-03-08 18:34:14.952961 [WARNING] switch_cpp.cpp:1227 TEST 1 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
EXECUTE sofia/internal/30 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:15.952932 [WARNING] switch_cpp.cpp:1227 TEST 2 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
EXECUTE sofia/internal/30 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:16.952933 [WARNING] switch_cpp.cpp:1227 TEST 3 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
EXECUTE sofia/internal/30 at 10.3.0.4 sleep(1000)
EXECUTE sofia/internal/30 at 10.3.0.4 info()
2012-03-08 18:34:17.952932 [INFO] mod_dptools.c:1439 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/30 at 10.3.0.4]
Unique-ID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Presence-ID: [30 at 10.3.0.4]
Channel-Call-UUID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Answer-State: [ringing]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Read-Codec-Bit-Rate: [64000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Channel-Write-Codec-Bit-Rate: [64000]
Caller-Direction: [inbound]
Caller-Username: [30]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [B]
Caller-Caller-ID-Number: [30]
Caller-Network-Addr: [10.3.0.26]
Caller-ANI: [30]
Caller-Destination-Number: [20]
Caller-Unique-ID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/30 at 10.3.0.4]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1331228054432937]
Caller-Channel-Created-Time: [1331228054432937]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
variable_session_id: [11]
variable_sip_local_network_addr: [10.3.0.4]
variable_sip_network_ip: [10.3.0.26]
variable_sip_network_port: [5060]
variable_sip_received_ip: [10.3.0.26]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_number_alias: [30]
variable_sip_auth_username: [30]
variable_sip_auth_realm: [10.3.0.4]
variable_number_alias: [30]
variable_user_name: [30]
variable_domain_name: [10.3.0.4]
variable_record_stereo: [true]
variable_default_gateway: [fonira]
variable_default_areacode: [01]
variable_transfer_fallback_extension: [operator]
variable_toll_allow: [local,domestic,international,vas]
variable_accountcode: [30]
variable_user_context: [default]
variable_effective_caller_id_name: [B]
variable_effective_caller_id_number: [30]
variable_outbound_caller_id_name: [B]
variable_outbound_caller_id_number: [1997156030]
variable_callgroup: [intercept]
variable_sip_from_user: [30]
variable_sip_from_uri: [30 at 10.3.0.4]
variable_sip_from_host: [10.3.0.4]
variable_sip_from_user_stripped: [30]
variable_sip_from_tag: [4AB6AEB9-5DA56A24]
variable_sofia_profile_name: [internal]
variable_sip_full_via: [SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F]
variable_sip_from_display: [B]
variable_sip_full_from: ["B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24]
variable_sip_full_to: [<sip:20 at 10.3.0.4;user=phone>]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [20]
variable_sip_req_port: [5060]
variable_sip_req_uri: [20 at 10.3.0.4:5060]
variable_sip_req_host: [10.3.0.4]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [20]
variable_sip_to_uri: [20 at 10.3.0.4]
variable_sip_to_host: [10.3.0.4]
variable_sip_contact_user: [30]
variable_sip_contact_uri: [30 at 10.3.0.26]
variable_sip_contact_host: [10.3.0.26]
variable_channel_name: [sofia/internal/30 at 10.3.0.4]
variable_sip_call_id: [da10f563-8c35d41e-ad0761b1 at 10.3.0.26]
variable_sip_user_agent: [PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933]
variable_sip_via_host: [10.3.0.26]
variable_max_forwards: [70]
variable_presence_id: [30 at 10.3.0.4]
variable_switch_r_sdp: [v=0
o=- 1167627590 1167627590 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 10.3.0.26
t=0 0
a=sendrecv
m=audio 2236 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
]
variable_remote_media_ip: [10.3.0.26]
variable_remote_media_port: [2236]
variable_sip_audio_recv_pt: [9]
variable_sip_use_codec_name: [G722]
variable_sip_use_codec_rate: [8000]
variable_sip_use_codec_ptime: [20]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_endpoint_disposition: [RECEIVED]
variable_DP_MATCH: [ARRAY::20|:20]
variable_call_uuid: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
variable_dialed_extension: [20]
variable_export_vars: [dialed_extension]
variable_continue_on_fail: [true]
variable_hangup_after_bridge: [true]
variable_current_application: [info]

EXECUTE sofia/internal/30 at 10.3.0.4 bridge([leg_timeout=15][origination_caller_id_number=30]user/20 at 10.3.0.4)
2012-03-08 18:34:17.972915 [DEBUG] switch_channel.c:1047 sofia/internal/30 at 10.3.0.4 EXPORTING[export_vars] [dialed_extension]=[20] to event
2012-03-08 18:34:17.972915 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables
2012-03-08 18:34:17.972915 [DEBUG] switch_ivr_originate.c:2299 Parsing session specific variables
2012-03-08 18:34:17.972915 [DEBUG] switch_event.c:1522 Parsing variable [leg_timeout]=[15]
2012-03-08 18:34:17.972915 [DEBUG] switch_event.c:1522 Parsing variable [origination_caller_id_number]=[30]
2012-03-08 18:34:17.972915 [DEBUG] switch_channel.c:1047 sofia/internal/30 at 10.3.0.4 EXPORTING[export_vars] [dialed_extension]=[20] to event
2012-03-08 18:34:17.972915 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables
2012-03-08 18:34:17.972915 [DEBUG] switch_event.c:1522 Parsing variable [presence_id]=[20 at 10.3.0.4]
2012-03-08 18:34:17.972915 [NOTICE] switch_channel.c:926 New Channel sofia/internal/sip:20 at 10.3.0.25 [ee9ed232-6944-11e1-a7dd-a55c2ebde3ff]
2012-03-08 18:34:17.972915 [DEBUG] mod_sofia.c:4673 (sofia/internal/sip:20 at 10.3.0.25) State Change CS_NEW -> CS_INIT
2012-03-08 18:34:17.972915 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:17.992947 [DEBUG] switch_ivr_originate.c:2561 sofia/internal/sip:20 at 10.3.0.25 Setting leg timeout to 15
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_INIT
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:20 at 10.3.0.25) State INIT
2012-03-08 18:34:17.992947 [DEBUG] mod_sofia.c:85 sofia/internal/sip:20 at 10.3.0.25 SOFIA INIT
2012-03-08 18:34:17.992947 [DEBUG] mod_sofia.c:125 (sofia/internal/sip:20 at 10.3.0.25) State Change CS_INIT -> CS_ROUTING
2012-03-08 18:34:17.992947 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/sip:20 at 10.3.0.25) State INIT going to sleep
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_ROUTING
2012-03-08 18:34:17.992947 [DEBUG] switch_channel.c:1886 (sofia/internal/sip:20 at 10.3.0.25) Callstate Change DOWN -> RINGING
send 1267 bytes to udp/[10.3.0.25]:5060 at 17:34:17.995749:
   ------------------------------------------------------------------------
   INVITE sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK8v28geK1ryD1m
   Max-Forwards: 69
   From: "B" <sip:30 at 10.3.0.4>;tag=g9t2j72Kc70UN
   To: <sip:20 at 10.3.0.25>
   Call-ID: c5fdcf90-e3e7-122f-41a2-00900b1be504
   CSeq: 25277964 INVITE
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 369
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "B" <sip:30 at 10.3.0.4>;party=calling;screen=yes;privacy=off

   v=0
   o=FreeSWITCH 1331211673 1331211674 IN IP4 10.3.0.4
   s=FreeSWITCH
   c=IN IP4 10.3.0.4
   t=0 0
   m=audio 16384 RTP/AVP 9 0 8 3 101 13
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   m=video 16422 RTP/AVP 98 99 100 34 31
   a=rtpmap:98 H264/90000
   a=rtpmap:99 H263-2000/90000
   a=rtpmap:100 H263-1998/90000
   a=rtpmap:34 H263/90000
   a=rtpmap:31 H261/90000
   ------------------------------------------------------------------------
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:20 at 10.3.0.25) State ROUTING
2012-03-08 18:34:17.992947 [DEBUG] mod_sofia.c:148 sofia/internal/sip:20 at 10.3.0.25 SOFIA ROUTING
2012-03-08 18:34:17.992947 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:20 at 10.3.0.25) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-03-08 18:34:17.992947 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/sip:20 at 10.3.0.25) State ROUTING going to sleep
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_CONSUME_MEDIA
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:20 at 10.3.0.25) State CONSUME_MEDIA
2012-03-08 18:34:17.992947 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:20 at 10.3.0.25) State CONSUME_MEDIA going to sleep
2012-03-08 18:34:17.992947 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:17.992947 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:20 at 10.3.0.25 entering state [calling][0]
recv 412 bytes from udp/[10.3.0.25]:5060 at 17:34:18.004636:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK8v28geK1ryD1m
   From: "B" <sip:30 at 10.3.0.4>;tag=g9t2j72Kc70UN
   To: "C" <sip:20 at 10.3.0.25>;tag=D3DA58FE-5FE1943D
   CSeq: 25277964 INVITE
   Call-ID: c5fdcf90-e3e7-122f-41a2-00900b1be504
   Contact: <sip:20 at 10.3.0.25>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1323 bytes to udp/[10.3.0.22]:5060 at 17:34:18.044978:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK95U1j934N73Kg
   Max-Forwards: 70
   From: <sip:20 at 10.3.0.4>;tag=nYGREnwV9Yw1
   To: "A" <sip:10 at 10.3.0.4>;tag=3AFAE503-964EC474
   Call-ID: 5e0bdbb0-b7399c09-c8206caa at 10.3.0.22
   CSeq: 185332682 NOTIFY
   Contact: <sip:20 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3307
   Content-Type: application/dialog-info+xml
   Content-Length: 509

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="248" state="partial" entity="sip:20 at 10.3.0.4">
   <dialog id="ee9ed232-6944-11e1-a7dd-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="20">sip:20 at 10.3.0.4</identity>
   <target uri="sip:20 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**20 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1330 bytes to udp/[10.3.0.26]:5060 at 17:34:18.048242:
   ------------------------------------------------------------------------
   NOTIFY sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKaFNtm4m8jgt6B
   Max-Forwards: 70
   From: <sip:20 at 10.3.0.4>;tag=eMGDLbL5kcdj
   To: "B" <sip:30 at 10.3.0.4>;tag=5D666AB7-2B76D012
   Call-ID: 467e0be4-bb0339a7-ce4d6682 at 10.3.0.26
   CSeq: 185332683 NOTIFY
   Contact: <sip:20 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3306
   Content-Type: application/dialog-info+xml
   Content-Length: 509

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="248" state="partial" entity="sip:20 at 10.3.0.4">
   <dialog id="ee9ed232-6944-11e1-a7dd-a55c2ebde3ff" direction="recipient">
   <state>early</state>
   <local>
   <identity display="20">sip:20 at 10.3.0.4</identity>
   <target uri="sip:20 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="30">sip:30 at 10.3.0.4</identity>
   <target uri="sip:**20 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:18.052291:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK95U1j934N73Kg
   From: <sip:20 at 10.3.0.4>;tag=nYGREnwV9Yw1
   To: "A" <sip:10 at 10.3.0.4>;tag=3AFAE503-964EC474
   CSeq: 185332682 NOTIFY
   Call-ID: 5e0bdbb0-b7399c09-c8206caa at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 414 bytes from udp/[10.3.0.26]:5060 at 17:34:18.053999:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKaFNtm4m8jgt6B
   From: <sip:20 at 10.3.0.4>;tag=eMGDLbL5kcdj
   To: "B" <sip:30 at 10.3.0.4>;tag=5D666AB7-2B76D012
   CSeq: 185332683 NOTIFY
   Call-ID: 467e0be4-bb0339a7-ce4d6682 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 449 bytes from udp/[10.3.0.25]:5060 at 17:34:18.060861:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK8v28geK1ryD1m
   From: "B" <sip:30 at 10.3.0.4>;tag=g9t2j72Kc70UN
   To: "C" <sip:20 at 10.3.0.25>;tag=D3DA58FE-5FE1943D
   CSeq: 25277964 INVITE
   Call-ID: c5fdcf90-e3e7-122f-41a2-00900b1be504
   Contact: <sip:20 at 10.3.0.25>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Allow-Events: talk,hold,conference
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:18.052945 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:18.052945 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:18.052945 [DEBUG] sofia.c:5526 Channel sofia/internal/sip:20 at 10.3.0.25 entering state [proceeding][180]
2012-03-08 18:34:18.052945 [NOTICE] sofia.c:5618 Ring-Ready sofia/internal/sip:20 at 10.3.0.25!
2012-03-08 18:34:18.052945 [NOTICE] mod_sofia.c:2514 Ring-Ready sofia/internal/30 at 10.3.0.4!
send 806 bytes to udp/[10.3.0.26]:5060 at 17:34:18.071638:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 2 INVITE
   Contact: <sip:20 at 10.3.0.4:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0
   Remote-Party-ID: "Outbound Call" <20>;party=calling;privacy=off;screen=no

   ------------------------------------------------------------------------
2012-03-08 18:34:18.052945 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:18.072922 [DEBUG] sofia.c:5526 Channel sofia/internal/30 at 10.3.0.4 entering state [early][180]
2012-03-08 18:34:18.072922 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:18.072922 [NOTICE] switch_ivr_originate.c:483 Ring Ready sofia/internal/30 at 10.3.0.4!
recv 625 bytes from udp/[10.3.0.26]:5060 at 17:34:20.691350:
   ------------------------------------------------------------------------
   REFER sip:mod_sofia at 10.3.0.4:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKb6a74a78C1F008DB
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   CSeq: 2 REFER
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Refer-To: <sip:20 at 10.3.0.4:5060;user=phone?Replaces=da10f563-8c35d41e-ad0761b1%4010.3.0.26%3Bto-tag%3DF019gcjgFya9S%3Bfrom-tag%3D4AB6AEB9-5DA56A24>
   Referred-By: <sip:30 at 10.3.0.4>
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.672931 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.692943 [DEBUG] sofia.c:6514 Process REFER to [20 at 10.3.0.4]
2012-03-08 18:34:20.692943 [DEBUG] sofia.c:6532 Replaces: [da10f563-8c35d41e-ad0761b1 at 10.3.0.26]
send 711 bytes to udp/[10.3.0.26]:5060 at 17:34:20.693751:
   ------------------------------------------------------------------------
   SIP/2.0 202 Accepted
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bKb6a74a78C1F008DB
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 2 REFER
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   Expires: 60
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.692943 [NOTICE] sofia.c:6615 Attended Transfer on originating session ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff
2012-03-08 18:34:20.692943 [DEBUG] switch_ivr.c:1711 (sofia/internal/10 at 10.3.0.4) State Change CS_EXECUTE -> CS_ROUTING
2012-03-08 18:34:20.692943 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.692943 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.692943 [NOTICE] switch_ivr.c:1717 Transfer sofia/internal/10 at 10.3.0.4 to inline[endless_playback:local_stream://moh,park@default]
send 851 bytes to udp/[10.3.0.26]:5060 at 17:34:20.695326:
   ------------------------------------------------------------------------
   NOTIFY sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKBreKpZ5BgSgSQ
   Max-Forwards: 70
   From: "A " <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 25277961 NOTIFY
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: refer;id=2
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: terminated;reason=noresource
   Content-Type: message/sipfrag;version=2.0
   Content-Length: 16

   SIP/2.0 200 OK
   ------------------------------------------------------------------------
send 645 bytes to udp/[10.3.0.26]:5060 at 17:34:20.696067:
   ------------------------------------------------------------------------
   BYE sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKc17BrtpFD26BK
   Max-Forwards: 70
   From: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   To: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 25277966 BYE
   Contact: <sip:20 at 10.3.0.4:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   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

   ------------------------------------------------------------------------
send 661 bytes to udp/[10.3.0.26]:5060 at 17:34:20.696525:
   ------------------------------------------------------------------------
   SIP/2.0 486 Busy Here
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 2 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Length: 0

   ------------------------------------------------------------------------
recv 428 bytes from udp/[10.3.0.26]:5060 at 17:34:20.703100:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKBreKpZ5BgSgSQ
   From: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   CSeq: 25277961 NOTIFY
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   Event: refer;id=2
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.692943 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
recv 440 bytes from udp/[10.3.0.26]:5060 at 17:34:20.705492:
   ------------------------------------------------------------------------
   BYE sip:mod_sofia at 10.3.0.4:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK415b2b56FCCA5AA9
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   CSeq: 3 BYE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   Contact: <sip:30 at 10.3.0.26>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.692943 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
recv 744 bytes from udp/[10.3.0.26]:5060 at 17:34:20.709331:
   ------------------------------------------------------------------------
   CANCEL sip:20 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>
   CSeq: 2 CANCEL
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Proxy-Authorization: Digest username="30", realm="10.3.0.4", nonce="ec7c3b52-6944-11e1-a7d4-a55c2ebde3ff", qop=auth, cnonce="XJz4HrL/160QNgt", nc=00000002, uri="sip:20 at 10.3.0.4:5060;user=phone", response="05c11ccdcec345f1fca83aa780770b28", algorithm=MD5
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
send 274 bytes to udp/[10.3.0.26]:5060 at 17:34:20.709881:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   CSeq: 2 CANCEL
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.712938 [DEBUG] switch_ivr_play_say.c:1678 done playing file local_stream://moh
2012-03-08 18:34:20.712938 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/internal/sip:30 at 10.3.0.26]
2012-03-08 18:34:20.712938 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_channel.c:2848 (sofia/internal/sip:30 at 10.3.0.26) Callstate Change HELD -> HANGUP
2012-03-08 18:34:20.712938 [NOTICE] switch_ivr_bridge.c:669 Hangup sofia/internal/sip:30 at 10.3.0.26 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2012-03-08 18:34:20.712938 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/sip:30 at 10.3.0.26 [KILL]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:420 (sofia/internal/sip:30 at 10.3.0.26) State EXCHANGE_MEDIA going to sleep
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_HANGUP
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_ivr_bridge.c:329 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:30 at 10.3.0.26) State HANGUP
2012-03-08 18:34:20.712938 [DEBUG] mod_sofia.c:469 Channel sofia/internal/sip:30 at 10.3.0.26 hanging up, cause: NORMAL_CLEARING
2012-03-08 18:34:20.712938 [DEBUG] mod_sofia.c:513 Sending BYE to sofia/internal/sip:30 at 10.3.0.26
send 622 bytes to udp/[10.3.0.26]:5060 at 17:34:20.724016:
   ------------------------------------------------------------------------
   BYE sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKDa14SN7jaBXye
   Max-Forwards: 70
   From: "A " <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 25277962 BYE
   Contact: <sip:mod_sofia at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   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

   ------------------------------------------------------------------------
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:47 sofia/internal/sip:30 at 10.3.0.26 Standard HANGUP, cause: NORMAL_CLEARING
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:30 at 10.3.0.26) State HANGUP going to sleep
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_HANGUP -> CS_REPORTING
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_REPORTING
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:30 at 10.3.0.26) State REPORTING
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:79 sofia/internal/sip:30 at 10.3.0.26 Standard REPORTING, cause: NORMAL_CLEARING
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:30 at 10.3.0.26) State REPORTING going to sleep
2012-03-08 18:34:20.712938 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/sip:30 at 10.3.0.26) State Change CS_REPORTING -> CS_DESTROY
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:1380 Session 10 (sofia/internal/sip:30 at 10.3.0.26) Locked, Waiting on external entities
recv 411 bytes from udp/[10.3.0.26]:5060 at 17:34:20.729848:
   ------------------------------------------------------------------------
   SIP/2.0 481 Call Leg/Transaction Does Not Exist
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKc17BrtpFD26BK
   From: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   To: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   CSeq: 25277966 BYE
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:875 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.712938 [DEBUG] sofia.c:5526 Channel sofia/internal/30 at 10.3.0.4 entering state [terminated][481]
2012-03-08 18:34:20.712938 [DEBUG] switch_channel.c:2848 (sofia/internal/30 at 10.3.0.4) Callstate Change RINGING -> HANGUP
2012-03-08 18:34:20.712938 [NOTICE] sofia.c:6293 Hangup sofia/internal/30 at 10.3.0.4 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2012-03-08 18:34:20.712938 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/30 at 10.3.0.4 [KILL]
2012-03-08 18:34:20.712938 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:20.732954 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/internal/10 at 10.3.0.4]
2012-03-08 18:34:20.732954 [DEBUG] switch_ivr_bridge.c:611 Send signal sofia/internal/sip:30 at 10.3.0.26 [BREAK]
2012-03-08 18:34:20.732954 [DEBUG] switch_core_session.c:729 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
recv 543 bytes from udp/[10.3.0.26]:5060 at 17:34:20.734163:
   ------------------------------------------------------------------------
   ACK sip:20 at 10.3.0.4:5060;user=phone SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F
   From: "B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24
   To: <sip:20 at 10.3.0.4;user=phone>;tag=F019gcjgFya9S
   CSeq: 2 ACK
   Call-ID: da10f563-8c35d41e-ad0761b1 at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Max-Forwards: 70
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:20.732954 [INFO] switch_cpp.cpp:1227 hangup hook for transfer!!

EXECUTE sofia/internal/10 at 10.3.0.4 info()
2012-03-08 18:34:20.732954 [NOTICE] switch_core_session.c:1398 Session 10 (sofia/internal/sip:30 at 10.3.0.26) Ended
2012-03-08 18:34:20.732954 [NOTICE] switch_core_session.c:1400 Close Channel sofia/internal/sip:30 at 10.3.0.26 [CS_DESTROY]
2012-03-08 18:34:20.732954 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/sip:30 at 10.3.0.26) Callstate Change HANGUP -> DOWN
2012-03-08 18:34:20.732954 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/sip:30 at 10.3.0.26) Running State Change CS_DESTROY
2012-03-08 18:34:20.732954 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:30 at 10.3.0.26) State DESTROY
2012-03-08 18:34:20.732954 [DEBUG] mod_sofia.c:374 sofia/internal/sip:30 at 10.3.0.26 SOFIA DESTROY
2012-03-08 18:34:20.732954 [DEBUG] switch_core_state_machine.c:86 sofia/internal/sip:30 at 10.3.0.26 Standard DESTROY
2012-03-08 18:34:20.732954 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:30 at 10.3.0.26) State DESTROY going to sleep
2012-03-08 18:34:20.732954 [INFO] mod_dptools.c:1439 CHANNEL_DATA:
Channel-State: [CS_ROUTING]
Channel-Call-State: [ACTIVE]
Channel-State-Number: [2]
Channel-Name: [sofia/internal/10 at 10.3.0.4]
Unique-ID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Presence-ID: [10 at 10.3.0.4]
Channel-Call-UUID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Answer-State: [answered]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Read-Codec-Bit-Rate: [64000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Channel-Write-Codec-Bit-Rate: [64000]
Caller-Direction: [inbound]
Caller-Username: [10]
Caller-Dialplan: [inline]
Caller-Caller-ID-Name: [A]
Caller-Caller-ID-Number: [10]
Caller-Callee-ID-Name: [Outbound Call]
Caller-Callee-ID-Number: [30]
Caller-Network-Addr: [10.3.0.22]
Caller-ANI: [10]
Caller-Destination-Number: [endless_playback:local_stream://moh,park]
Caller-Unique-ID: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
Caller-Source: [mod_sofia]
Caller-Transfer-Source: [1331228060:f03b71c2-6944-11e1-a7e1-a55c2ebde3ff:bl_xfer:endless_playback:local_stream://moh,park/default/inline]
Caller-Context: [default]
Caller-RDNIS: [30]
Caller-Channel-Name: [sofia/internal/10 at 10.3.0.4]
Caller-Profile-Index: [2]
Caller-Profile-Created-Time: [1331228060692943]
Caller-Channel-Created-Time: [1331228045612916]
Caller-Channel-Answered-Time: [1331228050212964]
Caller-Channel-Progress-Time: [1331228049352961]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
variable_session_id: [9]
variable_sip_local_network_addr: [10.3.0.4]
variable_sip_network_ip: [10.3.0.22]
variable_sip_network_port: [5060]
variable_sip_received_ip: [10.3.0.22]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_number_alias: [10]
variable_sip_auth_username: [10]
variable_sip_auth_realm: [10.3.0.4]
variable_number_alias: [10]
variable_user_name: [10]
variable_domain_name: [10.3.0.4]
variable_record_stereo: [true]
variable_default_gateway: [fonira]
variable_default_areacode: [01]
variable_transfer_fallback_extension: [operator]
variable_toll_allow: [local,domestic,international,vas]
variable_accountcode: [10]
variable_user_context: [default]
variable_effective_caller_id_name: [A ]
variable_effective_caller_id_number: [10]
variable_outbound_caller_id_name: [A ]
variable_outbound_caller_id_number: [1997156010]
variable_callgroup: [intercept]
variable_sip_from_user: [10]
variable_sip_from_uri: [10 at 10.3.0.4]
variable_sip_from_host: [10.3.0.4]
variable_sip_from_user_stripped: [10]
variable_sofia_profile_name: [internal]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [30]
variable_sip_req_port: [5060]
variable_sip_req_uri: [30 at 10.3.0.4:5060]
variable_sip_req_host: [10.3.0.4]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [30]
variable_sip_to_uri: [30 at 10.3.0.4]
variable_sip_to_host: [10.3.0.4]
variable_sip_contact_user: [10]
variable_sip_contact_uri: [10 at 10.3.0.22]
variable_sip_contact_host: [10.3.0.22]
variable_channel_name: [sofia/internal/10 at 10.3.0.4]
variable_sip_user_agent: [PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933]
variable_sip_via_host: [10.3.0.22]
variable_presence_id: [10 at 10.3.0.4]
variable_switch_r_sdp: [v=0
o=- 1167627581 1167627581 IN IP4 10.3.0.22
s=Polycom IP Phone
c=IN IP4 10.3.0.22
t=0 0
a=sendrecv
m=audio 2262 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
]
variable_sip_audio_recv_pt: [9]
variable_sip_use_codec_name: [G722]
variable_sip_use_codec_rate: [8000]
variable_sip_use_codec_ptime: [20]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_DP_MATCH: [ARRAY::30|:30]
variable_call_uuid: [e73f07fa-6944-11e1-a7c4-a55c2ebde3ff]
variable_dialed_extension: [30]
variable_export_vars: [dialed_extension]
variable_continue_on_fail: [true]
variable_hangup_after_bridge: [true]
variable_dialed_user: [30]
variable_dialed_domain: [10.3.0.4]
variable_sip_local_sdp_str: [v=0
o=FreeSWITCH 1331211630 1331211631 IN IP4 10.3.0.4
s=FreeSWITCH
c=IN IP4 10.3.0.4
t=0 0
m=audio 16420 RTP/AVP 9 127
a=rtpmap:9 G722/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
]
variable_local_media_ip: [10.3.0.4]
variable_local_media_port: [16420]
variable_advertised_media_ip: [10.3.0.4]
variable_sip_use_pt: [9]
variable_rtp_use_ssrc: [2056504069]
variable_sip_2833_send_payload: [127]
variable_sip_2833_recv_payload: [127]
variable_remote_media_ip: [10.3.0.22]
variable_remote_media_port: [2262]
variable_endpoint_disposition: [ANSWER]
variable_originate_disposition: [SUCCESS]
variable_DIALSTATUS: [SUCCESS]
variable_last_bridge_to: [e96bae48-6944-11e1-a7cc-a55c2ebde3ff]
variable_sip_to_tag: [c5NZBUZ5Q37gQ]
variable_sip_from_tag: [B0C14C18-E7DC6BB1]
variable_sip_cseq: [2]
variable_sip_call_id: [c64e932c-3eca2965-da54ee6 at 10.3.0.22]
variable_sip_full_via: [SIP/2.0/UDP 10.3.0.22;branch=z9hG4bKe8d47063D608BAD4]
variable_sip_from_display: [A]
variable_sip_full_from: ["A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1]
variable_sip_full_to: [<sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ]
variable_bridge_channel: [sofia/internal/sip:30 at 10.3.0.26]
variable_bridge_uuid: [e96bae48-6944-11e1-a7cc-a55c2ebde3ff]
variable_switch_m_sdp: [v=0
o=- 1167627586 1167627587 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 0.0.0.0
t=0 0
m=audio 2234 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=sendonly
m=video 0 RTP/AVP 98 99 100 34 31
a=rtpmap:98 H264/90000
a=rtpmap:99 H263-2000/90000
a=rtpmap:100 H263-1998/90000
a=rtpmap:34 H263/90000
a=rtpmap:31 H261/90000
]
variable_att_xfer_kill_uuid: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
variable_max_forwards: [69]
variable_transfer_history: [ARRAY::1331228060:f03b71c2-6944-11e1-a7e1-a55c2ebde3ff:bl_xfer:endless_playback:local_stream://moh,park/default/inline]
variable_transfer_source: [1331228060:f03b71c2-6944-11e1-a7e1-a55c2ebde3ff:bl_xfer:endless_playback:local_stream://moh,park/default/inline]
variable_playback_seconds: [16]
variable_playback_ms: [16720]
variable_playback_samples: [133760]
variable_bridge_hangup_cause: [NORMAL_CLEARING]
variable_current_application: [info]

2012-03-08 18:34:20.732954 [WARNING] switch_cpp.cpp:1227 TEST X for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
2012-03-08 18:34:20.732954 [WARNING] switch_cpp.cpp:1227 TEST: Originate Disposition after bridge is SUCCESS
2012-03-08 18:34:20.732954 [WARNING] switch_cpp.cpp:1227 TEST 4 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
recv 394 bytes from udp/[10.3.0.26]:5060 at 17:34:20.741808:
   ------------------------------------------------------------------------
   SIP/2.0 481 Call Leg/Transaction Does Not Exist
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKDa14SN7jaBXye
   From: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   To: <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   CSeq: 25277962 BYE
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 270 bytes to udp/[10.3.0.26]:5060 at 17:34:20.745132:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK415b2b56FCCA5AA9
   From: "B" <sip:30 at 10.3.0.26>;tag=7463F28A-2FFBD77D
   To: "A" <sip:10 at 10.3.0.4>;tag=DeFrDpg9mcy3j
   Call-ID: c0caa6b7-e3e7-122f-41a2-00900b1be504
   CSeq: 3 BYE
   Content-Length: 0

   ------------------------------------------------------------------------
send 1070 bytes to udp/[10.3.0.25]:5060 at 17:34:20.776577:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKeKtXUgrp7KKHa
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   CSeq: 185332684 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3304
   Content-Type: application/dialog-info+xml
   Content-Length: 258

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="515" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>terminated</state>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1082 bytes to udp/[10.3.0.27]:5060 at 17:34:20.780085:
   ------------------------------------------------------------------------
   NOTIFY sip:31 at 10.3.0.27 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKFvKpXB9S4v93N
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   CSeq: 185332685 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3304
   Content-Type: application/dialog-info+xml
   Content-Length: 258

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="515" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>terminated</state>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 405 bytes from udp/[10.3.0.25]:5060 at 17:34:20.783041:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKeKtXUgrp7KKHa
   From: <sip:30 at 10.3.0.4>;tag=zVD97bWqz9Ei
   To: "C" <sip:20 at 10.3.0.4>;tag=E729C66F-499D331E
   CSeq: 185332684 NOTIFY
   Call-ID: 6e8428e-4012accd-98b6429c at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
send 1072 bytes to udp/[10.3.0.22]:5060 at 17:34:20.783873:
   ------------------------------------------------------------------------
   NOTIFY sip:10 at 10.3.0.22 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKg5cFZ6SX15ZpH
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   CSeq: 185332686 NOTIFY
   Contact: <sip:30 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=3304
   Content-Type: application/dialog-info+xml
   Content-Length: 258

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="515" state="partial" entity="sip:30 at 10.3.0.4">
   <dialog id="e96bae48-6944-11e1-a7cc-a55c2ebde3ff" direction="recipient">
   <state>terminated</state>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 417 bytes from udp/[10.3.0.27]:5060 at 17:34:20.787412:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKFvKpXB9S4v93N
   From: <sip:30 at 10.3.0.4>;tag=j2FaQyd4KlIW
   To: "Patrick  SXXXXXXl" <sip:31 at 10.3.0.4>;tag=26B3115D-24F8F110
   CSeq: 185332685 NOTIFY
   Call-ID: 11c82624-cdfad25f-e9f5882 at 10.3.0.27
   Contact: <sip:31 at 10.3.0.27>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 407 bytes from udp/[10.3.0.22]:5060 at 17:34:20.790635:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKg5cFZ6SX15ZpH
   From: <sip:30 at 10.3.0.4>;tag=BL1yX2TI1X2c
   To: "A" <sip:10 at 10.3.0.4>;tag=7B5DFEAE-48CDC3F7
   CSeq: 185332686 NOTIFY
   Call-ID: ef7cb8bd-dc381cfe-bf64ccc7 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:21.732935 [WARNING] switch_cpp.cpp:1227 TEST 5 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:22.732931 [WARNING] switch_cpp.cpp:1227 TEST 6 for UUID e73f07fa-6944-11e1-a7c4-a55c2ebde3ff, src 10 dest 30
EXECUTE sofia/internal/10 at 10.3.0.4 sleep(1000)
2012-03-08 18:34:23.732934 [DEBUG] mod_python.c:284 Finished calling python script 
2012-03-08 18:34:23.732934 [DEBUG] switch_cpp.cpp:1007 sofia/internal/10 at 10.3.0.4 destroy/unlink session from object
2012-03-08 18:34:23.732934 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE going to sleep
2012-03-08 18:34:23.732934 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_ROUTING
2012-03-08 18:34:23.732934 [DEBUG] switch_channel.c:1886 (sofia/internal/10 at 10.3.0.4) Callstate Change ACTIVE -> RINGING
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/10 at 10.3.0.4) State ROUTING
2012-03-08 18:34:23.753118 [DEBUG] mod_sofia.c:148 sofia/internal/10 at 10.3.0.4 SOFIA ROUTING
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:104 sofia/internal/10 at 10.3.0.4 Standard ROUTING
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/10 at 10.3.0.4) State Change CS_ROUTING -> CS_EXECUTE
2012-03-08 18:34:23.753118 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/10 at 10.3.0.4) State ROUTING going to sleep
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_EXECUTE
2012-03-08 18:34:23.753118 [DEBUG] switch_channel.c:1888 (sofia/internal/10 at 10.3.0.4) Callstate Change RINGING -> ACTIVE
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE
2012-03-08 18:34:23.753118 [DEBUG] mod_sofia.c:241 sofia/internal/10 at 10.3.0.4 SOFIA EXECUTE
2012-03-08 18:34:23.753118 [DEBUG] switch_core_state_machine.c:192 sofia/internal/10 at 10.3.0.4 Standard EXECUTE
EXECUTE sofia/internal/10 at 10.3.0.4 endless_playback(local_stream://moh)
2012-03-08 18:34:23.753118 [DEBUG] mod_local_stream.c:421 Opening Stream [moh/16000] 16000hz
2012-03-08 18:34:23.753118 [DEBUG] switch_ivr_play_say.c:1306 Codec Activated L16 at 16000hz 1 channels 20ms
send 1402 bytes to udp/[10.3.0.25]:5060 at 17:34:23.860078:
   ------------------------------------------------------------------------
   NOTIFY sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKHe6701a1yep9c
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   CSeq: 185332687 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1138
   Content-Type: application/dialog-info+xml
   Content-Length: 589

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="405" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="endless_playback:local_stream://moh,park">sip:endless_playback:local_stream://moh,park@10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
send 1410 bytes to udp/[10.3.0.26]:5060 at 17:34:23.862933:
   ------------------------------------------------------------------------
   NOTIFY sip:30 at 10.3.0.26 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKjQZ02vU4UQcvr
   Max-Forwards: 70
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   CSeq: 185332688 NOTIFY
   Contact: <sip:10 at 10.3.0.4:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, precondition, path, replaces
   Event: dialog
   Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Subscription-State: active;expires=1138
   Content-Type: application/dialog-info+xml
   Content-Length: 589

   <?xml version="1.0"?>
   <dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="405" state="partial" entity="sip:10 at 10.3.0.4">
   <dialog id="e73f07fa-6944-11e1-a7c4-a55c2ebde3ff" direction="initiator">
   <state>confirmed</state>
   <local>
   <identity display="10">sip:10 at 10.3.0.4</identity>
   <target uri="sip:10 at 10.3.0.4">
   <param pname="+sip.rendering" pvalue="yes"/>
   </target>
   </local>
   <remote>
   <identity display="endless_playback:local_stream://moh,park">sip:endless_playback:local_stream://moh,park@10.3.0.4</identity>
   <target uri="sip:**10 at 10.3.0.4"/>
   </remote>
   </dialog>
   </dialog-info>
   ------------------------------------------------------------------------
recv 406 bytes from udp/[10.3.0.25]:5060 at 17:34:23.867468:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKHe6701a1yep9c
   From: <sip:10 at 10.3.0.4>;tag=JElIsHAUjri7
   To: "C" <sip:20 at 10.3.0.4>;tag=432C4A25-2C483674
   CSeq: 185332687 NOTIFY
   Call-ID: a941c408-2c54f3a7-82c5a8d6 at 10.3.0.25
   Contact: <sip:20 at 10.3.0.25>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
recv 414 bytes from udp/[10.3.0.26]:5060 at 17:34:23.870281:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKjQZ02vU4UQcvr
   From: <sip:10 at 10.3.0.4>;tag=hzYaAHIZscZq
   To: "B" <sip:30 at 10.3.0.4>;tag=A52D4836-AD38FE89
   CSeq: 185332688 NOTIFY
   Call-ID: 3f77033d-f3b24ec8-f0479fab at 10.3.0.26
   Contact: <sip:30 at 10.3.0.26>
   Event: dialog
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:32.012932 [DEBUG] switch_channel.c:2598 (sofia/internal/10 at 10.3.0.4) State Change CS_EXECUTE -> CS_RESET
2012-03-08 18:34:32.012932 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.032936 [DEBUG] switch_ivr_play_say.c:1678 done playing file local_stream://moh
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_RESET
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:413 (sofia/internal/10 at 10.3.0.4) State RESET
2012-03-08 18:34:32.032936 [DEBUG] switch_channel.c:2600 (sofia/internal/10 at 10.3.0.4) State Change CS_RESET -> CS_EXECUTE
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:166 sofia/internal/10 at 10.3.0.4 SOFIA RESET
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.032936 [DEBUG] switch_channel.c:2848 (sofia/internal/sip:20 at 10.3.0.25) Callstate Change RINGING -> HANGUP
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:413 (sofia/internal/10 at 10.3.0.4) State RESET going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_EXECUTE
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:241 sofia/internal/10 at 10.3.0.4 SOFIA EXECUTE
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:192 sofia/internal/10 at 10.3.0.4 Standard EXECUTE
2012-03-08 18:34:32.032936 [NOTICE] switch_ivr_originate.c:3075 Hangup sofia/internal/sip:20 at 10.3.0.25 [CS_CONSUME_MEDIA] [ATTENDED_TRANSFER]
2012-03-08 18:34:32.032936 [NOTICE] switch_core_state_machine.c:226 sofia/internal/10 at 10.3.0.4 has executed the last dialplan instruction, hanging up.
2012-03-08 18:34:32.032936 [DEBUG] switch_channel.c:2848 (sofia/internal/10 at 10.3.0.4) Callstate Change ACTIVE -> HANGUP
2012-03-08 18:34:32.032936 [NOTICE] switch_core_state_machine.c:228 Hangup sofia/internal/10 at 10.3.0.4 [CS_EXECUTE] [NORMAL_CLEARING]
2012-03-08 18:34:32.032936 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/sip:20 at 10.3.0.25 [KILL]
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:32.032936 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [ATTENDED_TRANSFER]
2012-03-08 18:34:32.032936 [DEBUG] switch_ivr_originate.c:3364 Originate Resulted in Error Cause: 601 [ATTENDED_TRANSFER]
2012-03-08 18:34:32.032936 [INFO] mod_dptools.c:2922 Originate Failed.  Cause: ATTENDED_TRANSFER
2012-03-08 18:34:32.032936 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/10 at 10.3.0.4 [KILL]
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/10 at 10.3.0.4) State EXECUTE going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_HANGUP
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2285 sofia/internal/30 at 10.3.0.4 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-03-08 18:34:32.032936 [INFO] switch_cpp.cpp:1227 hangup hook for hangup!!

2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2095 sofia/internal/30 at 10.3.0.4 ZOMBIE EXEC info()
EXECUTE sofia/internal/30 at 10.3.0.4 info()
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2271 sofia/internal/30 at 10.3.0.4 skip receive message [APPLICATION_EXEC] (channel is hungup already)
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/10 at 10.3.0.4) State HANGUP
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:469 Channel sofia/internal/10 at 10.3.0.4 hanging up, cause: NORMAL_CLEARING
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_HANGUP
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:20 at 10.3.0.25) State HANGUP
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:469 Channel sofia/internal/sip:20 at 10.3.0.25 hanging up, cause: ATTENDED_TRANSFER
2012-03-08 18:34:32.032936 [INFO] mod_dptools.c:1439 CHANNEL_DATA:
Channel-State: [CS_HANGUP]
Channel-Call-State: [HANGUP]
Channel-State-Number: [10]
Channel-Name: [sofia/internal/30 at 10.3.0.4]
Unique-ID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Presence-ID: [30 at 10.3.0.4]
Channel-Call-UUID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Answer-State: [hangup]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Read-Codec-Bit-Rate: [64000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Channel-Write-Codec-Bit-Rate: [64000]
Caller-Direction: [inbound]
Caller-Username: [30]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [B]
Caller-Caller-ID-Number: [30]
Caller-Callee-ID-Name: [Outbound Call]
Caller-Callee-ID-Number: [20]
Caller-Network-Addr: [10.3.0.26]
Caller-ANI: [30]
Caller-Destination-Number: [20]
Caller-Unique-ID: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/30 at 10.3.0.4]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1331228054432937]
Caller-Channel-Created-Time: [1331228054432937]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [1331228058052945]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
variable_session_id: [11]
variable_sip_local_network_addr: [10.3.0.4]
variable_sip_network_ip: [10.3.0.26]
variable_sip_network_port: [5060]
variable_sip_received_ip: [10.3.0.26]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_number_alias: [30]
variable_sip_auth_username: [30]
variable_sip_auth_realm: [10.3.0.4]
variable_number_alias: [30]
variable_user_name: [30]
variable_domain_name: [10.3.0.4]
variable_record_stereo: [true]
variable_default_gateway: [fonira]
variable_default_areacode: [01]
variable_transfer_fallback_extension: [operator]
variable_toll_allow: [local,domestic,international,vas]
variable_accountcode: [30]
variable_user_context: [default]
variable_effective_caller_id_name: [B]
variable_effective_caller_id_number: [30]
variable_outbound_caller_id_name: [B]
variable_outbound_caller_id_number: [1997156030]
variable_callgroup: [intercept]
variable_sip_from_user: [30]
variable_sip_from_uri: [30 at 10.3.0.4]
variable_sip_from_host: [10.3.0.4]
variable_sip_from_user_stripped: [30]
variable_sip_from_tag: [4AB6AEB9-5DA56A24]
variable_sofia_profile_name: [internal]
variable_sip_full_via: [SIP/2.0/UDP 10.3.0.26;branch=z9hG4bK909bdcdc8659BA5F]
variable_sip_from_display: [B]
variable_sip_full_from: ["B" <sip:30 at 10.3.0.4>;tag=4AB6AEB9-5DA56A24]
variable_sip_full_to: [<sip:20 at 10.3.0.4;user=phone>]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [20]
variable_sip_req_port: [5060]
variable_sip_req_uri: [20 at 10.3.0.4:5060]
variable_sip_req_host: [10.3.0.4]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [20]
variable_sip_to_uri: [20 at 10.3.0.4]
variable_sip_to_host: [10.3.0.4]
variable_sip_contact_user: [30]
variable_sip_contact_uri: [30 at 10.3.0.26]
variable_sip_contact_host: [10.3.0.26]
variable_channel_name: [sofia/internal/30 at 10.3.0.4]
variable_sip_call_id: [da10f563-8c35d41e-ad0761b1 at 10.3.0.26]
variable_sip_user_agent: [PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933]
variable_sip_via_host: [10.3.0.26]
variable_max_forwards: [70]
variable_presence_id: [30 at 10.3.0.4]
variable_switch_r_sdp: [v=0
o=- 1167627590 1167627590 IN IP4 10.3.0.26
s=Polycom IP Phone
c=IN IP4 10.3.0.26
t=0 0
a=sendrecv
m=audio 2236 RTP/AVP 9 0 8 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
]
variable_remote_media_ip: [10.3.0.26]
variable_remote_media_port: [2236]
variable_sip_audio_recv_pt: [9]
variable_sip_use_codec_name: [G722]
variable_sip_use_codec_rate: [8000]
variable_sip_use_codec_ptime: [20]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_DP_MATCH: [ARRAY::20|:20]
variable_call_uuid: [ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff]
variable_dialed_extension: [20]
variable_export_vars: [dialed_extension]
variable_continue_on_fail: [true]
variable_hangup_after_bridge: [true]
variable_dialed_user: [20]
variable_dialed_domain: [10.3.0.4]
variable_endpoint_disposition: [ATTENDED_TRANSFER]
variable_sip_term_status: [481]
variable_proto_specific_hangup_cause: [sip:481]
variable_sip_term_cause: [41]
variable_originate_disposition: [ATTENDED_TRANSFER]
variable_DIALSTATUS: [ATTENDED_TRANSFER]
variable_current_application: [info]

2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2285 sofia/internal/30 at 10.3.0.4 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-03-08 18:34:32.032936 [WARNING] switch_cpp.cpp:1227 TEST X for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
2012-03-08 18:34:32.032936 [WARNING] switch_cpp.cpp:1227 TEST: Originate Disposition after bridge is ATTENDED_TRANSFER
2012-03-08 18:34:32.032936 [WARNING] switch_cpp.cpp:1227 TEST 4 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2100 sofia/internal/30 at 10.3.0.4 Channel is hungup and application 'sleep' does not have the zombie_exec flag.
2012-03-08 18:34:32.032936 [WARNING] switch_cpp.cpp:1227 TEST 5 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2100 sofia/internal/30 at 10.3.0.4 Channel is hungup and application 'sleep' does not have the zombie_exec flag.
2012-03-08 18:34:32.032936 [WARNING] switch_cpp.cpp:1227 TEST 6 for UUID ec80d1f8-6944-11e1-a7d5-a55c2ebde3ff, src 30 dest 20
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2100 sofia/internal/30 at 10.3.0.4 Channel is hungup and application 'sleep' does not have the zombie_exec flag.
2012-03-08 18:34:32.032936 [DEBUG] mod_python.c:284 Finished calling python script 
2012-03-08 18:34:32.032936 [DEBUG] switch_cpp.cpp:1007 sofia/internal/30 at 10.3.0.4 destroy/unlink session from object
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:2285 sofia/internal/30 at 10.3.0.4 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/30 at 10.3.0.4) State EXECUTE going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_HANGUP
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/30 at 10.3.0.4) State HANGUP
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:469 Channel sofia/internal/30 at 10.3.0.4 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:513 Sending BYE to sofia/internal/10 at 10.3.0.4
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:47 sofia/internal/10 at 10.3.0.4 Standard HANGUP, cause: NORMAL_CLEARING
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/10 at 10.3.0.4) State HANGUP going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/10 at 10.3.0.4) State Change CS_HANGUP -> CS_REPORTING
send 637 bytes to udp/[10.3.0.22]:5060 at 17:34:32.048986:
   ------------------------------------------------------------------------
   BYE sip:10 at 10.3.0.22 SIP/2.02012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]

   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKK0rS4Qc8r02em
   Max-Forwards: 70
   From: <sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ
   To: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB12012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/10 at 10.3.0.4) Running State Change CS_REPORTING

   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   CSeq: 25277972 BYE
   Contact: <sip:30 at 10.3.0.4:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-fbe4e64 2012-02-22 23-08-19 -0600
   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

   ------------------------------------------------------------------------
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/10 at 10.3.0.4) State REPORTING
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:79 sofia/internal/10 at 10.3.0.4 Standard REPORTING, cause: NORMAL_CLEARING
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/10 at 10.3.0.4) State REPORTING going to sleep
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/10 at 10.3.0.4) State Change CS_REPORTING -> CS_DESTROY
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/10 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.032936 [DEBUG] switch_core_session.c:1380 Session 9 (sofia/internal/10 at 10.3.0.4) Locked, Waiting on external entities
2012-03-08 18:34:32.032936 [NOTICE] switch_core_session.c:1398 Session 9 (sofia/internal/10 at 10.3.0.4) Ended
2012-03-08 18:34:32.032936 [NOTICE] switch_core_session.c:1400 Close Channel sofia/internal/10 at 10.3.0.4 [CS_DESTROY]
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/10 at 10.3.0.4) Callstate Change HANGUP -> DOWN
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/10 at 10.3.0.4) Running State Change CS_DESTROY
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/10 at 10.3.0.4) State DESTROY
2012-03-08 18:34:32.032936 [DEBUG] mod_sofia.c:374 sofia/internal/10 at 10.3.0.4 SOFIA DESTROY
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:86 sofia/internal/10 at 10.3.0.4 Standard DESTROY
2012-03-08 18:34:32.032936 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/10 at 10.3.0.4) State DESTROY going to sleep
recv 399 bytes from udp/[10.3.0.22]:5060 at 17:34:32.055973:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bKK0rS4Qc8r02em
   From: <sip:30 at 10.3.0.4;user=phone>;tag=c5NZBUZ5Q37gQ
   To: "A" <sip:10 at 10.3.0.4>;tag=B0C14C18-E7DC6BB1
   CSeq: 25277972 BYE
   Call-ID: c64e932c-3eca2965-da54ee6 at 10.3.0.22
   Contact: <sip:10 at 10.3.0.22>2012-03-08 18:34:32.052952 [DEBUG] mod_sofia.c:523 Sending CANCEL to sofia/internal/sip:20 at 10.3.0.25

   User-Agent: PolycomSoundPointIP-SPIP_670-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:47 sofia/internal/sip:20 at 10.3.0.25 Standard HANGUP, cause: ATTENDED_TRANSFER
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/sip:20 at 10.3.0.25) State HANGUP going to sleep
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/sip:20 at 10.3.0.25) State Change CS_HANGUP -> CS_REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:20 at 10.3.0.25) State REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:79 sofia/internal/sip:20 at 10.3.0.25 Standard REPORTING, cause: ATTENDED_TRANSFER
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sip:20 at 10.3.0.25) State REPORTING going to sleep
send 341 bytes to udp/[10.3.0.25]:5060 at 17:34:32.056855:
   ------------------------------------------------------------------------
   CANCEL sip:20 at 10.3.0.25 SIP/2.0
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK8v28geK1ryD1m
   Max-Forwards: 69
   From: "B" <sip:30 at 10.3.0.4>;tag=g9t2j72Kc70UN
   To: <sip:20 at 10.3.0.25>
   Call-ID: c5fdcf90-e3e7-122f-41a2-00900b1be504
   CSeq: 25277964 CANCEL
   Reason: FreeSWITCH;cause=601;text="ATTENDED_TRANSFER"
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/sip:20 at 10.3.0.25) State Change CS_REPORTING -> CS_DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/sip:20 at 10.3.0.25 [BREAK]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1380 Session 12 (sofia/internal/sip:20 at 10.3.0.25) Locked, Waiting on external entities
2012-03-08 18:34:32.052952 [NOTICE] switch_core_session.c:1398 Session 12 (sofia/internal/sip:20 at 10.3.0.25) Ended
2012-03-08 18:34:32.052952 [NOTICE] switch_core_session.c:1400 Close Channel sofia/internal/sip:20 at 10.3.0.25 [CS_DESTROY]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/sip:20 at 10.3.0.25) Callstate Change HANGUP -> DOWN
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/sip:20 at 10.3.0.25) Running State Change CS_DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:20 at 10.3.0.25) State DESTROY
2012-03-08 18:34:32.052952 [DEBUG] mod_sofia.c:374 sofia/internal/sip:20 at 10.3.0.25 SOFIA DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:86 sofia/internal/sip:20 at 10.3.0.25 Standard DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/sip:20 at 10.3.0.25) State DESTROY going to sleep
recv 386 bytes from udp/[10.3.0.25]:5060 at 17:34:32.061492:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.3.0.4;rport;branch=z9hG4bK8v28geK1ryD1m
   From: "B" <sip:30 at 10.3.0.4>;tag=g9t2j72Kc70UN
   To: "C" <sip:20 at 10.3.0.25>
   CSeq: 25277964 CANCEL
   Call-ID: c5fdcf90-e3e7-122f-41a2-00900b1be504
   Contact: <sip:20 at 10.3.0.25>
   User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.1.0933
   Accept-Language: de-de,de;q=0.9,en;q=0.8
   Content-Length: 0

   ------------------------------------------------------------------------
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:47 sofia/internal/30 at 10.3.0.4 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/30 at 10.3.0.4) State HANGUP going to sleep
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/30 at 10.3.0.4) State Change CS_HANGUP -> CS_REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/30 at 10.3.0.4) Running State Change CS_REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/30 at 10.3.0.4) State REPORTING
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:79 sofia/internal/30 at 10.3.0.4 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/30 at 10.3.0.4) State REPORTING going to sleep
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/30 at 10.3.0.4) State Change CS_REPORTING -> CS_DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1180 Send signal sofia/internal/30 at 10.3.0.4 [BREAK]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_session.c:1380 Session 11 (sofia/internal/30 at 10.3.0.4) Locked, Waiting on external entities
2012-03-08 18:34:32.052952 [NOTICE] switch_core_session.c:1398 Session 11 (sofia/internal/30 at 10.3.0.4) Ended
2012-03-08 18:34:32.052952 [NOTICE] switch_core_session.c:1400 Close Channel sofia/internal/30 at 10.3.0.4 [CS_DESTROY]
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/30 at 10.3.0.4) Callstate Change HANGUP -> DOWN
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/30 at 10.3.0.4) Running State Change CS_DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/30 at 10.3.0.4) State DESTROY
2012-03-08 18:34:32.052952 [DEBUG] mod_sofia.c:374 sofia/internal/30 at 10.3.0.4 SOFIA DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:86 sofia/internal/30 at 10.3.0.4 Standard DESTROY
2012-03-08 18:34:32.052952 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/30 at 10.3.0.4) State DESTROY going to sleep
-------------- next part --------------
import os
import re
import sys
from freeswitch import *
import logging,sys

_REVISION_ = "$Revision: 1891 $"

# HANGUP HOOK
#
# session is a session object
# what is "hangup" or "transfer"
# if you pass an extra arg to setInputCallback then append 'arg' to get that value
# def hangup_hook(session, what, arg):
def hangup_hook(session, what):

	consoleLog("INFO", "hangup hook for %s!!\n\n" % what)
	return

# INPUT CALLBACK
#
# session is a session object
# what is "dtmf" or "event"
# obj is a dtmf object or an event object depending on the 'what' var.
# if you pass an extra arg to setInputCallback then append 'arg' to get that value
# def input_callback(session, what, obj, arg):
def input_callback(session, what, obj):
	if (what == "dtmf"):
		consoleLog("INFO", what + " " + obj.digit + "\n")
	else:
		consoleLog("INFO", what + " " + obj.serialize() + "\n")		
	return "pause"

# APPLICATION
#
# default name for apps is "handler" it can be overridden with <modname>::<function>
# session is a session object
# args is all the args passed after the module name

def handler(session, args):
#    try:
    session.setHangupHook(hangup_hook)
    session.setInputCallback(input_callback)

    destination_extension = int(session.getVariable("dialed_extension"))
    caller_number = session.getVariable("caller_id_number")
    domain = session.getVariable("domain_name")
    consoleLog("INFO", "TEST: Destination-extension "+str(destination_extension)+"\n")

    session.execute("set","continue_on_fail=true")
    session.execute("set","hangup_after_bridge=true")

    uuid = session.getVariable("uuid")
    consoleLog("WARNING", "TEST 1 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")
    consoleLog("WARNING", "TEST 2 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")
    consoleLog("WARNING", "TEST 3 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")
    session.execute('info')
    session.execute("bridge","[leg_timeout=%s][origination_caller_id_number=%s]user/%s@${domain_name}" % ('15',str(caller_number), str(destination_extension)))
    session.execute('info')
    originate_disposition = session.getVariable("originate_disposition")
    consoleLog("WARNING", "TEST X for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    consoleLog("WARNING", "TEST: Originate Disposition after bridge is "+str(originate_disposition)+"\n")
    #if originate_disposition == "PICKED_OFF" or originate_disposition == "ORIGINATOR_CANCEL" or\
    #    originate_disposition == "SUCCESS": #or originate_disposition == 'ATTENDED_TRANSFER' or \
    #    #originate_disposition == 'BLIND_TRANSFER':
    #    consoleLog("WARNING", "Sending call to park\n")
    #    session.execute("park")
    #else:
    consoleLog("WARNING", "TEST 4 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")
    consoleLog("WARNING", "TEST 5 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")
    consoleLog("WARNING", "TEST 6 for UUID "+str(uuid)+", src "+str(caller_number)+" dest "+str(destination_extension)+"\n")
    session.execute("sleep","1000")

# FSAPI CALL FROM CLI, DP HTTP etc
#
# default name for python FSAPI is "fsapi" it can be overridden with <modname>::<function>
# stream is a switch_stream, anything written with stream.write() is returned to the caller
# env is a switch_event
# args is all the args passed after the module name
# session is a session object when called from the dial plan or the string "na" when not.
def fsapi(session, stream, env, args):

	stream.write("w00t!\n" + env.serialize())

# RUN A FUNCTION IN A THREAD
#
# default name for pyrun is "runtime" it can be overridden with <modname>::<function>
# args is all the args passed after the module name
def runtime(args):

	print args + "\n"