<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=ISO-8859-1">
</head>
<body bgcolor="#FFFFFF" text="#333333">
<tt><font size="-1">Hi guys, <br>
<br>
I have very weird case, which i dont understand. I have voice
menu where customer is choosing language, and all works fine
apart from this that after pressing 1 applications related to
1-ext are being processed immediatly and after pressinf 2, there
is 4-5 sec delay betweek 1st application is being processed
related to that extension 2.<br>
<br>
Difference which i am seeing in this log files is that in 2nd
case, there is "</font></tt><tt><font size="-1"> == CDR updated
on</font></tt> ...", but why in 1st case it isnt and in 2nd is ?
Could that be my source of problem ?<br>
<tt><font size="-1"><br>
Thanks for your help, any hint will do<br>
<br>
Regards<br>
Robert<br>
---------------------------------------<br>
<br>
Below you can find part of menu from and log files....<br>
</font></tt><tt><font size="-1"><br>
<br>
*** menu ***<br>
[voiceservices_menu]<br>
exten => 2666,1,Background(custom/l_stories/swelcome)<br>
exten => 2666,n,WaitExten(15) ;wait 15 sec<br>
<br>
exten => 1,1,Verbose(Customer pressed key 1)<br>
exten => 1,n,Goto(storiesmenu-lu,2666,1) ;if customer choosed
1 jump to LU lang<br>
<br>
exten => 2,1,Verbose(Customer pressed key 2)<br>
exten => 2,n,Goto(storiesmenu-en,2666,1) ;if customer choosed
1 jump to EN lang<br>
<br>
exten => i,1,Playback(invalid)<br>
exten => i,n,Goto(voiceservices_menu,2666,1)<br>
<br>
exten => t,1,Playback(vm-goodbye)<br>
exten => t,n,Goto(voiceservices_menu,2666,1)</font></tt><br>
<tt><font size="-1"><br>
*** console log, without delay after pressing 1 ***<br>
voice*CLI> <br>
[Nov 7 17:01:24] DTMF[12808]: channel.c:3960 __ast_read: DTMF
begin '1' received on IAX2/spiderman-6887<br>
[Nov 7 17:01:24] DTMF[12808]: channel.c:3964 __ast_read: DTMF
begin ignored '1' on IAX2/spiderman-6887<br>
[Nov 7 17:01:24] DTMF[12808]: channel.c:3875 __ast_read: DTMF
end '1' received on IAX2/spiderman-6887, duration 0 ms<br>
[Nov 7 17:01:24] DTMF[12808]: channel.c:3933 __ast_read: DTMF
end accepted without begin '1' on IAX2/spiderman-6887<br>
[Nov 7 17:01:24] DTMF[12808]: channel.c:3944 __ast_read: DTMF
end passthrough '1' on IAX2/spiderman-6887<br>
[Nov 7 17:01:24] DEBUG[12808]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:01:24] DEBUG[12808]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:01:24] DEBUG[12808]: channel.c:5018 set_format: Set
channel IAX2/spiderman-6887 to write format ulaw<br>
[Nov 7 17:01:24] DEBUG[12808]: pbx.c:4067 pbx_extension_helper:
Launching 'Verbose'<br>
-- Executing [1@incoming-from-spiderman:1]
Verbose("IAX2/spiderman-6887", "Customer pressed key 1") in new
stack<br>
Customer pressed key 1<br>
[Nov 7 17:01:24] DEBUG[12808]: pbx.c:4067 pbx_extension_helper:
Launching 'Goto'<br>
-- Executing [1@incoming-from-spiderman:2]
Goto("IAX2/spiderman-6887", "storiesmenu-lu,2666,1") in new
stack<br>
-- Goto (storiesmenu-lu,2666,1)<br>
[Nov 7 17:01:24] DEBUG[12808]: pbx.c:4067 pbx_extension_helper:
Launching 'BackGround'<br>
-- Executing [2666@storiesmenu-lu:1]
BackGround("IAX2/spiderman-6887",
"custom/l_stories/lu_service_menu") in new stack<br>
[Nov 7 17:01:24] DEBUG[12808]: channel.c:5018 set_format: Set
channel IAX2/spiderman-6887 to write format gsm<br>
[Nov 7 17:01:24] DEBUG[12808]: channel.c:3402 ast_settimeout:
Scheduling timer at (50 requested / 50 actual) timer ticks per
second<br>
-- <IAX2/spiderman-6887> Playing
'custom/l_stories/lu_service_menu.gsm' (language 'en')<br>
[Nov 7 17:01:25] DEBUG[28034]: chan_iax2.c:10631
socket_process: Immediately destroying 6887, having received
hangup<br>
[Nov 7 17:01:25] DEBUG[12808]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:01:25] DEBUG[12808]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:01:25] DEBUG[12808]: channel.c:5018 set_format: Set
channel IAX2/spiderman-6887 to write format ulaw<br>
<br>
<br>
<br>
</font></tt><tt><font size="-1">*** console log, 4 sec delay after
pressing 2 ***</font></tt><br>
<tt><font size="-1">[Nov 7 17:19:42] DTMF[13309]: channel.c:3875
__ast_read: DTMF end '2' received on IAX2/spiderman-7784,
duration 0 ms<br>
[Nov 7 17:19:42] DTMF[13309]: channel.c:3933 __ast_read: DTMF
end accepted without begin '2' on IAX2/spiderman-7784<br>
[Nov 7 17:19:42] DTMF[13309]: channel.c:3944 __ast_read: DTMF
end passthrough '2' on IAX2/spiderman-7784<br>
[Nov 7 17:19:42] DEBUG[13309]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:19:42] DEBUG[13309]: channel.c:3402 ast_settimeout:
Scheduling timer at (0 requested / 0 actual) timer ticks per
second<br>
[Nov 7 17:19:42] DEBUG[13309]: channel.c:5018 set_format: Set
channel IAX2/spiderman-7784 to write format ulaw<br>
[Nov 7 17:19:42] DEBUG[13309]: pbx.c:4734 __ast_pbx_run: Oooh,
got something to jump out with ('2')!<br>
[Nov 7 17:19:46] DEBUG[28037]: chan_iax2.c:2366 peercnt_add: ip
callno count incremented to 4 for 62.233.208.241<br>
[Nov 7 17:19:46] DEBUG[28022]: chan_iax2.c:13889
iax2_devicestate: Checking device state for device spiderman<br>
[Nov 7 17:19:46] DEBUG[28022]: chan_iax2.c:13897
iax2_devicestate: iax2_devicestate: Found peer. What's device
state of spiderman? addr=1055510769, defaddr=0 maxms=0, lastms=0<br>
[Nov 7 17:19:46] DEBUG[28022]: devicestate.c:458
do_state_change: Changing state for IAX2/spiderman - state 2 (In
use)<br>
[Nov 7 17:19:46] DEBUG[28022]: devicestate.c:438
devstate_event: device 'IAX2/spiderman' state '2'<br>
[Nov 7 17:19:46] DEBUG[28052]: app_queue.c:1330
handle_statechange: Device 'IAX2/spiderman' changed to state '2'
(In use) but we don't care because they're not a member of any
queue.<br>
[Nov 7 17:19:46] DEBUG[28022]: chan_iax2.c:13889
iax2_devicestate: Checking device state for device spiderman<br>
[Nov 7 17:19:46] DEBUG[28022]: chan_iax2.c:13897
iax2_devicestate: iax2_devicestate: Found peer. What's device
state of spiderman? addr=1055510769, defaddr=0 maxms=0, lastms=0<br>
[Nov 7 17:19:46] DEBUG[28022]: devicestate.c:458
do_state_change: Changing state for IAX2/spiderman - state 2 (In
use)<br>
[Nov 7 17:19:46] DEBUG[28022]: devicestate.c:438
devstate_event: device 'IAX2/spiderman' state '2'<br>
[Nov 7 17:19:46] DEBUG[28052]: app_queue.c:1330
handle_statechange: Device 'IAX2/spiderman' changed to state '2'
(In use) but we don't care because they're not a member of any
queue.<br>
[Nov 7 17:19:46] DEBUG[28034]: chan_iax2.c:2714
sched_delay_remove: schedule decrement of callno used for
62.233.208.241 in 60 seconds<br>
== CDR updated on IAX2/spiderman-7784<br>
[Nov 7 17:19:47] DEBUG[13309]: pbx.c:4067 pbx_extension_helper:
Launching 'Verbose'<br>
-- Executing [2@incoming-from-spiderman:1]
Verbose("IAX2/spiderman-7784", "Customer pressed key 2") in new
stack<br>
Customer pressed key 2<br>
[Nov 7 17:19:47] DEBUG[13309]: pbx.c:4067 pbx_extension_helper:
Launching 'Goto'<br>
-- Executing [2@incoming-from-spiderman:2]
Goto("IAX2/spiderman-7784", "storiesmenu-en,2666,1") in new
stack<br>
-- Goto (storiesmenu-en,2666,1)<br>
[Nov 7 17:19:47] DEBUG[13309]: pbx.c:4067 pbx_extension_helper:
Launching 'BackGround'<br>
-- Executing [2666@storiesmenu-en:1]
BackGround("IAX2/spiderman-7784",
"custom/l_stories/en_service_menu") in new stack<br>
[Nov 7 17:19:47] DEBUG[13309]: channel.c:5018 set_format: Set
channel IAX2/spiderman-7784 to write format gsm<br>
[Nov 7 17:19:47] DEBUG[13309]: channel.c:3402 ast_settimeout:
Scheduling timer at (50 requested / 50 actual) timer ticks per
second<br>
-- <IAX2/spiderman-7784> Playing
'custom/l_stories/en_service_menu.gsm' (language 'en')<br>
[Nov 7 17:19:49] DEBUG[28045]: acl.c:715 ast_ouraddrfor: For
destination '192.168.2.124', our source address is '10.0.0.6'.<br>
[Nov 7 17:19:49] DEBUG[28045]: chan_sip.c:3243
ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address
10.0.0.6:5060<br>
[Nov 7 17:19:49] DEBUG[28045]: chan_sip.c:7215 sip_alloc:
Allocating new SIP dialog for
<a class="moz-txt-link-abbreviated" href="mailto:2a117190-c1f63b91-a8eee9ca@192.168.2.124">2a117190-c1f63b91-a8eee9ca@192.168.2.124</a> - REGISTER (No RTP)<br>
<br>
<br>
</font></tt>
</body>
</html>