[Freeswitch-users] Leg-A is automatically disconnected on Leg-B orginate failure

David Ma mays.david at gmail.com
Fri Jun 17 06:52:22 MSD 2011


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: "" &lt;sip:03996563750914 at 202.73.56.46&gt;;tag=H4ZN43UH9S9Qc
>>   To: &lt;sip:03996590031055 at 203.208.207.212&gt;
>>   Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>   CSeq: 13501633 INVITE
>>   Contact: &lt;sip:mod_sofia at 202.73.56.46:5080&gt;
>>   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: "" &lt;sip:03996563750914 at 202.73.56.46&gt;
>>
>>   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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To: &lt;sip:03996590031055 at 203.208.207.212&gt;
>>   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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996563750914 at 202.73.56.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>   Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>   CSeq: 13501633 ACK
>>   Contact: &lt;sip:mod_sofia at 202.73.56.46:5080&gt;
>>   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: "" &lt;sip:03996590031055 at 202.73.56.46&gt;;tag=jDSe6ycN62Zar
>>   To: &lt;sip:03996563750914 at 203.208.207.212&gt;
>>   Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
>>   CSeq: 13501649 INVITE
>>   Contact: &lt;sip:mod_sofia at 202.73.56.46:5080&gt;
>>   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: "" &lt;sip:03996590031055 at 202.73.56.46&gt;
>>
>>   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: "" &lt;sip:03996590031055 at 10.1.1.46&gt;;tag=jDSe6ycN62Zar
>>   To: &lt;sip:03996563750914 at 203.208.207.212&gt;
>>   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: "" &lt;sip:03996590031055 at 10.1.1.46&gt;;tag=jDSe6ycN62Zar
>>   To:
>> &lt;sip:03996563750914 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996590031055 at 10.1.1.46&gt;;tag=jDSe6ycN62Zar
>>   To:
>> &lt;sip:03996563750914 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996590031055 at 202.73.56.46&gt;;tag=jDSe6ycN62Zar
>>   To: &lt;sip:03996563750914 at 203.208.207.212&gt;
>>   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: "" &lt;sip:03996563750914 at 202.73.56.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
>>   Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
>>   CSeq: 13501634 BYE
>>   Contact: &lt;sip:mod_sofia at 202.73.56.46:5080&gt;
>>   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: "" &lt;sip:03996590031055 at 10.1.1.46&gt;;tag=jDSe6ycN62Zar
>>   To:
>> &lt;sip:03996563750914 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996590031055 at 10.1.1.46&gt;;tag=jDSe6ycN62Zar
>>   To:
>> &lt;sip:03996563750914 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996590031055 at 202.73.56.46&gt;;tag=jDSe6ycN62Zar
>>   To:
>> &lt;sip:03996563750914 at 203.208.207.212
>> &gt;;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: "" &lt;sip:03996563750914 at 10.1.1.46&gt;;tag=H4ZN43UH9S9Qc
>>   To:
>> &lt;sip:03996590031055 at 203.208.207.212
>> &gt;;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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110617/40cca436/attachment-0001.html 


More information about the FreeSWITCH-users mailing list