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

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.