[Home]

Summary:ASTERISK-25179: CDR(billsec,f) and CDR(duration,f) report incorrect values
Reporter:Gianluca Merlo (gian)Labels:
Date Opened:2015-06-22 03:56:28Date Closed:2016-01-20 10:35:53.000-0600
Priority:MajorRegression?
Status:Closed/CompleteComponents:CDR/cdr_custom Functions/func_cdr
Versions:13.4.0 Frequency of
Occurrence
Constant
Related
Issues:
Environment:Attachments:( 0) ASTERISK-25179-13.diff
( 1) ASTERISK-25179-13-2.diff
Description:Hello,

I noticed, while reviewing CSV CDRs created with cdr_custom, that while CDR(billsec) and CDR(duration) report correct values, the corresponding high precision values CDR(billsec,f) and CDR(duration,f) are wrong. More specifically these values seem to be a thousandth of their non-high-precision counterpart (e.g. if CDR(billsec) is 37, CDR(billsec,f) is 0.037000 ).

It seems to me that the code in funcs/func_cdr.c gets this value via ast_cdr_getvar() (from main/cdr.c), and assumes that the returned value is in milliseconds, this dividing the value by 1000. The problem appears to be that ast_cdr_getvar() gets the value via cdr_object_format_property() and thus via two specialized functions

* cdr_object_get_duration()
* cdr_object_get_billsec()

which both return the value in seconds. General assumptions seem to indicate that internal representation of these values should be considered in milliseconds. I hope you can verify my guesses, and provide a consistent fix.

As a side note, I can confirm that the issue was not present in the 1.8 series, and that the affected portions of code have been reorganized since then. In that version, values were returned in milliseconds, and the CDR() functions handled them properly.
Comments:By: Rusty Newton (rnewton) 2015-06-24 15:57:35.917-0500

From the documentation
https://wiki.asterisk.org/wiki/display/AST/Asterisk+13+Function_CDR

{quote}
f - Returns billsec or duration fields as floating point values.
{quote}

It sounds like things are functioning correctly.

Where are you getting the idea that the f option should return the value in milliseconds?

By: Gianluca Merlo (gian) 2015-06-25 03:27:12.325-0500

Hello Rusty,

I apologize, my explanation was probably a bit chaotic, and led you to misunderstand my observations.

I do not expect CDR(billsec,f) to return a value in milliseconds, but it seems it is returning a floating point value that is a thousandth of the correct value. E.g. if cdr_custom.conf includes

{noformat}
[mappings]
durations.csv => ${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec,f)})},${CSV_QUOTE(${CDR(duration,f)})}
{noformat}

the produced durations.csv file contains (again, as an example)

{noformat}
"7","30","0.007000","0.030000"
{noformat}

I hope that this clarifies the issue and helps you reproduce my findings. My initial description included an attempt to explain the portion of code that I deem related to the issue.

By: Rusty Newton (rnewton) 2015-06-25 08:39:23.973-0500

Ahh yes I see. I mis-read your description as well. That does look like a bug.

By: ServTelAr (servtelar) 2016-01-05 11:36:53.318-0600

I observed the same thing here on 13.5.0.
I see cdr_custom.c calls ast_str_substitute_variables, but I didn't see any reference to a float value in that function. Am I missing something?

By: Matt Jordan (mjordan) 2016-01-19 10:04:21.253-0600

[~servtelar] or [~gian]: I've written a patch that I believe fixes this issue. It's currently up on Gerrit for code review, but I've also attached a patch to this issue that you can try out.

Please let me know if it fixes the issue for you. Thanks!

By: ServTelAr (servtelar) 2016-01-19 10:07:11.904-0600

Testing now. Ill let you know as soon as I can.

Thanks a lot

By: ServTelAr (servtelar) 2016-01-19 10:21:45.530-0600

It shows 4 warnings:

[2016-01-19 13:15:39.870] DEBUG[6917]: pbx.c:4584 ast_str_substitute_variables_full: Evaluating 'CDR(duration,f)' (from 'CDR(duration,f)})' len 15)
[2016-01-19 13:15:39.870] WARNING[6917]: func_cdr.c:239 cdr_retrieve_time: Failed to fully extract 'start' from CDR
[2016-01-19 13:15:39.871] WARNING[6917]: func_cdr.c:239 cdr_retrieve_time: Failed to fully extract 'end' from CDR
[2016-01-19 13:15:39.871] DEBUG[6917]: pbx.c:4618 ast_str_substitute_variables_full: Function CDR(duration,f) result is '0.000000'
[2016-01-19 13:15:39.871] DEBUG[6917]: pbx.c:4584 ast_str_substitute_variables_full: Evaluating 'CDR(billsec,f)' (from 'CDR(billsec,f)})' len 14)
[2016-01-19 13:15:39.871] WARNING[6917]: func_cdr.c:239 cdr_retrieve_time: Failed to fully extract 'answer' from CDR
[2016-01-19 13:15:39.871] WARNING[6917]: func_cdr.c:239 cdr_retrieve_time: Failed to fully extract 'end' from CDR
[2016-01-19 13:15:39.871] DEBUG[6917]: pbx.c:4618 ast_str_substitute_variables_full: Function CDR(billsec,f) result is '0.000000'


By: Matt Jordan (mjordan) 2016-01-20 08:12:23.875-0600

Eek. Sorry about that - the second revision of the patch attached to the issue should fix that glitch.

By: ServTelAr (servtelar) 2016-01-20 09:52:46.602-0600

Hi Matt

Great, worked like a charm:

[2016-01-20 12:45:38.477] DEBUG[14848]: pbx.c:4618 ast_str_substitute_variables_full: Function CDR(duration,f) result is '10.271717'
[2016-01-20 12:45:38.477] DEBUG[14848]: pbx.c:4618 ast_str_substitute_variables_full: Function CSV_QUOTE(10.271717) result is '"10.271717"'
[2016-01-20 12:45:38.477] DEBUG[14848]: pbx.c:4618 ast_str_substitute_variables_full: Function CDR(billsec,f) result is '7.253883'
[2016-01-20 12:45:38.478] DEBUG[14848]: pbx.c:4618 ast_str_substitute_variables_full: Function CSV_QUOTE(7.253883) result is '"7.253883"'

Master.csv on custom:
"""2300"" <2300>","2300","2222","common","SIP/2300-00000000","","Wait","60","2016-01-20 12:45:28","2016-01-20 12:45:31","2016-01-20 12:45:38","10.271717","7.253883","ANSWERED","DOCUMENTATION","","MORN-1453304728.0","",0

Thanks a lot!