Caller ID problem Second try with correctly formatted log files. Sorry Gert
"Dave Packham" (dpackham@darkstar.utah.edu)
Mon, 11 Jan 1999 21:15:52 -0700
Guess what. The post-init-chat fixed the callerid problem and now I get the
whole caller id thing going great. BUT. guess what. putting the post-init
string in the mgetty.conf file the modem now answers in data mode as you can
see by the included log files. It inits correctly and wait for the call,
get the caller id then says it set the answer mode manualy to
data:fax:voice. I think I am stomping the answer_mode voice:data:fax line
with the post init chat line. am I close??
Dave.
Learning alot. Thanks for all your help here.
-----Original Message-----
From: Gert Doering <gert@greenie.muc.de>
To: Dave Packham <dpackham@darkstar.utah.edu>; mgetty@muc.de <mgetty@muc.de>
Date: Monday, January 11, 1999 12:45 AM
Subject: Re: Caller ID problem Second try with correctly formatted log
files. Sorry Gert
>Hi,
>
>On Sun, Jan 10, 1999 at 04:37:21PM -0700, Dave Packham wrote:
>> Here it is in minicom this is a block and copy including spaces
>>
>> ##start here##
>> RING
>>
>> MESG = ..0110163.O.
>>
>>
>>
>>
>>
>>
>>
>>
>> 8018090623f
>
>Was that with AT#CID=1 or #CID=2? This MESG = ... stuff should be
>supported, but if I remember correctly, AT#CID=1 produced a lot mroe
>useful output.
>
>> This is my cellphone numbers I have changed the first 6 digits to 5' to
save
>> my phone bill but otherwise its right
>
>Seems as if the modem loses its setup after a mode change
>(fax/voice/data), which can be found in the archives for some modems.
>
>Try setting
>
> post-init-chat '' AT#CID=1 OK
>
>in mgetty.config. Then send us a log file showing the 10 lines before
>"waiting..." and the 30 lines following it.
>
>gert
>--
>USENET is *not* the non-clickable part of WWW!
>
//www.muc.de/~gert/
>Gert Doering - Munich, Germany
gert@greenie.muc.de
>fax: +49-89-35655025
gert.doering@physik.tu-muenchen.de
check for lockfiles
01/11 21:10:52 yS1 checklock: stat failed, no file
01/11 21:10:52 yS1 locking the line
01/11 21:10:52 yS1 makelock(ttyS1) called
01/11 21:10:52 yS1 do_makelock: lock='/var/lock/LCK..ttyS1'
01/11 21:10:52 yS1 lock made
01/11 21:10:53 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR
01/11 21:10:53 yS1 lowering DTR to reset Modem
01/11 21:10:53 yS1 tss: set speed to 38400 (017)
01/11 21:10:53 yS1 tio_set_flow_control( HARD )
01/11 21:10:53 yS1 waiting for line to clear (VTIME), read:
01/11 21:10:53 yS1 send: \dATQ0V1H0[0d]
01/11 21:10:54 yS1 waiting for ``OK''
01/11 21:10:54 yS1 got: [0d][0a]OK ** found **
01/11 21:10:54 yS1 send: ATS0=0Q0&D3&C1#CID=1[0d]
01/11 21:10:54 yS1 waiting for ``OK''
01/11 21:10:54 yS1 got: [0d]
01/11 21:10:54 yS1 CND: OK[0a][0d][0a]OK ** found **
01/11 21:10:54 yS1 mdm_send: 'ATI'
01/11 21:10:54 yS1 got:[0d][0a][0d][0a]3361[0d]
01/11 21:10:54 yS1 mdm_gis: string 1: '3361'
01/11 21:10:54 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:54 yS1 mdm_identify: string '3361'
01/11 21:10:54 yS1 USR Courier/Sportster V.34(+) detected
01/11 21:10:54 yS1 mdm_send: 'ATI3'
01/11 21:10:54 yS1 got:[0a][0d][0a]USRobotics Sportster Voice 33600 Fax
RS Rev. 2.0[0d]
01/11 21:10:55 yS1 mdm_gis: string 1: 'USRobotics Sportster Voice 33600
Fax RS Rev. 2.0'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:55 yS1 additional info: 'USRobotics Sportster Voice 33600 Fax
RS Rev. 2.0'
01/11 21:10:55 yS1 mdm_send: 'AT+FCLASS=2.0'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:55 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:55 yS1 mdm_send: 'AT+FAA=1;+FCR=1'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:55 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:55 yS1 mdm_send: 'AT+FBO=1'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:55 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:55 yS1 mdm_send: 'AT+FNR=1,1,1,0'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:55 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:55 yS1 mdm_send: 'AT+FLI="8017569887"'
01/11 21:10:55 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:56 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:56 yS1 mdm_send: 'AT+FCC=1'
01/11 21:10:56 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:10:56 yS1 mdm_command: string 'OK' -> OK
01/11 21:10:56 yS1 tss: set speed to 38400 (017)
01/11 21:10:56 yS1 tio_set_flow_control( HARD )
01/11 21:10:56 yS1 detecting voice modem type
01/11 21:10:56 yS1 vgetty: ATE0
01/11 21:10:56 yS1 voice command: 'ATI' -> ''
01/11 21:10:56 yS1 vgetty: ATI
01/11 21:10:56 yS1 serial port: OK
01/11 21:10:56 yS1 serial port: 3361
01/11 21:10:56 yS1 US Robotics: OK
01/11 21:10:56 yS1 US Robotics detected
01/11 21:10:56 yS1 vgetty: entering voice mode
01/11 21:10:56 yS1 vgetty: Installing signal handlers
01/11 21:10:56 yS1 voice command: 'AT#CLS?' -> ''
01/11 21:10:56 yS1 vgetty: AT#CLS?
01/11 21:10:56 yS1 US Robotics: 0
01/11 21:10:57 yS1 voice command: '' -> 'OK'
01/11 21:10:57 yS1 US Robotics: OK
01/11 21:10:57 yS1 voice command: 'AT#CLS=8' -> 'OK'
01/11 21:10:57 yS1 vgetty: AT#CLS=8
01/11 21:10:57 yS1 US Robotics: OK
01/11 21:10:57 yS1 voice command: 'AT' -> 'OK'
01/11 21:10:57 yS1 vgetty: AT
01/11 21:10:57 yS1 US Robotics: OK
01/11 21:10:57 yS1 vgetty: queued event RESET_WATCHDOG at position 0000
01/11 21:10:57 yS1 US Robotics voice modem
01/11 21:10:57 yS1 This is a driver beta version. V0.4.b3
01/11 21:10:57 yS1 voice command: 'AT&H1&R2&I0' -> 'OK'
01/11 21:10:57 yS1 vgetty: AT&H1&R2&I0
01/11 21:10:57 yS1 vgetty: unqueued event RESET_WATCHDOG at position 0000
01/11 21:10:57 yS1 vgetty: voice_handle_event got event RESET_WATCHDOG
with data <
01/11 21:10:57 yS1 US Robotics: OK
01/11 21:10:57 yS1 tio_set_flow_control( HARD )
01/11 21:10:57 yS1 voice command: 'AT#VTD=3F,3F,3F' -> 'OK'
01/11 21:10:58 yS1 vgetty: AT#VTD=3F,3F,3F
01/11 21:10:58 yS1 US Robotics: OK
01/11 21:10:58 yS1 VTD setup successful
01/11 21:10:58 yS1 voice command: 'AT#VSD=1#VSS=1#VSP=70' -> 'OK'
01/11 21:10:58 yS1 vgetty: AT#VSD=1#VSS=1#VSP=70
01/11 21:10:58 yS1 US Robotics: OK
01/11 21:10:58 yS1 vgetty: leaving voice mode
01/11 21:10:58 yS1 voice command: 'AT#CLS=0' -> 'OK'
01/11 21:10:58 yS1 vgetty: AT#CLS=0
01/11 21:10:58 yS1 US Robotics: OK
01/11 21:10:58 yS1 voice command: 'AT' -> 'OK'
01/11 21:10:58 yS1 vgetty: AT
01/11 21:10:58 yS1 US Robotics: OK
01/11 21:10:59 yS1 vgetty: Restoring signal handlers
01/11 21:10:59 yS1 running post_init_chat
01/11 21:10:59 yS1 send: AT#CID=1[0d]
01/11 21:10:59 yS1 waiting for ``OK''
01/11 21:10:59 yS1 got: [0d]
01/11 21:10:59 yS1 CND: OK[0a]OK ** found **
01/11 21:10:59 yS1 waiting for line to clear (VTIME), read: [0d][0a]
01/11 21:10:59 yS1 removing lock file
01/11 21:10:59 yS1 waiting...
01/11 21:11:11 yS1 select returned 1
01/11 21:11:11 yS1 checking lockfiles, locking the line
01/11 21:11:11 yS1 makelock(ttyS1) called
01/11 21:11:11 yS1 do_makelock: lock='/var/lock/LCK..ttyS1'
01/11 21:11:11 yS1 lock made
01/11 21:11:11 yS1 vgetty: number of rings (6) was set directly
01/11 21:11:11 yS1 vgetty: decremented number of rings (6) by 0
01/11 21:11:11 yS1 wfr: waiting for ``RING''
01/11 21:11:11 yS1 got: [0a][0d][0a]RING[0d]
01/11 21:11:11 yS1 CND: RING
01/11 21:11:11 yS1 wfr: rc=0, drn=0
01/11 21:11:11 yS1 wfr: waiting for ``RING''
01/11 21:11:11 yS1 got: [0a][0d][0a]DATE = 0111[0d]
01/11 21:11:12 yS1 CND: DATE = 0111
01/11 21:11:12 yS1 CND: found: 0111
01/11 21:11:12 yS1 got: [0a]TIME = 2050[0d]
01/11 21:11:12 yS1 CND: TIME = 2050
01/11 21:11:12 yS1 CND: found: 2050
01/11 21:11:12 yS1 got: [0a]NAME = UNIV OF UT [0d]
01/11 21:11:12 yS1 CND: NAME = UNIV OF UT
01/11 21:11:12 yS1 CND: found: UNIV OF UT
snip
01/11 21:11:41 yS1 key: 'max_tries', type=0, flags=3, data=3
01/11 21:11:41 yS1 key: 'retry_delay', type=0, flags=3, data=5
01/11 21:11:41 yS1 key: 'dialout_timeout', type=0, flags=1, data=90
01/11 21:11:41 yS1 key: 'voice_devices', type=1, flags=1, data=
01/11 21:11:41 yS1 vgetty: answer mode was set directly
01/11 21:11:41 yS1 vgetty: answer mode is [data|fax|voice]
01/11 21:11:41 yS1 vgetty: opening list file
/var/spool/voice/messages/Index
01/11 21:11:41 yS1 vgetty: message name is
/var/spool/voice/messages/standard.rmd
01/11 21:11:41 yS1 vgetty: entering voice mode
01/11 21:11:41 yS1 vgetty: Installing signal handlers
01/11 21:11:41 yS1 voice command: 'AT#CLS?' -> ''
01/11 21:11:41 yS1 vgetty: AT#CLS?
01/11 21:11:41 yS1 US Robotics: 0
01/11 21:11:42 yS1 voice command: '' -> 'OK'
01/11 21:11:42 yS1 US Robotics: OK
01/11 21:11:42 yS1 voice command: 'AT#CLS=8' -> 'OK'
01/11 21:11:42 yS1 vgetty: AT#CLS=8
01/11 21:11:42 yS1 US Robotics: OK
01/11 21:11:42 yS1 voice command: 'AT' -> 'OK'
01/11 21:11:42 yS1 vgetty: AT
01/11 21:11:42 yS1 US Robotics: OK
01/11 21:11:42 yS1 vgetty: queued event RESET_WATCHDOG at position 0001
01/11 21:11:42 yS1 voice command: 'AT#VLS=0' -> 'OK|VCON'
01/11 21:11:42 yS1 vgetty: AT#VLS=0
01/11 21:11:42 yS1 vgetty: unqueued event RESET_WATCHDOG at position 0001
01/11 21:11:42 yS1 vgetty: voice_handle_event got event RESET_WATCHDOG
with data <
01/11 21:11:42 yS1 US Robotics: OK
01/11 21:11:42 yS1 voice command: 'AT#VLS=4A' -> 'VCON'
01/11 21:11:42 yS1 vgetty: AT#VLS=4A
01/11 21:11:42 yS1 US Robotics: VCON
01/11 21:11:42 yS1 vgetty: Executing shell script
/etc/mgetty+sendfax/switchboard with shell /bin/sh
01/11 21:11:42 yS1 vgetty: opening pipes
01/11 21:11:42 yS1 vgetty: forking shell
01/11 21:11:42 yS1 vgetty(0): HELLO SHELL
01/11 21:11:43 yS1 vgetty: Got child changed status signal
01/11 21:11:43 yS1 vgetty: queued event SIGNAL_SIGCHLD at position 0002
01/11 21:11:43 yS1 vgetty: shell exited normally with status 0x0002
01/11 21:11:43 yS1 vgetty: trying fax connection
01/11 21:11:43 yS1 vgetty: queued event RESET_WATCHDOG at position 0003
01/11 21:11:43 yS1 voice command: 'AT#CLS=0' -> 'OK'
01/11 21:11:43 yS1 vgetty: AT#CLS=0
01/11 21:11:43 yS1 vgetty: unqueued event SIGNAL_SIGCHLD at position 0002
01/11 21:11:43 yS1 vgetty: voice_handle_event got event SIGNAL_SIGCHLD
with data <
01/11 21:11:43 yS1 vgetty: voice_handle_event got unknown event
SIGNAL_SIGCHLD with data <
01/11 21:11:43 yS1 vgetty: unqueued event RESET_WATCHDOG at position 0003
01/11 21:11:43 yS1 vgetty: voice_handle_event got event RESET_WATCHDOG
with data <
01/11 21:11:43 yS1 US Robotics: OK
01/11 21:11:43 yS1 voice command: 'AT' -> 'OK'
01/11 21:11:43 yS1 vgetty: AT
01/11 21:11:43 yS1 US Robotics: OK
01/11 21:11:43 yS1 voice command: 'AT+FCLASS=2.0' -> 'OK'
01/11 21:11:43 yS1 vgetty: AT+FCLASS=2.0
01/11 21:11:43 yS1 US Robotics: OK
01/11 21:11:43 yS1 voice command: 'AT+FAA=0' -> 'OK'
01/11 21:11:43 yS1 vgetty: AT+FAA=0
01/11 21:11:43 yS1 US Robotics: OK
01/11 21:11:44 yS1 vgetty: Restoring signal handlers
01/11 21:11:44 yS1 mdm_send: 'AT+FBO=1'
01/11 21:11:44 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:11:44 yS1 mdm_command: string 'OK' -> OK
01/11 21:11:44 yS1 send: ATA[0d]
01/11 21:11:44 yS1 waiting for ``CONNECT''
01/11 21:11:44 yS1 got: [0a]
01/11 21:11:44 yS1 CND: OK[0d][0a]+FCO[0d]
01/11 21:11:54 yS1 CND: +FCO
01/11 21:11:54 yS1 found action string: ``+FCO_''
01/11 21:11:54 yS1 start fax receiver...
01/11 21:11:54 yS1 fax receiver: entry
01/11 21:11:54 yS1 fax_wait_for(OK)
01/11 21:11:54 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:11:58 yS1 fax_wait_for: string '+FCO'
01/11 21:11:58 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:12:07 yS1 fax_wait_for: string '+FCO'
01/11 21:12:07 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:12:15 yS1 fax_wait_for: string '+FCO'
01/11 21:12:15 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:12:20 yS1 fax_wait_for: string '+FCO'
01/11 21:12:20 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:12:30 yS1 fax_wait_for: string '+FCO'
01/11 21:12:30 yS1 got:[0a][0d][0a]+FCO[0d]
01/11 21:12:33 yS1 fax_wait_for: string '+FCO'
01/11 21:12:33 yS1 got:[0a][0d][0a]+FHS:74[0d]
01/11 21:12:39 yS1 fax_wait_for: string '+FHS:74'
01/11 21:12:39 yS1 connection hangup: '+FHS:74'
01/11 21:12:39 yS1 (T.30 T1 timeout after EOM received)
01/11 21:12:39 yS1 got:[0a][0d][0a]OK[0d]
01/11 21:12:39 yS1 fax_wait_for: string 'OK'** found **
01/11 21:12:39 yS1 tss: set speed to 19200 (016)
01/11 21:12:39 yS1 looking for utmp entry... (my PID: 2700)
01/11 21:12:39 yS1 utmp + wtmp entry made
01/11 21:12:39 yS1 tio_set_flow_control( HARD XON_IN )