Perl program for voice calls does not work...

"Thorbjoern List" (list@list.dk)
Fri, 18 Jun 1999 02:10:39 +0200
Messages sorted by:[ date ][ thread ][ subject ][ author ]
Hi there,

My vgetty works perfectly when I just use it the standard way as a voice =
recorder
(greeting, beep, record, end). The voice plays nicely, faxes are =
received, AutoPPP
logins work...

I then installed the Perl scripts from CPAN =
(http://www.cpan.org/authors/id/Y/YE/YENYA/)
and altered two lines in the voice.conf:

	voice_shell /usr/bin/perl

	call_program /usr/local/bin/answering_machine.pl

With these I do not get any voice greeting, just silence, I get no beep, =
but I do get
a recording...

It is the same rmd file I use (even though in two different dirs).

Can anyone help...?

Thorbjoern



The logs for the Perl case - and then for the standard case:

PERL:

06/18 02:00:17 yS0    vgetty: answer mode was set directly
06/18 02:00:17 yS0    vgetty: answer mode is [data|fax|voice]
06/18 02:00:17 yS0    vgetty: opening list file =
/var/spool/voice/messages/Index
06/18 02:00:17 yS0    vgetty: found 1 messages, picked message number 1
06/18 02:00:17 yS0    vgetty: message name is =
/var/spool/voice/messages/welcome.rmd
06/18 02:00:17 yS0   vgetty: entering voice mode
06/18 02:00:17 yS0   vgetty: Installing signal handlers
06/18 02:00:17 yS0   voice command: 'AT+FCLASS?' -> ''
06/18 02:00:17 yS0    vgetty: AT+FCLASS?
06/18 02:00:17 yS0    ZyXEL 2864: 0
06/18 02:00:17 yS0   voice command: '' -> 'OK'
06/18 02:00:17 yS0    ZyXEL 2864: OK
06/18 02:00:17 yS0   voice command: 'AT+FCLASS=3D8' -> 'OK'
06/18 02:00:17 yS0    vgetty: AT+FCLASS=3D8
06/18 02:00:17 yS0    ZyXEL 2864: OK
06/18 02:00:17 yS0   voice command: 'AT' -> 'OK'
06/18 02:00:17 yS0    vgetty: AT
06/18 02:00:17 yS0    ZyXEL 2864: OK
06/18 02:00:17 yS0    vgetty: queued event RESET_WATCHDOG at position =
0001
06/18 02:00:17 yS0   voice command: 'AT+VLS=3D2' -> 'OK|CONNECT*'
06/18 02:00:17 yS0    vgetty: AT+VLS=3D2
06/18 02:00:17 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0001
06/18 02:00:17 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:00:17 yS0    ZyXEL 2864: OK
06/18 02:00:17 yS0    vgetty: queued event RESET_WATCHDOG at position =
0002
06/18 02:00:17 yS0   voice command: 'AT+VLS=3D2' -> 'OK|CONNECT*'
06/18 02:00:17 yS0    vgetty: AT+VLS=3D2
06/18 02:00:17 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0002
06/18 02:00:17 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:00:17 yS0    ZyXEL 2864: OK
06/18 02:00:18 yS0  vgetty: Executing shell script =
/usr/local/bin/answering_machine.pl with shell /usr/bin/perl
06/18 02:00:18 yS0    vgetty: opening pipes
06/18 02:00:18 yS0    vgetty: forking shell
06/18 02:00:18 yS0   vgetty(0): HELLO SHELL
06/18 02:00:19 yS0    vgetty: Got pipe signal
06/18 02:00:19 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0003
06/18 02:00:19 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0003
06/18 02:00:19 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <NUL>
06/18 02:00:19 yS0   shell(1): HELLO VOICE PROGRAM
06/18 02:00:19 yS0   vgetty(1): READY
06/18 02:00:19 yS0   vgetty: initialized communication
06/18 02:00:19 yS0    vgetty: Got pipe signal
06/18 02:00:19 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0004
06/18 02:00:19 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0004
06/18 02:00:19 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <NUL>
06/18 02:00:19 yS0   shell(1): ENABLE EVENTS
06/18 02:00:19 yS0   vgetty(1): READY
06/18 02:00:19 yS0    vgetty: Got pipe signal
06/18 02:00:19 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0005
06/18 02:00:19 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0005
06/18 02:00:19 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <NUL>
06/18 02:00:19 yS0   shell(1): PLAY /var/spool/voice/welcome.rmd
06/18 02:00:19 yS0   vgetty(1): PLAYING
06/18 02:00:19 yS0  playing voice file /var/spool/voice/welcome.rmd
06/18 02:00:19 yS0   vgetty: raw modem data header found
06/18 02:00:19 yS0   vgetty: modem type ZyXEL 2864 found
06/18 02:00:19 yS0   vgetty: compression method 0x0004, speed 9600, bits =
4
06/18 02:00:19 yS0    vgetty: queued event RESET_WATCHDOG at position =
0006
06/18 02:00:19 yS0   voice command: 'AT+VSM=3D4,9600' -> 'OK'
06/18 02:00:19 yS0    vgetty: AT+VSM=3D4,9600
06/18 02:00:19 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0006
06/18 02:00:19 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <o>
06/18 02:00:19 yS0    ZyXEL 2864:=20
06/18 02:00:30 yS0  vgetty: timeout while reading character from voice =
modem
06/18 02:00:30 yS0  vgetty: Illegal compression method
06/18 02:00:30 yS0   vgetty(1): ERROR
06/18 02:00:30 yS0   vgetty(1): READY
06/18 02:00:30 yS0    vgetty: Got pipe signal
06/18 02:00:30 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0007
06/18 02:00:30 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0007
06/18 02:00:30 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <_>
06/18 02:00:30 yS0   shell(1): BEEP 100 10
06/18 02:00:30 yS0   vgetty(1): BEEPING
06/18 02:00:30 yS0    vgetty: queued event RESET_WATCHDOG at position =
0008
06/18 02:00:30 yS0   voice command: 'AT+VTS=3D[100,0,1]' -> ''
06/18 02:00:30 yS0    vgetty: AT+VTS=3D[100,0,1]
06/18 02:00:30 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0008
06/18 02:00:30 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <o>
06/18 02:00:30 yS0   voice command: '' -> 'OK'
06/18 02:00:30 yS0    ZyXEL 2864: OK
06/18 02:00:30 yS0   vgetty(1): READY
06/18 02:00:30 yS0    vgetty: Got pipe signal
06/18 02:00:30 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0009
06/18 02:00:30 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0009
06/18 02:00:30 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <_>
06/18 02:00:30 yS0   shell(1): RECORD /var/spool/voice/9.rmd
06/18 02:00:30 yS0   vgetty(1): RECORDING
06/18 02:00:30 yS0  recording voice file /var/spool/voice/9.rmd
06/18 02:00:30 yS0    vgetty: queued event RESET_WATCHDOG at position =
0010
06/18 02:00:30 yS0   voice command: 'AT+VSM=3D4,9600' -> 'OK'
06/18 02:00:30 yS0    vgetty: AT+VSM=3D4,9600
06/18 02:00:30 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0010
06/18 02:00:30 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:00:30 yS0    ZyXEL 2864: OK
06/18 02:00:30 yS0    vgetty: queued event RESET_WATCHDOG at position =
0011
06/18 02:00:30 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0011
06/18 02:00:30 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:00:30 yS0   voice command: 'AT+FLO=3D2' -> 'OK'
06/18 02:00:30 yS0    vgetty: AT+FLO=3D2
06/18 02:00:30 yS0    ZyXEL 2864: OK
06/18 02:00:30 yS0   tio_set_flow_control( HARD XON_IN )
06/18 02:00:30 yS0   voice command: 'AT+VRX' -> 'CONNECT'
06/18 02:00:30 yS0    vgetty: AT+VRX
06/18 02:00:30 yS0    ZyXEL 2864: CONNECT
06/18 02:01:00 yS0    vgetty: Got pipe signal
06/18 02:01:00 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0012
06/18 02:01:00 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0012
06/18 02:01:00 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <NUL>
06/18 02:01:00 yS0   shell(2): STOP
06/18 02:01:00 yS0    vgetty: <STOP RECORDING>
06/18 02:01:00 yS0    ZyXEL 2864: <VOICE DATA 142132 bytes>
06/18 02:01:00 yS0    ZyXEL 2864: <DLE> <ETX>
06/18 02:01:00 yS0   voice command: '' -> 'OK'
06/18 02:01:00 yS0    ZyXEL 2864: OK
06/18 02:01:00 yS0   vgetty(1): READY
06/18 02:01:00 yS0    vgetty: Got pipe signal
06/18 02:01:00 yS0    vgetty: queued event SIGNAL_SIGPIPE at position =
0013
06/18 02:01:00 yS0    vgetty: unqueued event SIGNAL_SIGPIPE at position =
0013
06/18 02:01:00 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGPIPE with data <_>
06/18 02:01:00 yS0   shell(1): GOODBYE
06/18 02:01:00 yS0   vgetty(1): GOODBYE SHELL
06/18 02:01:00 yS0    vgetty: Got child changed status signal
06/18 02:01:00 yS0    vgetty: queued event SIGNAL_SIGCHLD at position =
0014
06/18 02:01:00 yS0   vgetty: shell exited normally with status 0x0000
06/18 02:01:00 yS0    vgetty: queued event RESET_WATCHDOG at position =
0015
06/18 02:01:00 yS0   voice command: 'AT+VLS=3D0' -> 'OK'
06/18 02:01:00 yS0    vgetty: AT+VLS=3D0
06/18 02:01:00 yS0    vgetty: unqueued event SIGNAL_SIGCHLD at position =
0014
06/18 02:01:00 yS0    vgetty: voice_handle_event got event =
SIGNAL_SIGCHLD with data <_>
06/18 02:01:00 yS0    vgetty: voice_handle_event got unknown event =
SIGNAL_SIGCHLD with data <_>
06/18 02:01:00 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0015
06/18 02:01:00 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:01:00 yS0    ZyXEL 2864: OK
06/18 02:01:00 yS0   vgetty: leaving voice mode





STANDARD:


06/18 02:04:30 yS0    vgetty: answer mode was set directly
06/18 02:04:30 yS0    vgetty: answer mode is [data|fax|voice]
06/18 02:04:30 yS0    vgetty: opening list file =
/var/spool/voice/messages/Index
06/18 02:04:30 yS0    vgetty: found 1 messages, picked message number 1
06/18 02:04:30 yS0    vgetty: message name is =
/var/spool/voice/messages/welcome.rmd
06/18 02:04:30 yS0   vgetty: entering voice mode
06/18 02:04:30 yS0   vgetty: Installing signal handlers
06/18 02:04:30 yS0   voice command: 'AT+FCLASS?' -> ''
06/18 02:04:30 yS0    vgetty: AT+FCLASS?
06/18 02:04:30 yS0    ZyXEL 2864: 0
06/18 02:04:30 yS0   voice command: '' -> 'OK'
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0   voice command: 'AT+FCLASS=3D8' -> 'OK'
06/18 02:04:31 yS0    vgetty: AT+FCLASS=3D8
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0   voice command: 'AT' -> 'OK'
06/18 02:04:31 yS0    vgetty: AT
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0    vgetty: queued event RESET_WATCHDOG at position =
0001
06/18 02:04:31 yS0   voice command: 'AT+VLS=3D2' -> 'OK|CONNECT*'
06/18 02:04:31 yS0    vgetty: AT+VLS=3D2
06/18 02:04:31 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0001
06/18 02:04:31 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0    vgetty: queued event RESET_WATCHDOG at position =
0002
06/18 02:04:31 yS0   voice command: 'AT+VLS=3D2' -> 'OK|CONNECT*'
06/18 02:04:31 yS0    vgetty: AT+VLS=3D2
06/18 02:04:31 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0002
06/18 02:04:31 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0  playing voice file =
/var/spool/voice/messages/welcome.rmd
06/18 02:04:31 yS0   vgetty: raw modem data header found
06/18 02:04:31 yS0   vgetty: modem type ZyXEL 2864 found
06/18 02:04:31 yS0   vgetty: compression method 0x0004, speed 9600, bits =
4
06/18 02:04:31 yS0    vgetty: queued event RESET_WATCHDOG at position =
0003
06/18 02:04:31 yS0   voice command: 'AT+VSM=3D4,9600' -> 'OK'
06/18 02:04:31 yS0    vgetty: AT+VSM=3D4,9600
06/18 02:04:31 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0003
06/18 02:04:31 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <d>
06/18 02:04:31 yS0    ZyXEL 2864: OK
06/18 02:04:31 yS0    vgetty: queued event RESET_WATCHDOG at position =
0004
06/18 02:04:31 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0004
06/18 02:04:31 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <d>
06/18 02:04:31 yS0   voice command: 'AT+FLO=3D2' -> 'OK'
06/18 02:04:32 yS0    vgetty: AT+FLO=3D2
06/18 02:04:32 yS0    ZyXEL 2864: OK
06/18 02:04:32 yS0   tio_set_flow_control( HARD XON_OUT )
06/18 02:04:32 yS0   voice command: 'AT+VTX' -> 'CONNECT'
06/18 02:04:32 yS0    vgetty: AT+VTX
06/18 02:04:32 yS0    ZyXEL 2864: CONNECT
06/18 02:04:32 yS0    ZyXEL 2864: <DLE> <u>
06/18 02:04:32 yS0  vgetty: Buffer underrun
06/18 02:04:37 yS0    vgetty: <VOICE DATA 29478 bytes>
06/18 02:04:37 yS0    vgetty: queued event RESET_WATCHDOG at position =
0005
06/18 02:04:37 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0005
06/18 02:04:37 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <d>
06/18 02:04:37 yS0    vgetty: <STOP PLAY>
06/18 02:04:37 yS0   voice command: '' -> 'OK'
06/18 02:04:37 yS0    ZyXEL 2864: OK
06/18 02:04:38 yS0    vgetty: queued event RESET_WATCHDOG at position =
0006
06/18 02:04:38 yS0   voice command: 'AT+VTS=3D[933,0,100]' -> ''
06/18 02:04:38 yS0    vgetty: AT+VTS=3D[933,0,100]
06/18 02:04:38 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0006
06/18 02:04:38 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:04:38 yS0   voice command: '' -> 'OK'
06/18 02:04:38 yS0    ZyXEL 2864: OK
06/18 02:04:39 yS0  recording voice file =
/var/spool/voice/incoming/vGITElm.rmd
06/18 02:04:39 yS0    vgetty: queued event RESET_WATCHDOG at position =
0007
06/18 02:04:39 yS0   voice command: 'AT+VSM=3D4,9600' -> 'OK'
06/18 02:04:39 yS0    vgetty: AT+VSM=3D4,9600
06/18 02:04:39 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0007
06/18 02:04:39 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <d>
06/18 02:04:39 yS0    ZyXEL 2864: OK
06/18 02:04:39 yS0    vgetty: queued event RESET_WATCHDOG at position =
0008
06/18 02:04:39 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0008
06/18 02:04:39 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <d>
06/18 02:04:39 yS0   voice command: 'AT+FLO=3D2' -> 'OK'
06/18 02:04:39 yS0    vgetty: AT+FLO=3D2
06/18 02:04:39 yS0    ZyXEL 2864: OK
06/18 02:04:39 yS0   tio_set_flow_control( HARD XON_IN )
06/18 02:04:39 yS0   voice command: 'AT+VRX' -> 'CONNECT'
06/18 02:04:39 yS0    vgetty: AT+VRX
06/18 02:04:39 yS0    ZyXEL 2864: CONNECT
06/18 02:04:46 yS0    ZyXEL 2864: <DLE> <b>
06/18 02:04:46 yS0    vgetty: queued event BUSY_TONE at position 0009
06/18 02:04:46 yS0    vgetty: unqueued event BUSY_TONE at position 0009
06/18 02:04:46 yS0    vgetty: voice_handle_event got event BUSY_TONE =
with data <d>
06/18 02:04:46 yS0    vgetty: <STOP RECORDING>
06/18 02:04:46 yS0    ZyXEL 2864: <DLE> <l>
06/18 02:04:46 yS0    vgetty: queued event LOOP_BREAK at position 0010
06/18 02:04:46 yS0    vgetty: unqueued event LOOP_BREAK at position 0010
06/18 02:04:46 yS0    vgetty: voice_handle_event got event LOOP_BREAK =
with data <d>
06/18 02:04:46 yS0    vgetty: voice_handle_event got unknown event =
LOOP_BREAK with data <d>
06/18 02:04:46 yS0    ZyXEL 2864: <VOICE DATA 32616 bytes>
06/18 02:04:46 yS0    ZyXEL 2864: <DLE> <ETX>
06/18 02:04:46 yS0   voice command: '' -> 'OK'
06/18 02:04:46 yS0    ZyXEL 2864: OK
06/18 02:04:46 yS0    vgetty: queued event RESET_WATCHDOG at position =
0011
06/18 02:04:46 yS0   voice command: 'AT+VLS=3D0' -> 'OK'
06/18 02:04:46 yS0    vgetty: AT+VLS=3D0
06/18 02:04:46 yS0    vgetty: unqueued event RESET_WATCHDOG at position =
0011
06/18 02:04:46 yS0    vgetty: voice_handle_event got event =
RESET_WATCHDOG with data <NUL>
06/18 02:04:46 yS0    ZyXEL 2864: ERROR
06/18 02:04:46 yS0  vgetty: Modem returned ERROR
06/18 02:04:46 yS0   vgetty: leaving voice mode
06/18 02:04:46 yS0   voice command: 'AT+FCLASS=3D0' -> 'OK'
06/18 02:04:46 yS0    vgetty: AT+FCLASS=3D0
06/18 02:04:46 yS0    ZyXEL 2864: OK
06/18 02:04:46 yS0   voice command: 'AT' -> 'OK'
06/18 02:04:47 yS0    vgetty: AT
06/18 02:04:47 yS0    ZyXEL 2864: OK
06/18 02:04:47 yS0   vgetty: Restoring signal handlers
06/18 02:04:47 yS0  closing voice modem device
06/18 02:04:47 yS0   removing lock file
06/18 02:04:47 ##### message keep, length=3D00:00:07, name=3D'', =
caller=3D32961169, dev=3DttyS0, pid=3D977

06/18 02:04:47 yS0    vgetty: creating message flag file =
/var/spool/voice/.flag
06/18 02:04:47 yS0   executing message program, dev=3DttyS0, pid=3D977
06/18 02:04:47 yS0  vgetty: Executing shell script =
/usr/local/bin/new_voice with shell /usr/bin/perl
06/18 02:04:47 yS0    vgetty: opening pipes
06/18 02:04:47 yS0    vgetty: forking shell
06/18 02:04:47 yS0   vgetty(0): HELLO SHELL
06/18 02:04:47 yS0   vgetty: shell exited normally with status 0x0000