[Home]

Summary:ASTERISK-24016: CDR logs multiple unanswered devices despite unanswered=no
Reporter:S C (stephen)Labels:
Date Opened:2014-07-10 07:56:29Date Closed:2014-08-28 07:58:22
Priority:MinorRegression?
Status:Closed/CompleteComponents:CDR/General
Versions:12.3.2 Frequency of
Occurrence		Constant
Related
Issues:
is related toASTERISK-24279 Documentation: Clarify the behaviour of the CDR property 'unanswered'
Environment:Attachments:
Description:Every available device in a Dial command get a cdr record when unanswered (both by hangup or dial timeout).  Setting "unanswered" in cdr.conf to yes or no does not affect behavior.
Comments:By: Matt Jordan (mjordan) 2014-07-10 08:53:42.911-0500

Thank you for taking the time to report this bug and helping to make Asterisk better. Unfortunately, we cannot work on this bug because your description did not include enough information. You may find it helpful to read the Asterisk Issue Guidelines http://www.asterisk.org/developers/bug-guidelines. We would be grateful if you would then provide a more complete description of the problem. At a minimum, we need:

1. the specific steps or actions you took that caused you to encounter the problem,
2. the behavior you expected, and
3. the behavior you actually encountered (in as much detail as possible).

This likely includes output from the console with debug level logging, a SIP trace (if this is SIP related), and configuration information such as dialplan (e.g. extensions.conf) and channel configuration (e.g. sip.conf). Thanks!


By: S C (stephen) 2014-07-10 09:44:59.964-0500

1. Steps to reproduce: Dial multiple extensions which go unanswered: eg. dial(SIP/ext1&SIP/ext2)
2. Expected: 0 or 1 CDRs recorded.
3. Actual: multiple CDRs recorded - one per device.

Comment excerpt from cdr.conf regarding "unanswered":
{quote}
[...]"For example, if you try to dial 3 extensions, and this option is "yes", you will get 3 CDR's, one for each phone that was rung."
{quote}
Implies I should not get 3 CDR's if set to "no"?  In any case, these multiple CDRs are undesired.


extensions.conf:
{noformat}
[restricted]
exten = *779,1,dial(SIP/sipura&SIP/stephen)
{noformat}

{noformat}
VERBOSE[10706][C-000000dc] pbx.c: [Jul 10 08:55:13]     -- Executing [*779@restricted:1] Dial("SIP/stephen-android-000000a6", "SIP/sipura&SIP/stephen") in new stack
VERBOSE[10706][C-000000dc] netsock2.c: [Jul 10 08:55:13]   == Using SIP RTP CoS mark 5
VERBOSE[10706][C-000000dc] netsock2.c: [Jul 10 08:55:13]   == Using SIP RTP CoS mark 5
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- Called SIP/sipura
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- Called SIP/stephen
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- SIP/stephen-000000a8 connected line has changed. Saving it until answer for SIP/stephen-android-000000a6
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- SIP/sipura-000000a7 connected line has changed. Saving it until answer for SIP/stephen-android-000000a6
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- SIP/stephen-000000a8 is ringing
VERBOSE[10706][C-000000dc] app_dial.c: [Jul 10 08:55:13]     -- SIP/sipura-000000a7 is ringing
VERBOSE[10706][C-000000dc] pbx.c: [Jul 10 08:55:22]   == Spawn extension (restricted, *779, 1) exited non-zero on 'SIP/stephen-android-000000a6'
{noformat}

2 CDR's produced:

{noformat}
"","XXXXXXXXXX","*779","restricted",""""" <XXXXXXXXXX>","SIP/stephen-android-000000a6","SIP/sipura-000000a7","Dial","SIP/sipura&SIP/stephen","2014-07-10 12:55:13",,"2014-07-10 12:55:22",8,0,"NO ANSWER","DOCUMENTATION","1404996913.480",""
"","XXXXXXXXXX","*779","restricted",""""" <XXXXXXXXXX>","SIP/stephen-android-000000a6","SIP/stephen-000000a8","Dial","SIP/sipura&SIP/stephen","2014-07-10 12:55:13",,"2014-07-10 12:55:22",8,0,"NO ANSWER","DOCUMENTATION","1404996913.480",""
{noformat}
By: Rusty Newton (rnewton) 2014-08-04 18:16:13.894-0500

This happens with all CDR backends?
By: Rusty Newton (rnewton) 2014-08-26 14:51:01.518-0500

I tested with the core supported cdr_custom backend. The behavior appears as you describe.

My test was SIP/6001 dialing Dial(SIP/6002&SIp/6004) and letting it timeout to a Hangup

* CDR written with {{unanswered=yes}}
{noformat}
"""Alice"" <6001>","6001","6999","from-internal","SIP/6001-00000002","SIP/6002-00000003","Dial","SIP/6002&SIP/6004,15","2014-08-26 12:11:45","","2014-08-26 12:12:00","15","0","NO ANSWER","DOCUMENTATION","","1409073105.4","",3
"""Alice"" <6001>","6001","6999","from-internal","SIP/6001-00000002","SIP/6004-00000004","Dial","SIP/6002&SIP/6004,15","2014-08-26 12:11:45","","2014-08-26 12:12:00","15","0","NO ANSWER","DOCUMENTATION","","1409073105.4","",6
"""Alice"" <6001>","6001","6999","from-internal","SIP/6001-00000002","","Hangup","","2014-08-26 12:12:00","","2014-08-26 12:12:00","0","0","NO ANSWER","DOCUMENTATION","","1409073105.4","",7
{noformat}

* CDR written with {{unanswered=no}}
{noformat}
"""Alice"" <6001>","6001","6999","from-internal","SIP/6001-00000000","SIP/6002-00000001","Dial","SIP/6002&SIP/6004,15","2014-08-26 12:48:31","","2014-08-26 12:48:46","15","0","NO ANSWER","DOCUMENTATION","","1409075311.0","",0
"""Alice"" <6001>","6001","6999","from-internal","SIP/6001-00000000","SIP/6004-00000002","Dial","SIP/6002&SIP/6004,15","2014-08-26 12:48:31","","2014-08-26 12:48:46","15","0","NO ANSWER","DOCUMENTATION","","1409075311.0","",3
{noformat}

So, some CDR output is definitely getting filtered out with {{unanswered=no}}.

The documentation appears to conflict with itself. At least by the way I understand it:

In cdr.conf:
{noformat}
; Define whether or not to log unanswered calls. Setting this to "yes" will
; report every attempt to ring a phone in dialing attempts, when it was not
; answered. For example, if you try to dial 3 extensions, and this option is "yes",
; you will get 3 CDR's, one for each phone that was rung. Default is "no". Some
; find this information horribly useless. Others find it very valuable. Note, in "yes"
; mode, you will see one CDR, with one of the call targets on one side, and the originating
; channel on the other, and then one CDR for each channel attempted. This may seem
; redundant, but cannot be helped.
{noformat}

This makes me think any call as "NO ANSWER" will not be reported when the option is set to "no".

{noformat}
;
; In brief, this option controls the reporting of unanswered calls which only have an A
; party. Calls which get offered to an outgoing line, but are unanswered, are still
; logged, and that is the intended behaviour. (It also results in some B side CDRs being
; output, as they have the B side channel as their source channel, and no destination
; channel.)
{noformat}

This makes me think only "NO ANSWER" calls with only an A party will not be reported with the option is set to "no".

That is, with unanswered=yes, the CDR record with only an A party is reported, and with unanswered=no it is not reported. That is what we see actually happening.

If SIP/A calls SIP/B, even if it is unanswered, there will be an A and B party on the CDR record. It looks like this option is intended to filter out CDRs showing calls between the a device and extensions that don't result in a dial, like the execution of Hangup via SIP/6001 in my test.

I'm thinking the name of the option is ambiguous and the documentation could be reworded for clarity. I'll see if a developer can validate.

By: Matt Jordan (mjordan) 2014-08-28 07:57:58.359-0500

What you are seeing is the intended behaviour in Asterisk 12+. This is a documentation issue - the  {{unanswered}} documentation in the sample config file clearly conflicts a bit, and the documentation in the CDR specification on this facet is pretty lacking. We'll get that cleaned up.

Why did this behaviour change?

In Asterisk 12+, from the perspective of the CDR engine, dialling is now a common operation between all applications. If FollowMe, or Dial, or Queue, or anyone else performs a dial operation, the CDR engine views that as the same operation. This solved a large class of problems where certain dial operations created the wrong CDR in previous versions of Asterisk when initiated by a particular application (such as Queue). However, it also means that the logic for handling dial operations is the same, regardless of who initiated it.

In Queues, the default behaviour was to always log all agents that were dialled, regardless of the presence of the unanswered flag. In Dial, that was not the case. The philosophy taken in Asterisk 12 was: *Do not drop information*. Because we can't tell the difference between a "Queue" dial and a "Dial" dial, we output the information when there is both a Party A and a Party B.

Does that mean you have to post-process your records? Yes. To quote from the Asterisk 12 CDR spec:

{quote}
In Asterisk 12, changes in the bridging architecture necessitated a substantial upgrade to CDR behavior. The largest changes are:
* Individual components in Asterisk no longer modify CDRs directly. CDRs are produced based on the state of the channels and bridges within Asterisk. As a result, there is a much greater degree of consistency in CDRs throughout Asterisk, regardless of the application channels happen to be executing in.
* The behavior of CDRs between multiple parties is now defined.
* Depending on how channels are dialed and bridged, multiple CDRs will be created for a given call. Post-processing of these records will be required to determine the overall statistics of the call.
{quote}