Problems Getting pppd to Start
John Bell (jbell@sanderson.net.my)
Tue, 23 Feb 1999 15:32:16 +0800
Hi,
I have a pentium host running RedHat Linux 4.2 Kernel 2.0.30. My software is
mgetty 1.1.5, ppp 2.2.0f (integrated with Eric Toung's libdes 4.04 to allow
for connectivity to Microsoft NT running MSchap authentication) and uucp
1.06.1 for serial connectivity. My hardware includes a 4 port digiboard PC/Xe
(with the standard linux digiboard driver) and a TCN Merz 336 modem. All
communications software that addresses this port views it as /dev/modem
(uucp:uucp perms=664) which is a hard link to /dev/ttyD1 (the equivalent of
/dev/ttySn.) The mgetty software is compiled for AutoPPP support and views
the modem as a data-only device. This set up works fine for dial out ppp
(Unix PAP or CHAP, and NT with MSchap80) dial out serial (via cu) and dial in
async sessions. However, when I attempt an incoming ppp session from a MS95
(or later) it appears that even though mgetty recognises the ppp frames it is
unable to launch ppp. The basis for this statement is that ppp does not log
its start up message via syslog. Naturally pppd is world executable and suid
root. I am running mgetty at debug level 9 and have set debug for pppd. I
have read every resource on mgetty I can find, but cannot identify a solution
to this problem.
I have followed all the standard aadvice re linux installations and have
tried all the more generic modem toggles all to no avail. Unfortunately I do
not have access to a unix ppp host to dial in to the system. Thus I am not
sure if this is a Microsoft specific problem. Perhaps my lack of experience
with mgetty is to blame.
Following are my mgetty configuration files, the syslog output of mgetty and
the session log from log_mg.modem:
Regards,
John Bell <jbell@sanderson.net.my>
login.config file:
/AutoPPP/ a_ppp - /usr/sbin/pppd auth login -chap +pap kdebug 7 debug -detach
* - - /bin/login @
mgetty.config file:
debug 9
speed 38400
port-owner uucp
port-group uucp
port-mode 0664
syslog output from mgetty:
Feb 23 14:08:54 sultan mgetty[2904]: data dev=modem, pid=2904, caller=none,
conn='38400', name='', cmd='/usr/sbin/pppd', user='/AutoPPP/'
log_mg.modem:
02/23 14:07:42 dem waiting...
02/23 14:08:34 dem select returned 1
02/23 14:08:34 dem checking lockfiles, locking the line
02/23 14:08:34 dem makelock(modem) called
02/23 14:08:34 dem do_makelock: lock='/var/lock/LCK..modem'
02/23 14:08:34 dem lock made
02/23 14:08:34 dem waiting for ``RING''
02/23 14:08:34 dem got: [0d]
02/23 14:08:34 dem CND: OK[0a]RING ** found **
02/23 14:08:34 dem send: ATA[0d]
02/23 14:08:34 dem waiting for ``CONNECT''
02/23 14:08:34 dem got: [0d]
02/23 14:08:34 dem CND: RING[0a]ATA[0d]
02/23 14:08:34 dem CND: ATA[0d][0a]CONNECT ** found **
02/23 14:08:51 dem send:
02/23 14:08:51 dem waiting for ``_''
02/23 14:08:51 dem got: 38400[0d]
02/23 14:08:51 dem CND: CONNECT 38400
02/23 14:08:51 dem CND: found: 38400[0a] ** found **
02/23 14:08:51 dem waiting for line to clear (VTIME), read:
~[ff]}#[c0]!}!}!} }7}"}&} }*} } }%}&}!-w[c0]}'}"}(}"}-}#}&[cf];~
02/23 14:08:52 dem looking for utmp entry... (my PID: 2904)
02/23 14:08:52 dem utmp + wtmp entry made
02/23 14:08:52 dem tio_set_flow_control( HARD )
02/23 14:08:52 dem print welcome banner (/etc/issue)
02/23 14:08:52 dem getlogname (AUTO_PPP), read:~[ff]}#[c0]!
02/23 14:08:54 dem input finished with '\r', setting ICRNL ONLCR
02/23 14:08:54 dem tio_get_rs232_lines: status: RTS CTS DSR DTR DCD
02/23 14:08:54 dem login: use login config file
//etc/mgetty+sendfax/login.config
02/23 14:08:54 dem match: user='/AutoPPP/', key=''
02/23 14:08:54 dem match: user='/AutoPPP/', key=''
02/23 14:08:54 dem match: user='/AutoPPP/', key='/AutoPPP/'*** hit!
02/23 14:08:54 dem login: user id: /AutoPPP/ (uid 514, gid 514)
02/23 14:08:54 dem calling login: cmd='/usr/sbin/pppd', argv[]='pppd auth
login -chap +pap kdebug 7 debug -detach'
02/23 14:08:54 ##### data dev=modem, pid=2904, caller=none, conn='38400',
name='', cmd='/usr/sbin/pppd', user='/AutoPPP/'
02/23 14:08:54 dem setenv: 'CALLER_ID=none'
02/23 14:08:54 dem setenv: 'CONNECT=38400'
--
02/23 14:08:55 dem mgetty: experimental test release 1.1.5-Apr16
02/23 14:08:55 dem mgetty.c compiled at Feb 23 1999, 13:53:59
02/23 14:08:55 dem reading configuration data for port 'modem'
02/23 14:08:55 dem reading //etc/mgetty+sendfax/mgetty.config...
02/23 14:08:55 dem conf lib: read: 'debug 9'
02/23 14:08:55 dem conf lib: read: 'speed 38400'
02/23 14:08:55 dem conf lib: read: 'port-owner uucp'
02/23 14:08:55 dem conf lib: read: 'port-group uucp'
02/23 14:08:55 dem conf lib: read: 'port-mode 0664'
02/23 14:08:55 dem key: 'speed', type=0, flags=3, data=38400
02/23 14:08:55 dem key: 'switchbd', type=0, flags=1, data=0
02/23 14:08:55 dem key: 'direct', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'blocking', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'port-owner', type=1, flags=3, data=uucp
02/23 14:08:55 dem key: 'port-group', type=1, flags=3, data=uucp
02/23 14:08:55 dem key: 'port-mode', type=0, flags=3, data=436
02/23 14:08:55 dem key: 'toggle-dtr', type=3, flags=1, data=TRUE
02/23 14:08:55 dem key: 'toggle-dtr-waittime', type=0, flags=1, data=500
02/23 14:08:55 dem key: 'data-only', type=3, flags=2, data=TRUE
02/23 14:08:55 dem key: 'fax-only', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'modem-type', type=1, flags=1, data=data
02/23 14:08:55 dem key: 'init-chat', type=2, flags=1, data= \dATQ0V1H0 OK
ATS0=0Q0&D3&C1 OK
02/23 14:08:55 dem key: 'force-init-chat', type=2, flags=1, data=
\d\d\d\d+++\d\d\d
\dATQ0V1H0 OK
02/23 14:08:55 dem key: 'modem-check-time', type=0, flags=1, data=3600
02/23 14:08:55 dem key: 'rings', type=0, flags=1, data=1
02/23 14:08:55 dem key: 'get-cnd-chat', type=2, flags=0, data=(empty)
02/23 14:08:55 dem key: 'answer-chat', type=2, flags=1, data= ATA CONNECT \c
02/23 14:08:55 dem key: 'answer-chat-timeout', type=0, flags=1, data=80
02/23 14:08:55 dem key: 'autobauding', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'ringback', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'ringback-time', type=0, flags=1, data=30
02/23 14:08:55 dem key: 'ignore-carrier', type=3, flags=1, data=FALSE
02/23 14:08:55 dem key: 'issue-file', type=1, flags=1, data=/etc/issue
02/23 14:08:55 dem key: 'prompt-waittime', type=0, flags=1, data=500
02/23 14:08:55 dem key: 'login-prompt', type=1, flags=1, data=@!login:
02/23 14:08:55 dem key: 'login-time', type=0, flags=1, data=240
02/23 14:08:55 dem key: 'fido-send-emsi', type=3, flags=1, data=TRUE
02/23 14:08:55 dem key: 'fax-id', type=1, flags=1, data=49 89 xxxxxxxx
02/23 14:08:55 dem key: 'fax-server-file', type=1, flags=0, data=(empty)
02/23 14:08:55 dem key: 'diskspace', type=0, flags=1, data=1024
02/23 14:08:55 dem key: 'notify', type=1, flags=1, data=faxadmin
02/23 14:08:55 dem key: 'fax-owner', type=1, flags=1, data=uucp
02/23 14:08:55 dem key: 'fax-group', type=1, flags=0, data=(empty)
02/23 14:08:55 dem key: 'fax-mode', type=0, flags=1, data=432
02/23 14:08:55 dem key: 'debug', type=0, flags=2, data=9
02/23 14:08:55 dem key: 'statistics-chat', type=2, flags=0, data=(empty)
02/23 14:08:55 dem key: 'statistics-file', type=1, flags=0, data=(empty)
02/23 14:08:55 dem key: 'gettydefs', type=1, flags=1, data=n
02/23 14:08:55 dem key: 'term', type=1, flags=0, data=(empty)
02/23 14:08:55 dem check for lockfiles
02/23 14:08:55 dem checklock: no active process has lock, will remove
02/23 14:08:55 dem locking the line
02/23 14:08:55 dem makelock(modem) called
02/23 14:08:55 dem do_makelock: lock='/var/lock/LCK..modem'
02/23 14:08:55 dem lock made
02/23 14:08:56 dem tio_get_rs232_lines: status: RTS CTS DSR DTR
02/23 14:08:56 dem lowering DTR to reset Modem
02/23 14:08:56 dem tss: set speed to 38400 (017)
02/23 14:08:56 dem tio_set_flow_control( HARD )
02/23 14:08:56 dem waiting for line to clear (VTIME), read:
[0d][0a]OK[0d][0a]
02/23 14:08:56 dem send: \dATQ0V1H0[0d]
02/23 14:08:57 dem waiting for ``OK''
02/23 14:08:57 dem got: ATQ0V1H0[0d]
02/23 14:08:57 dem CND: ATQ0V1H0[0d][0a]OK ** found **
02/23 14:08:57 dem send: ATS0=0Q0&D3&C1[0d]
02/23 14:08:57 dem waiting for ``OK''
02/23 14:08:57 dem got: [0d]
02/23 14:08:57 dem CND: OK[0a]ATS0=0Q0&D3&C1[0d]
02/23 14:08:57 dem CND: ATS0=0Q0&D3&C1[0d][0a]OK ** found **
02/23 14:08:57 dem waiting for line to clear (VTIME), read: [0d][0a]
02/23 14:08:57 dem removing lock file
02/23 14:08:57 dem waiting...