vgetty + VOCP + pppd [AutoPPP] (CONTINUED)

[A***@yahoo.com]

I am still trying to figure out the issue with vgetty + DTMF + pppd.

I have successfully estabilished data connections with 3 different
modems using mgetty. However, when I switch to vgetty using DTMF 'D'
tones to signal vgetty to drop into data modem, it appears that vgetty
eventually timesout waiting for CONNECT and responds with NO CARRIER.

I can hear the client-side modem send the DTMF 'D' tones to drop vgetty
into data modem and then begin to try to negotiate a data connection,
but vgetty eventually hangs up.

The following is a very verbose log of the unsuccessfull data
connection using vgetty.

11/07 13:09:01 yS4 vgetty: experimental test release 0.9.33 / 26Dec02
11/07 13:09:01 yS4 mgetty: experimental test release 1.1.30-Dec16
11/07 13:09:01 yS4 reading generic configuration from config file
/etc/mgetty+sendfax/voice.conf
11/07 13:09:01 yS4 reading program vgetty configuration from config
file /etc/mgetty+sendfax/voice.conf
11/07 13:09:01 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/07 13:09:01 yS4 conf lib: read: 'part generic'
11/07 13:09:01 yS4 found CT_KEYWORD part generic
11/07 13:09:01 yS4 conf lib: read: 'voice_log_level 6'
11/07 13:09:01 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/07 13:09:01 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/07 13:09:01 yS4 conf lib: read: 'phone_owner uucp'
11/07 13:09:01 yS4 conf lib: read: 'phone_group uucp'
11/07 13:09:01 yS4 conf lib: read: 'phone_mode 0660'
11/07 13:09:01 yS4 conf lib: read: 'message_flag_file .flag'
11/07 13:09:01 yS4 conf lib: read: 'receive_dir incoming'
11/07 13:09:01 yS4 conf lib: read: 'message_dir messages'
11/07 13:09:01 yS4 conf lib: read: 'message_list Index'
11/07 13:09:01 yS4 conf lib: read: 'backup_message standard.rmd'
11/07 13:09:01 yS4 conf lib: read: 'port_speed 38400'
11/07 13:09:01 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/07 13:09:01 yS4 conf lib: read: 'port_timeout 10'
11/07 13:09:01 yS4 conf lib: read: 'dial_timeout 90'
11/07 13:09:01 yS4 conf lib: read: 'command_delay 100'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_len 30'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_threshold 40'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_wait 7'
11/07 13:09:01 yS4 conf lib: read: 'ignore_fax_dle false'
11/07 13:09:01 yS4 conf lib: read: 'raw_data false'
11/07 13:09:01 yS4 conf lib: read: 'rec_compression 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_speed 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_silence_len 70'
11/07 13:09:01 yS4 conf lib: read: 'rec_silence_threshold 40'
11/07 13:09:01 yS4 conf lib: read: 'rec_remove_silence false'
11/07 13:09:01 yS4 conf lib: read: 'rec_max_len 300'
11/07 13:09:01 yS4 conf lib: read: 'rec_min_len 5'
11/07 13:09:01 yS4 conf lib: read: 'do_hard_flow true'
11/07 13:09:01 yS4 conf lib: read: 'beep_frequency 933'
11/07 13:09:01 yS4 conf lib: read: 'beep_length 1500'
11/07 13:09:01 yS4 conf lib: read: 'max_tries 3'
11/07 13:09:01 yS4 conf lib: read: 'retry_delay 5'
11/07 13:09:01 yS4 conf lib: read: 'watchdog_timeout 60'
11/07 13:09:01 yS4 conf lib: read: 'receive_gain 100%'
11/07 13:09:01 yS4 conf lib: read: 'transmit_gain 100%'
11/07 13:09:01 yS4 conf lib: read: 'enable_command_echo false'
11/07 13:09:01 yS4 conf lib: read: 'poll_interval 10'
11/07 13:09:01 yS4 conf lib: read: 'program vgetty'
11/07 13:09:01 yS4 section: program vgetty, **found**
11/07 13:09:01 yS4 conf lib: read: 'rings 3'
11/07 13:09:01 yS4 conf lib: read: 'force_autodetect false'
11/07 13:09:01 yS4 conf lib: read: 'toll_saver_rings 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_always_keep true'
11/07 13:09:01 yS4 conf lib: read: 'button_program '
11/07 13:09:01 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/07 13:09:01 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/07 13:09:01 yS4 conf lib: read: 'do_message_light false'
11/07 13:09:01 yS4 conf lib: read: 'ring_report_delay 15'
11/07 13:09:01 yS4 conf lib: read: 'program vm'
11/07 13:09:01 yS4 section: program vm, ignore
11/07 13:09:01 yS4 conf lib: read: 'voice_devices ttyS4'
11/07 13:09:01 yS4 conf lib: read: 'dialout_timeout 90'
11/07 13:09:01 yS4 conf lib: read: 'ringback_goes_away 70'
11/07 13:09:01 yS4 conf lib: read: 'ringback_never_came 100'
11/07 13:09:01 yS4 conf lib: read: 'program pvf'
11/07 13:09:01 yS4 section: program pvf, ignore
11/07 13:09:01 yS4 conf lib: read: 'port ttyS4'
11/07 13:09:01 yS4 conf lib: read: 'ring_type virtual'
11/07 13:09:01 yS4 conf lib: read: 'answer_mode fax:data'
11/07 13:09:01 yS4 conf lib: read: 'ring_type ring2'
11/07 13:09:01 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/07 13:09:01 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/07 13:09:01 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/07 13:09:01 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/07 13:09:01 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/07 13:09:01 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/07 13:09:01 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/07 13:09:01 yS4 key: 'command_delay', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/07 13:09:01 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/07 13:09:01 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/07 13:09:01 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/07 13:09:01 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/07 13:09:01 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/07 13:09:01 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/07 13:09:01 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/07 13:09:01 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/07 13:09:01 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/07 13:09:01 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/07 13:09:01 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/07 13:09:01 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/07 13:09:01 yS4 key: 'rings', type=1, flags=3, data=3
11/07 13:09:01 yS4 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
11/07 13:09:01 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/07 13:09:01 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/07 13:09:01 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/07 13:09:01 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/07 13:09:01 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/07 13:09:01 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/07 13:09:01 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/07 13:09:01 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/07 13:09:01 yS4 key: 'message_list', type=1, flags=3, data=Index
11/07 13:09:01 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/07 13:09:01 yS4 key: 'button_program', type=1, flags=3, data=
11/07 13:09:01 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/07 13:09:01 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/07 13:09:01 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/07 13:09:01 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'pre_message', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'beepsound', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/07 13:09:01 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/07 13:09:01 yS4 key: 'max_tries', type=0, flags=3, data=3
11/07 13:09:01 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/07 13:09:01 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/07 13:09:01 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/07 13:09:01 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/07 13:09:01 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/07 13:09:01 yS4 key: 'voice_devices', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'force_detect', type=1, flags=1, data=
11/07 13:09:01 yS4 reading port ttyS4 configuration from config file
/etc/mgetty+sendfax/voice.conf
11/07 13:09:01 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/07 13:09:01 yS4 conf lib: read: 'part generic'
11/07 13:09:01 yS4 found CT_KEYWORD part generic
11/07 13:09:01 yS4 conf lib: read: 'voice_log_level 6'
11/07 13:09:01 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/07 13:09:01 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/07 13:09:01 yS4 conf lib: read: 'phone_owner uucp'
11/07 13:09:01 yS4 conf lib: read: 'phone_group uucp'
11/07 13:09:01 yS4 conf lib: read: 'phone_mode 0660'
11/07 13:09:01 yS4 conf lib: read: 'message_flag_file .flag'
11/07 13:09:01 yS4 conf lib: read: 'receive_dir incoming'
11/07 13:09:01 yS4 conf lib: read: 'message_dir messages'
11/07 13:09:01 yS4 conf lib: read: 'message_list Index'
11/07 13:09:01 yS4 conf lib: read: 'backup_message standard.rmd'
11/07 13:09:01 yS4 conf lib: read: 'port_speed 38400'
11/07 13:09:01 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/07 13:09:01 yS4 conf lib: read: 'port_timeout 10'
11/07 13:09:01 yS4 conf lib: read: 'dial_timeout 90'
11/07 13:09:01 yS4 conf lib: read: 'command_delay 100'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_len 30'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_threshold 40'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_wait 7'
11/07 13:09:01 yS4 conf lib: read: 'ignore_fax_dle false'
11/07 13:09:01 yS4 conf lib: read: 'raw_data false'
11/07 13:09:01 yS4 conf lib: read: 'rec_compression 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_speed 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_silence_len 70'
11/07 13:09:01 yS4 conf lib: read: 'rec_silence_threshold 40'
11/07 13:09:01 yS4 conf lib: read: 'rec_remove_silence false'
11/07 13:09:01 yS4 conf lib: read: 'rec_max_len 300'
11/07 13:09:01 yS4 conf lib: read: 'rec_min_len 5'
11/07 13:09:01 yS4 conf lib: read: 'do_hard_flow true'
11/07 13:09:01 yS4 conf lib: read: 'beep_frequency 933'
11/07 13:09:01 yS4 conf lib: read: 'beep_length 1500'
11/07 13:09:01 yS4 conf lib: read: 'max_tries 3'
11/07 13:09:01 yS4 conf lib: read: 'retry_delay 5'
11/07 13:09:01 yS4 conf lib: read: 'watchdog_timeout 60'
11/07 13:09:01 yS4 conf lib: read: 'receive_gain 100%'
11/07 13:09:01 yS4 conf lib: read: 'transmit_gain 100%'
11/07 13:09:01 yS4 conf lib: read: 'enable_command_echo false'
11/07 13:09:01 yS4 conf lib: read: 'poll_interval 10'
11/07 13:09:01 yS4 conf lib: read: 'program vgetty'
11/07 13:09:01 yS4 conf lib: read: 'rings 3'
11/07 13:09:01 yS4 conf lib: read: 'force_autodetect false'
11/07 13:09:01 yS4 conf lib: read: 'toll_saver_rings 0'
11/07 13:09:01 yS4 conf lib: read: 'rec_always_keep true'
11/07 13:09:01 yS4 conf lib: read: 'button_program '
11/07 13:09:01 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/07 13:09:01 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/07 13:09:01 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/07 13:09:01 yS4 conf lib: read: 'do_message_light false'
11/07 13:09:01 yS4 conf lib: read: 'ring_report_delay 15'
11/07 13:09:01 yS4 conf lib: read: 'program vm'
11/07 13:09:01 yS4 conf lib: read: 'voice_devices ttyS4'
11/07 13:09:01 yS4 conf lib: read: 'dialout_timeout 90'
11/07 13:09:01 yS4 conf lib: read: 'ringback_goes_away 70'
11/07 13:09:01 yS4 conf lib: read: 'ringback_never_came 100'
11/07 13:09:01 yS4 conf lib: read: 'program pvf'
11/07 13:09:01 yS4 conf lib: read: 'port ttyS4'
11/07 13:09:01 yS4 section: port ttyS4, **found**
11/07 13:09:01 yS4 conf lib: read: 'ring_type virtual'
11/07 13:09:01 yS4 found CT_KEYWORD ring_type virtual
11/07 13:09:01 yS4 conf lib: read: 'answer_mode fax:data'
11/07 13:09:01 yS4 conf lib: read: 'ring_type ring2'
11/07 13:09:01 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/07 13:09:01 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/07 13:09:01 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/07 13:09:01 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/07 13:09:01 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/07 13:09:01 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/07 13:09:01 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/07 13:09:01 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/07 13:09:01 yS4 key: 'command_delay', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/07 13:09:01 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/07 13:09:01 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/07 13:09:01 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/07 13:09:01 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/07 13:09:01 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/07 13:09:01 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/07 13:09:01 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/07 13:09:01 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/07 13:09:01 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/07 13:09:01 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/07 13:09:01 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/07 13:09:01 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/07 13:09:01 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/07 13:09:01 yS4 key: 'rings', type=1, flags=3, data=3
11/07 13:09:01 yS4 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
11/07 13:09:01 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/07 13:09:01 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/07 13:09:01 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/07 13:09:01 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/07 13:09:01 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/07 13:09:01 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/07 13:09:01 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/07 13:09:01 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/07 13:09:01 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/07 13:09:01 yS4 key: 'message_list', type=1, flags=3, data=Index
11/07 13:09:01 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/07 13:09:01 yS4 key: 'button_program', type=1, flags=3, data=
11/07 13:09:01 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/07 13:09:01 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/07 13:09:01 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/07 13:09:01 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/07 13:09:01 yS4 key: 'pre_message', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'beepsound', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/07 13:09:01 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/07 13:09:01 yS4 key: 'max_tries', type=0, flags=3, data=3
11/07 13:09:01 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/07 13:09:01 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/07 13:09:01 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/07 13:09:01 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/07 13:09:01 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/07 13:09:01 yS4 key: 'voice_devices', type=1, flags=1, data=
11/07 13:09:01 yS4 key: 'force_detect', type=1, flags=1, data=
11/07 13:09:01 yS4 check for lockfiles
11/07 13:09:01 yS4 checklock: stat failed, no file
11/07 13:09:01 yS4 locking the line
11/07 13:09:01 yS4 makelock(ttyS4) called
11/07 13:09:01 yS4 do_makelock: lock='/var/lock/LCK..ttyS4'
11/07 13:09:01 yS4 lock made
11/07 13:09:02 yS4 tio_get_rs232_lines: status: RTS CTS DSR DTR
11/07 13:09:02 yS4 lowering DTR to reset Modem
11/07 13:09:02 yS4 tss: set speed to 38400 (017)
11/07 13:09:02 yS4 tio_set_flow_control( HARD )
11/07 13:09:02 yS4 waiting for line to clear (VTIME), read:
11/07 13:09:02 yS4 send: \dATQ0V1H0[0d]
11/07 13:09:03 yS4 waiting for ``OK''
11/07 13:09:03 yS4 got: [0d][0a]OK ** found **
11/07 13:09:03 yS4 send: ATS0=0Q0&D3&C1[0d]
11/07 13:09:03 yS4 waiting for ``OK''
11/07 13:09:03 yS4 got: [0d]
11/07 13:09:03 yS4 CND: OK[0a][0d][0a]OK ** found **
11/07 13:09:03 yS4 mdm_send: 'ATI'
11/07 13:09:03 yS4 got:[0d][0a][0d][0a]5601[0d]
11/07 13:09:03 yS4 mdm_gis: string 1: '5601'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 mdm_identify: string '5601'
11/07 13:09:03 yS4 USR Courier/Sportster 56k detected
11/07 13:09:03 yS4 mdm_send: 'ATI3'
11/07 13:09:03 yS4 got:[0a][0d][0a]U.S. Robotics 56K Voice INT
V5.20.1[0d]
11/07 13:09:03 yS4 mdm_gis: string 1: 'U.S. Robotics 56K Voice INT
V5.20.1'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 additional info: 'U.S. Robotics 56K Voice INT
V5.20.1'
11/07 13:09:03 yS4 mdm_send: 'AT+FCLASS=2.0'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:03 yS4 mdm_send: 'AT+FAA=1;+FCR=1'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:03 yS4 mdm_send: 'AT+FBO=1'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:03 yS4 mdm_send: 'AT+FNR=1,1,1,0'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:03 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:03 yS4 mdm_send: 'AT+FLI="555-1234"'
11/07 13:09:03 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:04 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:04 yS4 mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0'
11/07 13:09:04 yS4 got:[0a][0d][0a]OK[0d]
11/07 13:09:04 yS4 mdm_command: string 'OK' -> OK
11/07 13:09:04 yS4 tss: set speed to 38400 (017)
11/07 13:09:04 yS4 tss: set speed to 38400 (017)
11/07 13:09:04 yS4 tio_set_flow_control( HARD )
11/07 13:09:04 yS4 detecting voice modem type
11/07 13:09:04 yS4 vgetty: ATE0
11/07 13:09:04 yS4 serial port: OK
11/07 13:09:04 yS4 voice command: 'ATI9' -> ''
11/07 13:09:04 yS4 vgetty: ATI9
11/07 13:09:04 yS4 serial port: (1.0USR3070\\Modem\PNPC10F\U.S.
Robotics 56K Voice INT)FF
11/07 13:09:04 yS4 PNP String: 'USR3070\\Modem\PNPC10F\U.S. Robotics
56K Voice INT)FF'
11/07 13:09:04 yS4 checking pnpid SUP / modelid <none>
11/07 13:09:04 yS4 checking pnpid ZYX / modelid 02FF
11/07 13:09:04 yS4 checking pnpid USR / modelid 0088
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0687
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0566
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0707
11/07 13:09:04 yS4 checking pnpid ELS / modelid 8318
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0853
11/07 13:09:04 yS4 checking pnpid ELS / modelid 8548
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0754
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0350
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0503
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0667
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0152
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0363
11/07 13:09:04 yS4 checking pnpid ELS / modelid 0862
11/07 13:09:04 yS4 checking pnpid ELS / modelid 6026
11/07 13:09:04 yS4 checking pnpid ELS / modelid 6027
11/07 13:09:04 yS4 serial port: OK
11/07 13:09:05 yS4 voice command: 'ATI3' -> ''
11/07 13:09:05 yS4 vgetty: ATI3
11/07 13:09:05 yS4 serial port: U.S. Robotics 56K Voice INT V5.20.1
11/07 13:09:05 yS4 serial port: OK
11/07 13:09:05 yS4 voice command: 'ATI' -> ''
11/07 13:09:05 yS4 vgetty: ATI
11/07 13:09:05 yS4 serial port: 5601
11/07 13:09:05 yS4 US Robotics: OK
11/07 13:09:05 yS4 US Robotics detected
11/07 13:09:05 yS4 vgetty: entering voice mode
11/07 13:09:05 yS4 vgetty: Installing signal handlers
11/07 13:09:05 yS4 voice command: 'AT#CLS?' -> ''
11/07 13:09:05 yS4 vgetty: AT#CLS?
11/07 13:09:05 yS4 US Robotics: 2.0
11/07 13:09:06 yS4 voice command: '' -> 'OK'
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 voice command: 'AT#CLS=8' -> 'OK'
11/07 13:09:06 yS4 vgetty: AT#CLS=8
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 voice command: 'AT' -> 'OK'
11/07 13:09:06 yS4 vgetty: AT
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 voice command:
'AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100' -> 'OK'
11/07 13:09:06 yS4 vgetty:
AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 vgetty: queued event RESET_WATCHDOG at position
0000
11/07 13:09:06 yS4 US Robotics voice modem
11/07 13:09:06 yS4 This is a driver beta version. V0.4.b3
11/07 13:09:06 yS4 voice command: 'AT&H1&R2&I0' -> 'OK'
11/07 13:09:06 yS4 vgetty: AT&H1&R2&I0
11/07 13:09:06 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0000
11/07 13:09:06 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 tio_set_flow_control( HARD )
11/07 13:09:06 yS4 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
11/07 13:09:06 yS4 vgetty: AT#VTD=3F,3F,3F
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:06 yS4 VTD setup successful
11/07 13:09:06 yS4 voice command: 'AT#VSD=1#VSS=2#VSP=70' -> 'OK'
11/07 13:09:06 yS4 vgetty: AT#VSD=1#VSS=2#VSP=70
11/07 13:09:06 yS4 US Robotics: OK
11/07 13:09:07 yS4 voice command: 'AT#VRA=70#VRN=100' -> 'OK'
11/07 13:09:07 yS4 vgetty: AT#VRA=70#VRN=100
11/07 13:09:07 yS4 US Robotics: OK
11/07 13:09:07 yS4 vgetty: leaving voice mode
11/07 13:09:07 yS4 voice command: 'AT#CLS=2.0' -> 'OK'
11/07 13:09:07 yS4 vgetty: AT#CLS=2.0
11/07 13:09:07 yS4 US Robotics: OK
11/07 13:09:07 yS4 voice command: 'AT' -> 'OK'
11/07 13:09:07 yS4 vgetty: AT
11/07 13:09:07 yS4 US Robotics: OK
11/07 13:09:07 yS4 vgetty: Restoring signal handlers
11/07 13:09:07 yS4 running post_init_chat
11/07 13:09:07 yS4 send: ATS41=1#CID=1[0d]
11/07 13:09:07 yS4 waiting for ``OK''
11/07 13:09:07 yS4 got: [0d]
11/07 13:09:07 yS4 CND: OK[0a]OK ** found **
11/07 13:09:07 yS4 waiting for line to clear (VTIME), read: [0d][0a]
11/07 13:09:07 yS4 removing lock file
11/07 13:09:07 yS4 waiting...
11/07 13:09:31 yS4 select returned 1
11/07 13:09:31 yS4 checking lockfiles, locking the line
11/07 13:09:31 yS4 makelock(ttyS4) called
11/07 13:09:31 yS4 do_makelock: lock='/var/lock/LCK..ttyS4'
11/07 13:09:31 yS4 lock made
11/07 13:09:31 yS4 vgetty: number of rings (3) was set directly
11/07 13:09:31 yS4 wfr: waiting for ``RING''
11/07 13:09:31 yS4 got: [0a][0d][0a]RING B[0d]
11/07 13:09:31 yS4 CND: RING B
11/07 13:09:31 yS4 wfr: rc=0, drn=2
11/07 13:09:31 yS4 wfr: waiting for ``RING''
11/07 13:09:31 yS4 got: [0a][0d][0a]NAME = MEV%[15]j[05]5[15]M0
[f2][0d]
11/07 13:09:32 yS4 CND: NAME = MEV%_j_5_M0 _
11/07 13:09:32 yS4 CND: found: MEV% j 5 M0
11/07 13:09:32 yS4 got: [0a][0d][0a]RING B[0d]
11/07 13:09:37 yS4 CND: RING B
11/07 13:09:37 yS4 wfr: rc=0, drn=2
11/07 13:09:37 yS4 wfr: waiting for ``RING''
11/07 13:09:37 yS4 got: [0a][0d][0a]RING B[0d]
11/07 13:09:43 yS4 CND: RING B
11/07 13:09:43 yS4 wfr: rc=0, drn=2
11/07 13:09:43 yS4 CND: check no: 'none'
11/07 13:09:43 yS4 CND: program "/etc/mgetty+sendfax/ringtype.sh
ttyS4 'none' 'MEV% j 5 M0 ' 2 '' >/dev/console 2>&1 </dev/null"
11/07 13:09:43 yS4 CND: rc=0x0
11/07 13:09:43 yS4 setenv: 'CALLER_ID=none'
11/07 13:09:43 yS4 setenv: 'CALLER_NAME=MEV% j 5 M0 '
11/07 13:09:43 yS4 setenv: 'CONNECT='
11/07 13:09:43 yS4 setenv: 'DEVICE=ttyS4'
11/07 13:09:43 yS4 reading ring_type ring2 configuration from config
file /etc/mgetty+sendfax/voice.conf
11/07 13:09:43 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/07 13:09:43 yS4 conf lib: read: 'part generic'
11/07 13:09:43 yS4 found CT_KEYWORD part generic
11/07 13:09:43 yS4 conf lib: read: 'voice_log_level 6'
11/07 13:09:43 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/07 13:09:43 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/07 13:09:43 yS4 conf lib: read: 'phone_owner uucp'
11/07 13:09:43 yS4 conf lib: read: 'phone_group uucp'
11/07 13:09:43 yS4 conf lib: read: 'phone_mode 0660'
11/07 13:09:43 yS4 conf lib: read: 'message_flag_file .flag'
11/07 13:09:43 yS4 conf lib: read: 'receive_dir incoming'
11/07 13:09:43 yS4 conf lib: read: 'message_dir messages'
11/07 13:09:43 yS4 conf lib: read: 'message_list Index'
11/07 13:09:43 yS4 conf lib: read: 'backup_message standard.rmd'
11/07 13:09:43 yS4 conf lib: read: 'port_speed 38400'
11/07 13:09:43 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/07 13:09:43 yS4 conf lib: read: 'port_timeout 10'
11/07 13:09:43 yS4 conf lib: read: 'dial_timeout 90'
11/07 13:09:43 yS4 conf lib: read: 'command_delay 100'
11/07 13:09:43 yS4 conf lib: read: 'dtmf_len 30'
11/07 13:09:43 yS4 conf lib: read: 'dtmf_threshold 40'
11/07 13:09:43 yS4 conf lib: read: 'dtmf_wait 7'
11/07 13:09:43 yS4 conf lib: read: 'ignore_fax_dle false'
11/07 13:09:43 yS4 conf lib: read: 'raw_data false'
11/07 13:09:43 yS4 conf lib: read: 'rec_compression 0'
11/07 13:09:43 yS4 conf lib: read: 'rec_speed 0'
11/07 13:09:43 yS4 conf lib: read: 'rec_silence_len 70'
11/07 13:09:43 yS4 conf lib: read: 'rec_silence_threshold 40'
11/07 13:09:43 yS4 conf lib: read: 'rec_remove_silence false'
11/07 13:09:43 yS4 conf lib: read: 'rec_max_len 300'
11/07 13:09:43 yS4 conf lib: read: 'rec_min_len 5'
11/07 13:09:43 yS4 conf lib: read: 'do_hard_flow true'
11/07 13:09:43 yS4 conf lib: read: 'beep_frequency 933'
11/07 13:09:43 yS4 conf lib: read: 'beep_length 1500'
11/07 13:09:43 yS4 conf lib: read: 'max_tries 3'
11/07 13:09:43 yS4 conf lib: read: 'retry_delay 5'
11/07 13:09:43 yS4 conf lib: read: 'watchdog_timeout 60'
11/07 13:09:43 yS4 conf lib: read: 'receive_gain 100%'
11/07 13:09:43 yS4 conf lib: read: 'transmit_gain 100%'
11/07 13:09:43 yS4 conf lib: read: 'enable_command_echo false'
11/07 13:09:43 yS4 conf lib: read: 'poll_interval 10'
11/07 13:09:43 yS4 conf lib: read: 'program vgetty'
11/07 13:09:43 yS4 conf lib: read: 'rings 3'
11/07 13:09:43 yS4 conf lib: read: 'force_autodetect false'
11/07 13:09:43 yS4 conf lib: read: 'toll_saver_rings 0'
11/07 13:09:43 yS4 conf lib: read: 'rec_always_keep true'
11/07 13:09:43 yS4 conf lib: read: 'button_program '
11/07 13:09:43 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/07 13:09:43 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/07 13:09:43 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/07 13:09:43 yS4 conf lib: read: 'do_message_light false'
11/07 13:09:43 yS4 conf lib: read: 'ring_report_delay 15'
11/07 13:09:43 yS4 conf lib: read: 'program vm'
11/07 13:09:43 yS4 conf lib: read: 'voice_devices ttyS4'
11/07 13:09:43 yS4 conf lib: read: 'dialout_timeout 90'
11/07 13:09:43 yS4 conf lib: read: 'ringback_goes_away 70'
11/07 13:09:43 yS4 conf lib: read: 'ringback_never_came 100'
11/07 13:09:43 yS4 conf lib: read: 'program pvf'
11/07 13:09:43 yS4 conf lib: read: 'port ttyS4'
11/07 13:09:43 yS4 conf lib: read: 'ring_type virtual'
11/07 13:09:43 yS4 section: ring_type virtual, ignore
11/07 13:09:43 yS4 conf lib: read: 'answer_mode fax:data'
11/07 13:09:43 yS4 conf lib: read: 'ring_type ring2'
11/07 13:09:43 yS4 section: ring_type ring2, **found**
11/07 13:09:43 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/07 13:09:43 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/07 13:09:43 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/07 13:09:43 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/07 13:09:43 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/07 13:09:43 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/07 13:09:43 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/07 13:09:43 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/07 13:09:43 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/07 13:09:43 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/07 13:09:43 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/07 13:09:43 yS4 key: 'command_delay', type=0, flags=3, data=100
11/07 13:09:43 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/07 13:09:43 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/07 13:09:43 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/07 13:09:43 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/07 13:09:43 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/07 13:09:43 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/07 13:09:43 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/07 13:09:43 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/07 13:09:43 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/07 13:09:43 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/07 13:09:43 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/07 13:09:43 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/07 13:09:43 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/07 13:09:43 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/07 13:09:43 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/07 13:09:43 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/07 13:09:43 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/07 13:09:43 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/07 13:09:43 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/07 13:09:43 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/07 13:09:43 yS4 key: 'rings', type=1, flags=3, data=3
11/07 13:09:43 yS4 key: 'answer_mode', type=1, flags=3,
data=voice:fax:data
11/07 13:09:43 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/07 13:09:43 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/07 13:09:43 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/07 13:09:43 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/07 13:09:43 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/07 13:09:43 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/07 13:09:43 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/07 13:09:43 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/07 13:09:43 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/07 13:09:43 yS4 key: 'message_list', type=1, flags=3, data=Index
11/07 13:09:43 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/07 13:09:43 yS4 key: 'button_program', type=1, flags=3, data=
11/07 13:09:43 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/07 13:09:43 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/07 13:09:43 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/07 13:09:43 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/07 13:09:43 yS4 key: 'pre_message', type=1, flags=1, data=
11/07 13:09:43 yS4 key: 'beepsound', type=1, flags=1, data=
11/07 13:09:43 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/07 13:09:43 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/07 13:09:43 yS4 key: 'max_tries', type=0, flags=3, data=3
11/07 13:09:43 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/07 13:09:43 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/07 13:09:43 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/07 13:09:43 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/07 13:09:43 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/07 13:09:43 yS4 key: 'voice_devices', type=1, flags=1, data=
11/07 13:09:43 yS4 key: 'force_detect', type=1, flags=1, data=
11/07 13:09:43 yS4 vgetty: answer mode was set directly
11/07 13:09:43 yS4 vgetty: answer mode is [data|fax|voice]
11/07 13:09:43 yS4 vgetty: opening list file
/var/spool/voice/messages/Index
11/07 13:09:43 yS4 vgetty: message name is
/var/spool/voice/messages/standard.rmd
11/07 13:09:43 yS4 vgetty: entering voice mode
11/07 13:09:43 yS4 vgetty: Installing signal handlers
11/07 13:09:43 yS4 voice command: 'AT#CLS?' -> ''
11/07 13:09:43 yS4 vgetty: AT#CLS?
11/07 13:09:43 yS4 US Robotics: 2.0
11/07 13:09:44 yS4 voice command: '' -> 'OK'
11/07 13:09:44 yS4 US Robotics: OK
11/07 13:09:44 yS4 voice command: 'AT#CLS=8' -> 'OK'
11/07 13:09:44 yS4 vgetty: AT#CLS=8
11/07 13:09:44 yS4 US Robotics: OK
11/07 13:09:44 yS4 voice command: 'AT' -> 'OK'
11/07 13:09:44 yS4 vgetty: AT
11/07 13:09:44 yS4 US Robotics: OK
11/07 13:09:44 yS4 voice command:
'AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100' -> 'OK'
11/07 13:09:44 yS4 vgetty:
AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100
11/07 13:09:44 yS4 US Robotics: OK
11/07 13:09:44 yS4 voice command: 'AT#VLS=0A' -> 'VCON'
11/07 13:09:44 yS4 vgetty: AT#VLS=0A
11/07 13:09:44 yS4 US Robotics: VCON
11/07 13:09:44 yS4 vgetty: queued event RESET_WATCHDOG at position
0001
11/07 13:09:44 yS4 voice command: 'AT#VLS=0' -> 'OK|VCON'
11/07 13:09:44 yS4 vgetty: AT#VLS=0
11/07 13:09:44 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0001
11/07 13:09:44 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
11/07 13:09:44 yS4 US Robotics: OK
11/07 13:09:44 yS4 vgetty: Executing shell script
/usr/local/vocp/bin/vocp.pl with shell /usr/bin/perl
11/07 13:09:44 yS4 vgetty: opening pipes
11/07 13:09:44 yS4 vgetty: forking shell
11/07 13:09:44 yS4 vgetty(0): HELLO SHELL
11/07 13:09:46 yS4 vgetty: Got pipe signal
11/07 13:09:46 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0002
11/07 13:09:46 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0002
11/07 13:09:46 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <NUL>
11/07 13:09:46 yS4 shell(1): HELLO VOICE PROGRAM
11/07 13:09:46 yS4 vgetty(1): READY
11/07 13:09:46 yS4 vgetty: initialized communication
11/07 13:09:46 yS4 vgetty: Got pipe signal
11/07 13:09:46 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0003
11/07 13:09:46 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0003
11/07 13:09:46 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <NUL>
11/07 13:09:46 yS4 shell(1): DEVICE DIALUP_LINE
11/07 13:09:46 yS4 vgetty: queued event RESET_WATCHDOG at position
0004
11/07 13:09:46 yS4 voice command: 'AT#VLS=0' -> 'OK|VCON'
11/07 13:09:46 yS4 vgetty: AT#VLS=0
11/07 13:09:46 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0004
11/07 13:09:46 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
11/07 13:09:46 yS4 US Robotics: <DLE> <D>
11/07 13:09:46 yS4 vgetty: queued event RECEIVED_DTMF at position
0005
11/07 13:09:46 yS4 US Robotics:
11/07 13:09:46 yS4 US Robotics: OK
11/07 13:09:46 yS4 vgetty(1): READY
11/07 13:09:46 yS4 vgetty: unqueued event RECEIVED_DTMF at position
0005
11/07 13:09:46 yS4 vgetty: voice_handle_event got event
RECEIVED_DTMF with data <D>
11/07 13:09:46 yS4 vgetty: Got pipe signal
11/07 13:09:46 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0006
11/07 13:09:46 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0006
11/07 13:09:46 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/07 13:09:46 yS4 shell(1): AUTOSTOP ON
11/07 13:09:46 yS4 vgetty(1): READY
11/07 13:09:47 yS4 vgetty: Got pipe signal
11/07 13:09:47 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0007
11/07 13:09:47 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0007
11/07 13:09:47 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/07 13:09:47 yS4 shell(1): ENABLE EVENTS
11/07 13:09:47 yS4 vgetty(1): READY
11/07 13:09:47 yS4 vgetty: Got pipe signal
11/07 13:09:47 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0008
11/07 13:09:47 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0008
11/07 13:09:47 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/07 13:09:47 yS4 shell(1): PLAY /var/spool/voice/messages/root.rmd
11/07 13:09:47 yS4 vgetty(1): PLAYING
11/07 13:09:47 yS4 playing voice file
/var/spool/voice/messages/root.rmd
11/07 13:09:47 yS4 vgetty: raw modem data header found
11/07 13:09:47 yS4 vgetty: modem type US Robotics found
11/07 13:09:47 yS4 vgetty: compression method 0x0001, speed 8000,
bits 8
11/07 13:09:47 yS4 vgetty: queued event RESET_WATCHDOG at position
0009
11/07 13:09:47 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0009
11/07 13:09:47 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <o>
11/07 13:09:47 yS4 voice command: 'AT' -> 'OK|VCON'
11/07 13:09:47 yS4 vgetty: AT
11/07 13:09:47 yS4 US Robotics: OK
11/07 13:09:47 yS4 tio_set_flow_control( HARD XON_OUT )
11/07 13:09:47 yS4 voice command: 'ATE0#VTX' -> 'CONNECT'
11/07 13:09:47 yS4 vgetty: ATE0#VTX
11/07 13:09:47 yS4 US Robotics: <DLE> <D>
11/07 13:09:47 yS4 vgetty: queued event RECEIVED_DTMF at position
0010
11/07 13:09:47 yS4 US Robotics:
11/07 13:09:47 yS4 US Robotics: CONNECT
11/07 13:09:47 yS4 vgetty: unqueued event RECEIVED_DTMF at position
0010
11/07 13:09:47 yS4 vgetty: voice_handle_event got event
RECEIVED_DTMF with data <D>
11/07 13:09:47 yS4 vgetty: stopping current action
11/07 13:09:47 yS4 vgetty(1): RECEIVED_DTMF
11/07 13:09:47 yS4 vgetty(1): D
11/07 13:09:47 yS4 vgetty: <VOICE DATA 800 bytes>
11/07 13:09:47 yS4 vgetty: queued event RESET_WATCHDOG at position
0011
11/07 13:09:47 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0011
11/07 13:09:47 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <D>
11/07 13:09:47 yS4 vgetty: <INTERRUPT PLAY>
11/07 13:09:47 yS4 voice command: '' -> 'OK|VCON'
11/07 13:09:47 yS4 US Robotics: VCON
11/07 13:09:49 yS4 voice command: 'AT' -> 'OK'
11/07 13:09:49 yS4 vgetty: AT
11/07 13:09:49 yS4 US Robotics: OK
11/07 13:09:49 yS4 vgetty(1): READY
11/07 13:09:49 yS4 vgetty: Got child -1 exit status -1 signal
11/07 13:09:49 yS4 vgetty: queued event SIGNAL_SIGCHLD at position
0012
11/07 13:09:49 yS4 vgetty: shell exited normally with status 0x0001
11/07 13:09:49 yS4 vgetty: asked DATA
11/07 13:09:49 yS4 vgetty: trying data connection
11/07 13:09:49 yS4 vgetty: queued event RESET_WATCHDOG at position
0013
11/07 13:09:49 yS4 voice command: 'AT#CLS=2.0' -> 'OK'
11/07 13:09:49 yS4 vgetty: AT#CLS=2.0
11/07 13:09:49 yS4 vgetty: unqueued event SIGNAL_SIGCHLD at position
0012
11/07 13:09:49 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGCHLD with data <_>
11/07 13:09:49 yS4 vgetty: voice_handle_event got unknown event
SIGNAL_SIGCHLD with data <_>
11/07 13:09:49 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0013
11/07 13:09:49 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
11/07 13:09:49 yS4 US Robotics: OK
11/07 13:09:49 yS4 voice command: 'AT' -> 'OK'
11/07 13:09:49 yS4 vgetty: AT
11/07 13:09:49 yS4 US Robotics: OK
11/07 13:09:49 yS4 voice command: 'AT+FCLASS=0' -> 'OK'
11/07 13:09:49 yS4 vgetty: AT+FCLASS=0
11/07 13:09:49 yS4 US Robotics: OK
11/07 13:09:49 yS4 voice command: 'AT+FAA=0' -> 'OK'
11/07 13:09:49 yS4 vgetty: AT+FAA=0
11/07 13:09:49 yS4 US Robotics: OK
11/07 13:09:49 yS4 vgetty: Restoring signal handlers
11/07 13:09:49 yS4 send: ATA[0d]
11/07 13:09:49 yS4 waiting for ``CONNECT''
11/07 13:09:49 yS4 got: [0d]
11/07 13:10:37 yS4 CND: OK[0a]NO CARRIER
11/07 13:10:37 yS4 found action string: ``NO CARRIER''
11/07 13:10:37 ##### failed A_FAIL dev=ttyS4, pid=4719, caller='none',
conn='', name='MEV% j 5 M0 '

The following is the pppd and chat log for a Lucent WinModem on a Linux
client machine.

Nov 7 13:09:21 localhost pppd[2150]: pppd 2.4.1 started by root, uid 0
Nov 7 13:09:22 localhost chat[2152]: send (ATZ^M)
Nov 7 13:09:22 localhost chat[2152]: expect (OK)
Nov 7 13:09:22 localhost chat[2152]: ATZ^M^M
Nov 7 13:09:22 localhost chat[2152]: OK
Nov 7 13:09:22 localhost chat[2152]: -- got it
Nov 7 13:09:22 localhost chat[2152]: send
(ATDT5551234,,,,,,,D,D,D,D,D^M)
Nov 7 13:09:23 localhost chat[2152]: expect (CONNECT)
Nov 7 13:09:23 localhost chat[2152]: ^M
Nov 7 13:10:23 localhost chat[2152]: alarm
Nov 7 13:10:23 localhost chat[2152]: Failed
Nov 7 13:10:23 localhost pppd[2150]: Connect script failed
Nov 7 13:10:24 localhost pppd[2150]: Exit.

As you can see, vgetty is in DATA mode and I can hear the client-side
modem trying to negotiate.

Why will mgetty negotiate the data connection, but vgetty in DATA mode
will not?

Is it possible to extent the data negotiation time in vgetty?

Is what I am attempting even possible?

Respectfully,


Gary

[A***@yahoo.com]

From the documentation I have found. It appears that what I am

attempting is possible.

"vgetty is an extension to mgetty that works with voice-capable modems
to provide additional call-handling capabilities. When the modem
reports a RING, vgetty has the modem pick up the line and play a voice
message (the greeting). If the modem detects a data or fax calling
tone, it reports this back to vgetty with special codes (DLE-sequences)
which causes vgetty to switch to either mode. Else voice mode is used."

http://www.faqs.org/faqs/fax-faq/mgetty+sendfax+vgetty/

"If vgetty detects a single number only, it stops playing, then tries
to make a data connection with the remote end, if it doesn't succeed,
then it tries a fax connection with the remote end. If vgetty detects
an empty # character (without *numbers before it), then it simply hangs
up the phone. If no DTMF was received during playing, vgetty issues a
beep command, then it switches to recording mode, when the remote end
can say the message to be recorded. Recording ends if DTMF tones
detected as described above (in this case vgetty removes the recorded
message), or if "record_max_len" time exceeded, or if the remote end
hangs up. When finished, vgetty executes "message_program" if specified
with the recorded filename as argument."

http://alpha.greenie.net/vgetty/readme.voice_shell.html

"When vgetty detects a fax or data connection, vocp will exit with the
appropriate status code. The rest is up to how you've set up
mgetty+sendfax, see their documentation for details ('info mgetty'). In
order to facilitate data connections, VOCP is set up such that if you
set your modem to dial into the VOCP machine using a telephone number
like: 5551212,,,,,D and you get the timing (number of commas) right so
that the DTMF 'D' tone is played during the greeting message, VOCP will
exit with the code for data connections. You need to make sure mgetty
is setup to accept these connections."

http://www.vocpsystem.com/faq.php#4

It appears to do this, but vgetty will never estabilish the negotiated
data connection.

Has anyone been able to get vgetty to estabilish a data connection
using DTMF tones?

Respectfully,


Gary

[A***@yahoo.com]

I think I've narrowed the problem down a little further. While testing
the vgetty + vocie/data + DTMF configuration, I by chance was finally
able to connect (refer to success log, below). When trying to
reproduce the successful connection, I found that only when the DTMF
'D' Tone was timed just right with the beginning of the voice
connection and if not too many DTMF 'D' Tones were sent would vgetty
switch to data mode and successfully negotiate the data connection. If
too many DTMF 'D' Tones are sent after vgetty is switched into data
mode, it appears to confuse the data negotiation of the vgetty modem.

To make the situation even more difficult, I am required to only allow
vgetty to answer voice:fax:data calls on a distinctive ring number
(RING B - 2 Quick Rings) that does not seem to be the same each time.
The problem is consistantly timing the DTMF 'D' Tone to be sent during
the short window when vgetty is expecting it, but not too many as to
confuse the data negotiation of the vgetty modem.

Besides using a different line or ring, is there anything I can do to
provide more consistent timing?

Thank you for your assistance.

Respectfully,


Gary


11/09 16:26:23 yS4 vgetty: experimental test release 0.9.33 / 26Dec02
11/09 16:26:23 yS4 mgetty: experimental test release 1.1.30-Dec16
11/09 16:26:23 yS4 reading generic configuration from config file
/etc/mgetty+sendfax/voice.conf
11/09 16:26:23 yS4 reading program vgetty configuration from config
file /etc/mgetty+sendfax/voice.conf
11/09 16:26:23 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/09 16:26:23 yS4 conf lib: read: 'part generic'
11/09 16:26:23 yS4 found CT_KEYWORD part generic
11/09 16:26:23 yS4 conf lib: read: 'voice_log_level 6'
11/09 16:26:23 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/09 16:26:23 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/09 16:26:23 yS4 conf lib: read: 'phone_owner uucp'
11/09 16:26:23 yS4 conf lib: read: 'phone_group uucp'
11/09 16:26:23 yS4 conf lib: read: 'phone_mode 0660'
11/09 16:26:23 yS4 conf lib: read: 'message_flag_file .flag'
11/09 16:26:23 yS4 conf lib: read: 'receive_dir incoming'
11/09 16:26:23 yS4 conf lib: read: 'message_dir messages'
11/09 16:26:23 yS4 conf lib: read: 'message_list Index'
11/09 16:26:23 yS4 conf lib: read: 'backup_message standard.rmd'
11/09 16:26:23 yS4 conf lib: read: 'port_speed 38400'
11/09 16:26:23 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/09 16:26:23 yS4 conf lib: read: 'port_timeout 10'
11/09 16:26:23 yS4 conf lib: read: 'dial_timeout 90'
11/09 16:26:23 yS4 conf lib: read: 'command_delay 100'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_len 30'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_threshold 40'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_wait 7'
11/09 16:26:23 yS4 conf lib: read: 'ignore_fax_dle false'
11/09 16:26:23 yS4 conf lib: read: 'raw_data false'
11/09 16:26:23 yS4 conf lib: read: 'rec_compression 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_speed 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_silence_len 70'
11/09 16:26:23 yS4 conf lib: read: 'rec_silence_threshold 40'
11/09 16:26:23 yS4 conf lib: read: 'rec_remove_silence false'
11/09 16:26:23 yS4 conf lib: read: 'rec_max_len 300'
11/09 16:26:23 yS4 conf lib: read: 'rec_min_len 5'
11/09 16:26:23 yS4 conf lib: read: 'do_hard_flow true'
11/09 16:26:23 yS4 conf lib: read: 'beep_frequency 933'
11/09 16:26:23 yS4 conf lib: read: 'beep_length 1500'
11/09 16:26:23 yS4 conf lib: read: 'max_tries 3'
11/09 16:26:23 yS4 conf lib: read: 'retry_delay 5'
11/09 16:26:23 yS4 conf lib: read: 'watchdog_timeout 60'
11/09 16:26:23 yS4 conf lib: read: 'receive_gain 100%'
11/09 16:26:23 yS4 conf lib: read: 'transmit_gain 100%'
11/09 16:26:23 yS4 conf lib: read: 'enable_command_echo false'
11/09 16:26:23 yS4 conf lib: read: 'poll_interval 10'
11/09 16:26:23 yS4 conf lib: read: 'program vgetty'
11/09 16:26:23 yS4 section: program vgetty, **found**
11/09 16:26:23 yS4 conf lib: read: 'rings 3'
11/09 16:26:23 yS4 conf lib: read: 'force_autodetect false'
11/09 16:26:23 yS4 conf lib: read: 'toll_saver_rings 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_always_keep true'
11/09 16:26:23 yS4 conf lib: read: 'button_program '
11/09 16:26:23 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/09 16:26:23 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/09 16:26:23 yS4 conf lib: read: 'do_message_light false'
11/09 16:26:23 yS4 conf lib: read: 'ring_report_delay 15'
11/09 16:26:23 yS4 conf lib: read: 'program vm'
11/09 16:26:23 yS4 section: program vm, ignore
11/09 16:26:23 yS4 conf lib: read: 'voice_devices ttyS4'
11/09 16:26:23 yS4 conf lib: read: 'dialout_timeout 90'
11/09 16:26:23 yS4 conf lib: read: 'ringback_goes_away 70'
11/09 16:26:23 yS4 conf lib: read: 'ringback_never_came 100'
11/09 16:26:23 yS4 conf lib: read: 'program pvf'
11/09 16:26:23 yS4 section: program pvf, ignore
11/09 16:26:23 yS4 conf lib: read: 'port ttyS4'
11/09 16:26:23 yS4 conf lib: read: 'ring_type virtual'
11/09 16:26:23 yS4 conf lib: read: 'answer_mode fax:data'
11/09 16:26:23 yS4 conf lib: read: 'ring_type ring2'
11/09 16:26:23 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/09 16:26:23 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/09 16:26:23 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/09 16:26:23 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/09 16:26:23 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/09 16:26:23 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/09 16:26:23 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/09 16:26:23 yS4 key: 'command_delay', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/09 16:26:23 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/09 16:26:23 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/09 16:26:23 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/09 16:26:23 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/09 16:26:23 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/09 16:26:23 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/09 16:26:23 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/09 16:26:23 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/09 16:26:23 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/09 16:26:23 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/09 16:26:23 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/09 16:26:23 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/09 16:26:23 yS4 key: 'rings', type=1, flags=3, data=3
11/09 16:26:23 yS4 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
11/09 16:26:23 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/09 16:26:23 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/09 16:26:23 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/09 16:26:23 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/09 16:26:23 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/09 16:26:23 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/09 16:26:23 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/09 16:26:23 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/09 16:26:23 yS4 key: 'message_list', type=1, flags=3, data=Index
11/09 16:26:23 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/09 16:26:23 yS4 key: 'button_program', type=1, flags=3, data=
11/09 16:26:23 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/09 16:26:23 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/09 16:26:23 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/09 16:26:23 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'pre_message', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'beepsound', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/09 16:26:23 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/09 16:26:23 yS4 key: 'max_tries', type=0, flags=3, data=3
11/09 16:26:23 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/09 16:26:23 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/09 16:26:23 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/09 16:26:23 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/09 16:26:23 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/09 16:26:23 yS4 key: 'voice_devices', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'force_detect', type=1, flags=1, data=
11/09 16:26:23 yS4 reading port ttyS4 configuration from config file
/etc/mgetty+sendfax/voice.conf
11/09 16:26:23 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/09 16:26:23 yS4 conf lib: read: 'part generic'
11/09 16:26:23 yS4 found CT_KEYWORD part generic
11/09 16:26:23 yS4 conf lib: read: 'voice_log_level 6'
11/09 16:26:23 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/09 16:26:23 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/09 16:26:23 yS4 conf lib: read: 'phone_owner uucp'
11/09 16:26:23 yS4 conf lib: read: 'phone_group uucp'
11/09 16:26:23 yS4 conf lib: read: 'phone_mode 0660'
11/09 16:26:23 yS4 conf lib: read: 'message_flag_file .flag'
11/09 16:26:23 yS4 conf lib: read: 'receive_dir incoming'
11/09 16:26:23 yS4 conf lib: read: 'message_dir messages'
11/09 16:26:23 yS4 conf lib: read: 'message_list Index'
11/09 16:26:23 yS4 conf lib: read: 'backup_message standard.rmd'
11/09 16:26:23 yS4 conf lib: read: 'port_speed 38400'
11/09 16:26:23 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/09 16:26:23 yS4 conf lib: read: 'port_timeout 10'
11/09 16:26:23 yS4 conf lib: read: 'dial_timeout 90'
11/09 16:26:23 yS4 conf lib: read: 'command_delay 100'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_len 30'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_threshold 40'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_wait 7'
11/09 16:26:23 yS4 conf lib: read: 'ignore_fax_dle false'
11/09 16:26:23 yS4 conf lib: read: 'raw_data false'
11/09 16:26:23 yS4 conf lib: read: 'rec_compression 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_speed 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_silence_len 70'
11/09 16:26:23 yS4 conf lib: read: 'rec_silence_threshold 40'
11/09 16:26:23 yS4 conf lib: read: 'rec_remove_silence false'
11/09 16:26:23 yS4 conf lib: read: 'rec_max_len 300'
11/09 16:26:23 yS4 conf lib: read: 'rec_min_len 5'
11/09 16:26:23 yS4 conf lib: read: 'do_hard_flow true'
11/09 16:26:23 yS4 conf lib: read: 'beep_frequency 933'
11/09 16:26:23 yS4 conf lib: read: 'beep_length 1500'
11/09 16:26:23 yS4 conf lib: read: 'max_tries 3'
11/09 16:26:23 yS4 conf lib: read: 'retry_delay 5'
11/09 16:26:23 yS4 conf lib: read: 'watchdog_timeout 60'
11/09 16:26:23 yS4 conf lib: read: 'receive_gain 100%'
11/09 16:26:23 yS4 conf lib: read: 'transmit_gain 100%'
11/09 16:26:23 yS4 conf lib: read: 'enable_command_echo false'
11/09 16:26:23 yS4 conf lib: read: 'poll_interval 10'
11/09 16:26:23 yS4 conf lib: read: 'program vgetty'
11/09 16:26:23 yS4 conf lib: read: 'rings 3'
11/09 16:26:23 yS4 conf lib: read: 'force_autodetect false'
11/09 16:26:23 yS4 conf lib: read: 'toll_saver_rings 0'
11/09 16:26:23 yS4 conf lib: read: 'rec_always_keep true'
11/09 16:26:23 yS4 conf lib: read: 'button_program '
11/09 16:26:23 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/09 16:26:23 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/09 16:26:23 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/09 16:26:23 yS4 conf lib: read: 'do_message_light false'
11/09 16:26:23 yS4 conf lib: read: 'ring_report_delay 15'
11/09 16:26:23 yS4 conf lib: read: 'program vm'
11/09 16:26:23 yS4 conf lib: read: 'voice_devices ttyS4'
11/09 16:26:23 yS4 conf lib: read: 'dialout_timeout 90'
11/09 16:26:23 yS4 conf lib: read: 'ringback_goes_away 70'
11/09 16:26:23 yS4 conf lib: read: 'ringback_never_came 100'
11/09 16:26:23 yS4 conf lib: read: 'program pvf'
11/09 16:26:23 yS4 conf lib: read: 'port ttyS4'
11/09 16:26:23 yS4 section: port ttyS4, **found**
11/09 16:26:23 yS4 conf lib: read: 'ring_type virtual'
11/09 16:26:23 yS4 found CT_KEYWORD ring_type virtual
11/09 16:26:23 yS4 conf lib: read: 'answer_mode fax:data'
11/09 16:26:23 yS4 conf lib: read: 'ring_type ring2'
11/09 16:26:23 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/09 16:26:23 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/09 16:26:23 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/09 16:26:23 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/09 16:26:23 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/09 16:26:23 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/09 16:26:23 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/09 16:26:23 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/09 16:26:23 yS4 key: 'command_delay', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/09 16:26:23 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/09 16:26:23 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/09 16:26:23 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/09 16:26:23 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/09 16:26:23 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/09 16:26:23 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/09 16:26:23 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/09 16:26:23 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/09 16:26:23 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/09 16:26:23 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/09 16:26:23 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/09 16:26:23 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/09 16:26:23 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/09 16:26:23 yS4 key: 'rings', type=1, flags=3, data=3
11/09 16:26:23 yS4 key: 'answer_mode', type=1, flags=1,
data=voice:fax:data
11/09 16:26:23 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/09 16:26:23 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/09 16:26:23 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/09 16:26:23 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/09 16:26:23 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/09 16:26:23 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/09 16:26:23 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/09 16:26:23 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/09 16:26:23 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/09 16:26:23 yS4 key: 'message_list', type=1, flags=3, data=Index
11/09 16:26:23 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/09 16:26:23 yS4 key: 'button_program', type=1, flags=3, data=
11/09 16:26:23 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/09 16:26:23 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/09 16:26:23 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/09 16:26:23 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/09 16:26:23 yS4 key: 'pre_message', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'beepsound', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/09 16:26:23 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/09 16:26:23 yS4 key: 'max_tries', type=0, flags=3, data=3
11/09 16:26:23 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/09 16:26:23 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/09 16:26:23 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/09 16:26:23 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/09 16:26:23 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/09 16:26:23 yS4 key: 'voice_devices', type=1, flags=1, data=
11/09 16:26:23 yS4 key: 'force_detect', type=1, flags=1, data=
11/09 16:26:23 yS4 check for lockfiles
11/09 16:26:23 yS4 checklock: stat failed, no file
11/09 16:26:23 yS4 locking the line
11/09 16:26:23 yS4 makelock(ttyS4) called
11/09 16:26:23 yS4 do_makelock: lock='/var/lock/LCK..ttyS4'
11/09 16:26:23 yS4 lock made
11/09 16:26:23 yS4 tio_get_rs232_lines: status: RTS CTS DSR DTR
11/09 16:26:23 yS4 lowering DTR to reset Modem
11/09 16:26:24 yS4 tss: set speed to 38400 (017)
11/09 16:26:24 yS4 tio_set_flow_control( HARD )
11/09 16:26:24 yS4 waiting for line to clear (VTIME), read:
11/09 16:26:24 yS4 send: \dATQ0V1H0[0d]
11/09 16:26:25 yS4 waiting for ``OK''
11/09 16:26:25 yS4 got: [0d][0a]OK ** found **
11/09 16:26:25 yS4 send: ATS0=0Q0&D3&C1[0d]
11/09 16:26:25 yS4 waiting for ``OK''
11/09 16:26:25 yS4 got: [0d]
11/09 16:26:25 yS4 CND: OK[0a][0d][0a]OK ** found **
11/09 16:26:25 yS4 mdm_send: 'ATI'
11/09 16:26:25 yS4 got:[0d][0a][0d][0a]5601[0d]
11/09 16:26:25 yS4 mdm_gis: string 1: '5601'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_identify: string '5601'
11/09 16:26:25 yS4 USR Courier/Sportster 56k detected
11/09 16:26:25 yS4 mdm_send: 'ATI3'
11/09 16:26:25 yS4 got:[0a][0d][0a]U.S. Robotics 56K Voice INT
V5.20.1[0d]
11/09 16:26:25 yS4 mdm_gis: string 1: 'U.S. Robotics 56K Voice INT
V5.20.1'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 additional info: 'U.S. Robotics 56K Voice INT
V5.20.1'
11/09 16:26:25 yS4 mdm_send: 'AT+FCLASS=2.0'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 mdm_send: 'AT+FAA=1;+FCR=1'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 mdm_send: 'AT+FBO=1'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 mdm_send: 'AT+FNR=1,1,1,0'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 mdm_send: 'AT+FLI="5551234"'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0'
11/09 16:26:25 yS4 got:[0a][0d][0a]OK[0d]
11/09 16:26:25 yS4 mdm_command: string 'OK' -> OK
11/09 16:26:25 yS4 tss: set speed to 38400 (017)
11/09 16:26:25 yS4 tss: set speed to 38400 (017)
11/09 16:26:25 yS4 tio_set_flow_control( HARD )
11/09 16:26:25 yS4 detecting voice modem type
11/09 16:26:25 yS4 vgetty: ATE0
11/09 16:26:26 yS4 serial port: OK
11/09 16:26:26 yS4 voice command: 'ATI9' -> ''
11/09 16:26:26 yS4 vgetty: ATI9
11/09 16:26:26 yS4 serial port: (1.0USR3070\\Modem\PNPC10F\U.S.
Robotics 56K Voice INT)FF
11/09 16:26:26 yS4 PNP String: 'USR3070\\Modem\PNPC10F\U.S. Robotics
56K Voice INT)FF'
11/09 16:26:26 yS4 checking pnpid SUP / modelid <none>
11/09 16:26:26 yS4 checking pnpid ZYX / modelid 02FF
11/09 16:26:26 yS4 checking pnpid USR / modelid 0088
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0687
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0566
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0707
11/09 16:26:26 yS4 checking pnpid ELS / modelid 8318
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0853
11/09 16:26:26 yS4 checking pnpid ELS / modelid 8548
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0754
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0350
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0503
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0667
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0152
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0363
11/09 16:26:26 yS4 checking pnpid ELS / modelid 0862
11/09 16:26:26 yS4 checking pnpid ELS / modelid 6026
11/09 16:26:26 yS4 checking pnpid ELS / modelid 6027
11/09 16:26:26 yS4 serial port: OK
11/09 16:26:27 yS4 voice command: 'ATI3' -> ''
11/09 16:26:27 yS4 vgetty: ATI3
11/09 16:26:27 yS4 serial port: U.S. Robotics 56K Voice INT V5.20.1
11/09 16:26:27 yS4 serial port: OK
11/09 16:26:27 yS4 voice command: 'ATI' -> ''
11/09 16:26:27 yS4 vgetty: ATI
11/09 16:26:27 yS4 serial port: 5601
11/09 16:26:27 yS4 US Robotics: OK
11/09 16:26:27 yS4 US Robotics detected
11/09 16:26:27 yS4 vgetty: entering voice mode
11/09 16:26:27 yS4 vgetty: Installing signal handlers
11/09 16:26:27 yS4 voice command: 'AT#CLS?' -> ''
11/09 16:26:27 yS4 vgetty: AT#CLS?
11/09 16:26:27 yS4 US Robotics: 2.0
11/09 16:26:27 yS4 voice command: '' -> 'OK'
11/09 16:26:27 yS4 US Robotics: OK
11/09 16:26:27 yS4 voice command: 'AT#CLS=8' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT#CLS=8
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 voice command: 'AT' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 voice command:
'AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100' -> 'OK'
11/09 16:26:28 yS4 vgetty:
AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 vgetty: queued event RESET_WATCHDOG at position
0000
11/09 16:26:28 yS4 US Robotics voice modem
11/09 16:26:28 yS4 This is a driver beta version. V0.4.b3
11/09 16:26:28 yS4 voice command: 'AT&H1&R2&I0' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT&H1&R2&I0
11/09 16:26:28 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0000
11/09 16:26:28 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <NUL>
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 tio_set_flow_control( HARD )
11/09 16:26:28 yS4 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT#VTD=3F,3F,3F
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 VTD setup successful
11/09 16:26:28 yS4 voice command: 'AT#VSD=1#VSS=2#VSP=70' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT#VSD=1#VSS=2#VSP=70
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 voice command: 'AT#VRA=70#VRN=100' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT#VRA=70#VRN=100
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:28 yS4 vgetty: leaving voice mode
11/09 16:26:28 yS4 voice command: 'AT#CLS=2.0' -> 'OK'
11/09 16:26:28 yS4 vgetty: AT#CLS=2.0
11/09 16:26:28 yS4 US Robotics: OK
11/09 16:26:29 yS4 voice command: 'AT' -> 'OK'
11/09 16:26:29 yS4 vgetty: AT
11/09 16:26:29 yS4 US Robotics: OK
11/09 16:26:29 yS4 vgetty: Restoring signal handlers
11/09 16:26:29 yS4 running post_init_chat
11/09 16:26:29 yS4 send: ATS41=1#CID=1[0d]
11/09 16:26:29 yS4 waiting for ``OK''
11/09 16:26:29 yS4 got: [0d]
11/09 16:26:29 yS4 CND: OK[0a]OK ** found **
11/09 16:26:29 yS4 waiting for line to clear (VTIME), read: [0d][0a]
11/09 16:26:29 yS4 removing lock file
11/09 16:26:29 yS4 waiting...
11/09 16:26:58 yS4 select returned 1
11/09 16:26:58 yS4 checking lockfiles, locking the line
11/09 16:26:58 yS4 makelock(ttyS4) called
11/09 16:26:58 yS4 do_makelock: lock='/var/lock/LCK..ttyS4'
11/09 16:26:58 yS4 lock made
11/09 16:26:58 yS4 vgetty: number of rings (3) was set directly
11/09 16:26:58 yS4 wfr: waiting for ``RING''
11/09 16:26:58 yS4 got: [0a][0d][0a]RING B[0d]
11/09 16:26:58 yS4 CND: RING B
11/09 16:26:58 yS4 wfr: rc=0, drn=2
11/09 16:26:58 yS4 wfr: waiting for ``RING''
11/09 16:26:58 yS4 got: [0a][0d][0a]DATE = 1109[0d]
11/09 16:27:00 yS4 CND: DATE = 1109
11/09 16:27:00 yS4 CND: found: 1109
11/09 16:27:00 yS4 got: [0a]TIME = 1626[0d]
11/09 16:27:00 yS4 CND: TIME = 1626
11/09 16:27:00 yS4 CND: found: 1626
11/09 16:27:00 yS4 got: [0a]NMBR = 5551234[07][0d]
11/09 16:27:00 yS4 CND: NMBR = 5551234_
11/09 16:27:00 yS4 CND: found: 5551234
11/09 16:27:00 yS4 wfr: rc=0, drn=2
11/09 16:27:00 yS4 wfr: waiting for ``RING''
11/09 16:27:00 yS4 got: [0a][0d][0a]RING B[0d]
11/09 16:27:04 yS4 CND: RING B
11/09 16:27:04 yS4 wfr: rc=0, drn=2
11/09 16:27:04 yS4 CND: check no: '5551234 '
11/09 16:27:04 yS4 CND: program "/etc/mgetty+sendfax/ringtype.sh
ttyS4 '5551234 ' '' 2 '' >/dev/console 2>&1 </dev/null"
11/09 16:27:04 yS4 CND: rc=0x0
11/09 16:27:04 yS4 setenv: 'CALLER_ID=5551234 '
11/09 16:27:04 yS4 setenv: 'CONNECT='
11/09 16:27:04 yS4 setenv: 'DEVICE=ttyS4'
11/09 16:27:04 yS4 reading ring_type ring2 configuration from config
file /etc/mgetty+sendfax/voice.conf
11/09 16:27:04 yS4 reading /etc/mgetty+sendfax/voice.conf...
11/09 16:27:04 yS4 conf lib: read: 'part generic'
11/09 16:27:04 yS4 found CT_KEYWORD part generic
11/09 16:27:04 yS4 conf lib: read: 'voice_log_level 6'
11/09 16:27:04 yS4 conf lib: read: 'voice_shell_log
/var/log/vgetty_voice_shell.%s'
11/09 16:27:04 yS4 conf lib: read: 'voice_dir /var/spool/voice'
11/09 16:27:04 yS4 conf lib: read: 'phone_owner uucp'
11/09 16:27:04 yS4 conf lib: read: 'phone_group uucp'
11/09 16:27:04 yS4 conf lib: read: 'phone_mode 0660'
11/09 16:27:04 yS4 conf lib: read: 'message_flag_file .flag'
11/09 16:27:04 yS4 conf lib: read: 'receive_dir incoming'
11/09 16:27:04 yS4 conf lib: read: 'message_dir messages'
11/09 16:27:04 yS4 conf lib: read: 'message_list Index'
11/09 16:27:04 yS4 conf lib: read: 'backup_message standard.rmd'
11/09 16:27:04 yS4 conf lib: read: 'port_speed 38400'
11/09 16:27:04 yS4 conf lib: read: 'voice_shell /usr/bin/perl'
11/09 16:27:04 yS4 conf lib: read: 'port_timeout 10'
11/09 16:27:04 yS4 conf lib: read: 'dial_timeout 90'
11/09 16:27:04 yS4 conf lib: read: 'command_delay 100'
11/09 16:27:04 yS4 conf lib: read: 'dtmf_len 30'
11/09 16:27:04 yS4 conf lib: read: 'dtmf_threshold 40'
11/09 16:27:04 yS4 conf lib: read: 'dtmf_wait 7'
11/09 16:27:04 yS4 conf lib: read: 'ignore_fax_dle false'
11/09 16:27:04 yS4 conf lib: read: 'raw_data false'
11/09 16:27:04 yS4 conf lib: read: 'rec_compression 0'
11/09 16:27:04 yS4 conf lib: read: 'rec_speed 0'
11/09 16:27:04 yS4 conf lib: read: 'rec_silence_len 70'
11/09 16:27:04 yS4 conf lib: read: 'rec_silence_threshold 40'
11/09 16:27:04 yS4 conf lib: read: 'rec_remove_silence false'
11/09 16:27:04 yS4 conf lib: read: 'rec_max_len 300'
11/09 16:27:04 yS4 conf lib: read: 'rec_min_len 5'
11/09 16:27:04 yS4 conf lib: read: 'do_hard_flow true'
11/09 16:27:04 yS4 conf lib: read: 'beep_frequency 933'
11/09 16:27:04 yS4 conf lib: read: 'beep_length 1500'
11/09 16:27:04 yS4 conf lib: read: 'max_tries 3'
11/09 16:27:04 yS4 conf lib: read: 'retry_delay 5'
11/09 16:27:04 yS4 conf lib: read: 'watchdog_timeout 60'
11/09 16:27:04 yS4 conf lib: read: 'receive_gain 100%'
11/09 16:27:04 yS4 conf lib: read: 'transmit_gain 100%'
11/09 16:27:04 yS4 conf lib: read: 'enable_command_echo false'
11/09 16:27:04 yS4 conf lib: read: 'poll_interval 10'
11/09 16:27:04 yS4 conf lib: read: 'program vgetty'
11/09 16:27:04 yS4 conf lib: read: 'rings 3'
11/09 16:27:04 yS4 conf lib: read: 'force_autodetect false'
11/09 16:27:04 yS4 conf lib: read: 'toll_saver_rings 0'
11/09 16:27:04 yS4 conf lib: read: 'rec_always_keep true'
11/09 16:27:04 yS4 conf lib: read: 'button_program '
11/09 16:27:04 yS4 conf lib: read: 'call_program
/usr/local/vocp/bin/vocp.pl'
11/09 16:27:04 yS4 conf lib: read: 'dtmf_program dtmf.sh'
11/09 16:27:04 yS4 conf lib: read: 'message_program
/usr/bin/cnd-program.py'
11/09 16:27:04 yS4 conf lib: read: 'do_message_light false'
11/09 16:27:04 yS4 conf lib: read: 'ring_report_delay 15'
11/09 16:27:04 yS4 conf lib: read: 'program vm'
11/09 16:27:04 yS4 conf lib: read: 'voice_devices ttyS4'
11/09 16:27:04 yS4 conf lib: read: 'dialout_timeout 90'
11/09 16:27:04 yS4 conf lib: read: 'ringback_goes_away 70'
11/09 16:27:04 yS4 conf lib: read: 'ringback_never_came 100'
11/09 16:27:04 yS4 conf lib: read: 'program pvf'
11/09 16:27:04 yS4 conf lib: read: 'port ttyS4'
11/09 16:27:04 yS4 conf lib: read: 'ring_type virtual'
11/09 16:27:04 yS4 section: ring_type virtual, ignore
11/09 16:27:04 yS4 conf lib: read: 'answer_mode fax:data'
11/09 16:27:04 yS4 conf lib: read: 'ring_type ring2'
11/09 16:27:04 yS4 section: ring_type ring2, **found**
11/09 16:27:04 yS4 conf lib: read: 'answer_mode voice:fax:data'
11/09 16:27:04 yS4 key: 'part', type=6, flags=4, data=(ignored)
11/09 16:27:04 yS4 key: 'program', type=6, flags=4, data=(ignored)
11/09 16:27:04 yS4 key: 'port', type=6, flags=4, data=(ignored)
11/09 16:27:04 yS4 key: 'ring_type', type=6, flags=4, data=(ignored)
11/09 16:27:04 yS4 key: 'voice_log_level', type=0, flags=3, data=6
11/09 16:27:04 yS4 key: 'voice_shell_log', type=1, flags=3,
data=/var/log/vgetty_voice_shell.%s
11/09 16:27:04 yS4 key: 'voice_shell', type=1, flags=3,
data=/usr/bin/perl
11/09 16:27:04 yS4 key: 'port_speed', type=0, flags=3, data=38400
11/09 16:27:04 yS4 key: 'port_timeout', type=0, flags=3, data=10
11/09 16:27:04 yS4 key: 'dial_timeout', type=0, flags=3, data=90
11/09 16:27:04 yS4 key: 'command_delay', type=0, flags=3, data=100
11/09 16:27:04 yS4 key: 'dtmf_len', type=0, flags=3, data=30
11/09 16:27:04 yS4 key: 'dtmf_threshold', type=0, flags=3, data=40
11/09 16:27:04 yS4 key: 'dtmf_wait', type=0, flags=3, data=7
11/09 16:27:04 yS4 key: 'ignore_fax_dle', type=3, flags=3, data=FALSE
11/09 16:27:04 yS4 key: 'raw_data', type=3, flags=3, data=FALSE
11/09 16:27:04 yS4 key: 'rec_compression', type=0, flags=3, data=0
11/09 16:27:04 yS4 key: 'rec_speed', type=0, flags=3, data=0
11/09 16:27:04 yS4 key: 'rec_silence_len', type=0, flags=3, data=70
11/09 16:27:04 yS4 key: 'rec_silence_threshold', type=0, flags=3,
data=40
11/09 16:27:04 yS4 key: 'rec_remove_silence', type=3, flags=3,
data=FALSE
11/09 16:27:04 yS4 key: 'rec_max_len', type=0, flags=3, data=300
11/09 16:27:04 yS4 key: 'rec_min_len', type=0, flags=3, data=5
11/09 16:27:04 yS4 key: 'do_hard_flow', type=3, flags=3, data=TRUE
11/09 16:27:04 yS4 key: 'force_autodetect', type=3, flags=3,
data=FALSE
11/09 16:27:04 yS4 key: 'watchdog_timeout', type=0, flags=3, data=60
11/09 16:27:04 yS4 key: 'receive_gain', type=0, flags=3, data=100
11/09 16:27:04 yS4 key: 'transmit_gain', type=0, flags=3, data=100
11/09 16:27:04 yS4 key: 'enable_command_echo', type=3, flags=3,
data=FALSE
11/09 16:27:04 yS4 key: 'poll_interval', type=0, flags=3, data=10
11/09 16:27:04 yS4 key: 'forceV253', type=3, flags=1, data=FALSE
11/09 16:27:04 yS4 key: 'rings', type=1, flags=3, data=3
11/09 16:27:04 yS4 key: 'answer_mode', type=1, flags=3,
data=voice:fax:data
11/09 16:27:04 yS4 key: 'toll_saver_rings', type=0, flags=3, data=0
11/09 16:27:04 yS4 key: 'rec_always_keep', type=3, flags=3, data=TRUE
11/09 16:27:04 yS4 key: 'voice_dir', type=1, flags=3,
data=/var/spool/voice
11/09 16:27:04 yS4 key: 'phone_owner', type=1, flags=3, data=uucp
11/09 16:27:04 yS4 key: 'phone_group', type=1, flags=3, data=uucp
11/09 16:27:04 yS4 key: 'phone_mode', type=0, flags=3, data=432
11/09 16:27:04 yS4 key: 'message_flag_file', type=1, flags=3,
data=.flag
11/09 16:27:04 yS4 key: 'receive_dir', type=1, flags=3, data=incoming
11/09 16:27:04 yS4 key: 'message_dir', type=1, flags=3, data=messages
11/09 16:27:04 yS4 key: 'message_list', type=1, flags=3, data=Index
11/09 16:27:04 yS4 key: 'backup_message', type=1, flags=3,
data=standard.rmd
11/09 16:27:04 yS4 key: 'button_program', type=1, flags=3, data=
11/09 16:27:04 yS4 key: 'call_program', type=1, flags=3,
data=/usr/local/vocp/bin/vocp.pl
11/09 16:27:04 yS4 key: 'dtmf_program', type=1, flags=3, data=dtmf.sh
11/09 16:27:04 yS4 key: 'message_program', type=1, flags=3,
data=/usr/bin/cnd-program.py
11/09 16:27:04 yS4 key: 'do_message_light', type=3, flags=3,
data=FALSE
11/09 16:27:04 yS4 key: 'pre_message', type=1, flags=1, data=
11/09 16:27:04 yS4 key: 'beepsound', type=1, flags=1, data=
11/09 16:27:04 yS4 key: 'beep_frequency', type=0, flags=3, data=933
11/09 16:27:04 yS4 key: 'beep_length', type=0, flags=3, data=1500
11/09 16:27:04 yS4 key: 'max_tries', type=0, flags=3, data=3
11/09 16:27:04 yS4 key: 'retry_delay', type=0, flags=3, data=5
11/09 16:27:04 yS4 key: 'dialout_timeout', type=0, flags=1, data=90
11/09 16:27:04 yS4 key: 'ringback_goes_away', type=0, flags=1,
data=70
11/09 16:27:04 yS4 key: 'ringback_never_came', type=0, flags=1,
data=100
11/09 16:27:04 yS4 key: 'ring_report_delay', type=0, flags=3, data=15
11/09 16:27:04 yS4 key: 'voice_devices', type=1, flags=1, data=
11/09 16:27:04 yS4 key: 'force_detect', type=1, flags=1, data=
11/09 16:27:04 yS4 vgetty: answer mode was set directly
11/09 16:27:04 yS4 vgetty: answer mode is [data|fax|voice]
11/09 16:27:04 yS4 vgetty: opening list file
/var/spool/voice/messages/Index
11/09 16:27:04 yS4 vgetty: message name is
/var/spool/voice/messages/standard.rmd
11/09 16:27:04 yS4 vgetty: entering voice mode
11/09 16:27:04 yS4 vgetty: Installing signal handlers
11/09 16:27:04 yS4 voice command: 'AT#CLS?' -> ''
11/09 16:27:04 yS4 vgetty: AT#CLS?
11/09 16:27:04 yS4 US Robotics: 2.0
11/09 16:27:04 yS4 voice command: '' -> 'OK'
11/09 16:27:05 yS4 US Robotics: OK
11/09 16:27:05 yS4 voice command: 'AT#CLS=8' -> 'OK'
11/09 16:27:05 yS4 vgetty: AT#CLS=8
11/09 16:27:05 yS4 US Robotics: OK
11/09 16:27:05 yS4 voice command: 'AT' -> 'OK'
11/09 16:27:05 yS4 vgetty: AT
11/09 16:27:05 yS4 US Robotics: OK
11/09 16:27:05 yS4 voice command:
'AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100' -> 'OK'
11/09 16:27:05 yS4 vgetty:
AT#VTD=3F,3F,3F#VSD=1#VSS=2#VSP=70#VRA=70#VRN=100
11/09 16:27:05 yS4 US Robotics: OK
11/09 16:27:05 yS4 voice command: 'AT#VLS=0A' -> 'VCON'
11/09 16:27:05 yS4 vgetty: AT#VLS=0A
11/09 16:27:05 yS4 US Robotics: VCON
11/09 16:27:05 yS4 vgetty: queued event RESET_WATCHDOG at position
0001
11/09 16:27:05 yS4 voice command: 'AT#VLS=0' -> 'OK|VCON'
11/09 16:27:05 yS4 vgetty: AT#VLS=0
11/09 16:27:05 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0001
11/09 16:27:05 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <_>
11/09 16:27:05 yS4 US Robotics: OK
11/09 16:27:05 yS4 vgetty: Executing shell script
/usr/local/vocp/bin/vocp.pl with shell /usr/bin/perl
11/09 16:27:05 yS4 vgetty: opening pipes
11/09 16:27:05 yS4 vgetty: forking shell
11/09 16:27:05 yS4 vgetty(0): HELLO SHELL
11/09 16:27:06 yS4 vgetty: Got pipe signal
11/09 16:27:06 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0002
11/09 16:27:06 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0002
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/09 16:27:06 yS4 shell(1): HELLO VOICE PROGRAM
11/09 16:27:06 yS4 vgetty(1): READY
11/09 16:27:06 yS4 vgetty: initialized communication
11/09 16:27:06 yS4 vgetty: Got pipe signal
11/09 16:27:06 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0003
11/09 16:27:06 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0003
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/09 16:27:06 yS4 shell(1): DEVICE DIALUP_LINE
11/09 16:27:06 yS4 vgetty: queued event RESET_WATCHDOG at position
0004
11/09 16:27:06 yS4 voice command: 'AT#VLS=0' -> 'OK|VCON'
11/09 16:27:06 yS4 vgetty: AT#VLS=0
11/09 16:27:06 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0004
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <_>
11/09 16:27:06 yS4 US Robotics: OK
11/09 16:27:06 yS4 vgetty(1): READY
11/09 16:27:06 yS4 vgetty: Got pipe signal
11/09 16:27:06 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0005
11/09 16:27:06 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0005
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/09 16:27:06 yS4 shell(1): AUTOSTOP ON
11/09 16:27:06 yS4 vgetty(1): READY
11/09 16:27:06 yS4 vgetty: Got pipe signal
11/09 16:27:06 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0006
11/09 16:27:06 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0006
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/09 16:27:06 yS4 shell(1): ENABLE EVENTS
11/09 16:27:06 yS4 vgetty(1): READY
11/09 16:27:06 yS4 vgetty: Got pipe signal
11/09 16:27:06 yS4 vgetty: queued event SIGNAL_SIGPIPE at position
0007
11/09 16:27:06 yS4 vgetty: unqueued event SIGNAL_SIGPIPE at position
0007
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGPIPE with data <_>
11/09 16:27:06 yS4 shell(1): PLAY /var/spool/voice/messages/root.rmd
11/09 16:27:06 yS4 vgetty(1): PLAYING
11/09 16:27:06 yS4 playing voice file
/var/spool/voice/messages/root.rmd
11/09 16:27:06 yS4 vgetty: raw modem data header found
11/09 16:27:06 yS4 vgetty: modem type US Robotics found
11/09 16:27:06 yS4 vgetty: compression method 0x0001, speed 8000,
bits 8
11/09 16:27:06 yS4 vgetty: queued event RESET_WATCHDOG at position
0008
11/09 16:27:06 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0008
11/09 16:27:06 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <_>
11/09 16:27:06 yS4 voice command: 'AT' -> 'OK|VCON'
11/09 16:27:06 yS4 vgetty: AT
11/09 16:27:06 yS4 US Robotics: OK
11/09 16:27:06 yS4 tio_set_flow_control( HARD XON_OUT )
11/09 16:27:06 yS4 voice command: 'ATE0#VTX' -> 'CONNECT'
11/09 16:27:06 yS4 vgetty: ATE0#VTX
11/09 16:27:06 yS4 US Robotics: CONNECT
11/09 16:27:07 yS4 US Robotics: <DLE> <D>
11/09 16:27:07 yS4 vgetty: queued event RECEIVED_DTMF at position
0009
11/09 16:27:07 yS4 vgetty: unqueued event RECEIVED_DTMF at position
0009
11/09 16:27:07 yS4 vgetty: voice_handle_event got event
RECEIVED_DTMF with data <D>
11/09 16:27:07 yS4 vgetty: stopping current action
11/09 16:27:07 yS4 vgetty(1): RECEIVED_DTMF
11/09 16:27:07 yS4 vgetty(1): D
11/09 16:27:07 yS4 vgetty: <VOICE DATA 4800 bytes>
11/09 16:27:07 yS4 vgetty: queued event RESET_WATCHDOG at position
0010
11/09 16:27:07 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0010
11/09 16:27:07 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <_>
11/09 16:27:07 yS4 vgetty: <INTERRUPT PLAY>
11/09 16:27:07 yS4 voice command: '' -> 'OK|VCON'
11/09 16:27:07 yS4 US Robotics: VCON
11/09 16:27:07 yS4 voice command: 'AT' -> 'OK'
11/09 16:27:07 yS4 vgetty: AT
11/09 16:27:07 yS4 US Robotics: OK
11/09 16:27:07 yS4 vgetty(1): READY
11/09 16:27:07 yS4 vgetty: Got child -1 exit status -1 signal
11/09 16:27:07 yS4 vgetty: queued event SIGNAL_SIGCHLD at position
0011
11/09 16:27:07 yS4 vgetty: shell exited normally with status 0x0001
11/09 16:27:07 yS4 vgetty: asked DATA
11/09 16:27:07 yS4 vgetty: trying data connection
11/09 16:27:07 yS4 vgetty: queued event RESET_WATCHDOG at position
0012
11/09 16:27:07 yS4 voice command: 'AT#CLS=2.0' -> 'OK'
11/09 16:27:08 yS4 vgetty: AT#CLS=2.0
11/09 16:27:08 yS4 vgetty: unqueued event SIGNAL_SIGCHLD at position
0011
11/09 16:27:08 yS4 vgetty: voice_handle_event got event
SIGNAL_SIGCHLD with data <_>
11/09 16:27:08 yS4 vgetty: voice_handle_event got unknown event
SIGNAL_SIGCHLD with data <_>
11/09 16:27:08 yS4 vgetty: unqueued event RESET_WATCHDOG at position
0012
11/09 16:27:08 yS4 vgetty: voice_handle_event got event
RESET_WATCHDOG with data <_>
11/09 16:27:08 yS4 US Robotics: OK
11/09 16:27:08 yS4 voice command: 'AT' -> 'OK'
11/09 16:27:08 yS4 vgetty: AT
11/09 16:27:08 yS4 US Robotics: OK
11/09 16:27:08 yS4 voice command: 'AT+FCLASS=0' -> 'OK'
11/09 16:27:08 yS4 vgetty: AT+FCLASS=0
11/09 16:27:08 yS4 US Robotics: OK
11/09 16:27:08 yS4 voice command: 'AT+FAA=0' -> 'OK'
11/09 16:27:08 yS4 vgetty: AT+FAA=0
11/09 16:27:08 yS4 US Robotics: OK
11/09 16:27:08 yS4 vgetty: Restoring signal handlers
11/09 16:27:08 yS4 send: ATA[0d]
11/09 16:27:08 yS4 waiting for ``CONNECT''
11/09 16:27:08 yS4 got: [0d]
11/09 16:27:22 yS4 CND: OK[0a]CONNECT ** found **
11/09 16:27:22 yS4 send:
11/09 16:27:22 yS4 waiting for ``_''
11/09 16:27:22 yS4 got: 2400/ARQ/LAPM/V42BIS[0d]
11/09 16:27:22 yS4 CND: CONNECT 2400/ARQ/LAPM/V42BIS
11/09 16:27:22 yS4 CND: found: 2400/ARQ/LAPM/V42BIS[0a] ** found **
11/09 16:27:22 yS4 waiting for line to clear (VTIME), read:
11/09 16:27:23 yS4 looking for utmp entry... (my PID: 10168)
11/09 16:27:23 yS4 utmp + wtmp entry made
11/09 16:27:23 yS4 tio_set_flow_control( HARD )
11/09 16:27:23 yS4 print welcome banner (/etc/issue)
11/09 16:27:23 yS4 getlogname (AUTO_PPP), read:~[ff]}#[c0]!
11/09 16:27:24 yS4 input finished with '\r', setting ICRNL ONLCR
11/09 16:27:24 yS4 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD
11/09 16:27:24 yS4 login: use login config file
/etc/mgetty+sendfax/login.config
11/09 16:27:24 yS4 match: user='/AutoPPP/', key=''
11/09 16:27:24 yS4 match: user='/AutoPPP/', key=''
11/09 16:27:24 yS4 match: user='/AutoPPP/', key='/AutoPPP/'*** hit!
11/09 16:27:24 yS4 calling login: cmd='/usr/sbin/pppd', argv[]='pppd
auth -chap +pap login debug'
11/09 16:27:24 yS4 setenv: 'CALLER_ID=5551234 '
11/09 16:27:24 yS4 setenv: 'CONNECT=2400/ARQ/LAPM/V42BIS'
11/09 16:27:24 yS4 setenv: 'DEVICE=ttyS4'
11/09 16:27:24 ##### data dev=ttyS4, pid=10168, caller='5551234 ',
conn='2400/ARQ/LAPM/V42BIS', name='', cmd='/usr/sbin/pppd',
user='/AutoPPP/'

[Brian J. McGovern]

Post by A***@yahoo.com
Has anyone been able to get vgetty to estabilish a data connection
using DTMF tones?
Respectfully,
Gary

Yes.

However, for the last several years it has been via external "script" (I
have a rather complex call-in setup, and DTMF->DATA is only one of the
top-level menu items).

However, even without an external script, you should be able to view the
vgetty log, see if its detecting the inbound DTMF, and responding
correctly.

-Brian

--
Posted automagically by a mail2news gateway at muc.de e.V.
Please direct questions, flames, donations, etc. to news-***@muc.de