/* call recovered */

2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:941 New Channel sofia/internal/3606@10.1.3.50 [6a8db0f1-d26d-49a9-9498-093ec5174aae]
2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:939 Rename Channel sofia/internal/3606@10.1.3.50->sofia/internal/3606@10.1.3.50 [6a8db0f1-d26d-49a9-9498-093ec5174aae]
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/3606@10.1.3.50 PCMU/8000 20 ms 160 samples 64000 bits
2012-10-31 09:19:22.639229 [DEBUG] switch_core_codec.c:111 sofia/internal/3606@10.1.3.50 Original read codec set to PCMU:0
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/3606@10.1.3.50] 10.1.3.50 port 17242 -> 10.1.45.149 port 4000 codec: 0 ms: 20
2012-10-31 09:19:22.639229 [DEBUG] switch_rtp.c:1935 Not using a timer
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3573 sofia/internal/3606@10.1.3.50 Set rtp dtmf delay to 40
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3579 Set comfort noise payload to 13
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:5965 (sofia/internal/3606@10.1.3.50) State Change CS_NEW -> CS_INIT
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3606@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [NOTICE] sofia_glue.c:5966 Resurrecting fallen channel sofia/internal/3606@10.1.3.50


2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:941 New Channel sofia/internal/3429@10.1.3.50 [b2da4eae-c696-434d-89ee-5ebcd978a668]
2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:939 Rename Channel sofia/internal/3429@10.1.3.50->sofia/internal/3429@10.1.3.50 [b2da4eae-c696-434d-89ee-5ebcd978a668]
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/3429@10.1.3.50 PCMU/8000 20 ms 160 samples 64000 bits
2012-10-31 09:19:22.639229 [DEBUG] switch_core_codec.c:111 sofia/internal/3429@10.1.3.50 Original read codec set to PCMU:0
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3606@10.1.3.50) Running State Change CS_INIT
2012-10-31 09:19:22.639229 [DEBUG] switch_channel.c:1936 (sofia/internal/3606@10.1.3.50) Callstate Change DOWN -> ACTIVE
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3606@10.1.3.50) State INIT
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/3429@10.1.3.50] 10.1.3.50 port 25200 -> 10.1.45.148 port 4000 codec: 0 ms: 20
2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:85 sofia/internal/3606@10.1.3.50 SOFIA INIT
2012-10-31 09:19:22.639229 [DEBUG] switch_rtp.c:1935 Not using a timer
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1351638120 1351638122 IN IP4 10.1.3.50
s=FreeSWITCH
c=IN IP4 10.1.3.50
t=0 0
m=audio 17242 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:119 (sofia/internal/3606@10.1.3.50) State Change CS_INIT -> CS_RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3606@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3606@10.1.3.50) State INIT going to sleep
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3606@10.1.3.50) Running State Change CS_RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3606@10.1.3.50) State RESET
2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:166 sofia/internal/3606@10.1.3.50 SOFIA RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:93 sofia/internal/3606@10.1.3.50 Standard RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3606@10.1.3.50) State RESET going to sleep
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3606@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [DEBUG] sofia.c:6040 Channel sofia/internal/3606@10.1.3.50 entering state [calling][0]
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3573 sofia/internal/3429@10.1.3.50 Set rtp dtmf delay to 40
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3579 Set comfort noise payload to 13
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:5965 (sofia/internal/3429@10.1.3.50) State Change CS_NEW -> CS_INIT
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [NOTICE] sofia_glue.c:5966 Resurrecting fallen channel sofia/internal/3429@10.1.3.50
2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:941 New Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 [09de40c0-eba4-44a3-aa4d-d47ec4b2acf0]
2012-10-31 09:19:22.639229 [NOTICE] switch_channel.c:939 Rename Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292->sofia/internal/sip:ukytvsci@10.1.19.195:1292 [09de40c0-eba4-44a3-aa4d-d47ec4b2acf0]
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3027 Set Codec sofia/internal/sip:ukytvsci@10.1.19.195:1292 PCMU/8000 20 ms 160 samples 64000 bits
2012-10-31 09:19:22.639229 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Original read codec set to PCMU:0
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_INIT
2012-10-31 09:19:22.639229 [DEBUG] switch_channel.c:1936 (sofia/internal/3429@10.1.3.50) Callstate Change DOWN -> ACTIVE
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3429@10.1.3.50) State INIT
2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:85 sofia/internal/3429@10.1.3.50 SOFIA INIT
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/internal/sip:ukytvsci@10.1.19.195:1292] 10.1.3.50 port 18356 -> 10.1.19.195 port 50000 codec: 0 ms: 20
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1351630162 1351630164 IN IP4 10.1.3.50
s=FreeSWITCH
c=IN IP4 10.1.3.50
t=0 0
m=audio 25200 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:119 (sofia/internal/3429@10.1.3.50) State Change CS_INIT -> CS_RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/3429@10.1.3.50) State INIT going to sleep
2012-10-31 09:19:22.639229 [DEBUG] switch_rtp.c:1935 Not using a timer
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET
2012-10-31 09:19:22.639229 [DEBUG] mod_sofia.c:166 sofia/internal/3429@10.1.3.50 SOFIA RESET
2012-10-31 09:19:22.639229 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3573 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Set rtp dtmf delay to 40
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:3579 Set comfort noise payload to 13
2012-10-31 09:19:22.639229 [DEBUG] sofia_glue.c:5965 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_NEW -> CS_INIT
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [NOTICE] sofia_glue.c:5966 Resurrecting fallen channel sofia/internal/sip:ukytvsci@10.1.19.195:1292
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_INIT
2012-10-31 09:19:22.659361 [DEBUG] switch_channel.c:1936 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Callstate Change DOWN -> ACTIVE
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State INIT
2012-10-31 09:19:22.659361 [DEBUG] mod_sofia.c:85 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA INIT
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:2609 Local SDP:
v=0
o=FreeSWITCH 1351637006 1351637008 IN IP4 10.1.3.50
s=FreeSWITCH
c=IN IP4 10.1.3.50
t=0 0
m=audio 18356 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2012-10-31 09:19:22.659361 [DEBUG] mod_sofia.c:119 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_INIT -> CS_RESET
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State INIT going to sleep
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_RESET
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET
2012-10-31 09:19:22.659361 [DEBUG] mod_sofia.c:166 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA RESET
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:93 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard RESET
2012-10-31 09:19:22.659361 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET going to sleep
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] sofia.c:6040 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 entering state [calling][0]
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] sofia.c:6040 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 entering state [completing][200]
2012-10-31 09:19:22.659361 [DEBUG] sofia.c:6051 Remote SDP:
v=0^M
o=- 3560663913 3560663915 IN IP4 10.1.19.195^M
s=Blink 0.2.7 (Windows)^M
c=IN IP4 10.1.19.195^M
t=0 0^M
m=audio 50000 RTP/AVP 0 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=rtcp:50001^M

2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.659361 [DEBUG] sofia.c:6040 Channel sofia/internal/sip:ukytvsci@10.1.19.195:1292 entering state [ready][200]
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:2961 Already using PCMU
2012-10-31 09:19:22.659361 [DEBUG] sofia_glue.c:5158 Set 2833 dtmf send payload to 101
2012-10-31 09:19:22.679370 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.679370 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.739357 [INFO] switch_channel.c:2776 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Flipping CID from "Extension 3429" <3429> to "Outbound Call" <ukytvsci>
2012-10-31 09:19:22.739357 [DEBUG] switch_ivr_bridge.c:1672 (sofia/internal/3429@10.1.3.50) State Change CS_RESET -> CS_HIBERNATE
2012-10-31 09:19:22.739357 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.739357 [DEBUG] switch_ivr_bridge.c:1674 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_RESET -> CS_HIBERNATE
2012-10-31 09:19:22.739357 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_HIBERNATE
2012-10-31 09:19:22.739357 [DEBUG] switch_core_session.c:840 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State HIBERNATE
2012-10-31 09:19:22.739357 [DEBUG] mod_sofia.c:222 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA HIBERNATE
2012-10-31 09:19:22.739357 [DEBUG] switch_ivr_bridge.c:757 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_HIBERNATE -> CS_RESET
2012-10-31 09:19:22.739357 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State HIBERNATE going to sleep
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_RESET
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET
2012-10-31 09:19:22.739357 [DEBUG] mod_sofia.c:166 sofia/internal/sip:ukytvsci@10.1.19.195:1292 SOFIA RESET
2012-10-31 09:19:22.739357 [DEBUG] switch_ivr_bridge.c:742 sofia/internal/sip:ukytvsci@10.1.19.195:1292 CUSTOM RESET
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:93 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard RESET
2012-10-31 09:19:22.739357 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State RESET going to sleep
2012-10-31 09:19:22.739357 [DEBUG] switch_core_session.c:840 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.739357 [DEBUG] switch_ivr_bridge.c:742 sofia/internal/3429@10.1.3.50 CUSTOM RESET
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET going to sleep
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_HIBERNATE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/3429@10.1.3.50) State HIBERNATE
2012-10-31 09:19:22.759770 [DEBUG] mod_sofia.c:222 sofia/internal/3429@10.1.3.50 SOFIA HIBERNATE
2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:757 (sofia/internal/3429@10.1.3.50) State Change CS_HIBERNATE -> CS_RESET
2012-10-31 09:19:22.759770 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/3429@10.1.3.50) State HIBERNATE going to sleep
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_RESET
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET
2012-10-31 09:19:22.759770 [DEBUG] mod_sofia.c:166 sofia/internal/3429@10.1.3.50 SOFIA RESET
2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:742 sofia/internal/3429@10.1.3.50 CUSTOM RESET
2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:749 (sofia/internal/3429@10.1.3.50) State Change CS_RESET -> CS_SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:436 (sofia/internal/3429@10.1.3.50) State RESET going to sleep
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/3429@10.1.3.50) Running State Change CS_SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/3429@10.1.3.50) State SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] mod_sofia.c:652 SOFIA SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:767 sofia/internal/3429@10.1.3.50 CUSTOM SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] sofia.c:6040 Channel sofia/internal/3429@10.1.3.50 entering state [calling][0]
2012-10-31 09:19:22.759770 [DEBUG] sofia.c:6040 Channel sofia/internal/3429@10.1.3.50 entering state [completing][200]
2012-10-31 09:19:22.759770 [DEBUG] sofia.c:6051 Remote SDP:
v=0^M
o=- 3560644143 3560644144 IN IP4 10.1.45.148^M
s=pjmedia^M
c=IN IP4 10.1.45.148^M
t=0 0^M
a=X-nat:0^M
m=audio 4000 RTP/AVP 0 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=rtcp:4001 IN IP4 10.1.45.148^M

2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:799 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_RESET -> CS_SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.759770 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.759770 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] mod_sofia.c:652 SOFIA SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_ivr_bridge.c:767 sofia/internal/sip:ukytvsci@10.1.19.195:1292 CUSTOM SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:264 sofia/internal/sip:ukytvsci@10.1.19.195:1292 Standard SOFT_EXECUTE
2012-10-31 09:19:22.759770 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State SOFT_EXECUTE going to sleep
2012-10-31 09:19:22.779360 [DEBUG] sofia.c:6040 Channel sofia/internal/3429@10.1.3.50 entering state [ready][200]
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:2961 Already using PCMU
2012-10-31 09:19:22.779360 [DEBUG] sofia_glue.c:5165 Set 2833 dtmf send/recv payload to 101
2012-10-31 09:19:22.779360 [DEBUG] switch_ivr_bridge.c:1257 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_CONSUME_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State CONSUME_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/sip:ukytvsci@10.1.19.195:1292 CUSTOM HOLD
2012-10-31 09:19:22.779360 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State CONSUME_MEDIA going to sleep
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] switch_ivr_bridge.c:1359 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) Running State Change CS_EXCHANGE_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_core_state_machine.c:443 (sofia/internal/sip:ukytvsci@10.1.19.195:1292) State EXCHANGE_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] mod_sofia.c:646 SOFIA EXCHANGE_MEDIA
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:840 Send signal sofia/internal/sip:ukytvsci@10.1.19.195:1292 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] switch_core_session.c:840 Send signal sofia/internal/3429@10.1.3.50 [BREAK]
2012-10-31 09:19:22.779360 [DEBUG] mod_sofia.c:2280 Not sending same id again "3429" <3429>
2012-10-31 09:19:22.779360 [DEBUG] switch_rtp.c:3594 Correct ip/port confirmed.
2012-10-31 09:19:22.779360 [DEBUG] switch_rtp.c:3594 Correct ip/port confirmed.