[Freeswitch-users] Leg-A is automatically disconnected on Leg-B orginate failure
dma
mays.david at gmail.com
Thu Jun 16 12:32:31 MSD 2011
I am creating a call-back solution. After leg-A answers, I originate leg-B
call. After receiving SIP 183 from Leg-B, I bridge the 2 legs. However, in
some cases, leg-A is automatically disconnected by FreeSwitch on leg-B
failure, for example, DESTINATION_OUT_OF_ORDER. The application is not given
a chance to handle leg-B failure event. This should not be a correct
scenario because I never set "hangup-after-bridge", which is false by
default.
The right way should be, FreeSwitch doesn't hang up leg-A automatically, but
give a chance for the application to decide what to do.
Please see the logs below:
=================================================
2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971 variable
string 0 = [origination_caller_id_number=03996563750914]
2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971 variable
string 1 = [originate_timeout=30]
2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971 variable
string 2 = [ccd_session_id=20110610105829676824]
2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971 variable
string 3 = [sip_cid_type=pid]
2011-06-10 11:09:55.370506 [DEBUG] switch_ivr_originate.c:1971 variable
string 4 = [privacy=yes]
2011-06-10 11:09:55.370506 [NOTICE] switch_channel.c:808 New Channel
sofia/external/03996590031055 at 203.208.207.212
[ea57b74b-a8c2-4fea-9683-98054dc03a79]
2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:4129
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_NEW ->
CS_INIT
2011-06-10 11:09:55.370506 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change CS_INIT
2011-06-10 11:09:55.370506 [DEBUG] switch_core_state_machine.c:356
(sofia/external/03996590031055 at 203.208.207.212) State INIT
2011-06-10 11:09:55.370506 [DEBUG] mod_sofia.c:84
sofia/external/03996590031055 at 203.208.207.212 SOFIA INIT
send 984 bytes to udp/[203.208.207.212]:5060 at 03:09:55.477997:
------------------------------------------------------------------------
INVITE sip:03996590031055 at 203.208.207.212 SIP/2.0
Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKXjQ7eFpKypy5D
Max-Forwards: 70
From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
To: <sip:03996590031055 at 203.208.207.212>
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Contact: <sip:mod_sofia at 202.73.56.46:5080>
User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, refer
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 204
X-FS-Support: update_display
P-Asserted-Identity: "" <sip:03996563750914 at 202.73.56.46>
v=0
o=FreeSWITCH 1307645395 1307645396 IN IP4 202.73.56.46
s=FreeSWITCH
c=IN IP4 202.73.56.46
t=0 0
m=audio 30000 RTP/AVP 18 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2011-06-10 11:09:55.371674 [DEBUG] mod_sofia.c:124
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_INIT ->
CS_ROUTING
2011-06-10 11:09:55.371674 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:09:55.371674 [DEBUG] sofia.c:4646 Channel
sofia/external/03996590031055 at 203.208.207.212 entering state [calling][0]
2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:356
(sofia/external/03996590031055 at 203.208.207.212) State INIT going to sleep
2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_ROUTING
2011-06-10 11:09:55.373478 [DEBUG] switch_channel.c:1657
(sofia/external/03996590031055 at 203.208.207.212) Callstate Change DOWN ->
RINGING
2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359
(sofia/external/03996590031055 at 203.208.207.212) State ROUTING
2011-06-10 11:09:55.373478 [DEBUG] mod_sofia.c:147
sofia/external/03996590031055 at 203.208.207.212 SOFIA ROUTING
2011-06-10 11:09:55.373478 [DEBUG] switch_ivr_originate.c:66
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2011-06-10 11:09:55.373478 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:359
(sofia/external/03996590031055 at 203.208.207.212) State ROUTING going to sleep
2011-06-10 11:09:55.373478 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_CONSUME_MEDIA
2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378
(sofia/external/03996590031055 at 203.208.207.212) State CONSUME_MEDIA
2011-06-10 11:09:55.374485 [DEBUG] switch_core_state_machine.c:378
(sofia/external/03996590031055 at 203.208.207.212) State CONSUME_MEDIA going to
sleep
recv 307 bytes from udp/[203.208.207.212]:5060 at 03:09:55.485130:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To: <sip:03996590031055 at 203.208.207.212>
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Content-Length: 0
------------------------------------------------------------------------
recv 669 bytes from udp/[203.208.207.212]:5060 at 03:09:56.677788:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Length: 189
v=0
o=- 421265648 1 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:09:56.571839 [INFO] sofia.c:729
sofia/external/03996590031055 at 203.208.207.212 Update Callee ID to "Outbound
Call" <03996590031055>
2011-06-10 11:09:56.571839 [DEBUG] sofia.c:4646 Channel
sofia/external/03996590031055 at 203.208.207.212 entering state
[proceeding][183]
2011-06-10 11:09:56.571839 [DEBUG] sofia.c:4657 Remote SDP:
v=0
o=- 421265648 1 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:4467 Audio Codec Compare
[G729:18:8000:20:8000]/[G729:18:8000:20:8000]
2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:2757 Set Codec
sofia/external/03996590031055 at 203.208.207.212 G729/8000 20 ms 160 samples
8000 bits
2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf send
payload to 101
2011-06-10 11:09:56.571839 [DEBUG] sofia_glue.c:2987 AUDIO RTP
[sofia/external/03996590031055 at 203.208.207.212] 10.1.1.46 port 30000 ->
203.208.207.196 port 30792 codec: 18 ms: 20
2011-06-10 11:09:56.571839 [DEBUG] switch_rtp.c:1607 Starting timer [soft]
160 bytes per 20ms
2011-06-10 11:09:56.573731 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf send
payload to 101
2011-06-10 11:09:56.573731 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf receive
payload to 101
2011-06-10 11:09:56.573731 [NOTICE] sofia_glue.c:3680 Pre-Answer
sofia/external/03996590031055 at 203.208.207.212!
2011-06-10 11:09:56.573731 [DEBUG] switch_channel.c:2627
(sofia/external/03996590031055 at 203.208.207.212) Callstate Change RINGING ->
EARLY
2011-06-10 11:09:56.573731 [DEBUG] switch_ivr_originate.c:3408 Originate
Resulted in Success: [sofia/external/03996590031055 at 203.208.207.212]
2011-06-10 11:09:56.573731 [DEBUG] mod_commands.c:3205
(sofia/external/03996590031055 at 203.208.207.212) State Change
CS_CONSUME_MEDIA -> CS_EXECUTE
2011-06-10 11:09:56.573731 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_EXECUTE
2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:366
(sofia/external/03996590031055 at 203.208.207.212) State EXECUTE
2011-06-10 11:09:56.575262 [DEBUG] mod_sofia.c:240
sofia/external/03996590031055 at 203.208.207.212 SOFIA EXECUTE
2011-06-10 11:09:56.575262 [DEBUG] switch_core_state_machine.c:157
sofia/external/03996590031055 at 203.208.207.212 Standard EXECUTE
EXECUTE sofia/external/03996590031055 at 203.208.207.212 park()
2011-06-10 11:09:56.618770 [DEBUG] switch_rtp.c:2933 Correct ip/port
confirmed.
recv 669 bytes from udp/[203.208.207.212]:5060 at 03:10:01.562021:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Length: 189
v=0
o=- 421265648 2 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:10:01.455944 [INFO] sofia.c:729
sofia/external/03996590031055 at 203.208.207.212 Update Callee ID to
"03996590031055" <03996590031055>
2011-06-10 11:10:01.455944 [DEBUG] sofia.c:4641 Channel
sofia/external/03996590031055 at 203.208.207.212 skipping state
[proceeding][183]
recv 669 bytes from udp/[203.208.207.212]:5060 at 03:10:01.563178:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Length: 189
v=0
o=- 421265648 3 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:10:01.457169 [DEBUG] sofia.c:4641 Channel
sofia/external/03996590031055 at 203.208.207.212 skipping state
[proceeding][183]
recv 749 bytes from udp/[203.208.207.212]:5060 at 03:10:27.365284:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKXjQ7eFpKypy5D;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 INVITE
Contact: <sip:203.208.207.212:5060>
Allow-Events: refer
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Supported: 100rel, timer, replaces
Content-Length: 189
v=0
o=- 421265648 4 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:10:27.258092 [DEBUG] sofia.c:4646 Channel
sofia/external/03996590031055 at 203.208.207.212 entering state
[completing][200]
2011-06-10 11:10:27.258092 [DEBUG] sofia.c:4657 Remote SDP:
v=0
o=- 421265648 4 IN IP4 203.208.207.219
s=session
c=IN IP4 203.208.207.196
t=0 0
m=audio 30792 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
send 405 bytes to udp/[203.208.207.212]:5060 at 03:10:27.366562:
------------------------------------------------------------------------
ACK sip:203.208.207.212:5060 SIP/2.0
Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKyUg0ga7pUZmrS
Max-Forwards: 70
From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501633 ACK
Contact: <sip:mod_sofia at 202.73.56.46:5080>
Content-Length: 0
------------------------------------------------------------------------
2011-06-10 11:10:27.260267 [DEBUG] sofia.c:4646 Channel
sofia/external/03996590031055 at 203.208.207.212 entering state [ready][200]
2011-06-10 11:10:27.260267 [DEBUG] switch_channel.c:2782
(sofia/external/03996590031055 at 203.208.207.212) Callstate Change EARLY ->
ACTIVE
2011-06-10 11:10:27.260267 [NOTICE] sofia.c:5175 Channel
[sofia/external/03996590031055 at 203.208.207.212] has been answered
2011-06-10 11:10:27.264178 [DEBUG] switch_scheduler.c:214 Added task 23
switch_ivr_schedule_hangup (ea57b74b-a8c2-4fea-9683-98054dc03a79) to run at
1307676927
2011-06-10 11:10:27.265202 [DEBUG] switch_core_session.c:954 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971 variable
string 0 = [origination_caller_id_number=03996590031055]
2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971 variable
string 1 = [ccd_session_id=20110610105829676824]
2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971 variable
string 2 = [sip_cid_type=pid]
2011-06-10 11:10:27.266218 [DEBUG] switch_ivr_originate.c:1971 variable
string 3 = [privacy=yes]
2011-06-10 11:10:27.266218 [NOTICE] switch_channel.c:808 New Channel
sofia/external/03996563750914 at 203.208.207.212
[30228d2b-756a-4a98-871d-db63a2955b52]
2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:4129
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_NEW ->
CS_INIT
2011-06-10 11:10:27.266218 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change CS_INIT
2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356
(sofia/external/03996563750914 at 203.208.207.212) State INIT
2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:84
sofia/external/03996563750914 at 203.208.207.212 SOFIA INIT
2011-06-10 11:10:27.266218 [DEBUG] mod_sofia.c:124
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_INIT ->
CS_ROUTING
2011-06-10 11:10:27.266218 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:356
(sofia/external/03996563750914 at 203.208.207.212) State INIT going to sleep
2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_ROUTING
2011-06-10 11:10:27.266218 [DEBUG] switch_channel.c:1657
(sofia/external/03996563750914 at 203.208.207.212) Callstate Change DOWN ->
RINGING
2011-06-10 11:10:27.266218 [DEBUG] switch_core_state_machine.c:359
(sofia/external/03996563750914 at 203.208.207.212) State ROUTING
send 984 bytes to udp/[203.208.207.212]:5060 at 03:10:27.373220:
------------------------------------------------------------------------
INVITE sip:03996563750914 at 203.208.207.212 SIP/2.0
Via: SIP/2.0/UDP
202.73.56.46:5080;rport;branch=z9hG4bKZ49rj5Qtr8aBN2011-06-10
11:10:27.266218 [DEBUG] mod_sofia.c:147
sofia/external/03996563750914 at 203.208.207.212 SOFIA ROUTING
Max-Forwards: 70
From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
To: <sip:03996563750914 at 203.208.207.212>
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 INVITE
Contact: <sip:mod_sofia at 202.73.56.46:5080>
User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, refer
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 204
X-FS-Support: update_display
P-Asserted-Identity: "" <sip:03996590031055 at 202.73.56.46>
v=0
o=FreeSWITCH 1307646863 1307646864 IN IP4 202.73.56.46
s=FreeSWITCH
c=IN IP4 202.73.56.46
t=0 0
m=audio 28564 RTP/AVP 18 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2011-06-10 11:10:27.267630 [DEBUG] sofia.c:4646 Channel
sofia/external/03996563750914 at 203.208.207.212 entering state [calling][0]
2011-06-10 11:10:27.267630 [DEBUG] switch_ivr_originate.c:66
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2011-06-10 11:10:27.267630 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:359
(sofia/external/03996563750914 at 203.208.207.212) State ROUTING going to sleep
2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_CONSUME_MEDIA
2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378
(sofia/external/03996563750914 at 203.208.207.212) State CONSUME_MEDIA
2011-06-10 11:10:27.267630 [DEBUG] switch_core_state_machine.c:378
(sofia/external/03996563750914 at 203.208.207.212) State CONSUME_MEDIA going to
sleep
recv 307 bytes from udp/[203.208.207.212]:5060 at 03:10:27.378710:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
To: <sip:03996563750914 at 203.208.207.212>
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 INVITE
Content-Length: 0
------------------------------------------------------------------------
2011-06-10 11:10:27.278484 [DEBUG] switch_ivr.c:563
sofia/external/03996590031055 at 203.208.207.212 Command Execute
playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav)
EXECUTE sofia/external/03996590031055 at 203.208.207.212
playback(/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav)
2011-06-10 11:10:27.278484 [DEBUG] switch_core_file.c:176 File
/usr/local/freeswitch/sounds/clearhub/MusicForCalls_v1.wav sample rate 11025
doesn't match requested rate 8000
2011-06-10 11:10:27.278484 [WARNING] switch_core_file.c:189 File has 2
channels, muxing to mono will occur.
2011-06-10 11:10:27.278484 [DEBUG] switch_ivr_play_say.c:1244 Codec
Activated L16 at 8000hz 2 channels 20ms
2011-06-10 11:10:27.298764 [INFO] mod_com_g729.c:119 ENCODER CREATE -
0x2aaab00310c0 0x2aaab00b20c0
recv 666 bytes from udp/[203.208.207.212]:5060 at 03:10:28.618472:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
To:
<sip:03996563750914 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Length: 186
v=0
o=- 131082 1 IN IP4 203.208.207.218
s=session
c=IN IP4 203.208.207.195
t=0 0
m=audio 45002 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:10:28.513195 [INFO] sofia.c:729
sofia/external/03996563750914 at 203.208.207.212 Update Callee ID to "Outbound
Call" <03996563750914>
2011-06-10 11:10:28.513195 [DEBUG] sofia.c:4646 Channel
sofia/external/03996563750914 at 203.208.207.212 entering state
[proceeding][183]
2011-06-10 11:10:28.513195 [DEBUG] sofia.c:4657 Remote SDP:
v=0
o=- 131082 1 IN IP4 203.208.207.218
s=session
c=IN IP4 203.208.207.195
t=0 0
m=audio 45002 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:4467 Audio Codec Compare
[G729:18:8000:20:8000]/[G729:18:8000:20:8000]
2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:2757 Set Codec
sofia/external/03996563750914 at 203.208.207.212 G729/8000 20 ms 160 samples
8000 bits
2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:4565 Set 2833 dtmf send
payload to 101
2011-06-10 11:10:28.513195 [DEBUG] sofia_glue.c:2987 AUDIO RTP
[sofia/external/03996563750914 at 203.208.207.212] 10.1.1.46 port 28564 ->
203.208.207.195 port 45002 codec: 18 ms: 20
2011-06-10 11:10:28.513195 [DEBUG] switch_rtp.c:1607 Starting timer [soft]
160 bytes per 20ms
2011-06-10 11:10:28.514938 [DEBUG] sofia_glue.c:3228 Set 2833 dtmf send
payload to 101
2011-06-10 11:10:28.514938 [DEBUG] sofia_glue.c:3233 Set 2833 dtmf receive
payload to 101
2011-06-10 11:10:28.514938 [NOTICE] sofia_glue.c:3680 Pre-Answer
sofia/external/03996563750914 at 203.208.207.212!
2011-06-10 11:10:28.514938 [DEBUG] switch_channel.c:2627
(sofia/external/03996563750914 at 203.208.207.212) Callstate Change RINGING ->
EARLY
2011-06-10 11:10:28.514938 [DEBUG] switch_ivr_originate.c:3408 Originate
Resulted in Success: [sofia/external/03996563750914 at 203.208.207.212]
2011-06-10 11:10:28.514938 [DEBUG] mod_commands.c:3205
(sofia/external/03996563750914 at 203.208.207.212) State Change
CS_CONSUME_MEDIA -> CS_EXECUTE
2011-06-10 11:10:28.514938 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_EXECUTE
2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:366
(sofia/external/03996563750914 at 203.208.207.212) State EXECUTE
2011-06-10 11:10:28.515884 [DEBUG] mod_sofia.c:240
sofia/external/03996563750914 at 203.208.207.212 SOFIA EXECUTE
2011-06-10 11:10:28.515884 [DEBUG] switch_core_state_machine.c:157
sofia/external/03996563750914 at 203.208.207.212 Standard EXECUTE
EXECUTE sofia/external/03996563750914 at 203.208.207.212 park()
2011-06-10 11:10:28.516887 [DEBUG] switch_core_session.c:954 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1480
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_EXECUTE ->
CS_HIBERNATE
2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.517896 [DEBUG] switch_ivr_bridge.c:1482
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_EXECUTE ->
CS_HIBERNATE
2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.517896 [DEBUG] switch_core_session.c:771 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_play_say.c:1581 done playing
file
2011-06-10 11:10:28.519223 [DEBUG] switch_ivr.c:563
sofia/external/03996590031055 at 203.208.207.212 Command Execute
playback(tone_stream://%(2000,4000,440,480);loops=10)
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:366
(sofia/external/03996563750914 at 203.208.207.212) State EXECUTE going to sleep
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_HIBERNATE
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381
(sofia/external/03996563750914 at 203.208.207.212) State HIBERNATE
2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:221
sofia/external/03996563750914 at 203.208.207.212 SOFIA HIBERNATE
2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:731
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_HIBERNATE ->
CS_RESET
2011-06-10 11:10:28.519223 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:381
(sofia/external/03996563750914 at 203.208.207.212) State HIBERNATE going to
sleep
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_RESET
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362
(sofia/external/03996563750914 at 203.208.207.212) State RESET
2011-06-10 11:10:28.519223 [DEBUG] mod_sofia.c:165
sofia/external/03996563750914 at 203.208.207.212 SOFIA RESET
2011-06-10 11:10:28.519223 [DEBUG] switch_ivr_bridge.c:716
sofia/external/03996563750914 at 203.208.207.212 CUSTOM RESET
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:66
sofia/external/03996563750914 at 203.208.207.212 Standard RESET
2011-06-10 11:10:28.519223 [DEBUG] switch_core_state_machine.c:362
(sofia/external/03996563750914 at 203.208.207.212) State RESET going to sleep
2011-06-10 11:10:28.519223 [DEBUG] switch_core_session.c:709 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
recv 666 bytes from udp/[203.208.207.212]:5060 at 03:10:30.540814:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
To:
<sip:03996563750914 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY,
SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Length: 186
v=0
o=- 131082 2 IN IP4 203.208.207.218
s=session
c=IN IP4 203.208.207.195
t=0 0
m=audio 45002 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
------------------------------------------------------------------------
2011-06-10 11:10:30.435309 [INFO] sofia.c:729
sofia/external/03996563750914 at 203.208.207.212 Update Callee ID to
"03996563750914" <03996563750914>
2011-06-10 11:10:30.435309 [DEBUG] sofia.c:4641 Channel
sofia/external/03996563750914 at 203.208.207.212 skipping state
[proceeding][183]
2011-06-10 11:10:30.691404 [WARNING] switch_core_session.c:1940 Cannot
execute app 'playback' media required on an outbound channel that does not
have media established
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:366
(sofia/external/03996590031055 at 203.208.207.212) State EXECUTE going to sleep
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_HIBERNATE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381
(sofia/external/03996590031055 at 203.208.207.212) State HIBERNATE
2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:221
sofia/external/03996590031055 at 203.208.207.212 SOFIA HIBERNATE
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:731
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_HIBERNATE ->
CS_RESET
2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:381
(sofia/external/03996590031055 at 203.208.207.212) State HIBERNATE going to
sleep
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_RESET
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362
(sofia/external/03996590031055 at 203.208.207.212) State RESET
2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:165
sofia/external/03996590031055 at 203.208.207.212 SOFIA RESET
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:716
sofia/external/03996590031055 at 203.208.207.212 CUSTOM RESET
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:723
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_RESET ->
CS_SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:362
(sofia/external/03996590031055 at 203.208.207.212) State RESET going to sleep
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
(sofia/external/03996590031055 at 203.208.207.212) State SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:741
sofia/external/03996590031055 at 203.208.207.212 CUSTOM SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:761
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_RESET ->
CS_SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
(sofia/external/03996563750914 at 203.208.207.212) State SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] mod_sofia.c:558 SOFIA SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_ivr_bridge.c:741
sofia/external/03996563750914 at 203.208.207.212 CUSTOM SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:204
sofia/external/03996563750914 at 203.208.207.212 Standard SOFT_EXECUTE
2011-06-10 11:10:30.691404 [DEBUG] switch_core_state_machine.c:372
(sofia/external/03996563750914 at 203.208.207.212) State SOFT_EXECUTE going to
sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535
(sofia/external/03996563750914 at 203.208.207.212) Callstate Change EARLY ->
HANGUP
2011-06-10 11:10:30.711798 [NOTICE] switch_ivr_originate.c:1045 Hangup
sofia/external/03996563750914 at 203.208.207.212 [CS_SOFT_EXECUTE]
[DESTINATION_OUT_OF_ORDER]
2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2551 Send signal
sofia/external/03996563750914 at 203.208.207.212 [KILL]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_HANGUP
2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2535
(sofia/external/03996590031055 at 203.208.207.212) Callstate Change ACTIVE ->
HANGUP
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
(sofia/external/03996563750914 at 203.208.207.212) State HANGUP
2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel
sofia/external/03996563750914 at 203.208.207.212 hanging up, cause:
DESTINATION_OUT_OF_ORDER
2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:510 Sending CANCEL to
sofia/external/03996563750914 at 203.208.207.212
send 390 bytes to udp/[203.208.207.212]:5060 at 03:10:30.818391:
------------------------------------------------------------------------
CANCEL sip:03996563750914 at 203.208.207.212 SIP/2.0
Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKZ49rj5Qtr8aBN
Max-Forwards: 70
From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
To: <sip:03996563750914 at 203.208.207.212>
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 CANCEL
Reason: Q.850;cause=27;text="DESTINATION_OUT_OF_ORDER"
Content-Length: 0
------------------------------------------------------------------------
2011-06-10 11:10:30.711798 [NOTICE] switch_ivr_bridge.c:772 Hangup
sofia/external/03996590031055 at 203.208.207.212 [CS_SOFT_EXECUTE]
[ORIGINATOR_CANCEL]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46
sofia/external/03996563750914 at 203.208.207.212 Standard HANGUP, cause:
DESTINATION_OUT_OF_ORDER
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
(sofia/external/03996563750914 at 203.208.207.212) State HANGUP going to sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:351
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_HANGUP ->
CS_REPORTING
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_REPORTING
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
(sofia/external/03996563750914 at 203.208.207.212) State REPORTING
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:53
sofia/external/03996563750914 at 203.208.207.212 Standard REPORTING, cause:
DESTINATION_OUT_OF_ORDER
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
(sofia/external/03996563750914 at 203.208.207.212) State REPORTING going to
sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_channel.c:2551 Send signal
sofia/external/03996590031055 at 203.208.207.212 [KILL]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:372
(sofia/external/03996590031055 at 203.208.207.212) State SOFT_EXECUTE going to
sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_HANGUP
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:345
(sofia/external/03996563750914 at 203.208.207.212) State Change CS_REPORTING ->
CS_DESTROY
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996563750914 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1288 Session 40
(sofia/external/03996563750914 at 203.208.207.212) Locked, Waiting on external
entities
2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1306 Session 40
(sofia/external/03996563750914 at 203.208.207.212) Ended
2011-06-10 11:10:30.711798 [NOTICE] switch_core_session.c:1308 Close Channel
sofia/external/03996563750914 at 203.208.207.212 [CS_DESTROY]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:449
(sofia/external/03996563750914 at 203.208.207.212) Callstate Change HANGUP ->
DOWN
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:452
(sofia/external/03996563750914 at 203.208.207.212) Running State Change
CS_DESTROY
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462
(sofia/external/03996563750914 at 203.208.207.212) State DESTROY
2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:362
sofia/external/03996563750914 at 203.208.207.212 SOFIA DESTROY
2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:78 ENCODER DESTROYX -
0x2aaaac013028 (nil)
2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:79 DECODER DESTROYX -
0x2aaaac013028 (nil)
2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:78 ENCODER DESTROYX -
0x2aaaac013088 (nil)
2011-06-10 11:10:30.711798 [INFO] mod_com_g729.c:79 DECODER DESTROYX -
0x2aaaac013088 (nil)
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:60
sofia/external/03996563750914 at 203.208.207.212 Standard DESTROY
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:462
(sofia/external/03996563750914 at 203.208.207.212) State DESTROY going to sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
(sofia/external/03996590031055 at 203.208.207.212) State HANGUP
2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:457 Channel
sofia/external/03996590031055 at 203.208.207.212 hanging up, cause:
ORIGINATOR_CANCEL
2011-06-10 11:10:30.711798 [DEBUG] mod_sofia.c:500 Sending BYE to
sofia/external/03996590031055 at 203.208.207.212
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:46
sofia/external/03996590031055 at 203.208.207.212 Standard HANGUP, cause:
ORIGINATOR_CANCEL
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:557
(sofia/external/03996590031055 at 203.208.207.212) State HANGUP going to sleep
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:351
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_HANGUP ->
CS_REPORTING
2011-06-10 11:10:30.711798 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:320
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_REPORTING
2011-06-10 11:10:30.711798 [DEBUG] switch_core_state_machine.c:617
(sofia/external/03996590031055 at 203.208.207.212) State REPORTING
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:53
sofia/external/03996590031055 at 203.208.207.212 Standard REPORTING, cause:
ORIGINATOR_CANCEL
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:617
(sofia/external/03996590031055 at 203.208.207.212) State REPORTING going to
sleep
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:345
(sofia/external/03996590031055 at 203.208.207.212) State Change CS_REPORTING ->
CS_DESTROY
2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1116 Send signal
sofia/external/03996590031055 at 203.208.207.212 [BREAK]
2011-06-10 11:10:30.714001 [DEBUG] switch_core_session.c:1288 Session 39
(sofia/external/03996590031055 at 203.208.207.212) Locked, Waiting on external
entities
2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1306 Session 39
(sofia/external/03996590031055 at 203.208.207.212) Ended
2011-06-10 11:10:30.714001 [NOTICE] switch_core_session.c:1308 Close Channel
sofia/external/03996590031055 at 203.208.207.212 [CS_DESTROY]
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:449
(sofia/external/03996590031055 at 203.208.207.212) Callstate Change HANGUP ->
DOWN
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:452
(sofia/external/03996590031055 at 203.208.207.212) Running State Change
CS_DESTROY
2011-06-10 11:10:30.714001 [DEBUG] switch_core_state_machine.c:462
(sofia/external/03996590031055 at 203.208.207.212) State DESTROY
2011-06-10 11:10:30.714001 [DEBUG] mod_sofia.c:362
sofia/external/03996590031055 at 203.208.207.212 SOFIA DESTROY
2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:78 ENCODER DESTROYX -
0x2aaab0031060 (nil)
2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:79 DECODER DESTROYX -
0x2aaab0031060 (nil)
2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:78 ENCODER DESTROYX -
0x2aaab00310c0 0x2aaab00b20c0
2011-06-10 11:10:30.714001 [INFO] mod_com_g729.c:79 DECODER DESTROYX -
0x2aaab00310c0 (nil)
send 662 bytes to udp/[203.208.207.212]:5060 at 03:10:30.820530:
------------------------------------------------------------------------
BYE sip:203.208.207.212:5060 SIP/2.0
Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bK0D3Hm08XNH1Xg
Max-Forwards: 70
From: "" <sip:03996563750914 at 202.73.56.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501634 BYE
Contact: <sip:mod_sofia at 202.73.56.46:5080>
User-Agent: FreeSWITCH-mod_sofia/1.0.7-hacked-20110603T012235Z
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY
Supported: timer, precondition, path, replaces
Reason: FreeSWITCH;cause=487;text="ORIGINATOR_CANCEL"
Content-Length: 0
------------------------------------------------------------------------
2011-06-10 11:10:30.715878 [INFO] mod_com_g729.c:83 ENCODER DESTROY -
0x2aaab00310c0 0x2aaab00b20c0
2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:60
sofia/external/03996590031055 at 203.208.207.212 Standard DESTROY
2011-06-10 11:10:30.715878 [DEBUG] switch_core_state_machine.c:462
(sofia/external/03996590031055 at 203.208.207.212) State DESTROY going to sleep
recv 383 bytes from udp/[203.208.207.212]:5060 at 03:10:30.823302:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
To:
<sip:03996563750914 at 203.208.207.212>;tag=2QGB951HCR30000E1D00000u00000001QXU3LU
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 CANCEL
Contact: <sip:203.208.207.212:5060>
Content-Length: 0
------------------------------------------------------------------------
recv 411 bytes from udp/[203.208.207.212]:5060 at 03:10:30.824765:
------------------------------------------------------------------------
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bKZ49rj5Qtr8aBN;received=10.1.1.46
From: "" <sip:03996590031055 at 10.1.1.46>;tag=jDSe6ycN62Zar
To:
<sip:03996563750914 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 INVITE
Reason: SIP;cause=487;text="Request Terminated"
Content-Length: 0
------------------------------------------------------------------------
send 371 bytes to udp/[203.208.207.212]:5060 at 03:10:30.824891:
------------------------------------------------------------------------
ACK sip:03996563750914 at 203.208.207.212 SIP/2.0
Via: SIP/2.0/UDP 202.73.56.46:5080;rport;branch=z9hG4bKZ49rj5Qtr8aBN
Max-Forwards: 70
From: "" <sip:03996590031055 at 202.73.56.46>;tag=jDSe6ycN62Zar
To:
<sip:03996563750914 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ410OWC5F
Call-ID: 082c8244-0db2-122f-c4ab-0015c5fc7ad9
CSeq: 13501649 ACK
Content-Length: 0
------------------------------------------------------------------------
recv 380 bytes from udp/[203.208.207.212]:5060 at 03:10:30.826375:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP
10.1.1.46:5080;rport=5080;branch=z9hG4bK0D3Hm08XNH1Xg;received=10.1.1.46
From: "" <sip:03996563750914 at 10.1.1.46>;tag=H4ZN43UH9S9Qc
To:
<sip:03996590031055 at 203.208.207.212>;tag=2QGB951HCR30000E1D0001Ll0008FJ21EI9PBW
Call-ID: f529ae7e-0db1-122f-c4ab-0015c5fc7ad9
CSeq: 13501634 BYE
--
View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Leg-A-is-automatically-disconnected-on-Leg-B-orginate-failure-tp6482192p6482192.html
Sent from the freeswitch-users mailing list archive at Nabble.com.
More information about the FreeSWITCH-users
mailing list