mgetty not logging (was: Fax receive times out))

"Jeremy Malcolm" (terminus@odyssey.apana.org.au)
Tue, 8 Sep 1998 15:34:46 +0200
Messages sorted by:[ date ][ thread ][ subject ][ author ]
> > Having solved that, I was able to study the log file and solve my
> > other (main) problem - the fax receive timing out.  So now
> everything
> > seems to be working fine!
>
> Glad to hear that!  Have fun with it.

Um, I spoke too soon I'm afraid.  Yes, receiving faxes is now working
fine... but dialing in and establishing a PPP connection is now broken!
When I try dialling in using Windows NT, I now get an error, "TCP/IP CP
reported error 738: The server did not assign an address."  If I
specifically tell Windows NT my static IP address then it does not give me
the error 738, but it gives me a whole heap of CRC errors while I'm
connected and no packets are passed.

PPP was working fine until I added "switchbd 19200" to my mgetty.config
(yes, this was the problem that was preventing me from receiving faxes... I
could have sworn I tried adding that line before, but perhaps I hadn't
reloaded mgetty's config file).

Here is the logfile, if it gives anyone any obvious clues I would much
appreciate some advice...

09/09 03:19:49 yS0  mgetty: experimental test release 1.1.14-Apr02
09/09 03:19:49 yS0   mgetty.c compiled at May 23 1998, 14:16:58
09/09 03:19:49 yS0   user id: 0, parent pid: 1
09/09 03:19:49 yS0   reading configuration data for port 'ttyS0'
09/09 03:19:49 yS0   reading /etc/mgetty/mgetty.config...
09/09 03:19:49 yS0   conf lib: read: 'debug 5'
09/09 03:19:49 yS0   conf lib: read: 'fax-id +61-8-9421 1762'
09/09 03:19:49 yS0   conf lib: read: 'speed 38400'
09/09 03:19:49 yS0   conf lib: read: 'fax-owner root'
09/09 03:19:49 yS0   conf lib: read: 'fax-group uucp'
09/09 03:19:49 yS0   conf lib: read: 'fax-mode 0640'
09/09 03:19:49 yS0   conf lib: read: 'port ttyS0'
09/09 03:19:49 yS0   section: port ttyS0, **found**
09/09 03:19:49 yS0   conf lib: read: 'switchbd 19200'
09/09 03:19:49 yS0   key: 'speed', type=0, flags=2, data=57600
09/09 03:19:49 yS0   key: 'switchbd', type=0, flags=3, data=19200
09/09 03:19:49 yS0   key: 'direct', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'blocking', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'port-owner', type=1, flags=1, data=root
09/09 03:19:49 yS0   key: 'port-group', type=1, flags=1, data=dialout
09/09 03:19:49 yS0   key: 'port-mode', type=0, flags=1, data=432
09/09 03:19:49 yS0   key: 'toggle-dtr', type=3, flags=1, data=TRUE
09/09 03:19:49 yS0   key: 'toggle-dtr-waittime', type=0, flags=1, data=500
09/09 03:19:49 yS0   key: 'data-only', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'fax-only', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'modem-type', type=1, flags=1, data=auto
09/09 03:19:49 yS0   key: 'modem-quirks', type=0, flags=0, data=(empty)
09/09 03:19:49 yS0   key: 'init-chat', type=2, flags=1, data= \dATQ0V1H0 OK
AT OK
09/09 03:19:49 yS0   key: 'force-init-chat', type=2, flags=1, data=
\d\d\d\d+++\\dATQ0V1H0 OK
09/09 03:19:49 yS0   key: 'modem-check-time', type=0, flags=1, data=3600
09/09 03:19:49 yS0   key: 'rings', type=0, flags=1, data=1
09/09 03:19:49 yS0   key: 'get-cnd-chat', type=2, flags=0, data=(empty)
09/09 03:19:49 yS0   key: 'answer-chat', type=2, flags=1, data= ATA CONNECT
\c
09/09 03:19:49 yS0   key: 'answer-chat-timeout', type=0, flags=1, data=80
09/09 03:19:49 yS0   key: 'autobauding', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'ringback', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'ringback-time', type=0, flags=1, data=30
09/09 03:19:49 yS0   key: 'ignore-carrier', type=3, flags=1, data=FALSE
09/09 03:19:49 yS0   key: 'issue-file', type=1, flags=1, data=/etc/issue
09/09 03:19:49 yS0   key: 'prompt-waittime', type=0, flags=1, data=500
09/09 03:19:49 yS0   key: 'login-prompt', type=1, flags=1, data=@!login:
09/09 03:19:49 yS0   key: 'login-time', type=0, flags=1, data=240
09/09 03:19:49 yS0   key: 'fido-send-emsi', type=3, flags=1, data=TRUE
09/09 03:19:49 yS0   key: 'fax-id', type=1, flags=3, data=+61-8-9421 1762
09/09 03:19:49 yS0   key: 'fax-server-file', type=1, flags=0, data=(empty)
09/09 03:19:49 yS0   key: 'diskspace', type=0, flags=1, data=1024
09/09 03:19:49 yS0   key: 'notify', type=1, flags=1, data=root
09/09 03:19:49 yS0   key: 'fax-owner', type=1, flags=3, data=root
09/09 03:19:49 yS0   key: 'fax-group', type=1, flags=3, data=uucp
09/09 03:19:49 yS0   key: 'fax-mode', type=0, flags=3, data=416
09/09 03:19:49 yS0   key: 'debug', type=0, flags=2, data=5
09/09 03:19:49 yS0   key: 'statistics-chat', type=2, flags=0, data=(empty)
09/09 03:19:49 yS0   key: 'statistics-file', type=1, flags=0, data=(empty)
09/09 03:19:49 yS0   key: 'gettydefs', type=1, flags=1, data=n
09/09 03:19:49 yS0   key: 'term', type=1, flags=0, data=(empty)
09/09 03:19:49 yS0  check for lockfiles
09/09 03:19:49 yS0   checklock: no active process has lock, will remove
09/09 03:19:49 yS0  locking the line
09/09 03:19:49 yS0   makelock(ttyS0) called
09/09 03:19:49 yS0   do_makelock: lock='/var/lock/LCK..ttyS0'
09/09 03:19:49 yS0   lock made
09/09 03:19:49 yS0   tio_get_rs232_lines: status: RTS CTS DSR DTR
09/09 03:19:49 yS0  lowering DTR to reset Modem
09/09 03:19:50 yS0   tss: set speed to 57600 (10001)
09/09 03:19:50 yS0   tio_set_flow_control( HARD )
09/09 03:19:50 yS0   waiting for line to clear (VTIME), read:
09/09 03:19:50 yS0  send: \dATQ0V1H0[0d]
09/09 03:19:50 yS0  waiting for ``OK''
09/09 03:19:50 yS0   got: ATQ0V1H0[0d][0d][0a]OK ** found **
09/09 03:19:51 yS0  send: AT[0d]
09/09 03:19:51 yS0  waiting for ``OK''
09/09 03:19:51 yS0   got: [0d][0a]AT[0d][0d][0a]OK ** found **
09/09 03:19:51 yS0  mdm_send: 'ATI'
09/09 03:19:51 yS0   mdm_gis: string 1: '33600'
09/09 03:19:51 yS0   mdm_identify: string '33600'
09/09 03:19:51 yS0  Generic Rockwell modem (33600)
09/09 03:19:51 yS0  mdm_send: 'ATI3'
09/09 03:19:51 yS0   mdm_gis: string 1: 'V1.450-V34_DS'
09/09 03:19:51 yS0  mdm_send: 'ATI4'
09/09 03:19:51 yS0   mdm_gis: string 1: '288ER FOR AUSTRALIA 02/07/96'
09/09 03:19:51 yS0  additional info: '288ER FOR AUSTRALIA 02/07/96'
09/09 03:19:51 yS0  modem quirks: 0004
09/09 03:19:51 yS0  mdm_send: 'AT+FCLASS=2'
09/09 03:19:51 yS0   mdm_command: string 'AT+FCLASS=2'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0  mdm_send: 'AT+FCLASS=0'
09/09 03:19:51 yS0   mdm_command: string 'AT+FCLASS=0'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0  mdm_send: 'AT+FAA=1;+FCR=1'
09/09 03:19:51 yS0   mdm_command: string 'AT+FAA=1;+FCR=1'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0  mdm_send: 'AT+FBOR=0'
09/09 03:19:51 yS0   mdm_command: string 'AT+FBOR=0'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0  mdm_send: 'AT+FLID="+61-8-9421 1762"'
09/09 03:19:51 yS0   mdm_command: string 'AT+FLID="+61-8-9421 1762"'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0  mdm_send: 'AT+FDCC=1,5,0,2,0,0,0,0'
09/09 03:19:51 yS0   mdm_command: string 'AT+FDCC=1,5,0,2,0,0,0,0'
09/09 03:19:51 yS0   mdm_command: string 'OK' -> OK
09/09 03:19:51 yS0   waiting for line to clear (VTIME), read:
09/09 03:19:51 yS0   removing lock file
09/09 03:19:51 yS0  waiting...
09/09 03:23:16 yS0   checking lockfiles, locking the line
09/09 03:23:16 yS0   makelock(ttyS0) called
09/09 03:23:16 yS0   do_makelock: lock='/var/lock/LCK..ttyS0'
09/09 03:23:16 yS0   lock made
09/09 03:23:16 yS0  waiting for ``RING''
09/09 03:23:16 yS0   got: [0d][0a]RING ** found **
09/09 03:23:16 yS0  send: ATA[0d]
09/09 03:23:16 yS0  waiting for ``CONNECT''
09/09 03:23:16 yS0   got: [0d][0a]ATA[0d][0d][0a]DATA[0d][0a][0d][0a]CONNECT
**
found **
09/09 03:23:33 yS0  send:
09/09 03:23:33 yS0  waiting for ``_''
09/09 03:23:33 yS0   got:  57600[0d][0a] ** found **
09/09 03:23:33 yS0   waiting for line to clear (VTIME), read:
~[ff]}#[c0]!}!} }
}4}"}&} } } } }%}&} } ?J}'}"}(}"[b5][f5]~
09/09 03:23:33 yS0   utmp + wtmp entry made
09/09 03:23:33 yS0   tio_set_flow_control( HARD )
09/09 03:23:33 yS0   print welcome banner (/etc/issue)
09/09 03:23:33 yS0   getlogname (FIDO AUTO_PPP), read:~[ff]}#[c0]!
09/09 03:23:35 yS0   input finished with '\r', setting ICRNL ONLCR
09/09 03:23:35 yS0   tio_get_rs232_lines: status: RTS CTS DSR DTR DCD
09/09 03:23:35 yS0   match: user='/AutoPPP/', key=''
09/09 03:23:35 yS0   match: user='/AutoPPP/', key=''
09/09 03:23:35 yS0   match: user='/AutoPPP/', key='/AutoPPP/'*** hit!
09/09 03:23:35 yS0   login: utmp entry: a_ppp
09/09 03:23:35 yS0   utmp + wtmp entry made
09/09 03:23:35 yS0   calling login: cmd='/usr/sbin/pppd', argv[]='pppd
auth -chap +pap login'
09/09 03:23:35 ##### data dev=ttyS0, pid=2268, caller='none', conn='57600',
name='', cmd='/usr/sbin/pppd', user='/AutoPPP/'
09/09 03:23:35 yS0   setenv: 'CALLER_ID=none'
09/09 03:23:35 yS0   setenv: 'CONNECT=57600'

also sometimes it seems to end differently, it goes as follows:

09/09 03:28:07 yS0   got:  57600[0d][0a] ** found **
09/09 03:28:07 yS0   waiting for line to clear (VTIME), read:
09/09 03:28:07 yS0   utmp + wtmp entry made
09/09 03:28:08 yS0   tio_set_flow_control( HARD )
09/09 03:28:08 yS0   print welcome banner (/etc/issue)
09/09 03:28:08 yS0   getlogname (FIDO AUTO_PPP), read:terminus[0d]
09/09 03:28:11 yS0   input finished with '\r', setting ICRNL ONLCR
09/09 03:28:11 yS0   tio_get_rs232_lines: status: RTS CTS DSR DTR DCD
09/09 03:28:11 yS0   match: user='terminus', key=''
09/09 03:28:11 yS0   match: user='terminus', key=''
09/09 03:28:11 yS0   match: user='terminus', key=''
09/09 03:28:11 yS0   match: user='terminus', key='/AutoPPP/'
09/09 03:28:11 yS0   match: user='terminus', key=''
09/09 03:28:11 yS0   match: user='terminus', key='*'*** hit!
09/09 03:28:11 yS0   calling login: cmd='/bin/login', argv[]='login
terminus'
09/09 03:28:11 ##### data dev=ttyS0, pid=2287, caller='none', conn='57600',
name='', cmd='/bin/login', user='terminus'
09/09 03:28:11 yS0   setenv: 'CALLER_ID=none'
09/09 03:28:11 yS0   setenv: 'CONNECT=57600'

Many thanks for any help!

--
|---------  JEREMY MALCOLM <terminus@odyssey.apana.org.au>  ---------|
SIG of the day: [ ] Contact  [ ] Web  [ ] PGP  [x] Taglines #1  [ ] #2
Reality is for those who can't face science fiction. | Power corrupts;
absolute power is kind of neat. | "It's in Tibetan!" - The Doctor (5G)
"A lawyer is like a river." - Kosh | Life is like a simile | Dynsdale!