[Freeswitch-users] Leg-A is automatically disconnected on Leg-B orginate failure
David Ma
mays.david at gmail.com
Tue Jun 28 19:38:37 MSD 2011
Hi Michael,
Sorry for the inconvenience. I just pastebin the log. It can be found in
path http://pastebin.freeswitch.org/16617.
Thanks,
David Ma
On Mon, Jun 27, 2011 at 11:09 PM, Michael Collins <msc at freeswitch.org>wrote:
> This makes my eyes bleed. Can you please put this on
> pastebin.freeswitch.org? Use "FreeSWITCH Log" as the syntax highlight.
> -MC
>
> On Sun, Jun 26, 2011 at 11:27 PM, David Ma <mays.david at gmail.com> wrote:
>
>> Hi Michael,
>>
>> Thanks very much for the response. There is no dialplan specified for this
>> call. In the FS setting, G729 is used as preferred stack for originating
>> calls. The leg-A and B are bridged immediately after receiving
>> PROGRESS-MEDIA from leg-B.
>>
>> Calls are originated with following parameters:
>> *
>> -- Leg-A --
>> "api originate
>> {origination_caller_id_number=<caller>,sip_cid_type=pid,privacy=yes,continue_on_fail=true}
>> <called> &park()"
>>
>> **-- Leg-B --*
>> * "api originate
>> {origination_caller_id_number=<caller>,originate_timeout=60,sip_cid_type=pid,privacy=yes,continue_on_fail=false}
>> <called> &park()"
>> *
>>
>> The entire debug log for this call follows.
>>
>> Thanks,
>> D.Ma
>>
>> On Fri, Jun 24, 2011 at 2:41 PM, Michael Collins <msc at freeswitch.org>wrote:
>>
>>> Pastebin the entire debug log, including the siptrace. Also include the
>>> originate line and any other dialplan config that might be used.
>>> -MC
>>>
>>>
>>> On Thu, Jun 23, 2011 at 11:26 PM, David Ma <mays.david at gmail.com> wrote:
>>>
>>>> Hi Michael,
>>>>
>>>> Unfortunately this problem still happens.
>>>>
>>>> I enabled "continue_on_fail" for leg-A when I originated the call. Leg-A
>>>> call went well. Then I originated leg-B call ("continue_on_fail" is NOT set
>>>> for leg-B), which failed for [DESTINATION_OUT_OF_ORDER]. As the consequence,
>>>> leg-A was hung up by FS automatically for [ORIGINATOR_CANCEL].
>>>>
>>>> The log excerpt follows.
>>>>
>>>> Do you think "continue_on_fail" should be also enabled for leg-B call?
>>>>
>>>> Thanks,
>>>> D.Ma
>>>>
>>>> 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable
>>>> string 5 = [continue_on_fail=true]
>>>>
>>>> 2011-06-24 13:29:35.887830 [NOTICE] switch_channel.c:808 New Channel
>>>> sofia/external/03996597632298 at 203.208.207.212[c0bd700d-913c-42ad-b68f-81001bf658b8]
>>>> [...]
>>>> 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:372
>>>> (sofia/external/03996563750911 at 203.208.207.212) State SOFT_EXECUTE
>>>> going to sleep
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535
>>>> (sofia/external/03996563750911 at 203.208.207.212) Callstate Change EARLY
>>>> -> HANGUP
>>>> 2011-06-24 13:29:48.161779 [NOTICE] switch_ivr_originate.c:1045 Hangup
>>>> sofia/external/03996563750911 at 203.208.207.212 [CS_SOFT_EXECUTE]
>>>> [DESTINATION_OUT_OF_ORDER]
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal
>>>> sofia/external/03996563750911 at 203.208.207.212 [KILL]
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send
>>>> signal sofia/external/03996563750911 at 203.208.207.212 [BREAK]
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320
>>>> (sofia/external/03996563750911 at 203.208.207.212) Running State Change
>>>> CS_HANGUP
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535
>>>> (sofia/external/03996597632298 at 203.208.207.212) Callstate Change ACTIVE
>>>> -> HANGUP
>>>> 2011-06-24 13:29:48.161779 [NOTICE] switch_ivr_bridge.c:772 Hangup
>>>> sofia/external/03996597632298 at 203.208.207.212 [CS_SOFT_EXECUTE]
>>>> [ORIGINATOR_CANCEL]
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:557
>>>> (sofia/external/03996563750911 at 203.208.207.212) State HANGUP
>>>> 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel
>>>> sofia/external/03996563750911 at 203.208.207.212 hanging up, cause:
>>>> DESTINATION_OUT_OF_ORDER
>>>> 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:510 Sending CANCEL to
>>>> sofia/external/03996563750911 at 203.208.207.212
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal
>>>> sofia/external/03996597632298 at 203.208.207.212 [KILL]
>>>> 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send
>>>> signal sofia/external/03996597632298 at 203.208.207.212 [BREAK]
>>>>
>>>> On Fri, Jun 17, 2011 at 10:52 AM, David Ma <mays.david at gmail.com>wrote:
>>>>
>>>>> Hi Michael,
>>>>>
>>>>> Thanks very much for your prompt response! I appreciate the information
>>>>> provided.
>>>>>
>>>>> I was actually searching the the existence of such a variable. I was
>>>>> not so luck to find it out and thereby resort to the support forum.
>>>>>
>>>>> I've modified my code to build this parameter into my application. Will
>>>>> feedback to you after verification.
>>>>>
>>>>> Thanks again,
>>>>> D.Ma
>>>>>
>>>>> On Fri, Jun 17, 2011 at 4:51 AM, Michael Collins <msc at freeswitch.org>wrote:
>>>>>
>>>>>> How about setting this?
>>>>>> http://wiki.freeswitch.org/wiki/Channel_Variables#continue_on_fail
>>>>>>
>>>>>> -MC
>>>>>>
>>>>>>
>>>>>> On Thu, Jun 16, 2011 at 1:32 AM, dma <mays.david at gmail.com> wrote:
>>>>>>
>>>>>>> I am creating a call-back solution. After leg-A answers, I originate
>>>>>>> leg-B
>>>>>>> call. After receiving SIP 183 from Leg-B, I bridge the 2 legs.
>>>>>>> However, in
>>>>>>> some cases, leg-A is automatically disconnected by FreeSwitch on
>>>>>>> leg-B
>>>>>>> failure, for example, DESTINATION_OUT_OF_ORDER. The application is
>>>>>>> not given
>>>>>>> a chance to handle leg-B failure event. This should not be a correct
>>>>>>> scenario because I never set "hangup-after-bridge", which is false by
>>>>>>> default.
>>>>>>>
>>>>>>> The right way should be, FreeSwitch doesn't hang up leg-A
>>>>>>> automatically, but
>>>>>>> give a chance for the application to decide what to do.
>>>>>>>
>>>>>>> Please see the logs below:
>>>>>>>
>>>>>>> =================================================
>>>>>>>
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 0 = [origination_caller_id_number=03996563750914]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 1 = [originate_timeout=30]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 2 = [ccd_session_id=20110610105829676824]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 3 = [sip_cid_type=pid]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 4 = [privacy=yes]
>>>>>>> 2011-06-10 11:09:55.370506 [NOTICE] switch_channel.c:808 New Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212
>>>>>>> [ea57b74b-a8c2-4fea-9683-98054dc03a79]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:4129
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change CS_NEW
>>>>>>> ->
>>>>>>> CS_INIT
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_INIT
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:356
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State INIT
>>>>>>> 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:84
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA INIT
>>>>>>> send 984 bytes to udp/[203.208.207.212]:5060 at 03:09:55.477997:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> INVITE sip:03996590031055 at 203.208.207.212 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP 202.73.56.46:5080
>>>>>>> ;rport;branch=z9hG4bKXjQ7eFpKypy5D
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To: <sip:03996590031055 at 203.208.207.212>
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Contact: <sip:mod_sofia at 202.73.56.46:5080>
>>>>>>> User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
>>>>>>> REGISTER, REFER, NOTIFY
>>>>>>> Supported: timer, precondition, path, replaces
>>>>>>> Allow-Events: talk, hold, refer
>>>>>>> Privacy: none
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Disposition: session
>>>>>>> Content-Length: 204
>>>>>>> X-FS-Support: update_display
>>>>>>> P-Asserted-Identity: "" <sip:03996563750914 at 202.73.56.46>
>>>>>>>
>>>>>>> v=0
>>>>>>> o=FreeSWITCH 1307645395 1307645396 IN IP4 202.73.56.46
>>>>>>> s=FreeSWITCH
>>>>>>> c=IN IP4 202.73.56.46
>>>>>>> t=0 0
>>>>>>> m=audio 30000 RTP/AVP 18 3 101 13
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=fmtp:101 0-16
>>>>>>> a=ptime:20
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:09:55.371674 [DEBUG] mod_sofia.c:124
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change CS_INIT
>>>>>>> ->
>>>>>>> CS_ROUTING
>>>>>>> 2011-06-10 11:09:55.371674 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:09:55.371674 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 entering state
>>>>>>> [calling][0]
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:356
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State INIT going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_ROUTING
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_channel.c:1657
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Callstate Change
>>>>>>> DOWN ->
>>>>>>> RINGING
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State ROUTING
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] mod_sofia.c:147
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA ROUTING
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_ivr_originate.c:66
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_ROUTING ->
>>>>>>> CS_CONSUME_MEDIA
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State ROUTING going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_CONSUME_MEDIA
>>>>>>> 2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State CONSUME_MEDIA
>>>>>>> 2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State CONSUME_MEDIA
>>>>>>> going to
>>>>>>> sleep
>>>>>>> recv 307 bytes from udp/[203.208.207.212]:5060 at 03:09:55.485130:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 100 Trying
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To: <sip:03996590031055 at 203.208.207.212>
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> recv 669 bytes from udp/[203.208.207.212]:5060 at 03:09:56.677788:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 183 Session Progress
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Length: 189
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 421265648 1 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:09:56.571839 [INFO] sofia.c:729
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Update Callee ID to
>>>>>>> "Outbound
>>>>>>> Call" <03996590031055>
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 entering state
>>>>>>> [proceeding][183]
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia.c:4657 Remote SDP:
>>>>>>> v=0
>>>>>>> o=- 421265648 1 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>>
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:4467 Audio Codec
>>>>>>> Compare
>>>>>>> [G729:18:8000:20:8000]/[G729:18:8000:20:8000]
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:2757 Set Codec
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 G729/8000 20 ms 160
>>>>>>> samples
>>>>>>> 8000 bits
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf
>>>>>>> send
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:2987 AUDIO RTP
>>>>>>> [sofia/external/03996590031055 at 203.208.207.212] 10.1.1.46 port 30000
>>>>>>> ->
>>>>>>> 203.208.207.196 port 30792 codec: 18 ms: 20
>>>>>>> 2011-06-10 11:09:56.571839 [DEBUG] switch_rtp.c:1607 Starting timer
>>>>>>> [soft]
>>>>>>> 160 bytes per 20ms
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf
>>>>>>> send
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf
>>>>>>> receive
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:09:56.573731 [NOTICE] sofia_glue.c:3680 Pre-Answer
>>>>>>> sofia/external/03996590031055 at 203.208.207.212!
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] switch_channel.c:2627
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Callstate Change
>>>>>>> RINGING ->
>>>>>>> EARLY
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] switch_ivr_originate.c:3408
>>>>>>> Originate
>>>>>>> Resulted in Success: [sofia/external/03996590031055 at 203.208.207.212]
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] mod_commands.c:3205
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_CONSUME_MEDIA -> CS_EXECUTE
>>>>>>> 2011-06-10 11:09:56.573731 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_EXECUTE
>>>>>>> 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:366
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State EXECUTE
>>>>>>> 2011-06-10 11:09:56.575262 [DEBUG] mod_sofia.c:240
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA EXECUTE
>>>>>>> 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:157
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Standard EXECUTE
>>>>>>> EXECUTE sofia/external/03996590031055 at 203.208.207.212 park()
>>>>>>> 2011-06-10 11:09:56.618770 [DEBUG] switch_rtp.c:2933 Correct ip/port
>>>>>>> confirmed.
>>>>>>> recv 669 bytes from udp/[203.208.207.212]:5060 at 03:10:01.562021:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 183 Session Progress
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Length: 189
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 421265648 2 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:01.455944 [INFO] sofia.c:729
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Update Callee ID to
>>>>>>> "03996590031055" <03996590031055>
>>>>>>> 2011-06-10 11:10:01.455944 [DEBUG] sofia.c:4641 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 skipping state
>>>>>>> [proceeding][183]
>>>>>>> recv 669 bytes from udp/[203.208.207.212]:5060 at 03:10:01.563178:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 183 Session Progress
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Length: 189
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 421265648 3 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:01.457169 [DEBUG] sofia.c:4641 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 skipping state
>>>>>>> [proceeding][183]
>>>>>>> recv 749 bytes from udp/[203.208.207.212]:5060 at 03:10:27.365284:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 200 Ok
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 INVITE
>>>>>>> Contact: <sip:203.208.207.212:5060>
>>>>>>> Allow-Events: refer
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Supported: 100rel, timer, replaces
>>>>>>> Content-Length: 189
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 421265648 4 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:27.258092 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 entering state
>>>>>>> [completing][200]
>>>>>>> 2011-06-10 11:10:27.258092 [DEBUG] sofia.c:4657 Remote SDP:
>>>>>>> v=0
>>>>>>> o=- 421265648 4 IN IP4 203.208.207.219
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.196
>>>>>>> t=0 0
>>>>>>> m=audio 30792 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>>
>>>>>>> send 405 bytes to udp/[203.208.207.212]:5060 at 03:10:27.366562:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> ACK sip:203.208.207.212:5060 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP 202.73.56.46:5080
>>>>>>> ;rport;branch=z9hG4bKyUg0ga7pUZmrS
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501633 ACK
>>>>>>> Contact: <sip:mod_sofia at 202.73.56.46:5080>
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:27.260267 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 entering state
>>>>>>> [ready][200]
>>>>>>> 2011-06-10 11:10:27.260267 [DEBUG] switch_channel.c:2782
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Callstate Change
>>>>>>> EARLY ->
>>>>>>> ACTIVE
>>>>>>> 2011-06-10 11:10:27.260267 [NOTICE] sofia.c:5175 Channel
>>>>>>> [sofia/external/03996590031055 at 203.208.207.212] has been answered
>>>>>>> 2011-06-10 11:10:27.264178 [DEBUG] switch_scheduler.c:214 Added task
>>>>>>> 23
>>>>>>> switch_ivr_schedule_hangup (ea57b74b-a8c2-4fea-9683-98054dc03a79) to
>>>>>>> run at
>>>>>>> 1307676927
>>>>>>> 2011-06-10 11:10:27.265202 [DEBUG] switch_core_session.c:954 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 0 = [origination_caller_id_number=03996590031055]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 1 = [ccd_session_id=20110610105829676824]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 2 = [sip_cid_type=pid]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971
>>>>>>> variable
>>>>>>> string 3 = [privacy=yes]
>>>>>>> 2011-06-10 11:10:27.266218 [NOTICE] switch_channel.c:808 New Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212
>>>>>>> [30228d2b-756a-4a98-871d-db63a2955b52]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:4129
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change CS_NEW
>>>>>>> ->
>>>>>>> CS_INIT
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_INIT
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State INIT
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:84
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA INIT
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:124
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change CS_INIT
>>>>>>> ->
>>>>>>> CS_ROUTING
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State INIT going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_ROUTING
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_channel.c:1657
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Callstate Change
>>>>>>> DOWN ->
>>>>>>> RINGING
>>>>>>> 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:359
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State ROUTING
>>>>>>> send 984 bytes to udp/[203.208.207.212]:5060 at 03:10:27.373220:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> INVITE sip:03996563750914 at 203.208.207.212 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 202.73.56.46:5080;rport;branch=z9hG4bKZ49rj5Qtr8aBN2011-06-10
>>>>>>> 11:10:27.266218 [DEBUG] mod_sofia.c:147
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA ROUTING
>>>>>>>
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
>>>>>>> To: <sip:03996563750914 at 203.208.207.212>
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 INVITE
>>>>>>> Contact: <sip:mod_sofia at 202.73.56.46:5080>
>>>>>>> User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
>>>>>>> REGISTER, REFER, NOTIFY
>>>>>>> Supported: timer, precondition, path, replaces
>>>>>>> Allow-Events: talk, hold, refer
>>>>>>> Privacy: none
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Disposition: session
>>>>>>> Content-Length: 204
>>>>>>> X-FS-Support: update_display
>>>>>>> P-Asserted-Identity: "" <sip:03996590031055 at 202.73.56.46>
>>>>>>>
>>>>>>> v=0
>>>>>>> o=FreeSWITCH 1307646863 1307646864 IN IP4 202.73.56.46
>>>>>>> s=FreeSWITCH
>>>>>>> c=IN IP4 202.73.56.46
>>>>>>> t=0 0
>>>>>>> m=audio 28564 RTP/AVP 18 3 101 13
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=fmtp:101 0-16
>>>>>>> a=ptime:20
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 entering state
>>>>>>> [calling][0]
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_ivr_originate.c:66
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_ROUTING ->
>>>>>>> CS_CONSUME_MEDIA
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:359
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State ROUTING going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_CONSUME_MEDIA
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State CONSUME_MEDIA
>>>>>>> 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State CONSUME_MEDIA
>>>>>>> going to
>>>>>>> sleep
>>>>>>> recv 307 bytes from udp/[203.208.207.212]:5060 at 03:10:27.378710:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 100 Trying
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
>>>>>>> From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
>>>>>>> To: <sip:03996563750914 at 203.208.207.212>
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 INVITE
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:27.278484 [DEBUG] switch_ivr.c:563
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Command Execute
>>>>>>> playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav)
>>>>>>> EXECUTE sofia/external/03996590031055 at 203.208.207.212
>>>>>>> playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav)
>>>>>>> 2011-06-10 11:10:27.278484 [DEBUG] switch_core_file.c:176 File
>>>>>>> /usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav sample
>>>>>>> rate 11025
>>>>>>> doesn't match requested rate 8000
>>>>>>> 2011-06-10 11:10:27.278484 [WARNING] switch_core_file.c:189 File has
>>>>>>> 2
>>>>>>> channels, muxing to mono will occur.
>>>>>>> 2011-06-10 11:10:27.278484 [DEBUG] switch_ivr_play_say.c:1244 Codec
>>>>>>> Activated L16 at 8000hz 2 channels 20ms
>>>>>>> 2011-06-10 11:10:27.298764 [INFO] mod_com_g729.c:119 ENCODER CREATE -
>>>>>>> 0x2aaab00310c0 0x2aaab00b20c0
>>>>>>> recv 666 bytes from udp/[203.208.207.212]:5060 at 03:10:28.618472:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 183 Session Progress
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
>>>>>>> From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
>>>>>>> To:
>>>>>>> <sip:03996563750914 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 INVITE
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Length: 186
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 131082 1 IN IP4 203.208.207.218
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.195
>>>>>>> t=0 0
>>>>>>> m=audio 45002 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:28.513195 [INFO] sofia.c:729
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Update Callee ID to
>>>>>>> "Outbound
>>>>>>> Call" <03996563750914>
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia.c:4646 Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 entering state
>>>>>>> [proceeding][183]
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia.c:4657 Remote SDP:
>>>>>>> v=0
>>>>>>> o=- 131082 1 IN IP4 203.208.207.218
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.195
>>>>>>> t=0 0
>>>>>>> m=audio 45002 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>>
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:4467 Audio Codec
>>>>>>> Compare
>>>>>>> [G729:18:8000:20:8000]/[G729:18:8000:20:8000]
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:2757 Set Codec
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 G729/8000 20 ms 160
>>>>>>> samples
>>>>>>> 8000 bits
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf
>>>>>>> send
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:2987 AUDIO RTP
>>>>>>> [sofia/external/03996563750914 at 203.208.207.212] 10.1.1.46 port 28564
>>>>>>> ->
>>>>>>> 203.208.207.195 port 45002 codec: 18 ms: 20
>>>>>>> 2011-06-10 11:10:28.513195 [DEBUG] switch_rtp.c:1607 Starting timer
>>>>>>> [soft]
>>>>>>> 160 bytes per 20ms
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf
>>>>>>> send
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf
>>>>>>> receive
>>>>>>> payload to 101
>>>>>>> 2011-06-10 11:10:28.514938 [NOTICE] sofia_glue.c:3680 Pre-Answer
>>>>>>> sofia/external/03996563750914 at 203.208.207.212!
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] switch_channel.c:2627
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Callstate Change
>>>>>>> RINGING ->
>>>>>>> EARLY
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] switch_ivr_originate.c:3408
>>>>>>> Originate
>>>>>>> Resulted in Success: [sofia/external/03996563750914 at 203.208.207.212]
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] mod_commands.c:3205
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_CONSUME_MEDIA -> CS_EXECUTE
>>>>>>> 2011-06-10 11:10:28.514938 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_EXECUTE
>>>>>>> 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:366
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State EXECUTE
>>>>>>> 2011-06-10 11:10:28.515884 [DEBUG] mod_sofia.c:240
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA EXECUTE
>>>>>>> 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:157
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard EXECUTE
>>>>>>> EXECUTE sofia/external/03996563750914 at 203.208.207.212 park()
>>>>>>> 2011-06-10 11:10:28.516887 [DEBUG] switch_core_session.c:954 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1480
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_EXECUTE ->
>>>>>>> CS_HIBERNATE
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1482
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_EXECUTE ->
>>>>>>> CS_HIBERNATE
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_play_say.c:1581 done
>>>>>>> playing
>>>>>>> file
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr.c:563
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Command Execute
>>>>>>> playback(tone_stream://%(2000,4000,440,480);loops=10)
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:366
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State EXECUTE going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_HIBERNATE
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State HIBERNATE
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:221
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA HIBERNATE
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:731
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_HIBERNATE ->
>>>>>>> CS_RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State HIBERNATE
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:165
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:716
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 CUSTOM RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:66
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard RESET
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State RESET going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:28.519223 [DEBUG] switch_core_session.c:709 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> recv 666 bytes from udp/[203.208.207.212]:5060 at 03:10:30.540814:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 183 Session Progress
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
>>>>>>> From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
>>>>>>> To:
>>>>>>> <sip:03996563750914 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 INVITE
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER,
>>>>>>> NOTIFY,
>>>>>>> SUBSCRIBE, UPDATE
>>>>>>> Content-Type: application/sdp
>>>>>>> Content-Length: 186
>>>>>>>
>>>>>>> v=0
>>>>>>> o=- 131082 2 IN IP4 203.208.207.218
>>>>>>> s=session
>>>>>>> c=IN IP4 203.208.207.195
>>>>>>> t=0 0
>>>>>>> m=audio 45002 RTP/AVP 18 101
>>>>>>> a=rtpmap:18 G729/8000
>>>>>>> a=rtpmap:101 telephone-event/8000
>>>>>>> a=sendrecv
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:30.435309 [INFO] sofia.c:729
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Update Callee ID to
>>>>>>> "03996563750914" <03996563750914>
>>>>>>> 2011-06-10 11:10:30.435309 [DEBUG] sofia.c:4641 Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 skipping state
>>>>>>> [proceeding][183]
>>>>>>> 2011-06-10 11:10:30.691404 [WARNING] switch_core_session.c:1940
>>>>>>> Cannot
>>>>>>> execute app 'playback' media required on an outbound channel that
>>>>>>> does not
>>>>>>> have media established
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:366
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State EXECUTE going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_HIBERNATE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State HIBERNATE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:221
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA HIBERNATE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:731
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_HIBERNATE ->
>>>>>>> CS_RESET
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State HIBERNATE
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_RESET
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State RESET
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:165
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA RESET
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:716
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 CUSTOM RESET
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:723
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_RESET ->
>>>>>>> CS_SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State RESET going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:741
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 CUSTOM SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:761
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_RESET ->
>>>>>>> CS_SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:741
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 CUSTOM SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:204
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard SOFT_EXECUTE
>>>>>>> 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State SOFT_EXECUTE
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Callstate Change
>>>>>>> EARLY ->
>>>>>>> HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [NOTICE] switch_ivr_originate.c:1045
>>>>>>> Hangup
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [CS_SOFT_EXECUTE]
>>>>>>> [DESTINATION_OUT_OF_ORDER]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2551 Send signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [KILL]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Callstate Change
>>>>>>> ACTIVE ->
>>>>>>> HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 hanging up, cause:
>>>>>>> DESTINATION_OUT_OF_ORDER
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:510 Sending CANCEL to
>>>>>>> sofia/external/03996563750914 at 203.208.207.212
>>>>>>> send 390 bytes to udp/[203.208.207.212]:5060 at 03:10:30.818391:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> CANCEL sip:03996563750914 at 203.208.207.212 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP 202.73.56.46:5080
>>>>>>> ;rport;branch=z9hG4bKZ49rj5Qtr8aBN
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
>>>>>>> To: <sip:03996563750914 at 203.208.207.212>
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 CANCEL
>>>>>>> Reason: Q.850;cause=27;text="DESTINATION_OUT_OF_ORDER"
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:30.711798 [NOTICE] switch_ivr_bridge.c:772 Hangup
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [CS_SOFT_EXECUTE]
>>>>>>> [ORIGINATOR_CANCEL]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard HANGUP,
>>>>>>> cause:
>>>>>>> DESTINATION_OUT_OF_ORDER
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State HANGUP going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:351
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_HANGUP ->
>>>>>>> CS_REPORTING
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_REPORTING
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State REPORTING
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:53
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard REPORTING,
>>>>>>> cause:
>>>>>>> DESTINATION_OUT_OF_ORDER
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State REPORTING
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2551 Send signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [KILL]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:372
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State SOFT_EXECUTE
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:345
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State Change
>>>>>>> CS_REPORTING ->
>>>>>>> CS_DESTROY
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1288 Session
>>>>>>> 40
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Locked, Waiting on
>>>>>>> external
>>>>>>> entities
>>>>>>> 2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1306
>>>>>>> Session 40
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Ended
>>>>>>> 2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1308 Close
>>>>>>> Channel
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 [CS_DESTROY]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:449
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Callstate Change
>>>>>>> HANGUP ->
>>>>>>> DOWN
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:452
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) Running State Change
>>>>>>> CS_DESTROY
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State DESTROY
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:362
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 SOFIA DESTROY
>>>>>>> 2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:78 ENCODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaaac013028 (nil)
>>>>>>> 2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:79 DECODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaaac013028 (nil)
>>>>>>> 2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:78 ENCODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaaac013088 (nil)
>>>>>>> 2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:79 DECODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaaac013088 (nil)
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:60
>>>>>>> sofia/external/03996563750914 at 203.208.207.212 Standard DESTROY
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462
>>>>>>> (sofia/external/03996563750914 at 203.208.207.212) State DESTROY going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State HANGUP
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 hanging up, cause:
>>>>>>> ORIGINATOR_CANCEL
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:500 Sending BYE to
>>>>>>> sofia/external/03996590031055 at 203.208.207.212
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Standard HANGUP,
>>>>>>> cause:
>>>>>>> ORIGINATOR_CANCEL
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State HANGUP going
>>>>>>> to sleep
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:351
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_HANGUP ->
>>>>>>> CS_REPORTING
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_REPORTING
>>>>>>> 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State REPORTING
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:53
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Standard REPORTING,
>>>>>>> cause:
>>>>>>> ORIGINATOR_CANCEL
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:617
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State REPORTING
>>>>>>> going to
>>>>>>> sleep
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:345
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State Change
>>>>>>> CS_REPORTING ->
>>>>>>> CS_DESTROY
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1116 Send
>>>>>>> signal
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [BREAK]
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1288 Session
>>>>>>> 39
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Locked, Waiting on
>>>>>>> external
>>>>>>> entities
>>>>>>> 2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1306
>>>>>>> Session 39
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Ended
>>>>>>> 2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1308 Close
>>>>>>> Channel
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 [CS_DESTROY]
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:449
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Callstate Change
>>>>>>> HANGUP ->
>>>>>>> DOWN
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:452
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) Running State Change
>>>>>>> CS_DESTROY
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:462
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State DESTROY
>>>>>>> 2011-06-10 11:10:30.714001 [DEBUG] mod_sofia.c:362
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 SOFIA DESTROY
>>>>>>> 2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:78 ENCODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaab0031060 (nil)
>>>>>>> 2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:79 DECODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaab0031060 (nil)
>>>>>>> 2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:78 ENCODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaab00310c0 0x2aaab00b20c0
>>>>>>> 2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:79 DECODER DESTROYX
>>>>>>> -
>>>>>>> 0x2aaab00310c0 (nil)
>>>>>>> send 662 bytes to udp/[203.208.207.212]:5060 at 03:10:30.820530:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> BYE sip:203.208.207.212:5060 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP 202.73.56.46:5080
>>>>>>> ;rport;branch=z9hG4bK0D3Hm08XNH1Xg
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501634 BYE
>>>>>>> Contact: <sip:mod_sofia at 202.73.56.46:5080>
>>>>>>> User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
>>>>>>> REGISTER, REFER, NOTIFY
>>>>>>> Supported: timer, precondition, path, replaces
>>>>>>> Reason: FreeSWITCH;cause=487;text="ORIGINATOR_CANCEL"
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> 2011-06-10 11:10:30.715878 [INFO] mod_com_g729.c:83 ENCODER DESTROY -
>>>>>>> 0x2aaab00310c0 0x2aaab00b20c0
>>>>>>> 2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:60
>>>>>>> sofia/external/03996590031055 at 203.208.207.212 Standard DESTROY
>>>>>>> 2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:462
>>>>>>> (sofia/external/03996590031055 at 203.208.207.212) State DESTROY going
>>>>>>> to sleep
>>>>>>> recv 383 bytes from udp/[203.208.207.212]:5060 at 03:10:30.823302:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 200 Ok
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
>>>>>>> From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
>>>>>>> To:
>>>>>>> <sip:03996563750914 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D00000u00000001QXU3LU
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 CANCEL
>>>>>>> Contact: <sip:203.208.207.212:5060>
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> recv 411 bytes from udp/[203.208.207.212]:5060 at 03:10:30.824765:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 487 Request Terminated
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
>>>>>>> From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
>>>>>>> To:
>>>>>>> <sip:03996563750914 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 INVITE
>>>>>>> Reason: SIP;cause=487;text="Request Terminated"
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> send 371 bytes to udp/[203.208.207.212]:5060 at 03:10:30.824891:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> ACK sip:03996563750914 at 203.208.207.212 SIP/2.0
>>>>>>> Via: SIP/2.0/UDP 202.73.56.46:5080
>>>>>>> ;rport;branch=z9hG4bKZ49rj5Qtr8aBN
>>>>>>> Max-Forwards: 70
>>>>>>> From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
>>>>>>> To:
>>>>>>> <sip:03996563750914 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
>>>>>>> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501649 ACK
>>>>>>> Content-Length: 0
>>>>>>>
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> recv 380 bytes from udp/[203.208.207.212]:5060 at 03:10:30.826375:
>>>>>>>
>>>>>>> ------------------------------------------------------------------------
>>>>>>> SIP/2.0 200 Ok
>>>>>>> Via: SIP/2.0/UDP
>>>>>>> 10.1.1.46:5080
>>>>>>> ;rport=5080;branch=z9hG4bK0D3Hm08XNH1Xg;received=10.1.1.46
>>>>>>> From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
>>>>>>> To:
>>>>>>> <sip:03996590031055 at 203.208.207.212
>>>>>>> >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>>>>>> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>>>>>> CSeq: 13501634 BYE
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> --
>>>>>>> View this message in context:
>>>>>>> http://freeswitch-users.2379917.n2.nabble.com/Leg-A-is-automatically-disconnected-on-Leg-B-orginate-failure-tp6482192p6482192.html
>>>>>>> Sent from the freeswitch-users mailing list archive at Nabble.com.
>>>>>>>
>>>>>>> _______________________________________________
>>>>>>> FreeSWITCH-users mailing list
>>>>>>> FreeSWITCH-users at lists.freeswitch.org
>>>>>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>>>>>> UNSUBSCRIBE:
>>>>>>> http://lists.freeswitch.org/mailman/options/freeswitch-users
>>>>>>> http://www.freeswitch.org
>>>>>>>
>>>>>>
>>>>>>
>>>>>> _______________________________________________
>>>>>> Join us at ClueCon 2011, Aug 9-11, Chicago
>>>>>> http://www.cluecon.com 877-7-4ACLUE
>>>>>>
>>>>>>
>>>>>> FreeSWITCH-users mailing list
>>>>>> FreeSWITCH-users at lists.freeswitch.org
>>>>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>>>>> UNSUBSCRIBE:
>>>>>> http://lists.freeswitch.org/mailman/options/freeswitch-users
>>>>>> http://www.freeswitch.org
>>>>>>
>>>>>>
>>>>>
>>>>
>>>> _______________________________________________
>>>> Join us at ClueCon 2011, Aug 9-11, Chicago
>>>> http://www.cluecon.com 877-7-4ACLUE
>>>>
>>>> FreeSWITCH-users mailing list
>>>> FreeSWITCH-users at lists.freeswitch.org
>>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>>> UNSUBSCRIBE:
>>>> http://lists.freeswitch.org/mailman/options/freeswitch-users
>>>> http://www.freeswitch.org
>>>>
>>>>
>>>
>>> _______________________________________________
>>> Join us at ClueCon 2011, Aug 9-11, Chicago
>>> http://www.cluecon.com 877-7-4ACLUE
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>
>> _______________________________________________
>> Join us at ClueCon 2011, Aug 9-11, Chicago
>> http://www.cluecon.com 877-7-4ACLUE
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>
> _______________________________________________
> Join us at ClueCon 2011, Aug 9-11, Chicago
> http://www.cluecon.com 877-7-4ACLUE
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110628/298d1d07/attachment-0001.html
More information about the FreeSWITCH-users
mailing list