[Home]

Summary:ASTERISK-03743: ADSI breaks voicemail
Reporter:logitel (logitel)Labels:
Date Opened:2005-03-22 15:26:15.000-0600Date Closed:2008-01-15 15:39:36.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_voicemail
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 3833HeadCommit.txt
( 1) adsi-20050601-2310.stable.diff
Description:In recent CVS voicemail prompts and voicemail messages itself are not played back properly when voicemail_main is being accessed from an ADSI compatible phone. Prompts and messages
work properly on the same Zap interface when a non ADSI phone is used.
It seems that ADSI messages preempt voice prompts.

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

Call to VM from an ADSI phone:
-------------------------------------------------------------
-- Starting simple switch on 'Zap/2-1'
-- Executing VoiceMailMain("Zap/2-1", "s5533") in new stack
-- Playing 'vm-youhave' (language 'en')
-- Playing 'vm-onefor' (language 'en')
-- Playing 'vm-Old' (language 'en')
-- Playing 'vm-messages' (language 'en')
-- Playing 'vm-opts' (language 'en')
== Spawn extension (T1, ##, 1) exited non-zero on 'Zap/2-1'

-------------------------------------------------------------
Call to VM from an Non-ADSI phone:

-- Starting simple switch on 'Zap/2-1'
-- Executing VoiceMailMain("Zap/2-1", "s5533") in new stack
-- Playing 'vm-youhave' (language 'en')
-- Playing 'digits/3' (language 'en')
-- Playing 'vm-Old' (language 'en')
-- Playing 'vm-messages' (language 'en')
-- Playing 'vm-onefor' (language 'en')
-- Playing 'vm-Old' (language 'en')
-- Playing 'vm-messages' (language 'en')
-- Playing 'vm-opts' (language 'en')
== Spawn extension (T1, ##, 1) exited non-zero on 'Zap/2-1'
Comments:By: Mark Spencer (markster) 2005-03-22 16:39:25.000-0600

can you turn on debug and see if perhaps we're getting extra digits / characters that might be interrupting things?
By: logitel (logitel) 2005-03-22 19:39:43.000-0600

Here is the debug output.

Call to voicemail from a non-ADSI phone
---------------------------------------------------------------------------------
   -- Starting simple switch on 'Zap/2-1'
2005-03-22 17:34:10 DEBUG[3487]: chan_zap.c:4262 zt_read: DTMF digit: # on Zap/2-1
2005-03-22 17:34:11 DEBUG[3487]: chan_zap.c:4262 zt_read: DTMF digit: # on Zap/2-1
2005-03-22 17:34:11 DEBUG[3487]: chan_zap.c:1327 zt_enable_ec: Enabled echo cancellation on channel 2
   -- Executing VoiceMailMain("Zap/2-1", "s5533") in new stack
2005-03-22 17:34:11 DEBUG[3487]: chan_zap.c:2420 zt_answer: Took Zap/2-1 off hook
2005-03-22 17:34:11 DEBUG[3487]: res_adsi.c:212 __adsi_transmit_messages: No ADSI CPE detected (0)
2005-03-22 17:34:11 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:34:11 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:34:11 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/INBOX'
2005-03-22 17:34:11 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/INBOX'
2005-03-22 17:34:11 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:34:11 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:34:11 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-youhave' (language 'en')
2005-03-22 17:34:12 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:12 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:12 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'digits/3' (language 'en')
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-Old' (language 'en')
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:13 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-messages' (language 'en')
2005-03-22 17:34:14 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:14 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:14 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-onefor' (language 'en')
2005-03-22 17:34:15 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:15 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:15 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-Old' (language 'en')
2005-03-22 17:34:16 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:16 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:16 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-messages' (language 'en')
2005-03-22 17:34:16 DEBUG[3487]: chan_zap.c:3984 __zt_exception: Exception on 31, channel 2
2005-03-22 17:34:16 DEBUG[3487]: chan_zap.c:3234 zt_handle_event: Got event On hook(1) on channel 2 (index 0)
2005-03-22 17:34:16 DEBUG[3487]: chan_zap.c:1359 zt_disable_ec: disabled echo cancellation on channel 2
2005-03-22 17:34:16 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:34:16 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:34:16 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
 == Spawn extension (T1, ##, 1) exited non-zero on 'Zap/2-1'
---------------------------------------------------------------------------------
Call from ADSI phone:

2005-03-22 17:37:30 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:37:30 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:37:30 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/INBOX'
2005-03-22 17:37:30 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/INBOX'
2005-03-22 17:37:30 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:37:30 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:37:30 DEBUG[3487]: res_adsi.c:246 __adsi_transmit_messages: Already in data mode
2005-03-22 17:37:30 DEBUG[3487]: res_adsi.c:259 __adsi_transmit_messages: Message 1, of 49 input bytes, 4734 output bytes
2005-03-22 17:37:31 DEBUG[3487]: res_adsi.c:273 __adsi_transmit_messages: Sent total spill of 4734 bytes
2005-03-22 17:37:32 DEBUG[3487]: chan_zap.c:4262 zt_read: DTMF digit: D on Zap/2-1
2005-03-22 17:37:32 DEBUG[3487]: chan_zap.c:4262 zt_read: DTMF digit: 1 on Zap/2-1
2005-03-22 17:37:32 DEBUG[3487]: res_adsi.c:282 __adsi_transmit_messages: Acked up to message 1
2005-03-22 17:37:32 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-youhave' (language 'en')
2005-03-22 17:37:32 DEBUG[3487]: chan_zap.c:4262 zt_read: DTMF digit: B on Zap/2-1
2005-03-22 17:37:32 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:32 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-onefor' (language 'en')
2005-03-22 17:37:33 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:33 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:33 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-Old' (language 'en')
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-messages' (language 'en')
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:3984 __zt_exception: Exception on 31, channel 2
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:3234 zt_handle_event: Got event On hook(1) on channel 2 (index 0)
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:1359 zt_disable_ec: disabled echo cancellation on channel 2
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
2005-03-22 17:37:34 DEBUG[3487]: app.c:1108 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/5533/Old'
2005-03-22 17:37:34 DEBUG[3487]: app.c:1119 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/5533/Old'
 == Spawn extension (T1, ##, 1) exited non-zero on 'Zap/2-1'
   -- Executing Playback("Zap/2-1", "thank-u-for-calling-log") in new stack
2005-03-22 17:37:34 WARNING[3487]: file.c:561 ast_readaudio_callback: Failed to write frame
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Playing 'thank-u-for-calling-log' (language 'en')
2005-03-22 17:37:34 DEBUG[3487]: channel.c:1155 ast_settimeout: Scheduling timer at 0 sample intervals
 == Spawn extension (T1, h, 1) exited non-zero on 'Zap/2-1'
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:2104 zt_hangup: Hangup: channel: 2 index = 0, normal = 31, callwait = -1, thirdcall = -1
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:1359 zt_disable_ec: disabled echo cancellation on channel 2
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:2512 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/2-1
2005-03-22 17:37:34 DEBUG[3487]: chan_zap.c:1296 update_conf: Updated conferencing on 2, with 0 conference users
   -- Hungup 'Zap/2-1'
By: tclark (tclark) 2005-03-23 16:15:03.000-0600

The real question why do we send *ANY*
voicemail prompts down the wire to adsi SCREEN Phone in the first place ..
Is that not the point of the adsi SCREEN phone to showe a UI & skip the audio
because all the options are there right in front of you :)

edited on: 03-23-05 16:16
By: logitel (logitel) 2005-03-23 17:03:50.000-0600

You are right the voiceprompts would not really be necessary when using ADSI.
This bug prevents the actual voicemail message to be sent though not only the prompts.
By: Mark Spencer (markster) 2005-03-23 17:17:54.000-0600

It's actually more serious because the "B" can get in the way of dialing stuff too.  Root cause is that when we switch back to voice mode, we need to wait to receive the "B" before proceeding (or at least wait a bit for it).
By: Mark Spencer (markster) 2005-04-06 00:19:15

Fixed in CVS head.
By: Jason Parker (jparker) 2005-06-02 00:58:04

Added patch for v1-0.

Existing patch didn't apply entirely cleanly (though, it almost did).

Disclaimer on file under A.K.A. North Antara.


By: Russell Bryant (russell) 2005-06-24 18:28:06

fixed in 1.0, thanks!
By: Digium Subversion (svnbot) 2008-01-15 15:31:00.000-0600

Repository: asterisk
Revision: 5422

U   trunk/include/asterisk/adsi.h
U   trunk/res/res_adsi.c

------------------------------------------------------------------------
r5422 | markster | 2008-01-15 15:31:00 -0600 (Tue, 15 Jan 2008) | 2 lines

Fix ADSI 'B' issue (bug ASTERISK-3743)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=5422
By: Digium Subversion (svnbot) 2008-01-15 15:39:36.000-0600

Repository: asterisk
Revision: 6007

U   branches/v1-0/include/asterisk/adsi.h
U   branches/v1-0/res/res_adsi.c

------------------------------------------------------------------------
r6007 | russell | 2008-01-15 15:39:36 -0600 (Tue, 15 Jan 2008) | 2 lines

when switching back to voice mode, wait for 'B' (bug ASTERISK-3743)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=6007