[Home]

Summary:ASTERISK-06195: [patch] L option of Dial does not work properly
Reporter:Peng Yong (ppyy)Labels:
Date Opened:2006-01-26 02:41:30.000-0600Date Closed:2006-11-09 15:10:00.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_dial
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) cdr.txt
( 1) fulllog.txt
( 2) patch.timelimit
Description:exten => 3002,1,Dial(SIP/8888,60,HL(57000:60000:30000))

duration of the call will not be longer than 57s, but the CDR shows that some call will last 87s (30s longer).

and i add some debug info after following statement shows:

Jan 26 17:06:26 DEBUG[30192] channel.c: DDDBBBGGG1: time_left_ms 1, timelimit: 57000.

time_left_ms = config->timelimit - ast_tvdiff_ms(now, config->start_time);

so the call will last (timelimit + warning_freq) some time
Comments:By: Peng Yong (ppyy) 2006-01-26 02:56:56.000-0600

should also merge into 1.2
By: Dawid M (dmielnik) 2006-01-27 07:02:22.000-0600

I have also noticed this problem. After applying this patch I still get actual answered time longer than that spicified in L option:

-- AGI Script Executing Application: (DIAL) Options: (IAX2/opt1/0221234567|120|CL(240000:30000))
   -- Limit Data for this call:
   -- - timelimit     = 240000
   -- - play_warning  = 30000
   -- - play_to_caller= yes
   -- - play_to_callee= no

(..)

prepaid|2653|0221234567: >> GET VARIABLE ANSWEREDTIME
prepaid|2653|0221234567: makeBillingAttributes: bill_seconds 241

sometimes its 2/3 seconds - sometimes much longer

(asterisk 1.2.0)
By: Peng Yong (ppyy) 2006-01-27 08:55:20.000-0600

dmielnik, your problem is not same as this issue.

the bug of this issue is only happened when you z parameter of L(x[:y][:z]).
when there is a z parameter, sometime the call will last (timelimit + warning_freq).

your dialplan only have L(X:Y), no Z. and your CDR shows bill_seconds is a little longer than timelimit (x parameter). the CDR is posted when the channel is hangup, so it's a little longer than timelimit, from which will start to hangup the channer.

maybe you should decrease one second:

(IAX2/opt1/0221234567|120|CL(239000:30000))

any one have good solution to problem of dmielnik ?

BTW, you say "sometimes much longer", then how long?
By: Dawid M (dmielnik) 2006-01-27 11:28:23.000-0600

I noticed the problem when I discovered a 'large' negative balance in one of the prepaid accounts (AGI application) which would suggest that the caller talked a couple of minutes more than the max calculated call time. Unfortunately I have no logs for this.

When tracking down the problem I got to this - the L option in Dial command. Unfortunately I cant seem to reproduce the problem with more than 3 seconds over the Dial L limit.
By: Dawid M (dmielnik) 2006-01-27 11:32:48.000-0600

btw - at first I have tried to decrease the limit by two seconds - but it varies, sometimes the call disconnects correctly - sometimes 1, 2 or 3 seconds later - what I have done now is set call duration (billing) to my limit in L if the actual call duration is larger than the L limit - which is really ugly hack for the problem :/
By: Peng Yong (ppyy) 2006-01-27 12:34:44.000-0600

it's important to prepaid accounting system.

in my situation:
time 0, Dial(SIP/8888,60,HL(57000:60000:30000))
time 0, Play warning_sound
time 29999, time_left_ms=30001, Play warning_sound again
time 59999, time_left_ms=1, bridge channels extra time(warning_freq, 30s)

time_left_ms=1, so don't stop bridge
if (config->warning_freq)
      nexteventts = ast_tvadd(nexteventts, ast_samp2tv(config->warning_freq, 1000));



in dmielnik situation:

time 0, Dial(IAX2/opt1/0221234567|120|CL(240000:30000))
time 240000-30000, Play warning_sound
time 240000, stop bridge
time 240000+?   gernerate CDR (maybe sevral second longer than 240000), hangup
By: Kevin P. Fleming (kpfleming) 2006-02-14 15:24:08.000-0600

This code was fixed recently to correct rounding errors that allowed calls to last longer than they should. If you can still reproduce this problem, you can request the bug to be reopened, but you will need to:

1) provide a revision number of the code you tested with
2) provide an actual complete trace of the call lasting longer than it should, not just a chopped-up summary

At the moment I don't see any reason for this patch to be applied.
By: Peng Yong (ppyy) 2006-02-14 23:49:42.000-0600

easy to reproduce the problem.

img*CLI> show version
Asterisk SVN-branch-1.2-r10137M built by root @ img.cn99.com on a i686 running Linux on 2006-02-15 06:08:14 UTC

[pbx]
exten => 8863,1,Dial(SIP/8888,60,HL(57000:60000:30000))

i test only 8 times and get 3 such issues. cdrs and full log attached.
By: Olle Johansson (oej) 2006-04-04 08:54:08

kpfleming: Did you look at the provided files?

/Housekeeping
By: Nir Simionovich (atelis) 2006-04-11 09:37:47

Any news about this bug, I've tried applying the above patch, but still option L still doesn't work - anybody working on it?

I've been trying to use the L parameter according to the following scenario:

1. Manager originates a call to a Local channel
2. Local channels answers and performs a Dial via a SIP channel. The Dial command has an L parameter defined with (90000:60000:30000).
3. Remote SIP end picks up the call and is passed into a MeetMe room.

Although I see that the asterisk received the information to the L parameter correctly, the call isn't hung up at 90 seconds, not even at 110 seconds. A warning sound isn't played, nothing actually happend. I trying bringing up the debug level and see what's going on, Asterisk doesn't even show anything happening at the time the warning is supposed to come out.

After this, I did a small experiment to do a simple dial using a direct IAX->SIP connection, and the problem wasn't there. Looks like that problem here is related to chan_local or something like that.

I've also added a typeout of my console at http://pastebin.com/653673

Which appear to show the following:

#
Apr 11 19:39:02 DEBUG[21712]: app_meetme.c:1062 conf_run: Placed channel SIP/62.90.49.50-fcf4 in ZAP conf 1023
#
   -- Stopped music on hold on SIP/62.90.49.50-35b5
#
Apr 11 19:39:02 DEBUG[21710]: channel.c:1718 ast_settimeout: Scheduling timer at 0 sample intervals
#
 == Spawn extension (macro-ngx1_originator_connect, s, 16) exited non-zero on 'SIP/62.90.49.50-35b5' in macro 'ngx1_originator_connect'
#
Apr 11 19:39:08 DEBUG[21710]: app_dial.c:1442 dial_exec_full: Macro exited with status -1
#
Apr 11 19:39:08 WARNING[21710]: res_features.c:1374 ast_bridge_call: Bridge failed on channels Local/972544482826@ngx1_call_init_originator-eafc,2 and SIP/62.90.49.50-35b5
#
Apr 11 19:39:08 DEBUG[21710]: chan_sip.c:2419 sip_hangup: update_call_counter(972544482826) - decrement call limit counter
#
Apr 11 19:39:08 DEBUG[21710]: app_dial.c:1588 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
#
 == Spawn extension (ngx1_call_init_originator, 972544482826, 7) exited non-zero on 'Local/972544482826@ngx1_call_init_originator-eafc,2'
#
   -- Executing DeadAGI("Local/972544482826@ngx1_call_init_originator-eafc,2", "agiGenericWrapper.php|inC2^HandleOriginatorDisconnect") in new stack

Any idea about that warning up there?


By: Andrey S Pankov (casper) 2006-04-11 10:41:32

atelis: do you pass /n option to chan_local? Anyway this bug report in for an other issue IMO.
By: Nir Simionovich (atelis) 2006-04-11 10:44:45

Just tested the /n option, behaviour remains.

I think you are correct, this needs to be moved to a new bug, as it's most probably an issue with chan_local


By: Kevin P. Fleming (kpfleming) 2006-04-11 15:12:52

This appears to have been caused by the 'warning' time being longer than the total call time limit, so the next event was calculated incorrectly. I have fixed app_dial in 1.2 and trunk so that the 'first warning' time is reduced so that it will occur within the call's total time if possible, thus eliminating the miscalculation. Please retest your dialplan after updating from Subversion. Thanks!
By: Peng Yong (ppyy) 2006-08-18 12:51:42

i still find some problem in our cdrs if we does not apply this patch.
By: Serge Vecher (serge-v) 2006-09-06 12:13:11

ppyy: please provide specific information that will show the problem you are still having with CDRs.
By: Peng Yong (ppyy) 2006-09-07 08:43:03

exten => 1023,1,Dial(SIP/8888,60,HL(30000:15000:5000))

i tested five times, and got three error which have 35 seconds cdr other than 30 seconds limits.

""Peng Yong@gz" <6802>","6802","1023","pbx","SIP/gz.pbx.netease.com-081a5748","SIP/8888-081aac88","Dial","SIP/8888|60|HL(30000:15000
:5000)","2006-09-07 21:35:20","2006-09-07 21:35:23","2006-09-07 21:35:53","33","30","ANSWERED","DOCUMENTATION","","1157636120.0",""
""Peng Yong@gz" <6802>","6802","1023","pbx","SIP/gz.pbx.netease.com-081a5748","SIP/8888-081aac88","Dial","SIP/8888|60|HL(30000:15000
:5000)","2006-09-07 21:36:00","2006-09-07 21:36:02","2006-09-07 21:36:37","37","35","ANSWERED","DOCUMENTATION","","1157636160.2",""
""Peng Yong@gz" <6802>","6802","1023","pbx","SIP/gz.pbx.netease.com-081a5748","SIP/8888-081aac88","Dial","SIP/8888|60|HL(30000:15000
:5000)","2006-09-07 21:37:31","2006-09-07 21:37:34","2006-09-07 21:38:09","38","35","ANSWERED","DOCUMENTATION","","1157636251.4",""
""Peng Yong@gz" <6802>","6802","1023","pbx","SIP/gz.pbx.netease.com-081a5748","SIP/8888-081aac88","Dial","SIP/8888|60|HL(30000:15000
:5000)","2006-09-07 21:38:12","2006-09-07 21:38:13","2006-09-07 21:38:43","31","30","ANSWERED","DOCUMENTATION","","1157636292.6",""
""Peng Yong@gz" <6802>","6802","1023","pbx","SIP/gz.pbx.netease.com-081a5748","SIP/8888-081aac88","Dial","SIP/8888|60|HL(30000:15000
:5000)","2006-09-07 21:38:46","2006-09-07 21:38:47","2006-09-07 21:39:22","36","35","ANSWERED","DOCUMENTATION","","1157636326.8",""

and here is output of console:

   -- Called 8888
   -- SIP/8888-081aac88 is ringing
   -- SIP/8888-081aac88 answered SIP/gz.pbx.netease.com-081a5748
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/15' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/10' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/5' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Executing Dial("SIP/gz.pbx.netease.com-081a5748", "SIP/8888|60|HL(30000:15000:5000)") in new stack
   -- Limit Data for this call:
   -- - timelimit     = 30000
   -- - play_warning  = 15000
   -- - play_to_caller= yes
   -- - play_to_callee= no
   -- - warning_freq  = 5000
   -- - start_sound   = UNDEF
   -- - warning_sound = timeleft
   -- - end_sound     = UNDEF
   -- Called 8888
Sep  7 21:38:12 NOTICE[25524]: res_musiconhold.c:515 monmp3thread: Request to schedule in the past?!?!
   -- SIP/8888-081aac88 is ringing
   -- SIP/8888-081aac88 answered SIP/gz.pbx.netease.com-081a5748
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/15' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/10' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/5' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Executing Dial("SIP/gz.pbx.netease.com-081a5748", "SIP/8888|60|HL(30000:15000:5000)") in new stack
   -- Limit Data for this call:
   -- - timelimit     = 30000
   -- - play_warning  = 15000
   -- - play_to_caller= yes
   -- - play_to_callee= no
   -- - warning_freq  = 5000
   -- - start_sound   = UNDEF
   -- - warning_sound = timeleft
   -- - end_sound     = UNDEF
Sep  7 21:38:46 NOTICE[25524]: res_musiconhold.c:515 monmp3thread: Request to schedule in the past?!?!
   -- Called 8888
   -- SIP/8888-081aac88 is ringing
   -- SIP/8888-081aac88 answered SIP/gz.pbx.netease.com-081a5748
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/15' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/10' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
   -- Playing 'vm-youhave' (language 'en')
   -- Playing 'digits/5' (language 'en')
   -- Playing 'queue-seconds' (language 'en')
By: Serge Vecher (serge-v) 2006-09-07 09:00:11

alright, and what version of Asterisk is this on?
By: Peng Yong (ppyy) 2006-09-07 09:55:49

CLI> show version
Asterisk SVN-branch-1.2-r42200M built by root @ bar3.3322.org on a i686 running Linux on 2006-09-07 13:48:03 UTC
By: Anthony LaMantia (alamantia) 2006-10-30 12:51:46.000-0600

anyone have any thoughts on this patch vs the one in 0007531?
By: Anthony LaMantia (alamantia) 2006-11-09 15:09:39.000-0600

the patch commited via 7531 resolves this issue... if you are still having trouble   reopen this bug,
By: Anthony LaMantia (alamantia) 2006-11-09 15:09:58.000-0600

fixed via bug 7531.