Hi all, This one perhaps missed a reply, so here I repost it. So here I am again, with some ppp problems this time it is a Win95 login. I think the failure to login is on the linux server side. Please let me know what you think about it. I have attached the modem log below the first part does not have debug 9 but the latter part has debug 9 with thanks and best regards Jacob These 3 lines are most likely the problem. Where do they come from ? Jun 6 23:29:55 narada pppd[9275]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:29:55 narada pppd[9275]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:29:55 narada pppd[9275]: Exit. this is my ppplogin script ========================== #!/bin/bash # ppplogin script to fire up pppd on login mesg n stty -echo # 1 exec /usr/sbin/pppd -detach silent /dev/modem crtscts exec /usr/sbin/pppd passive /dev/ttyS1 /var/log/messages ================= Jun 6 23:10:31 narada mgetty[8536]: failed dev=ttyS1, pid=8536, got signal 1, exiting Jun 6 23:14:58 narada mgetty[8779]: data dev=ttyS1, pid=8779, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:15:13 narada PAM_pwdb[8779]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:15:13 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:15:13 narada kernel: CSLIP: code copyright 1989 Regents of the University of California Jun 6 23:15:13 narada kernel: PPP: version 2.2.0 (dynamic channel allocation) Jun 6 23:15:13 narada kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc. Jun 6 23:15:13 narada kernel: PPP line discipline registered. Jun 6 23:15:13 narada kernel: registered device ppp0 Jun 6 23:15:13 narada pppd[8795]: pppd 2.2.0 started by mettanet, uid 501 Jun 6 23:15:13 narada pppd[8795]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:15:13 narada pppd[8795]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:15:13 narada pppd[8795]: Exit. Jun 6 23:15:13 narada PAM_pwdb[8779]: (login) session closed for user mettanet Jun 6 23:17:13 narada kernel: PPP: ppp line discipline successfully unregistered Jun 6 23:17:21 narada innd[416]: s Jun 6 23:26:23 narada mgetty[8801]: failed dev=ttyS1, pid=8801, got signal 1, exiting Jun 6 23:27:23 narada innd[416]: s Jun 6 23:29:46 narada mgetty[9050]: data dev=ttyS1, pid=9050, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:29:54 narada PAM_pwdb[9050]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:29:54 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:29:55 narada kernel: CSLIP: code copyright 1989 Regents of the University of California Jun 6 23:29:55 narada kernel: PPP: version 2.2.0 (dynamic channel allocation) Jun 6 23:29:55 narada kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc. Jun 6 23:29:55 narada kernel: PPP line discipline registered. Jun 6 23:29:55 narada kernel: registered device ppp0 Jun 6 23:29:55 narada pppd[9275]: pppd 2.2..0 started by mettanet, uid 501 Jun 6 23:29:55 narada pppd[9275]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:29:55 narada pppd[9275]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:29:55 narada pppd[9275]: Exit. Jun 6 23:29:55 narada PAM_pwdb[9050]: (login) session closed for user mettanet Jun 6 23:29:56 narada mgetty[9281]: TIOCMBIS failed: I/O error Jun 6 23:29:56 narada mgetty[9281]: cannot turn off soft carrier: I/O error Jun 6 23:29:56 narada mgetty[9281]: tcgetattr failed: I/O error Jun 6 23:29:56 narada mgetty[9281]: cannot get TIO: I/O error Jun 6 23:31:17 narada mgetty[9281]: data dev=ttyS1, pid=9281, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:31:23 narada PAM_pwdb[9281]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:31:23 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:31:23 narada pppd[9288]: pppd 2.2.0 started by mettanet, uid 501 Jun 6 23:31:23 narada pppd[9288]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:31:23 narada PAM_pwdb[9281]: (login) session closed for user mettanet Jun 6 23:31:23 narada pppd[9288]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:31:23 narada pppd[9288]: Exit. Jun 6 23:31:24 narada mgetty[9291]: TIOCMBIS failed: I/O error Jun 6 23:31:24 narada mgetty[9291]: cannot turn off soft carrier: I/O error Jun 6 23:31:24 narada mgetty[9291]: tcgetattr failed: I/O error Jun 6 23:31:24 narada mgetty[9291]: cannot get TIO: I/O error Jun 6 23:32:54 narada kernel: PPP: ppp line discipline successfully unregistered Jun 6 23:33:04 narada mgetty[9291]: data dev=ttyS1, pid=9291, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:33:07 narada PAM_pwdb[9291]: (login) session opened for user metta by metta(uid=0) Jun 6 23:33:07 narada syslog: DIALUP ttyS1, metta Jun 6 23:34:25 narada PAM_pwdb[9314]: 1 authentication failure; metta(uid=500) -> root for su service Jun 6 23:34:30 narada PAM_pwdb[9315]: (su) session opened for user root by metta(uid=0) Jun 6 23:35:07 narada named[191]: ns_forw: sendto([198.41.0.4].53): Network is unreachable Jun 6 23:35:41 narada PAM_pwdb[9315]: (su) session closed for user root Jun 6 23:35:44 narada PAM_pwdb[9291]: (login) session closed for user metta Jun 6 23:35:45 narada mgetty[9353]: TIOCMBIS failed: I/O error Jun 6 23:35:45 narada mgetty[9353]: cannot turn off soft carrier: I/O error Jun 6 23:35:45 narada mgetty[9353]: tcgetattr failed: I/O error Jun 6 23:35:45 narada mgetty[9353]: cannot get TIO: I/O error Jun 6 23:36:49 narada mgetty[9353]: data dev=ttyS1, pid=9353, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:36:54 narada PAM_pwdb[9353]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:36:54 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:36:54 narada kernel: CSLIP: code copyright 1989 Regents of the University of California Jun 6 23:36:54 narada kernel: PPP: version 2.2.0 (dynamic channel allocation) Jun 6 23:36:54 narada kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc. Jun 6 23:36:54 narada kernel: PPP line discipline registered. Jun 6 23:36:54 narada kernel: registered device ppp0 Jun 6 23:36:54 narada pppd[9475]: pppd 2.2.0 started by mettanet, uid 501 Jun 6 23:36:54 narada pppd[9475]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:36:54 narada pppd[9475]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:36:54 narada PAM_pwdb[9353]: (login) session closed for user mettanet Jun 6 23:36:54 narada pppd[9475]: Exit. Jun 6 23:36:55 narada mgetty[9481]: TIOCMBIS failed: I/O error Jun 6 23:36:55 narada mgetty[9481]: cannot turn off soft carrier: I/O error Jun 6 23:36:55 narada mgetty[9481]: tcgetattr failed: I/O error Jun 6 23:36:55 narada mgetty[9481]: cannot get TIO: I/O error Jun 6 23:37:26 narada innd[416]: s Jun 6 23:37:52 narada mgetty[9481]: data dev=ttyS1, pid=9481, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:37:55 narada PAM_pwdb[9481]: (login) session opened for user metta by metta(uid=0) Jun 6 23:37:55 narada syslog: DIALUP ttyS1, metta Jun 6 23:38:19 narada PAM_pwdb[9785]: (su) session opened for user root by metta(uid=0) Jun 6 23:38:54 narada kernel: PPP: ppp line discipline successfully unregistered Jun 6 23:42:50 narada PAM_pwdb[9785]: (su) session closed for user root Jun 6 23:42:51 narada PAM_pwdb[9481]: (login) session closed for user metta Jun 6 23:42:52 narada mgetty[9804]: TIOCMBIS failed: I/O error Jun 6 23:42:52 narada mgetty[9804]: cannot turn off soft carrier: I/O error Jun 6 23:42:52 narada mgetty[9804]: tcgetattr failed: I/O error Jun 6 23:42:52 narada mgetty[9804]: cannot get TIO: I/O error Jun 6 23:43:48 narada mgetty[9804]: data dev=ttyS1, pid=9804, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:43:51 narada PAM_pwdb[9804]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:43:51 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:43:52 narada kernel: CSLIP: code copyright 1989 Regents of the University of California Jun 6 23:43:52 narada kernel: PPP: version 2.2.0 (dynamic channel allocation) Jun 6 23:43:52 narada kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc. Jun 6 23:43:52 narada kernel: PPP line discipline registered. Jun 6 23:43:52 narada kernel: registered device ppp0 Jun 6 23:43:52 narada pppd[9808]: pppd 2.2.0 started by mettanet, uid 501 Jun 6 23:43:52 narada pppd[9808]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:43:52 narada pppd[9808]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:43:52 narada pppd[9808]: Exit. Jun 6 23:43:52 narada PAM_pwdb[9804]: (login) session closed for user mettanet Jun 6 23:44:49 narada mgetty[9814]: data dev=ttyS1, pid=9814, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:44:52 narada PAM_pwdb[9814]: (login) session opened for user metta by metta(uid=0) Jun 6 23:44:52 narada syslog: DIALUP ttyS1, metta Jun 6 23:44:58 narada PAM_pwdb[9829]: (su) session opened for user root by metta(uid=0) Jun 6 23:45:52 narada kernel: PPP: ppp line discipline successfully unregistered Jun 6 23:47:26 narada PAM_pwdb[9829]: (su) session closed for user root Jun 6 23:47:28 narada innd[416]: s Jun 6 23:48:27 narada mgetty[9844]: data dev=ttyS1, pid=9844, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:48:30 narada PAM_pwdb[9844]: (login) session opened for user metta by metta(uid=0) Jun 6 23:48:30 narada syslog: DIALUP ttyS1, metta Jun 6 23:48:36 narada PAM_pwdb[10075]: (su) session opened for user root by metta(uid=0) Jun 6 23:49:17 narada PAM_pwdb[10075]: (su) session closed for user root Jun 6 23:49:18 narada PAM_pwdb[9844]: (login) session closed for user metta Jun 6 23:49:19 narada mgetty[10083]: TIOCMBIS failed: I/O error Jun 6 23:49:19 narada mgetty[10083]: cannot turn off soft carrier: I/O error Jun 6 23:49:19 narada mgetty[10083]: tcgetattr failed: I/O error Jun 6 23:49:19 narada mgetty[10083]: cannot get TIO: I/O error Jun 6 23:50:13 narada mgetty[10083]: data dev=ttyS1, pid=10083, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' Jun 6 23:50:15 narada PAM_pwdb[10083]: (login) session opened for user mettanet by mettanet(uid=0) Jun 6 23:50:15 narada syslog: DIALUP ttyS1, mettanet Jun 6 23:50:15 narada kernel: CSLIP: code copyright 1989 Regents of the University of California Jun 6 23:50:15 narada kernel: PPP: version 2.2.0 (dynamic channel allocation) Jun 6 23:50:15 narada kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc. Jun 6 23:50:15 narada kernel: PPP line discipline registered. Jun 6 23:50:15 narada kernel: registered device ppp0 Jun 6 23:50:15 narada pppd[10087]: pppd 2.2.0 started by mettanet, uid 501 Jun 6 23:50:15 narada pppd[10087]: ioctl(PPPIOCGUNIT): Operation not permitted Jun 6 23:50:15 narada pppd[10087]: ioctl(PPPIOCGDEBUG): Operation not permitted Jun 6 23:50:15 narada pppd[10087]: Exit. Jun 6 23:50:15 narada PAM_pwdb[10083]: (login) session closed for user mettanet Jun 6 23:51:08 narada mgetty[10093]: data dev=ttyS1, pid=10093, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:51:12 narada PAM_pwdb[10093]: (login) session opened for user metta by metta(uid=0) Jun 6 23:51:12 narada syslog: DIALUP ttyS1, metta Jun 6 23:51:18 narada PAM_pwdb[10108]: (su) session opened for user root by metta(uid=0) Jun 6 23:52:15 narada kernel: PPP: ppp line discipline successfully unregistered Jun 6 23:56:15 narada PAM_pwdb[10108]: (su) session closed for user root Jun 6 23:57:31 narada innd[416]: s Jun 6 23:59:12 narada mgetty[10131]: data dev=ttyS1, pid=10131, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' Jun 6 23:59:17 narada PAM_pwdb[10131]: (login) session opened for user metta by metta(uid=0) Jun 6 23:59:17 narada syslog: DIALUP ttyS1, metta Jun 6 23:59:23 narada PAM_pwdb[10367]: (su) session opened for user root by metta(uid=0) Jun 7 00:01:01 narada PAM_pwdb[10367]: (su) session closed for user root Jun 7 00:01:03 narada PAM_pwdb[10131]: (login) session closed for user metta Jun 7 00:01:05 narada mgetty[10384]: TIOCMBIS failed: I/O error Jun 7 00:01:05 narada mgetty[10384]: cannot turn off soft carrier: I/O error Jun 7 00:01:05 narada mgetty[10384]: tcgetattr failed: I/O error Jun 7 00:01:05 narada mgetty[10384]: cannot get TIO: I/O error /var/log/log_mg.ttyS1 ===================== 06/06 23:29:13 yS1 waiting for ``_'' ** found ** 06/06 23:29:46 ##### data dev=ttyS1, pid=9050, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' -- 06/06 23:29:55 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:29:55 yS1 check for lockfiles 06/06 23:29:55 yS1 locking the line 06/06 23:29:55 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:29:55 yS1 lowering DTR to reset Modem 06/06 23:29:56 yS1 TIOCMBIS failed: I/O error 06/06 23:29:56 yS1 cannot turn off soft carrier: I/O error 06/06 23:29:56 yS1 tcgetattr failed: I/O error 06/06 23:29:56 yS1 cannot get TIO: I/O error 06/06 23:29:56 yS1 mg_init_device failed, trying again 06/06 23:29:56 yS1 lowering DTR to reset Modem 06/06 23:29:56 yS1 send: \dATQ0V1H0[0d] 06/06 23:29:57 yS1 waiting for ``OK'' ** found ** 06/06 23:29:57 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:29:57 yS1 waiting for ``OK'' ** found ** 06/06 23:29:57 yS1 waiting... 06/06 23:30:31 yS1 waiting for ``RING'' ** found ** 06/06 23:30:31 yS1 waiting for ``RING'' ** found ** 06/06 23:30:34 yS1 waiting for ``RING'' ** found ** 06/06 23:30:37 yS1 send: ATA[0d] 06/06 23:30:37 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:30:57 yS1 send: 06/06 23:30:57 yS1 waiting for ``_'' ** found ** 06/06 23:31:17 ##### data dev=ttyS1, pid=9281, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' -- 06/06 23:31:23 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:31:23 yS1 check for lockfiles 06/06 23:31:23 yS1 locking the line 06/06 23:31:23 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:31:23 yS1 lowering DTR to reset Modem 06/06 23:31:24 yS1 TIOCMBIS failed: I/O error 06/06 23:31:24 yS1 cannot turn off soft carrier: I/O error 06/06 23:31:24 yS1 tcgetattr failed: I/O error 06/06 23:31:24 yS1 cannot get TIO: I/O error 06/06 23:31:24 yS1 mg_init_device failed, trying again 06/06 23:31:24 yS1 lowering DTR to reset Modem 06/06 23:31:25 yS1 send: \dATQ0V1H0[0d] 06/06 23:31:25 yS1 waiting for ``OK'' ** found ** 06/06 23:31:25 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:31:25 yS1 waiting for ``OK'' ** found ** 06/06 23:31:25 yS1 waiting... 06/06 23:32:33 yS1 waiting for ``RING'' ** found ** 06/06 23:32:33 yS1 waiting for ``RING'' ** found ** 06/06 23:32:36 yS1 waiting for ``RING'' ** found ** 06/06 23:32:39 yS1 send: ATA[0d] 06/06 23:32:39 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:32:59 yS1 send: 06/06 23:32:59 yS1 waiting for ``_'' ** found ** 06/06 23:33:04 ##### data dev=ttyS1, pid=9291, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' -- 06/06 23:35:44 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:35:44 yS1 check for lockfiles 06/06 23:35:44 yS1 locking the line 06/06 23:35:44 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:35:44 yS1 lowering DTR to reset Modem 06/06 23:35:45 yS1 TIOCMBIS failed: I/O error 06/06 23:35:45 yS1 cannot turn off soft carrier: I/O error 06/06 23:35:45 yS1 tcgetattr failed: I/O error 06/06 23:35:45 yS1 cannot get TIO: I/O error 06/06 23:35:45 yS1 mg_init_device failed, trying again 06/06 23:35:45 yS1 lowering DTR to reset Modem 06/06 23:35:45 yS1 send: \dATQ0V1H0[0d] 06/06 23:35:46 yS1 waiting for ``OK'' ** found ** 06/06 23:35:46 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:35:46 yS1 waiting for ``OK'' ** found ** 06/06 23:35:46 yS1 waiting... 06/06 23:36:12 yS1 waiting for ``RING'' ** found ** 06/06 23:36:12 yS1 waiting for ``RING'' ** found ** 06/06 23:36:15 yS1 waiting for ``RING'' ** found ** 06/06 23:36:18 yS1 send: ATA[0d] 06/06 23:36:18 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:36:38 yS1 send: 06/06 23:36:38 yS1 waiting for ``_'' ** found ** 06/06 23:36:49 ##### data dev=ttyS1, pid=9353, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' -- 06/06 23:36:54 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:36:54 yS1 check for lockfiles 06/06 23:36:54 yS1 locking the line 06/06 23:36:55 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:36:55 yS1 lowering DTR to reset Modem 06/06 23:36:55 yS1 TIOCMBIS failed: I/O error 06/06 23:36:55 yS1 cannot turn off soft carrier: I/O error 06/06 23:36:55 yS1 tcgetattr failed: I/O error 06/06 23:36:55 yS1 cannot get TIO: I/O error 06/06 23:36:55 yS1 mg_init_device failed, trying again 06/06 23:36:55 yS1 lowering DTR to reset Modem 06/06 23:36:56 yS1 send: \dATQ0V1H0[0d] 06/06 23:36:57 yS1 waiting for ``OK'' ** found ** 06/06 23:36:57 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:36:57 yS1 waiting for ``OK'' ** found ** 06/06 23:36:57 yS1 waiting... 06/06 23:37:20 yS1 waiting for ``RING'' ** found ** 06/06 23:37:20 yS1 waiting for ``RING'' ** found ** 06/06 23:37:23 yS1 waiting for ``RING'' ** found ** 06/06 23:37:26 yS1 send: ATA[0d] 06/06 23:37:26 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:37:46 yS1 send: 06/06 23:37:46 yS1 waiting for ``_'' ** found ** 06/06 23:37:52 ##### data dev=ttyS1, pid=9481, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' -- 06/06 23:42:51 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:42:51 yS1 check for lockfiles 06/06 23:42:51 yS1 locking the line 06/06 23:42:52 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:42:52 yS1 lowering DTR to reset Modem 06/06 23:42:52 yS1 TIOCMBIS failed: I/O error 06/06 23:42:52 yS1 cannot turn off soft carrier: I/O error 06/06 23:42:52 yS1 tcgetattr failed: I/O error 06/06 23:42:52 yS1 cannot get TIO: I/O error 06/06 23:42:52 yS1 mg_init_device failed, trying again 06/06 23:42:52 yS1 lowering DTR to reset Modem 06/06 23:42:53 yS1 send: \dATQ0V1H0[0d] 06/06 23:42:53 yS1 waiting for ``OK'' ** found ** 06/06 23:42:53 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:42:53 yS1 waiting for ``OK'' ** found ** 06/06 23:42:54 yS1 waiting... 06/06 23:43:12 yS1 waiting for ``RING'' ** found ** 06/06 23:43:12 yS1 waiting for ``RING'' ** found ** 06/06 23:43:15 yS1 waiting for ``RING'' ** found ** 06/06 23:43:18 yS1 send: ATA[0d] 06/06 23:43:18 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:43:39 yS1 send: 06/06 23:43:39 yS1 waiting for ``_'' ** found ** 06/06 23:43:48 ##### data dev=ttyS1, pid=9804, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' -- 06/06 23:43:52 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:43:52 yS1 check for lockfiles 06/06 23:43:52 yS1 locking the line 06/06 23:43:52 yS1 lowering DTR to reset Modem 06/06 23:43:53 yS1 send: \dATQ0V1H0[0d] 06/06 23:43:54 yS1 waiting for ``OK'' ** found ** 06/06 23:43:54 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:43:54 yS1 waiting for ``OK'' ** found ** 06/06 23:43:54 yS1 waiting... 06/06 23:44:18 yS1 waiting for ``RING'' ** found ** 06/06 23:44:18 yS1 waiting for ``RING'' ** found ** 06/06 23:44:21 yS1 waiting for ``RING'' ** found ** 06/06 23:44:24 yS1 send: ATA[0d] 06/06 23:44:24 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:44:44 yS1 send: 06/06 23:44:44 yS1 waiting for ``_'' ** found ** 06/06 23:44:49 ##### data dev=ttyS1, pid=9814, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' -- 06/06 23:47:26 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:47:26 yS1 check for lockfiles 06/06 23:47:26 yS1 locking the line 06/06 23:47:27 yS1 lowering DTR to reset Modem 06/06 23:47:27 yS1 send: \dATQ0V1H0[0d] 06/06 23:47:28 yS1 waiting for ``OK'' ** found ** 06/06 23:47:28 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:47:28 yS1 waiting for ``OK'' ** found ** 06/06 23:47:28 yS1 waiting... 06/06 23:47:56 yS1 waiting for ``RING'' ** found ** 06/06 23:47:56 yS1 waiting for ``RING'' ** found ** 06/06 23:48:00 yS1 waiting for ``RING'' ** found ** 06/06 23:48:03 yS1 send: ATA[0d] 06/06 23:48:03 yS1 waiting for ``CONNECT'' ** found ** 06/06 23:48:23 yS1 send: 06/06 23:48:23 yS1 waiting for ``_'' ** found ** 06/06 23:48:27 ##### data dev=ttyS1, pid=9844, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' at this point I set debug 9 to get some more info -- 06/06 23:49:18 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:49:18 yS1 check for lockfiles 06/06 23:49:18 yS1 checklock: no active process has lock, will remove 06/06 23:49:18 yS1 locking the line 06/06 23:49:18 yS1 makelock(ttyS1) called 06/06 23:49:18 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:49:18 yS1 lock made 06/06 23:49:19 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD 06/06 23:49:19 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/06 23:49:19 yS1 lowering DTR to reset Modem 06/06 23:49:19 yS1 TIOCMBIS failed: I/O error 06/06 23:49:19 yS1 cannot turn off soft carrier: I/O error 06/06 23:49:19 yS1 tcgetattr failed: I/O error 06/06 23:49:19 yS1 cannot get TIO: I/O error 06/06 23:49:19 yS1 mg_init_device failed, trying again 06/06 23:49:19 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR 06/06 23:49:19 yS1 lowering DTR to reset Modem 06/06 23:49:20 yS1 tss: set speed to 38400 (017) 06/06 23:49:20 yS1 tio_set_flow_control( HARD ) 06/06 23:49:20 yS1 waiting for line to clear (VTIME), read: 06/06 23:49:20 yS1 send: \dATQ0V1H0[0d] 06/06 23:49:20 yS1 waiting for ``OK'' 06/06 23:49:20 yS1 got: [0d][0a]OK ** found ** 06/06 23:49:20 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:49:20 yS1 waiting for ``OK'' 06/06 23:49:20 yS1 got: [0d] 06/06 23:49:20 yS1 CND: OK[0a]ATQ0V1H0[0d] 06/06 23:49:20 yS1 CND: ATQ0V1H0[0d][0a]OK ** found ** 06/06 23:49:20 yS1 waiting for line to clear (VTIME), read: [0d][0a]ATS0=0Q0&D3&C1[0d][0d][0a]OK[0d][0a] 06/06 23:49:21 yS1 removing lock file 06/06 23:49:21 yS1 waiting... 06/06 23:49:38 yS1 select returned 1 06/06 23:49:38 yS1 checking lockfiles, locking the line 06/06 23:49:38 yS1 makelock(ttyS1) called 06/06 23:49:38 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:49:38 yS1 lock made 06/06 23:49:38 yS1 waiting for ``RING'' 06/06 23:49:38 yS1 got: [0d] 06/06 23:49:38 yS1 CND: OK[0a]RING ** found ** 06/06 23:49:38 yS1 waiting for ``RING'' 06/06 23:49:38 yS1 got: [0d] 06/06 23:49:38 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:49:41 yS1 waiting for ``RING'' 06/06 23:49:41 yS1 got: [0d] 06/06 23:49:41 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:49:44 yS1 send: ATA[0d] 06/06 23:49:44 yS1 waiting for ``CONNECT'' 06/06 23:49:44 yS1 got: [0d] 06/06 23:49:44 yS1 CND: RING[0a]ATA[0d] 06/06 23:49:44 yS1 CND: ATA[0d][0a]CONNECT ** found ** 06/06 23:50:04 yS1 send: 06/06 23:50:04 yS1 waiting for ``_'' 06/06 23:50:04 yS1 got: 38400[0d] 06/06 23:50:04 yS1 CND: CONNECT 38400 06/06 23:50:04 yS1 CND: found: 38400[0a] ** found ** 06/06 23:50:04 yS1 waiting for line to clear (VTIME), read: 06/06 23:50:05 yS1 looking for utmp entry... (my PID: 10083) 06/06 23:50:05 yS1 utmp + wtmp entry made 06/06 23:50:05 yS1 tio_set_flow_control( HARD ) 06/06 23:50:05 yS1 print welcome banner (/etc/issue) 06/06 23:50:05 yS1 getlogname (no opts), read:[0d] 06/06 23:50:11 yS1 input finished with '\r', setting ICRNL ONLCR 06/06 23:50:11 yS1 tio_set_flow_control( HARD ) 06/06 23:50:11 yS1 print welcome banner (/etc/issue) 06/06 23:50:11 yS1 getlogname (no opts), read:mettanet[0d] 06/06 23:50:13 yS1 input finished with '\r', setting ICRNL ONLCR 06/06 23:50:13 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD 06/06 23:50:13 yS1 login: use login config file /etc/mgetty+sendfax/login.config 06/06 23:50:13 yS1 match: user='mettanet', key='' 06/06 23:50:13 yS1 match: user='mettanet', key='/FIDO/' 06/06 23:50:13 yS1 match: user='mettanet', key='' 06/06 23:50:13 yS1 match: user='mettanet', key='' 06/06 23:50:13 yS1 match: user='mettanet', key='*'*** hit! 06/06 23:50:13 yS1 calling login: cmd='/bin/login', argv[]='login mettanet' 06/06 23:50:13 ##### data dev=ttyS1, pid=10083, caller=none, conn='38400', name='', cmd='/bin/login', user='mettanet' 06/06 23:50:13 yS1 setenv: 'CALLER_ID=none' 06/06 23:50:13 yS1 setenv: 'CONNECT=38400' -- 06/06 23:50:16 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:50:16 yS1 check for lockfiles 06/06 23:50:16 yS1 checklock: no active process has lock, will remove 06/06 23:50:16 yS1 locking the line 06/06 23:50:16 yS1 makelock(ttyS1) called 06/06 23:50:16 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:50:16 yS1 lock made 06/06 23:50:16 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR 06/06 23:50:16 yS1 lowering DTR to reset Modem 06/06 23:50:17 yS1 tss: set speed to 38400 (017) 06/06 23:50:17 yS1 tio_set_flow_control( HARD ) 06/06 23:50:17 yS1 waiting for line to clear (VTIME), read: 06/06 23:50:17 yS1 send: \dATQ0V1H0[0d] 06/06 23:50:17 yS1 waiting for ``OK'' 06/06 23:50:17 yS1 got: [0d][0a]OK ** found ** 06/06 23:50:17 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:50:17 yS1 waiting for ``OK'' 06/06 23:50:17 yS1 got: [0d] 06/06 23:50:17 yS1 CND: OK[0a]ATS0=0Q0&D3&C1[0d] 06/06 23:50:17 yS1 CND: ATS0=0Q0&D3&C1[0d][0a]OK ** found ** 06/06 23:50:17 yS1 waiting for line to clear (VTIME), read: [0d][0a] 06/06 23:50:18 yS1 removing lock file 06/06 23:50:18 yS1 waiting... 06/06 23:50:38 yS1 select returned 1 06/06 23:50:38 yS1 checking lockfiles, locking the line 06/06 23:50:38 yS1 makelock(ttyS1) called 06/06 23:50:38 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:50:38 yS1 lock made 06/06 23:50:38 yS1 waiting for ``RING'' 06/06 23:50:38 yS1 got: [0d] 06/06 23:50:38 yS1 CND: OK[0a]RING ** found ** 06/06 23:50:38 yS1 waiting for ``RING'' 06/06 23:50:38 yS1 got: [0d] 06/06 23:50:38 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:50:41 yS1 waiting for ``RING'' 06/06 23:50:41 yS1 got: [0d] 06/06 23:50:41 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:50:44 yS1 send: ATA[0d] 06/06 23:50:44 yS1 waiting for ``CONNECT'' 06/06 23:50:44 yS1 got: [0d] 06/06 23:50:44 yS1 CND: RING[0a]ATA[0d] 06/06 23:50:44 yS1 CND: ATA[0d][0a]CONNECT ** found ** 06/06 23:51:04 yS1 send: 06/06 23:51:04 yS1 waiting for ``_'' 06/06 23:51:04 yS1 got: 38400[0d] 06/06 23:51:04 yS1 CND: CONNECT 38400 06/06 23:51:04 yS1 CND: found: 38400[0a] ** found ** 06/06 23:51:04 yS1 waiting for line to clear (VTIME), read: 06/06 23:51:04 yS1 looking for utmp entry... (my PID: 10093) 06/06 23:51:04 yS1 utmp + wtmp entry made 06/06 23:51:05 yS1 tio_set_flow_control( HARD ) 06/06 23:51:05 yS1 print welcome banner (/etc/issue) 06/06 23:51:05 yS1 getlogname (no opts), read:metta[0d] 06/06 23:51:08 yS1 input finished with '\r', setting ICRNL ONLCR 06/06 23:51:08 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD 06/06 23:51:08 yS1 login: use login config file /etc/mgetty+sendfax/login.config 06/06 23:51:08 yS1 match: user='metta', key='' 06/06 23:51:08 yS1 match: user='metta', key='/FIDO/' 06/06 23:51:08 yS1 match: user='metta', key='' 06/06 23:51:08 yS1 match: user='metta', key='' 06/06 23:51:08 yS1 match: user='metta', key='*'*** hit! 06/06 23:51:08 yS1 calling login: cmd='/bin/login', argv[]='login metta' 06/06 23:51:08 ##### data dev=ttyS1, pid=10093, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' 06/06 23:51:08 yS1 setenv: 'CALLER_ID=none' 06/06 23:51:08 yS1 setenv: 'CONNECT=38400' -- 06/06 23:56:15 yS1 mgetty: experimental test release 1.1.5-Apr16 06/06 23:56:15 yS1 check for lockfiles 06/06 23:56:15 yS1 checklock: no active process has lock, will remove 06/06 23:56:15 yS1 locking the line 06/06 23:56:15 yS1 makelock(ttyS1) called 06/06 23:56:15 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:56:15 yS1 lock made 06/06 23:56:16 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR 06/06 23:56:16 yS1 lowering DTR to reset Modem 06/06 23:56:16 yS1 tss: set speed to 38400 (017) 06/06 23:56:16 yS1 tio_set_flow_control( HARD ) 06/06 23:56:16 yS1 waiting for line to clear (VTIME), read: 06/06 23:56:17 yS1 send: \dATQ0V1H0[0d] 06/06 23:56:17 yS1 waiting for ``OK'' 06/06 23:56:17 yS1 got: [0d][0a]OK ** found ** 06/06 23:56:17 yS1 send: ATS0=0Q0&D3&C1[0d] 06/06 23:56:17 yS1 waiting for ``OK'' 06/06 23:56:17 yS1 got: [0d] 06/06 23:56:17 yS1 CND: OK[0a]ATQ0V1H0[0d] 06/06 23:56:17 yS1 CND: ATQ0V1H0[0d][0a]OK ** found ** 06/06 23:56:17 yS1 waiting for line to clear (VTIME), read: [0d][0a]ATS0=0Q0&D3&C1[0d][0d][0a]OK[0d][0a] 06/06 23:56:17 yS1 removing lock file 06/06 23:56:17 yS1 waiting... 06/06 23:58:26 yS1 select returned 1 06/06 23:58:26 yS1 checking lockfiles, locking the line 06/06 23:58:26 yS1 makelock(ttyS1) called 06/06 23:58:26 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/06 23:58:26 yS1 lock made 06/06 23:58:26 yS1 waiting for ``RING'' 06/06 23:58:26 yS1 got: [0d] 06/06 23:58:26 yS1 CND: OK[0a]RING ** found ** 06/06 23:58:26 yS1 waiting for ``RING'' 06/06 23:58:26 yS1 got: [0d] 06/06 23:58:26 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:58:29 yS1 waiting for ``RING'' 06/06 23:58:29 yS1 got: [0d] 06/06 23:58:29 yS1 CND: RING[0a][0d][0a]RING ** found ** 06/06 23:58:32 yS1 send: ATA[0d] 06/06 23:58:32 yS1 waiting for ``CONNECT'' 06/06 23:58:32 yS1 got: [0d] 06/06 23:58:32 yS1 CND: RING[0a]ATA[0d] 06/06 23:58:32 yS1 CND: ATA[0d][0a]CONNECT ** found ** 06/06 23:58:53 yS1 send: 06/06 23:58:53 yS1 waiting for ``_'' 06/06 23:58:53 yS1 got: 38400[0d] 06/06 23:58:53 yS1 CND: CONNECT 38400 06/06 23:58:53 yS1 CND: found: 38400[0a] ** found ** 06/06 23:58:53 yS1 waiting for line to clear (VTIME), read: 06/06 23:58:53 yS1 looking for utmp entry... (my PID: 10131) 06/06 23:58:53 yS1 utmp + wtmp entry made 06/06 23:58:53 yS1 tio_set_flow_control( HARD ) 06/06 23:58:53 yS1 print welcome banner (/etc/issue) 06/06 23:58:53 yS1 getlogname (no opts), read:metta[0d] 06/06 23:59:12 yS1 input finished with '\r', setting ICRNL ONLCR 06/06 23:59:12 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD 06/06 23:59:12 yS1 login: use login config file /etc/mgetty+sendfax/login.config 06/06 23:59:12 yS1 match: user='metta', key='' 06/06 23:59:12 yS1 match: user='metta', key='/FIDO/' 06/06 23:59:12 yS1 match: user='metta', key='' 06/06 23:59:12 yS1 match: user='metta', key='' 06/06 23:59:12 yS1 match: user='metta', key='*'*** hit! 06/06 23:59:12 yS1 calling login: cmd='/bin/login', argv[]='login metta' 06/06 23:59:12 ##### data dev=ttyS1, pid=10131, caller=none, conn='38400', name='', cmd='/bin/login', user='metta' 06/06 23:59:12 yS1 setenv: 'CALLER_ID=none' 06/06 23:59:12 yS1 setenv: 'CONNECT=38400' -- 06/07 00:01:04 yS1 mgetty: experimental test release 1.1.5-Apr16 06/07 00:01:04 yS1 check for lockfiles 06/07 00:01:04 yS1 checklock: no active process has lock, will remove 06/07 00:01:04 yS1 locking the line 06/07 00:01:04 yS1 makelock(ttyS1) called 06/07 00:01:04 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/07 00:01:04 yS1 lock made 06/07 00:01:04 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR DCD 06/07 00:01:04 yS1 WARNING: DCD line still active, check modem settings (AT&Dx) 06/07 00:01:04 yS1 lowering DTR to reset Modem 06/07 00:01:05 yS1 TIOCMBIS failed: I/O error 06/07 00:01:05 yS1 cannot turn off soft carrier: I/O error 06/07 00:01:05 yS1 tcgetattr failed: I/O error 06/07 00:01:05 yS1 cannot get TIO: I/O error 06/07 00:01:05 yS1 mg_init_device failed, trying again 06/07 00:01:05 yS1 tio_get_rs232_lines: status: RTS CTS DSR DTR 06/07 00:01:05 yS1 lowering DTR to reset Modem 06/07 00:01:05 yS1 tss: set speed to 38400 (017) 06/07 00:01:05 yS1 tio_set_flow_control( HARD ) 06/07 00:01:05 yS1 waiting for line to clear (VTIME), read: 06/07 00:01:05 yS1 send: \dATQ0V1H0[0d] 06/07 00:01:06 yS1 waiting for ``OK'' 06/07 00:01:06 yS1 got: [0d][0a]OK ** found ** 06/07 00:01:06 yS1 send: ATS0=0Q0&D3&C1[0d] 06/07 00:01:06 yS1 waiting for ``OK'' 06/07 00:01:06 yS1 got: [0d] 06/07 00:01:06 yS1 CND: OK[0a]ATQ0V1H0[0d] 06/07 00:01:06 yS1 CND: ATQ0V1H0[0d][0a]OK ** found ** 06/07 00:01:06 yS1 waiting for line to clear (VTIME), read: [0d][0a]ATS0=0Q0&D3&C1[0d][0d][0a]OK[0d][0a] 06/07 00:01:06 yS1 removing lock file 06/07 00:01:06 yS1 waiting... 06/07 01:01:06 yS1 select returned 0 06/07 01:01:06 yS1 checking if modem is still alive 06/07 01:01:06 yS1 makelock(ttyS1) called 06/07 01:01:06 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/07 01:01:06 yS1 lock made 06/07 01:01:06 yS1 mdm_send: 'AT' 06/07 01:01:06 yS1 got:AT[0d] 06/07 01:01:06 yS1 mdm_command: string 'AT' 06/07 01:01:06 yS1 got:[0d][0a]OK[0d] 06/07 01:01:06 yS1 mdm_command: string 'OK' -> OK 06/07 01:01:06 yS1 waiting for line to clear (VTIME), read: 06/07 01:01:07 yS1 removing lock file 06/07 01:01:07 yS1 waiting... interesting to see that every hour mgetty is resetting the modem. 06/07 02:01:07 yS1 select returned 0 06/07 02:01:07 yS1 checking if modem is still alive 06/07 02:01:07 yS1 makelock(ttyS1) called 06/07 02:01:07 yS1 do_makelock: lock='/var/lock/LCK..ttyS1' 06/07 02:01:07 yS1 lock made 06/07 02:01:07 yS1 mdm_send: 'AT' 06/07 02:01:07 yS1 got:[0a]AT[0d] 06/07 02:01:07 yS1 mdm_command: string 'AT' 06/07 02:01:07 yS1 got:[0d][0a]OK[0d] 06/07 02:01:07 yS1 mdm_command: string 'OK' -> OK 06/07 02:01:07 yS1 waiting for line to clear (VTIME), read: 06/07 02:01:07 yS1 removing lock file 06/07 02:01:07 yS1 waiting... 06/07 03:01:07 yS1 select returned 0 06/07 03:01:07 yS1 checking if modem is still alive Jacob (Mettavihari)
