[Home]

Summary:ASTERISK-12977: [patch] forkcdr() doesn't fork when call disposition is ANSWERED
Reporter:Damian Adamski (sh0t)Labels:
Date Opened:2008-10-29 08:59:54Date Closed:2009-05-21 11:19:30
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_forkcdr
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 13797.patch
( 1) cdr-setanswer1.diff
Description:Hello, I have problem with forkcdr app. (sip-sip calls)
First look at this sample dialplan

exten => s,1,answer
exten => s,n,Set(CDR(accountcode)=1001)
exten => s,n,Set(CDR(userfield)=MAIN)
exten => s,n,wait(2)
exten => s,n,ForkCDR()
exten => s,n,ResetCDR()
exten => s,n,Set(CDR(userfield)=OUTpggw1)
exten => s,n,Dial(SIP/pggw1,20)
exten => s,n,hangup

Everything works ok when that Dial result is NO ANSWER or for example FAILED
but if I answer that call. I will see only one CDR record (that with userfield MAIN)

(the failure scenario (with answered call))
bellow two examples of the cdr records (stored in pgsql database)
2008-10-29 14:17:58,32,32,11,pg-gw,SIP/pggw2-c8073fd0,,Dial,SIP/pggw1|20,14,6,ANSWERED,3,1001,1225286278.17290,MAIN

(the expected one, only when call disposition is NO ANSWER or billsec=0)
2008-10-29 14:19:03,32,32,11,pg-gw,SIP/pggw2-c807dd30,,ForkCDR,,10,10,ANSWERED,3,1001,1225286343.17309,MAIN
2008-10-29 14:19:05,32,32,s,test1,SIP/pggw2-c807dd30,SIP/pggw1-01139f40,Dial,SIP/pggw1|20,8,0,NO ANSWER,3,1001,1225286343.17309,OUTpggw1

I'm using forkcdr because I need to have two cdr records. One for incomiing call and one for that dial.

It worked for a long time with earlier versions of asterisk (for example 1.4.11)
Comments:By: Damian Adamski (sh0t) 2008-11-20 07:46:05.000-0600

hello. I've checked this problem on my test machine with other versions of asterisk and here are the results:

asterisk 1.4.21
08-11-20 12:52,"0123456 <0123456>",123456,"s","testfork","SIP/4822349-00861cb0",,"ForkCDR",,29,27,"ANSWERED",3,"1.4.21","1227181967.0","MAIN"
08-11-20 12:52,"0123456 <0123456>",123456,"s","testfork","SIP/4822349-00861cb0","SIP/a_outp-00874fe0","Dial","SIP/a_outp/05026000xx",25,10,"ANSWERED",3,"1.4.21","1227181967.0","OUTpggw1"
asterisk 1.4.22
08-11-20 12:37,"0123456 <0123456>",123456,48223349,"ain","SIP/4822349-0085dbd0",,"Dial","SIP/a_outp/05026000xx",22,9,"ANSWERED",3,"1.4.22","1227181020.0","MAIN"
asterisk 1.4.23RC1
08-11-20 12:46,"0123456 <0123456>",123456,"s","testfork","SIP/4822349-0085ec50","SIP/a_outp-00870f00","Dial","SIP/a_outp/05026000xx",0,0,"NO ANSWER",3,"1.4.23rc1","1227181574.0","OUTpggw1"
08-11-20 12:46,"0123456 <0123456>",123456,48223349,"ain","SIP/4822349-0085ec50",,"ForkCDR",,23,21,"ANSWERED",3,"1.4.23rc1","1227181574.0","MAIN"
08-11-20 12:46,"0123456 <0123456>",123456,"s","testfork","SIP/4822349-0085ec50","SIP/a_outp-00870f00","Dial","SIP/a_outp/05026000xx",19,9,"ANSWERED",3,"1.4.23rc1","1227181574.0","OUTpggw1"

As you can see It was OK on 1.4.21 (we've got 2 CDR records as expected) then on 1.4.22 ForkCDR didn't work, and finally on 1.4.23RC1 the same config and scenario will generate 3 CDR records, one for incoming call, and two for that outgoing dial (after ForkCDR and ResetCDR)

Another strange thing is that record from 1.4.23RC1 with DISPOSITIO=NO ANSWER, billsec=0 and duration=0 which is useless in my opinion.

By: Steve Murphy (murf) 2008-11-21 13:13:12.000-0600

OK, I've attached a patch that I hope will solve this problem. I had some misconceptions about what to do with chained CDR's coming into the bridge, but this bug has helped to clarify the issue.

By: Damian Adamski (sh0t) 2008-11-21 13:52:08.000-0600

I've tried this patch (with Asterisk SVN-branch-1.4-r158306M) and now it generates two CDR records, but the billsec in both CDRs has the same value. It looks like that ResetCDR zeroed also that CDR before fork.

2008-11-21 20:43:33,"<52529xxxx>,52529xxxx,482234xxxxxx,altemp,SIP/482234xxxxx-0083ffc0,,Dial,SIP/a_outp/050260xxxx,26,13,ANSWERED,3,1111,1227296613.2,MAIN
2008-11-21 20:43:37,"<52529xxxx>,52529xxxx,s,testfork,SIP/482234xxxxx-0083ffc0,SIP/a_outp-00874410,Dial,SIP/a_outp/050260xxxx,22,13,ANSWERED,3,1111,1227296613.2,OUTpggw1



By: Damian Adamski (sh0t) 2008-11-21 14:07:47.000-0600

Just tried similar scenario without ResetCDR cmd, and still billsec information from that CDR before ForkCDR is wrong..

By: Steve Murphy (murf) 2008-11-24 16:34:01.000-0600

How is it wrong?

By: Damian Adamski (sh0t) 2008-11-24 16:42:12.000-0600

As I mentioned before it is wrong because both CDRs has the same billsec value.
You can see it on that CDRs I have put on note 0095293.

Call was something about 25s long, bridge time was 13s but both CDR has billsec=13s.

By: Steve Murphy (murf) 2008-11-25 15:37:21.000-0600

Have you checked the forkCDR documentation? It does its own reset operation as part of the CDR cloning processing that generates a new CDR.


With forkCDR() and resetCDR():

""fxo.24" <124>","124","s","default","DAHDI/24-1","","Dial","SIP/polycom430|20","2008-11-25 08:04:08","2008-11-25 08:04:20","2008-11-25 08:04:30","22","10","ANSWERED","DOCUMENTATION","1001","1227625448.9","MAIN",""
""fxo.24" <124>","124","s","incoming","DAHDI/24-1","SIP/polycom430-0865f060","Dial","SIP/polycom430|20","2008-11-25 08:04:17","2008-11-25 08:04:20","2008-11-25 08:04:30","13","10","ANSWERED","DOCUMENTATION","1001","1227625448.9","OUTpggw1",""



with just forkCDR(a):

""fxo.24" <124>","124","s","default","DAHDI/24-1","","Dial","SIP/polycom430|20","2008-11-25 08:41:39","2008-11-25 08:41:50","2008-11-25 08:42:04","25","14","ANSWERED","DOCUMENTATION","1001","1227627699.3","MAIN",""
""fxo.24" <124>","124","s","incoming","DAHDI/24-1","SIP/polycom430-0865d430","Dial","SIP/polycom430|20","2008-11-25 08:41:47","2008-11-25 08:41:47","2008-11-25 08:42:04","17","17","ANSWERED","DOCUMENTATION","1001","1227627699.3","OUTpggw1",""


because actions like Answer() (and end) apply themselves to every CDR in the chain, irregardless of LOCKed status or not. Several options are now available to modify this behavior.

By: Damian Adamski (sh0t) 2008-11-26 04:37:44.000-0600

Yes, I have read new ForkCDR options before, and also the history of issue ASTERISK-1060668 which clarified some of my doubts.
But it does not change the fact that behaviour of ForkCDR() between releases have changed.

You wrote someday before adding that options:
"...Again, the new options should be totally transparent
to existing apps! Current behavior of CDR,
forkCDR, and the rest of the CDR system should
not change one little bit. Until you add the
new options, at least!"

After all, even with those new options I can not get it working as before. I mean to have billsec in that first CDR (before Fork) close to duration value.

I must say that keeping all this CDR stuff working is probably quite hard job.
You are a brave man! :)

best regards

By: Steve Murphy (murf) 2008-12-01 14:42:52.000-0600

more foolish than brave, I fear.

It isn't really forkCDR that changed; it was the setting of a disposition, or the not, that may have changed. I thank you for your patience; but, please,
let's just add an option to your forkCDR and call this quits for the moment.

I've fixed a few other bugs with dispositions, and some have just plain always been there.

By: Damian Adamski (sh0t) 2008-12-02 09:09:38.000-0600

I tried that new forkcdr options and this is what I get.
For example forkcdr(Av) (without any resetcdr)
A - Lock the original CDR against the answer time being updated.
        This will allow the disposition on the original CDR to remain the same.

Correct me if I'm wrong, but I expect CDR system to not change "AnswerTime" in original CDR.

Bellow example log from manager events (to see more than on CDR records) during this call,

Event: Cdr
Privilege: call,all
AccountCode: 1111
Source: 4852xxxxxx
Destination: 4822xxxxx
DestinationContext: alekontakt
CallerID: "4852xxxxxx" <4852xxxxxx>
Channel: SIP/4822xxxxxx-008f9c20
DestinationChannel:
LastApplication: Dial
LastData: SIP/a_outp/0502xxxxxx|15
StartTime: 2008-12-02 15:42:57
AnswerTime: 2008-12-02 15:43:10
EndTime: 2008-12-02 15:43:17
Duration: 20
BillableSeconds: 7
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1228228977.66
UserField: MAIN


Event: Cdr
Privilege: call,all
AccountCode: 1111
Source: 4852xxxxxx
Destination: s
DestinationContext: testfork
CallerID: "4852xxxxxx" <4852xxxxxx>
Channel: SIP/4822xxxxxx-008f9c20
DestinationChannel: SIP/a_outp-00870500
LastApplication: Dial
LastData: SIP/a_outp/0502xxxxxx|15
StartTime: 2008-12-02 15:43:01
AnswerTime: 2008-12-02 15:43:10
EndTime: 2008-12-02 15:43:17
Duration: 16
BillableSeconds: 7
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1228228977.66
UserField: OUTpggw1

"AnswerTime" in the original CDR has changed to the time when bridge linked those two channels.

The patch you provided earlier helped with problem of missing CDR, so tell me if this is another/different issue ?

By: keeky (keeky) 2009-03-30 15:34:17

Any news on this case I got to install this patch in my asterisk 1.4.23 and .24
When this patch will be integrated to trunk ?

By: Matthew Nicholson (mnicholson) 2009-05-15 16:06:09

I think I have found and fixed the remaining issues with answer time here.  Test the attached patch.  With ForkCDR() the answer times should be the same, but with ForkCDR(A) the answer times should be different (and correct).

Please test and let if my patch works correctly.

By: Damian Adamski (sh0t) 2009-05-18 15:45:38

hello..

I've tried this patch on 1.4.25rc1 and everything works as I expected.. Thanks to ForkCDR(A) I can finally upgrade my asterisk to newer versions ;)

Big thanks..

By: Digium Subversion (svnbot) 2009-05-21 10:25:51

Repository: asterisk
Revision: 195881

U   branches/1.4/include/asterisk/cdr.h
U   branches/1.4/main/cdr.c
U   branches/1.4/res/res_features.c

------------------------------------------------------------------------
r195881 | mnicholson | 2009-05-21 10:25:50 -0500 (Thu, 21 May 2009) | 13 lines

This commit prevents cdr records with AST_CDR_FLAG_ANSLOCKED and AST_CDR_FLAG_LOCKED from being updated in certain cases.

This is accomplished by adding two functions to update the answer time and disposition of calls that checks for the proper lock flags.  These functions are used in the ast_bridge_call() function so that ForkCDR(A) calls are respected.

This patch also modifies the way ast_bridge_call() chooses the cdr record to base the bridged_cdr on.  Previously the first unlocked cdr record would be chosen, now instead the first cdr record is chosen and forked cdr records are moved to the bridge_cdr.  This allows the original cdr record and any forked cdr records to be properly updated with answer and end times.

(closes issue ASTERISK-12977)
Reported by: sh0t
Tested by: sh0t

(closes issue ASTERISK-13822)
Reported by: deepesh

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

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

By: Digium Subversion (svnbot) 2009-05-21 10:33:56

Repository: asterisk
Revision: 195882

_U  trunk/
U   trunk/include/asterisk/cdr.h
U   trunk/main/cdr.c

------------------------------------------------------------------------
r195882 | mnicholson | 2009-05-21 10:33:56 -0500 (Thu, 21 May 2009) | 20 lines

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

........
 r195881 | mnicholson | 2009-05-21 10:25:50 -0500 (Thu, 21 May 2009) | 13 lines
 
 This commit prevents cdr records with AST_CDR_FLAG_ANSLOCKED and AST_CDR_FLAG_LOCKED from being updated in certain cases.
 
 This is accomplished by adding two functions to update the answer time and disposition of calls that checks for the proper lock flags.  These functions are used in the ast_bridge_call() function so that ForkCDR(A) calls are respected.
 
 This patch also modifies the way ast_bridge_call() chooses the cdr record to base the bridged_cdr on.  Previously the first unlocked cdr record would be chosen, now instead the first cdr record is chosen and forked cdr records are moved to the bridge_cdr.  This allows the original cdr record and any forked cdr records to be properly updated with answer and end times.
 
 (closes issue ASTERISK-12977)
 Reported by: sh0t
 Tested by: sh0t
 
 (closes issue ASTERISK-13822)
 Reported by: deepesh
........

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

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

By: Digium Subversion (svnbot) 2009-05-21 10:57:01

Repository: asterisk
Revision: 195883

_U  branches/1.6.2/
U   branches/1.6.2/include/asterisk/cdr.h
U   branches/1.6.2/main/cdr.c

------------------------------------------------------------------------
r195883 | mnicholson | 2009-05-21 10:57:01 -0500 (Thu, 21 May 2009) | 27 lines

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

................
 r195882 | mnicholson | 2009-05-21 10:33:55 -0500 (Thu, 21 May 2009) | 20 lines
 
 Merged revisions 195881 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r195881 | mnicholson | 2009-05-21 10:25:50 -0500 (Thu, 21 May 2009) | 13 lines
   
   This commit prevents cdr records with AST_CDR_FLAG_ANSLOCKED and AST_CDR_FLAG_LOCKED from being updated in certain cases.
   
   This is accomplished by adding two functions to update the answer time and disposition of calls that checks for the proper lock flags.  These functions are used in the ast_bridge_call() function so that ForkCDR(A) calls are respected.
   
   This patch also modifies the way ast_bridge_call() chooses the cdr record to base the bridged_cdr on.  Previously the first unlocked cdr record would be chosen, now instead the first cdr record is chosen and forked cdr records are moved to the bridge_cdr.  This allows the original cdr record and any forked cdr records to be properly updated with answer and end times.
   
   (closes issue ASTERISK-12977)
   Reported by: sh0t
   Tested by: sh0t
   
   (closes issue ASTERISK-13822)
   Reported by: deepesh
 ........
................

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

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

By: Digium Subversion (svnbot) 2009-05-21 11:19:21

Repository: asterisk
Revision: 195892

_U  branches/1.6.1/
U   branches/1.6.1/include/asterisk/cdr.h
U   branches/1.6.1/main/cdr.c

------------------------------------------------------------------------
r195892 | mnicholson | 2009-05-21 11:19:20 -0500 (Thu, 21 May 2009) | 27 lines

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

................
 r195882 | mnicholson | 2009-05-21 10:33:55 -0500 (Thu, 21 May 2009) | 20 lines
 
 Merged revisions 195881 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r195881 | mnicholson | 2009-05-21 10:25:50 -0500 (Thu, 21 May 2009) | 13 lines
   
   This commit prevents cdr records with AST_CDR_FLAG_ANSLOCKED and AST_CDR_FLAG_LOCKED from being updated in certain cases.
   
   This is accomplished by adding two functions to update the answer time and disposition of calls that checks for the proper lock flags.  These functions are used in the ast_bridge_call() function so that ForkCDR(A) calls are respected.
   
   This patch also modifies the way ast_bridge_call() chooses the cdr record to base the bridged_cdr on.  Previously the first unlocked cdr record would be chosen, now instead the first cdr record is chosen and forked cdr records are moved to the bridge_cdr.  This allows the original cdr record and any forked cdr records to be properly updated with answer and end times.
   
   (closes issue ASTERISK-12977)
   Reported by: sh0t
   Tested by: sh0t
   
   (closes issue ASTERISK-13822)
   Reported by: deepesh
 ........
................

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

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

By: Digium Subversion (svnbot) 2009-05-21 11:19:29

Repository: asterisk
Revision: 195894

_U  branches/1.6.0/
U   branches/1.6.0/include/asterisk/cdr.h
U   branches/1.6.0/main/cdr.c

------------------------------------------------------------------------
r195894 | mnicholson | 2009-05-21 11:19:29 -0500 (Thu, 21 May 2009) | 27 lines

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

................
 r195882 | mnicholson | 2009-05-21 10:33:55 -0500 (Thu, 21 May 2009) | 20 lines
 
 Merged revisions 195881 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r195881 | mnicholson | 2009-05-21 10:25:50 -0500 (Thu, 21 May 2009) | 13 lines
   
   This commit prevents cdr records with AST_CDR_FLAG_ANSLOCKED and AST_CDR_FLAG_LOCKED from being updated in certain cases.
   
   This is accomplished by adding two functions to update the answer time and disposition of calls that checks for the proper lock flags.  These functions are used in the ast_bridge_call() function so that ForkCDR(A) calls are respected.
   
   This patch also modifies the way ast_bridge_call() chooses the cdr record to base the bridged_cdr on.  Previously the first unlocked cdr record would be chosen, now instead the first cdr record is chosen and forked cdr records are moved to the bridge_cdr.  This allows the original cdr record and any forked cdr records to be properly updated with answer and end times.
   
   (closes issue ASTERISK-12977)
   Reported by: sh0t
   Tested by: sh0t
   
   (closes issue ASTERISK-13822)
   Reported by: deepesh
 ........
................

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

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