[Home]

Summary:ASTERISK-25620: Call pickup during a Multi-party Dial results in a channel hanging up later than it should and a duplicate CDR entry.
Reporter:Dmitry Wagin (dmitry2004@yandex.ru)Labels:
Date Opened:2015-12-10 02:39:04.000-0600Date Closed:
Priority:MajorRegression?
Status:Open/NewComponents:Applications/app_dial CDR/General Core/Channels Features
Versions:13.6.0 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) debug-13.6.txt
( 1) debug-13.6-2015-12-14.txt
( 2) debug-13.6-3.txt
( 3) Master-13.6.csv.txt
( 4) Master-13.6-2015-12-14.csv.txt
( 5) rusty_extensions.txt
( 6) rusty_features.txt
( 7) rusty_full.txt
( 8) rusty_master_csv.txt
( 9) rusty_messages.txt
(10) rusty_pjsip.txt
(11) rusty_show_channels.txt
Description:[Edit by Rusty]
A very concise description:
h3. Scenario:
A calls B and C simultaneously, D uses call pickup to answer the call to B.

h3. Problematic result:
Duplicate CDR entry for A to D.
Strange but somewhat expected CDR entry for C, probably a result of the channel being stuck Up and Ringing for the duration of the call to A to D.

h3. Notes:
* Problem does not appear to be with a specific channel tech or CDR backend.
** Occurs with chan_sip and chan_pjsip.
** Occurs with cdr_custom and cdr_pgsql.

[End edit by Rusty]

Devices:
1. SIP/2102
2. SIP/2103
3. SIP/2104
4. SIP/2105

On incoming call do Dial(SIP/2103&SIP/2104&SIP/2105,120,tS(3600));

SIP/2103, SIP/2104, SIP/2105 ringing

User SIP/2102 pickup ringing channel SIP/2103, talk some time and hangup.

In results not correct CDRs + zombie channels (see SIP/2104-00000002, SIP/2105-00000003):

|| accountcode || src || dst || dcontext || clid || channel || dstchannel || lastapp || lastdata || start || answer || end || duration || billsec || disposition || amaflags || uniqueid || peeraccount || linkedid || sequence ||
| | 2103 | *8 | office | "Office 2103" <2103> | SIP/2103-00000001 |  | AppDial | (Outgoing Line) | 2015-12-09 12:23:56 | | 2015-12-09 12:23:58 | 2 | 0 | NO ANSWER | DOCUMENTATION | 1449663836.1 |  | 1449663836.0 | 1 |
| incoming-office | 7xxxxxxxxxx | office | incoming | "Incoming" <7xxxxxxxxxx> | SIP/incoming-00000000 | SIP/2103-00000001 | Dial | SIP/2103&SIP/2104&SIP/2105,120,tS(3600) | 2015-12-09 12:23:56 | | 2015-12-09 12:23:58 | 2 | 0 | NO ANSWER | DOCUMENTATION | 1449663836.0 |  | 1449663836.0 | 0 |
| incoming-office | 7xxxxxxxxxx | office | incoming | "Incoming" <7xxxxxxxxxx> | SIP/incoming-00000000 | SIP/2104-00000002 | Dial | SIP/2103&SIP/2104&SIP/2105,120,tS(3600) | 2015-12-09 12:23:56 | 2015-12-09 12:23:58 | 2015-12-09 12:24:12 | 16 | 14 | ANSWERED | DOCUMENTATION | 1449663836.0 | incoming-office | 1449663836.0 | 4 |
| incoming-office | 7xxxxxxxxxx | office | incoming | "Incoming" <7xxxxxxxxxx> | SIP/incoming-00000000 | SIP/2105-00000003 | Dial | SIP/2103&SIP/2104&SIP/2105,120,tS(3600) | 2015-12-09 12:23:56 | 2015-12-09 12:23:58 | 2015-12-09 12:24:12 | 16 | 14 | ANSWERED | DOCUMENTATION | 1449663836.0 | incoming-office | 1449663836.0 | 5 |
| incoming-office | 7xxxxxxxxxx | office | incoming | "Incoming" <7xxxxxxxxxx> | SIP/incoming-00000000 | SIP/2102-00000004 | Dial | SIP/2103&SIP/2104&SIP/2105,120,tS(3600) | 2015-12-09 12:23:58 | 2015-12-09 12:23:58 | 2015-12-09 12:24:12 | 14 | 14 | ANSWERED | DOCUMENTATION | 1449663836.0 |  | 1449663836.0 | 7 |
| incoming-office | 7xxxxxxxxxx | office | incoming | "Incoming" <7xxxxxxxxxx> | SIP/incoming-00000000 | SIP/2102-00000004 | Dial | SIP/2103&SIP/2104&SIP/2105,120,tS(3600) | 2015-12-09 12:23:58 | 2015-12-09 12:23:58 | 2015-12-09 12:24:12 | 14 | 14 | ANSWERED | DOCUMENTATION | 1449663836.0 |  | 1449663836.0 | 8 |
Comments:By: Asterisk Team (asteriskteam) 2015-12-10 02:39:05.508-0600

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].
By: Rusty Newton (rnewton) 2015-12-10 19:34:09.045-0600

We require additional debug to continue with triage of your issue. Please follow the instructions on the wiki [1] for how to collect debugging information from Asterisk. For expediency, where possible, attach the debug with a '.txt' file extension so that the debug will be usable for further analysis.

Thanks!

[1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information


By: Rusty Newton (rnewton) 2015-12-10 19:35:07.909-0600

In addition to the debug trace of the call, please provide the correlating CDR log.

Have you tested this behavior to see if it has changed from 11 or 12 to 13?
By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-10 20:40:39.724-0600

I can check on 11.20
By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-11 00:27:17.179-0600

Asterisk-13.6 debug log
By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-11 00:28:10.941-0600

Asterisk-13.6 CDRs
By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-11 00:30:11.956-0600

Asterisk-13.6 debug log via syslog
By: Matt Jordan (mjordan) 2015-12-11 07:55:28.648-0600

Let's at least start here: The CDRs in 13 are not going to be the same as in 11. They are not expected to be. Please read the upgrade notes on 12 and 13 on the Asterisk wiki:

https://wiki.asterisk.org/wiki/display/AST/Upgrading+to+Asterisk+12

https://wiki.asterisk.org/wiki/display/AST/Upgrading+to+Asterisk+13

The debug logs you've attached were not generated correctly, and do not contain the VERBOSE, NOTICE, WARNING, or ERROR messages. Please attach a properly generated debug log, using the instructions on the wiki:

https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

Please enable 'cdr set debug on' when you create the debug log.

It is expected that you would have a CDR for each pair of channels involved in a Dial operation. That includes each channel in a parallel dial. That part is not a bug.

The only part that is odd is the extraneous CDR for SIP/2003, and the two CDRs for the call after it was picked up. That doesn't look quite right, but a debug log would be needed to see why those entries were created.

By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-11 08:01:50.804-0600

SIP/2104 and SIP/2105 - not answered, but in CDR disposition = ANSWERED and wrong billsec.
By: Dmitry Wagin (dmitry2004@yandex.ru) 2015-12-14 01:10:26.378-0600

Updated debug with cdr debug on
By: Rusty Newton (rnewton) 2015-12-29 19:09:55.801-0600

Reproduced to confirm. Attaching many files prefixed with 'rusty_' which can be used to reproduce the issue. Included is debug and '... show channels" output from my reproduction.

pjsip.txt contains endpoints for ALICE,BOB,CATHY and DANIEL. Once these are registered you simply have to :

* ALICE calls extension 7000 which dials BOB and CATHY
* DANIEL dials *8 to pickup the outbound channel to BOB

In my reproduction the channel for CATHY hangs for the duration of the call that gets established between ALICE and DANIEL.

I observed essentially the same CDR issues as [~dmitry2004@yandex.ru] saw.

Issues that are apparent to me:

* Duplicate CDR for call from ALICE to DANIEL
* CDR for ALICE to CATHY is ANSWERED when it should be UNANSWERED.
* CDR for ALICE to CATHY has invalid duration and billsec compared to what you would expect. It should be the same as the call to BOB. Perhaps the CDR is valid and the problem is the weird state the channel gets into. (hung as ringing).

I'm going to update the summary a bit.