[Home]

Summary:ASTERISK-09763: CDR dst and dcontext field wrong information depending if caller or callee hangs up first
Reporter:Sam Deller (samdell3)Labels:
Date Opened:2007-06-26 17:49:29Date Closed:2011-06-07 14:03:17
Priority:MajorRegression?No
Status:Closed/CompleteComponents:
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:We are in the process of bench testing 1.4.5 (gotta love that T.38!)
This bug can be replicated 100% of the time.
I classify this as major as many calls cannot be billed.

All test calls are SIP to SIP. Caller = 6500011,  Callee = 6500012

If the CALLER hangs up first:
CDR record logs dst and dcontext field from within the macro. Weird. EG dst field results in 's' and dcontext results in 'macro-call-sip-nap'

If the CALLEE hangs up first:
CDR is recorded OK
dst field results in '66500012' and dcontext results in 'default'



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

Default Context:
[default]
exten => _650[0-7]XXX/_6650[0-7]XXX,1,Macro(call-sip-nap,6${EXTEN})
exten => _6508XXX/_66508XXX,1,Macro(call-sip-nap,6${EXTEN})
exten => _6509XXX/_66509XXX,1,Macro(call-sip-nap,6${EXTEN})
exten => _06650XXXX,1,Macro(call-sip-nap,${EXTEN:1})


Dial Macro:
[macro-call-sip-nap]
exten => s,1,Wait,1
;exten => s,2,Progress()
exten => s,2,NoOp()
exten => s,3,NoOp()
exten => s,4,Set(headerfrom=${SIP_HEADER(From,1)})
exten => s,5,Set(tgtemp=${CUT(headerfrom,\=,2)})
exten => s,6,Set(TG=${CUT(tgtemp,\>,1)})
exten => s,7,Set(Status=${SIPPEER(${ARG1}:status)})
exten => s,8,GotoIf($["${Status}" = ""]?256:9)
exten => s,9,GotoIf($[ "${TG}" : "^Chan" ]?11:10)
exten => s,10,Set(TG=NOT-PSTN)
exten => s,11,Set(remoteparty=${SIP_HEADER(Remote-Party-ID,1)})
exten => s,12,Set(cutremote=${CUT(remoteparty,\<,1)})
exten => s,13,Set(CDR(userfield)=${CDR(userfield)}Remote-Party:${cutremote}\;InTrunkGroup:${TG}\;${ARG3})
exten => s,14,GotoIf($[${EXISTS(${PORTED})}]?15:16)
exten => s,15,Set(CALLERID(number)=${PORTED})
exten => s,16,GotoIf($[${EXISTS(${FAXABILITY})}]?18:17)
exten => s,17,GotoIf($[${EXISTS(${VMAIL})}]?138:18)
exten => s,18,Dial(SIP/${ARG1}&SIP/voipnap1/${ARG1},60,L(14400000))
exten => s,19,Goto(ct-status,s-${DIALSTATUS}-${HANGUPCAUSE},1)
exten => s,119,NoOp(Call SIP Napier Priority 119, DialStatus:${DIALSTATUS} HangupCause:${HANGUPCAUSE})
exten => s,120,Goto(ct-status,s-${DIALSTATUS}-${HANGUPCAUSE},1)
exten => s,138,Dial(SIP/${ARG1}&SIP/voipnap1/${ARG1},15,L(14400000))
exten => s,139,Voicemail(0${ARG1}|u)
exten => s,140,Goto(ct-status,s-${DIALSTATUS}-${HANGUPCAUSE},1)
exten => s,239,NoOp(Call SIP Napier Priority 239 VOICEMAIL, DialStatus:${DIALSTATUS} HangupCause:${HANGUPCAUSE})
exten => s,240,Voicemail(0${ARG1}|u)
exten => s,241,Goto(ct-status,s-${DIALSTATUS}-${HANGUPCAUSE},1)
exten => s,256,Goto(ct-status,s-PEERNOTEXIST,1)

Comments:By: Sam Deller (samdell3) 2007-06-27 03:27:23

Full CDR Detail:

1) 66500011 calls 66500012. 66500011 hangs up first:

"","66500011","s","macro-call-sip-nap","""66500011"" <66500011>","SIP/66500011-b60fe758","SIP/66500012-0863d828","Dial","SIP/66500012&SIP/voipnap1/66500012|60|L(14400000)","2007-06-26 22:24:47","2007-06-26 22:24:50","2007-06-26 22:25:03",16,13,"ANSWERED","DOCUMENTATION","1182896687.583","Remote-Party:66500011 ;InTrunkGroup:NOT-PSTN;"


1) 66500011 calls 66500012. 66500012 hangs up first:

"","66500011","6500012","default","""66500011"" <66500011>","SIP/66500011-b62fcdb8","SIP/66500012-0864e6c0","Dial","SIP/66500012&SIP/voipnap1/66500012|60|L(14400000)","2007-06-26 22:25:20","2007-06-26 22:25:22","2007-06-26 22:25:27",7,5,"ANSWERED","DOCUMENTATION","1182896720.585","Remote-Party:66500011 ;InTrunkGroup:NOT-PSTN;"
By: Christoph Stadlmann (cstadlmann) 2007-06-27 08:00:46

This bug exists for a long time in svn-branch. My workaround is the following, assuming cdr is stored in a mysql database:

1) When an extension initiates the call, store the initial destination in a variable, e.g. Set(_ORIGDEST=${EXTEN}). Use the "_" not to loose the value if call is tranfered or otherwise forwarded.

2) When any party hangs up the call, just launch a macro or AGI in exten=>h. If using AGI remember to use DeadAGI() instead of AGI(). In this script or macro, just run an UPDATE sql statement against the current table entry.

Of course, the text files Master.csv or whatever are not updated and still contain the wrong values. In my case that doesn't matter.
And of course I know it's a nasty bug which also generates multiple lines in the mysql table with weired data, but using the workaround above, you are able to bill your customers again.
By: Steve Murphy (murf) 2007-06-28 13:43:42

To fix this bug in the most general way, and save everyone a headache or two, I propose lifting the restrictions in the CDR() function (to just allow you to mod the amaflags, accountcode, and userfield fields), so that you can set ANY CDR field as you desire.

It may require that you set a local channel var to the ${EXTEN} value, and set the field in the hangup field or something, but at least you don't have to write AGI scripts, etc.
By: Steve Murphy (murf) 2007-06-28 14:25:27

Oh, and cstadlmann-- while using _globalvarnames is a possible solution, what happens when multiple channels are operating in parallel? Couldn't one channel mess up the others this way?
By: Christoph Stadlmann (cstadlmann) 2007-06-29 00:41:48

@murf: I use one single '_' and not the double one, so the variable is just inherited once if there is some call forward to a local channel happening. Of course I check in an AGI script if we are in a local channel and act accordingly.
My suggested workaround was just a simple summary how I cope with that issue.

BTW, during compilation the following waring occurs:

[CC] cdr.c -> cdr.o
cdr.c: In function `cdr_merge_vars':
cdr.c:472: warning: `tovarval' might be used uninitialized in this function

Maybe this is the reason for the buggy behavior?
By: Sam Deller (samdell3) 2007-06-29 03:43:39

cstadlmann, Thanks for your workaround. I might give that a go. We also use MySQL. Otherwise plan-b is to write a perl script to read the (incorrect) records and update the wrong dst fields based on the 'lastdata' field. In our case, it will look something like 'SIP/5551068781269#@imgnap1|60|L(14400000)' therefore we can extract the dst number as 68781269.

Really messy, and not exactly a workaround, but I have ZERO experience with C coding... however, I might grab myself a copy of "C for dummies" and begin trawling. As a starting point, may I ask where this bug *could* lie? EG would it be a simple as a bug in cdr.c, or is this a lot deeper and tied into a lot of other code/variables ?
By: Christoph Stadlmann (cstadlmann) 2007-06-29 08:04:48

samdell, I'm also no c guru at all, so I don't even try to dig into the source. Anyway, extracting the values from the lastdata field could cause extra trouble, so in my case the workaround with storing the inital ${EXTEN} seems to be the most riskless way.

BTW, I'm sure you found out that some zombie entries are stored into cdr table, at least in svn-branch version. These zombie entries have nearly the same data but no 'dstchannel', 'lastapp', 'lastdata' or 'duration'. So in my hangup-script (which is PHP AGI) I call the following sql query:


// Now check if a zombie entry is in the table
$tuniqueid = explode(".", $agi->request["agi_uniqueid"]);
$query = "DELETE FROM cdr WHERE uniqueid LIKE '".$tuniqueid[0].".%' AND lastapp='';";
$result = mysql_query($query) or die_with_message("Update for Zombie failed: ".mysql_error());


Maybe this is useful for you in housekeeping the database, because you really don't need these zombies...
By: Pedro Tomas (tracinet) 2007-06-29 09:01:06

FWIW - I am having cdr issue reagrdless of who hangs up first...  Switched to Asterisk 1.4.4 and cdrs *seem* ok.  Is there a specific reason you are using 1.4.5?  You may just need to roll back to 1.4.4 (just a thought).
By: Christoph Stadlmann (cstadlmann) 2007-06-29 10:09:36

tracinet - If you look at the bugtracker often, you will see that 1.4.4 had several bugs which are fixed in 1.4.5.
Because I don't want to wait that long time for a new release version I use svn-branch in my production system. You can grab a 'fresh' copy every week or so, and major bugs are fixed.
Going back to 1.4.4 is nothing I would recommend. Lastest svn-branch version runs very smooth on my system, expect for that nasty cdr issue. But... The workaround works for me, and maybe murf can spend some time fixing the bug.
By: Sam Deller (samdell3) 2007-06-29 19:41:33

OK this is an easy workaround (for us anyway) based on ideas posted here.

It's simply the equivalent of AppendCDRUserfield (now depreciated) by appending a 'Dialled Number (DSTNumber)' into the userfield. ARG1 is the EXTEN variable passed to the dial macro.

exten => s,N,Set(CDR(userfield)=${CDR(userfield)}DSTNumber:${ARG1}\;)

Our billing code looks for Key:Value; fields in the userfield for additional info, so we will simply modify it to read DSTNumber:DIALLEDNUMBER; instead of reading the 'dst' field.

Not sure what happens when we get ghost CDR records :-(
Havent seen any of these as yet. Are they just random records (eg nothing to worry about) or are they actual billable calls that cannot be billed given that they do not have the duration field populated ?

In many situations the above userfield workaround would not work, but it suits us and happy for now. Long term 'real solution' still appreciated and happy to test in production when a patch may become available.

Thanks cstadlmann and murf for your feedback so far.
By: Steve Murphy (murf) 2007-07-05 17:35:23

OK, I have just revised my opinion.

After some discussions with tilghman (corydon76), I have changed my
attitude about this situation.

First of all, in both situations, the CDRs are indeed telling the truth. If you call a macro in the dial, it gets executed on the peer side (IIRC). "s" and macro name for dst and dcontext are truthful.

While you may not be particurly interested in what I'm about to say, because it looks like you've found a work-around, I'm going to say it for the sake of all who bump into this sort of problem...

First of all, the CDR system as it stands has some pretty big deficiencies. I've patched and tweeked, but it has to really be changed fundamentally to get it to handle transfers and other situations correctly. I'm working on that now. Some big shifts in strategy will occur in 1.6 (I hope to get in before we release). And perhaps in 1.8, I'll be able to intro CEL.

My determination is to settle on having CDR's tell the unwanted, maybe different truth than it did in previous releases. Working around it using the accountcode or userfields is the suggested thing to do right now. Corydon76 has introduced the adaptive_odbc stuff, and I think in trunk, that will be the advised way to handle situations like this. Shove ${EXTEN} (or whatever you want) into a CDR variable or userfield, or accountcode, or whatever, and then using mapping capabilities on the backend, map it into the field you are interested in seeing.

The main drawback to just allowing folks to tweak CDR field, is that it still will not solve all the problems. Any of the "non-editable' fields you might set, might mysteriously get changed by the underlying CDR mechanisms in Asterisk. You might waste a lot of time twiddling and tweaking and experimenting, only to find that you can't solve the problem that way! So, doing mappings at the backend is the real, true answer. We've had some discussion on this on asterisk-dev; look for postings from murf (me) there.

If you are using mysql, then you might consider, if things need tweaking, moving over to an ODBC interface, and moving up to cdr_adaptive_odbc.

So, I will close this bug, for the time being. Any who have violent objections to this strategy, please reopen and feel free to share your most poignant feelings on the subject. If nothing else, we can always serve as a shoulder to cry on!
By: Steve Murphy (murf) 2007-07-05 17:36:34

OK, closing this bug as previously explained. Reopen if you have something you think might serve better than the present strategy.