[Home]

Summary:ASTERISK-27444: CDR Error on ConfChannel
Reporter:Oguzhan Kayhan (gobris)Labels:
Date Opened:2017-11-24 08:13:53.000-0600Date Closed:
Priority:MajorRegression?
Status:Open/NewComponents:Applications/app_cdr
Versions:13.18.2 Frequency of
Occurrence
Related
Issues:
Environment:Ubuntu 14.04Attachments:( 0) cdr.conf
( 1) cdr-debug.txt
( 2) confbridge.conf
( 3) Master.csv.txt
( 4) messages.txt
Description:During ConfCall, CDR answered time written incorrectly.

First Case:
Single User on Conference
{code}
x2b6774043ba0 -- Strict RTP switching source address to 10.1.200.50:8000
   -- Executing [Conf4509@CommPanelsWithAnalog:2] ConfBridge("SIP/4509-000000e0", "Conf4509,bridge_profile,conf_user_profile,menu_profile") in new stack
   -- Channel CBAnn/Conf4509-0000003c;2 joined 'softmix' base-bridge <92388207-8e8f-4c2d-90fe-96d93472c03d>
   -- <SIP/4509-000000e0> Playing 'conf-onlyperson.ulaw' (language 'en')
Channel SIP/4509-000000e0 joined 'softmix' base-bridge <92388207-8e8f-4c2d-90fe-96d93472c03d>
   -- <CBAnn/Conf4509-0000003c;1> Playing 'confbridge-join.gsm' (language 'en')
Channel SIP/4509-000000e0 left 'softmix' base-bridge <92388207-8e8f-4c2d-90fe-96d93472c03d>
   -- <CBAnn/Conf4509-0000003c;1> Playing 'confbridge-leave.gsm' (language 'en')
   -- Channel CBAnn/Conf4509-0000003c;2 left 'softmix' base-bridge <92388207-8e8f-4c2d-90fe-96d93472c03d>
{code}

Dİalplan for Confbridge:
{code}
exten => Conf4509,1,Answer()
       same => n,ConfBridge(${EXTEN},bridge_profile,conf_user_profile,menu_profile)
       same => n,Hangup()
{code}

I had a call for 10 seconds and cdr output as follows:
{code}
"","4509","Conf4509","CommPanelsWithAnalog",""""" <4509>","SIP/4509-000000e0","","ConfBridge","Conf4509,bridge_profile,conf_user_profile,menu_profile","2017-11-24 14:04:19","2017-11-24 14:04:19","2017-11-24 14:04:22",3,3,"ANSWERED","DOCUMENTATION","1511532259.541",""
{code}

It is always 3 seconds not dependent on the time i spent on the conference.


2 users on conference:
4509 user calls Conf4509  stays there for 10 seconds. Then 4503 user calls in and stays for 10 seconds. after it hang up, 4509 waits for 10 seconds more (total of 30 seconds) and hangs up.

The CDR for two users :

{code}
"","4503","Conf4509","CommPanelsWithAnalog","""4503"" <4503>","SIP/4503-000000e2","","ConfBridge","Conf4509,bridge_profile,conf_user_profile,menu_profile","2017-11-24 14:07:58","2017-11-24 14:07:58","2017-11-24 14:07:58",0,0,"ANSWERED","DOCUMENTATION","1511532478.548",""

"","4509","Conf4509","CommPanelsWithAnalog",""""" <4509>","SIP/4509-000000e1","SIP/4503-000000e2","ConfBridge","Conf4509,bridge_profile,conf_user_profile,menu_profile","2017-11-24 14:07:48","2017-11-24 14:07:48","2017-11-24 14:08:09",20,20,"ANSWERED","DOCUMENTATION","1511532468.545",""
{code}

First user shows 0 seconds.. Second user shows 20 seconds.

There is inconsistency in CDR logs..Only in confchannels.
Confchannel configuration shared as attachment also.

Comments:By: Asterisk Team (asteriskteam) 2017-11-24 08:13:54.628-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: Oguzhan Kayhan (gobris) 2017-11-24 08:46:08.538-0600

With same rules I did the testing on 11.5.0  and CDR working fine with that version.

By: Oguzhan Kayhan (gobris) 2017-11-24 10:19:11.765-0600

THings getting strange..
Trying different scenarios..

I have a device joining to 2 different confchannels at bootup.
with name rxpae3040  and txpae3040.

I booted it.. And shutdown asterisk at 20 seconds.
record was fine with 20 seconds.

Then i rebooted services.
At 20. second i joined the channel rxpae3040 with another client.  Stayed there for 10 seconds. and hanged up last client logged in.   And after 5 seconds more shutdown asterisk again.

What i observed is.. txpae3040 channel was with correct billable time.35 seconds.
But rxpae3040 channel.. 1st client seem to updated  as logged off when 2nd client logged off too:  30 seconds
second client  start and stop time was stop time actually. thats why total duration was 0 seconds.


Final observation is..
WHen a second client enters the conference  its cdr record starts fine.
Then when it logs off, the end time of 2nd client is written as first clients logoff time.

Second clients endtime never updates.


Test:  
at 15:51:33  system boots up and first client logs in.(idpae3040)
at  15:52:01  second user logs in to conference (4503)
at 15:52:30  second user logs off from conference
at 15:53:00  1st user closes conf channel.
{code}

"","4503","rxpae3040","CommPanelsWithAnalog","""4503"" <4503>","SIP/4503-00000002","","ConfBridge","rxpae3040,bridge_profile,conf_user_profile,menu_profile","2017-11-24 15:52:01","2017-11-24 15:52:01","2017-11-24 15:52:01",0,0,"ANSWERED","DOCUMENTATION","1511538721.6",""
"","idpae3040","rxpae3040","CommPanels",""""" <idpae3040>","SIP/idpae3040-00000000","SIP/4503-00000002","ConfBridge","rxpae3040,bridge_profile,conf_user_profile,menu_profile","2017-11-24 15:51:33","2017-11-24 15:51:33","2017-11-24 15:52:30",57,57,"ANSWERED","DOCUMENTATION","1511538693.0",""
"","idpae3040","txpae3040","CommPanels",""""" <idpae3040>","SIP/idpae3040-00000001","","ConfBridge","txpae3040,bridge_profile,conf_user_profile,menu_profile","2017-11-24 15:51:33","2017-11-24 15:51:33","2017-11-24 15:53:00",87,87,"ANSWERED","DOCUMENTATION","1511538693.1",""

{code}

By: Richard Mudgett (rmudgett) 2017-11-24 10:26:35.712-0600

Comparing Asterisk v11 and v12+ CDR's is like comparing apples to oranges.  Prior to v12 CDR's had no real specification defining how it should work and could not be maintained.  Any attempt to fix a CDR problem resulted in breaking something.  CDR's became untouchable.  In v12 CDR support was *completely* rewritten \[1] with a specification to live up to.

Please follow the steps \[2] to collect debug information.  We need to see the call verbose, debug, and CDR debug information logged for a test call you describe.  We'll also need the generated CDR records from the test.  In step 6 it is important to attach text type files with the .txt exten.

Please examine the mentioned CDR specification \[1] to confirm if Asterisk is complying with it.

\[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+12+CDR+Specification
\[2] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

By: Oguzhan Kayhan (gobris) 2017-11-24 10:28:19.071-0600

cdr-debug files has been added.

the client idpae3040  is on channel. call received to join same confbridge.

Client 4503 enters conf.
then client 4503 disconnects from conf..

the debug shows the following:

0x2b1a00001680 - Transitioning CDR for SIP/4503-00000002 from state Bridged to Finalized
0x2b1a00000940 - Transitioning CDR for SIP/idpae3040-00000000 from state Bridged to Finalized

But idpae3040 still in channel.


By: Oguzhan Kayhan (gobris) 2017-11-24 10:58:43.819-0600

Clients 4510 and 4511 entering to ConfChannel Conf4510.

4510 was the first and last recipient.


By: Benjamin Keith Ford (bford) 2017-11-29 16:19:32.343-0600

Hey [~gobris], I just did some testing and can reproduce this. I opened an issue for it.
By: Brad Belanger (btrain1227) 2018-05-02 10:09:46.746-0500

I still see this same behavior with Asterisk 15.4.0.