[asterisk-bugs] [JIRA] (ASTERISK-25713) Queue produces large number of undesired cdr records

Thu Feb 18 16:49:33 CST 2016

    [ https://issues.asterisk.org/jira/browse/ASTERISK-25713?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=229573#comment-229573 ] 

George Keretchashvili edited comment on ASTERISK-25713 at 2/18/16 4:47 PM:
---------------------------------------------------------------------------

Attaching debug log file (debug_log_25713.txt) for a call. Hopefully I have sanitized file properly and removed unrelated debug output. Some unrelated data might be left as this is a production system with number of connections.

As seen in the file, queue_log row is inserted right after each try, cdr rows are inserted at the end of the call.

The following scenario is not present in this file, however is seen in bug description CDR log: when call is answered after several agent attempts, first CDR row shows 16 secs in 'duration' and 'billsec' fields (that is for the first attempt) and the last row shows talk time with an agent. That makes very difficult to extract even simple data from the CDR - total length of the call.

To track queues there is queue_log feature, which logs everything related to queues very well. I was able to use and extract information from CDR logs and queue_logs as expected for years. Now, CDR is all messed up and unusable in the name of 'people asked for it' and 'everything should be logged'. I understand logging is vital, however I don't understand how come this happened that CDR became real mess by default and without an fallback option because of people that do not bother to use perfectly designed queue_logs? Okay, I might be missing something, but at least there should an option to switch back to previous behavior of CDRs to be able to extract and manipulate data like number of calls, lengths of calls etc. Besides the size of CDR now grows like crazy and for me it will hold gigs of useless data after could of months.

was (Author: telvo):
Attaching debug log file (debug_log_25713.txt) for a call. Hopefully I have sanitized file properly and removed unrelated debug output. Some unrelated data might be left as this is a production system with number of connections.

As seen in the file, queue_log row is inserted right after each try, cdr rows are inserted at the end of the call.

The following scenario is not present in this file, however is seen in bug description CDR log: when call is answered after several agent attempts, first CDR row shows 16 secs in 'duration' and 'billsec' fields (that is for the first attempt) and the last row shows talk time with an agent. That makes very difficult to extract even simple data from the CDR - total length of the call.

To track queues there is queue_log feature, which logs everything related to queues very well. I was able to use and extract information from CDR logs and queue_logs as expected for years. Now, CDR is all messed up and unusable in the name of 'users asked for it'. I don't understand how come this happened that CDR became real mess by default and without an fallback option because of users that do not bother to use perfectly designed queue_logs? Okay, I might be missing something, but at least there should an option to switch back to previous behavior of CDRs to be able to extract and manipulate data like number of calls, lengths of calls etc. Besides the size of CDR now grows like crazy and for me it will hold gigs of useless data after could of months.

> Queue produces large number of undesired cdr records
> ----------------------------------------------------
>
>                 Key: ASTERISK-25713
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-25713
>             Project: Asterisk
>          Issue Type: Improvement
>      Security Level: None
>          Components: Applications/app_queue, CDR/General
>    Affects Versions: 13.4.0, 13.7.0
>         Environment: CentOS 7
>            Reporter: George Keretchashvili
>            Assignee: Unassigned
>         Attachments: debug_log_25713.txt, dialplan.ael.txt, queuerules.conf.txt, queues.conf.txt, queues.jpg, queues.sql.csv.txt, queues.sql.readable.txt
>
>
> Queue produces large number of undesired CDR records as a result of CDR behavior 12 version change.
> For example 1067 incoming calls to the system that have entered the queue, have produced 11672 CDR records. Beside that, I already have separate logging for queues and have 13624 records and use it for generating statistical data.
> CDR logs for each queue member retry when they're busy (in our case) are absolutely unnecessary for us and bring lots of trouble with generating statistics from CDR -  I find it hard even to calculate how many real incoming calls I have received during a day. Another problem is that the CDR table grows up very quickly.
> I am looking for a way to disable this behavior and have one CDR per call as before version 12.
> {noformat:title=CDR log for 1 call, 20 rows}
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b794","Queue","mozo","2016-01-21 10:28:29","2016-01-21 10:28:29","2016-01-21 10:28:46","16","16","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78916"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b795","Queue","mozo","2016-01-21 10:28:46","2016-01-21 10:28:46","2016-01-21 10:28:46","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78928"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b796","Queue","mozo","2016-01-21 10:28:51","2016-01-21 10:28:51","2016-01-21 10:28:51","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78930"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b797","Queue","mozo","2016-01-21 10:28:51","2016-01-21 10:28:51","2016-01-21 10:28:51","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78932"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b79a","Queue","mozo","2016-01-21 10:28:56","2016-01-21 10:28:56","2016-01-21 10:28:56","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78936"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b79b","Queue","mozo","2016-01-21 10:28:56","2016-01-21 10:28:56","2016-01-21 10:28:57","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78938"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b79d","Queue","mozo","2016-01-21 10:29:02","2016-01-21 10:29:02","2016-01-21 10:29:02","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78941"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b79e","Queue","mozo","2016-01-21 10:29:02","2016-01-21 10:29:02","2016-01-21 10:29:02","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78943"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b79f","Queue","mozo","2016-01-21 10:29:07","2016-01-21 10:29:07","2016-01-21 10:29:07","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78945"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b7a0","Queue","mozo","2016-01-21 10:29:07","2016-01-21 10:29:07","2016-01-21 10:29:07","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78947"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b7a1","Queue","mozo","2016-01-21 10:29:12","2016-01-21 10:29:12","2016-01-21 10:29:12","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78949"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b7a2","Queue","mozo","2016-01-21 10:29:12","2016-01-21 10:29:12","2016-01-21 10:29:12","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78951"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b7a3","Queue","mozo","2016-01-21 10:29:17","2016-01-21 10:29:17","2016-01-21 10:29:17","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78953"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b7a4","Queue","mozo","2016-01-21 10:29:17","2016-01-21 10:29:17","2016-01-21 10:29:17","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78955"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b7a5","Queue","mozo","2016-01-21 10:29:22","2016-01-21 10:29:22","2016-01-21 10:29:23","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78957"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b7a6","Queue","mozo","2016-01-21 10:29:23","2016-01-21 10:29:23","2016-01-21 10:29:23","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78959"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b7a7","Queue","mozo","2016-01-21 10:29:28","2016-01-21 10:29:28","2016-01-21 10:29:28","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78961"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-420-0000b7a8","Queue","mozo","2016-01-21 10:29:28","2016-01-21 10:29:28","2016-01-21 10:29:28","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-420","78963"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-418-0000b7aa","Queue","mozo","2016-01-21 10:29:33","2016-01-21 10:29:33","2016-01-21 10:29:33","0","0","BUSY","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-418","78966"
> "2500550","90558778549","s","MOZO_IVR","""995558778549"" <90558778549>","SIP/GEONET-0000b78c","SIP/mozo-419-0000b7ab","Queue","mozo","2016-01-21 10:29:33","2016-01-21 10:29:33","2016-01-21 10:31:31","117","117","ANSWERED","DOCUMENTATION",NULL,"1453357709.46988","1453357709.46988","mozo-419","78968"
> {noformat}
> {noformat:title=queue_log for the same call, 22 rows}
> "2016-01-21 10:28:46.363882","1453357709.46988","mozo","NONE","ENTERQUEUE",,"90558778549","1",,
> "2016-01-21 10:28:46.394437","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:28:46.482651","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:28:51.581619","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:28:51.672426","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:28:56.761529","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:28:57.023727","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","1000",,,,
> "2016-01-21 10:29:02.111538","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:02.222512","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:07.321435","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:07.412420","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:12.502565","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:12.682368","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:17.761432","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:17.932532","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:23.011526","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","1000",,,,
> "2016-01-21 10:29:23.122461","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:28.252452","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:28.441435","1453357709.46988","mozo","SIP/mozo-420","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:33.571692","1453357709.46988","mozo","SIP/mozo-418","RINGNOANSWER","0",,,,
> "2016-01-21 10:29:35.228784","1453357709.46988","mozo","SIP/mozo-419","CONNECT","49","1453357773.47019","1",,
> "2016-01-21 10:31:31.530847","1453357709.46988","mozo","SIP/mozo-419","COMPLETECALLER","49","116","1",,
> {noformat}

--
This message was sent by Atlassian JIRA
(v6.2#6252)