asterisk users - Dec 2003 - Strange variable chopping from AGI's

AGI's are resulting in unusual behaviors.  Can someone please tell me 
if this is my inappropriate use of AGI's, inappropriate use of 
Time::HiRes, or a bug with *:

I call this script twice:

#!/usr/bin/perl
use Time::HiRes qw( gettimeofday );
($seconds, $microseconds) = gettimeofday;
$hirestime = sprintf("%s","$seconds$microseconds");
print "SET VARIABLE HIRESTIMESTAMP $hirestime\n";


I run this script twice, once before a bunch of stuff, and once 
after, in order to perform a crude version of time measurement. 
However, the script sometimes (1 out of 20?  40?) will return with 
fewer digits in the output of the AGI, which means that when I do my 
subtraction, the numbers come out negative or wildy incorrect.  I'm 
throwing 5 calls into the outgoing spool at once during these tests. 
What's going on here with AGI return values getting chopped? 
Sometimes the first column gets chopped, sometimes the second column 
gets chopped.  Numbers can and do end in "0", so this is not an issue 
of the digits being dropped due to ending with "0" or "00".

Other notes: if I swap out priority 5 with other non-agi 
applications, there is no difference in results.

[foo]
exten => _X.,1,AbsoluteTimeout(4)
exten => _X.,2,AGI(/home/jtodd/agi/timer1)
exten => _X.,3,SetVar(STARTTIME=${HIRESTIMESTAMP})
exten => _X.,4,NoOp(${HIRESTIMESTAMP})
exten => _X.,5,AGI(some-harmless-other-agi-here)
exten => _X.,6,AGI(/home/jtodd/agi/timer1)
exten => _X.,7,NoOp(${HIRESTIMESTAMP})
exten => _X.,8,SetVar(ENDTIME=${HIRESTIMESTAMP})
exten => _X.,9,SetVar(DURATION=$[${ENDTIME} - ${STARTTIME}])
exten => _X.,10,System(echo ${STARTTIME} ${ENDTIME} ${DURATION} >>
/tmp/tests)
exten => _X.,11,Hangup


example output:

start time       end time         duration (endtime-starttime)
1070917681581683 1070917681942384 360701
1070917681666607 1070917681968283 301676
1070918477712530 1070918478137011 424481
1070917681788671 1070917681998254 209583
1070917681837624 107091768221563 -963825913616061  <- error!



JT

On Mon, 2003-12-08 at 15:31, John Todd wrote:
> AGI's are resulting in unusual behaviors.  Can someone please tell me 
> if this is my inappropriate use of AGI's, inappropriate use of 
> Time::HiRes, or a bug with *:
> 
> I call this script twice:
> 
> #!/usr/bin/perl
> use Time::HiRes qw( gettimeofday );
> ($seconds, $microseconds) = gettimeofday;
> $hirestime = sprintf("%s","$seconds$microseconds");
> print "SET VARIABLE HIRESTIMESTAMP $hirestime\n";
I think your problem is with the fact that leading zeros in
$microseconds are not important enough to show up. What you need to do
is dived it by 1000 to shift the digits down and preserve the leading
zeros. Then you won't get chomping of digits when you sprintf the
combination. Either that or you will need to multiply the seconds by
1000 before adding the two fields together and staying all microseconds.
-- 
Steven Critchfield  <critch@basesys.com>

On Mon, 8 Dec 2003, John Todd wrote:
> 
> AGI's are resulting in unusual behaviors.  Can someone please tell me 
> if this is my inappropriate use of AGI's, inappropriate use of 
> Time::HiRes, or a bug with *:
I'd say inappropriate use on Time::HiRes.  Microseconds increment from 0
up to 999,999 and when it passes that mark the second count is incremented
and microseconds is reset to 0.
> 
> I call this script twice:
> 
> #!/usr/bin/perl
> use Time::HiRes qw( gettimeofday );
> ($seconds, $microseconds) = gettimeofday;
> $hirestime = sprintf("%s","$seconds$microseconds");
> print "SET VARIABLE HIRESTIMESTAMP $hirestime\n";
There are tons of ways to do this right, but here are two of them.

Change your sprintf to:
$hirestime = sprintf("%d%06d", $seconds, $microseconds);
This will make it so that microseconds will always be 6 characters long

or change it to something like:
$hirestime = sprintf("%d.%d", $seconds, $microseconds);
So there will always be a decimal place between seconds and microseconds.
Assuming your later code can deal with it, this is the way I would do it.
> start time       end time         duration (endtime-starttime)
> 1070917681581683 1070917681942384 360701
> 1070917681666607 1070917681968283 301676
> 1070918477712530 1070918478137011 424481
> 1070917681788671 1070917681998254 209583
> 1070917681837624 107091768221563 -963825913616061  <- error!
Makes sense to me, here is how the numbers look when broken in seconds and
microseconds
1070917681.837624 1070917682.21563

James

James Golovich <james@wwnet.net> wrote:
>Change your sprintf to:
>$hirestime = sprintf("%d%06d", $seconds, $microseconds);
>This will make it so that microseconds will always be 6 characters long
>or change it to something like:
>$hirestime = sprintf("%d.%d", $seconds, $microseconds);
>So there will always be a decimal place between seconds and microseconds.
You still need to %06d in the second example, so that should read:

# either:
$hirestime = sprintf("%d%06d", $seconds, $microseconds);
# or:
$hirestime = sprintf("%d.%06d", $seconds, $microseconds);

depending on whether you want $hirestime to be in seconds or mcroseconds.

-JimC