jdaniels
2006-03-14 18:13:03 UTC
Hi,
I have a BT FaxModem 56k running on a Redhat Enterprise Linux 3 (Update
4) server, com port /dev/cua0, using mgetty-sendfax v.1.1.21-5 and
vgetty in mgetty-voice-1.1.21-5. I am attempting to do the following:
1) Dial out using a script running in the vm shell
2) Connect to any phone line
3) Record the voice heard from that line into a .RMD file
4) Terminate call.
This works in general, but the problem is that the RMD file that is
recorded contains only static, although the modem speaker plays the
sound correctly. Other RMD files played using the same media player
(Cool Edit 2000) sound as normal.
The following script is what is being used to make the call and capture
the recording:
$ ./record.sh 02079999999 MyRecordedFile.rmd
=========================================================
#! /usr/bin/vm shell
#
# Define the function to receive an answer from the voice library
# but do not read data for longer than 60 seconds. This is due
# to not being able to detect an engaged tone during recording.
#
function receive
{
read -r INPUT <&$VOICE_INPUT;
echo "$INPUT";
}
#
# Define the function to send a command to the voice library
#
function send
{
echo $1 >&$VOICE_OUTPUT;
kill -PIPE $VOICE_PID
}
#
# Check command line options
#
if [ $# -ne 2 ]; then
echo "usage: $0 <phone_number> <filename>" >&2
exit 99
fi
#
# Let's see if the voice library is talking to us
#
ANSWER=`receive`
if [ "$ANSWER" != "HELLO SHELL" ]; then
kill -KILL $$
fi
send "HELLO VOICE PROGRAM"
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
kill -KILL $$
fi
#
# Enable events
#
send "ENABLE EVENTS"
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
kill -KILL $$
fi
#
# Start dialout
#
send "DIAL $1"
ANSWER=`receive`
if [ "$ANSWER" != "DIALING" ]; then
kill -KILL $$
fi
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
echo "ERROR: Got $ANSWER instead of READY after dialing "
exit 99
fi
#
# Just wait for a second. We can't determine when a voice pickup is
made (Blame IS-101).
#
sleep 1
#
# Now record what happens into the filename supplied
#
send "RECORD $2"
ANSWER=`receive`
if [ "$ANSWER" != "RECORDING" ]; then
kill -KILL $$
fi
#
# Its a bit odd, I know, but this loop seems to do the job.. even if
very crudely.
# Watch out for the infinite engaged tone. You may have to have an
external program
# monitoring the size of the file that this one produces.
#
send "STOP"
ANSWER=`receive`
#
# Enable events coz annoyingly STOP disables them
#
send "ENABLE EVENTS"
ANSWER=`receive`
#
# Now we can say goodbye
#
send "GOODBYE"
ANSWER=`receive`
if [ "$ANSWER" != "GOODBYE SHELL" ]; then
kill -KILL $$
fi
exit 0
=========================================================
So that basically works en-to-end. As I say, the recorded RMD is just
static however. I have included the log (logging level 6, apologies for
the length)
=========================================================
03/14 18:03:25 vgetty: experimental test release 0.9.4 / 20Jul99
03/14 18:03:25 reading program vm configuration from config file
/etc/mgetty+sendfax/voice.conf
03/14 18:03:25 reading /etc/mgetty+sendfax/voice.conf...
03/14 18:03:25 conf lib: read: 'part generic'
03/14 18:03:25 found CT_KEYWORD part generic
03/14 18:03:25 conf lib: read: 'voice_log_level 6'
03/14 18:03:25 conf lib: read: 'voice_dir /var/spool/voice'
03/14 18:03:25 conf lib: read: 'phone_owner root'
03/14 18:03:25 conf lib: read: 'phone_group phone'
03/14 18:03:25 conf lib: read: 'phone_mode 0660'
03/14 18:03:25 conf lib: read: 'message_flag_file .flag'
03/14 18:03:25 conf lib: read: 'receive_dir incoming'
03/14 18:03:25 conf lib: read: 'message_dir messages'
03/14 18:03:25 conf lib: read: 'message_list Index'
03/14 18:03:25 conf lib: read: 'backup_message standard.rmd'
03/14 18:03:25 conf lib: read: 'port_speed 115200'
03/14 18:03:25 conf lib: read: 'voice_shell /bin/sh'
03/14 18:03:25 conf lib: read: 'port_timeout 10'
03/14 18:03:25 conf lib: read: 'dial_timeout 90'
03/14 18:03:25 conf lib: read: 'command_delay 100'
03/14 18:03:25 conf lib: read: 'dtmf_len 30'
03/14 18:03:25 conf lib: read: 'dtmf_threshold 40'
03/14 18:03:25 conf lib: read: 'dtmf_wait 7'
03/14 18:03:25 conf lib: read: 'ignore_fax_dle false'
03/14 18:03:25 conf lib: read: 'raw_data false'
03/14 18:03:25 conf lib: read: 'rec_compression 0'
03/14 18:03:25 conf lib: read: 'rec_speed 0'
03/14 18:03:25 conf lib: read: 'rec_silence_len 70'
03/14 18:03:25 conf lib: read: 'rec_silence_threshold 40'
03/14 18:03:25 conf lib: read: 'rec_remove_silence false'
03/14 18:03:25 conf lib: read: 'rec_max_len 300'
03/14 18:03:25 conf lib: read: 'rec_min_len 0'
03/14 18:03:25 conf lib: read: 'do_hard_flow true'
03/14 18:03:25 conf lib: read: 'beep_frequency 933'
03/14 18:03:25 conf lib: read: 'beep_length 1500'
03/14 18:03:25 conf lib: read: 'max_tries 3'
03/14 18:03:25 conf lib: read: 'retry_delay 5'
03/14 18:03:25 conf lib: read: 'watchdog_timeout 60'
03/14 18:03:25 conf lib: read: 'receive_gain -1'
03/14 18:03:25 conf lib: read: 'transmit_gain -1'
03/14 18:03:25 conf lib: read: 'enable_command_echo true'
03/14 18:03:25 conf lib: read: 'poll_interval 10'
03/14 18:03:25 conf lib: read: 'program vgetty'
03/14 18:03:25 section: program vgetty, ignore
03/14 18:03:25 conf lib: read: 'rings 3'
03/14 18:03:25 conf lib: read: 'answer_mode voice:fax:data'
03/14 18:03:25 conf lib: read: 'force_autodetect false'
03/14 18:03:25 conf lib: read: 'toll_saver_rings 0'
03/14 18:03:25 conf lib: read: 'rec_always_keep true'
03/14 18:03:25 conf lib: read: 'button_program '
03/14 18:03:25 conf lib: read: 'call_program '
03/14 18:03:25 conf lib: read: 'dtmf_program dtmf.sh'
03/14 18:03:25 conf lib: read: 'message_program '
03/14 18:03:25 conf lib: read: 'do_message_light false'
03/14 18:03:25 conf lib: read: 'program vm'
03/14 18:03:25 section: program vm, **found**
03/14 18:03:25 conf lib: read: 'voice_devices cua0'
03/14 18:03:25 conf lib: read: 'dialout_timeout 90'
03/14 18:03:25 conf lib: read: 'ringback_goes_away 70'
03/14 18:03:25 conf lib: read: 'ringback_never_came 100'
03/14 18:03:25 conf lib: read: 'program pvf'
03/14 18:03:25 section: program pvf, ignore
03/14 18:03:25 conf lib: read: 'port cua0'
03/14 18:03:25 conf lib: read: 'port ttyS5'
03/14 18:03:25 conf lib: read: 'ring_type virtual'
03/14 18:03:25 conf lib: read: 'answer_mode fax:data'
03/14 18:03:25 conf lib: read: 'ring_type ring'
03/14 18:03:25 conf lib: read: 'ring_type ring1'
03/14 18:03:25 key: 'part', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'program', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'port', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'ring_type', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'voice_log_level', type=0, flags=3, data=6
03/14 18:03:25 key: 'voice_shell', type=1, flags=3, data=/bin/sh
03/14 18:03:25 key: 'port_speed', type=0, flags=3, data=115200
03/14 18:03:25 key: 'port_timeout', type=0, flags=3, data=10
03/14 18:03:25 key: 'dial_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'command_delay', type=0, flags=3, data=100
03/14 18:03:25 key: 'dtmf_len', type=0, flags=3, data=30
03/14 18:03:25 key: 'dtmf_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'dtmf_wait', type=0, flags=3, data=7
03/14 18:03:25 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'raw_data', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_compression', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_speed', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_silence_len', type=0, flags=3, data=70
03/14 18:03:25 key: 'rec_silence_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_max_len', type=0, flags=3, data=300
03/14 18:03:25 key: 'rec_min_len', type=0, flags=3, data=0
03/14 18:03:25 key: 'do_hard_flow', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'force_autodetect', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'watchdog_timeout', type=0, flags=3, data=60
03/14 18:03:25 key: 'receive_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'transmit_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'enable_command_echo', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'poll_interval', type=0, flags=3, data=10
03/14 18:03:25 key: 'rings', type=1, flags=1, data=3
03/14 18:03:25 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
03/14 18:03:25 key: 'toll_saver_rings', type=0, flags=1, data=0
03/14 18:03:25 key: 'rec_always_keep', type=3, flags=1, data=TRUE
03/14 18:03:25 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
03/14 18:03:25 key: 'phone_owner', type=1, flags=3, data=root
03/14 18:03:25 key: 'phone_group', type=1, flags=3, data=phone
03/14 18:03:25 key: 'phone_mode', type=0, flags=3, data=432
03/14 18:03:25 key: 'message_flag_file', type=1, flags=3, data=.flag
03/14 18:03:25 key: 'receive_dir', type=1, flags=3, data=incoming
03/14 18:03:25 key: 'message_dir', type=1, flags=3, data=messages
03/14 18:03:25 key: 'message_list', type=1, flags=3, data=Index
03/14 18:03:25 key: 'backup_message', type=1, flags=3,
data=standard.rmd
03/14 18:03:25 key: 'button_program', type=1, flags=1, data=
03/14 18:03:25 key: 'call_program', type=1, flags=1, data=
03/14 18:03:25 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
03/14 18:03:25 key: 'message_program', type=1, flags=1, data=
03/14 18:03:25 key: 'do_message_light', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'beep_frequency', type=0, flags=3, data=933
03/14 18:03:25 key: 'beep_length', type=0, flags=3, data=1500
03/14 18:03:25 key: 'max_tries', type=0, flags=3, data=3
03/14 18:03:25 key: 'retry_delay', type=0, flags=3, data=5
03/14 18:03:25 key: 'dialout_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'ringback_goes_away', type=0, flags=3, data=70
03/14 18:03:25 key: 'ringback_never_came', type=0, flags=3, data=100
03/14 18:03:25 key: 'voice_devices', type=1, flags=3, data=cua0
03/14 18:03:25 opening voice modem device
03/14 18:03:25 voice open 'cua0'
03/14 18:03:25 trying device '/dev/cua0'
03/14 18:03:25 makelock(cua0) called
03/14 18:03:25 do_makelock: lock='/var/lock/LCK..cua0'
03/14 18:03:25 stale lockfile, created by process 8428, ignoring
03/14 18:03:25 lock made
03/14 18:03:25 opened voice modem device /dev/cua0
03/14 18:03:25 reading port cua0 configuration from config file
/etc/mgetty+sendfax/voice.conf
03/14 18:03:25 reading /etc/mgetty+sendfax/voice.conf...
03/14 18:03:25 conf lib: read: 'part generic'
03/14 18:03:25 found CT_KEYWORD part generic
03/14 18:03:25 conf lib: read: 'voice_log_level 6'
03/14 18:03:25 conf lib: read: 'voice_dir /var/spool/voice'
03/14 18:03:25 conf lib: read: 'phone_owner root'
03/14 18:03:25 conf lib: read: 'phone_group phone'
03/14 18:03:25 conf lib: read: 'phone_mode 0660'
03/14 18:03:25 conf lib: read: 'message_flag_file .flag'
03/14 18:03:25 conf lib: read: 'receive_dir incoming'
03/14 18:03:25 conf lib: read: 'message_dir messages'
03/14 18:03:25 conf lib: read: 'message_list Index'
03/14 18:03:25 conf lib: read: 'backup_message standard.rmd'
03/14 18:03:25 conf lib: read: 'port_speed 115200'
03/14 18:03:25 conf lib: read: 'voice_shell /bin/sh'
03/14 18:03:25 conf lib: read: 'port_timeout 10'
03/14 18:03:25 conf lib: read: 'dial_timeout 90'
03/14 18:03:25 conf lib: read: 'command_delay 100'
03/14 18:03:25 conf lib: read: 'dtmf_len 30'
03/14 18:03:25 conf lib: read: 'dtmf_threshold 40'
03/14 18:03:25 conf lib: read: 'dtmf_wait 7'
03/14 18:03:25 conf lib: read: 'ignore_fax_dle false'
03/14 18:03:25 conf lib: read: 'raw_data false'
03/14 18:03:25 conf lib: read: 'rec_compression 0'
03/14 18:03:25 conf lib: read: 'rec_speed 0'
03/14 18:03:25 conf lib: read: 'rec_silence_len 70'
03/14 18:03:25 conf lib: read: 'rec_silence_threshold 40'
03/14 18:03:25 conf lib: read: 'rec_remove_silence false'
03/14 18:03:25 conf lib: read: 'rec_max_len 300'
03/14 18:03:25 conf lib: read: 'rec_min_len 0'
03/14 18:03:25 conf lib: read: 'do_hard_flow true'
03/14 18:03:25 conf lib: read: 'beep_frequency 933'
03/14 18:03:25 conf lib: read: 'beep_length 1500'
03/14 18:03:25 conf lib: read: 'max_tries 3'
03/14 18:03:25 conf lib: read: 'retry_delay 5'
03/14 18:03:25 conf lib: read: 'watchdog_timeout 60'
03/14 18:03:25 conf lib: read: 'receive_gain -1'
03/14 18:03:25 conf lib: read: 'transmit_gain -1'
03/14 18:03:25 conf lib: read: 'enable_command_echo true'
03/14 18:03:25 conf lib: read: 'poll_interval 10'
03/14 18:03:25 conf lib: read: 'program vgetty'
03/14 18:03:25 conf lib: read: 'rings 3'
03/14 18:03:25 conf lib: read: 'answer_mode voice:fax:data'
03/14 18:03:25 conf lib: read: 'force_autodetect false'
03/14 18:03:25 conf lib: read: 'toll_saver_rings 0'
03/14 18:03:25 conf lib: read: 'rec_always_keep true'
03/14 18:03:25 conf lib: read: 'button_program '
03/14 18:03:25 conf lib: read: 'call_program '
03/14 18:03:25 conf lib: read: 'dtmf_program dtmf.sh'
03/14 18:03:25 conf lib: read: 'message_program '
03/14 18:03:25 conf lib: read: 'do_message_light false'
03/14 18:03:25 conf lib: read: 'program vm'
03/14 18:03:25 conf lib: read: 'voice_devices cua0'
03/14 18:03:25 conf lib: read: 'dialout_timeout 90'
03/14 18:03:25 conf lib: read: 'ringback_goes_away 70'
03/14 18:03:25 conf lib: read: 'ringback_never_came 100'
03/14 18:03:25 conf lib: read: 'program pvf'
03/14 18:03:25 conf lib: read: 'port cua0'
03/14 18:03:25 section: port cua0, **found**
03/14 18:03:25 conf lib: read: 'port ttyS5'
03/14 18:03:25 section: port ttyS5, ignore
03/14 18:03:25 conf lib: read: 'ring_type virtual'
03/14 18:03:25 conf lib: read: 'answer_mode fax:data'
03/14 18:03:25 conf lib: read: 'ring_type ring'
03/14 18:03:25 conf lib: read: 'ring_type ring1'
03/14 18:03:25 key: 'part', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'program', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'port', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'ring_type', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'voice_log_level', type=0, flags=3, data=6
03/14 18:03:25 key: 'voice_shell', type=1, flags=3, data=/bin/sh
03/14 18:03:25 key: 'port_speed', type=0, flags=3, data=115200
03/14 18:03:25 key: 'port_timeout', type=0, flags=3, data=10
03/14 18:03:25 key: 'dial_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'command_delay', type=0, flags=3, data=100
03/14 18:03:25 key: 'dtmf_len', type=0, flags=3, data=30
03/14 18:03:25 key: 'dtmf_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'dtmf_wait', type=0, flags=3, data=7
03/14 18:03:25 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'raw_data', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_compression', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_speed', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_silence_len', type=0, flags=3, data=70
03/14 18:03:25 key: 'rec_silence_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_max_len', type=0, flags=3, data=300
03/14 18:03:25 key: 'rec_min_len', type=0, flags=3, data=0
03/14 18:03:25 key: 'do_hard_flow', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'force_autodetect', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'watchdog_timeout', type=0, flags=3, data=60
03/14 18:03:25 key: 'receive_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'transmit_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'enable_command_echo', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'poll_interval', type=0, flags=3, data=10
03/14 18:03:25 key: 'rings', type=1, flags=1, data=3
03/14 18:03:25 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
03/14 18:03:25 key: 'toll_saver_rings', type=0, flags=1, data=0
03/14 18:03:25 key: 'rec_always_keep', type=3, flags=1, data=TRUE
03/14 18:03:25 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
03/14 18:03:25 key: 'phone_owner', type=1, flags=3, data=root
03/14 18:03:25 key: 'phone_group', type=1, flags=3, data=phone
03/14 18:03:25 key: 'phone_mode', type=0, flags=3, data=432
03/14 18:03:25 key: 'message_flag_file', type=1, flags=3, data=.flag
03/14 18:03:25 key: 'receive_dir', type=1, flags=3, data=incoming
03/14 18:03:25 key: 'message_dir', type=1, flags=3, data=messages
03/14 18:03:25 key: 'message_list', type=1, flags=3, data=Index
03/14 18:03:25 key: 'backup_message', type=1, flags=3,
data=standard.rmd
03/14 18:03:25 key: 'button_program', type=1, flags=1, data=
03/14 18:03:25 key: 'call_program', type=1, flags=1, data=
03/14 18:03:25 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
03/14 18:03:25 key: 'message_program', type=1, flags=1, data=
03/14 18:03:25 key: 'do_message_light', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'beep_frequency', type=0, flags=3, data=933
03/14 18:03:25 key: 'beep_length', type=0, flags=3, data=1500
03/14 18:03:25 key: 'max_tries', type=0, flags=3, data=3
03/14 18:03:25 key: 'retry_delay', type=0, flags=3, data=5
03/14 18:03:25 key: 'dialout_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'ringback_goes_away', type=0, flags=3, data=70
03/14 18:03:25 key: 'ringback_never_came', type=0, flags=3, data=100
03/14 18:03:25 key: 'voice_devices', type=1, flags=3, data=cua0
03/14 18:03:25 tss: set speed to 115200 (10002)
03/14 18:03:25 tio_set_flow_control( HARD )
03/14 18:03:25 detecting voice modem type
03/14 18:03:25 vm: ATE1
03/14 18:03:25 voice command: '' -> 'OK|ATE1'
03/14 18:03:25 serial port: ATE1
03/14 18:03:25 serial port: OK
03/14 18:03:25 voice command: 'ATI9' -> ''
03/14 18:03:26 vm: ATI9
03/14 18:03:26 serial port: ATI9
03/14 18:03:26 serial port: ERROR
03/14 18:03:26 voice command: 'ATI' -> ''
03/14 18:03:26 vm: ATI
03/14 18:03:26 serial port: ATI
03/14 18:03:26 serial port: 56000
03/14 18:03:26 Rockwell: OK
03/14 18:03:26 Rockwell detected
03/14 18:03:26 vm: entering voice mode
03/14 18:03:26 vm: Installing signal handlers
03/14 18:03:26 voice command: 'AT#CLS?' -> ''
03/14 18:03:26 vm: AT#CLS?
03/14 18:03:26 Rockwell: AT#CLS?
03/14 18:03:26 Rockwell: 0
03/14 18:03:26 voice command: '' -> 'OK'
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#CLS=8' -> 'OK'
03/14 18:03:27 vm: AT#CLS=8
03/14 18:03:27 Rockwell: AT#CLS=8
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT' -> 'OK'
03/14 18:03:27 vm: AT
03/14 18:03:27 Rockwell: <DLE> <h>
03/14 18:03:27 vm: queued event HANDSET_ON_HOOK at position 0000
03/14 18:03:27 Rockwell:
03/14 18:03:27 Rockwell: AT
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 vm: queued event RESET_WATCHDOG at position 0001
03/14 18:03:27 initializing ROCKWELL voice modem
03/14 18:03:27 voice command: 'AT#VSP=70' -> 'OK'
03/14 18:03:27 vm: AT#VSP=70
03/14 18:03:27 vm: unqueued event HANDSET_ON_HOOK at position 0000
03/14 18:03:27 vm: voice_handle_event got event HANDSET_ON_HOOK with
data <0>
03/14 18:03:27 vm: unqueued event RESET_WATCHDOG at position 0001
03/14 18:03:27 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:27 Rockwell: AT#VSP=70
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VSD=0' -> 'OK'
03/14 18:03:27 vm: AT#VSD=0
03/14 18:03:27 Rockwell: AT#VSD=0
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
03/14 18:03:27 vm: AT#VTD=3F,3F,3F
03/14 18:03:27 Rockwell: AT#VTD=3F,3F,3F
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VSS=1' -> 'OK'
03/14 18:03:27 vm: AT#VSS=1
03/14 18:03:27 Rockwell: AT#VSS=1
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT&K3' -> 'OK'
03/14 18:03:27 vm: AT&K3
03/14 18:03:27 Rockwell: AT&K3
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 tio_set_flow_control( HARD )
03/14 18:03:27 vm: leaving voice mode
03/14 18:03:27 voice command: 'AT#CLS=0' -> 'OK'
03/14 18:03:28 vm: AT#CLS=0
03/14 18:03:28 Rockwell: AT#CLS=0
03/14 18:03:28 Rockwell: OK
03/14 18:03:28 voice command: 'AT' -> 'OK'
03/14 18:03:28 vm: AT
03/14 18:03:28 Rockwell: AT
03/14 18:03:28 Rockwell: OK
03/14 18:03:28 vm: Restoring signal handlers
03/14 18:03:28 vm: entering voice mode
03/14 18:03:28 vm: Installing signal handlers
03/14 18:03:28 voice command: 'AT#CLS?' -> ''
03/14 18:03:28 vm: AT#CLS?
03/14 18:03:28 Rockwell: AT#CLS?
03/14 18:03:28 Rockwell: 0
03/14 18:03:28 voice command: '' -> 'OK'
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 voice command: 'AT#CLS=8' -> 'OK'
03/14 18:03:29 vm: AT#CLS=8
03/14 18:03:29 Rockwell: AT#CLS=8
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 voice command: 'AT' -> 'OK'
03/14 18:03:29 vm: AT
03/14 18:03:29 Rockwell: <DLE> <h>
03/14 18:03:29 vm: queued event HANDSET_ON_HOOK at position 0002
03/14 18:03:29 Rockwell:
03/14 18:03:29 Rockwell: AT
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 vm: Executing shell script ./record.sh with shell
/bin/sh
03/14 18:03:29 vm: opening pipes
03/14 18:03:29 vm: forking shell
03/14 18:03:29 vm(0): HELLO SHELL
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0003
03/14 18:03:29 vm: unqueued event HANDSET_ON_HOOK at position 0002
03/14 18:03:29 vm: voice_handle_event got event HANDSET_ON_HOOK with
data <_>
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0003
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): HELLO VOICE PROGRAM
03/14 18:03:29 vm(1): READY
03/14 18:03:29 vm: initialized communication
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0004
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0004
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): ENABLE EVENTS
03/14 18:03:29 vm(1): READY
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0005
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0005
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): DIAL 02079999999
03/14 18:03:29 vm(1): DIALING
03/14 18:03:29 vm: queued event RESET_WATCHDOG at position 0006
03/14 18:03:29 vm: ATD07810880071
03/14 18:03:29 vm: unqueued event RESET_WATCHDOG at position 0006
03/14 18:03:29 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:29 Rockwell: ATD02079999999
03/14 18:03:29 vm: queued event RESET_WATCHDOG at position 0007
03/14 18:03:29 vm: unqueued event RESET_WATCHDOG at position 0007
03/14 18:03:29 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:55 Rockwell: VCON
03/14 18:03:55 vm(1): READY
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0008
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0008
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:56 shell(1): RECORD test_data_new.rmd
03/14 18:03:56 vm(1): RECORDING
03/14 18:03:56 recording voice file test_data_new.rmd
03/14 18:03:56 vm: queued event RESET_WATCHDOG at position 0009
03/14 18:03:56 voice command: 'AT#VBS=2' -> 'OK'
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0010
03/14 18:03:56 vm: AT#VBS=2
03/14 18:03:56 vm: unqueued event RESET_WATCHDOG at position 0009
03/14 18:03:56 vm: voice_handle_event got event RESET_WATCHDOG with
data <P>
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0010
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <_>
03/14 18:03:56 shell(2): STOP
03/14 18:03:56 vm: STOP during IDLE
03/14 18:03:56 vm(2): READY
03/14 18:03:56 Rockwell:
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position
0011AT#VBS=2
03/14 18:03:56 Rockwell: OK
03/14 18:03:56 vm: queued event RESET_WATCHDOG at position 0012
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0011
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <_>
03/14 18:03:56 shell(2): ENABLE EVENTS
03/14 18:03:56 vm: Nested command in shell script
03/14 18:03:56 vm(2): ERROR
03/14 18:03:56 vm: unqueued event RESET_WATCHDOG at position 0012
03/14 18:03:56 vm: voice_handle_event got event RESET_WATCHDOG with
data <P>
03/14 18:03:56 voice command: 'AT&K3' -> 'OK'
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0013
03/14 18:03:56 vm: AT&K3
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0013
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <P>
03/14 18:03:56 shell(2): GOODBYE
03/14 18:03:56 vm: Nested command in shell script
03/14 18:03:56 vm(2): ERROR
03/14 18:03:56 Rockwell:
03/14 18:03:56 vm: Got child changed status signal
03/14 18:03:56 vm: queued event SIGNAL_SIGCHLD at position 0014AT&K3
03/14 18:03:56 Rockwell: OK
03/14 18:03:56 tio_set_flow_control( HARD XON_IN )
03/14 18:03:56 voice command: 'AT#VRX' -> 'CONNECT'
03/14 18:03:56 vm: AT#VRX
03/14 18:03:56 vm: unqueued event SIGNAL_SIGCHLD at position 0014
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGCHLD with
data <P>
03/14 18:03:56 vm: <STOP RECORDING>
03/14 18:03:56 Rockwell: AT#VRX!
03/14 18:03:56 Rockwell: CONNECT
03/14 18:04:05 Rockwell: <DLE> <q>
03/14 18:04:05 vm: queued event SILENCE_DETECTED at position 0015
03/14 18:04:05 vm: unqueued event SILENCE_DETECTED at position 0015
03/14 18:04:05 vm: voice_handle_event got event SILENCE_DETECTED
with data <P>
03/14 18:04:05 vm: <STOP RECORDING>
03/14 18:04:05 Rockwell: <VOICE DATA 16283 bytes>
03/14 18:04:05 Rockwell: <DLE> <ETX>
03/14 18:04:05 voice command: '' -> 'OK|VCON'
03/14 18:04:05 Rockwell: VCON
03/14 18:04:05 vm(1): READY
03/14 18:04:05 vm: Got pipe signal
03/14 18:04:05 vm: queued event SIGNAL_SIGPIPE at position 0016
03/14 18:04:05 vm: could not write to shell
03/14 18:04:05 vm: Could not handle event, something failed
=========================================================
As you can see, 'something' failed as vm could not write to shell.
Everything involved is running as root and is owned by root and is
writable by root. Any thoughts as to how I can find out what failed, or
alternatively, any experience with a similar issue?
The modem has incidentaly been in production use as a fax gateway until
about 3 weeks ago on a Win2k Server.
Thanks in adv.,
Jon D
I have a BT FaxModem 56k running on a Redhat Enterprise Linux 3 (Update
4) server, com port /dev/cua0, using mgetty-sendfax v.1.1.21-5 and
vgetty in mgetty-voice-1.1.21-5. I am attempting to do the following:
1) Dial out using a script running in the vm shell
2) Connect to any phone line
3) Record the voice heard from that line into a .RMD file
4) Terminate call.
This works in general, but the problem is that the RMD file that is
recorded contains only static, although the modem speaker plays the
sound correctly. Other RMD files played using the same media player
(Cool Edit 2000) sound as normal.
The following script is what is being used to make the call and capture
the recording:
$ ./record.sh 02079999999 MyRecordedFile.rmd
=========================================================
#! /usr/bin/vm shell
#
# Define the function to receive an answer from the voice library
# but do not read data for longer than 60 seconds. This is due
# to not being able to detect an engaged tone during recording.
#
function receive
{
read -r INPUT <&$VOICE_INPUT;
echo "$INPUT";
}
#
# Define the function to send a command to the voice library
#
function send
{
echo $1 >&$VOICE_OUTPUT;
kill -PIPE $VOICE_PID
}
#
# Check command line options
#
if [ $# -ne 2 ]; then
echo "usage: $0 <phone_number> <filename>" >&2
exit 99
fi
#
# Let's see if the voice library is talking to us
#
ANSWER=`receive`
if [ "$ANSWER" != "HELLO SHELL" ]; then
kill -KILL $$
fi
send "HELLO VOICE PROGRAM"
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
kill -KILL $$
fi
#
# Enable events
#
send "ENABLE EVENTS"
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
kill -KILL $$
fi
#
# Start dialout
#
send "DIAL $1"
ANSWER=`receive`
if [ "$ANSWER" != "DIALING" ]; then
kill -KILL $$
fi
ANSWER=`receive`
if [ "$ANSWER" != "READY" ]; then
echo "ERROR: Got $ANSWER instead of READY after dialing "
exit 99
fi
#
# Just wait for a second. We can't determine when a voice pickup is
made (Blame IS-101).
#
sleep 1
#
# Now record what happens into the filename supplied
#
send "RECORD $2"
ANSWER=`receive`
if [ "$ANSWER" != "RECORDING" ]; then
kill -KILL $$
fi
#
# Its a bit odd, I know, but this loop seems to do the job.. even if
very crudely.
# Watch out for the infinite engaged tone. You may have to have an
external program
# monitoring the size of the file that this one produces.
#
send "STOP"
ANSWER=`receive`
#
# Enable events coz annoyingly STOP disables them
#
send "ENABLE EVENTS"
ANSWER=`receive`
#
# Now we can say goodbye
#
send "GOODBYE"
ANSWER=`receive`
if [ "$ANSWER" != "GOODBYE SHELL" ]; then
kill -KILL $$
fi
exit 0
=========================================================
So that basically works en-to-end. As I say, the recorded RMD is just
static however. I have included the log (logging level 6, apologies for
the length)
=========================================================
03/14 18:03:25 vgetty: experimental test release 0.9.4 / 20Jul99
03/14 18:03:25 reading program vm configuration from config file
/etc/mgetty+sendfax/voice.conf
03/14 18:03:25 reading /etc/mgetty+sendfax/voice.conf...
03/14 18:03:25 conf lib: read: 'part generic'
03/14 18:03:25 found CT_KEYWORD part generic
03/14 18:03:25 conf lib: read: 'voice_log_level 6'
03/14 18:03:25 conf lib: read: 'voice_dir /var/spool/voice'
03/14 18:03:25 conf lib: read: 'phone_owner root'
03/14 18:03:25 conf lib: read: 'phone_group phone'
03/14 18:03:25 conf lib: read: 'phone_mode 0660'
03/14 18:03:25 conf lib: read: 'message_flag_file .flag'
03/14 18:03:25 conf lib: read: 'receive_dir incoming'
03/14 18:03:25 conf lib: read: 'message_dir messages'
03/14 18:03:25 conf lib: read: 'message_list Index'
03/14 18:03:25 conf lib: read: 'backup_message standard.rmd'
03/14 18:03:25 conf lib: read: 'port_speed 115200'
03/14 18:03:25 conf lib: read: 'voice_shell /bin/sh'
03/14 18:03:25 conf lib: read: 'port_timeout 10'
03/14 18:03:25 conf lib: read: 'dial_timeout 90'
03/14 18:03:25 conf lib: read: 'command_delay 100'
03/14 18:03:25 conf lib: read: 'dtmf_len 30'
03/14 18:03:25 conf lib: read: 'dtmf_threshold 40'
03/14 18:03:25 conf lib: read: 'dtmf_wait 7'
03/14 18:03:25 conf lib: read: 'ignore_fax_dle false'
03/14 18:03:25 conf lib: read: 'raw_data false'
03/14 18:03:25 conf lib: read: 'rec_compression 0'
03/14 18:03:25 conf lib: read: 'rec_speed 0'
03/14 18:03:25 conf lib: read: 'rec_silence_len 70'
03/14 18:03:25 conf lib: read: 'rec_silence_threshold 40'
03/14 18:03:25 conf lib: read: 'rec_remove_silence false'
03/14 18:03:25 conf lib: read: 'rec_max_len 300'
03/14 18:03:25 conf lib: read: 'rec_min_len 0'
03/14 18:03:25 conf lib: read: 'do_hard_flow true'
03/14 18:03:25 conf lib: read: 'beep_frequency 933'
03/14 18:03:25 conf lib: read: 'beep_length 1500'
03/14 18:03:25 conf lib: read: 'max_tries 3'
03/14 18:03:25 conf lib: read: 'retry_delay 5'
03/14 18:03:25 conf lib: read: 'watchdog_timeout 60'
03/14 18:03:25 conf lib: read: 'receive_gain -1'
03/14 18:03:25 conf lib: read: 'transmit_gain -1'
03/14 18:03:25 conf lib: read: 'enable_command_echo true'
03/14 18:03:25 conf lib: read: 'poll_interval 10'
03/14 18:03:25 conf lib: read: 'program vgetty'
03/14 18:03:25 section: program vgetty, ignore
03/14 18:03:25 conf lib: read: 'rings 3'
03/14 18:03:25 conf lib: read: 'answer_mode voice:fax:data'
03/14 18:03:25 conf lib: read: 'force_autodetect false'
03/14 18:03:25 conf lib: read: 'toll_saver_rings 0'
03/14 18:03:25 conf lib: read: 'rec_always_keep true'
03/14 18:03:25 conf lib: read: 'button_program '
03/14 18:03:25 conf lib: read: 'call_program '
03/14 18:03:25 conf lib: read: 'dtmf_program dtmf.sh'
03/14 18:03:25 conf lib: read: 'message_program '
03/14 18:03:25 conf lib: read: 'do_message_light false'
03/14 18:03:25 conf lib: read: 'program vm'
03/14 18:03:25 section: program vm, **found**
03/14 18:03:25 conf lib: read: 'voice_devices cua0'
03/14 18:03:25 conf lib: read: 'dialout_timeout 90'
03/14 18:03:25 conf lib: read: 'ringback_goes_away 70'
03/14 18:03:25 conf lib: read: 'ringback_never_came 100'
03/14 18:03:25 conf lib: read: 'program pvf'
03/14 18:03:25 section: program pvf, ignore
03/14 18:03:25 conf lib: read: 'port cua0'
03/14 18:03:25 conf lib: read: 'port ttyS5'
03/14 18:03:25 conf lib: read: 'ring_type virtual'
03/14 18:03:25 conf lib: read: 'answer_mode fax:data'
03/14 18:03:25 conf lib: read: 'ring_type ring'
03/14 18:03:25 conf lib: read: 'ring_type ring1'
03/14 18:03:25 key: 'part', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'program', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'port', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'ring_type', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'voice_log_level', type=0, flags=3, data=6
03/14 18:03:25 key: 'voice_shell', type=1, flags=3, data=/bin/sh
03/14 18:03:25 key: 'port_speed', type=0, flags=3, data=115200
03/14 18:03:25 key: 'port_timeout', type=0, flags=3, data=10
03/14 18:03:25 key: 'dial_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'command_delay', type=0, flags=3, data=100
03/14 18:03:25 key: 'dtmf_len', type=0, flags=3, data=30
03/14 18:03:25 key: 'dtmf_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'dtmf_wait', type=0, flags=3, data=7
03/14 18:03:25 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'raw_data', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_compression', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_speed', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_silence_len', type=0, flags=3, data=70
03/14 18:03:25 key: 'rec_silence_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_max_len', type=0, flags=3, data=300
03/14 18:03:25 key: 'rec_min_len', type=0, flags=3, data=0
03/14 18:03:25 key: 'do_hard_flow', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'force_autodetect', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'watchdog_timeout', type=0, flags=3, data=60
03/14 18:03:25 key: 'receive_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'transmit_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'enable_command_echo', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'poll_interval', type=0, flags=3, data=10
03/14 18:03:25 key: 'rings', type=1, flags=1, data=3
03/14 18:03:25 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
03/14 18:03:25 key: 'toll_saver_rings', type=0, flags=1, data=0
03/14 18:03:25 key: 'rec_always_keep', type=3, flags=1, data=TRUE
03/14 18:03:25 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
03/14 18:03:25 key: 'phone_owner', type=1, flags=3, data=root
03/14 18:03:25 key: 'phone_group', type=1, flags=3, data=phone
03/14 18:03:25 key: 'phone_mode', type=0, flags=3, data=432
03/14 18:03:25 key: 'message_flag_file', type=1, flags=3, data=.flag
03/14 18:03:25 key: 'receive_dir', type=1, flags=3, data=incoming
03/14 18:03:25 key: 'message_dir', type=1, flags=3, data=messages
03/14 18:03:25 key: 'message_list', type=1, flags=3, data=Index
03/14 18:03:25 key: 'backup_message', type=1, flags=3,
data=standard.rmd
03/14 18:03:25 key: 'button_program', type=1, flags=1, data=
03/14 18:03:25 key: 'call_program', type=1, flags=1, data=
03/14 18:03:25 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
03/14 18:03:25 key: 'message_program', type=1, flags=1, data=
03/14 18:03:25 key: 'do_message_light', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'beep_frequency', type=0, flags=3, data=933
03/14 18:03:25 key: 'beep_length', type=0, flags=3, data=1500
03/14 18:03:25 key: 'max_tries', type=0, flags=3, data=3
03/14 18:03:25 key: 'retry_delay', type=0, flags=3, data=5
03/14 18:03:25 key: 'dialout_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'ringback_goes_away', type=0, flags=3, data=70
03/14 18:03:25 key: 'ringback_never_came', type=0, flags=3, data=100
03/14 18:03:25 key: 'voice_devices', type=1, flags=3, data=cua0
03/14 18:03:25 opening voice modem device
03/14 18:03:25 voice open 'cua0'
03/14 18:03:25 trying device '/dev/cua0'
03/14 18:03:25 makelock(cua0) called
03/14 18:03:25 do_makelock: lock='/var/lock/LCK..cua0'
03/14 18:03:25 stale lockfile, created by process 8428, ignoring
03/14 18:03:25 lock made
03/14 18:03:25 opened voice modem device /dev/cua0
03/14 18:03:25 reading port cua0 configuration from config file
/etc/mgetty+sendfax/voice.conf
03/14 18:03:25 reading /etc/mgetty+sendfax/voice.conf...
03/14 18:03:25 conf lib: read: 'part generic'
03/14 18:03:25 found CT_KEYWORD part generic
03/14 18:03:25 conf lib: read: 'voice_log_level 6'
03/14 18:03:25 conf lib: read: 'voice_dir /var/spool/voice'
03/14 18:03:25 conf lib: read: 'phone_owner root'
03/14 18:03:25 conf lib: read: 'phone_group phone'
03/14 18:03:25 conf lib: read: 'phone_mode 0660'
03/14 18:03:25 conf lib: read: 'message_flag_file .flag'
03/14 18:03:25 conf lib: read: 'receive_dir incoming'
03/14 18:03:25 conf lib: read: 'message_dir messages'
03/14 18:03:25 conf lib: read: 'message_list Index'
03/14 18:03:25 conf lib: read: 'backup_message standard.rmd'
03/14 18:03:25 conf lib: read: 'port_speed 115200'
03/14 18:03:25 conf lib: read: 'voice_shell /bin/sh'
03/14 18:03:25 conf lib: read: 'port_timeout 10'
03/14 18:03:25 conf lib: read: 'dial_timeout 90'
03/14 18:03:25 conf lib: read: 'command_delay 100'
03/14 18:03:25 conf lib: read: 'dtmf_len 30'
03/14 18:03:25 conf lib: read: 'dtmf_threshold 40'
03/14 18:03:25 conf lib: read: 'dtmf_wait 7'
03/14 18:03:25 conf lib: read: 'ignore_fax_dle false'
03/14 18:03:25 conf lib: read: 'raw_data false'
03/14 18:03:25 conf lib: read: 'rec_compression 0'
03/14 18:03:25 conf lib: read: 'rec_speed 0'
03/14 18:03:25 conf lib: read: 'rec_silence_len 70'
03/14 18:03:25 conf lib: read: 'rec_silence_threshold 40'
03/14 18:03:25 conf lib: read: 'rec_remove_silence false'
03/14 18:03:25 conf lib: read: 'rec_max_len 300'
03/14 18:03:25 conf lib: read: 'rec_min_len 0'
03/14 18:03:25 conf lib: read: 'do_hard_flow true'
03/14 18:03:25 conf lib: read: 'beep_frequency 933'
03/14 18:03:25 conf lib: read: 'beep_length 1500'
03/14 18:03:25 conf lib: read: 'max_tries 3'
03/14 18:03:25 conf lib: read: 'retry_delay 5'
03/14 18:03:25 conf lib: read: 'watchdog_timeout 60'
03/14 18:03:25 conf lib: read: 'receive_gain -1'
03/14 18:03:25 conf lib: read: 'transmit_gain -1'
03/14 18:03:25 conf lib: read: 'enable_command_echo true'
03/14 18:03:25 conf lib: read: 'poll_interval 10'
03/14 18:03:25 conf lib: read: 'program vgetty'
03/14 18:03:25 conf lib: read: 'rings 3'
03/14 18:03:25 conf lib: read: 'answer_mode voice:fax:data'
03/14 18:03:25 conf lib: read: 'force_autodetect false'
03/14 18:03:25 conf lib: read: 'toll_saver_rings 0'
03/14 18:03:25 conf lib: read: 'rec_always_keep true'
03/14 18:03:25 conf lib: read: 'button_program '
03/14 18:03:25 conf lib: read: 'call_program '
03/14 18:03:25 conf lib: read: 'dtmf_program dtmf.sh'
03/14 18:03:25 conf lib: read: 'message_program '
03/14 18:03:25 conf lib: read: 'do_message_light false'
03/14 18:03:25 conf lib: read: 'program vm'
03/14 18:03:25 conf lib: read: 'voice_devices cua0'
03/14 18:03:25 conf lib: read: 'dialout_timeout 90'
03/14 18:03:25 conf lib: read: 'ringback_goes_away 70'
03/14 18:03:25 conf lib: read: 'ringback_never_came 100'
03/14 18:03:25 conf lib: read: 'program pvf'
03/14 18:03:25 conf lib: read: 'port cua0'
03/14 18:03:25 section: port cua0, **found**
03/14 18:03:25 conf lib: read: 'port ttyS5'
03/14 18:03:25 section: port ttyS5, ignore
03/14 18:03:25 conf lib: read: 'ring_type virtual'
03/14 18:03:25 conf lib: read: 'answer_mode fax:data'
03/14 18:03:25 conf lib: read: 'ring_type ring'
03/14 18:03:25 conf lib: read: 'ring_type ring1'
03/14 18:03:25 key: 'part', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'program', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'port', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'ring_type', type=6, flags=4, data=(ignored)
03/14 18:03:25 key: 'voice_log_level', type=0, flags=3, data=6
03/14 18:03:25 key: 'voice_shell', type=1, flags=3, data=/bin/sh
03/14 18:03:25 key: 'port_speed', type=0, flags=3, data=115200
03/14 18:03:25 key: 'port_timeout', type=0, flags=3, data=10
03/14 18:03:25 key: 'dial_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'command_delay', type=0, flags=3, data=100
03/14 18:03:25 key: 'dtmf_len', type=0, flags=3, data=30
03/14 18:03:25 key: 'dtmf_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'dtmf_wait', type=0, flags=3, data=7
03/14 18:03:25 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'raw_data', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_compression', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_speed', type=0, flags=3, data=0
03/14 18:03:25 key: 'rec_silence_len', type=0, flags=3, data=70
03/14 18:03:25 key: 'rec_silence_threshold', type=0, flags=3, data=40
03/14 18:03:25 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
03/14 18:03:25 key: 'rec_max_len', type=0, flags=3, data=300
03/14 18:03:25 key: 'rec_min_len', type=0, flags=3, data=0
03/14 18:03:25 key: 'do_hard_flow', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'force_autodetect', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'watchdog_timeout', type=0, flags=3, data=60
03/14 18:03:25 key: 'receive_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'transmit_gain', type=0, flags=3, data=-1
03/14 18:03:25 key: 'enable_command_echo', type=3, flags=3, data=TRUE
03/14 18:03:25 key: 'poll_interval', type=0, flags=3, data=10
03/14 18:03:25 key: 'rings', type=1, flags=1, data=3
03/14 18:03:25 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
03/14 18:03:25 key: 'toll_saver_rings', type=0, flags=1, data=0
03/14 18:03:25 key: 'rec_always_keep', type=3, flags=1, data=TRUE
03/14 18:03:25 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
03/14 18:03:25 key: 'phone_owner', type=1, flags=3, data=root
03/14 18:03:25 key: 'phone_group', type=1, flags=3, data=phone
03/14 18:03:25 key: 'phone_mode', type=0, flags=3, data=432
03/14 18:03:25 key: 'message_flag_file', type=1, flags=3, data=.flag
03/14 18:03:25 key: 'receive_dir', type=1, flags=3, data=incoming
03/14 18:03:25 key: 'message_dir', type=1, flags=3, data=messages
03/14 18:03:25 key: 'message_list', type=1, flags=3, data=Index
03/14 18:03:25 key: 'backup_message', type=1, flags=3,
data=standard.rmd
03/14 18:03:25 key: 'button_program', type=1, flags=1, data=
03/14 18:03:25 key: 'call_program', type=1, flags=1, data=
03/14 18:03:25 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
03/14 18:03:25 key: 'message_program', type=1, flags=1, data=
03/14 18:03:25 key: 'do_message_light', type=3, flags=1, data=FALSE
03/14 18:03:25 key: 'beep_frequency', type=0, flags=3, data=933
03/14 18:03:25 key: 'beep_length', type=0, flags=3, data=1500
03/14 18:03:25 key: 'max_tries', type=0, flags=3, data=3
03/14 18:03:25 key: 'retry_delay', type=0, flags=3, data=5
03/14 18:03:25 key: 'dialout_timeout', type=0, flags=3, data=90
03/14 18:03:25 key: 'ringback_goes_away', type=0, flags=3, data=70
03/14 18:03:25 key: 'ringback_never_came', type=0, flags=3, data=100
03/14 18:03:25 key: 'voice_devices', type=1, flags=3, data=cua0
03/14 18:03:25 tss: set speed to 115200 (10002)
03/14 18:03:25 tio_set_flow_control( HARD )
03/14 18:03:25 detecting voice modem type
03/14 18:03:25 vm: ATE1
03/14 18:03:25 voice command: '' -> 'OK|ATE1'
03/14 18:03:25 serial port: ATE1
03/14 18:03:25 serial port: OK
03/14 18:03:25 voice command: 'ATI9' -> ''
03/14 18:03:26 vm: ATI9
03/14 18:03:26 serial port: ATI9
03/14 18:03:26 serial port: ERROR
03/14 18:03:26 voice command: 'ATI' -> ''
03/14 18:03:26 vm: ATI
03/14 18:03:26 serial port: ATI
03/14 18:03:26 serial port: 56000
03/14 18:03:26 Rockwell: OK
03/14 18:03:26 Rockwell detected
03/14 18:03:26 vm: entering voice mode
03/14 18:03:26 vm: Installing signal handlers
03/14 18:03:26 voice command: 'AT#CLS?' -> ''
03/14 18:03:26 vm: AT#CLS?
03/14 18:03:26 Rockwell: AT#CLS?
03/14 18:03:26 Rockwell: 0
03/14 18:03:26 voice command: '' -> 'OK'
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#CLS=8' -> 'OK'
03/14 18:03:27 vm: AT#CLS=8
03/14 18:03:27 Rockwell: AT#CLS=8
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT' -> 'OK'
03/14 18:03:27 vm: AT
03/14 18:03:27 Rockwell: <DLE> <h>
03/14 18:03:27 vm: queued event HANDSET_ON_HOOK at position 0000
03/14 18:03:27 Rockwell:
03/14 18:03:27 Rockwell: AT
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 vm: queued event RESET_WATCHDOG at position 0001
03/14 18:03:27 initializing ROCKWELL voice modem
03/14 18:03:27 voice command: 'AT#VSP=70' -> 'OK'
03/14 18:03:27 vm: AT#VSP=70
03/14 18:03:27 vm: unqueued event HANDSET_ON_HOOK at position 0000
03/14 18:03:27 vm: voice_handle_event got event HANDSET_ON_HOOK with
data <0>
03/14 18:03:27 vm: unqueued event RESET_WATCHDOG at position 0001
03/14 18:03:27 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:27 Rockwell: AT#VSP=70
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VSD=0' -> 'OK'
03/14 18:03:27 vm: AT#VSD=0
03/14 18:03:27 Rockwell: AT#VSD=0
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
03/14 18:03:27 vm: AT#VTD=3F,3F,3F
03/14 18:03:27 Rockwell: AT#VTD=3F,3F,3F
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT#VSS=1' -> 'OK'
03/14 18:03:27 vm: AT#VSS=1
03/14 18:03:27 Rockwell: AT#VSS=1
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 voice command: 'AT&K3' -> 'OK'
03/14 18:03:27 vm: AT&K3
03/14 18:03:27 Rockwell: AT&K3
03/14 18:03:27 Rockwell: OK
03/14 18:03:27 tio_set_flow_control( HARD )
03/14 18:03:27 vm: leaving voice mode
03/14 18:03:27 voice command: 'AT#CLS=0' -> 'OK'
03/14 18:03:28 vm: AT#CLS=0
03/14 18:03:28 Rockwell: AT#CLS=0
03/14 18:03:28 Rockwell: OK
03/14 18:03:28 voice command: 'AT' -> 'OK'
03/14 18:03:28 vm: AT
03/14 18:03:28 Rockwell: AT
03/14 18:03:28 Rockwell: OK
03/14 18:03:28 vm: Restoring signal handlers
03/14 18:03:28 vm: entering voice mode
03/14 18:03:28 vm: Installing signal handlers
03/14 18:03:28 voice command: 'AT#CLS?' -> ''
03/14 18:03:28 vm: AT#CLS?
03/14 18:03:28 Rockwell: AT#CLS?
03/14 18:03:28 Rockwell: 0
03/14 18:03:28 voice command: '' -> 'OK'
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 voice command: 'AT#CLS=8' -> 'OK'
03/14 18:03:29 vm: AT#CLS=8
03/14 18:03:29 Rockwell: AT#CLS=8
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 voice command: 'AT' -> 'OK'
03/14 18:03:29 vm: AT
03/14 18:03:29 Rockwell: <DLE> <h>
03/14 18:03:29 vm: queued event HANDSET_ON_HOOK at position 0002
03/14 18:03:29 Rockwell:
03/14 18:03:29 Rockwell: AT
03/14 18:03:29 Rockwell: OK
03/14 18:03:29 vm: Executing shell script ./record.sh with shell
/bin/sh
03/14 18:03:29 vm: opening pipes
03/14 18:03:29 vm: forking shell
03/14 18:03:29 vm(0): HELLO SHELL
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0003
03/14 18:03:29 vm: unqueued event HANDSET_ON_HOOK at position 0002
03/14 18:03:29 vm: voice_handle_event got event HANDSET_ON_HOOK with
data <_>
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0003
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): HELLO VOICE PROGRAM
03/14 18:03:29 vm(1): READY
03/14 18:03:29 vm: initialized communication
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0004
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0004
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): ENABLE EVENTS
03/14 18:03:29 vm(1): READY
03/14 18:03:29 vm: Got pipe signal
03/14 18:03:29 vm: queued event SIGNAL_SIGPIPE at position 0005
03/14 18:03:29 vm: unqueued event SIGNAL_SIGPIPE at position 0005
03/14 18:03:29 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:29 shell(1): DIAL 02079999999
03/14 18:03:29 vm(1): DIALING
03/14 18:03:29 vm: queued event RESET_WATCHDOG at position 0006
03/14 18:03:29 vm: ATD07810880071
03/14 18:03:29 vm: unqueued event RESET_WATCHDOG at position 0006
03/14 18:03:29 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:29 Rockwell: ATD02079999999
03/14 18:03:29 vm: queued event RESET_WATCHDOG at position 0007
03/14 18:03:29 vm: unqueued event RESET_WATCHDOG at position 0007
03/14 18:03:29 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
03/14 18:03:55 Rockwell: VCON
03/14 18:03:55 vm(1): READY
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0008
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0008
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <0>
03/14 18:03:56 shell(1): RECORD test_data_new.rmd
03/14 18:03:56 vm(1): RECORDING
03/14 18:03:56 recording voice file test_data_new.rmd
03/14 18:03:56 vm: queued event RESET_WATCHDOG at position 0009
03/14 18:03:56 voice command: 'AT#VBS=2' -> 'OK'
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0010
03/14 18:03:56 vm: AT#VBS=2
03/14 18:03:56 vm: unqueued event RESET_WATCHDOG at position 0009
03/14 18:03:56 vm: voice_handle_event got event RESET_WATCHDOG with
data <P>
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0010
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <_>
03/14 18:03:56 shell(2): STOP
03/14 18:03:56 vm: STOP during IDLE
03/14 18:03:56 vm(2): READY
03/14 18:03:56 Rockwell:
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position
0011AT#VBS=2
03/14 18:03:56 Rockwell: OK
03/14 18:03:56 vm: queued event RESET_WATCHDOG at position 0012
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0011
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <_>
03/14 18:03:56 shell(2): ENABLE EVENTS
03/14 18:03:56 vm: Nested command in shell script
03/14 18:03:56 vm(2): ERROR
03/14 18:03:56 vm: unqueued event RESET_WATCHDOG at position 0012
03/14 18:03:56 vm: voice_handle_event got event RESET_WATCHDOG with
data <P>
03/14 18:03:56 voice command: 'AT&K3' -> 'OK'
03/14 18:03:56 vm: Got pipe signal
03/14 18:03:56 vm: queued event SIGNAL_SIGPIPE at position 0013
03/14 18:03:56 vm: AT&K3
03/14 18:03:56 vm: unqueued event SIGNAL_SIGPIPE at position 0013
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGPIPE with
data <P>
03/14 18:03:56 shell(2): GOODBYE
03/14 18:03:56 vm: Nested command in shell script
03/14 18:03:56 vm(2): ERROR
03/14 18:03:56 Rockwell:
03/14 18:03:56 vm: Got child changed status signal
03/14 18:03:56 vm: queued event SIGNAL_SIGCHLD at position 0014AT&K3
03/14 18:03:56 Rockwell: OK
03/14 18:03:56 tio_set_flow_control( HARD XON_IN )
03/14 18:03:56 voice command: 'AT#VRX' -> 'CONNECT'
03/14 18:03:56 vm: AT#VRX
03/14 18:03:56 vm: unqueued event SIGNAL_SIGCHLD at position 0014
03/14 18:03:56 vm: voice_handle_event got event SIGNAL_SIGCHLD with
data <P>
03/14 18:03:56 vm: <STOP RECORDING>
03/14 18:03:56 Rockwell: AT#VRX!
03/14 18:03:56 Rockwell: CONNECT
03/14 18:04:05 Rockwell: <DLE> <q>
03/14 18:04:05 vm: queued event SILENCE_DETECTED at position 0015
03/14 18:04:05 vm: unqueued event SILENCE_DETECTED at position 0015
03/14 18:04:05 vm: voice_handle_event got event SILENCE_DETECTED
with data <P>
03/14 18:04:05 vm: <STOP RECORDING>
03/14 18:04:05 Rockwell: <VOICE DATA 16283 bytes>
03/14 18:04:05 Rockwell: <DLE> <ETX>
03/14 18:04:05 voice command: '' -> 'OK|VCON'
03/14 18:04:05 Rockwell: VCON
03/14 18:04:05 vm(1): READY
03/14 18:04:05 vm: Got pipe signal
03/14 18:04:05 vm: queued event SIGNAL_SIGPIPE at position 0016
03/14 18:04:05 vm: could not write to shell
03/14 18:04:05 vm: Could not handle event, something failed
=========================================================
As you can see, 'something' failed as vm could not write to shell.
Everything involved is running as root and is owned by root and is
writable by root. Any thoughts as to how I can find out what failed, or
alternatively, any experience with a similar issue?
The modem has incidentaly been in production use as a fax gateway until
about 3 weeks ago on a Win2k Server.
Thanks in adv.,
Jon D