[Home]

Summary:ASTERISK-15012: [regression] 1.4 SVN branch does not write Userfield in CDR
Reporter:Danny Nicholas (sethsdad)Labels:
Date Opened:2009-10-20 08:52:44Date Closed:2011-06-07 14:07:20
Priority:MinorRegression?Yes
Status:Closed/CompleteComponents:Applications/app_dial
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I'm trying to get hangup cause into my CDR because I'm getting intermittent hangups on production calls.  I put the command
Set(CDR(userfield)=${CDR(userfield)} Hangupcause:${HANGUPCAUSE})
into my dialplan after my Dial commands.  This works fine on 1.4.25.1 and 1.4.26.1, but does not work on the 1.4SVN branch I'm using in production.
Comments:By: Tilghman Lesher (tilghman) 2009-10-20 09:19:53

What exactly is contained in your userfield?  It might be a question of syntax.  Can you show the verbose output of the command being executed?  What CDR backend are you using?
By: Danny Nicholas (sethsdad) 2009-10-20 09:24:08

Userfield is blank.  I'm using the csv CDR "/var/log/asterisk/cdr-csv/Master.csv".

here is the CLI output of a call with verbose 15 debug 10.
   -- DAHDI/1-1 answered SIP/104-08473880
   -- fixed jitterbuffer created on channel DAHDI/1-1
Really destroying SIP dialog 'adaefac9-7bdd35df-d9e94df4@192.168.23.121' Method: SUBSCRIBE
Really destroying SIP dialog '3c00a63a0092732a1f19711d0a4ae390@192.168.23.96' Method: OPTIONS
   -- Hungup 'DAHDI/1-1'
   -- fixed jitterbuffer destroyed on channel DAHDI/1-1
Extension Changed 551[internal] new state Idle for Notify User 105
Extension Changed 551[internal] new state Idle for Notify User 107
Extension Changed 551[internal] new state Idle for Notify User 100
 == Spawn extension (DLPN_DialPlan1, 2975000, 1) exited non-zero on 'SIP/104-08473880'
   -- Executing [h@macro-trunkdial-failover-0.3:1] Set("SIP/104-08473880", "CDR(userfield)= Hangupcause:16") in new stack
   -- Executing [h@macro-trunkdial-failover-0.3:2] NoOp("SIP/104-08473880", "Hangup Cause:16") in new stack
Extension Changed 104[internal] new state Idle for Notify User 106
Really destroying SIP dialog '1b5ad99b-64d61da5-8245b9ae@192.168.23.114' Method: BYE
Really destroying SIP dialog '075f314101e8463b33d27b2415b68412@192.168.23.96' Method: OPTIONS

here is the line generated by that call
"","","2975000","DLPN_DialPlan1","DAHDI/R1","SIP/104-08473880","DAHDI/1-1","Dial","DAHDI/R1/w2975000|20|kKtTg","2009-10-20 14:18:26","2009-10-20 14:18:29","2009-10-20 14:18:40",14,11,"ANSWERED","DOCUMENTATION","1256048306.29",""
By: Danny Nicholas (sethsdad) 2009-10-20 13:08:42

added note - installed 1.4.26.2 and problem duplicated itself, but only on outgoing calls.  incoming calls create field as expected.
By: Tilghman Lesher (tilghman) 2009-10-20 14:13:09

As far as Asterisk is concerned, there is no difference between incoming and outgoing calls.  Both involve an originating channel and a destination channel.  However, there could be something in your dialplan which distinguishes between them and could be the cause of this issue.  Could we see example dialplans (just the parts that actually execute) for both a call which generates the Userfield and a call which does not?
By: Danny Nicholas (sethsdad) 2009-10-20 14:21:48

works -
[from-pstn]
exten => s,1,Answer()
exten => s,n,Verbose(Ringing )
exten => s,n,Verbose(Caller number ${CALLERID(num)} )
exten => s,n,Gotoif($[ "${CALLERID(num)})}" < "2010010"]?skipset)
exten => s,n,Set(DB(${CHANNEL})=${CALLERID(all)})
exten => s,n(skipset),Verbose(Called ${EXTEN} )
exten => s,n,Goto(default|s|1)
[default]
include => parkedfeat
exten => s,1,Answer()
exten => s,n,Verbose(Ringing )
; load local vars for call control each time through
exten => s,n,Set(TESTOP=${DB(Nightop/ext)})
; show callerid to me if i'm watching
exten => s,n,Verbose(Caller name ${CALLERID(name)} )
exten => s,n,Verbose(Caller number ${CALLERID(num)} )
; put callerid into asterisk db so we can get from AGI
exten => s,n,Gotoif($[ "${CALLERID(num)})}" < "2010010"]?skipset)
exten => s,n,Set(DB(${CHANNEL})=${CALLERID(all)})
exten => s,n(skipset),Verbose(Called ${EXTEN} )
; jump to various spots if we select them
exten => s,n,Gotoif($[ "${TESTOP})}" > "801"]?866)
exten => s,n,Gotoif($[ "${TESTOP})}" > "401"]?501)
exten => s,n,Gotoif($[ "${TESTOP})}" > "228"]?401)
exten => s,n,Gotoif($[ "${TESTOP})}" > "208"]?lunch)
; try live people first
exten => s,n,Dial(SIP/${TESTOP},40,,KktTm)
; start automated appearance
exten => s,n,Background(record/welcometodebs)
exten => s,n,Background(record/retry)
exten => s,n,WaitExten(5)
exten => s,n,Background(record/pleasewait)
; try everyone
exten => s,n(lunch),Dial(SIP/100&SIP/102&SIP/104&SIP/107&SIP/105,40,,KktTm)
; still no luck, get voicemail and hang up
exten => s,n,Macro(voicemail-email|108)
exten => s,n,Background(vm-goodbye)
exten => s,n,Hangup(${HANGUP_CAUSE})
exten => _1XX,1,Verbose(1|Extension ${EXTEN})
exten => _1XX,n,Answer()
exten => _1XX,n,Dial(SIP/${EXTEN},30,rKkTtg)
exten => _1XX,n,Set(CDR(userfield)=${CDR(userfield)} Hangupcause:${HANGUPCAUSE})
exten => _1XX,n,Macro(voicemail-email|${EXTEN})
exten => _1XX,n,Hangup(${HANGUP_CAUSE})

does not
[macro-stdexten]
exten = s,1,Set(__DYNAMIC_FEATURES=${FEATURES})
exten = s,2,GotoIf($["${FOLLOWME_${ARG1}}" = "1"]?5:3)
exten = s,n,Set(LINESTAT=Idle)
exten = s,n,AGI(hintcheck.agi|${ARG1})
;exten = s,n,Wait(1)
exten = s,n,Verbose(status is ${LINESTAT} for ${ARG1} )
exten = s,n,Gotoif($["${LINESTAT}" != "Idle"]?inuse)
exten = s,n,AGI(callid.agi|${CHANNEL})
exten = s,n,Gotoif($["${INCID}" = "INTERNAL"]?internal)
exten = s,n,Set(WORKID=${DB(${INCID})})
exten = s,n,Gotoif($[ "${LEN(${WORKID})}" < "4"]?foofoo)
exten = s,n,Set(CALLERID(all)=${WORKID})
exten = s,n,Goto(?foofoo)
exten = s,n(internal),Set(CALLERID(all)=${DB(CID/${CALLERID(num)})})
exten = s,n(foofoo),Dial(${ARG2},${RINGTIME},${DIALOPTIONS})
exten = s,n,Goto(s-${DIALSTATUS},1)
exten = s,n,Macro(stdexten-followme,${ARG1},${ARG2})
exten = s,n(inuse),Voicemail(${ARG1},b)
exten = s,n,Goto(default,s,1)

exten = s-NOANSWER,1,Macro(voicemail-email|${ARG1})
exten = s-NOANSWER,2,Goto(default,s,1)
exten = s-BUSY,1,Macro(voicemail-email|${ARG1})
exten = s-BUSY,2,Goto(default,s,1)
exten = _s-.,1,Goto(s-NOANSWER,1)
exten = a,1,Macro(voicemail-email|${ARG1})

[macro-stdexten-followme]
exten = s,1,Dial(${ARG2},${RINGTIME},${DIALOPTIONS})
exten = s,2,Followme(${ARG1},${FOLLOWMEOPTIONS})
exten = s,3,Voicemail(${ARG1},u)
exten = s-NOANSWER,1,Voicemail(${ARG1},u)
exten = s-BUSY,1,Voicemail(${ARG1},b)
exten = s-BUSY,2,Goto(default,s,1)
exten = _s-.,1,Goto(s-NOANSWER,1)
exten = a,1,VoicemailMain(${ARG1})
By: Danny Nicholas (sethsdad) 2009-10-26 10:43:56

Tested this today and find that problem is that cdr->userfield does not get processed by cdr-csv.c on outgoing calls.   works fine on incoming calls. The value gets set and can be verified via noop, but either gets reset or just doesn't get processed for whatever reason.

this is CLI output
 -- Executing [6163010@DLPN_DialPlan1:1] Macro("SIP/170-087d3320", "trunkdial-failover-0.3|DAHDI/R1/w6163010||trunk_1|trunk_1") in new stack
   -- Executing [s@macro-trunkdial-failover-0.3:1] Set("SIP/170-087d3320", "CALLERID(num)=") in new stack
   -- Executing [s@macro-trunkdial-failover-0.3:2] GotoIf("SIP/170-087d3320", "0?1-dial|1") in new stack
   -- Executing [s@macro-trunkdial-failover-0.3:3] Set("SIP/170-087d3320", "CALLERID(all)=DAHDI/R1") in new stack
   -- Executing [s@macro-trunkdial-failover-0.3:4] Goto("SIP/170-087d3320", "1-dial|1") in new stack
   -- Goto (macro-trunkdial-failover-0.3,1-dial,1)
   -- Executing [1-dial@macro-trunkdial-failover-0.3:1] Answer("SIP/170-087d3320", "") in new stack
   -- Executing [1-dial@macro-trunkdial-failover-0.3:2] Dial("SIP/170-087d3320", "DAHDI/R1/w6163010|20|kKtTg") in new stack
   -- Called R1/w6163010
   -- DAHDI/1-1 answered SIP/170-087d3320
   -- Saved useragent "PolycomSoundPointIP-SPIP_501-UA/3.1.2.0392" for peer 170
   -- Hungup 'DAHDI/1-1'
   -- Executing [1-dial@macro-trunkdial-failover-0.3:3] Set("SIP/170-087d3320", "CDR(userfield)=foo:16_US") in new stack
   -- Executing [1-dial@macro-trunkdial-failover-0.3:4] GotoIf("SIP/170-087d3320", "0 > 0 ?1-ANSWER|1:1-out|1") in new stack
   -- Goto (macro-trunkdial-failover-0.3,1-out,1)
   -- Executing [1-out@macro-trunkdial-failover-0.3:1] Hangup("SIP/170-087d3320", "") in new stack
 == Spawn extension (macro-trunkdial-failover-0.3, 1-out, 1) exited non-zero on 'SIP/170-087d3320' in macro 'trunkdial-failover-0.3'
 == Spawn extension (DLPN_DialPlan1, 6163010, 1) exited non-zero on 'SIP/170-087d3320'
   -- Executing [h@macro-trunkdial-failover-0.3:1] Set("SIP/170-087d3320", "CDR(userfield)=foo:16_US Hangupcause:16") in new stack
   -- Executing [h@macro-trunkdial-failover-0.3:2] NoOp("SIP/170-087d3320", "uf=foo:16_US Hangupcause:16") in new stack
   -- Executing [h@macro-trunkdial-failover-0.3:3] NoOp("SIP/170-087d3320", "Hangup Cause:16") in new stack
   -- Executing [h@macro-trunkdial-failover-0.3:4] ForkCDR("SIP/170-087d3320", "hangcause=16") in new stack
   -- Executing [h@macro-trunkdial-failover-0.3:5] Hangup("SIP/170-087d3320", "16") in new stack
 == Spawn extension (macro-trunkdial-failover-0.3, h, 5) exited non-zero on 'SIP/170-087d3320'

this is CDR record
"","","6163010","DLPN_DialPlan1","DAHDI/R1","SIP/170-087d3320","DAHDI/1-1","Dial","DAHDI/R1/w6163010|20|kKtTg","2009-10-26 10:20:38","2009-10
-26 10:20:42","2009-10-26 10:20:57",19,15,"ANSWERED","DOCUMENTATION","1256570438.0",""
By: Tilghman Lesher (tilghman) 2010-01-27 14:15:20.000-0600

Okay, what's actually happening here is that the CDR is getting posted at the end of the bridge (in the Dial), so anything that you set in the dialplan after that point is hitting too late.
By: Tilghman Lesher (tilghman) 2010-01-27 14:25:40.000-0600

So what you really need to do is move setting the userfield to the "h" extension, because that is run before the Dial exits.
By: Danny Nicholas (sethsdad) 2010-01-27 14:46:54.000-0600

Okay.  After a few tweaks to the dialplan, this issue seems to be resolved.  Note to readers; You'll need to do at least 4-5 different calls to insure that this works.  Of course Til rocks...
By: Tilghman Lesher (tilghman) 2010-01-27 16:27:41.000-0600

Fixed by configuration change.