When freeswitch answers the call, everything seems fine at first, but
then it redirects the call to the magic number of 6201 which fails
because I haven't defined this number anywhere. For an incoming SIP
call the call is hang up after the first ring. For an incoming call
from FreeDTM, callerid doesn't work, and the phone keeps ringing
randomly until well after the caller has hang up. As it a result it is
not possible to answer the incoming call.
At first I thought maybe a problem with my analog telephone line, I
think I have ruled this out now that I see similar logs for SIP calls.
What is weird is that I haven't made any changes to the setup, and
everything was working fine until yesterday.
Here is an excerpt from my logs for an incoming SIP call. Where is
this magic number of 6201 coming from? I did a grep of all my config
files and came up with nothing.
Last night I rebooted the box, it worked for one call, then failed for
subsequent calls.
Any ideas??
Thanks
2011-03-24 10:31:22.061336 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET
[dialed_extension]=[2000]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au
export(dialed_extension=2000)
2011-03-24 10:31:22.080434 [DEBUG] mod_dptools.c:938 EXPORT
[dialed_extension]=[2000]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au bind_meta_app(1 b
s execute_extension::dx XML features)
2011-03-24 10:31:22.095423 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*1 execute_extension::dx XML features
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au bind_meta_app(2 b
s record_session::/opt/freeswitch/recordings/1004.2011-03-24-10-31-22.wav)
2011-03-24 10:31:22.116351 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*2 record_session::/opt/freeswitch/recordings/1004.2011-03-24-10-31-22.wav
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au bind_meta_app(3 b
s execute_extension::cf XML features)
2011-03-24 10:31:22.130335 [INFO] switch_ivr_async.c:2464 Bound B-Leg:
*3 execute_extension::cf XML features
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au set(ringback=)
2011-03-24 10:31:22.141503 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET [ringback]=[UNDEF]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au
set(transfer_ringback=local_stream://moh)
2011-03-24 10:31:22.164352 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au set(call_timeout=30)
2011-03-24 10:31:22.179416 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET [call_timeout]=[30]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au
set(hangup_after_bridge=true)
2011-03-24 10:31:22.192366 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET
[hangup_after_bridge]=[true]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au set(continue_on_fail=true)
2011-03-24 10:31:22.206368 [DEBUG] mod_dptools.c:854
sofia/internal/1004(a)microcomaustralia.com.au SET
[continue_on_fail]=[true]
EXECUTE sofia/internal/1004(a)microcomaustralia.com.au
bridge([presence_id=1000@microcomaustralia.com.au]error/user_not_registered,FreeTDM/1/1,[presence_id=1001@microcomaustralia.com.au]error/user_not_registered,FreeTDM/2/1,[presence_id=1002@microcomaustralia.com.au]sofia/internal/sip:1002@192.168.2.13:5060,[presence_id=1003@microcomaustralia.com.au]sofia/internal/sip:1003@192.168.2.13:5061,[presence_id=1004@microcomaustralia.com.au]sofia/internal/sip:1004@192.168.2.16)
Everything fine up to (and beyond) this point.
2011-03-24 10:31:22.374349 [DEBUG] switch_ivr_originate.c:2599 local
variable string 0 = [presence_id=1000(a)microcomaustralia.com.au]
2011-03-24 10:31:22.374349 [ERR] switch_ivr_originate.c:2632 Cannot
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2011-03-24 10:31:22.380323 [INFO] ftmod_zt.c:636 Setting echo cancel
to 64 taps for 1:1
2011-03-24 10:31:22.381586 [DEBUG] mod_freetdm.c:377 Set codec PCMU 20ms
2011-03-24 10:31:22.393312 [DEBUG] mod_freetdm.c:1334 Connect outbound
channel FreeTDM/1:1/
2011-03-24 10:31:22.393312 [NOTICE] switch_channel.c:779 New Channel
FreeTDM/1:1/ [d1b1124a-e8cf-485a-8c1e-dafbcaf0d09b]
2011-03-24 10:31:22.399504 [DEBUG] mod_freetdm.c:1348 (FreeTDM/1:1/)
State Change CS_NEW -> CS_INIT
2011-03-24 10:31:22.399504 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/1:1/ [BREAK]
2011-03-24 10:31:22.399504 [DEBUG] ftmod_analog.c:361 [s1c1][1:1]
ANALOG CHANNEL thread starting.
2011-03-24 10:31:22.404683 [DEBUG] ftmod_analog.c:88 [s1c1][1:1]
Changed state from DOWN to GENRING
2011-03-24 10:31:23.514411 [INFO] ftmod_zt.c:636 Setting echo cancel
to 64 taps for 1:1
2011-03-24 10:31:23.514411 [DEBUG] ftdm_io.c:2539 [s1c1][1:1] Enabled
software DTMF detector
2011-03-24 10:31:23.514411 [DEBUG] ftmod_analog.c:381 [s1c1][1:1]
Initialized DTMF detection
2011-03-24 10:31:23.514411 [DEBUG] ftmod_analog.c:534 [s1c1][1:1]
Executing state handler on 1:1 for GENRING
2011-03-24 10:31:23.514411 [DEBUG] mod_freetdm.c:1715 got FXS sig [PROGRESS]
2011-03-24 10:31:23.514411 [NOTICE] mod_freetdm.c:1732 Ring-Ready FreeTDM/1:1/!
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/1:1/) Running State Change CS_INIT
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:338
(FreeTDM/1:1/) State INIT
2011-03-24 10:31:23.525898 [DEBUG] mod_freetdm.c:405 (FreeTDM/1:1/)
State Change CS_INIT -> CS_ROUTING
2011-03-24 10:31:23.525898 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/1:1/ [BREAK]
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:338
(FreeTDM/1:1/) State INIT going to sleep
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/1:1/) Running State Change CS_ROUTING
2011-03-24 10:31:23.525898 [DEBUG] switch_channel.c:1512
(FreeTDM/1:1/) Callstate Change DOWN -> RINGING
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:341
(FreeTDM/1:1/) State ROUTING
2011-03-24 10:31:23.525898 [DEBUG] mod_freetdm.c:428 FreeTDM/1:1/
CHANNEL ROUTING
2011-03-24 10:31:23.525898 [DEBUG] switch_ivr_originate.c:66
(FreeTDM/1:1/) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2011-03-24 10:31:23.525898 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/1:1/ [BREAK]
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:341
(FreeTDM/1:1/) State ROUTING going to sleep
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/1:1/) Running State Change CS_CONSUME_MEDIA
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:360
(FreeTDM/1:1/) State CONSUME_MEDIA
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:360
(FreeTDM/1:1/) State CONSUME_MEDIA going to sleep
2011-03-24 10:31:23.536490 [DEBUG] switch_ivr_originate.c:2599 local
variable string 0 = [presence_id=1001(a)microcomaustralia.com.au]
2011-03-24 10:31:23.538398 [ERR] switch_ivr_originate.c:2632 Cannot
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2011-03-24 10:31:23.538398 [INFO] ftmod_zt.c:636 Setting echo cancel
to 64 taps for 2:1
2011-03-24 10:31:23.544342 [DEBUG] mod_freetdm.c:377 Set codec PCMU 20ms
2011-03-24 10:31:23.551431 [DEBUG] mod_freetdm.c:1334 Connect outbound
channel FreeTDM/2:1/
2011-03-24 10:31:23.555384 [NOTICE] switch_channel.c:779 New Channel
FreeTDM/2:1/ [86275359-c4be-4663-9561-c5973344c1a7]
2011-03-24 10:31:23.559646 [DEBUG] mod_freetdm.c:1348 (FreeTDM/2:1/)
State Change CS_NEW -> CS_INIT
2011-03-24 10:31:23.561459 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/2:1/ [BREAK]
2011-03-24 10:31:23.561459 [DEBUG] ftmod_analog.c:361 [s2c1][1:2]
ANALOG CHANNEL thread starting.
2011-03-24 10:31:23.565467 [DEBUG] ftmod_analog.c:88 [s2c1][1:2]
Changed state from DOWN to GENRING
2011-03-24 10:31:24.665349 [INFO] ftmod_zt.c:636 Setting echo cancel
to 64 taps for 2:1
2011-03-24 10:31:24.665349 [DEBUG] ftdm_io.c:2539 [s2c1][1:2] Enabled
software DTMF detector
2011-03-24 10:31:24.665349 [DEBUG] ftmod_analog.c:381 [s2c1][1:2]
Initialized DTMF detection
2011-03-24 10:31:24.665349 [DEBUG] ftmod_analog.c:534 [s2c1][1:2]
Executing state handler on 2:1 for GENRING
2011-03-24 10:31:24.665349 [DEBUG] mod_freetdm.c:1715 got FXS sig [PROGRESS]
2011-03-24 10:31:24.665349 [NOTICE] mod_freetdm.c:1732 Ring-Ready FreeTDM/2:1/!
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/2:1/) Running State Change CS_INIT
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:338
(FreeTDM/2:1/) State INIT
2011-03-24 10:31:24.677691 [DEBUG] mod_freetdm.c:405 (FreeTDM/2:1/)
State Change CS_INIT -> CS_ROUTING
2011-03-24 10:31:24.677691 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/2:1/ [BREAK]
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:338
(FreeTDM/2:1/) State INIT going to sleep
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/2:1/) Running State Change CS_ROUTING
2011-03-24 10:31:24.677691 [DEBUG] switch_channel.c:1512
(FreeTDM/2:1/) Callstate Change DOWN -> RINGING
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:341
(FreeTDM/2:1/) State ROUTING
2011-03-24 10:31:24.677691 [DEBUG] mod_freetdm.c:428 FreeTDM/2:1/
CHANNEL ROUTING
2011-03-24 10:31:24.677691 [DEBUG] switch_ivr_originate.c:66
(FreeTDM/2:1/) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2011-03-24 10:31:24.677691 [DEBUG] switch_core_session.c:1047 Send
signal FreeTDM/2:1/ [BREAK]
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:341
(FreeTDM/2:1/) State ROUTING going to sleep
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314
(FreeTDM/2:1/) Running State Change CS_CONSUME_MEDIA
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:360
(FreeTDM/2:1/) State CONSUME_MEDIA
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:360
(FreeTDM/2:1/) State CONSUME_MEDIA going to sleep
2011-03-24 10:31:24.692818 [DEBUG] switch_ivr_originate.c:2599 local
variable string 0 = [presence_id=1002(a)microcomaustralia.com.au]
2011-03-24 10:31:24.697423 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/sip:1002@192.168.2.13:5060
[0da6383c-4633-4a03-99ed-839918a74161]
2011-03-24 10:31:24.737484 [DEBUG] mod_sofia.c:3920
(sofia/internal/sip:1002@192.168.2.13:5060) State Change CS_NEW ->
CS_INIT
2011-03-24 10:31:24.737484 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1002@192.168.2.13:5060 [BREAK]
2011-03-24 10:31:24.752679 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002@192.168.2.13:5060) Running State Change
CS_INIT
2011-03-24 10:31:24.756503 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1002@192.168.2.13:5060) State INIT
2011-03-24 10:31:24.758368 [DEBUG] mod_sofia.c:83
sofia/internal/sip:1002@192.168.2.13:5060 SOFIA INIT
2011-03-24 10:31:24.777518 [DEBUG] mod_sofia.c:123
(sofia/internal/sip:1002@192.168.2.13:5060) State Change CS_INIT ->
CS_ROUTING
2011-03-24 10:31:24.777518 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1002@192.168.2.13:5060 [BREAK]
2011-03-24 10:31:24.777518 [DEBUG] sofia.c:4402 Channel
sofia/internal/sip:1002@192.168.2.13:5060 entering state [calling][0]
2011-03-24 10:31:24.781657 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1002@192.168.2.13:5060) State INIT going to sleep
2011-03-24 10:31:24.781657 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002@192.168.2.13:5060) Running State Change
CS_ROUTING
2011-03-24 10:31:24.785366 [DEBUG] switch_channel.c:1512
(sofia/internal/sip:1002@192.168.2.13:5060) Callstate Change DOWN ->
RINGING
2011-03-24 10:31:24.799334 [INFO] sofia.c:709
sofia/internal/sip:1002@192.168.2.13:5060 Update Callee ID to "1002"
<1002>
2011-03-24 10:31:24.808910 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1002@192.168.2.13:5060) State ROUTING
2011-03-24 10:31:24.808910 [DEBUG] sofia.c:4402 Channel
sofia/internal/sip:1002@192.168.2.13:5060 entering state
[proceeding][180]
2011-03-24 10:31:24.812354 [NOTICE] sofia.c:4474 Ring-Ready
sofia/internal/sip:1002@192.168.2.13:5060!
2011-03-24 10:31:24.815429 [DEBUG] mod_sofia.c:146
sofia/internal/sip:1002@192.168.2.13:5060 SOFIA ROUTING
2011-03-24 10:31:24.815429 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1002@192.168.2.13:5060) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2011-03-24 10:31:24.815429 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1002@192.168.2.13:5060 [BREAK]
2011-03-24 10:31:24.815429 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1002@192.168.2.13:5060) State ROUTING going to
sleep
2011-03-24 10:31:24.815429 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1002@192.168.2.13:5060) Running State Change
CS_CONSUME_MEDIA
2011-03-24 10:31:24.817284 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1002@192.168.2.13:5060) State CONSUME_MEDIA
2011-03-24 10:31:24.817284 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1002@192.168.2.13:5060) State CONSUME_MEDIA going
to sleep
2011-03-24 10:31:24.819480 [DEBUG] switch_ivr_originate.c:2599 local
variable string 0 = [presence_id=1003(a)microcomaustralia.com.au]
2011-03-24 10:31:24.819480 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/sip:1003@192.168.2.13:5061
[644a2402-7658-4831-8599-2439dc82e1f2]
2011-03-24 10:31:24.850900 [DEBUG] mod_sofia.c:3920
(sofia/internal/sip:1003@192.168.2.13:5061) State Change CS_NEW ->
CS_INIT
2011-03-24 10:31:24.851903 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1003@192.168.2.13:5061 [BREAK]
2011-03-24 10:31:24.865923 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1003@192.168.2.13:5061) Running State Change
CS_INIT
2011-03-24 10:31:24.865923 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1003@192.168.2.13:5061) State INIT
2011-03-24 10:31:24.872367 [DEBUG] mod_sofia.c:83
sofia/internal/sip:1003@192.168.2.13:5061 SOFIA INIT
2011-03-24 10:31:24.897626 [DEBUG] mod_sofia.c:123
(sofia/internal/sip:1003@192.168.2.13:5061) State Change CS_INIT ->
CS_ROUTING
2011-03-24 10:31:24.898904 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1003@192.168.2.13:5061 [BREAK]
2011-03-24 10:31:24.898904 [DEBUG] sofia.c:4402 Channel
sofia/internal/sip:1003@192.168.2.13:5061 entering state [calling][0]
2011-03-24 10:31:24.899882 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1003@192.168.2.13:5061) State INIT going to sleep
2011-03-24 10:31:24.899882 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1003@192.168.2.13:5061) Running State Change
CS_ROUTING
2011-03-24 10:31:24.920400 [DEBUG] sofia.c:4402 Channel
sofia/internal/sip:1003@192.168.2.13:5061 entering state [calling][0]
2011-03-24 10:31:24.930315 [DEBUG] sofia.c:6117 IP 59.167.180.194
Rejected by acl "domains". Falling back to Digest auth.
2011-03-24 10:31:24.930315 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/1004(a)59.167.180.194
[294c0493-b397-481a-ac78-09fa727d79b9]
2011-03-24 10:31:24.939488 [DEBUG] switch_channel.c:1512
(sofia/internal/sip:1003@192.168.2.13:5061) Callstate Change DOWN ->
RINGING
2011-03-24 10:31:24.947209 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1003@192.168.2.13:5061) State ROUTING
2011-03-24 10:31:24.947209 [DEBUG] mod_sofia.c:146
sofia/internal/sip:1003@192.168.2.13:5061 SOFIA ROUTING
2011-03-24 10:31:24.949210 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1003@192.168.2.13:5061) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2011-03-24 10:31:24.950890 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1003@192.168.2.13:5061 [BREAK]
2011-03-24 10:31:24.950890 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1003@192.168.2.13:5061) State ROUTING going to
sleep
2011-03-24 10:31:24.950890 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1003@192.168.2.13:5061) Running State Change
CS_CONSUME_MEDIA
2011-03-24 10:31:24.954269 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1003@192.168.2.13:5061) State CONSUME_MEDIA
2011-03-24 10:31:24.954269 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1003@192.168.2.13:5061) State CONSUME_MEDIA going
to sleep
2011-03-24 10:31:24.954269 [DEBUG] switch_ivr_originate.c:2599 local
variable string 0 = [presence_id=1004(a)microcomaustralia.com.au]
2011-03-24 10:31:24.960337 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/sip:1004@192.168.2.16
[55c3e984-ddf8-45db-a157-65c50e18c8d0]
2011-03-24 10:31:24.970358 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1004(a)59.167.180.194) Running State Change CS_NEW
2011-03-24 10:31:24.970358 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/1004(a)59.167.180.194) State NEW
2011-03-24 10:31:24.994428 [DEBUG] mod_sofia.c:3920
(sofia/internal/sip:1004@192.168.2.16) State Change CS_NEW -> CS_INIT
2011-03-24 10:31:24.996392 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/sip:1004@192.168.2.16 [BREAK]
2011-03-24 10:31:25.023275 [DEBUG] sofia.c:4402 Channel
sofia/internal/1004(a)59.167.180.194 entering state [received][100]
2011-03-24 10:31:25.029365 [DEBUG] sofia.c:4413 Remote SDP:
v=0
o=FreeSWITCH 1300899030 1300899032 IN IP4 59.167.180.194
s=FreeSWITCH
c=IN IP4 59.167.180.194
t=0 0
m=audio 24054 RTP/AVP 8 115 107 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:115 G7221/32000
a=fmtp:115 bitrate=48000
a=rtpmap:107 G7221/16000
a=fmtp:107 bitrate=32000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec
Compare [PCMA:8:8000:20]/[G7221:115:32000:20]
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec
Compare [PCMA:8:8000:20]/[G7221:107:16000:20]
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec
Compare [PCMA:8:8000:20]/[PCMU:0:8000:20]
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec
Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2011-03-24 10:31:25.037256 [DEBUG] sofia_glue.c:2454 Set Codec
sofia/internal/1004(a)59.167.180.194 PCMA/8000 20 ms 160 samples
2011-03-24 10:31:25.049229 [DEBUG] sofia_glue.c:3955 Set 2833 dtmf
send/recv payload to 101
2011-03-24 10:31:25.049229 [DEBUG] sofia.c:4573
(sofia/internal/1004(a)59.167.180.194) State Change CS_NEW -> CS_INIT
2011-03-24 10:31:25.049229 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/1004(a)59.167.180.194 [BREAK]
2011-03-24 10:31:25.053356 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1004(a)59.167.180.194) Running State Change CS_INIT
2011-03-24 10:31:25.053356 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/1004(a)59.167.180.194) State INIT
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:83
sofia/internal/1004(a)59.167.180.194 SOFIA INIT
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:123
(sofia/internal/1004(a)59.167.180.194) State Change CS_INIT ->
CS_ROUTING
2011-03-24 10:31:25.055393 [DEBUG] switch_core_session.c:1047 Send
signal sofia/internal/1004(a)59.167.180.194 [BREAK]
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/1004(a)59.167.180.194) State INIT going to sleep
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/1004(a)59.167.180.194) Running State Change CS_ROUTING
2011-03-24 10:31:25.055393 [DEBUG] switch_channel.c:1512
(sofia/internal/1004(a)59.167.180.194) Callstate Change DOWN -> RINGING
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/1004(a)59.167.180.194) State ROUTING
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:146
sofia/internal/1004(a)59.167.180.194 SOFIA ROUTING
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:77
sofia/internal/1004(a)59.167.180.194 Standard ROUTING
2011-03-24 10:31:25.055393 [INFO] mod_dialplan_xml.c:331 Processing
Brian May <1004>->6201 in context public
Something went wrong here. It starts processing 6201 as per normal.
--
Brian May <brian(a)microcomaustralia.com.au>