Wednesday, September 26, 2012

Asterisk Dictate and the old Hangup Issue

I implemented a custom phone based dictation solution using Asterisk PBX and the Dictate app and noticed that anything in the dictation dial-plan after the Dictate command, was never executed *if* the call was dropped or hung-up by the caller. When researching the issue, I found various other references to people having this same problem:

  • http://www.voip-info.org/wiki/index.php?page_id=2595&comments_page=1 (My solution could have saved someone $40K apparently!)
  •  http://forums.digium.com/viewtopic.php?t=7151

The most typical reason for adding other dial-plan entries after the Dictate call, is to apply post processing of the .raw files after the dictation call is complete. Note that ending the dictation in the normal manner, by using #,# would exit the Dictate app gracefully and therefore dial-plan entries after the Dictate call, would be executed.

The Asterisk Dictate application has a bug [IMHO] which causes the Dictate application to continue after a caller has hung up the call or the call was dropped. The attached file shows debug information where one can see that Asterisk recieves "SIP BYE" and proceeds to issue the "owner hangup", but immediately after that the log shows a warning: "WARNING[12065] file.c: Failed to write frame", followed by the Dictate app playing another sound file prompting to enter a new file name: "Playing 'dictate/enter_filename.ulaw'".
So it's evident that the Dictate app knows that the dictation has stopped because it prompt for a new file name for a new dictation, however, it does not detect from Asterisk that the call ended, which is why it prompts for a new dictation file-name.

Log output:

 <!-- the call hang-up is detected by Asterisk here: -->  
 [2012-09-26 06:40:07] DEBUG[11441] chan_sip.c: **** Received BYE (8) - Command in SIP BYE  
 [2012-09-26 06:40:07] DEBUG[11441] netsock2.c: Splitting '192.168.1.106:62724' into...  
 [2012-09-26 06:40:07] DEBUG[11441] netsock2.c: ...host '192.168.1.106' and port '62724'.  
 [2012-09-26 06:40:07] DEBUG[11441] chan_sip.c: Setting SIP_ALREADYGONE on dialog B3L2U8Zl2YEmju4BEo0jwFk8nBTlKiwk  
 [2012-09-26 06:40:07] DEBUG[11441] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb7704b18'  
 [2012-09-26 06:40:07] DEBUG[11441] chan_sip.c: Session timer stopped: 777 - B3L2U8Zl2YEmju4BEo0jwFk8nBTlKiwk  
 [2012-09-26 06:40:07] DEBUG[11441] chan_sip.c: Received bye, issuing owner hangup  
 [2012-09-26 06:40:07] DEBUG[11441] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.100.2:62724  
 [2012-09-26 06:40:07] DEBUG[11452] manager.c: Examining event:  
 <!-- Dictate (I assume) tries to create a file handle for a new dictation here - even though the call has ended: -->  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Set channel SIP/999-00000004 to write format ulaw  
 [2012-09-26 06:40:07] WARNING[12065] file.c: Failed to write frame  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second  
 <!-- Dictate prompts for a new dictation filename to write data to here - even though the call has ended: -->  
 [2012-09-26 06:40:07] VERBOSE[12065] file.c: -- <SIP/999-00000004> Playing 'dictate/enter_filename.ulaw' (language 'en')  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Set channel SIP/999-00000004 to read format ulaw  
 [2012-09-26 06:40:07] DEBUG[12065] pbx.c: Extension _., priority 11 returned normally even though call was hung up  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Soft-Hanging up channel 'SIP/999-00000004'  
 <!-- Notice that Asterisk does answer on the hangup extension for the Dictate app after the call ends, -->  
 <!-- but I have noticed that adding dial-plan directives there (for post-processing) won't work either -->  
 [2012-09-26 06:40:07] DEBUG[12065] pbx.c: Launching 'Answer'  
 [2012-09-26 06:40:07] VERBOSE[12065] pbx.c: -- Executing [h@app-dictate-record-custom:1] Answer("SIP/999-00000004", "") in new stack  
 [2012-09-26 06:40:07] DEBUG[12065] pbx.c: Spawn extension (app-dictate-record-custom,h,1) exited non-zero on 'SIP/999-00000004'  
 [2012-09-26 06:40:07] VERBOSE[12065] pbx.c: == Spawn extension (app-dictate-record-custom, h, 1) exited non-zero on 'SIP/999-00000004'  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second  
 [2012-09-26 06:40:07] DEBUG[12065] channel.c: Hanging up channel 'SIP/999-00000004'  
 [2012-09-26 06:40:07] DEBUG[12065] chan_sip.c: Hangup call SIP/999-00000004, SIP callid B3L2U8Zl2YEmju4BEo0jwFk8nBTlKiwk  
 [2012-09-26 06:40:07] DEBUG[12065] chan_sip.c: Updating call counter for incoming call  

Since the CDR is always correctly updated after the caller hangs up, I simply updated my own post-processing script to check the CDR records for dictations that are completed. Problem solved.

No comments:

Post a Comment