[Freeswitch-dev] Google Voice incoming calls
Oleg Khovayko
khovayko at gmail.com
Sun Sep 5 07:36:07 PDT 2010
Hi,
I very excited with your new feature: support GV in the FreeSWITCH.
This is real and valuable asset, and I definitely plan to use it.
Yesterday, Sep 4, I fetch new FS tree by GIT, build and install.
Outgoing calls through GV works OK.
But, I faced 2 problems with incoming calls.
1. When calls comes in, phone rings.
But, when I pick up handset on recipient's phone, I hear nothing.
In the caller's handset,I continue hear long beeps. And, thereafter,
in ~30s, GVs answering machine activated.
Looks like GV doesn't understand, when I pick up handset on recepient's
phone.
I tried couple times, with 2 phones: X-lite softphone and VM1188T SIP phone.
Result is same. Can you help me to resolve this problem? Log following.
2. When call comes from GV, on the phone, in the CID line, i see message
"Google Voice".
In the logs, I see Caller's Number in the line:
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3066 Creating an
identity for SIP1182451466 at 10.218.25.84 Google Voice <+12404760839> 1002
This meaning, CID sending correct. Problem in the both my phones, they
shows CID Name only.
I have fixed it, by adding into dialplan "public" following XML code:
<extension name="Fix CID" continue="true">
<condition field="caller_id_name" expression="^Google Voice">
<action application="set"
data="effective_caller_id_name=${caller_id_number}"/>
</condition>
</extension>
RESUME:
Please, help me with [1], and add [2] onto WIKI about GV call, if you
found it interesting.
Following - log of the unsuccessful call through GV->dingaling
2010-09-05 09:26:48.363159 [DEBUG] sofia_reg.c:1583 Changing expire time
to 60 by request of proxy sip:callcentric.com
2010-09-05 09:26:48.455464 [DEBUG] sofia_reg.c:1583 Changing expire time
to 60 by request of proxy sip:callcentric.com
2010-09-05 09:27:15.336517 [DEBUG] sofia_reg.c:1583 Changing expire time
to 61 by request of proxy sip:callcentric.com
2010-09-05 09:27:20.332705 [DEBUG] sofia_reg.c:1583 Changing expire time
to 61 by request of proxy sip:callcentric.com
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:1002 Send Candidate
192.168.1.5:31596 [OfpLNJrFNLpxHUnK]
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3066 Creating an
identity for SIP1182451466 at 10.218.25.84 Google Voice <+12404760839> 1002
2010-09-05 09:27:32.554417 [NOTICE] switch_channel.c:779 New Channel
dingaling/1002 [dc89b256-f1b8-df11-8091-005004c3cb7e]
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3094 Creating a
session for SIP1182451466 at 10.218.25.84
2010-09-05 09:27:32.554417 [NOTICE] switch_channel.c:777 Rename Channel
dingaling/1002->DingaLing/new [dc89b256-f1b8-df11-8091-005004c3cb7e]
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3098 (DingaLing/new)
State Change CS_NEW -> CS_INIT
2010-09-05 09:27:32.554417 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3200 2 payloads
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3202 Available
Payload PCMU 0
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3210 compare PCMU
0/8000 to PCMU 0/8000
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:3221 Choosing Payload
index 0 PCMU 0
2010-09-05 09:27:32.554417 [DEBUG] mod_dingaling.c:1077 Send Describe
[PCMU at 8000]
2010-09-05 09:27:32.562847 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_INIT
2010-09-05 09:27:32.562847 [DEBUG] switch_core_state_machine.c:338
(DingaLing/new) State INIT
2010-09-05 09:27:32.562847 [NOTICE] mod_dingaling.c:1104 Ring-Ready
DingaLing/new!
2010-09-05 09:27:32.795806 [DEBUG] mod_dingaling.c:2934 using Existing
session for SIP1182451466 at 10.218.25.84
2010-09-05 09:27:32.795806 [DEBUG] mod_dingaling.c:3272 3 candidates
2010-09-05 09:27:32.795806 [DEBUG] mod_dingaling.c:3292 candidate
74.125.93.126:19295 PASS ACL wan.auto
2010-09-05 09:27:32.795806 [DEBUG] mod_dingaling.c:3344 Acceptable
Candidate 74.125.93.126:19295
2010-09-05 09:27:32.800152 [DEBUG] mod_dingaling.c:859 Set Read Codec to
PCMU at 8000
2010-09-05 09:27:32.800152 [DEBUG] mod_dingaling.c:874 Set Write Codec
to PCMU at 8000
2010-09-05 09:27:35.151687 [DEBUG] switch_nat.c:500 mapped public port
31596 protocol UDP to localport 31596
2010-09-05 09:27:35.151687 [DEBUG] mod_dingaling.c:886 SETUP RTP
192.168.1.5:31596 -> 74.125.93.126:19295
2010-09-05 09:27:35.151687 [DEBUG] switch_rtp.c:1413 Starting timer
[soft] 160 bytes per 20ms
2010-09-05 09:27:35.156967 [DEBUG] switch_rtp.c:3545 Activate VAD codec
PCMU 20ms
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1199 (DingaLing/new)
State Change CS_INIT -> CS_ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:338
(DingaLing/new) State INIT going to sleep
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_channel.c:1512 (DingaLing/new)
Callstate Change DOWN -> RINGING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:341
(DingaLing/new) State ROUTING
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1213 DingaLing/new
CHANNEL ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:77
DingaLing/new Standard ROUTING
2010-09-05 09:27:35.156967 [INFO] mod_dialplan_xml.c:331 Processing
Google Voice <+12404760839>->1002 in context public
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:119
(DingaLing/new) State Change CS_ROUTING -> CS_EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:341
(DingaLing/new) State ROUTING going to sleep
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:348
(DingaLing/new) State EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1230 DingaLing/new
CHANNEL EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:157
DingaLing/new Standard EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[outside_call]=[true]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[bypass_media]=[false]
2010-09-05 09:27:35.156967 [DEBUG] switch_ivr.c:1470 (DingaLing/new)
State Change CS_EXECUTE -> CS_ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:35.156967 [DEBUG] switch_core_session.c:658 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:35.156967 [NOTICE] switch_ivr.c:1476 Transfer
DingaLing/new to XML[1002 at default]
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:348
(DingaLing/new) State EXECUTE going to sleep
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:341
(DingaLing/new) State ROUTING
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1213 DingaLing/new
CHANNEL ROUTING
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:77
DingaLing/new Standard ROUTING
2010-09-05 09:27:35.156967 [INFO] mod_dialplan_xml.c:331 Processing
Google Voice <+12404760839>->1002 in context default
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:119
(DingaLing/new) State Change CS_ROUTING -> CS_EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:341
(DingaLing/new) State ROUTING going to sleep
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:348
(DingaLing/new) State EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] mod_dingaling.c:1230 DingaLing/new
CHANNEL EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] switch_core_state_machine.c:157
DingaLing/new Standard EXECUTE
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[dialed_extension]=[1002]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:938 EXPORT
[dialed_extension]=[1002]
2010-09-05 09:27:35.156967 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*1 execute_extension::dx XML features
EXECUTE DingaLing/new bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/+12404760839.2010-09-05-09-27-35.wav)
2010-09-05 09:27:35.156967 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*2
record_session::/usr/local/freeswitch/recordings/+12404760839.2010-09-05-09-27-35.wav
2010-09-05 09:27:35.156967 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*3 execute_extension::cf XML features
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[ringback]=[%(2000,4000,440.0,480.0)]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[transfer_ringback]=[local_stream://moh]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[call_timeout]=[30]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[hangup_after_bridge]=[true]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[continue_on_fail]=[true]
2010-09-05 09:27:35.156967 [DEBUG] mod_dptools.c:854 DingaLing/new SET
[called_party_callgroup]=[techsupport]
2010-09-05 09:27:35.266981 [DEBUG] switch_ivr_originate.c:1979 variable
string 0 = [presence_id=1002 at 192.168.1.5]
2010-09-05 09:27:35.266981 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/sip:1002 at 173.79.240.220:42889
[6de15b58-f1b8-df11-8091-005004c3cb7e]
2010-09-05 09:27:35.266981 [DEBUG] mod_sofia.c:3899
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change CS_NEW ->
CS_INIT
2010-09-05 09:27:35.266981 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:35.840736 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change CS_INIT
2010-09-05 09:27:35.840736 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1002 at 173.79.240.220:42889) State INIT
2010-09-05 09:27:35.840736 [DEBUG] mod_sofia.c:83
sofia/internal/sip:1002 at 173.79.240.220:42889 SOFIA INIT
2010-09-05 09:27:38.271136 [DEBUG] switch_nat.c:500 mapped public port
26562 protocol UDP to localport 26562
2010-09-05 09:27:40.682970 [DEBUG] switch_nat.c:500 mapped public port
26563 protocol UDP to localport 26563
2010-09-05 09:27:40.682970 [DEBUG] sofia_glue.c:2036
sip:1002 at 173.79.240.220:42889;rinstance=67bf5b5a98c827e0 Setting proxy
route to sofia/internal/sip:1002 at 173.79.240.220:42889
2010-09-05 09:27:40.692198 [DEBUG] mod_sofia.c:119
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change CS_INIT ->
CS_ROUTING
2010-09-05 09:27:40.692198 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1002 at 173.79.240.220:42889) State INIT going to sleep
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_ROUTING
2010-09-05 09:27:40.692198 [DEBUG] switch_channel.c:1512
(sofia/internal/sip:1002 at 173.79.240.220:42889) Callstate Change DOWN ->
RINGING
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1002 at 173.79.240.220:42889) State ROUTING
2010-09-05 09:27:40.692198 [DEBUG] mod_sofia.c:142
sofia/internal/sip:1002 at 173.79.240.220:42889 SOFIA ROUTING
2010-09-05 09:27:40.692198 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change CS_ROUTING
-> CS_CONSUME_MEDIA
2010-09-05 09:27:40.692198 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1002 at 173.79.240.220:42889) State ROUTING going to sleep
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_CONSUME_MEDIA
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1002 at 173.79.240.220:42889) State CONSUME_MEDIA
2010-09-05 09:27:40.692198 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1002 at 173.79.240.220:42889) State CONSUME_MEDIA going
to sleep
2010-09-05 09:27:40.702461 [DEBUG] sofia.c:4405 Channel
sofia/internal/sip:1002 at 173.79.240.220:42889 entering state [calling][0]
2010-09-05 09:27:40.767237 [INFO] sofia.c:709
sofia/internal/sip:1002 at 173.79.240.220:42889 Update Callee ID to "1002"
<1002>
2010-09-05 09:27:40.841074 [DEBUG] sofia.c:4405 Channel
sofia/internal/sip:1002 at 173.79.240.220:42889 entering state
[proceeding][180]
2010-09-05 09:27:40.841074 [NOTICE] sofia.c:4477 Ring-Ready
sofia/internal/sip:1002 at 173.79.240.220:42889!
2010-09-05 09:27:40.852851 [DEBUG] switch_core_session.c:658 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:40.852851 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:40.852851 [NOTICE] switch_ivr_originate.c:1079
Pre-Answer DingaLing/new!
2010-09-05 09:27:40.852851 [DEBUG] switch_channel.c:2409 (DingaLing/new)
Callstate Change RINGING -> EARLY
2010-09-05 09:27:40.852851 [DEBUG] switch_ivr_originate.c:1128 Raw Codec
Activation Success L16 at 8000hz 1 channel 20ms
2010-09-05 09:27:40.852851 [DEBUG] switch_core_codec.c:116 DingaLing/new
Push codec L16:10
2010-09-05 09:27:40.852851 [DEBUG] switch_ivr_originate.c:1193 Play
Ringback Tone [%(2000,4000,440.0,480.0)]
2010-09-05 09:27:40.942585 [DEBUG] switch_rtp.c:2527 Correct ip/port
confirmed.
2010-09-05 09:27:46.853579 [DEBUG] sofia.c:4405 Channel
sofia/internal/sip:1002 at 173.79.240.220:42889 entering state
[completing][200]
2010-09-05 09:27:46.853579 [DEBUG] sofia.c:4416 Remote SDP:
2010-09-05 09:27:46.860768 [DEBUG] sofia.c:4405 Channel
sofia/internal/sip:1002 at 173.79.240.220:42889 entering state [ready][200]
2010-09-05 09:27:46.860768 [DEBUG] sofia_glue.c:3851 Audio Codec Compare
[PCMU:0:8000:20]/[PCMU:0:8000:20]
2010-09-05 09:27:46.860768 [DEBUG] sofia_glue.c:2446 Set Codec
sofia/internal/sip:1002 at 173.79.240.220:42889 PCMU/8000 20 ms 160 samples
2010-09-05 09:27:46.860768 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf send
payload to 101
2010-09-05 09:27:46.860768 [DEBUG] sofia_glue.c:2686 AUDIO RTP
[sofia/internal/sip:1002 at 173.79.240.220:42889] 192.168.1.5 port 26562 ->
192.168.1.8 port 43976 codec: 0 ms: 20
2010-09-05 09:27:46.860768 [DEBUG] switch_rtp.c:1413 Starting timer
[soft] 160 bytes per 20ms
2010-09-05 09:27:46.879728 [DEBUG] sofia_glue.c:2896 Set 2833 dtmf send
payload to 101
2010-09-05 09:27:46.879728 [DEBUG] sofia_glue.c:2901 Set 2833 dtmf
receive payload to 101
2010-09-05 09:27:46.879728 [DEBUG] switch_channel.c:2555
(sofia/internal/sip:1002 at 173.79.240.220:42889) Callstate Change RINGING
-> ACTIVE
2010-09-05 09:27:46.879728 [DEBUG] switch_channel.c:2567 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:46.879728 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:46.879728 [NOTICE] sofia.c:4963 Channel
[sofia/internal/sip:1002 at 173.79.240.220:42889] has been answered
2010-09-05 09:27:46.929612 [DEBUG] switch_core_codec.c:140 DingaLing/new
Restore previous codec PCMU:0.
2010-09-05 09:27:46.929612 [DEBUG] switch_core_session.c:658 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:46.929612 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:46.929612 [DEBUG] switch_channel.c:2555 (DingaLing/new)
Callstate Change EARLY -> ACTIVE
2010-09-05 09:27:46.929612 [NOTICE] switch_ivr_originate.c:3315 Channel
[DingaLing/new] has been answered
2010-09-05 09:27:46.929612 [DEBUG] switch_ivr_originate.c:3360 Originate
Resulted in Success: [sofia/internal/sip:1002 at 173.79.240.220:42889]
2010-09-05 09:27:46.929612 [DEBUG] switch_ivr_originate.c:3360 Originate
Resulted in Success: [sofia/internal/sip:1002 at 173.79.240.220:42889]
2010-09-05 09:27:46.929612 [DEBUG] switch_core_session.c:658 Send signal
sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:46.929612 [DEBUG] switch_core_session.c:658 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:46.929612 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:46.929612 [DEBUG] switch_ivr_bridge.c:1186
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change
CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2010-09-05 09:27:46.929612 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:46.977702 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_EXCHANGE_MEDIA
2010-09-05 09:27:46.977702 [DEBUG] switch_core_state_machine.c:351
(sofia/internal/sip:1002 at 173.79.240.220:42889) State EXCHANGE_MEDIA
2010-09-05 09:27:46.977702 [DEBUG] mod_sofia.c:548 SOFIA EXCHANGE_MEDIA
2010-09-05 09:27:46.977702 [DEBUG] switch_core_session.c:720 Send signal
sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:46.977702 [DEBUG] switch_core_session.c:720 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:46.977702 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.241475 [INFO] switch_rtp.c:2510 Auto Changing port
from 192.168.1.8:43976 to 173.79.240.220:43976
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:2934 using Existing
session for SIP1182451466 at 10.218.25.84
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:3404 hungup DingaLing/new
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:704 Terminate called
from line 3405 state=CS_EXECUTE
2010-09-05 09:27:47.261722 [DEBUG] switch_channel.c:2322 (DingaLing/new)
Callstate Change ACTIVE -> HANGUP
2010-09-05 09:27:47.261722 [NOTICE] mod_dingaling.c:725 Hangup
DingaLing/new [CS_EXECUTE] [NORMAL_CLEARING]
2010-09-05 09:27:47.261722 [DEBUG] switch_channel.c:2338 Send signal
DingaLing/new [KILL]
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.261722 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.261722 [DEBUG] mod_dingaling.c:3406 End Call
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:473 DingaLing/new
ending bridge by request from write function
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:560 BRIDGE THREAD
DONE [sofia/internal/sip:1002 at 173.79.240.220:42889]
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:580 Send signal
DingaLing/new [BREAK]
2010-09-05 09:27:47.295949 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.295949 [DEBUG] switch_channel.c:2322
(sofia/internal/sip:1002 at 173.79.240.220:42889) Callstate Change ACTIVE
-> HANGUP
2010-09-05 09:27:47.295949 [NOTICE] switch_ivr_bridge.c:632 Hangup
sofia/internal/sip:1002 at 173.79.240.220:42889 [CS_EXCHANGE_MEDIA]
[NORMAL_CLEARING]
2010-09-05 09:27:47.295949 [DEBUG] switch_channel.c:2338 Send signal
sofia/internal/sip:1002 at 173.79.240.220:42889 [KILL]
2010-09-05 09:27:47.295949 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:351
(sofia/internal/sip:1002 at 173.79.240.220:42889) State EXCHANGE_MEDIA
going to sleep
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_HANGUP
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/sip:1002 at 173.79.240.220:42889) State HANGUP
2010-09-05 09:27:47.295949 [DEBUG] mod_sofia.c:453 Channel
sofia/internal/sip:1002 at 173.79.240.220:42889 hanging up, cause:
NORMAL_CLEARING
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:479 DingaLing/new
ending bridge by request from read function
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:560 BRIDGE THREAD
DONE [DingaLing/new]
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:580 Send signal
sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:1257
sofia/internal/sip:1002 at 173.79.240.220:42889 skip receive message
[UNBRIDGE] (channel is hungup already)
2010-09-05 09:27:47.295949 [DEBUG] switch_ivr_bridge.c:1260
DingaLing/new skip receive message [UNBRIDGE] (channel is hungup already)
2010-09-05 09:27:47.295949 [DEBUG] switch_core_session.c:1909
DingaLing/new skip receive message [APPLICATION_EXEC_COMPLETE] (channel
is hungup already)
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:348
(DingaLing/new) State EXECUTE going to sleep
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_HANGUP
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:535
(DingaLing/new) State HANGUP
2010-09-05 09:27:47.295949 [DEBUG] mod_dingaling.c:1310 DingaLing/new
CHANNEL HANGUP
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:46
DingaLing/new Standard HANGUP, cause: NORMAL_CLEARING
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:535
(DingaLing/new) State HANGUP going to sleep
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:333
(DingaLing/new) State Change CS_HANGUP -> CS_REPORTING
2010-09-05 09:27:47.295949 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:47.295949 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:314
(DingaLing/new) Running State Change CS_REPORTING
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:595
(DingaLing/new) State REPORTING
2010-09-05 09:27:47.295949 [DEBUG] mod_sofia.c:496 Sending BYE to
sofia/internal/sip:1002 at 173.79.240.220:42889
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:53
DingaLing/new Standard REPORTING, cause: NORMAL_CLEARING
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:595
(DingaLing/new) State REPORTING going to sleep
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:327
(DingaLing/new) State Change CS_REPORTING -> CS_DESTROY
2010-09-05 09:27:47.295949 [DEBUG] switch_core_session.c:1039 Send
signal DingaLing/new [BREAK]
2010-09-05 09:27:47.295949 [DEBUG] mod_dingaling.c:1341 DingaLing/new
CHANNEL KILL
2010-09-05 09:27:47.295949 [DEBUG] switch_core_session.c:1202 Session 1
(DingaLing/new) Locked, Waiting on external entities
2010-09-05 09:27:47.295949 [NOTICE] switch_core_session.c:1220 Session 1
(DingaLing/new) Ended
2010-09-05 09:27:47.295949 [NOTICE] switch_core_session.c:1222 Close
Channel DingaLing/new [CS_DESTROY]
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:427
(DingaLing/new) Callstate Change HANGUP -> DOWN
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:430
(DingaLing/new) Running State Change CS_DESTROY
2010-09-05 09:27:47.295949 [DEBUG] switch_core_state_machine.c:440
(DingaLing/new) State DESTROY
2010-09-05 09:27:47.295949 [DEBUG] mod_dingaling.c:1246 NUKE RTP
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:1002 at 173.79.240.220:42889 Standard HANGUP, cause:
NORMAL_CLEARING
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/sip:1002 at 173.79.240.220:42889) State HANGUP going to sleep
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change CS_HANGUP ->
CS_REPORTING
2010-09-05 09:27:47.412489 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_REPORTING
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:595
(sofia/internal/sip:1002 at 173.79.240.220:42889) State REPORTING
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:1002 at 173.79.240.220:42889 Standard REPORTING, cause:
NORMAL_CLEARING
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:595
(sofia/internal/sip:1002 at 173.79.240.220:42889) State REPORTING going to
sleep
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/sip:1002 at 173.79.240.220:42889) State Change CS_REPORTING
-> CS_DESTROY
2010-09-05 09:27:47.412489 [DEBUG] switch_core_session.c:1039 Send
signal sofia/internal/sip:1002 at 173.79.240.220:42889 [BREAK]
2010-09-05 09:27:47.412489 [DEBUG] switch_core_session.c:1202 Session 2
(sofia/internal/sip:1002 at 173.79.240.220:42889) Locked, Waiting on
external entities
2010-09-05 09:27:47.412489 [NOTICE] switch_core_session.c:1220 Session 2
(sofia/internal/sip:1002 at 173.79.240.220:42889) Ended
2010-09-05 09:27:47.412489 [NOTICE] switch_core_session.c:1222 Close
Channel sofia/internal/sip:1002 at 173.79.240.220:42889 [CS_DESTROY]
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:427
(sofia/internal/sip:1002 at 173.79.240.220:42889) Callstate Change HANGUP
-> DOWN
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:430
(sofia/internal/sip:1002 at 173.79.240.220:42889) Running State Change
CS_DESTROY
2010-09-05 09:27:47.412489 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:1002 at 173.79.240.220:42889) State DESTROY
2010-09-05 09:27:47.412489 [DEBUG] mod_sofia.c:358
sofia/internal/sip:1002 at 173.79.240.220:42889 SOFIA DESTROY
2010-09-05 09:27:47.533113 [DEBUG] switch_nat.c:560 unmapped public port
31596 protocol UDP to localport 31596
2010-09-05 09:27:47.533113 [DEBUG] switch_core_state_machine.c:60
DingaLing/new Standard DESTROY
2010-09-05 09:27:47.533113 [DEBUG] switch_core_state_machine.c:440
(DingaLing/new) State DESTROY going to sleep
2010-09-05 09:27:47.533113 [DEBUG] switch_nat.c:560 unmapped public port
26562 protocol UDP to localport 26562
2010-09-05 09:27:47.642883 [DEBUG] switch_nat.c:560 unmapped public port
26563 protocol UDP to localport 26563
2010-09-05 09:27:47.642883 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:1002 at 173.79.240.220:42889 Standard DESTROY
2010-09-05 09:27:47.642883 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:1002 at 173.79.240.220:42889) State DESTROY going to sleep
2010-09-05 09:27:48.361715 [DEBUG] sofia_reg.c:1583 Changing expire time
to 62 by request of proxy sip:callcentric.com
More information about the FreeSWITCH-dev
mailing list