[Home]

Summary:ASTERISK-12974: [patch] CDR for picked up parked call gives answer time < start time and no record for parking
Reporter:David Woolley (davidw)Labels:
Date Opened:2008-10-28 13:34:43Date Closed:2009-06-25 16:12:33
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Resources/res_features
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 13794.patch
( 1) 13794.patch.160
( 2) 13794.patch.alternate
( 3) 13794.patch.alternate.160
Description:Dial 700 on one phone and 701 on another.  No call record is generated for the first phone and the call record for the second phone gives the time of parking as the answer time.  The "billable" time is longer than the call duration!

****** ADDITIONAL INFORMATION ******

This is the only CDR generated for the exact case described.

"","6106","701","internal","""6106"" <6106>","SIP/6106-08af20e0","SIP/djw-messen
ger-08b74570","ParkedCall","701","2008-10-28 17:21:21","2008-10-28 17:21:11","2008-10-28 17:21:31",10,20,"ANSWERED","DOCUMENTATION","1225214481.45",""

In a more complex case, using the dialplan logic used to demonstrate issue ASTERISK-1364747, we also get "NO ANSWER", rather than "ANSWER".

(There may also be cases in which one does get a record for the parked call, up to the point of parking, but I need to verify some facts on that.)

What I suspect is the cause of this is that the answer time in the call record associated with the first channel is being perceived as being the answer time before a macro was run on the peer, as part of the Dial command processing, even though this isn't actually a dial command and there is no macro.

The code I suspect is(in ast_bridge_call, in main/features.c):

  1969                 ast_debug(4,"bridge answer set, chan answer set\n");
  1970                 /* peer->cdr->answer will be set when a macro runs on the peer;
  1971                    in that case, the bridge answer will be delayed while the
  1972                    macro plays on the peer channel. The peer answered the call
  1973                    before the macro started playing. To the phone system,
  1974                    this is billable time for the call, even tho the caller
  1975                    hears nothing but ringing while the macro does its thing. */
  1976                 if (peer->cdr && !ast_tvzero(peer->cdr->answer)) {
  1977                         bridge_cdr->answer = peer->cdr->answer;
  1978                         chan->cdr->answer = peer->cdr->answer;
  1979                 } else {
  1980                         ast_cdr_answer(bridge_cdr);
  1981                         ast_cdr_answer(chan->cdr); /* for the sake of cli status checks */
  1982                 }

Debug output (not from the same run as the CDR) confirms that this code is executed:

[2008-10-28 17:45:58.691] VERBOSE[14558] logger.c:     -- Channel SIP/6105-08af20e0 connected to parked call 701
[2008-10-28 17:45:58.692] DEBUG[14558] features.c: bridge answer set, chan answer set
[2008-10-28 17:45:58.692] VERBOSE[14558] logger.c:     -- Native bridging SIP/6105-08af20e0 and SIP/djw-messenger-08b74570
Comments:By: David Woolley (davidw) 2008-10-29 06:45:45

I wonder if what should be happening here is that the parked call CDR should be output and reset before connecting the unparking call.  (Although I'm not saying that that would be enough for the CDRs to actually be useful.)
By: David Woolley (davidw) 2008-11-07 13:10:15.000-0600

It looks like this fragment of code also causes problems for non-parking cases (I'm not convinced the else branch is ever used).

In 1.6.0, if you ResetCDR before dialling, either explicitly, or as the result of Dial,g and a successful call, and then do another successful Dial, the second CDR shows a valid answer time but "NO ANSWER" status.  I think this is because app_dial.c does:

   666                                                 if (peer->cdr) {
   667                                                         peer->cdr->answer = ast_tvnow();
   668                                                         peer->cdr->disposition = AST_CDR_ANSWERED;
   669                                                 }

This results in the disposition being left at null, and eventually being output as NO ANSWER.

The reason you don't see this on simple cases is that ast_answer'ing the incoming channel also sets the disposition, but only if it was in RINGING (or RING) state, which can only happen once per call:

main/channel.c:

  1695         case AST_STATE_RINGING:
  1696         case AST_STATE_RING:
  1697                 ast_channel_lock(chan);
  1698                 if (chan->tech->answer) {
  1699                         res = chan->tech->answer(chan);
  1700                 }
  1701                 ast_setstate(chan, AST_STATE_UP);
  1702                 ast_cdr_answer(chan->cdr);
By: Leif Madsen (lmadsen) 2009-01-20 13:37:42.000-0600

This is a hidden CDR issue... maybe murf has already fixed it? I've assigned to him for his review.
By: Steve Murphy (murf) 2009-01-23 09:55:16.000-0600

OK, I reproduced this on my SIP phone... and found that it's a problem in 1.4 on up. The code to copy into the bridge cdr, the answer time from a macro run peer also catches this case; I put in a call to ast_tvcmp to make sure that if a peer does have an answer time, we'll only bring it into the bridge CDR if the answer time is greater/== to the bridge CDR's start time.

Another possibility is to, if a peer has an answer time before the bridge_cdr's start time, we could reset the start and answer times to the earlier times.... but that's pretty dangerous, and who knows how many other cases there are/would/could be where we wouldn't want to do that!
By: Steve Murphy (murf) 2009-01-23 10:07:52.000-0600

Oh, and as to the parking time being covered; hmmm. Maybe the alternate fix above might help, because if there are other cases where the peer has an answer time set, I haven't seen any complaints about the times... we could do an experiment and see... I'll attach another patch. Please report on both...
By: Steve Murphy (murf) 2009-01-23 10:33:02.000-0600

there-- uploaded 13794.patch.alternate, which instead of just preventing the bridge cdr from having its answer time updated with the peer answer time when the answer time is before the start time, will update both the answer and start times from the peers CDR.

That will force the CDR to attribute the time spent in park to the conversation; but really, deep down, I think this is wrong. The park time should either be in a CDR that spells that out, or the CDR should record all the time it spent with everything, but that goes against the current CDR philosophy, which is a bad breeding of both "leg" and "simple" CDRs (see my spec for a rewrite of the CDR system by "svn co http://svn.digium.com/svn/asterisk/team/murf/RFCs" and look at the CDRfix2 text file in that dir.)

As to getting the park time to write a CDR, .... I'm not certain that this is something we should do in 1.4... hmmm.... no-one is expecting this, they might look on the change in CDR behavior as an unwelcome enhancement in an already-released product, and it might throw back end CDR processing programs into a tizzy...
By: Steve Murphy (murf) 2009-01-23 11:56:58.000-0600

OOps, those patches were against 1.4; so I edited them for 1.6.0 and
tested them out, and they apply (with offsets, but that's OK).
I've just attached them, see 13794.patch.160 and 13794.patch.alternate.160
By: Leif Madsen (lmadsen) 2009-03-04 19:07:01.000-0600

Pinging all followers and the reporter. Please report back on your testing so we can move some of these CDR issues forward. Thanks!
By: Leif Madsen (lmadsen) 2009-05-21 11:00:10

Assigned to dbrooks for testing!
By: David Brooks (dbrooks) 2009-05-22 15:36:05

Tested 13794.patch.160 and 13794.patch, which seems to fix the issue of Answer being prior to Start on both 1.6.0 SVN and 1.4 SVN. The two fields are now identical. The alternate patches also fix the issue in that the two fields become identical. I'm not too clear on what the difference is, however.
By: Digium Subversion (svnbot) 2009-06-25 16:12:20

Repository: asterisk
Revision: 203375

U   branches/1.4/res/res_features.c

------------------------------------------------------------------------
r203375 | russell | 2009-06-25 16:12:19 -0500 (Thu, 25 Jun 2009) | 9 lines

Fix a case where CDR answer time could be before the start time involving parking.

(closes issue ASTERISK-12974)
Reported by: davidw
Patches:
     13794.patch uploaded by murf (license 17)
     13794.patch.160 uploaded by murf (license 17)
Tested by: murf, dbrooks

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=203375
By: Digium Subversion (svnbot) 2009-06-25 16:12:24

Repository: asterisk
Revision: 203376

_U  trunk/
U   trunk/main/features.c

------------------------------------------------------------------------
r203376 | russell | 2009-06-25 16:12:24 -0500 (Thu, 25 Jun 2009) | 16 lines

Merged revisions 203375 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
 r203375 | russell | 2009-06-25 16:02:18 -0500 (Thu, 25 Jun 2009) | 9 lines
 
 Fix a case where CDR answer time could be before the start time involving parking.
 
 (closes issue ASTERISK-12974)
 Reported by: davidw
 Patches:
       13794.patch uploaded by murf (license 17)
       13794.patch.160 uploaded by murf (license 17)
 Tested by: murf, dbrooks
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=203376
By: Digium Subversion (svnbot) 2009-06-25 16:12:27

Repository: asterisk
Revision: 203377

_U  branches/1.6.0/
U   branches/1.6.0/main/features.c

------------------------------------------------------------------------
r203377 | russell | 2009-06-25 16:12:27 -0500 (Thu, 25 Jun 2009) | 23 lines

Merged revisions 203376 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
 r203376 | russell | 2009-06-25 16:04:55 -0500 (Thu, 25 Jun 2009) | 16 lines
 
 Merged revisions 203375 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r203375 | russell | 2009-06-25 16:02:18 -0500 (Thu, 25 Jun 2009) | 9 lines
   
   Fix a case where CDR answer time could be before the start time involving parking.
   
   (closes issue ASTERISK-12974)
   Reported by: davidw
   Patches:
         13794.patch uploaded by murf (license 17)
         13794.patch.160 uploaded by murf (license 17)
   Tested by: murf, dbrooks
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=203377
By: Digium Subversion (svnbot) 2009-06-25 16:12:31

Repository: asterisk
Revision: 203378

_U  branches/1.6.1/
U   branches/1.6.1/main/features.c

------------------------------------------------------------------------
r203378 | russell | 2009-06-25 16:12:31 -0500 (Thu, 25 Jun 2009) | 23 lines

Merged revisions 203376 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
 r203376 | russell | 2009-06-25 16:04:55 -0500 (Thu, 25 Jun 2009) | 16 lines
 
 Merged revisions 203375 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r203375 | russell | 2009-06-25 16:02:18 -0500 (Thu, 25 Jun 2009) | 9 lines
   
   Fix a case where CDR answer time could be before the start time involving parking.
   
   (closes issue ASTERISK-12974)
   Reported by: davidw
   Patches:
         13794.patch uploaded by murf (license 17)
         13794.patch.160 uploaded by murf (license 17)
   Tested by: murf, dbrooks
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=203378
By: Digium Subversion (svnbot) 2009-06-25 16:12:32

Repository: asterisk
Revision: 203379

_U  branches/1.6.2/
U   branches/1.6.2/main/features.c

------------------------------------------------------------------------
r203379 | russell | 2009-06-25 16:12:32 -0500 (Thu, 25 Jun 2009) | 23 lines

Merged revisions 203376 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
 r203376 | russell | 2009-06-25 16:04:55 -0500 (Thu, 25 Jun 2009) | 16 lines
 
 Merged revisions 203375 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r203375 | russell | 2009-06-25 16:02:18 -0500 (Thu, 25 Jun 2009) | 9 lines
   
   Fix a case where CDR answer time could be before the start time involving parking.
   
   (closes issue ASTERISK-12974)
   Reported by: davidw
   Patches:
         13794.patch uploaded by murf (license 17)
         13794.patch.160 uploaded by murf (license 17)
   Tested by: murf, dbrooks
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=203379