Star2Billing / a2billing

A2Billing is a telecom switch and billing system capable of providing and billing a range of telecom products and services to customers such as calling card products, residential and wholesale VoIP termination, DID resale and callback services.
www.asterisk2billing.org
Other
182 stars 174 forks source link

On Asterisk version 12 or 13, callback calls are not billed correctly by a2billing #129

Open africallshop opened 8 years ago

africallshop commented 8 years ago

ample :

Log from a2billing [16/04/2016 01:10:38]:[file:Class.RateEngine.php - line:1154 - uniqueid:1460761811.0]:[CallerID:xxxxxxxxxxx]:[CN:5670473373333]:[[CC_RATE_ENGINE_UPDATESYSTEM: usedratecard K=0 - (sessiontime=0 :: dialstatus=ANSWER :: buycost=0 :: cost= : signe_cc_call=-: signe=+)]]

Asterisk CDR :

"5670473373333","xxxxxx","xxxxxx","a2billing",""""" ","SIP/xxxxxx","SIP/xxxxxx","Dial","SIP/xxxxxx,120,L(480000)","2016-04-15 23:10:22","2016-04-15 23:10:22","2016-04-15 23:10:38",16,16,"ANSWERED","DOCUMENTATION","1460761811.0",""

As you can see, the duration time is : 16 secondes.

A2billing gets the sessiontime from $agi->get_variable("ANSWEREDTIME") variable but it seems the beheavior on Asterisk 12 and 13 has changed.

I have no problem with Asterisk 11.

Could you help me please to fix the issue ? I need to upgrade asterisk.

Regards AfriCallShop.

areski commented 8 years ago

More info on this: https://wiki.asterisk.org/wiki/display/AST/Asterisk+13+Application_Dial ANSWEREDTIME - This is the amount of time for actual call.

an issue is opened on this matter: https://issues.asterisk.org/jira/browse/ASTERISK-24620

mason-chase commented 8 years ago

To overcome this issue we get correct call time from CDR directly:

$agi->get_variable("CDR(answer)");

Please let me know if this works for you.

Cheers​

africallshop commented 8 years ago

Ok, thanks for your feedback.

On asterisk 11, $agi->get_variable("CDR(answer)") return just Array.

I suppose that $agi->get_variable("CDR(answer)"); works only with asterisk 12 or asterisk 13. Do you confirm that ? Rregards

africallshop commented 8 years ago

[2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Tx >> 200 result=1 [2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Rx << GET VARIABLE ANSWEREDTIME

AGI debug from ASTERISK 11.

CDR(answer) seems to not an AGI variable on Asterisk 11.

[2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Tx >> 200 result=1 (309) [2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Rx << GET VARIABLE DIALSTATUS [2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Tx >> 200 result=1 (ANSWER) [2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Rx << GET VARIABLE CDR(answer) [2016-04-18 17:09:51] VERBOSE[26043][C-00000907] res_agi.c: <SIP/56e3f387cf6fe-00001370>AGI Tx >> 200 result=0

mason-chase commented 8 years ago

Please use this on Asterisk 13. You may also use CDR(billsec) which is only available in latest Asterisk 13:

this is a new feature:

${CDR(clid)} Caller ID ${CDR(src)} Source ${CDR(dst)} Destination ${CDR(dcontext)} Destination context ${CDR(channel)} Channel name ${CDR(dstchannel)} Destination channel ${CDR(lastapp)} Last app executed ${CDR(lastdata)} Last app's arguments ${CDR(start)} Time the call started. ${CDR(answer)} Time the call was answered. ${CDR(end)} Time the call ended. ${CDR(duration)} Duration of the call. ${CDR(billsec)} Duration of the call once it was answered. ${CDR(disposition)} ANSWERED, NO ANSWER, BUSY ${CDR(amaflags)} DOCUMENTATION, BILL, IGNORE etc ${CDR(accountcode)} The channel's account code. ${CDR(uniqueid)} The channel's unique id. ${CDR(userfield)} The channels uses specified field.

africallshop commented 8 years ago

Thanks,

I use ${CDR(billsec)} => Duration of the call once it was answered..

About billing -> SIP : billing is correct -> Card number : access number : billing is correct -> Callback service : sessiontime is not equal to null :). I get a value of sessiontime but it seems incorrect.

Here is the Asterisk CDR. In my case, I shoudn't be have duration of the call = duration of the call once it was answered (2nd leg of my call). I should be duration of the call > duration of the call once it was answered.

"5670473373333","XXXX","XXXX","a2billing",""""" ","SIP/idt-00000031","SIP/idt-00000037","Dial","SIP/XXXXX,120,L(1020000)","2016-04-18 23:42:24","2016-04-18 23:42:24","2016-04-18 23:42:34",9,9,"ANSWERED","DOCUMENTATION","1461022935.91",""

mason-chase commented 8 years ago

That's where Asterisk 13 rendered useless until we could figure out something for Callback service we used Asterisk 11 for Callback

We can't wait to use HES protocol introduced in Asterisk 13.

You could play around getting the Unique ID on second leg and fetch the duration from second leg's CDR.

Please let us know if you have any success

dbbrito commented 8 years ago

Someone was able to properly callback the callback, and could post the solution? I need urgently to migrate from asterisk11 to 13 but I need the callback working perfectly. Thank you

andresmmujica commented 7 years ago

Dear Team, we're having this issue with an A2Billing 2.20 and Asterisk 13.

We've already changed the lines with

$answeredtime = $agi->get_variable("ANSWEREDTIME");

to

$answeredtime = $agi->get_variable("CDR(billsec)");

in Class.RateEngine.php

However it seems not to be working, it gets better than using ANSWEREDTIME but it's not the real answered time when using billsec.

Any help would be greatly appreciated.

chris001 commented 7 years ago

Is the $answeredtime for callbacks incorrect because asterisk is counting from the time when the first party has answered and waiting for the second party to answer?

andresmmujica commented 7 years ago

Actually, is not just with the Callback, it's happening with all the calls. The billsec time is not measuring the answered time accurately

chris001 commented 7 years ago

Is there a pattern to the inaccurate CDR(billsec) - is it always longer or shorter by X seconds.

andresmmujica commented 7 years ago

Yes. The answered time is always about 12-13 seconds shorter than the total duration of the call, regardless how long it's the actual duration of the talk time. If the call is longer than a few minutes we've noticed the answered time tends to be 10 seconds shorter than the call time, again, regardless the talk time.

On Sat, Nov 4, 2017, 23:00 Chris Coleman notifications@github.com wrote:

Is there a pattern to the inaccurate CDR(billsec) - is it always longer or shorter by X seconds.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/Star2Billing/a2billing/issues/129#issuecomment-341947483, or mute the thread https://github.com/notifications/unsubscribe-auth/AGFovN8a4Zp0DhjW9jLA5Sz2q2DAuNR8ks5szTLQgaJpZM4II9ka .

chris001 commented 7 years ago

Does this mean that you're undercharging customers consistently by 10-13 seconds of call time.

jansuar commented 7 years ago

@chris001 , no, we are overcharging customers. The time it shows in the a2billing when placing the CDR(billsec) is about 11 - 13 seconds less than the total duration of the call. (duration-billsec-show = 11 or 13 seconds)

Here are some reports of the tests performed: start | answer | end | billsec-real | billsec-show | duration 0 | 31 | 52 | 21 | 39 | 52 0 | 42 | 73 | 31 | 60 | 73 0 | 29 | 40 | 11 | 29 | 40 0 | 30 | 61 | 31 | 50 | 61 0 | 28 | 39 | 11 | 28 | 39

jansuar commented 7 years ago

we did tests with asterisk 1.8 and asterisk 13. these are the records of the call

captura de pantalla de 2017-11-07 17-43-35

I think the failure can be in the starttime, because if we calculate the times these are correct in both versions

chris001 commented 7 years ago

@jansuar Is it possible that the reason for the overcharged seconds, because one party didn't hang up the line, so it takes about 10-15 seconds for the line, or their calling app, to realize the other party has hung up the call, and the line/app finally drops the connection?

jansuar commented 7 years ago

I'm going to check if the line/app finally drops the connection. Because the party B hang up the line ok.

jansuar commented 7 years ago

We kept debugging the issue and found what may the problem be. According to [1] it seem that the CDR(billsec) is registering the answered time of the initial call and not the answered time of the bridged one (I mean after dialing the number on the DISA and the other party answering the call )

We CDR debug we found the right answered time data in the bridged CDR thread as shown in this log:

-- SIP/sipetb-00000009 is ringing
-- SIP/sipetb-00000009 is making progress passing it to SIP/sipetb-00000008
-- SIP/sipetb-00000009 answered SIP/sipetb-00000008

0x7f2c04002830 - Set answered time to 1510800709.529550 Dial End message for SIP/sipetb-00000008, SIP/sipetb-00000009: 1510800709.00529783 0x7f2c04000970 - Processing Dial End message for channel SIP/sipetb-00000008, peer SIP/sipetb-00000009 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Dial to DialedPending -- Channel SIP/sipetb-00000009 joined 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Enter message for channel SIP/sipetb-00000009: 1510800709.00529977 0x7f2c04002830 - Updating Party A SIP/sipetb-00000009 snapshot 0x7f2c04002830 - Processing bridge enter for SIP/sipetb-00000009 0x7f2c04002830 - Transitioning CDR for SIP/sipetb-00000009 from state Single to Bridged -- Channel SIP/sipetb-00000008 joined 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Enter message for channel SIP/sipetb-00000008: 1510800709.00530039 0x7f2c04000970 - Updating Party A SIP/sipetb-00000008 snapshot 0x7f2c04000970 - Processing bridge enter for SIP/sipetb-00000008 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state DialedPending to Dial 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Dial to Bridged -- Remote UNIX connection -- Remote UNIX connection disconnected -- Remote UNIX connection -- Remote UNIX connection disconnected -- Remote UNIX connection -- Remote UNIX connection disconnected -- Channel SIP/sipetb-00000009 left 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> -- Channel SIP/sipetb-00000008 left 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Leave message for SIP/sipetb-00000009: 1510800739.00509557 0x7f2c04002830 - Processing Bridge Leave for SIP/sipetb-00000009 0x7f2c04002830 - Transitioning CDR for SIP/sipetb-00000009 from state Bridged to Finalized 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Bridged to Finalized 0x7f2c04002830 - Beginning finalize/dispatch for SIP/sipetb-00000009 0x7f2c04002830 - Dispatching CDR for Party A SIP/sipetb-00000009, Party B Bridge Leave message for SIP/sipetb-00000008: 1510800739.00509705 a2billing_cc3.php,6: file:Class.RateEngine.php - line:1281 - uniqueid:1510800680.13 - DIAL SIP/sipetb/033168456954,60,rL(20460000:0) a2billing_cc3.php,6: file:Class.RateEngine.php - line:1164 - uniqueid:1510800680.13 - [TRUNK STATUS UPDATE : UPDATE cc_trunk SET inuse=inuse-1 WHERE id_trunk='2'] a2billing_cc3.php,6: file:Class.RateEngine.php - line:1433 - uniqueid:1510800680.13 - -> dialstatus : ANSWER, answered time is 47 a2billing_cc3.php,6: a2billing_cc3.php,6: file:Class.RateEngine.php - line:1437 - uniqueid:1510800680.13 - [USEDRATECARD=0] a2billing_cc3.php,6: file:a2billing_cc3.php - line:736 - uniqueid:1510800680.13 - :[DIALEDTIME: ->59<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:740 - uniqueid:1510800680.13 - :[DIALSTATUS: ->ANSWER<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:744 - uniqueid:1510800680.13 - :[CDRSTARTTIME: ->2017-11-15 21:51:31<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:748 - uniqueid:1510800680.13 - :[CDRANSWER: ->2017-11-15 21:51:31<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:752 - uniqueid:1510800680.13 - :[CDRend: ->2017-11-15 21:52:19<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:756 - uniqueid:1510800680.13 - :[CDRduration: ->47<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:760 - uniqueid:1510800680.13 - :[CDRbillsec: ->47<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:764 - uniqueid:1510800680.13 - :[CDRdisposition: ->ANSWERED<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:768 - uniqueid:1510800680.13 - :[ANSWERED: ->59<-]

What we need to do is to make the CDRANSWER variable to take the answered time registered in CDR thread 0x7f2c04002830 instead of using the one provided by the CDR thread 0x7f2c04000970

traza.txt

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+12+CDR+Specification

chris001 commented 7 years ago

@jansuar Great work, excellent find! I think, in some billing scenarios, there's a need for CDR(billsec) as Asterisk 12 CDR specification calculates it = the answered time of the initial call. It would be good to add this feature to Asterisk 12, name it something like, CDR(billsecbridged) = the answered time of the bridged call. I think you should make this request on Asterisk JIRA to Asterisk 12/13/14 dev team, to provide CDR(billdecbridged), paste all of your researched data, and link to this issue thread here on github.

InterLinked1 commented 3 years ago

We kept debugging the issue and found what may the problem be. According to [1] it seem that the CDR(billsec) is registering the answered time of the initial call and not the answered time of the bridged one (I mean after dialing the number on the DISA and the other party answering the call )

We CDR debug we found the right answered time data in the bridged CDR thread as shown in this log:

-- SIP/sipetb-00000009 is ringing
-- SIP/sipetb-00000009 is making progress passing it to SIP/sipetb-00000008
-- SIP/sipetb-00000009 answered SIP/sipetb-00000008

0x7f2c04002830 - Set answered time to 1510800709.529550 Dial End message for SIP/sipetb-00000008, SIP/sipetb-00000009: 1510800709.00529783 0x7f2c04000970 - Processing Dial End message for channel SIP/sipetb-00000008, peer SIP/sipetb-00000009 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Dial to DialedPending -- Channel SIP/sipetb-00000009 joined 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Enter message for channel SIP/sipetb-00000009: 1510800709.00529977 0x7f2c04002830 - Updating Party A SIP/sipetb-00000009 snapshot 0x7f2c04002830 - Processing bridge enter for SIP/sipetb-00000009 0x7f2c04002830 - Transitioning CDR for SIP/sipetb-00000009 from state Single to Bridged -- Channel SIP/sipetb-00000008 joined 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Enter message for channel SIP/sipetb-00000008: 1510800709.00530039 0x7f2c04000970 - Updating Party A SIP/sipetb-00000008 snapshot 0x7f2c04000970 - Processing bridge enter for SIP/sipetb-00000008 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state DialedPending to Dial 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Dial to Bridged -- Remote UNIX connection -- Remote UNIX connection disconnected -- Remote UNIX connection -- Remote UNIX connection disconnected -- Remote UNIX connection -- Remote UNIX connection disconnected -- Channel SIP/sipetb-00000009 left 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> -- Channel SIP/sipetb-00000008 left 'simple_bridge' basic-bridge <40047399-8742-427f-8b36-e9f4eec1f8bc> Bridge Leave message for SIP/sipetb-00000009: 1510800739.00509557 0x7f2c04002830 - Processing Bridge Leave for SIP/sipetb-00000009 0x7f2c04002830 - Transitioning CDR for SIP/sipetb-00000009 from state Bridged to Finalized 0x7f2c04000970 - Transitioning CDR for SIP/sipetb-00000008 from state Bridged to Finalized 0x7f2c04002830 - Beginning finalize/dispatch for SIP/sipetb-00000009 0x7f2c04002830 - Dispatching CDR for Party A SIP/sipetb-00000009, Party B Bridge Leave message for SIP/sipetb-00000008: 1510800739.00509705 a2billing_cc3.php,6: file:Class.RateEngine.php - line:1281 - uniqueid:1510800680.13 - DIAL SIP/sipetb/033168456954,60,rL(20460000:0) a2billing_cc3.php,6: file:Class.RateEngine.php - line:1164 - uniqueid:1510800680.13 - [TRUNK STATUS UPDATE : UPDATE cc_trunk SET inuse=inuse-1 WHERE id_trunk='2'] a2billing_cc3.php,6: file:Class.RateEngine.php - line:1433 - uniqueid:1510800680.13 - -> dialstatus : ANSWER, answered time is 47 a2billing_cc3.php,6: a2billing_cc3.php,6: file:Class.RateEngine.php - line:1437 - uniqueid:1510800680.13 - [USEDRATECARD=0] a2billing_cc3.php,6: file:a2billing_cc3.php - line:736 - uniqueid:1510800680.13 - :[DIALEDTIME: ->59<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:740 - uniqueid:1510800680.13 - :[DIALSTATUS: ->ANSWER<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:744 - uniqueid:1510800680.13 - :[CDRSTARTTIME: ->2017-11-15 21:51:31<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:748 - uniqueid:1510800680.13 - :[CDRANSWER: ->2017-11-15 21:51:31<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:752 - uniqueid:1510800680.13 - :[CDRend: ->2017-11-15 21:52:19<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:756 - uniqueid:1510800680.13 - :[CDRduration: ->47<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:760 - uniqueid:1510800680.13 - :[CDRbillsec: ->47<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:764 - uniqueid:1510800680.13 - :[CDRdisposition: ->ANSWERED<- ]17366200 a2billing_cc3.php,6: file:a2billing_cc3.php - line:768 - uniqueid:1510800680.13 - :[ANSWERED: ->59<-]

What we need to do is to make the CDRANSWER variable to take the answered time registered in CDR thread 0x7f2c04002830 instead of using the one provided by the CDR thread 0x7f2c04000970

traza.txt

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+12+CDR+Specification

What is the status on this issue? I think I am having the same issue now with Asterisk 13.

All the built-in variables are useless. ANSWEREDTIME, DIALEDTIME, CDR(billsecs), CDR(duration), you name it. Completely useless. They tell me when I got my DIAL TONE on my switch, not even when the call started going through, and certainly not when my call was answered, which is what I need.

A custom wrapper I wrote gives me the time the call started going through (literally just storing the time before calling Dial()), but this is still insufficient while not as atrocious as the built-in Asterisk vars which are way off base.

I really need a way to actually get the time the most recent channel was answered, for billing purposes. I am overcharging big time now, including charging for calls that are not supposed to make a ticket at all. Partially avoided by explicitly checking for DIALSTATUS = ANSWERED but not enough to avoid charging for quick hangup calls.

This is a very serious bug in Asterisk. I am willing to upgrade from v13 if there is a fix in a newer version.

gadamo commented 1 year ago

Just in case this helps someone else, I was recently tasked with bringing an old legacy pbx up-to-date, with a fresh OS, a recent asterisk, etc, and I had to deal with this issue.

On asterisk 18, for cc_card (pin-based/prepaid card) dialing a2billing would report total (leg#1) duration. That's because ANSWEREDTIME returns the total call duration, before bridging the calls (leg#1 with leg#2), whereas the value we needed is now CDR(billsec).

Changing most occurrences of agi->get_variable("ANSWEREDTIME"); to $agi->get_variable("CDR(billsec)", true); has worked well for our setup. I haven't put this under thorough testing, yet initial test show the correct (leg#2 only) call duration.

Sidenote: For our setup, we only had to apply the change on common/lib/Class.RateEngine.php on Lines 1357 and 1450, although -for completeness- I also applied the same change on common/lib/Class.A2Billing.php on Lines 1195, 1335, 1593 and 1738.