[Home]

Summary:ASTERISK-23493: SIP Attended Transfer CDR record has differing linkedid than associated CDRs from the entire call - conflicts with spec
Reporter:c0rnoTa (c0rnota)Labels:
Date Opened:2014-03-17 09:01:33Date Closed:2014-03-19 16:36:57
Priority:MajorRegression?
Status:Closed/CompleteComponents:CDR/General
Versions:12.1.1 Frequency of
Occurrence
Related
Issues:
duplicatesASTERISK-24839 CDRs: LinkedID field in Attended Transfer not reporting as expected
Environment:Attachments:( 0) CDR.sql
( 1) myDebugLog
Description:Attended Transfer CDR as specified in Asterisk 12 CDR specification does not work.

Party A calls Party B
Party B calls Party C and does an Attended transfer from Party A to Party B

CDR has old behavior as in Asterisk 1.4/1.8/11. There is no trace of CDR between Party A to Party C when bridged.
Comments:By: Matt Jordan (mjordan) 2014-03-17 09:06:58.382-0500

We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

Please make sure you have 'cdr set debug on' enabled. Please also specify how the attended transfer took place - did it occur via a protocol, or was the attended transfer managed by the core?
By: c0rnoTa (c0rnota) 2014-03-18 01:36:26.505-0500

Thanks for your answer. I use attended transfer via a protocol. Attached is debug log file and cdr.

Situation:
Number 100 calls number 119.
Number 119 calls Number 112 and does an Attended transfer from 100 to 112.

Notice linkedid, linkedidl is not identical to the length of the call.
Best, regards.
By: Rusty Newton (rnewton) 2014-03-19 15:24:48.178-0500

Deleting a duplicate comment.
By: Rusty Newton (rnewton) 2014-03-19 16:23:06.407-0500

Looking at your CDR and the SIP attended transfer in your debug..

{quote}
There is no trace of CDR between Party A to Party C when bridged.
{quote}

Your sql file includes the CDR:

{noformat}
('2014-03-18', '09:06:52', '"Test" <100>', '100', '119', 'internal', 'SIP/100-00000000', 'SIP/112-00000003', 'Dial', 'SIP/119,20,TtWwM(record^100^1395119184.3)', '11', '11', 'ANSWERED', '', 'BILLING', '', '', '1395119184.3', '1395119184.3', '5');
{noformat}

Which, is the CDR for Party A to Party C (SIP/100 to SIP/112) , look at the *channel* and *dstchannel* fields, not the *src* and *dst* fields.

{quote}
Notice linkedid, linkedidl is not identical to the length of the call.
{quote}
I'm assuming you meant *for* the length of the call, since there is a total of four CDR records in your sql file and one of them has a different *linkedid* than the rest.

The CDR record (below) with the different linkedid appears to be the record for the call from Party B to Party C. That does appear to differ from what is shown in the [CDR spec at this link|https://wiki.asterisk.org/wiki/display/AST/Asterisk+12+CDR+Specification#Asterisk12CDRSpecification-SIPAttendedTransfer]

{noformat}
('2014-03-18', '09:06:44', '"Test" <119>', '119', '112', 'internal', 'SIP/119-00000002', 'SIP/112-00000003', 'Dial', 'SIP/112,20,TtWwM(record^119^1395119204.5)', '8', '5', 'ANSWERED', '', 'BILLING', '', '', '1395119204.5', '1395119204.5', '2'),
{noformat}

I get this same behavior in my tests with cdr-csv in Asterisk 12.

I'll ping Matt again as he may know what is going on.
By: Matt Jordan (mjordan) 2014-03-19 16:36:32.573-0500

The specification makes an assumption there about how the transfers occur; it can't predict everything about the linkedids. Here's the important bit about linkedids:

{quote}
LinkedID Propagation

When two channels are bridged, the linkedid property for the channels is updated. The channel with the oldest linkedid "wins", and the other channel's linkedid is replaced. This creates an association between the channels that lasts even if the bridge is broken at a latter time.

Note that dialed channels automatically receive the linkedid of the calling channel.
{quote}

This then becomes a question of agent: who called whom first, and who had the oldest linkedid?

Looking at the first two records:

{noformat}
('2014-03-18', '09:06:44', '"Test" <119>', '119', '112', 'internal', 'SIP/119-00000002', 'SIP/112-00000003', 'Dial', 'SIP/112,20,TtWwM(record^119^1395119204.5)', '8', '5', 'ANSWERED', '', 'BILLING', '', '', '1395119204.5', '1395119204.5', '2'),
('2014-03-18', '09:06:24', '"Test" <100>', '100', '119', 'internal', 'SIP/100-00000000', 'SIP/119-00000001', 'Dial', 'SIP/119,20,TtWwM(record^100^1395119184.3)', '28', '24', 'ANSWERED', '', 'BILLING', '', '', '1395119184.3', '1395119184.3', '0'),
{noformat}

Despite the fact that '119' is one extension, this is actually two channels at work here: {{SIP/119-00000002}} and {{SIP/119-00000001}}. Because {{SIP/119-00000002}} dialed {{SIP/112-00000003}}, I'd expect that record to use {{SIP/119-00000002}}'s linkedid. All is well. However, since {{SIP/100-0000000}} dialed {{SIP/119-00000001}}, I'd expect that record to use {{SIP/100-00000000}}'s linkedid. Which is what occurs.

Now, later we see {{SIP/100-00000000}} talking with {{SIP/119-00000002}}:

{noformat}
('2014-03-18', '09:06:52', '"Test" <100>', '100', '119', 'internal', 'SIP/100-00000000', 'SIP/119-00000002', 'Dial', 'SIP/119,20,TtWwM(record^100^1395119184.3)', '0', '0', 'ANSWERED', '', 'BILLING', '', '', '1395119184.3', '1395119184.3', '4'),
{noformat}

Neither of these were dialed channels, so now we go to channel age. Because {{SIP/100-00000000}} is older than {{SIP/119-00000002}}, we use the linkedid for {{SIP/119-00000002}}. However, that doesn't get propagated back to the first record, because that call already hung up! We can see that it already hung up as the duration for the first record (between {{SIP/119-00000002}} and {{SIP/112-00000003}}) was 8 seconds, and {{SIP/100-00000000}} wasn't bridged with {{SIP/119-00000002}} until that point. That goes back to the entry on finalization in the specification:

{quote}
Finalization

A CDR is finalized in one of the following scenarios:

   If in a dial, the dial operation completes with a status other than ANSWER
   If in a bridge, either party A or party B leaves the bridge
   Either channel in a CDR hangs up
   The CDR is forked and the forking operation instructs that the CDR should be finalized

When a CDR is finalized, no further modifications can be made to the CDR by the user or Asterisk.
{quote}

Asterisk doesn't hang onto records indefinitely, waiting to see if some future event changes them. When it knows the parties are no longer talking (in this case, {{SIP/119-00000002}} and {{SIP/112-00000003}}), it writes the record out.

So I agree with Rusty. There is not a bug here.