[asterisk-bugs] [Asterisk 0013815]: Missing CallerID in CDR when last app is voicemail
Asterisk Bug Tracker
noreply at bugs.digium.com
Fri Oct 31 08:46:56 CDT 2008
A NOTE has been added to this issue.
======================================================================
http://bugs.digium.com/view.php?id=13815
======================================================================
Reported By: ssuehring
Assigned To: otherwiseguy
======================================================================
Project: Asterisk
Issue ID: 13815
Category: General
Reproducibility: always
Severity: minor
Priority: normal
Status: assigned
Asterisk Version: 1.6.0.1
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Disclaimer on File?: N/A
Request Review:
======================================================================
Date Submitted: 2008-10-30 15:54 CDT
Last Modified: 2008-10-31 08:46 CDT
======================================================================
Summary: Missing CallerID in CDR when last app is voicemail
Description:
Hello,
I believe this to be a bug but I haven't had any luck combing the code for
where it might be happening. I have a dialplan (included in this ticket)
that ends with a call to VoiceMail. However, whenever this happens the CDR
record contains no callerid information, neither number nor name. The CDR
record is indeed produced but the callerid info is empty. This is true
regardless of the method for CDR, of which I'm using cdr-csv, cdr_custom,
and cdr-mysql. None of them contain callerid info when the last app is
voicemail.
Here's a CDR record for a voicemail-answered call:
"","","s","dp-incoming","","DAHDI/3-1","SIP/gxp2000-081ebaa8","VoiceMail","110 at default","2008-10-30
15:29:09","2008-10-30 15:29:36","2008-10-30 15:29:48",39
,12,"ANSWERED","DOCUMENTATION","1225398549.14",""
Here's a CDR record for a person-answered call (using X's to replace the
phone number):
"","71534XXXXX","s","dp-open","""UW STE"" <71534XXXXX>","DAHDI/3-1","SI
P/spa31-b7a4ae38","Dial","SIP/spa31&SIP/gxpste1&SIP/gxp2000,25","2008-1
0-30 15:08:25","2008-10-30 15:08:35","2008-10-30
15:09:18",53,43,"ANSWERED","DOC
UMENTATION","1225397305.11",""
This occurs regardless of whether the person leaves a voicemail or not. I
did a NoOp and the callerid is sent to the messages log just fine for
either type of call.
Here's the dialplan:
[dp-incoming]
exten => s,1,Gosub(checkid,s,1)
exten => s,n,GotoIfTime(08:00-17:00,*,*,*?dp-open,s,1)
exten => s,n,GotoIfTime(17:01-07:59,*,*,*?dp-closed,s,1)
exten => s,n,Goto(dp-closed,s,1)
[dp-open]
exten => s,1,Dial(SIP/spa31&SIP/gxpste1&SIP/gxp2000,25)
exten => s,n,Answer
exten => s,n,Wait(2)
exten => s,n,VoiceMail(110 at default)
exten => t,1,Playback(vm-goodbye)
exten => t,2,Hangup()
Please let me know if I can provide any additional details.
Steve
======================================================================
----------------------------------------------------------------------
(0094470) ssuehring (reporter) - 2008-10-31 08:46
http://bugs.digium.com/view.php?id=13815#c94470
----------------------------------------------------------------------
Some debug info. Looks like pbx.c calls the VoiceMail app but when
processing comes back to pbx.c the callerid is cleared. There's a ton of
callerid related things going on in app_voicemail.c, so maybe one of them
is clearing the variable. Interesting to note that the callerid number is
in the e-mail I receive with the voicemail.
[Oct 30 21:16:33] DEBUG[4355] pbx.c: Launching 'VoiceMail'
[Oct 30 21:16:33] VERBOSE[4355] logger.c: -- Executing [s at dp-open:4]
VoiceMail("DAHDI/3-1", "110 at default") in new stack
[Oct 30 21:16:33] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format gsm
[Oct 30 21:16:33] DEBUG[4355] channel.c: Scheduling timer at 160 sample
intervals
[Oct 30 21:16:33] VERBOSE[4355] logger.c: -- <DAHDI/3-1> Playing
'vm-intro.gsm' (language 'en')
[Oct 30 21:16:38] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:38] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:38] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format ulaw
[Oct 30 21:16:38] DEBUG[4355] app.c: Locked path
'/var/spool/asterisk/voicemail/default/110/INBOX'
[Oct 30 21:16:38] DEBUG[4355] app.c: Unlocked path
'/var/spool/asterisk/voicemail/default/110/INBOX'
[Oct 30 21:16:38] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format gsm
[Oct 30 21:16:38] DEBUG[4355] channel.c: Scheduling timer at 160 sample
intervals
[Oct 30 21:16:38] VERBOSE[4355] logger.c: -- <DAHDI/3-1> Playing
'beep.gsm' (language 'en')
[Oct 30 21:16:39] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:39] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:39] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format ulaw
[Oct 30 21:16:39] VERBOSE[4355] logger.c: -- Recording the message
[Oct 30 21:16:39] DEBUG[4355] app.c: play_and_record: <None>,
/var/spool/asterisk/voicemail/default/110/tmp/dRRyLw,
'wav49|gsm|wav'
[Oct 30 21:16:39] DEBUG[4355] app.c: Recording Formats: sfmts=wav49
[Oct 30 21:16:39] VERBOSE[4355] logger.c: -- x=0, open writing:
/var/spool/asterisk/voicemail/default/110/tmp/dRRyLw format: wav49,
0xb7a9fbd0
[Oct 30 21:16:39] VERBOSE[4355] logger.c: -- x=1, open writing:
/var/spool/asterisk/voicemail/default/110/tmp/dRRyLw format: gsm,
0xb7a745a0
[Oct 30 21:16:39] VERBOSE[4355] logger.c: -- x=2, open writing:
/var/spool/asterisk/voicemail/default/110/tmp/dRRyLw format: wav,
0xb7a9fd18
[Oct 30 21:16:39] DEBUG[4355] dsp.c: Setup tone 1100 Hz, 500 ms,
block_size=160, hits_required=21
[Oct 30 21:16:39] DEBUG[4355] dsp.c: Setup tone 2100 Hz, 2600 ms,
block_size=160, hits_required=116
[Oct 30 21:16:39] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to read
format slin
[Oct 30 21:16:39] DEBUG[4355] chan_dahdi.c: Requested indication 18 on
channel DAHDI/3-1
[Oct 30 21:16:46] VERBOSE[4355] logger.c: -- Recording automatically
stopped after a silence of 3 seconds
[Oct 30 21:16:46] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to read
format ulaw
[Oct 30 21:16:46] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format gsm
[Oct 30 21:16:46] DEBUG[4355] channel.c: Scheduling timer at 160 sample
intervals
[Oct 30 21:16:46] VERBOSE[4355] logger.c: -- <DAHDI/3-1> Playing
'auth-thankyou.gsm' (language 'en')
[Oct 30 21:16:46] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:46] DEBUG[4355] channel.c: Scheduling timer at 0 sample
intervals
[Oct 30 21:16:46] DEBUG[4355] channel.c: Set channel DAHDI/3-1 to write
format ulaw
[Oct 30 21:16:46] DEBUG[4355] app.c: Locked path
'/var/spool/asterisk/voicemail/default/110/INBOX'
[Oct 30 21:16:46] DEBUG[4355] app.c: Unlocked path
'/var/spool/asterisk/voicemail/default/110/INBOX'
[Oct 30 21:16:46] DEBUG[4355] app_voicemail.c: Sent mail to
110 at braingia.org with command '/usr/sbin/sendmail -t'
[Oct 30 21:16:46] DEBUG[4337] chan_sip.c: Allocating new SIP dialog for
(No Call-ID) - NOTIFY (No RTP)
[Oct 30 21:16:46] DEBUG[4337] chan_sip.c: Initializing initreq for method
NOTIFY - callid 3ade1b614262d2700f3624a37f3904ea at 192.168.1.200
[Oct 30 21:16:46] DEBUG[4337] chan_sip.c: Trying to put 'NOTIFY sip' onto
UDP socket destined for 192.168.1.15:5060
[Oct 30 21:16:46] VERBOSE[4355] logger.c: -- Auto fallthrough, channel
'DAHDI/3-1' status is 'NOANSWER'
[Oct 30 21:16:46] DEBUG[4355] channel.c: Soft-Hanging up channel
'DAHDI/3-1'
[Oct 30 21:16:46] DEBUG[4355] channel.c: Hanging up channel 'DAHDI/3-1'
[Oct 30 21:16:46] DEBUG[4355] chan_dahdi.c: dahdi_hangup(DAHDI/3-1)
[Oct 30 21:16:46] DEBUG[4355] chan_dahdi.c: Hangup: channel: 3 index = 0,
normal = 13, callwait = -1, thirdcall = -1
[Oct 30 21:16:46] DEBUG[4355] chan_dahdi.c: Disabled echo cancellation on
channel 3
[Oct 30 21:16:46] DEBUG[4355] chan_dahdi.c: Set option TDD MODE, value:
OFF(0) on DAHDI/3-1
[Oct 30 21:16:46] DEBUG[4355] chan_dahdi.c: Updated conferencing on 3,
with 0 conference users
[Oct 30 21:16:46] VERBOSE[4355] logger.c: -- Hungup 'DAHDI/3-1'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is ''
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is ''
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 's'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 'dp-incoming'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 'DAHDI/3-1'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is
'SIP/gxp2000-b7aa7ad8'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 'VoiceMail'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '110 at default'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '2008-10-30
21:16:03'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '2008-10-30
21:16:31'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '2008-10-30
21:16:46'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '43'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '15'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 'ANSWERED'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is 'DOCUMENTATION'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is ''
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is '1225419363.3'
[Oct 30 21:16:46] DEBUG[4355] pbx.c: Function result is ''
Issue History
Date Modified Username Field Change
======================================================================
2008-10-31 08:46 ssuehring Note Added: 0094470
======================================================================
More information about the asterisk-bugs
mailing list