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@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@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@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@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@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_HANGUP 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535 (sofia/external/ 03996597632298@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@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@203.208.207.212) State HANGUP 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel sofia/external/ 03996563750911@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@203.208.207.212 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal sofia/external/03996597632298@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] On Fri, Jun 17, 2011 at 10:52 AM, David Ma <mays.david@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@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@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@203.208.207.212 [ea57b74b-a8c2-4fea-9683-98054dc03a79] 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:4129 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State INIT 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:84 sofia/external/03996590031055@203.208.207.212 SOFIA INIT send 984 bytes to udp/[203.208.207.212]:5060 at 03:09:55.477997:

------------------------------------------------------------------------ INVITE sip:03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501633 INVITE Contact: <sip:mod_sofia@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.371674 [DEBUG] sofia.c:4646 Channel sofia/external/03996590031055@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@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@203.208.207.212) Running State Change CS_ROUTING 2011-06-10 11:09:55.373478 [DEBUG] switch_channel.c:1657 (sofia/external/03996590031055@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@203.208.207.212) State ROUTING 2011-06-10 11:09:55.373478 [DEBUG] mod_sofia.c:147 sofia/external/03996590031055@203.208.207.212 SOFIA ROUTING 2011-06-10 11:09:55.373478 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996590031055@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@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@203.208.207.212) State CONSUME_MEDIA 2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@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@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@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@203.208.207.212! 2011-06-10 11:09:56.573731 [DEBUG] switch_channel.c:2627 (sofia/external/03996590031055@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@203.208.207.212] 2011-06-10 11:09:56.573731 [DEBUG] mod_commands.c:3205 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State EXECUTE 2011-06-10 11:09:56.575262 [DEBUG] mod_sofia.c:240 sofia/external/03996590031055@203.208.207.212 SOFIA EXECUTE 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996590031055@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212 >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501633 ACK Contact: <sip:mod_sofia@202.73.56.46:5080> Content-Length: 0

------------------------------------------------------------------------ 2011-06-10 11:10:27.260267 [DEBUG] sofia.c:4646 Channel sofia/external/03996590031055@203.208.207.212 entering state [ready][200] 2011-06-10 11:10:27.260267 [DEBUG] switch_channel.c:2782 (sofia/external/03996590031055@203.208.207.212) Callstate Change EARLY -> ACTIVE 2011-06-10 11:10:27.260267 [NOTICE] sofia.c:5175 Channel [sofia/external/03996590031055@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@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@203.208.207.212 [30228d2b-756a-4a98-871d-db63a2955b52] 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:4129 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State INIT 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:84 sofia/external/03996563750914@203.208.207.212 SOFIA INIT 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:124 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996563750914@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@203.208.207.212) Running State Change CS_ROUTING 2011-06-10 11:10:27.266218 [DEBUG] switch_channel.c:1657 (sofia/external/03996563750914@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@203.208.207.212) State ROUTING send 984 bytes to udp/[203.208.207.212]:5060 at 03:10:27.373220:

------------------------------------------------------------------------ INVITE sip:03996563750914@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@203.208.207.212 SOFIA ROUTING

Max-Forwards: 70 From: "" <sip:03996590031055@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@203.208.207.212> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9 CSeq: 13501649 INVITE Contact: <sip:mod_sofia@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@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@203.208.207.212 entering state [calling][0] 2011-06-10 11:10:27.267630 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996563750914@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@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@203.208.207.212) State CONSUME_MEDIA 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@203.208.207.212 Command Execute playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav) EXECUTE sofia/external/03996590031055@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@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212! 2011-06-10 11:10:28.514938 [DEBUG] switch_channel.c:2627 (sofia/external/03996563750914@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@203.208.207.212] 2011-06-10 11:10:28.514938 [DEBUG] mod_commands.c:3205 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State EXECUTE 2011-06-10 11:10:28.515884 [DEBUG] mod_sofia.c:240 sofia/external/03996563750914@203.208.207.212 SOFIA EXECUTE 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996563750914@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996563750914@203.208.207.212 park() 2011-06-10 11:10:28.516887 [DEBUG] switch_core_session.c:954 Send signal sofia/external/03996590031055@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1480 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1482 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996563750914@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996590031055@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@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@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@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@203.208.207.212) State HIBERNATE 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:221 sofia/external/03996563750914@203.208.207.212 SOFIA HIBERNATE 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996563750914@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@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@203.208.207.212) State RESET 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:165 sofia/external/03996563750914@203.208.207.212 SOFIA RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:716 sofia/external/03996563750914@203.208.207.212 CUSTOM RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:66 sofia/external/03996563750914@203.208.207.212 Standard RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996563750914@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@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212) State HIBERNATE 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:221 sofia/external/03996590031055@203.208.207.212 SOFIA HIBERNATE 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996590031055@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@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@203.208.207.212) State RESET 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:165 sofia/external/03996590031055@203.208.207.212 SOFIA RESET 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:716 sofia/external/03996590031055@203.208.207.212 CUSTOM RESET 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:723 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996590031055@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@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:761 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:204 sofia/external/03996563750914@203.208.207.212 Standard SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996563750914@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@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@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@203.208.207.212 [KILL] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750914@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@203.208.207.212) Running State Change CS_HANGUP 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535 (sofia/external/03996590031055@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@203.208.207.212) State HANGUP 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel sofia/external/03996563750914@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@203.208.207.212 send 390 bytes to udp/[203.208.207.212]:5060 at 03:10:30.818391:

------------------------------------------------------------------------ CANCEL sip:03996563750914@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@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State REPORTING 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996563750914@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@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@203.208.207.212 [KILL] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996590031055@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1288 Session 40 (sofia/external/03996563750914@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@203.208.207.212) Ended 2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996563750914@203.208.207.212 [CS_DESTROY] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996563750914@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@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@203.208.207.212) State DESTROY 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:362 sofia/external/03996563750914@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@203.208.207.212 Standard DESTROY 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996563750914@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@203.208.207.212) State HANGUP 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel sofia/external/03996590031055@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@203.208.207.212 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46 sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State REPORTING 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1288 Session 39 (sofia/external/03996590031055@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@203.208.207.212) Ended 2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996590031055@203.208.207.212 [CS_DESTROY] 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996590031055@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@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@203.208.207.212) State DESTROY 2011-06-10 11:10:30.714001 [DEBUG] mod_sofia.c:362 sofia/external/03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212 >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501634 BYE Contact: <sip:mod_sofia@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@203.208.207.212 Standard DESTROY 2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996590031055@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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-disconn... Sent from the freeswitch-users mailing list archive at Nabble.com.

_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

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 ================================= 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable string 0 = [origination_caller_id_number=03996563750911] 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable string 1 = [originate_timeout=60] 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable string 2 = [ccd_session_id=20110624132936888918] 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable string 3 = [sip_cid_type=pid] 2011-06-24 13:29:35.887830 [DEBUG] switch_ivr_originate.c:1971 variable string 4 = [privacy=yes] 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@203.208.207.212[c0bd700d-913c-42ad-b68f-81001bf658b8] 2011-06-24 13:29:35.887830 [DEBUG] mod_sofia.c:4129 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_NEW -> CS_INIT 2011-06-24 13:29:35.887830 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:35.889072 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_INIT 2011-06-24 13:29:35.889829 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996597632298@203.208.207.212) State INIT 2011-06-24 13:29:35.889829 [DEBUG] mod_sofia.c:84 sofia/external/ 03996597632298@203.208.207.212 SOFIA INIT send 999 bytes to udp/[203.208.207.212]:5060 at 05:29:36.398490: ------------------------------------------------------------------------ INVITE sip:03996597632298@203.208.207.212 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKtpaQ28SQXKvem Max-Forwards: 70 From: "" <sip:03996563750911@202.73.56.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212> Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 INVITE Contact: <sip:mod_sofia@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, PRACK, NOTIFY Supported: 100rel, 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:03996563750911@202.73.56.46> v=0 o=FreeSWITCH 1308862405 1308862406 IN IP4 202.73.56.46 s=FreeSWITCH c=IN IP4 202.73.56.46 t=0 0 m=audio 30970 RTP/AVP 18 3 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2011-06-24 13:29:35.891343 [DEBUG] mod_sofia.c:124 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_INIT -> CS_ROUTING 2011-06-24 13:29:35.891343 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:35.891343 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996597632298@203.208.207.212 entering state [calling][0] 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996597632298@203.208.207.212) State INIT going to sleep 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_ROUTING 2011-06-24 13:29:35.891343 [DEBUG] switch_channel.c:1657 (sofia/external/ 03996597632298@203.208.207.212) Callstate Change DOWN -> RINGING 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996597632298@203.208.207.212) State ROUTING 2011-06-24 13:29:35.891343 [DEBUG] mod_sofia.c:147 sofia/external/ 03996597632298@203.208.207.212 SOFIA ROUTING 2011-06-24 13:29:35.891343 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996597632298@203.208.207.212) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-06-24 13:29:35.891343 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996597632298@203.208.207.212) State ROUTING going to sleep 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_CONSUME_MEDIA 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996597632298@203.208.207.212) State CONSUME_MEDIA 2011-06-24 13:29:35.891343 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996597632298@203.208.207.212) State CONSUME_MEDIA going to sleep recv 307 bytes from udp/[203.208.207.212]:5060 at 05:29:36.404598: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKtpaQ28SQXKvem;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212> Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 774 bytes from udp/[203.208.207.212]:5060 at 05:29:37.615248: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKtpaQ28SQXKvem;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 INVITE Contact: <sip:203.208.207.212:5060> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE Content-Type: application/sdp Require: 100rel RSeq: 1 Content-Length: 231

v=0 o=- 508539113671071081 1 IN IP4 203.208.207.212 s=session c=IN IP4 203.208.207.201 t=0 0 m=audio 25120 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv ------------------------------------------------------------------------ send 651 bytes to udp/[203.208.207.212]:5060 at 05:29:37.615605: ------------------------------------------------------------------------ PRACK sip:203.208.207.212:5060 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKUZ3F43aUtvj1F Max-Forwards: 70 From: "" <sip:03996563750911@202.73.56.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110625 PRACK Contact: <sip:mod_sofia@202.73.56.46:5080> RAck: 1 14110624 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:37.107576 [INFO] sofia.c:729 sofia/external/ 03996597632298@203.208.207.212 Update Callee ID to "Outbound Call" <03996597632298> 2011-06-24 13:29:37.107576 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996597632298@203.208.207.212 entering state [proceeding][183] 2011-06-24 13:29:37.107576 [DEBUG] sofia.c:4657 Remote SDP: v=0 o=- 508539113671071081 1 IN IP4 203.208.207.212 s=session c=IN IP4 203.208.207.201 t=0 0 m=audio 25120 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=ptime:20 2011-06-24 13:29:37.107576 [DEBUG] sofia_glue.c:4467 Audio Codec Compare [G729:18:8000:20:8000]/[G729:18:8000:20:8000] 2011-06-24 13:29:37.107576 [DEBUG] sofia_glue.c:2757 Set Codec sofia/external/03996597632298@203.208.207.212 G729/8000 20 ms 160 samples 8000 bits 2011-06-24 13:29:37.108995 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf send payload to 101 2011-06-24 13:29:37.108995 [DEBUG] sofia_glue.c:2987 AUDIO RTP [sofia/external/03996597632298@203.208.207.212] 10.1.1.46 port 30970 -> 203.208.207.201 port 25120 codec: 18 ms: 20 2011-06-24 13:29:37.108995 [DEBUG] switch_rtp.c:1607 Starting timer [soft] 160 bytes per 20ms 2011-06-24 13:29:37.109893 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf send payload to 101 2011-06-24 13:29:37.109893 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf receive payload to 101 2011-06-24 13:29:37.109893 [NOTICE] sofia_glue.c:3680 Pre-Answer sofia/external/03996597632298@203.208.207.212! 2011-06-24 13:29:37.109893 [DEBUG] switch_channel.c:2627 (sofia/external/ 03996597632298@203.208.207.212) Callstate Change RINGING -> EARLY 2011-06-24 13:29:37.109893 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/external/03996597632298@203.208.207.212] 2011-06-24 13:29:37.109893 [DEBUG] mod_commands.c:3205 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_CONSUME_MEDIA -> CS_EXECUTE 2011-06-24 13:29:37.109893 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:37.111618 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_EXECUTE 2011-06-24 13:29:37.111618 [DEBUG] switch_core_state_machine.c:366 (sofia/external/03996597632298@203.208.207.212) State EXECUTE 2011-06-24 13:29:37.111618 [DEBUG] mod_sofia.c:240 sofia/external/ 03996597632298@203.208.207.212 SOFIA EXECUTE 2011-06-24 13:29:37.111618 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996597632298@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996597632298@203.208.207.212 park() recv 382 bytes from udp/[203.208.207.212]:5060 at 05:29:37.620736: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKUZ3F43aUtvj1F;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110625 PRACK Contact: <sip:203.208.207.212:5060> Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:37.160714 [DEBUG] switch_rtp.c:2933 Correct ip/port confirmed. recv 512 bytes from udp/[203.208.207.212]:5060 at 05:29:45.146388: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKtpaQ28SQXKvem;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 INVITE Contact: <sip:203.208.207.212:5060> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE Require: 100rel RSeq: 2 Content-Length: 0

------------------------------------------------------------------------ send 651 bytes to udp/[203.208.207.212]:5060 at 05:29:45.146628: ------------------------------------------------------------------------ PRACK sip:203.208.207.212:5060 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKv8v85yUyQ58KB Max-Forwards: 70 From: "" <sip:03996563750911@202.73.56.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110626 PRACK Contact: <sip:mod_sofia@202.73.56.46:5080> RAck: 2 14110624 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:44.639310 [INFO] sofia.c:729 sofia/external/ 03996597632298@203.208.207.212 Update Callee ID to "03996597632298" <03996597632298> 2011-06-24 13:29:44.639310 [DEBUG] sofia.c:4641 Channel sofia/external/ 03996597632298@203.208.207.212 skipping state [proceeding][183] recv 382 bytes from udp/[203.208.207.212]:5060 at 05:29:45.151718: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKv8v85yUyQ58KB;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110626 PRACK Contact: <sip:203.208.207.212:5060> Content-Length: 0

------------------------------------------------------------------------ recv 529 bytes from udp/[203.208.207.212]:5060 at 05:29:47.446072: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKtpaQ28SQXKvem;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 INVITE Contact: <sip:203.208.207.212:5060> Allow-Events: refer Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE Supported: 100rel, timer, replaces Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:46.938477 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996597632298@203.208.207.212 entering state [completing][200] send 405 bytes to udp/[203.208.207.212]:5060 at 05:29:47.446869: ------------------------------------------------------------------------ ACK sip:203.208.207.212:5060 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKXHp17Sc2meZ6p Max-Forwards: 70 From: "" <sip:03996563750911@202.73.56.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110624 ACK Contact: <sip:mod_sofia@202.73.56.46:5080> Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:46.939738 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996597632298@203.208.207.212 entering state [ready][200] 2011-06-24 13:29:46.939738 [DEBUG] switch_channel.c:2782 (sofia/external/ 03996597632298@203.208.207.212) Callstate Change EARLY -> ACTIVE 2011-06-24 13:29:46.939738 [NOTICE] sofia.c:5175 Channel [sofia/external/ 03996597632298@203.208.207.212] has been answered 2011-06-24 13:29:46.942763 [DEBUG] switch_scheduler.c:214 Added task 27 switch_ivr_schedule_hangup (c0bd700d-913c-42ad-b68f-81001bf658b8) to run at 1308896986 2011-06-24 13:29:46.944563 [DEBUG] switch_core_session.c:954 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:1971 variable string 0 = [origination_caller_id_number=03996597632298] 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:1971 variable string 1 = [ccd_session_id=20110624132936888918] 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:1971 variable string 2 = [sip_cid_type=pid] 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:1971 variable string 3 = [privacy=yes] 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:1971 variable string 4 = [continue_on_fail=false] 2011-06-24 13:29:46.945633 [NOTICE] switch_channel.c:808 New Channel sofia/external/03996563750911@203.208.207.212[817124e6-26fe-46cc-af55-89715abdfced] 2011-06-24 13:29:46.945633 [DEBUG] mod_sofia.c:4129 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_NEW -> CS_INIT 2011-06-24 13:29:46.945633 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_INIT 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996563750911@203.208.207.212) State INIT 2011-06-24 13:29:46.945633 [DEBUG] mod_sofia.c:84 sofia/external/ 03996563750911@203.208.207.212 SOFIA INIT 2011-06-24 13:29:46.945633 [DEBUG] mod_sofia.c:124 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_INIT -> CS_ROUTING 2011-06-24 13:29:46.945633 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996563750911@203.208.207.212) State INIT going to sleep 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_ROUTING 2011-06-24 13:29:46.945633 [DEBUG] switch_channel.c:1657 (sofia/external/ 03996563750911@203.208.207.212) Callstate Change DOWN -> RINGING 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996563750911@203.208.207.212) State ROUTING 2011-06-24 13:29:46.945633 [DEBUG] mod_sofia.c:147 sofia/external/ 03996563750911@203.208.207.212 SOFIA ROUTING 2011-06-24 13:29:46.945633 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996563750911@203.208.207.212) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-06-24 13:29:46.945633 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996563750911@203.208.207.212) State ROUTING going to sleep 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_CONSUME_MEDIA send 999 bytes to udp/[203.208.207.212]:5060 at 05:29:47.454251: ------------------------------------------------------------------------ INVITE sip:03996563750911@203.208.207.212 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKytFt9mX5HQNSj Max-Forwards: 70 From: "" <sip:03996597632298@202.73.56.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212> Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad92011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:378 (sofia/external/ 03996563750911@203.208.207.212) State CONSUME_MEDIA CSeq: 14110629 INVITE Contact: <sip:mod_sofia@202.73.56.46:5080> 2011-06-24 13:29:46.945633 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996563750911@203.208.207.212) State CONSUME_MEDIA going to sleep User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, 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:03996597632298@202.73.56.46> v=0 o=FreeSWITCH 1308872756 1308872757 IN IP4 202.73.56.46 s=FreeSWITCH c=IN IP4 202.73.56.46 t=0 0 m=audio 20630 RTP/AVP 18 3 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2011-06-24 13:29:46.946974 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996563750911@203.208.207.212 entering state [calling][0] recv 307 bytes from udp/[203.208.207.212]:5060 at 05:29:47.460017: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKytFt9mX5HQNSj;received=10.1.1.46 From: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212> Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 INVITE Content-Length: 0 ------------------------------------------------------------------------ 2011-06-24 13:29:46.960900 [DEBUG] switch_ivr.c:563 sofia/external/ 03996597632298@203.208.207.212 Command Execute playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav) EXECUTE sofia/external/03996597632298@203.208.207.212playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav) 2011-06-24 13:29:46.960900 [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-24 13:29:46.960900 [WARNING] switch_core_file.c:189 File has 2 channels, muxing to mono will occur. 2011-06-24 13:29:46.960900 [DEBUG] switch_ivr_play_say.c:1244 Codec Activated L16@8000hz 2 channels 20ms 2011-06-24 13:29:46.981203 [INFO] mod_com_g729.c:119 ENCODER CREATE - 0x2aaab80894b8 0x5112110 recv 774 bytes from udp/[203.208.207.212]:5060 at 05:29:48.623941: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKytFt9mX5HQNSj;received=10.1.1.46 From: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 INVITE Contact: <sip:203.208.207.212:5060> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE Content-Type: application/sdp Require: 100rel RSeq: 1 Content-Length: 231

v=0 o=- 508550174225779858 1 IN IP4 203.208.207.212 s=session c=IN IP4 203.208.207.202 t=0 0 m=audio 25150 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv ------------------------------------------------------------------------ send 651 bytes to udp/[203.208.207.212]:5060 at 05:29:48.624297: ------------------------------------------------------------------------ PRACK sip:203.208.207.212:5060 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKZ38jBge9e0Bce Max-Forwards: 70 From: "" <sip:03996597632298@202.73.56.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110630 PRACK Contact: <sip:mod_sofia@202.73.56.46:5080> RAck: 1 14110629 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:48.115941 [INFO] sofia.c:729 sofia/external/ 03996563750911@203.208.207.212 Update Callee ID to "Outbound Call" <03996563750911> 2011-06-24 13:29:48.115941 [DEBUG] sofia.c:4646 Channel sofia/external/ 03996563750911@203.208.207.212 entering state [proceeding][183] 2011-06-24 13:29:48.115941 [DEBUG] sofia.c:4657 Remote SDP: v=0 o=- 508550174225779858 1 IN IP4 203.208.207.212 s=session c=IN IP4 203.208.207.202 t=0 0 m=audio 25150 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=ptime:20 2011-06-24 13:29:48.115941 [DEBUG] sofia_glue.c:4467 Audio Codec Compare [G729:18:8000:20:8000]/[G729:18:8000:20:8000] 2011-06-24 13:29:48.115941 [DEBUG] sofia_glue.c:2757 Set Codec sofia/external/03996563750911@203.208.207.212 G729/8000 20 ms 160 samples 8000 bits 2011-06-24 13:29:48.115941 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf send payload to 101 2011-06-24 13:29:48.115941 [DEBUG] sofia_glue.c:2987 AUDIO RTP [sofia/external/03996563750911@203.208.207.212] 10.1.1.46 port 20630 -> 203.208.207.202 port 25150 codec: 18 ms: 20 2011-06-24 13:29:48.115941 [DEBUG] switch_rtp.c:1607 Starting timer [soft] 160 bytes per 20ms 2011-06-24 13:29:48.119065 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf send payload to 101 2011-06-24 13:29:48.119065 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf receive payload to 101 2011-06-24 13:29:48.119065 [NOTICE] sofia_glue.c:3680 Pre-Answer sofia/external/03996563750911@203.208.207.212! 2011-06-24 13:29:48.119065 [DEBUG] switch_channel.c:2627 (sofia/external/ 03996563750911@203.208.207.212) Callstate Change RINGING -> EARLY 2011-06-24 13:29:48.120495 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/external/03996563750911@203.208.207.212] 2011-06-24 13:29:48.120495 [DEBUG] mod_commands.c:3205 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_CONSUME_MEDIA -> CS_EXECUTE 2011-06-24 13:29:48.120495 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.120495 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_EXECUTE 2011-06-24 13:29:48.120495 [DEBUG] switch_core_state_machine.c:366 (sofia/external/03996563750911@203.208.207.212) State EXECUTE 2011-06-24 13:29:48.120495 [DEBUG] mod_sofia.c:240 sofia/external/ 03996563750911@203.208.207.212 SOFIA EXECUTE 2011-06-24 13:29:48.120495 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996563750911@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996563750911@203.208.207.212 park() 2011-06-24 13:29:48.122782 [DEBUG] switch_core_session.c:954 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] recv 382 bytes from udp/[203.208.207.212]:5060 at 05:29:48.630447: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKZ38jBge9e0Bce;received=10.1.1.46 From: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110630 PRACK Contact: <sip:203.208.207.212:5060> Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:48.122782 [DEBUG] switch_ivr.c:563 sofia/external/ 03996597632298@203.208.207.212 Command Execute playback(tone_stream://%(2000,4000,440,480);loops=10) EXECUTE sofia/external/03996597632298@203.208.207.212playback(tone_stream://%(2000,4000,440,480);loops=10) 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_bridge.c:1480 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_EXECUTE -> CS_HIBERNATE 2011-06-24 13:29:48.124434 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_bridge.c:1482 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_EXECUTE -> CS_HIBERNATE 2011-06-24 13:29:48.124434 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.124434 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.124434 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_play_say.c:1244 Codec Activated L16@8000hz 1 channels 20ms 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_play_say.c:1581 done playing file 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:366 (sofia/external/03996563750911@203.208.207.212) State EXECUTE going to sleep 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_HIBERNATE 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996563750911@203.208.207.212) State HIBERNATE 2011-06-24 13:29:48.124434 [DEBUG] mod_sofia.c:221 sofia/external/ 03996563750911@203.208.207.212 SOFIA HIBERNATE 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_HIBERNATE -> CS_RESET 2011-06-24 13:29:48.124434 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996563750911@203.208.207.212) State HIBERNATE going to sleep 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_RESET 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996563750911@203.208.207.212) State RESET 2011-06-24 13:29:48.124434 [DEBUG] mod_sofia.c:165 sofia/external/ 03996563750911@203.208.207.212 SOFIA RESET 2011-06-24 13:29:48.124434 [DEBUG] switch_ivr_bridge.c:716 sofia/external/ 03996563750911@203.208.207.212 CUSTOM RESET 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:66 sofia/external/03996563750911@203.208.207.212 Standard RESET 2011-06-24 13:29:48.124434 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996563750911@203.208.207.212) State RESET going to sleep 2011-06-24 13:29:48.126015 [DEBUG] switch_core_session.c:709 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_play_say.c:1581 done playing file 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:366 (sofia/external/03996597632298@203.208.207.212) State EXECUTE going to sleep 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_HIBERNATE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996597632298@203.208.207.212) State HIBERNATE 2011-06-24 13:29:48.142264 [DEBUG] mod_sofia.c:221 sofia/external/ 03996597632298@203.208.207.212 SOFIA HIBERNATE 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_HIBERNATE -> CS_RESET 2011-06-24 13:29:48.142264 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996597632298@203.208.207.212) State HIBERNATE going to sleep 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_RESET 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996597632298@203.208.207.212) State RESET 2011-06-24 13:29:48.142264 [DEBUG] mod_sofia.c:165 sofia/external/ 03996597632298@203.208.207.212 SOFIA RESET 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:716 sofia/external/ 03996597632298@203.208.207.212 CUSTOM RESET 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:723 (sofia/external/ 03996597632298@203.208.207.212) State Change CS_RESET -> CS_SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996597632298@203.208.207.212) State RESET going to sleep 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996597632298@203.208.207.212) State SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:741 sofia/external/ 03996597632298@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:761 (sofia/external/ 03996563750911@203.208.207.212) State Change CS_RESET -> CS_SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996563750911@203.208.207.212) State SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_ivr_bridge.c:741 sofia/external/ 03996563750911@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:204 sofia/external/03996563750911@203.208.207.212 Standard SOFT_EXECUTE 2011-06-24 13:29:48.142264 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996563750911@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@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@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@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_HANGUP 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535 (sofia/external/ 03996597632298@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@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@203.208.207.212) State HANGUP 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel sofia/external/ 03996563750911@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@203.208.207.212 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal sofia/external/03996597632298@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996597632298@203.208.207.212) State SOFT_EXECUTE going to sleep 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_HANGUP 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:46 sofia/external/03996563750911@203.208.207.212 Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:557 (sofia/external/03996563750911@203.208.207.212) State HANGUP going to sleep 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:351 (sofia/external/03996563750911@203.208.207.212) State Change CS_HANGUP -> CS_REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:617 (sofia/external/03996563750911@203.208.207.212) State REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996563750911@203.208.207.212 Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:617 (sofia/external/03996563750911@203.208.207.212) State REPORTING going to sleep 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:557 (sofia/external/03996597632298@203.208.207.212) State HANGUP 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel sofia/external/ 03996597632298@203.208.207.212 hanging up, cause: ORIGINATOR_CANCEL 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:500 Sending BYE to sofia/external/03996597632298@203.208.207.212 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:345 (sofia/external/03996563750911@203.208.207.212) State Change CS_REPORTING -> CS_DESTROY 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1288 Session 52 (sofia/external/03996563750911@203.208.207.212) Locked, Waiting on external entities 2011-06-24 13:29:48.161779 [NOTICE] switch_core_session.c:1306 Session 52 (sofia/external/03996563750911@203.208.207.212) Ended 2011-06-24 13:29:48.161779 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996563750911@203.208.207.212 [CS_DESTROY] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996563750911@203.208.207.212) Callstate Change HANGUP -> DOWN 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:452 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_DESTROY 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996563750911@203.208.207.212) State DESTROY 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:362 sofia/external/ 03996563750911@203.208.207.212 SOFIA DESTROY 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:78 ENCODER DESTROYX - 0x2aaaac03fff8 (nil) 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:79 DECODER DESTROYX - 0x2aaaac03fff8 (nil) 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:78 ENCODER DESTROYX - 0x2aaaac068fc8 (nil) 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:79 DECODER DESTROYX - 0x2aaaac068fc8 (nil) 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:46 sofia/external/03996597632298@203.208.207.212 Standard HANGUP, cause: ORIGINATOR_CANCEL 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:60 sofia/external/03996563750911@203.208.207.212 Standard DESTROY 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:557 (sofia/external/03996597632298@203.208.207.212) State HANGUP going to sleep 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996563750911@203.208.207.212) State DESTROY going to sleep 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:351 (sofia/external/03996597632298@203.208.207.212) State Change CS_HANGUP -> CS_REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:617 (sofia/external/03996597632298@203.208.207.212) State REPORTING 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996597632298@203.208.207.212 Standard REPORTING, cause: ORIGINATOR_CANCEL 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:617 (sofia/external/03996597632298@203.208.207.212) State REPORTING going to sleep send 390 bytes to udp/[203.208.207.212]:5060 at 05:29:48.671783: ------------------------------------------------------------------------ CANCEL sip:03996563750911@203.208.207.212 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKytFt9mX5HQNSj Max-Forwards: 70 From: "" <sip:03996597632298@202.73.56.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212> Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 CANCEL Reason: Q.850;cause=27;text="DESTINATION_OUT_OF_ORDER" Content-Length: 0 ------------------------------------------------------------------------ 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:345 (sofia/external/03996597632298@203.208.207.212) State Change CS_REPORTING -> CS_DESTROY 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1288 Session 51 (sofia/external/03996597632298@203.208.207.212) Locked, Waiting on external entities 2011-06-24 13:29:48.161779 [NOTICE] switch_core_session.c:1306 Session 51 (sofia/external/03996597632298@203.208.207.212) Ended 2011-06-24 13:29:48.161779 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996597632298@203.208.207.212 [CS_DESTROY] send 677 bytes to udp/[203.208.207.212]:5060 at 05:29:48.671936: ------------------------------------------------------------------------ BYE sip:203.208.207.212:5060 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bK0c2BDBZcc91yS Max-Forwards: 70 From: "" <sip:03996563750911@202.73.56.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110627 BYE Contact: <sip:mod_sofia@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, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Reason: FreeSWITCH;cause=487;text="ORIGINATOR_CANCEL" Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996597632298@203.208.207.212) Callstate Change HANGUP -> DOWN 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:452 (sofia/external/03996597632298@203.208.207.212) Running State Change CS_DESTROY 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996597632298@203.208.207.212) State DESTROY 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:362 sofia/external/ 03996597632298@203.208.207.212 SOFIA DESTROY 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:78 ENCODER DESTROYX - 0x2aaab8030878 (nil) 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:79 DECODER DESTROYX - 0x2aaab8030878 (nil) 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:78 ENCODER DESTROYX - 0x2aaab80894b8 0x5112110 2011-06-24 13:29:48.161779 [INFO] mod_com_g729.c:79 DECODER DESTROYX - 0x2aaab80894b8 (nil) 2011-06-24 13:29:48.166430 [INFO] mod_com_g729.c:83 ENCODER DESTROY - 0x2aaab80894b8 0x5112110 2011-06-24 13:29:48.166430 [DEBUG] switch_core_state_machine.c:60 sofia/external/03996597632298@203.208.207.212 Standard DESTROY 2011-06-24 13:29:48.166430 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996597632298@203.208.207.212) State DESTROY going to sleep recv 383 bytes from udp/[203.208.207.212]:5060 at 05:29:48.679561: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKytFt9mX5HQNSj;received=10.1.1.46 From: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D00000u000000013MCNME Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 CANCEL Contact: <sip:203.208.207.212:5060> Content-Length: 0

------------------------------------------------------------------------ recv 731 bytes from udp/[203.208.207.212]:5060 at 05:29:48.681395: ------------------------------------------------------------------------ UPDATE sip:mod_sofia@10.1.1.46:5080 SIP/2.0 Via: SIP/2.0/UDP 203.208.207.212:5060 ;branch=z9hG4bK00151746C47A8307FCE25ED9D752 From: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK To: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 46496 UPDATE Contact: <sip:03996563750911@203.208.207.212:5060> Content-Type: application/sdp Max-Forwards: 70 Supported: 100rel, timer, replaces Content-Length: 231

v=0 o=- 508550174225779858 2 IN IP4 203.208.207.212 s=session c=IN IP4 203.208.207.202 t=0 0 m=audio 25150 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=ptime:20 a=inactive ------------------------------------------------------------------------ send 895 bytes to udp/[203.208.207.212]:5060 at 05:29:48.681661: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 203.208.207.212:5060 ;branch=z9hG4bK00151746C47A8307FCE25ED9D752 From: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK To: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 46496 UPDATE Contact: <sip:mod_sofia@202.73.56.46:5080> User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 216

v=0 o=FreeSWITCH 1308872756 1308872758 IN IP4 202.73.56.46 s=FreeSWITCH c=IN IP4 202.73.56.46 t=0 0 m=audio 20630 RTP/AVP 18 101 3 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=inactive a=ptime:20 ------------------------------------------------------------------------ recv 411 bytes from udp/[203.208.207.212]:5060 at 05:29:48.681824: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bKytFt9mX5HQNSj;received=10.1.1.46 From: "" <sip:03996597632298@10.1.1.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 INVITE Reason: SIP;cause=487;text="Request Terminated" Content-Length: 0

------------------------------------------------------------------------ send 371 bytes to udp/[203.208.207.212]:5060 at 05:29:48.681913: ------------------------------------------------------------------------ ACK sip:03996563750911@203.208.207.212 SIP/2.0 Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKytFt9mX5HQNSj Max-Forwards: 70 From: "" <sip:03996597632298@202.73.56.46>;tag=62eBXSt93tr7F To: <sip:03996563750911@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RV0KORLQK Call-ID: d0f42376-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110629 ACK Content-Length: 0

------------------------------------------------------------------------ recv 380 bytes from udp/[203.208.207.212]:5060 at 05:29:48.683041: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.1.46:5080 ;rport=5080;branch=z9hG4bK0c2BDBZcc91yS;received=10.1.1.46 From: "" <sip:03996563750911@10.1.1.46>;tag=5SNjUy956H2mm To: <sip:03996597632298@203.208.207.212

;tag=2QGB951HCR30000E1D0001Ll000B8RX0S6R1TX Call-ID: ca5d29b7-18c5-122f-3387-0015c5fc7ad9 CSeq: 14110627 BYE Contact: <sip:203.208.207.212:5060> Content-Length: 0

------------------------------------------------------------------------ 2011-06-24 13:29:48.524051 [DEBUG] switch_scheduler.c:138 Deleting task 27 switch_ivr_schedule_hangup (c0bd700d-913c-42ad-b68f-81001bf658b8) On Fri, Jun 24, 2011 at 2:41 PM, Michael Collins <msc@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@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@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@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@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@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@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_HANGUP 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535 (sofia/external/ 03996597632298@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@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@203.208.207.212) State HANGUP 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel sofia/external/ 03996563750911@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@203.208.207.212 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal sofia/external/03996597632298@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK]

On Fri, Jun 17, 2011 at 10:52 AM, David Ma <mays.david@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@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@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@203.208.207.212 [ea57b74b-a8c2-4fea-9683-98054dc03a79] 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:4129 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State INIT 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:84 sofia/external/03996590031055@203.208.207.212 SOFIA INIT send 984 bytes to udp/[203.208.207.212]:5060 at 03:09:55.477997:

------------------------------------------------------------------------ INVITE sip:03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212> Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501633 INVITE Contact: <sip:mod_sofia@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.371674 [DEBUG] sofia.c:4646 Channel sofia/external/03996590031055@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@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@203.208.207.212) Running State Change CS_ROUTING 2011-06-10 11:09:55.373478 [DEBUG] switch_channel.c:1657 (sofia/external/03996590031055@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@203.208.207.212) State ROUTING 2011-06-10 11:09:55.373478 [DEBUG] mod_sofia.c:147 sofia/external/03996590031055@203.208.207.212 SOFIA ROUTING 2011-06-10 11:09:55.373478 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996590031055@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@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@203.208.207.212) State CONSUME_MEDIA 2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@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@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@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@203.208.207.212! 2011-06-10 11:09:56.573731 [DEBUG] switch_channel.c:2627 (sofia/external/03996590031055@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@203.208.207.212] 2011-06-10 11:09:56.573731 [DEBUG] mod_commands.c:3205 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State EXECUTE 2011-06-10 11:09:56.575262 [DEBUG] mod_sofia.c:240 sofia/external/03996590031055@203.208.207.212 SOFIA EXECUTE 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996590031055@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212 >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501633 ACK Contact: <sip:mod_sofia@202.73.56.46:5080> Content-Length: 0

------------------------------------------------------------------------ 2011-06-10 11:10:27.260267 [DEBUG] sofia.c:4646 Channel sofia/external/03996590031055@203.208.207.212 entering state [ready][200] 2011-06-10 11:10:27.260267 [DEBUG] switch_channel.c:2782 (sofia/external/03996590031055@203.208.207.212) Callstate Change EARLY -> ACTIVE 2011-06-10 11:10:27.260267 [NOTICE] sofia.c:5175 Channel [sofia/external/03996590031055@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@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@203.208.207.212 [30228d2b-756a-4a98-871d-db63a2955b52] 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:4129 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State INIT 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:84 sofia/external/03996563750914@203.208.207.212 SOFIA INIT 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:124 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356 (sofia/external/03996563750914@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@203.208.207.212) Running State Change CS_ROUTING 2011-06-10 11:10:27.266218 [DEBUG] switch_channel.c:1657 (sofia/external/03996563750914@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@203.208.207.212) State ROUTING send 984 bytes to udp/[203.208.207.212]:5060 at 03:10:27.373220:

------------------------------------------------------------------------ INVITE sip:03996563750914@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@203.208.207.212 SOFIA ROUTING

Max-Forwards: 70 From: "" <sip:03996590031055@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@203.208.207.212> Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9 CSeq: 13501649 INVITE Contact: <sip:mod_sofia@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@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@203.208.207.212 entering state [calling][0] 2011-06-10 11:10:27.267630 [DEBUG] switch_ivr_originate.c:66 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:359 (sofia/external/03996563750914@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@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@203.208.207.212) State CONSUME_MEDIA 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378 (sofia/external/03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@203.208.207.212 Command Execute playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav) EXECUTE sofia/external/03996590031055@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@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212! 2011-06-10 11:10:28.514938 [DEBUG] switch_channel.c:2627 (sofia/external/03996563750914@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@203.208.207.212] 2011-06-10 11:10:28.514938 [DEBUG] mod_commands.c:3205 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State EXECUTE 2011-06-10 11:10:28.515884 [DEBUG] mod_sofia.c:240 sofia/external/03996563750914@203.208.207.212 SOFIA EXECUTE 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:157 sofia/external/03996563750914@203.208.207.212 Standard EXECUTE EXECUTE sofia/external/03996563750914@203.208.207.212 park() 2011-06-10 11:10:28.516887 [DEBUG] switch_core_session.c:954 Send signal sofia/external/03996590031055@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1480 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1482 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996563750914@203.208.207.212 [BREAK] 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal sofia/external/03996590031055@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@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@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@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@203.208.207.212) State HIBERNATE 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:221 sofia/external/03996563750914@203.208.207.212 SOFIA HIBERNATE 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996563750914@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@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@203.208.207.212) State RESET 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:165 sofia/external/03996563750914@203.208.207.212 SOFIA RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:716 sofia/external/03996563750914@203.208.207.212 CUSTOM RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:66 sofia/external/03996563750914@203.208.207.212 Standard RESET 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996563750914@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@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212) State HIBERNATE 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:221 sofia/external/03996590031055@203.208.207.212 SOFIA HIBERNATE 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:731 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381 (sofia/external/03996590031055@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@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@203.208.207.212) State RESET 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:165 sofia/external/03996590031055@203.208.207.212 SOFIA RESET 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:716 sofia/external/03996590031055@203.208.207.212 CUSTOM RESET 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:723 (sofia/external/03996590031055@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362 (sofia/external/03996590031055@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@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:761 (sofia/external/03996563750914@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:204 sofia/external/03996563750914@203.208.207.212 Standard SOFT_EXECUTE 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996563750914@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@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@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@203.208.207.212 [KILL] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750914@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@203.208.207.212) Running State Change CS_HANGUP 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535 (sofia/external/03996590031055@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@203.208.207.212) State HANGUP 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel sofia/external/03996563750914@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@203.208.207.212 send 390 bytes to udp/[203.208.207.212]:5060 at 03:10:30.818391:

------------------------------------------------------------------------ CANCEL sip:03996563750914@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@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750914@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@203.208.207.212) State REPORTING 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996563750914@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@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@203.208.207.212 [KILL] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996590031055@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:372 (sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1288 Session 40 (sofia/external/03996563750914@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@203.208.207.212) Ended 2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996563750914@203.208.207.212 [CS_DESTROY] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996563750914@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@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@203.208.207.212) State DESTROY 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:362 sofia/external/03996563750914@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@203.208.207.212 Standard DESTROY 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996563750914@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@203.208.207.212) State HANGUP 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel sofia/external/03996590031055@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@203.208.207.212 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46 sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996590031055@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@203.208.207.212) State REPORTING 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:53 sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] 2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1288 Session 39 (sofia/external/03996590031055@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@203.208.207.212) Ended 2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/03996590031055@203.208.207.212 [CS_DESTROY] 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:449 (sofia/external/03996590031055@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@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@203.208.207.212) State DESTROY 2011-06-10 11:10:30.714001 [DEBUG] mod_sofia.c:362 sofia/external/03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@203.208.207.212 >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 CSeq: 13501634 BYE Contact: <sip:mod_sofia@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@203.208.207.212 Standard DESTROY 2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:462 (sofia/external/03996590031055@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@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@202.73.56.46>;tag=jDSe6ycN62Zar To: <sip:03996563750914@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@10.1.1.46>;tag=H4ZN43UH9S9Qc To: <sip:03996590031055@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-disconn... Sent from the freeswitch-users mailing list archive at Nabble.com.

_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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@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@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

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@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@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@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@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@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@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@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@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@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996563750911@203.208.207.212 [BREAK] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_state_machine.c:320 (sofia/external/03996563750911@203.208.207.212) Running State Change CS_HANGUP 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2535 (sofia/external/03996597632298@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@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@203.208.207.212) State HANGUP 2011-06-24 13:29:48.161779 [DEBUG] mod_sofia.c:457 Channel sofia/external/03996563750911@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@203.208.207.212 2011-06-24 13:29:48.161779 [DEBUG] switch_channel.c:2551 Send signal sofia/external/03996597632298@203.208.207.212 [KILL] 2011-06-24 13:29:48.161779 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/03996597632298@203.208.207.212 [BREAK]

On Fri, Jun 17, 2011 at 10:52 AM, David Ma <mays.david@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@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@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@203.208.207.212 > [ea57b74b-a8c2-4fea-9683-98054dc03a79] > 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:4129 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996590031055@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@203.208.207.212) State INIT > 2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:84 > sofia/external/03996590031055@203.208.207.212 SOFIA INIT > send 984 bytes to udp/[203.208.207.212]:5060 at 03:09:55.477997: > > ------------------------------------------------------------------------ > INVITE sip:03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc > To: <sip:03996590031055@203.208.207.212> > Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 > CSeq: 13501633 INVITE > Contact: <sip:mod_sofia@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@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@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@203.208.207.212 [BREAK] > 2011-06-10 11:09:55.371674 [DEBUG] sofia.c:4646 Channel > sofia/external/03996590031055@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@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@203.208.207.212) Running State Change > CS_ROUTING > 2011-06-10 11:09:55.373478 [DEBUG] switch_channel.c:1657 > (sofia/external/03996590031055@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@203.208.207.212) State ROUTING > 2011-06-10 11:09:55.373478 [DEBUG] mod_sofia.c:147 > sofia/external/03996590031055@203.208.207.212 SOFIA ROUTING > 2011-06-10 11:09:55.373478 [DEBUG] switch_ivr_originate.c:66 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359 > (sofia/external/03996590031055@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@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@203.208.207.212) State CONSUME_MEDIA > 2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378 > (sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: <sip:03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@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@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@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@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@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@203.208.207.212! > 2011-06-10 11:09:56.573731 [DEBUG] switch_channel.c:2627 > (sofia/external/03996590031055@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@203.208.207.212] > 2011-06-10 11:09:56.573731 [DEBUG] mod_commands.c:3205 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996590031055@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@203.208.207.212) State EXECUTE > 2011-06-10 11:09:56.575262 [DEBUG] mod_sofia.c:240 > sofia/external/03996590031055@203.208.207.212 SOFIA EXECUTE > 2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:157 > sofia/external/03996590031055@203.208.207.212 Standard EXECUTE > EXECUTE sofia/external/03996590031055@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@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@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@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@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@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@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@202.73.56.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@203.208.207.212 > >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW > Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 > CSeq: 13501633 ACK > Contact: <sip:mod_sofia@202.73.56.46:5080> > Content-Length: 0 > > > ------------------------------------------------------------------------ > 2011-06-10 11:10:27.260267 [DEBUG] sofia.c:4646 Channel > sofia/external/03996590031055@203.208.207.212 entering state > [ready][200] > 2011-06-10 11:10:27.260267 [DEBUG] switch_channel.c:2782 > (sofia/external/03996590031055@203.208.207.212) Callstate Change > EARLY -> > ACTIVE > 2011-06-10 11:10:27.260267 [NOTICE] sofia.c:5175 Channel > [sofia/external/03996590031055@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@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@203.208.207.212 > [30228d2b-756a-4a98-871d-db63a2955b52] > 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:4129 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996563750914@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@203.208.207.212) State INIT > 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:84 > sofia/external/03996563750914@203.208.207.212 SOFIA INIT > 2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:124 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356 > (sofia/external/03996563750914@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@203.208.207.212) Running State Change > CS_ROUTING > 2011-06-10 11:10:27.266218 [DEBUG] switch_channel.c:1657 > (sofia/external/03996563750914@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@203.208.207.212) State ROUTING > send 984 bytes to udp/[203.208.207.212]:5060 at 03:10:27.373220: > > ------------------------------------------------------------------------ > INVITE sip:03996563750914@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@203.208.207.212 SOFIA ROUTING > > Max-Forwards: 70 > From: "" <sip:03996590031055@202.73.56.46>;tag=jDSe6ycN62Zar > To: <sip:03996563750914@203.208.207.212> > Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9 > CSeq: 13501649 INVITE > Contact: <sip:mod_sofia@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@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@203.208.207.212 entering state > [calling][0] > 2011-06-10 11:10:27.267630 [DEBUG] switch_ivr_originate.c:66 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:359 > (sofia/external/03996563750914@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@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@203.208.207.212) State CONSUME_MEDIA > 2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378 > (sofia/external/03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar > To: <sip:03996563750914@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@203.208.207.212 Command Execute > playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav) > EXECUTE sofia/external/03996590031055@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@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@10.1.1.46>;tag=jDSe6ycN62Zar > To: > <sip:03996563750914@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@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@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@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@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@203.208.207.212! > 2011-06-10 11:10:28.514938 [DEBUG] switch_channel.c:2627 > (sofia/external/03996563750914@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@203.208.207.212] > 2011-06-10 11:10:28.514938 [DEBUG] mod_commands.c:3205 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996563750914@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@203.208.207.212) State EXECUTE > 2011-06-10 11:10:28.515884 [DEBUG] mod_sofia.c:240 > sofia/external/03996563750914@203.208.207.212 SOFIA EXECUTE > 2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:157 > sofia/external/03996563750914@203.208.207.212 Standard EXECUTE > EXECUTE sofia/external/03996563750914@203.208.207.212 park() > 2011-06-10 11:10:28.516887 [DEBUG] switch_core_session.c:954 Send > signal > sofia/external/03996590031055@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1480 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1482 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send > signal > sofia/external/03996563750914@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send > signal > sofia/external/03996590031055@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@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@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@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@203.208.207.212) State HIBERNATE > 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:221 > sofia/external/03996563750914@203.208.207.212 SOFIA HIBERNATE > 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:731 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381 > (sofia/external/03996563750914@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@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@203.208.207.212) State RESET > 2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:165 > sofia/external/03996563750914@203.208.207.212 SOFIA RESET > 2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:716 > sofia/external/03996563750914@203.208.207.212 CUSTOM RESET > 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:66 > sofia/external/03996563750914@203.208.207.212 Standard RESET > 2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362 > (sofia/external/03996563750914@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@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@10.1.1.46>;tag=jDSe6ycN62Zar > To: > <sip:03996563750914@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@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@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@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@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@203.208.207.212) State HIBERNATE > 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:221 > sofia/external/03996590031055@203.208.207.212 SOFIA HIBERNATE > 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:731 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381 > (sofia/external/03996590031055@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@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@203.208.207.212) State RESET > 2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:165 > sofia/external/03996590031055@203.208.207.212 SOFIA RESET > 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:716 > sofia/external/03996590031055@203.208.207.212 CUSTOM RESET > 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:723 > (sofia/external/03996590031055@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362 > (sofia/external/03996590031055@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@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE > 2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:761 > (sofia/external/03996563750914@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996563750914@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@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@203.208.207.212 CUSTOM SOFT_EXECUTE > 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:204 > sofia/external/03996563750914@203.208.207.212 Standard SOFT_EXECUTE > 2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372 > (sofia/external/03996563750914@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@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@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@203.208.207.212 [KILL] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send > signal > sofia/external/03996563750914@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996563750914@203.208.207.212) Running State Change > CS_HANGUP > 2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535 > (sofia/external/03996590031055@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@203.208.207.212) State HANGUP > 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel > sofia/external/03996563750914@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@203.208.207.212 > send 390 bytes to udp/[203.208.207.212]:5060 at 03:10:30.818391: > > ------------------------------------------------------------------------ > CANCEL sip:03996563750914@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@202.73.56.46>;tag=jDSe6ycN62Zar > To: <sip:03996563750914@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@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@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@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@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996563750914@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@203.208.207.212) State REPORTING > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:53 > sofia/external/03996563750914@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@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@203.208.207.212 [KILL] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send > signal > sofia/external/03996590031055@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:372 > (sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1288 Session > 40 > (sofia/external/03996563750914@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@203.208.207.212) Ended > 2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1308 Close > Channel > sofia/external/03996563750914@203.208.207.212 [CS_DESTROY] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:449 > (sofia/external/03996563750914@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@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@203.208.207.212) State DESTROY > 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:362 > sofia/external/03996563750914@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@203.208.207.212 Standard DESTROY > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462 > (sofia/external/03996563750914@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@203.208.207.212) State HANGUP > 2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel > sofia/external/03996590031055@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@203.208.207.212 > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46 > sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320 > (sofia/external/03996590031055@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@203.208.207.212) State REPORTING > 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:53 > sofia/external/03996590031055@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@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@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@203.208.207.212 [BREAK] > 2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1288 Session > 39 > (sofia/external/03996590031055@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@203.208.207.212) Ended > 2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1308 Close > Channel > sofia/external/03996590031055@203.208.207.212 [CS_DESTROY] > 2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:449 > (sofia/external/03996590031055@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@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@203.208.207.212) State DESTROY > 2011-06-10 11:10:30.714001 [DEBUG] mod_sofia.c:362 > sofia/external/03996590031055@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@202.73.56.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@203.208.207.212 > >;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW > Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9 > CSeq: 13501634 BYE > Contact: <sip:mod_sofia@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@203.208.207.212 Standard DESTROY > 2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:462 > (sofia/external/03996590031055@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@10.1.1.46>;tag=jDSe6ycN62Zar > To: > <sip:03996563750914@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@10.1.1.46>;tag=jDSe6ycN62Zar > To: > <sip:03996563750914@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@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@202.73.56.46>;tag=jDSe6ycN62Zar > To: > <sip:03996563750914@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@10.1.1.46>;tag=H4ZN43UH9S9Qc > To: > <sip:03996590031055@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-disconn... > Sent from the freeswitch-users mailing list archive at Nabble.com. > > _______________________________________________ > FreeSWITCH-users mailing list > FreeSWITCH-users@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@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@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@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@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

Hi Anthony, Thanks very much for the information. I appreciate your advice. It is great to learn about such a parameter. FS wiki has only a little description about this parameter. Is there any side effect, or caution for using such a parameter? Thanks, D.Ma On Wed, Jun 29, 2011 at 12:08 AM, Anthony Minessale < anthony.minessale@gmail.com> wrote:

The cases where you have this problem arise because you are originating to the B leg who answers 183 (early media) then hangs up before the call was answered.

set the channel variable uuid_bridge_continue_on_cancel=true on the A leg to change the behavior to what you want.

On Mon, Jun 27, 2011 at 10:09 AM, Michael Collins <msc@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@gmail.com> wrote:

...

Hi Michael,

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE

FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

Hi Anthony, I've tried channel variable uuid_bridge_continue_on_cancel=true. However, this doesn't solve the problem. The log is in the following on pastebin, please kindly help investigate why. http://pastebin.freeswitch.org/16839 Thanks a lot! Best regards, D.Ma On Wed, Jun 29, 2011 at 10:53 PM, Anthony Minessale < anthony.minessale@gmail.com> wrote:

The only side effect is that it will give you the behavior you want in this particular situation.

On Wed, Jun 29, 2011 at 4:35 AM, David Ma <mays.david@gmail.com> wrote:

...

Hi Anthony,

Thanks very much for the information. I appreciate your advice. It is great to learn about such a parameter.

FS wiki has only a little description about this parameter. Is there any side effect, or caution for using such a parameter?

Thanks, D.Ma

On Wed, Jun 29, 2011 at 12:08 AM, Anthony Minessale <anthony.minessale@gmail.com> wrote:

...

The cases where you have this problem arise because you are originating to the B leg who answers 183 (early media) then hangs up before the call was answered.

set the channel variable uuid_bridge_continue_on_cancel=true on the A leg to change the behavior to what you want.

On Mon, Jun 27, 2011 at 10:09 AM, Michael Collins <msc@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@gmail.com> wrote:

...

Hi Michael,

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE

FreeSWITCH-users mailing list FreeSWITCH-users@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE

FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

FYI, Tony is on vacation for a bit, so we'll have to do our best without him. Could you please do two things? First, turn off the sofia debugging. The SIP trace is fine, but all that other stuff is just noise. Second, can you show the call log from the very beginning, including any dialplan hunting. Thanks, MC On Mon, Jul 18, 2011 at 2:25 AM, David Ma <mays.david@gmail.com> wrote:

Hello Anthony,

The same log in better formatting is here:

http://pastebin.freeswitch.org/16840

Regards, D.Ma

On Mon, Jul 18, 2011 at 5:18 PM, David Ma <mays.david@gmail.com> wrote:

...

Hi Anthony,

I've tried channel variable uuid_bridge_continue_on_cancel=true. However, this doesn't solve the problem. The log is in the following on pastebin, please kindly help investigate why.

http://pastebin.freeswitch.org/16839

Thanks a lot!

Best regards, D.Ma

On Wed, Jun 29, 2011 at 10:53 PM, Anthony Minessale < anthony.minessale@gmail.com> wrote:

...

The only side effect is that it will give you the behavior you want in this particular situation.

On Wed, Jun 29, 2011 at 4:35 AM, David Ma <mays.david@gmail.com> wrote:

...

Hi Anthony,

Thanks very much for the information. I appreciate your advice. It is great to learn about such a parameter.

FS wiki has only a little description about this parameter. Is there any side effect, or caution for using such a parameter?

Thanks, D.Ma

On Wed, Jun 29, 2011 at 12:08 AM, Anthony Minessale <anthony.minessale@gmail.com> wrote:

...

The cases where you have this problem arise because you are originating to the B leg who answers 183 (early media) then hangs up before the call was answered.

set the channel variable uuid_bridge_continue_on_cancel=true on the A leg to change the behavior to what you want.

On Mon, Jun 27, 2011 at 10:09 AM, Michael Collins <msc@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@gmail.com> wrote: > > Hi Michael, >

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE

FreeSWITCH-users mailing list FreeSWITCH-users@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE

FreeSWITCH-users mailing list FreeSWITCH-users@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@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org