Vgetty API play problems

Brian McGovern (bmcgover@cisco.com)
Tue, 03 Aug 1999 13:26:02 -0400
Messages sorted by:[ date ][ thread ][ subject ][ author ]
Here is another strange one. The synopsis is this: I used to be be able to use
my call program (call tree) to play out a series of messages, handle DTMF, etc.
Now, I can't. It happened between two calls with no configuration changes or
code changes, so I'm stumped...

Recently, I have been tweaking the configuration file to fix some errors I
introduced when I initially wrote it. I had been running several RMD files
through the modem as a series of OGMs. During one of those plays, the API 
suddenly returned an ERROR. Since then, I've been unable to get the API to
play ANY messages (even the ones that worked fine originally). However, if I
turn off the call_program in voice.conf, I can make it resume normal answering
machine operations.

The modem is a Sportster 33.6 Voice/Fax modem.

I suspect the bug is in my code, but I'm lost as to what it may be. I guess 
what I'm looking for is a list of possibilities as to why a play command on
a perfectly good RMD file would fail (vgetty doesn't appear helpful as to
the reason).

Here is the vgetty log, both for "answering machine" mode and, with my 
application, in that order. I've inserted comments:


>This also happens on 1.1.20. I've not backgraded to 1.1.19
08/03 12:53:04 yd2  vgetty: experimental test release 0.9.4 / 20Jul99
08/03 12:53:04 yd2  mgetty: experimental test release 1.1.21-Jul24
08/03 12:53:04 yd2  reading generic configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 12:53:04 yd2  reading program vgetty configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 12:53:04 yd2  reading port ttyd2 configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 12:53:05 yd2  check for lockfiles
08/03 12:53:05 yd2  locking the line
08/03 12:53:07 yd2  lowering DTR to reset Modem
08/03 12:53:07 yd2  send: \dATQ0V1H0[0d]
08/03 12:53:08 yd2  waiting for ``OK'' ** found **
08/03 12:53:08 yd2  send: ATS0=0Q0&D3&C1[0d]
08/03 12:53:08 yd2  waiting for ``OK'' ** found **
08/03 12:53:08 yd2  mdm_send: 'ATI'
08/03 12:53:08 yd2  USR Courier/Sportster V.34(+) detected
08/03 12:53:08 yd2  mdm_send: 'ATI3'
08/03 12:53:09 yd2  additional info: 'USRobotics Sportster Voice 33600 Fax RS Rev. 2.0'
08/03 12:53:09 yd2  mdm_send: 'AT+FCLASS=2.0' -> OK
08/03 12:53:09 yd2  mdm_send: 'AT+FAA=1;+FCR=1' -> OK
08/03 12:53:09 yd2  mdm_send: 'AT+FBO=1' -> OK
08/03 12:53:09 yd2  mdm_send: 'AT+FNR=1,1,1,0' -> OK
08/03 12:53:09 yd2  mdm_send: 'AT+FLI="+1.978.957.9886"' -> OK
08/03 12:53:10 yd2  mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0' -> OK
08/03 12:53:10 yd2  detecting voice modem type
08/03 12:53:11 yd2  US Robotics detected
08/03 12:53:13 yd2  US Robotics voice modem
08/03 12:53:13 yd2  This is a driver beta version. V0.4.b3
08/03 12:53:13 yd2  VTD setup successful
08/03 12:53:14 yd2  vgetty: Modem returned ERROR
08/03 12:53:14 yd2  setting ringback delay didn't work
08/03 12:53:15 yd2  waiting...
08/03 13:05:53 yd2  wfr: waiting for ``RING''
08/03 13:05:53 yd2  wfr: waiting for ``RING''
08/03 13:05:59 yd2  wfr: waiting for ``RING''
08/03 13:06:05 yd2  reading ring_type ring configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 13:06:06 yd2  playing voice file /var/spool/voice/messages/standard.rmd
> The following is correct. I sent a -HUP signal once I heard the message and
> knew it worked
08/03 13:06:21 ##### hangup requested, name='', caller=none, dev=ttyd2, pid=255

08/03 13:06:22 yd2  closing voice modem device


> Here I change call_program to be my application/script
>
--
08/03 13:06:45 yd2  vgetty: experimental test release 0.9.4 / 20Jul99
08/03 13:06:45 yd2  mgetty: experimental test release 1.1.21-Jul24
08/03 13:06:45 yd2  reading generic configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 13:06:45 yd2  reading program vgetty configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 13:06:45 yd2  reading port ttyd2 configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 13:06:45 yd2  check for lockfiles
08/03 13:06:45 yd2  locking the line
08/03 13:06:48 yd2  lowering DTR to reset Modem
08/03 13:06:49 yd2  send: \dATQ0V1H0[0d]
08/03 13:06:49 yd2  waiting for ``OK'' ** found **
08/03 13:06:49 yd2  send: ATS0=0Q0&D3&C1[0d]
08/03 13:06:49 yd2  waiting for ``OK'' ** found **
08/03 13:06:50 yd2  mdm_send: 'ATI'
08/03 13:06:50 yd2  USR Courier/Sportster V.34(+) detected
08/03 13:06:50 yd2  mdm_send: 'ATI3'
08/03 13:06:50 yd2  additional info: 'USRobotics Sportster Voice 33600 Fax RS Rev. 2.0'
08/03 13:06:50 yd2  mdm_send: 'AT+FCLASS=2.0' -> OK
08/03 13:06:50 yd2  mdm_send: 'AT+FAA=1;+FCR=1' -> OK
08/03 13:06:50 yd2  mdm_send: 'AT+FBO=1' -> OK
08/03 13:06:51 yd2  mdm_send: 'AT+FNR=1,1,1,0' -> OK
08/03 13:06:51 yd2  mdm_send: 'AT+FLI="+1.978.957.9886"' -> OK
08/03 13:06:51 yd2  mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0' -> OK
08/03 13:06:51 yd2  detecting voice modem type
08/03 13:06:53 yd2  US Robotics detected
08/03 13:06:54 yd2  US Robotics voice modem
08/03 13:06:54 yd2  This is a driver beta version. V0.4.b3
08/03 13:06:54 yd2  VTD setup successful
08/03 13:06:55 yd2  vgetty: Modem returned ERROR
08/03 13:06:55 yd2  setting ringback delay didn't work
08/03 13:06:56 yd2  waiting...
08/03 13:06:59 yd2  wfr: waiting for ``RING''
08/03 13:06:59 yd2  wfr: waiting for ``RING''
08/03 13:07:05 yd2  wfr: waiting for ``RING''

> Here is where it bombs. Note, its the exact same file as played above, so
> I don't think its the RMD file that is causing it.

08/03 13:07:11 yd2  reading ring_type ring configuration from config file /usr/local/etc/mgetty+sendfax/voice.conf
08/03 13:07:12 yd2  vgetty: Executing shell script /var/spool/voice/bin/calltree with shell /usr/local/bin/bash
08/03 13:07:13 yd2  playing voice file /var/spool/voice/messages/standard.rmd
08/03 13:07:13 yd2  vgetty: Invalid modem answer
08/03 13:07:13 yd2  vgetty: start_play_file command failed
08/03 13:07:13 yd2  vgetty: Modem returned ERROR
08/03 13:07:13 yd2  vgetty: Modem returned ERROR
08/03 13:07:13 yd2  closing voice modem device



To also give a slightly different perspective, here is the output I see
from my application, also with my occational comment. The lines that
start as Receiving: are the ones gotten from the API. The ones starting with
Sending: is what is sent to the API. Other messages are the application
just letting you know what its attempting to do.

Aug  3 13:07:12 www calltree.app: Current Directory is /var/spool/voice 
Aug  3 13:07:12 www calltree.app: Receiving: HELLO SHELL 
Aug  3 13:07:12 www calltree.app: Sending: HELLO VOICE PROGRAM  
Aug  3 13:07:13 www calltree.app: Receiving: READY 
Aug  3 13:07:13 www calltree.app: Executing CHDR to /var/spool/voice/messages 
Aug  3 13:07:13 www calltree.app: Executing PLAY: standard.rmd 
Aug  3 13:07:13 www calltree.app: We have been asked to play file standard.rmd 
Aug  3 13:07:13 www calltree.app: Sending: AUTOSTOP ON  
Aug  3 13:07:13 www calltree.app: Receiving: READY 
Aug  3 13:07:13 www calltree.app: Sending: ENABLE EVENTS  
Aug  3 13:07:13 www calltree.app: Receiving: READY 
Aug  3 13:07:13 www calltree.app: Sending: PLAY /var/spool/voice/messages/standard.rmd  
Aug  3 13:07:13 www calltree.app: Receiving: PLAYING 
>> Here is where it appears to die for no obvious reason.
Aug  3 13:07:13 www calltree.app: Receiving: ERROR 
Aug  3 13:07:13 www calltree.app: Receiving: READY 
>> On error, we exit with an error code of 0 (hang up) after saying goodbye to
>> the API.
Aug  3 13:07:13 www calltree.app: Executing HNGP: 0 
Aug  3 13:07:13 www calltree.app: Sending: GOODBYE  
Aug  3 13:07:13 www calltree.app: Receiving: GOODBYE SHELL 


If anyone wants code snippets, config files or the like, please let me know. I
didn't send them along with this due to the length of the log files, and
the fact I don't think they're relevant, as it works in answering machine mode,
and not with my program, and the only difference in the config files is the
call_program line :)

	-Brian