Basics of using a voice modem

Discussion:

(too old to reply)

Jamie

2006-06-14 00:22:01 UTC

I'm trying to get an external Hayes Optima 5362US (voice/ccid) modem to
work with linux & eventually vgetty but I'm not able to detect the
voice capabilities with vgetty-test.pl and the examples in Hayes the
manual have be a bit puzzled.

Following an example from the manual, to record a greeting manually, I
should enter:

AT#CLS=8 (RETURN) configures modem for voice
AT#VBS=4 (RETURN) sets 4 bit compression
ATS30=60 (RETURN) set register 30 -> Inactivity Timer
AT#BDR=16 (RETURN) set the baud rate
AT#VSP=20 (RETURN) set wait for receiving ADPCM data (20 * 100ms)
AT#VSD=1 (RETURN) enable silence deletion
AT#VSS=1 (RETURN) set silence detection threshold
AT#VLS=1 (RETURN) selects handset as input device
AT#VRX (RETURN) verifies DTE ready to receive voice message
<<Speak into the handset. Recording will start and stop
automatically.>>
AT#VLS=0 (RETURN) stops input from handset

My problem at the moment seems to be with setting the baud rate. Once
#BDR is issued in either kermit or minicom, commands are not echoed
back (I get non-ascii garbage back to the terminal) and I'm unable to
record or playback anything through the headset? If I skip the #BDR
command, I can get the modem to pickup the handset and hear feedback
through the speaker but I'm unable to replay anything which suggests
that nothing was actually recorded.

I'm rather new to voice modems so this is probably something rather
simple.

Many thanks,
Jamie

Thumbing through the manual, it looks like only a subset of voice
commands are availible:

AT#VGT=n (playback volume)
This command allows the DTE to set the playback volume of the headphone
and
speaker.
Range: 128-228, default: 153

AT#BDR=n (baud rate)
This command forces the modem to select a specific baud rate for DTE
interface.
AT#BDR=0 Enables autobaud detection.
AT#BDR=n Where 1<n<48. Sends OK message at current speed, then
switches
to the new speed defined by n*2400 bps unless or until another
AT#BDR=n
command is received. Autobaud is disabled, and the character
format is
maintained at the format most recently detected.

AT#CLS (select data/fax/voice)
This command selects the operation mode for the modem.
AT#CLS=0 Selects data operation mode.
AT#CLS=1 Selects Class 1 Fax operating mode.
AT#CLS=2 Selects Class 2 Fax operating mode.
AT#CLS=8 Selects voice/audio mode.

AT#TL (audio output level)
This command adjusts the transmit level of the audio output for the
handset
and speaker.

AT#VBQ? (buffer size)
This command requests the size of the buffer for voice transmit and
voice
receive.

AT#VBS (bits per sample)
This command selects the degree of voice compression to be used.
AT#VBS=2 Selects 2 bits per sample.
AT#VBS=4 Selects 4 bits per sample.
AT#VBS=8 Selects 8 bits per sample.
AT#VBS=16 Selects 16 bits per sample.

AT#VBT (beep tone timer)
This command defines the time period used by the modem as the tone
duration.
AT#VBT=0 Disables the tone generation.
AT#VBT=1-40 Sets the duration time in tenths of seconds.

AT#VLS (voice line select)
This command determines which devices are routed through the modem.
AT#VLS=0 Sets the modem to route the telephone line on all voice
calls.
AT#VLS=1 Sets the modem to route only the handset.
AT#VLS=2 Sets the modem to route only the speaker.
AT#VLS=3 Sets the modem to route only a microphone.
AT#VLS=4 Sets the modem to route an internal speaker and the
telephone line.

AT#VRA (ringback timer)
This command sets the amount of time measured from when the cadence
stops
after detected.
AT#VRA=0 Turns off the ringback.
AT#VRA=n Defined in 100ms units.

AT#VRN (ringback never came)
This command sets the amount of time the modem will wait before it will
assume
that the remote modem has picked up.
AT#VRN=0 Turns off the ringback never came timer.
AT#VRN=n Defines the time in 100 ms units for the modem to wait.

AT#VRX (voice receive)
This command sets the modem to switch to receiving a voice
transmission.

AT#VSD (silence deletion)
This command sets the modem to either delete silence from a received
voice
message, or leave the silence intact.
AT#VSD=0 Turns off the silence deletion.
AT#VSD=1 Turns on the silence deletion.

AT#VSP (silence period)
This command sets the length of time the modem will wait for receiving
ADPCM data.
AT#VSP=0 Turns off the silence period detection timer.
AT#VSP=n Where n defines the time period in 100 ms units.

AT#VSS (silence detection tuner)
This command enables or disables the silence detection in voice receive
mode,
and controls the sensitivity of the modem.
AT#VSS=0 Disables the silence detection.
AT#VSS=1 Sets least sensitive detection.
AT#VSS=2 Sets midrange sensitivity.
AT#VSS=3 Sets most sensitive.

Below is the info the modem returns:
OK
ATI1
007

OK
ATI2
OK

OK
ATI3
Version 7.00

OK
ATI4
a125843FA848D70EF0810700

bC60004000

r102111115111200C0

r30001111FF7000000

OK
ATI6
Last Call Statistics Screen
Link Statistics:

Characters Sent: 0 Characters Received:
0
Octets Sent: 0 Octets Received:
0
Packets Sent: 0 Packets Received:
0
NAKs Sent: 0 NAKs Received:
0
Rates Sent: 0 Rates Received:
0
Retrains Sent: 0 Retrains Received:
0

Link Details:

Last Number Called:
Connection Time: 00:06:52 DTE: 115200 8N1
DCE:
Mode: &Q5 RBS Pattern Detected: 00
Protocol: None Data Rate Dropped in kbps:
00
Compression: None Digital Pad Detected: None
Flow Control: &K3 Codec Law: u-law

Call Termination: Normal Termination
OK
ATI7
OPTIMA 56K, Model 5362US/HK, Version 7.00
Copyright 1996, 1997 Hayes Microcomputer Products, Inc.

OK
ATI9
(1.00HAY5362\\MODEM\\Hayes OPTIMA 56K, 5362US/HK 6A)

Jamie

2006-06-14 03:03:46 UTC

Permalink

NB: Here is my log from vgetty. I'm not able to play a voice file with
'vm play -H file.rmd' but I'm not sure what the problem is. Any ideas?

Cheers,
Jamie

06/13 22:42:23 yS0 vgetty: experimental test release 0.9.32 / with
duplex patch
06/13 22:42:23 yS0 mgetty: interim release 1.1.35-Feb22
06/13 22:42:23 yS0 WARNING: parent process not init(pid=1), but
pid=31479 (bash)
06/13 22:42:23 yS0 reading generic configuration from config file
/usr/local/etc/mgetty+sendfax/voice.conf
06/13 22:42:23 yS0 reading
/usr/local/etc/mgetty+sendfax/voice.conf...
06/13 22:42:23 yS0 conf lib: read: 'part generic'
06/13 22:42:23 yS0 section: part generic, **found**
06/13 22:42:23 yS0 conf lib: read: 'voice_log_level 6'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
06/13 22:42:23 yS0 conf lib: read: 'voice_dir /var/spool/voice'
06/13 22:42:23 yS0 conf lib: read: 'message_flag_file .flag'
06/13 22:42:23 yS0 conf lib: read: 'receive_dir incoming'
06/13 22:42:23 yS0 conf lib: read: 'message_dir messages'
06/13 22:42:23 yS0 conf lib: read: 'message_list Index'
06/13 22:42:23 yS0 conf lib: read: 'backup_message standard.rmd'
06/13 22:42:23 yS0 conf lib: read: 'port_speed 115200'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell /usr/bin/perl'
06/13 22:42:23 yS0 conf lib: read: 'port_timeout 10'
06/13 22:42:23 yS0 conf lib: read: 'dial_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'command_delay 100'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_len 30'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_wait 7'
06/13 22:42:23 yS0 conf lib: read: 'ignore_fax_dle false'
06/13 22:42:23 yS0 conf lib: read: 'raw_data false'
06/13 22:42:23 yS0 conf lib: read: 'rec_compression 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_speed 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_len 70'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'rec_remove_silence false'
06/13 22:42:23 yS0 conf lib: read: 'rec_max_len 300'
06/13 22:42:23 yS0 conf lib: read: 'rec_min_len 0'
06/13 22:42:23 yS0 conf lib: read: 'do_hard_flow true'
06/13 22:42:23 yS0 conf lib: read: 'beep_frequency 933'
06/13 22:42:23 yS0 conf lib: read: 'beep_length 1500'
06/13 22:42:23 yS0 conf lib: read: 'max_tries 3'
06/13 22:42:23 yS0 conf lib: read: 'retry_delay 5'
06/13 22:42:23 yS0 conf lib: read: 'watchdog_timeout 60'
06/13 22:42:23 yS0 conf lib: read: 'receive_gain -1'
06/13 22:42:23 yS0 conf lib: read: 'transmit_gain 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_command_echo true'
06/13 22:42:23 yS0 conf lib: read: 'poll_interval 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_compression_mapping_querry
FALSE'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_signed 0'
06/13 22:42:23 yS0 conf lib: read: 'compression_16bit_linear_signed
0'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_unsigned
1'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_ulaw 4'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_alaw 5'
06/13 22:42:23 yS0 conf lib: read: 'compression_2bit_adpcm 140'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_adpcm 141'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_ima_adpcm 129'
06/13 22:42:23 yS0 conf lib: read: 'program vgetty'
06/13 22:42:23 yS0 found CT_KEYWORD program vgetty
06/13 22:42:23 yS0 conf lib: read: 'rings 5'
06/13 22:42:23 yS0 conf lib: read: 'answer_mode voice:fax:data'
06/13 22:42:23 yS0 conf lib: read: 'force_autodetect false'
06/13 22:42:23 yS0 conf lib: read: 'toll_saver_rings 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_always_keep true'
06/13 22:42:23 yS0 conf lib: read: 'button_program '
06/13 22:42:23 yS0 conf lib: read: 'call_program '
06/13 22:42:23 yS0 conf lib: read: 'dtmf_program dtmf.sh'
06/13 22:42:23 yS0 conf lib: read: 'message_program '
06/13 22:42:23 yS0 conf lib: read: 'do_message_light false'
06/13 22:42:23 yS0 conf lib: read: 'ring_report_delay 15'
06/13 22:42:23 yS0 conf lib: read: 'program vm'
06/13 22:42:23 yS0 conf lib: read: 'voice_devices ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'dialout_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'ringback_goes_away 70'
06/13 22:42:23 yS0 conf lib: read: 'ringback_never_came 100'
06/13 22:42:23 yS0 conf lib: read: 'program pvf'
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'ring_type virtual'
06/13 22:42:23 yS0 conf lib: read: 'answer_mode fax:data'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring1'
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'force_detect V253modem'
06/13 22:42:23 yS0 key: 'part', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'program', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'port', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'ring_type', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'voice_log_level', type=0, flags=3, data=6
06/13 22:42:23 yS0 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
06/13 22:42:23 yS0 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
06/13 22:42:23 yS0 key: 'port_speed', type=0, flags=3, data=115200
06/13 22:42:23 yS0 key: 'port_timeout', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'dial_timeout', type=0, flags=3, data=90
06/13 22:42:23 yS0 key: 'command_delay', type=0, flags=3, data=100
06/13 22:42:23 yS0 key: 'dtmf_len', type=0, flags=3, data=30
06/13 22:42:23 yS0 key: 'dtmf_threshold', type=0, flags=3, data=40
06/13 22:42:23 yS0 key: 'dtmf_wait', type=0, flags=3, data=7
06/13 22:42:23 yS0 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'raw_data', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'rec_compression', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_speed', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_silence_len', type=0, flags=3, data=70
06/13 22:42:23 yS0 key: 'rec_silence_threshold', type=0, flags=3,
data=40
06/13 22:42:23 yS0 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'rec_max_len', type=0, flags=3, data=300
06/13 22:42:23 yS0 key: 'rec_min_len', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'do_hard_flow', type=3, flags=3, data=TRUE
06/13 22:42:23 yS0 key: 'force_autodetect', type=3, flags=1,
data=FALSE
06/13 22:42:23 yS0 key: 'watchdog_timeout', type=0, flags=3, data=60
06/13 22:42:23 yS0 key: 'receive_gain', type=0, flags=3, data=-1
06/13 22:42:23 yS0 key: 'transmit_gain', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'enable_command_echo', type=3, flags=3,
data=TRUE
06/13 22:42:23 yS0 key: 'poll_interval', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'forceV253', type=3, flags=1, data=FALSE
06/13 22:42:23 yS0 key: 'forceV253subset', type=3, flags=1,
data=FALSE
06/13 22:42:23 yS0 key: 'enable_compression_mapping_querry', type=3,
flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'compression_8bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_16bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_8bit_linear_unsigned', type=0,
flags=3, data=1
06/13 22:42:23 yS0 key: 'compression_8bit_ulaw', type=0, flags=3,
data=4
06/13 22:42:23 yS0 key: 'compression_8bit_alaw', type=0, flags=3,
data=5
06/13 22:42:23 yS0 key: 'compression_2bit_adpcm', type=0, flags=3,
data=140
06/13 22:42:23 yS0 key: 'compression_4bit_adpcm', type=0, flags=3,
data=141
06/13 22:42:23 yS0 key: 'compression_4bit_ima_adpcm', type=0,
flags=3, data=129
06/13 22:42:23 yS0 key: 'rings', type=1, flags=1, data=3
06/13 22:42:23 yS0 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
06/13 22:42:23 yS0 key: 'toll_saver_rings', type=0, flags=1, data=0
06/13 22:42:23 yS0 key: 'rec_always_keep', type=3, flags=1, data=TRUE
06/13 22:42:23 yS0 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
06/13 22:42:23 yS0 key: 'phone_owner', type=1, flags=1, data=root
06/13 22:42:23 yS0 key: 'phone_group', type=1, flags=1, data=phone
06/13 22:42:23 yS0 key: 'phone_mode', type=0, flags=1, data=432
06/13 22:42:23 yS0 key: 'message_flag_file', type=1, flags=3,
data=.flag
06/13 22:42:23 yS0 key: 'receive_dir', type=1, flags=3, data=incoming
06/13 22:42:23 yS0 key: 'message_dir', type=1, flags=3, data=messages
06/13 22:42:23 yS0 key: 'message_list', type=1, flags=3, data=Index
06/13 22:42:23 yS0 key: 'backup_message', type=1, flags=3,
data=standard.rmd
06/13 22:42:23 yS0 key: 'button_program', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'call_program', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
06/13 22:42:23 yS0 key: 'message_program', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'do_message_light', type=3, flags=1,
data=FALSE
06/13 22:42:23 yS0 key: 'pre_message', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beepsound', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beep_frequency', type=0, flags=3, data=933
06/13 22:42:23 yS0 key: 'beep_length', type=0, flags=3, data=1500
06/13 22:42:23 yS0 key: 'max_tries', type=0, flags=3, data=3
06/13 22:42:23 yS0 key: 'retry_delay', type=0, flags=3, data=5
06/13 22:42:23 yS0 key: 'dialout_timeout', type=0, flags=1, data=90
06/13 22:42:23 yS0 key: 'ringback_goes_away', type=0, flags=1,
data=70
06/13 22:42:23 yS0 key: 'ringback_never_came', type=0, flags=1,
data=100
06/13 22:42:23 yS0 key: 'ring_report_delay', type=0, flags=1, data=15
06/13 22:42:23 yS0 key: 'voice_devices', type=1, flags=1, data=
06/13 22:42:23 yS0 reading program vgetty configuration from config
file /usr/local/etc/mgetty+sendfax/voice.conf
06/13 22:42:23 yS0 reading
/usr/local/etc/mgetty+sendfax/voice.conf...
06/13 22:42:23 yS0 conf lib: read: 'part generic'
06/13 22:42:23 yS0 found CT_KEYWORD part generic
06/13 22:42:23 yS0 conf lib: read: 'voice_log_level 6'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
06/13 22:42:23 yS0 conf lib: read: 'voice_dir /var/spool/voice'
06/13 22:42:23 yS0 conf lib: read: 'message_flag_file .flag'
06/13 22:42:23 yS0 conf lib: read: 'receive_dir incoming'
06/13 22:42:23 yS0 conf lib: read: 'message_dir messages'
06/13 22:42:23 yS0 conf lib: read: 'message_list Index'
06/13 22:42:23 yS0 conf lib: read: 'backup_message standard.rmd'
06/13 22:42:23 yS0 conf lib: read: 'port_speed 115200'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell /usr/bin/perl'
06/13 22:42:23 yS0 conf lib: read: 'port_timeout 10'
06/13 22:42:23 yS0 conf lib: read: 'dial_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'command_delay 100'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_len 30'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_wait 7'
06/13 22:42:23 yS0 conf lib: read: 'ignore_fax_dle false'
06/13 22:42:23 yS0 conf lib: read: 'raw_data false'
06/13 22:42:23 yS0 conf lib: read: 'rec_compression 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_speed 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_len 70'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'rec_remove_silence false'
06/13 22:42:23 yS0 conf lib: read: 'rec_max_len 300'
06/13 22:42:23 yS0 conf lib: read: 'rec_min_len 0'
06/13 22:42:23 yS0 conf lib: read: 'do_hard_flow true'
06/13 22:42:23 yS0 conf lib: read: 'beep_frequency 933'
06/13 22:42:23 yS0 conf lib: read: 'beep_length 1500'
06/13 22:42:23 yS0 conf lib: read: 'max_tries 3'
06/13 22:42:23 yS0 conf lib: read: 'retry_delay 5'
06/13 22:42:23 yS0 conf lib: read: 'watchdog_timeout 60'
06/13 22:42:23 yS0 conf lib: read: 'receive_gain -1'
06/13 22:42:23 yS0 conf lib: read: 'transmit_gain 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_command_echo true'
06/13 22:42:23 yS0 conf lib: read: 'poll_interval 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_compression_mapping_querry
FALSE'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_signed 0'
06/13 22:42:23 yS0 conf lib: read: 'compression_16bit_linear_signed
0'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_unsigned
1'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_ulaw 4'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_alaw 5'
06/13 22:42:23 yS0 conf lib: read: 'compression_2bit_adpcm 140'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_adpcm 141'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_ima_adpcm 129'
06/13 22:42:23 yS0 conf lib: read: 'program vgetty'
06/13 22:42:23 yS0 section: program vgetty, **found**
06/13 22:42:23 yS0 conf lib: read: 'rings 5'
06/13 22:42:23 yS0 conf lib: read: 'answer_mode voice:fax:data'
06/13 22:42:23 yS0 conf lib: read: 'force_autodetect false'
06/13 22:42:23 yS0 conf lib: read: 'toll_saver_rings 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_always_keep true'
06/13 22:42:23 yS0 conf lib: read: 'button_program '
06/13 22:42:23 yS0 conf lib: read: 'call_program '
06/13 22:42:23 yS0 conf lib: read: 'dtmf_program dtmf.sh'
06/13 22:42:23 yS0 conf lib: read: 'message_program '
06/13 22:42:23 yS0 conf lib: read: 'do_message_light false'
06/13 22:42:23 yS0 conf lib: read: 'ring_report_delay 15'
06/13 22:42:23 yS0 conf lib: read: 'program vm'
06/13 22:42:23 yS0 section: program vm, ignore
06/13 22:42:23 yS0 conf lib: read: 'voice_devices ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'dialout_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'ringback_goes_away 70'
06/13 22:42:23 yS0 conf lib: read: 'ringback_never_came 100'
06/13 22:42:23 yS0 conf lib: read: 'program pvf'
06/13 22:42:23 yS0 section: program pvf, ignore
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'ring_type virtual'
06/13 22:42:23 yS0 conf lib: read: 'answer_mode fax:data'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring1'
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'force_detect V253modem'
06/13 22:42:23 yS0 key: 'part', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'program', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'port', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'ring_type', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'voice_log_level', type=0, flags=3, data=6
06/13 22:42:23 yS0 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
06/13 22:42:23 yS0 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
06/13 22:42:23 yS0 key: 'port_speed', type=0, flags=3, data=115200
06/13 22:42:23 yS0 key: 'port_timeout', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'dial_timeout', type=0, flags=3, data=90
06/13 22:42:23 yS0 key: 'command_delay', type=0, flags=3, data=100
06/13 22:42:23 yS0 key: 'dtmf_len', type=0, flags=3, data=30
06/13 22:42:23 yS0 key: 'dtmf_threshold', type=0, flags=3, data=40
06/13 22:42:23 yS0 key: 'dtmf_wait', type=0, flags=3, data=7
06/13 22:42:23 yS0 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'raw_data', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'rec_compression', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_speed', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_silence_len', type=0, flags=3, data=70
06/13 22:42:23 yS0 key: 'rec_silence_threshold', type=0, flags=3,
data=40
06/13 22:42:23 yS0 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'rec_max_len', type=0, flags=3, data=300
06/13 22:42:23 yS0 key: 'rec_min_len', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'do_hard_flow', type=3, flags=3, data=TRUE
06/13 22:42:23 yS0 key: 'force_autodetect', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'watchdog_timeout', type=0, flags=3, data=60
06/13 22:42:23 yS0 key: 'receive_gain', type=0, flags=3, data=-1
06/13 22:42:23 yS0 key: 'transmit_gain', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'enable_command_echo', type=3, flags=3,
data=TRUE
06/13 22:42:23 yS0 key: 'poll_interval', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'forceV253', type=3, flags=1, data=FALSE
06/13 22:42:23 yS0 key: 'forceV253subset', type=3, flags=1,
data=FALSE
06/13 22:42:23 yS0 key: 'enable_compression_mapping_querry', type=3,
flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'compression_8bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_16bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_8bit_linear_unsigned', type=0,
flags=3, data=1
06/13 22:42:23 yS0 key: 'compression_8bit_ulaw', type=0, flags=3,
data=4
06/13 22:42:23 yS0 key: 'compression_8bit_alaw', type=0, flags=3,
data=5
06/13 22:42:23 yS0 key: 'compression_2bit_adpcm', type=0, flags=3,
data=140
06/13 22:42:23 yS0 key: 'compression_4bit_adpcm', type=0, flags=3,
data=141
06/13 22:42:23 yS0 key: 'compression_4bit_ima_adpcm', type=0,
flags=3, data=129
06/13 22:42:23 yS0 key: 'rings', type=1, flags=3, data=5
06/13 22:42:23 yS0 key: 'answer_mode', type=1, flags=3,
data=voice:fax:data
06/13 22:42:23 yS0 key: 'toll_saver_rings', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_always_keep', type=3, flags=3, data=TRUE
06/13 22:42:23 yS0 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
06/13 22:42:23 yS0 key: 'phone_owner', type=1, flags=1, data=root
06/13 22:42:23 yS0 key: 'phone_group', type=1, flags=1, data=phone
06/13 22:42:23 yS0 key: 'phone_mode', type=0, flags=1, data=432
06/13 22:42:23 yS0 key: 'message_flag_file', type=1, flags=3,
data=.flag
06/13 22:42:23 yS0 key: 'receive_dir', type=1, flags=3, data=incoming
06/13 22:42:23 yS0 key: 'message_dir', type=1, flags=3, data=messages
06/13 22:42:23 yS0 key: 'message_list', type=1, flags=3, data=Index
06/13 22:42:23 yS0 key: 'backup_message', type=1, flags=3,
data=standard.rmd
06/13 22:42:23 yS0 key: 'button_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'call_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
06/13 22:42:23 yS0 key: 'message_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'do_message_light', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'pre_message', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beepsound', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beep_frequency', type=0, flags=3, data=933
06/13 22:42:23 yS0 key: 'beep_length', type=0, flags=3, data=1500
06/13 22:42:23 yS0 key: 'max_tries', type=0, flags=3, data=3
06/13 22:42:23 yS0 key: 'retry_delay', type=0, flags=3, data=5
06/13 22:42:23 yS0 key: 'dialout_timeout', type=0, flags=1, data=90
06/13 22:42:23 yS0 key: 'ringback_goes_away', type=0, flags=1,
data=70
06/13 22:42:23 yS0 key: 'ringback_never_came', type=0, flags=1,
data=100
06/13 22:42:23 yS0 key: 'ring_report_delay', type=0, flags=3, data=15
06/13 22:42:23 yS0 key: 'voice_devices', type=1, flags=1, data=
06/13 22:42:23 yS0 reading port ttyS0 configuration from config file
/usr/local/etc/mgetty+sendfax/voice.conf
06/13 22:42:23 yS0 reading
/usr/local/etc/mgetty+sendfax/voice.conf...
06/13 22:42:23 yS0 conf lib: read: 'part generic'
06/13 22:42:23 yS0 found CT_KEYWORD part generic
06/13 22:42:23 yS0 conf lib: read: 'voice_log_level 6'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
06/13 22:42:23 yS0 conf lib: read: 'voice_dir /var/spool/voice'
06/13 22:42:23 yS0 conf lib: read: 'message_flag_file .flag'
06/13 22:42:23 yS0 conf lib: read: 'receive_dir incoming'
06/13 22:42:23 yS0 conf lib: read: 'message_dir messages'
06/13 22:42:23 yS0 conf lib: read: 'message_list Index'
06/13 22:42:23 yS0 conf lib: read: 'backup_message standard.rmd'
06/13 22:42:23 yS0 conf lib: read: 'port_speed 115200'
06/13 22:42:23 yS0 conf lib: read: 'voice_shell /usr/bin/perl'
06/13 22:42:23 yS0 conf lib: read: 'port_timeout 10'
06/13 22:42:23 yS0 conf lib: read: 'dial_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'command_delay 100'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_len 30'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'dtmf_wait 7'
06/13 22:42:23 yS0 conf lib: read: 'ignore_fax_dle false'
06/13 22:42:23 yS0 conf lib: read: 'raw_data false'
06/13 22:42:23 yS0 conf lib: read: 'rec_compression 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_speed 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_len 70'
06/13 22:42:23 yS0 conf lib: read: 'rec_silence_threshold 40'
06/13 22:42:23 yS0 conf lib: read: 'rec_remove_silence false'
06/13 22:42:23 yS0 conf lib: read: 'rec_max_len 300'
06/13 22:42:23 yS0 conf lib: read: 'rec_min_len 0'
06/13 22:42:23 yS0 conf lib: read: 'do_hard_flow true'
06/13 22:42:23 yS0 conf lib: read: 'beep_frequency 933'
06/13 22:42:23 yS0 conf lib: read: 'beep_length 1500'
06/13 22:42:23 yS0 conf lib: read: 'max_tries 3'
06/13 22:42:23 yS0 conf lib: read: 'retry_delay 5'
06/13 22:42:23 yS0 conf lib: read: 'watchdog_timeout 60'
06/13 22:42:23 yS0 conf lib: read: 'receive_gain -1'
06/13 22:42:23 yS0 conf lib: read: 'transmit_gain 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_command_echo true'
06/13 22:42:23 yS0 conf lib: read: 'poll_interval 10'
06/13 22:42:23 yS0 conf lib: read: 'enable_compression_mapping_querry
FALSE'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_signed 0'
06/13 22:42:23 yS0 conf lib: read: 'compression_16bit_linear_signed
0'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_linear_unsigned
1'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_ulaw 4'
06/13 22:42:23 yS0 conf lib: read: 'compression_8bit_alaw 5'
06/13 22:42:23 yS0 conf lib: read: 'compression_2bit_adpcm 140'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_adpcm 141'
06/13 22:42:23 yS0 conf lib: read: 'compression_4bit_ima_adpcm 129'
06/13 22:42:23 yS0 conf lib: read: 'program vgetty'
06/13 22:42:23 yS0 conf lib: read: 'rings 5'
06/13 22:42:23 yS0 conf lib: read: 'answer_mode voice:fax:data'
06/13 22:42:23 yS0 conf lib: read: 'force_autodetect false'
06/13 22:42:23 yS0 conf lib: read: 'toll_saver_rings 0'
06/13 22:42:23 yS0 conf lib: read: 'rec_always_keep true'
06/13 22:42:23 yS0 conf lib: read: 'button_program '
06/13 22:42:23 yS0 conf lib: read: 'call_program '
06/13 22:42:23 yS0 conf lib: read: 'dtmf_program dtmf.sh'
06/13 22:42:23 yS0 conf lib: read: 'message_program '
06/13 22:42:23 yS0 conf lib: read: 'do_message_light false'
06/13 22:42:23 yS0 conf lib: read: 'ring_report_delay 15'
06/13 22:42:23 yS0 conf lib: read: 'program vm'
06/13 22:42:23 yS0 conf lib: read: 'voice_devices ttyS0'
06/13 22:42:23 yS0 conf lib: read: 'dialout_timeout 90'
06/13 22:42:23 yS0 conf lib: read: 'ringback_goes_away 70'
06/13 22:42:23 yS0 conf lib: read: 'ringback_never_came 100'
06/13 22:42:23 yS0 conf lib: read: 'program pvf'
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 section: port ttyS0, **found**
06/13 22:42:23 yS0 conf lib: read: 'ring_type virtual'
06/13 22:42:23 yS0 found CT_KEYWORD ring_type virtual
06/13 22:42:23 yS0 conf lib: read: 'answer_mode fax:data'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring'
06/13 22:42:23 yS0 conf lib: read: 'ring_type ring1'
06/13 22:42:23 yS0 conf lib: read: 'port ttyS0'
06/13 22:42:23 yS0 section: port ttyS0, **found**
06/13 22:42:23 yS0 conf lib: read: 'force_detect V253modem'
06/13 22:42:23 yS0 something foul in config line: 'force_detect
V253modem'
06/13 22:42:23 yS0 (keyword 'force_detect' not found)
06/13 22:42:23 yS0 key: 'part', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'program', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'port', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'ring_type', type=6, flags=4, data=(ignored)
06/13 22:42:23 yS0 key: 'voice_log_level', type=0, flags=3, data=6
06/13 22:42:23 yS0 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
06/13 22:42:23 yS0 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
06/13 22:42:23 yS0 key: 'port_speed', type=0, flags=3, data=115200
06/13 22:42:23 yS0 key: 'port_timeout', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'dial_timeout', type=0, flags=3, data=90
06/13 22:42:23 yS0 key: 'command_delay', type=0, flags=3, data=100
06/13 22:42:23 yS0 key: 'dtmf_len', type=0, flags=3, data=30
06/13 22:42:23 yS0 key: 'dtmf_threshold', type=0, flags=3, data=40
06/13 22:42:23 yS0 key: 'dtmf_wait', type=0, flags=3, data=7
06/13 22:42:23 yS0 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'raw_data', type=3, flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'rec_compression', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_speed', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_silence_len', type=0, flags=3, data=70
06/13 22:42:23 yS0 key: 'rec_silence_threshold', type=0, flags=3,
data=40
06/13 22:42:23 yS0 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'rec_max_len', type=0, flags=3, data=300
06/13 22:42:23 yS0 key: 'rec_min_len', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'do_hard_flow', type=3, flags=3, data=TRUE
06/13 22:42:23 yS0 key: 'force_autodetect', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'watchdog_timeout', type=0, flags=3, data=60
06/13 22:42:23 yS0 key: 'receive_gain', type=0, flags=3, data=-1
06/13 22:42:23 yS0 key: 'transmit_gain', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'enable_command_echo', type=3, flags=3,
data=TRUE
06/13 22:42:23 yS0 key: 'poll_interval', type=0, flags=3, data=10
06/13 22:42:23 yS0 key: 'forceV253', type=3, flags=1, data=FALSE
06/13 22:42:23 yS0 key: 'forceV253subset', type=3, flags=1,
data=FALSE
06/13 22:42:23 yS0 key: 'enable_compression_mapping_querry', type=3,
flags=3, data=FALSE
06/13 22:42:23 yS0 key: 'compression_8bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_16bit_linear_signed', type=0,
flags=3, data=0
06/13 22:42:23 yS0 key: 'compression_8bit_linear_unsigned', type=0,
flags=3, data=1
06/13 22:42:23 yS0 key: 'compression_8bit_ulaw', type=0, flags=3,
data=4
06/13 22:42:23 yS0 key: 'compression_8bit_alaw', type=0, flags=3,
data=5
06/13 22:42:23 yS0 key: 'compression_2bit_adpcm', type=0, flags=3,
data=140
06/13 22:42:23 yS0 key: 'compression_4bit_adpcm', type=0, flags=3,
data=141
06/13 22:42:23 yS0 key: 'compression_4bit_ima_adpcm', type=0,
flags=3, data=129
06/13 22:42:23 yS0 key: 'rings', type=1, flags=3, data=5
06/13 22:42:23 yS0 key: 'answer_mode', type=1, flags=3,
data=voice:fax:data
06/13 22:42:23 yS0 key: 'toll_saver_rings', type=0, flags=3, data=0
06/13 22:42:23 yS0 key: 'rec_always_keep', type=3, flags=3, data=TRUE
06/13 22:42:23 yS0 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
06/13 22:42:23 yS0 key: 'phone_owner', type=1, flags=1, data=root
06/13 22:42:23 yS0 key: 'phone_group', type=1, flags=1, data=phone
06/13 22:42:23 yS0 key: 'phone_mode', type=0, flags=1, data=432
06/13 22:42:23 yS0 key: 'message_flag_file', type=1, flags=3,
data=.flag
06/13 22:42:23 yS0 key: 'receive_dir', type=1, flags=3, data=incoming
06/13 22:42:23 yS0 key: 'message_dir', type=1, flags=3, data=messages
06/13 22:42:23 yS0 key: 'message_list', type=1, flags=3, data=Index
06/13 22:42:23 yS0 key: 'backup_message', type=1, flags=3,
data=standard.rmd
06/13 22:42:23 yS0 key: 'button_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'call_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
06/13 22:42:23 yS0 key: 'message_program', type=1, flags=3, data=
06/13 22:42:23 yS0 key: 'do_message_light', type=3, flags=3,
data=FALSE
06/13 22:42:23 yS0 key: 'pre_message', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beepsound', type=1, flags=1, data=
06/13 22:42:23 yS0 key: 'beep_frequency', type=0, flags=3, data=933
06/13 22:42:23 yS0 key: 'beep_length', type=0, flags=3, data=1500
06/13 22:42:23 yS0 key: 'max_tries', type=0, flags=3, data=3
06/13 22:42:23 yS0 key: 'retry_delay', type=0, flags=3, data=5
06/13 22:42:23 yS0 key: 'dialout_timeout', type=0, flags=1, data=90
06/13 22:42:23 yS0 key: 'ringback_goes_away', type=0, flags=1,
data=70
06/13 22:42:23 yS0 key: 'ringback_never_came', type=0, flags=1,
data=100
06/13 22:42:23 yS0 key: 'ring_report_delay', type=0, flags=3, data=15
06/13 22:42:23 yS0 key: 'voice_devices', type=1, flags=1, data=
06/13 22:42:23 yS0 check for lockfiles
06/13 22:42:23 yS0 checklock: stat failed, no file
06/13 22:42:23 yS0 locking the line
06/13 22:42:23 yS0 makelock(ttyS0) called
06/13 22:42:23 yS0 do_makelock: lock='/var/lock/LCK..ttyS0'
06/13 22:42:23 yS0 lock made
06/13 22:42:24 yS0 tio_get_rs232_lines: status: RTS CTS DSR DTR
06/13 22:42:24 yS0 lowering DTR to reset Modem
06/13 22:42:24 yS0 tss: set speed to 115200 (10002)
06/13 22:42:24 yS0 tio_set_flow_control( HARD )
06/13 22:42:24 yS0 waiting for line to clear (VTIME=1), read:
06/13 22:42:24 yS0 send: \dATQ0V1H0[0d]
06/13 22:42:25 yS0 waiting for ``OK''
06/13 22:42:25 yS0 got: ATQ0V1H0[0d]
06/13 22:42:25 yS0 CND: ATQ0V1H0[0d][0a]OK ** found **
06/13 22:42:25 yS0 send: ATS0=0Q0&D3&C1[0d]
06/13 22:42:25 yS0 waiting for ``OK''
06/13 22:42:25 yS0 got: [0d]
06/13 22:42:25 yS0 CND: OK[0a]ATS0=0Q0&D3&C1[0d]
06/13 22:42:25 yS0 CND: ATS0=0Q0&D3&C1[0d][0a]OK ** found **
06/13 22:42:25 yS0 mdm_send: 'ATI'
06/13 22:42:25 yS0 got:[0d][0a]ATI[0d]
06/13 22:42:25 yS0 got:[0d][0a]56000[0d]
06/13 22:42:25 yS0 mdm_gis: string 1: '56000'
06/13 22:42:25 yS0 got:[0a][0d][0a]OK[0d]
06/13 22:42:25 yS0 mdm_identify: string '56000'
06/13 22:42:25 yS0 Generic Rockwell modem (56000)
06/13 22:42:25 yS0 mdm_send: 'ATI3'
06/13 22:42:25 yS0 got:[0a]ATI3[0d]
06/13 22:42:25 yS0 got:[0d][0a]Version 7.00 [0d]
06/13 22:42:25 yS0 mdm_gis: string 1: 'Version 7.00 '
06/13 22:42:25 yS0 got:[0a][0d][0a]OK[0d]
06/13 22:42:25 yS0 mdm_send: 'ATI4'
06/13 22:42:25 yS0 got:[0a]ATI4[0d]
06/13 22:42:25 yS0 got:[0d][0a]a125843FA848D70EF0810700[0d]
06/13 22:42:26 yS0 mdm_gis: string 1: 'a125843FA848D70EF0810700'
06/13 22:42:26 yS0 got:[0a][0d][0a]bC60004000[0d]
06/13 22:42:26 yS0 mdm_gis: string 2: 'bC60004000'
06/13 22:42:26 yS0 got:[0a][0d][0a]r102111115111200C0[0d]
06/13 22:42:26 yS0 mdm_gis: string 3: 'r102111115111200C0'
06/13 22:42:26 yS0 got:[0a][0d][0a]r30001111FF7000000[0d]
06/13 22:42:26 yS0 mdm_gis: string 4: 'r30001111FF7000000'
06/13 22:42:26 yS0 got:[0a][0d][0a]OK[0d]
06/13 22:42:26 yS0 additional info: 'a125843FA848D70EF0810700'
06/13 22:42:26 yS0 modem quirks: 0004
06/13 22:42:26 yS0 mdm_send: 'AT+FCLASS=2'
06/13 22:42:26 yS0 got:[0a]AT+FCLASS=2[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FCLASS=2'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 mdm_send: 'AT+FCLASS=0'
06/13 22:42:26 yS0 got:[0a]AT+FCLASS=0[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FCLASS=0'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 mdm_send: 'AT+FAA=1;+FCR=1'
06/13 22:42:26 yS0 got:[0a]AT+FAA=1;+FCR=1[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FAA=1;+FCR=1'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 mdm_send: 'AT+FBOR=0'
06/13 22:42:26 yS0 got:[0a]AT+FBOR=0[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FBOR=0'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 mdm_send: 'AT+FLID="01 123 1234567"'
06/13 22:42:26 yS0 got:[0a]AT+FLID="01 123 1234567"[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FLID="01 123 1234567"'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
06/13 22:42:26 yS0 got:[0a]AT+FDCC=1,5,0,2,0,0,0,0[0d]
06/13 22:42:26 yS0 mdm_command: string 'AT+FDCC=1,5,0,2,0,0,0,0'
06/13 22:42:26 yS0 got:[0d][0a]OK[0d]
06/13 22:42:26 yS0 mdm_command: string 'OK' -> OK
06/13 22:42:26 yS0 tss: set speed to 115200 (10002)
06/13 22:42:26 yS0 tss: set speed to 115200 (10002)
06/13 22:42:26 yS0 tio_set_flow_control( HARD )
06/13 22:42:26 yS0 detecting voice modem type
06/13 22:42:26 yS0 vgetty: ATE1
06/13 22:42:26 yS0 voice command: '' -> 'OK|ATE1'
06/13 22:42:26 yS0 serial port: ATE1
06/13 22:42:26 yS0 serial port: OK
06/13 22:42:27 yS0 voice command: 'ATI9' -> ''
06/13 22:42:27 yS0 vgetty: ATI9
06/13 22:42:27 yS0 serial port: ATI9
06/13 22:42:27 yS0 serial port: (1.00HAY5362\\MODEM\\Hayes OPTIMA
56K, 5362US/HK 6A)
06/13 22:42:27 yS0 PNP String: 'HAY5362\\MODEM\\Hayes OPTIMA 56K,
5362US/HK 6A)'
06/13 22:42:27 yS0 checking pnpid SUP / modelid <none>
06/13 22:42:27 yS0 checking pnpid ZYX / modelid 02FF
06/13 22:42:27 yS0 checking pnpid USR / modelid 0088
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0687
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0566
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0707
06/13 22:42:27 yS0 checking pnpid ELS / modelid 8318
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0853
06/13 22:42:27 yS0 checking pnpid ELS / modelid 8548
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0754
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0350
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0503
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0667
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0152
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0363
06/13 22:42:27 yS0 checking pnpid ELS / modelid 0862
06/13 22:42:27 yS0 checking pnpid ELS / modelid 6026
06/13 22:42:27 yS0 checking pnpid ELS / modelid 6027
06/13 22:42:27 yS0 serial port: OK
06/13 22:42:27 yS0 voice command: 'ATI3' -> ''
06/13 22:42:27 yS0 vgetty: ATI3
06/13 22:42:27 yS0 serial port: ATI3
06/13 22:42:27 yS0 serial port: Version 7.00
06/13 22:42:27 yS0 serial port: OK
06/13 22:42:27 yS0 voice command: 'ATI' -> ''
06/13 22:42:27 yS0 vgetty: ATI
06/13 22:42:27 yS0 serial port: ATI
06/13 22:42:28 yS0 serial port: 56000
06/13 22:42:28 yS0 Rockwell: OK
06/13 22:42:28 yS0 Rockwell detected
06/13 22:42:28 yS0 vgetty: entering voice mode
06/13 22:42:28 yS0 vgetty: Installing signal handlers
06/13 22:42:28 yS0 voice command: 'AT#CLS?' -> ''
06/13 22:42:28 yS0 vgetty: AT#CLS?
06/13 22:42:28 yS0 Rockwell: AT#CLS?
06/13 22:42:28 yS0 Rockwell: 0
06/13 22:42:28 yS0 voice command: '' -> 'OK'
06/13 22:42:28 yS0 Rockwell: OK
06/13 22:42:28 yS0 voice command: 'AT#CLS=8' -> 'OK'
06/13 22:42:28 yS0 vgetty: AT#CLS=8
06/13 22:42:28 yS0 Rockwell: AT#CLS=8
06/13 22:42:28 yS0 Rockwell: OK
06/13 22:42:28 yS0 voice command: 'AT' -> 'OK'
06/13 22:42:28 yS0 vgetty: AT
06/13 22:42:28 yS0 Rockwell: AT
06/13 22:42:28 yS0 Rockwell: OK
06/13 22:42:28 yS0 vgetty: queued event RESET_WATCHDOG at position
0000
06/13 22:42:28 yS0 initializing ROCKWELL voice modem
06/13 22:42:28 yS0 voice command: 'AT#VSP=70' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#VSP=70
06/13 22:42:29 yS0 vgetty: unqueued event RESET_WATCHDOG at position
0000
06/13 22:42:29 yS0 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
06/13 22:42:29 yS0 Rockwell: AT#VSP=70
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT#TL=1999' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#TL=1999
06/13 22:42:29 yS0 Rockwell: AT#TL=1999
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT#RG=8000' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#RG=8000
06/13 22:42:29 yS0 Rockwell: AT#RG=8000
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT#VSD=0' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#VSD=0
06/13 22:42:29 yS0 Rockwell: AT#VSD=0
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#VTD=3F,3F,3F
06/13 22:42:29 yS0 Rockwell: AT#VTD=3F,3F,3F
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT#VSS=1' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#VSS=1
06/13 22:42:29 yS0 Rockwell: AT#VSS=1
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT&K3' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT&K3
06/13 22:42:29 yS0 Rockwell: AT&K3
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 tio_set_flow_control( HARD )
06/13 22:42:29 yS0 vgetty: leaving voice mode
06/13 22:42:29 yS0 voice command: 'AT#CLS=0' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT#CLS=0
06/13 22:42:29 yS0 Rockwell: AT#CLS=0
06/13 22:42:29 yS0 Rockwell: OK
06/13 22:42:29 yS0 voice command: 'AT' -> 'OK'
06/13 22:42:29 yS0 vgetty: AT
06/13 22:42:29 yS0 Rockwell: AT
06/13 22:42:30 yS0 Rockwell: OK
06/13 22:42:30 yS0 vgetty: Restoring signal handlers
06/13 22:42:30 yS0 waiting for line to clear (VTIME=3), read:
06/13 22:42:30 yS0 removing lock file
06/13 22:42:30 yS0 waiting...

The command 'vm play -H -x5 -v file.rmd' seems to engage the line, but
there is no sound.

06/13 22:48:53 yS0 select returned 1
06/13 22:48:53 yS0 checking lockfiles, locking the line
06/13 22:48:53 yS0 makelock(ttyS0) called
06/13 22:48:53 yS0 do_makelock: lock='/var/lock/LCK..ttyS0'
06/13 22:48:53 yS0 lock not made: lock file exists (pid=32389)
06/13 22:48:53 yS0 lock file exists (dialout)!
06/13 22:48:53 yS0 lockfile found, pid=32389
06/13 22:48:53 yS0 looking for utmp entry... (my PID: 32386)
06/13 22:48:53 yS0 lockfile found, pid=32389
06/13 22:49:03 yS0 lockfile found, pid=32389
06/13 22:49:13 yS0 lockfile found, pid=32389
06/13 22:49:23 yS0 lockfile found, pid=32389
06/13 22:49:33 yS0 lockfile found, pid=32389
06/13 22:49:43 yS0 lockfile found, pid=32389
06/13 22:49:53 yS0 lockfile found, pid=32389
06/13 22:50:03 yS0 lockfile found, pid=32389
06/13 22:50:13 yS0 lockfile found, pid=32389
06/13 22:50:23 yS0 lockfile found, pid=32389
06/13 22:50:33 yS0 checklock: stat failed, no file
06/13 22:50:38 yS0 checklock: stat failed, no file

Jamie

2006-06-14 13:20:07 UTC

Permalink

Finally, here are the contents of vm.log. Note the lines that read:

vm: timeout while writing buffer to voice modem

Any ideas?

Thanks,
Jamie

06/14 08:30:32 vgetty: experimental test release 0.9.32 / with duplex
patch
06/14 08:30:32 reading program vm configuration from config file
/usr/local/etc/mgetty+sendfax/voice.conf
06/14 08:30:32 reading /usr/local/etc/mgetty+sendfax/voice.conf...
06/14 08:30:32 conf lib: read: 'part generic'
06/14 08:30:32 found CT_KEYWORD part generic
06/14 08:30:32 conf lib: read: 'voice_log_level 6'
06/14 08:30:32 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
06/14 08:30:32 conf lib: read: 'voice_dir /var/spool/voice'
06/14 08:30:32 conf lib: read: 'message_flag_file .flag'
06/14 08:30:32 conf lib: read: 'receive_dir incoming'
06/14 08:30:32 conf lib: read: 'message_dir messages'
06/14 08:30:32 conf lib: read: 'message_list Index'
06/14 08:30:32 conf lib: read: 'backup_message standard.rmd'
06/14 08:30:32 conf lib: read: 'port_speed 38400'
06/14 08:30:32 conf lib: read: 'voice_shell /usr/bin/perl'
06/14 08:30:32 conf lib: read: 'port_timeout 10'
06/14 08:30:32 conf lib: read: 'dial_timeout 90'
06/14 08:30:32 conf lib: read: 'command_delay 100'
06/14 08:30:32 conf lib: read: 'dtmf_len 30'
06/14 08:30:32 conf lib: read: 'dtmf_threshold 40'
06/14 08:30:32 conf lib: read: 'dtmf_wait 7'
06/14 08:30:32 conf lib: read: 'ignore_fax_dle false'
06/14 08:30:32 conf lib: read: 'raw_data false'
06/14 08:30:32 conf lib: read: 'rec_compression 0'
06/14 08:30:32 conf lib: read: 'rec_speed 7200'
06/14 08:30:32 conf lib: read: 'rec_silence_len 70'
06/14 08:30:32 conf lib: read: 'rec_silence_threshold 40'
06/14 08:30:32 conf lib: read: 'rec_remove_silence false'
06/14 08:30:32 conf lib: read: 'rec_max_len 300'
06/14 08:30:32 conf lib: read: 'rec_min_len 0'
06/14 08:30:32 conf lib: read: 'do_hard_flow true'
06/14 08:30:32 conf lib: read: 'beep_frequency 933'
06/14 08:30:32 conf lib: read: 'beep_length 1500'
06/14 08:30:32 conf lib: read: 'max_tries 3'
06/14 08:30:32 conf lib: read: 'retry_delay 5'
06/14 08:30:32 conf lib: read: 'watchdog_timeout 60'
06/14 08:30:32 conf lib: read: 'receive_gain -1'
06/14 08:30:32 conf lib: read: 'transmit_gain -1'
06/14 08:30:32 conf lib: read: 'enable_command_echo true'
06/14 08:30:32 conf lib: read: 'poll_interval 10'
06/14 08:30:32 conf lib: read: 'enable_compression_mapping_querry
TRUE'
06/14 08:30:32 conf lib: read: 'compression_8bit_linear_signed 0'
06/14 08:30:32 conf lib: read: 'compression_16bit_linear_signed 0'
06/14 08:30:32 conf lib: read: 'compression_8bit_linear_unsigned 1'
06/14 08:30:32 conf lib: read: 'compression_8bit_ulaw 4'
06/14 08:30:32 conf lib: read: 'compression_8bit_alaw 5'
06/14 08:30:32 conf lib: read: 'compression_2bit_adpcm 140'
06/14 08:30:32 conf lib: read: 'compression_4bit_adpcm 141'
06/14 08:30:32 conf lib: read: 'compression_4bit_ima_adpcm 129'
06/14 08:30:32 conf lib: read: 'program vgetty'
06/14 08:30:32 section: program vgetty, ignore
06/14 08:30:32 conf lib: read: 'rings 5'
06/14 08:30:32 conf lib: read: 'answer_mode voice:fax:data'
06/14 08:30:32 conf lib: read: 'force_autodetect false'
06/14 08:30:32 conf lib: read: 'toll_saver_rings 0'
06/14 08:30:32 conf lib: read: 'rec_always_keep true'
06/14 08:30:32 conf lib: read: 'button_program '
06/14 08:30:32 conf lib: read: 'call_program '
06/14 08:30:32 conf lib: read: 'dtmf_program dtmf.sh'
06/14 08:30:32 conf lib: read: 'message_program '
06/14 08:30:32 conf lib: read: 'do_message_light false'
06/14 08:30:32 conf lib: read: 'ring_report_delay 15'
06/14 08:30:32 conf lib: read: 'program vm'
06/14 08:30:32 section: program vm, **found**
06/14 08:30:32 conf lib: read: 'voice_devices ttyS0'
06/14 08:30:32 conf lib: read: 'dialout_timeout 90'
06/14 08:30:32 conf lib: read: 'ringback_goes_away 70'
06/14 08:30:32 conf lib: read: 'ringback_never_came 100'
06/14 08:30:32 conf lib: read: 'program pvf'
06/14 08:30:32 section: program pvf, ignore
06/14 08:30:32 conf lib: read: 'port ttyS0'
06/14 08:30:32 conf lib: read: 'ring_type virtual'
06/14 08:30:32 conf lib: read: 'answer_mode fax:data'
06/14 08:30:32 conf lib: read: 'ring_type ring'
06/14 08:30:32 conf lib: read: 'ring_type ring1'
06/14 08:30:32 key: 'part', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'program', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'port', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'ring_type', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'voice_log_level', type=0, flags=3, data=6
06/14 08:30:32 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
06/14 08:30:32 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
06/14 08:30:32 key: 'port_speed', type=0, flags=3, data=38400
06/14 08:30:32 key: 'port_timeout', type=0, flags=3, data=10
06/14 08:30:32 key: 'dial_timeout', type=0, flags=3, data=90
06/14 08:30:32 key: 'command_delay', type=0, flags=3, data=100
06/14 08:30:32 key: 'dtmf_len', type=0, flags=3, data=30
06/14 08:30:32 key: 'dtmf_threshold', type=0, flags=3, data=40
06/14 08:30:32 key: 'dtmf_wait', type=0, flags=3, data=7
06/14 08:30:32 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'raw_data', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'rec_compression', type=0, flags=3, data=0
06/14 08:30:32 key: 'rec_speed', type=0, flags=3, data=7200
06/14 08:30:32 key: 'rec_silence_len', type=0, flags=3, data=70
06/14 08:30:32 key: 'rec_silence_threshold', type=0, flags=3, data=40
06/14 08:30:32 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'rec_max_len', type=0, flags=3, data=300
06/14 08:30:32 key: 'rec_min_len', type=0, flags=3, data=0
06/14 08:30:32 key: 'do_hard_flow', type=3, flags=3, data=TRUE
06/14 08:30:32 key: 'force_autodetect', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'watchdog_timeout', type=0, flags=3, data=60
06/14 08:30:32 key: 'receive_gain', type=0, flags=3, data=-1
06/14 08:30:32 key: 'transmit_gain', type=0, flags=3, data=-1
06/14 08:30:32 key: 'enable_command_echo', type=3, flags=3, data=TRUE
06/14 08:30:32 key: 'poll_interval', type=0, flags=3, data=10
06/14 08:30:32 key: 'forceV253', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'forceV253subset', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'enable_compression_mapping_querry', type=3,
flags=3, data=TRUE
06/14 08:30:32 key: 'compression_8bit_linear_signed', type=0,
flags=3, data=0
06/14 08:30:32 key: 'compression_16bit_linear_signed', type=0,
flags=3, data=0
06/14 08:30:32 key: 'compression_8bit_linear_unsigned', type=0,
flags=3, data=1
06/14 08:30:32 key: 'compression_8bit_ulaw', type=0, flags=3, data=4
06/14 08:30:32 key: 'compression_8bit_alaw', type=0, flags=3, data=5
06/14 08:30:32 key: 'compression_2bit_adpcm', type=0, flags=3,
data=140
06/14 08:30:32 key: 'compression_4bit_adpcm', type=0, flags=3,
data=141
06/14 08:30:32 key: 'compression_4bit_ima_adpcm', type=0, flags=3,
data=129
06/14 08:30:32 key: 'rings', type=1, flags=1, data=3
06/14 08:30:32 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
06/14 08:30:32 key: 'toll_saver_rings', type=0, flags=1, data=0
06/14 08:30:32 key: 'rec_always_keep', type=3, flags=1, data=TRUE
06/14 08:30:32 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
06/14 08:30:32 key: 'phone_owner', type=1, flags=1, data=root
06/14 08:30:32 key: 'phone_group', type=1, flags=1, data=phone
06/14 08:30:32 key: 'phone_mode', type=0, flags=1, data=432
06/14 08:30:32 key: 'message_flag_file', type=1, flags=3, data=.flag
06/14 08:30:32 key: 'receive_dir', type=1, flags=3, data=incoming
06/14 08:30:32 key: 'message_dir', type=1, flags=3, data=messages
06/14 08:30:32 key: 'message_list', type=1, flags=3, data=Index
06/14 08:30:32 key: 'backup_message', type=1, flags=3,
data=standard.rmd
06/14 08:30:32 key: 'button_program', type=1, flags=1, data=
06/14 08:30:32 key: 'call_program', type=1, flags=1, data=
06/14 08:30:32 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
06/14 08:30:32 key: 'message_program', type=1, flags=1, data=
06/14 08:30:32 key: 'do_message_light', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'pre_message', type=1, flags=1, data=
06/14 08:30:32 key: 'beepsound', type=1, flags=1, data=
06/14 08:30:32 key: 'beep_frequency', type=0, flags=3, data=933
06/14 08:30:32 key: 'beep_length', type=0, flags=3, data=1500
06/14 08:30:32 key: 'max_tries', type=0, flags=3, data=3
06/14 08:30:32 key: 'retry_delay', type=0, flags=3, data=5
06/14 08:30:32 key: 'dialout_timeout', type=0, flags=3, data=90
06/14 08:30:32 key: 'ringback_goes_away', type=0, flags=3, data=70
06/14 08:30:32 key: 'ringback_never_came', type=0, flags=3, data=100
06/14 08:30:32 key: 'ring_report_delay', type=0, flags=1, data=15
06/14 08:30:32 key: 'voice_devices', type=1, flags=3, data=ttyS0
06/14 08:30:32 opening voice modem device
06/14 08:30:32 voice open 'ttyS0'
06/14 08:30:32 trying device '/dev/ttyS0'
06/14 08:30:32 makelock(ttyS0) called
06/14 08:30:32 do_makelock: lock='/var/lock/LCK..ttyS0'
06/14 08:30:32 lock made
06/14 08:30:32 opened voice modem device /dev/ttyS0
06/14 08:30:32 reading port ttyS0 configuration from config file
/usr/local/etc/mgetty+sendfax/voice.conf
06/14 08:30:32 reading /usr/local/etc/mgetty+sendfax/voice.conf...
06/14 08:30:32 conf lib: read: 'part generic'
06/14 08:30:32 found CT_KEYWORD part generic
06/14 08:30:32 conf lib: read: 'voice_log_level 6'
06/14 08:30:32 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
06/14 08:30:32 conf lib: read: 'voice_dir /var/spool/voice'
06/14 08:30:32 conf lib: read: 'message_flag_file .flag'
06/14 08:30:32 conf lib: read: 'receive_dir incoming'
06/14 08:30:32 conf lib: read: 'message_dir messages'
06/14 08:30:32 conf lib: read: 'message_list Index'
06/14 08:30:32 conf lib: read: 'backup_message standard.rmd'
06/14 08:30:32 conf lib: read: 'port_speed 38400'
06/14 08:30:32 conf lib: read: 'voice_shell /usr/bin/perl'
06/14 08:30:32 conf lib: read: 'port_timeout 10'
06/14 08:30:32 conf lib: read: 'dial_timeout 90'
06/14 08:30:32 conf lib: read: 'command_delay 100'
06/14 08:30:32 conf lib: read: 'dtmf_len 30'
06/14 08:30:32 conf lib: read: 'dtmf_threshold 40'
06/14 08:30:32 conf lib: read: 'dtmf_wait 7'
06/14 08:30:32 conf lib: read: 'ignore_fax_dle false'
06/14 08:30:32 conf lib: read: 'raw_data false'
06/14 08:30:32 conf lib: read: 'rec_compression 0'
06/14 08:30:32 conf lib: read: 'rec_speed 7200'
06/14 08:30:32 conf lib: read: 'rec_silence_len 70'
06/14 08:30:32 conf lib: read: 'rec_silence_threshold 40'
06/14 08:30:32 conf lib: read: 'rec_remove_silence false'
06/14 08:30:32 conf lib: read: 'rec_max_len 300'
06/14 08:30:32 conf lib: read: 'rec_min_len 0'
06/14 08:30:32 conf lib: read: 'do_hard_flow true'
06/14 08:30:32 conf lib: read: 'beep_frequency 933'
06/14 08:30:32 conf lib: read: 'beep_length 1500'
06/14 08:30:32 conf lib: read: 'max_tries 3'
06/14 08:30:32 conf lib: read: 'retry_delay 5'
06/14 08:30:32 conf lib: read: 'watchdog_timeout 60'
06/14 08:30:32 conf lib: read: 'receive_gain -1'
06/14 08:30:32 conf lib: read: 'transmit_gain -1'
06/14 08:30:32 conf lib: read: 'enable_command_echo true'
06/14 08:30:32 conf lib: read: 'poll_interval 10'
06/14 08:30:32 conf lib: read: 'enable_compression_mapping_querry
TRUE'
06/14 08:30:32 conf lib: read: 'compression_8bit_linear_signed 0'
06/14 08:30:32 conf lib: read: 'compression_16bit_linear_signed 0'
06/14 08:30:32 conf lib: read: 'compression_8bit_linear_unsigned 1'
06/14 08:30:32 conf lib: read: 'compression_8bit_ulaw 4'
06/14 08:30:32 conf lib: read: 'compression_8bit_alaw 5'
06/14 08:30:32 conf lib: read: 'compression_2bit_adpcm 140'
06/14 08:30:32 conf lib: read: 'compression_4bit_adpcm 141'
06/14 08:30:32 conf lib: read: 'compression_4bit_ima_adpcm 129'
06/14 08:30:32 conf lib: read: 'program vgetty'
06/14 08:30:32 conf lib: read: 'rings 5'
06/14 08:30:32 conf lib: read: 'answer_mode voice:fax:data'
06/14 08:30:32 conf lib: read: 'force_autodetect false'
06/14 08:30:32 conf lib: read: 'toll_saver_rings 0'
06/14 08:30:32 conf lib: read: 'rec_always_keep true'
06/14 08:30:32 conf lib: read: 'button_program '
06/14 08:30:32 conf lib: read: 'call_program '
06/14 08:30:32 conf lib: read: 'dtmf_program dtmf.sh'
06/14 08:30:32 conf lib: read: 'message_program '
06/14 08:30:32 conf lib: read: 'do_message_light false'
06/14 08:30:32 conf lib: read: 'ring_report_delay 15'
06/14 08:30:32 conf lib: read: 'program vm'
06/14 08:30:32 conf lib: read: 'voice_devices ttyS0'
06/14 08:30:32 conf lib: read: 'dialout_timeout 90'
06/14 08:30:32 conf lib: read: 'ringback_goes_away 70'
06/14 08:30:32 conf lib: read: 'ringback_never_came 100'
06/14 08:30:32 conf lib: read: 'program pvf'
06/14 08:30:32 conf lib: read: 'port ttyS0'
06/14 08:30:32 section: port ttyS0, **found**
06/14 08:30:32 conf lib: read: 'ring_type virtual'
06/14 08:30:32 found CT_KEYWORD ring_type virtual
06/14 08:30:32 conf lib: read: 'answer_mode fax:data'
06/14 08:30:32 conf lib: read: 'ring_type ring'
06/14 08:30:32 conf lib: read: 'ring_type ring1'
06/14 08:30:32 key: 'part', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'program', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'port', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'ring_type', type=6, flags=4, data=(ignored)
06/14 08:30:32 key: 'voice_log_level', type=0, flags=3, data=6
06/14 08:30:32 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
06/14 08:30:32 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
06/14 08:30:32 key: 'port_speed', type=0, flags=3, data=38400
06/14 08:30:32 key: 'port_timeout', type=0, flags=3, data=10
06/14 08:30:32 key: 'dial_timeout', type=0, flags=3, data=90
06/14 08:30:32 key: 'command_delay', type=0, flags=3, data=100
06/14 08:30:32 key: 'dtmf_len', type=0, flags=3, data=30
06/14 08:30:32 key: 'dtmf_threshold', type=0, flags=3, data=40
06/14 08:30:32 key: 'dtmf_wait', type=0, flags=3, data=7
06/14 08:30:32 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'raw_data', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'rec_compression', type=0, flags=3, data=0
06/14 08:30:32 key: 'rec_speed', type=0, flags=3, data=7200
06/14 08:30:32 key: 'rec_silence_len', type=0, flags=3, data=70
06/14 08:30:32 key: 'rec_silence_threshold', type=0, flags=3, data=40
06/14 08:30:32 key: 'rec_remove_silence', type=3, flags=3, data=FALSE
06/14 08:30:32 key: 'rec_max_len', type=0, flags=3, data=300
06/14 08:30:32 key: 'rec_min_len', type=0, flags=3, data=0
06/14 08:30:32 key: 'do_hard_flow', type=3, flags=3, data=TRUE
06/14 08:30:32 key: 'force_autodetect', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'watchdog_timeout', type=0, flags=3, data=60
06/14 08:30:32 key: 'receive_gain', type=0, flags=3, data=-1
06/14 08:30:32 key: 'transmit_gain', type=0, flags=3, data=-1
06/14 08:30:32 key: 'enable_command_echo', type=3, flags=3, data=TRUE
06/14 08:30:32 key: 'poll_interval', type=0, flags=3, data=10
06/14 08:30:32 key: 'forceV253', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'forceV253subset', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'enable_compression_mapping_querry', type=3,
flags=3, data=TRUE
06/14 08:30:32 key: 'compression_8bit_linear_signed', type=0,
flags=3, data=0
06/14 08:30:32 key: 'compression_16bit_linear_signed', type=0,
flags=3, data=0
06/14 08:30:32 key: 'compression_8bit_linear_unsigned', type=0,
flags=3, data=1
06/14 08:30:32 key: 'compression_8bit_ulaw', type=0, flags=3, data=4
06/14 08:30:32 key: 'compression_8bit_alaw', type=0, flags=3, data=5
06/14 08:30:32 key: 'compression_2bit_adpcm', type=0, flags=3,
data=140
06/14 08:30:32 key: 'compression_4bit_adpcm', type=0, flags=3,
data=141
06/14 08:30:32 key: 'compression_4bit_ima_adpcm', type=0, flags=3,
data=129
06/14 08:30:32 key: 'rings', type=1, flags=1, data=3
06/14 08:30:32 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
06/14 08:30:32 key: 'toll_saver_rings', type=0, flags=1, data=0
06/14 08:30:32 key: 'rec_always_keep', type=3, flags=1, data=TRUE
06/14 08:30:32 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
06/14 08:30:32 key: 'phone_owner', type=1, flags=1, data=root
06/14 08:30:32 key: 'phone_group', type=1, flags=1, data=phone
06/14 08:30:32 key: 'phone_mode', type=0, flags=1, data=432
06/14 08:30:32 key: 'message_flag_file', type=1, flags=3, data=.flag
06/14 08:30:32 key: 'receive_dir', type=1, flags=3, data=incoming
06/14 08:30:32 key: 'message_dir', type=1, flags=3, data=messages
06/14 08:30:32 key: 'message_list', type=1, flags=3, data=Index
06/14 08:30:32 key: 'backup_message', type=1, flags=3,
data=standard.rmd
06/14 08:30:32 key: 'button_program', type=1, flags=1, data=
06/14 08:30:32 key: 'call_program', type=1, flags=1, data=
06/14 08:30:32 key: 'dtmf_program', type=1, flags=1, data=dtmf.sh
06/14 08:30:32 key: 'message_program', type=1, flags=1, data=
06/14 08:30:32 key: 'do_message_light', type=3, flags=1, data=FALSE
06/14 08:30:32 key: 'pre_message', type=1, flags=1, data=
06/14 08:30:32 key: 'beepsound', type=1, flags=1, data=
06/14 08:30:32 key: 'beep_frequency', type=0, flags=3, data=933
06/14 08:30:32 key: 'beep_length', type=0, flags=3, data=1500
06/14 08:30:32 key: 'max_tries', type=0, flags=3, data=3
06/14 08:30:32 key: 'retry_delay', type=0, flags=3, data=5
06/14 08:30:32 key: 'dialout_timeout', type=0, flags=3, data=90
06/14 08:30:32 key: 'ringback_goes_away', type=0, flags=3, data=70
06/14 08:30:32 key: 'ringback_never_came', type=0, flags=3, data=100
06/14 08:30:32 key: 'ring_report_delay', type=0, flags=1, data=15
06/14 08:30:32 key: 'voice_devices', type=1, flags=3, data=ttyS0
06/14 08:30:32 tss: set speed to 38400 (017)
06/14 08:30:32 tss: set speed to 38400 (017)
06/14 08:30:32 tio_set_flow_control( HARD )
06/14 08:30:32 detecting voice modem type
06/14 08:30:33 vm: ATE1
06/14 08:30:33 voice command: '' -> 'OK|ATE1'
06/14 08:30:33 serial port: ATE1
06/14 08:30:33 serial port: OK
06/14 08:30:33 voice command: 'ATI9' -> ''
06/14 08:30:33 vm: ATI9
06/14 08:30:33 serial port: ATI9
06/14 08:30:33 serial port: (1.00HAY5362\\MODEM\\Hayes OPTIMA 56K,
5362US/HK 6A)
06/14 08:30:33 PNP String: 'HAY5362\\MODEM\\Hayes OPTIMA 56K,
5362US/HK 6A)'
06/14 08:30:33 checking pnpid SUP / modelid <none>
06/14 08:30:33 checking pnpid ZYX / modelid 02FF
06/14 08:30:33 checking pnpid USR / modelid 0088
06/14 08:30:33 checking pnpid ELS / modelid 0687
06/14 08:30:33 checking pnpid ELS / modelid 0566
06/14 08:30:33 checking pnpid ELS / modelid 0707
06/14 08:30:33 checking pnpid ELS / modelid 8318
06/14 08:30:33 checking pnpid ELS / modelid 0853
06/14 08:30:33 checking pnpid ELS / modelid 8548
06/14 08:30:33 checking pnpid ELS / modelid 0754
06/14 08:30:33 checking pnpid ELS / modelid 0350
06/14 08:30:33 checking pnpid ELS / modelid 0503
06/14 08:30:33 checking pnpid ELS / modelid 0667
06/14 08:30:33 checking pnpid ELS / modelid 0152
06/14 08:30:33 checking pnpid ELS / modelid 0363
06/14 08:30:33 checking pnpid ELS / modelid 0862
06/14 08:30:33 checking pnpid ELS / modelid 6026
06/14 08:30:33 checking pnpid ELS / modelid 6027
06/14 08:30:33 serial port: OK
06/14 08:30:33 voice command: 'ATI3' -> ''
06/14 08:30:33 vm: ATI3
06/14 08:30:33 serial port: ATI3
06/14 08:30:33 serial port: Version 7.00
06/14 08:30:33 serial port: OK
06/14 08:30:34 voice command: 'ATI' -> ''
06/14 08:30:34 vm: ATI
06/14 08:30:34 serial port: ATI
06/14 08:30:34 serial port: 56000
06/14 08:30:34 Rockwell: OK
06/14 08:30:34 Rockwell detected
06/14 08:30:34 vm: entering voice mode
06/14 08:30:34 vm: Installing signal handlers
06/14 08:30:34 voice command: 'AT#CLS?' -> ''
06/14 08:30:34 vm: AT#CLS?
06/14 08:30:34 Rockwell: AT#CLS?
06/14 08:30:34 Rockwell: 0
06/14 08:30:34 voice command: '' -> 'OK'
06/14 08:30:34 Rockwell: OK
06/14 08:30:34 voice command: 'AT#CLS=8' -> 'OK'
06/14 08:30:34 vm: AT#CLS=8
06/14 08:30:34 Rockwell: AT#CLS=8
06/14 08:30:34 Rockwell: OK
06/14 08:30:34 voice command: 'AT' -> 'OK'
06/14 08:30:35 vm: AT
06/14 08:30:35 Rockwell: AT
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 vm: queued event RESET_WATCHDOG at position 0000
06/14 08:30:35 initializing ROCKWELL voice modem
06/14 08:30:35 voice command: 'AT#VSP=70' -> 'OK'
06/14 08:30:35 vm: AT#VSP=70
06/14 08:30:35 vm: unqueued event RESET_WATCHDOG at position 0000
06/14 08:30:35 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
06/14 08:30:35 Rockwell: AT#VSP=70
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT#TL=8000' -> 'OK'
06/14 08:30:35 vm: AT#TL=8000
06/14 08:30:35 Rockwell: AT#TL=8000
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT#RG=8000' -> 'OK'
06/14 08:30:35 vm: AT#RG=8000
06/14 08:30:35 Rockwell: AT#RG=8000
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT#VSD=0' -> 'OK'
06/14 08:30:35 vm: AT#VSD=0
06/14 08:30:35 Rockwell: AT#VSD=0
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
06/14 08:30:35 vm: AT#VTD=3F,3F,3F
06/14 08:30:35 Rockwell: AT#VTD=3F,3F,3F
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT#VSS=1' -> 'OK'
06/14 08:30:35 vm: AT#VSS=1
06/14 08:30:35 Rockwell: AT#VSS=1
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 voice command: 'AT&K3' -> 'OK'
06/14 08:30:35 vm: AT&K3
06/14 08:30:35 Rockwell: AT&K3
06/14 08:30:35 Rockwell: OK
06/14 08:30:35 tio_set_flow_control( HARD )
06/14 08:30:35 vm: leaving voice mode
06/14 08:30:35 voice command: 'AT#CLS=0' -> 'OK'
06/14 08:30:36 vm: AT#CLS=0
06/14 08:30:36 Rockwell: AT#CLS=0
06/14 08:30:36 Rockwell: OK
06/14 08:30:36 voice command: 'AT' -> 'OK'
06/14 08:30:36 vm: AT
06/14 08:30:36 Rockwell: AT
06/14 08:30:36 Rockwell: OK
06/14 08:30:36 vm: Restoring signal handlers
06/14 08:30:36 vm: entering voice mode
06/14 08:30:36 vm: Installing signal handlers
06/14 08:30:36 voice command: 'AT#CLS?' -> ''
06/14 08:30:36 vm: AT#CLS?
06/14 08:30:36 Rockwell: AT#CLS?
06/14 08:30:36 Rockwell: 0
06/14 08:30:36 voice command: '' -> 'OK'
06/14 08:30:36 Rockwell: OK
06/14 08:30:36 voice command: 'AT#CLS=8' -> 'OK'
06/14 08:30:36 vm: AT#CLS=8
06/14 08:30:36 Rockwell: AT#CLS=8
06/14 08:30:36 Rockwell: OK
06/14 08:30:36 voice command: 'AT' -> 'OK'
06/14 08:30:36 vm: AT
06/14 08:30:36 Rockwell: AT
06/14 08:30:36 Rockwell: OK
06/14 08:30:36 vm: queued event RESET_WATCHDOG at position 0001
06/14 08:30:36 voice command: 'AT#VLS=1' -> 'VCON'
06/14 08:30:36 vm: AT#VLS=1
06/14 08:30:36 vm: unqueued event RESET_WATCHDOG at position 0001
06/14 08:30:36 vm: voice_handle_event got event RESET_WATCHDOG with
data <_>
06/14 08:30:36 Rockwell: AT#VLS=1
06/14 08:30:36 Rockwell: VCON
06/14 08:30:36 playing voice file rhs_test2.rmd
06/14 08:30:36 can't get group 'phone': Success
06/14 08:30:36 vm: raw modem data header found
06/14 08:30:36 vm: modem type Rockwell found
06/14 08:30:36 vm: compression method 0x0004, speed 7200, bits 4
06/14 08:30:36 vm: queued event RESET_WATCHDOG at position 0002
06/14 08:30:36 voice command: 'AT#VBS=4' -> 'OK'
06/14 08:30:37 vm: AT#VBS=4
06/14 08:30:37 vm: unqueued event RESET_WATCHDOG at position 0002
06/14 08:30:37 vm: voice_handle_event got event RESET_WATCHDOG with
data <NUL>
06/14 08:30:37 Rockwell: AT#VBS=4
06/14 08:30:37 Rockwell: OK
06/14 08:30:37 vm: queued event RESET_WATCHDOG at position 0003
06/14 08:30:37 vm: unqueued event RESET_WATCHDOG at position 0003
06/14 08:30:37 vm: voice_handle_event got event RESET_WATCHDOG with
data <NUL>
06/14 08:30:37 voice command: 'AT&K3' -> 'OK'
06/14 08:30:37 vm: AT&K3
06/14 08:30:37 Rockwell: <DLE> <t>
06/14 08:30:37 vm: queued event HANDSET_OFF_HOOK at position 0004
06/14 08:30:37 Rockwell:
06/14 08:30:37 Rockwell: AT&K3
06/14 08:30:37 Rockwell: OK
06/14 08:30:37 tio_set_flow_control( HARD XON_OUT )
06/14 08:30:37 voice command: 'AT#VTX' -> 'CONNECT'
06/14 08:30:37 vm: AT#VTX
06/14 08:30:37 vm: unqueued event HANDSET_OFF_HOOK at position 0004
06/14 08:30:37 vm: voice_handle_event got event HANDSET_OFF_HOOK
with data <NUL>
06/14 08:30:37 Rockwell: AT#VTX
06/14 08:30:37 Rockwell: CONNECT
06/14 08:30:52 vm: timeout while writing buffer to voice modem
06/14 08:30:52 vm: play_file command failed
06/14 08:30:52 vm: queued event RESET_WATCHDOG at position 0005
06/14 08:30:52 voice command: 'ATH0' -> 'VCON|OK'
06/14 08:30:52 vm: ATH0
06/14 08:30:52 vm: unqueued event RESET_WATCHDOG at position 0005
06/14 08:30:52 vm: voice_handle_event got event RESET_WATCHDOG with
data <NUL>
06/14 08:31:03 vm: timeout while writing buffer to voice modem
06/14 08:31:03 voice command: 'AT#CLS=8' -> 'OK'
06/14 08:31:03 vm: AT#CLS=8
06/14 08:31:14 vm: timeout while writing buffer to voice modem
06/14 08:31:14 voice command: 'AT#VLS=0' -> 'OK'
06/14 08:31:14 vm: AT#VLS=0
06/14 08:31:25 vm: timeout while writing buffer to voice modem
06/14 08:31:25 vm: leaving voice mode
06/14 08:31:25 voice command: 'AT#CLS=0' -> 'OK'
06/14 08:31:25 vm: AT#CLS=0
06/14 08:31:36 vm: timeout while writing buffer to voice modem
06/14 08:31:36 vm: Restoring signal handlers
06/14 08:31:36 closing voice modem device

Juergen Kosel

2006-06-20 20:21:35 UTC

Permalink

Post by Jamie
vm: timeout while writing buffer to voice modem
Any ideas?
06/14 08:30:37 Rockwell: AT#VBS=4
06/14 08:30:37 Rockwell: OK
06/14 08:30:37 vm: queued event RESET_WATCHDOG at position 0003
06/14 08:30:37 vm: unqueued event RESET_WATCHDOG at position 0003
06/14 08:30:37 vm: voice_handle_event got event RESET_WATCHDOG with
data <NUL>
06/14 08:30:37 voice command: 'AT&K3' -> 'OK'
06/14 08:30:37 vm: AT&K3
06/14 08:30:37 Rockwell: <DLE> <t>
06/14 08:30:37 vm: queued event HANDSET_OFF_HOOK at position 0004
06/14 08:30:37 Rockwell: AT&K3
06/14 08:30:37 Rockwell: OK
06/14 08:30:37 tio_set_flow_control( HARD XON_OUT )
06/14 08:30:37 voice command: 'AT#VTX' -> 'CONNECT'
06/14 08:30:37 vm: AT#VTX
06/14 08:30:37 vm: unqueued event HANDSET_OFF_HOOK at position 0004
06/14 08:30:37 vm: voice_handle_event got event HANDSET_OFF_HOOK
with data <NUL>

Your modem has reported, that you manually picked up the phone.
Therefore vm droped the phone line, so that a human could use the phone.

Since many modems don't have a (phone line) independent speaker, you
should start with vgetty using as phone awnsering machine, instead of
using vm play.

Greetings
Juergen