[debian-users:24524] flets-ISDN TA line cut off periodically

[MATSUDA Yoh-ichi / 松田陽一 <yoh@xxxxxxxxxxxx>]

こんにちは。松田陽一@三鷹です。
長文失礼します。(__)

表題の通り、私の住む三鷹市にもフレッツISDNが通るようになり、早速 pppd
にて常時接続環境に移行しました。
勿論、 ipchains でポートはキュッと閉めてます。

ところが、約10時間毎の定期的な間隔で、回線が切断される現象に悩んでます。
「IPアドレスが動くからセキュリティ的にはそっちの方が良いだろう」と思わ
れるかも知れませんが、メール取り込みの最中にいきなりブツッと切られては
かないません。
なお、 /var/log/syslog* にて、 hangup という文字列で検索した結果を、し
ぐねちゃ以降に添付します。

最初はプロバイダのOCN に問い合わせたのですが、「当方ではそのような定期
的な切断処理は行っておりません。」との回答でした。

そこで、 TA のマニュアルを引っ張り出して、 AT コマンドの一覧を眺めてみ
ました。
連続してデータが流れない場合は切断するタイマとして、

AT$N9=n(n=0-10) データポートの無通信監視タイマ
                0:監視しない
                1〜10:1〜10分

がありますが、これとてたったの10分しか設定できません。
これでは、メール取得の最中にいきなり切られる原因の説明になりません。

その代わり、切断原因を報告する

AT#C データポートの通信料金、切断理由表示
        CAUSE  =#の後に切断理由コードを表示します。
        SOURCE = の後に生成源を表示します。
        CHARGE =\の後に通信料金を表示します。

を見つけましたので、これを pppd の chatscript に仕込んでみました。

# 電話番号は隠蔽してます。

######## /etc/chatscripts/flets_ocn ########
# This chatfile was generated by pppconfig 2.0.5.
# Please do not delete any of the comments.  Pppconfig needs them.
# 
# ispauth PAP
# abortstring
ABORT BUSY ABORT 'NO CARRIER' ABORT VOICE ABORT 'NO DIALTONE' ABORT 'NO DIAL TONE' ABORT 'NO ANSWER'
# modeminit
'' AT#CZ
# ispnumber
OK-AT-OK ATH0E1Q0V1X3$N9=10$N1=1&D1D0422999999
# ispconnect
CONNECT \d\c
# prelogin
# ispname
# isppassword
# postlogin
# end of pppconfig stuff
######## /etc/chatscripts/flets_ocn end ####

本来、
	'' ATZ
のところを、
	'' AT#CZ
としてみました。
以下にログを添付します。
#---------------------------------------------------------------
Oct 13 20:00:05 hoge pppd[10902]: Hangup (SIGHUP)
Oct 13 20:00:05 hoge pppd[10902]: Modem hangup
Oct 13 20:00:05 hoge pppd[10902]: Script /etc/ppp/ip-down started (pid 12932)
Oct 13 20:00:05 hoge pppd[10902]: Connection terminated.
Oct 13 20:00:05 hoge pppd[10902]: Connect time 600.0 minutes.
Oct 13 20:00:05 hoge pppd[10902]: Sent 923248 bytes, received 1473243 bytes.
Oct 13 20:00:05 hoge pppd[10902]: Waiting for 1 child processes...
Oct 13 20:00:05 hoge pppd[10902]:   script /etc/ppp/ip-down, pid 12932
Oct 13 20:00:05 hoge pppd[10902]: Script /etc/ppp/ip-down finished (pid 12932), status = 0x0
Oct 13 20:00:05 hoge pppd[10902]: Exit.
Oct 13 20:05:01 hoge /USR/SBIN/CRON[12943]: (yoh) CMD (/home/yoh/pppcontinue.sh)
Oct 13 20:05:02 hoge pppd[12952]: pppd 2.3.11 started by yoh, uid 1000
Oct 13 20:05:03 hoge chat[12953]: abort on (BUSY)
Oct 13 20:05:03 hoge chat[12953]: abort on (NO CARRIER)
Oct 13 20:05:03 hoge chat[12953]: abort on (VOICE)
Oct 13 20:05:03 hoge chat[12953]: abort on (NO DIALTONE)
Oct 13 20:05:03 hoge chat[12953]: abort on (NO DIAL TONE)
Oct 13 20:05:03 hoge chat[12953]: abort on (NO ANSWER)
Oct 13 20:05:03 hoge chat[12953]: send (AT#CZ^M)
Oct 13 20:05:04 hoge chat[12953]: expect (OK)
Oct 13 20:05:04 hoge chat[12953]: AT#CZ^M^M
Oct 13 20:05:04 hoge chat[12953]: DATA PORT CAUSE INFORMATION^M
Oct 13 20:05:04 hoge chat[12953]: ^M
Oct 13 20:05:04 hoge chat[12953]: CAUSE                    = #016^M
Oct 13 20:05:04 hoge chat[12953]: SOURCE                   = 00^M
Oct 13 20:05:04 hoge chat[12953]: CHARGE                   = \0^M
Oct 13 20:05:04 hoge chat[12953]: ^M
Oct 13 20:05:04 hoge chat[12953]: OK
Oct 13 20:05:04 hoge chat[12953]:  -- got it 
Oct 13 20:05:04 hoge chat[12953]: send (ATH0E1Q0V1X3$N9=10$N1=1&D1D0422999999^M)
Oct 13 20:05:04 hoge chat[12953]: expect (CONNECT)
Oct 13 20:05:04 hoge chat[12953]: ^M
Oct 13 20:05:06 hoge chat[12953]: ATH0E1Q0V1X3$N9=10$N1=1&D1D0422999999^M^M
Oct 13 20:05:06 hoge chat[12953]: CONNECT
Oct 13 20:05:06 hoge chat[12953]:  -- got it 
Oct 13 20:05:06 hoge chat[12953]: send (\d)
Oct 13 20:05:07 hoge pppd[12952]: Serial connection established.
Oct 13 20:05:07 hoge pppd[12952]: Using interface ppp0
Oct 13 20:05:07 hoge pppd[12952]: Connect: ppp0 <--> /dev/ttyS0
#---------------------------------------------------------------

# /home/yoh/pppcontinue.sh は、 5分毎に ppp 接続を監視して、切れて
# いたら再度接続するシェルスクリプトです。

先ず、

Oct 13 20:05:04 hoge chat[12953]: CAUSE                    = #016^M

#016 は「正常切断」とのことです。
00 は「ユーザ自身」とのことです。
よって、 TA のリザルトコードからは、ユーザ側で切断を行ったとの記録
になっています。

そして、

Oct 13 20:00:05 hoge pppd[10902]: Connect time 600.0 minutes.

ぴったり 600分と出ています。
もし、 TA 側、或はフレッツISDN網側の原因なら、このようなぴったりの数値
にはならない筈です。

念の為、 syslog を "Connect time" で検索した結果もしぐねちゃ以降にぶら
下げておきます。

何らかのソフトの設定で、 ppp 接続が 600分に制限されているのではないか
と思うのですが、何が原因なのかが見当つきません。

そこで、 /etc/ 以下の全てのファイルに対して、 "600" で rgrep してみま
した。

#---------------------------------------------------------------
hoge# rgrep 600 /etc/*
/etc/alternatives/communicator:			chmod 600 ${HOME}/.netscape/*
/etc/alternatives/netscape:			chmod 600 ${HOME}/.netscape/*
/etc/alternatives/pgp-doc/pgpdoc1.txt:There is a company called AccessData (87 East 600 South, Orem, Utah
/etc/alternatives/navigator:			chmod 600 ${HOME}/.netscape/*
バイナリー・ファイル/etc/alternatives/mule2と一致します
/etc/cron.daily/standard:        chmod 600 passwd.bak group.bak
/etc/cron.daily/standard:          chmod 600 shadow.bak
/etc/cron.daily/standard:	  chmod 600 gshadow.bak
/etc/default/devpts:# Set to 600 to have `mesg n' be the default
/etc/devinfo:	fd[0-3]h1600  (floppy) : 92
/etc/devinfo:	fd[0-3]u1600  (floppy) : 124
/etc/devinfo:	fd[4-7]h1600  (floppy) : 128 + 92
/etc/devinfo:	fd[4-7]u1600  (floppy) : 128 + 124
/etc/dhcpd.conf:default-lease-time 600;
/etc/dhcpd.conf.dpkg-dist:default-lease-time 600;
/etc/dhcpd.conf.dpkg-dist:  default-lease-time 600;
/etc/emacs/site-start.d/50mgp.el:(setq mgp-options "-g 800x600")
/etc/fdprm:cbm1581         1600    10   2  80    2 0x2A 0x02 0xDF     0x2E
/etc/fdprm:800/720         1600    10   2  80    0 0x2A 0x02 0xDF     0x2E
/etc/im/SiteConfig:#MsgMode=0600
/etc/init.d/mountall.sh:	mknod -m 600 /dev/initctl p
/etc/inittab:#T0:23:respawn:/sbin/getty -L ttyS0 9600 vt100
/etc/inittab:#T1:23:respawn:/sbin/getty -L ttyS1 9600 vt100
/etc/inittab:#T3:23:respawn:/sbin/mgetty -x0 -s 57600 ttyS3
/etc/kon.cfg:	800 864 1016 1064 600 606 608 632
/etc/kon.cfg:	800 864 1016 1064 600 606 608 632
/etc/login.defs:# TTYPERM to either 622 or 600.
/etc/login.defs:TTYPERM		0600
/etc/login.defs:UID_MAX			60000
/etc/login.defs:GID_MAX			60000
/etc/lyxrc:#\autosave 600
/etc/makedev.cfg:class mouse:	root	root	0600	# mouse*
/etc/makedev.cfg:class scsi:	root	root	0600	# sg*
/etc/makedev.cfg:class vcs:	root	root	0600	# vcs*
/etc/netscape4/defaults/bookmarks.html:    <DT><H3 ADD_DATE="903260084">Personal Toolbar Folder</H3>
/etc/pcnfsd.conf:#	uidrange uid-uid		( default: 100-60002 )
/etc/ppp/ip-up:/sbin/ipchains -A ppp-in -p tcp -s 0/0 -d $PPP_LOCAL 6000 -j DENY
/etc/ppxp/conf/modem:set DIAL.TIMEOUT 60000
/etc/proftpd.conf.dpkg-dist:TimeoutNoTransfer		600
/etc/proftpd.conf.dpkg-dist:TimeoutStalled			600
/etc/proftpd.conf.old:TimeoutNoTransfer		600
/etc/proftpd.conf.old:TimeoutStalled			600
/etc/rcS.d/S35mountall.sh:	mknod -m 600 /dev/initctl p
/etc/services:zebrasrv	2600/tcp			# zebra service
/etc/ssh/sshd_config:LoginGraceTime 600
/etc/ssh/sshd_config:KeyRegenerationInterval 3600
#---------------------------------------------------------------

/etc/X11/
/etc/texmf/
/etc/vga/
/etc/netscape4/
は除外しました。

おうち LAN 用に動かしている dhcpd が一番クサイかな? という気もしなくも
ないのですが、 ppp と mgetty には該当するような設定項目も見当たらず、
一体何が悪いのか判らず、どんづまり状態になってしまいました。

何が原因でしょうか?

最後に、マシン諸元を記します。

OS: potato, カーネル2.2.17(自前カスタム)
TA: NEC AtermIT55(DSUなし)

他に調べなければならない項目等ありましたら、ご教授願います。(__)
--
♪そぉ〜っとぉ〜☆彡
松田 陽一(yoh)
mailto:yoh@xxxxxxxxxxxx
http://www2.palnet.or.jp/~matsuda/index.htm

hoge:~$ zgrep -i hangup /var/log/syslog /var/log/syslog.*
/var/log/syslog:Oct 13 09:57:49 hoge pppd[7493]: Hangup (SIGHUP)
/var/log/syslog:Oct 13 09:57:49 hoge pppd[7493]: Modem hangup
/var/log/syslog:Oct 13 20:00:05 vawr pppd[10902]: Hangup (SIGHUP)
/var/log/syslog:Oct 13 20:00:05 vawr pppd[10902]: Modem hangup
/var/log/syslog.0:Oct 12 15:55:05 hoge pppd[3073]: Hangup (SIGHUP)
/var/log/syslog.0:Oct 12 15:55:05 hoge pppd[3073]: Modem hangup
/var/log/syslog.1.gz:Oct 11 09:45:05 hoge pppd[29657]: Hangup (SIGHUP)
/var/log/syslog.1.gz:Oct 11 09:45:05 hoge pppd[29657]: Modem hangup
/var/log/syslog.1.gz:Oct 11 19:50:06 hoge pppd[31413]: Hangup (SIGHUP)
/var/log/syslog.1.gz:Oct 11 19:50:06 hoge pppd[31413]: Modem hangup
/var/log/syslog.1.gz:Oct 12 05:51:18 hoge pppd[1029]: Hangup (SIGHUP)
/var/log/syslog.1.gz:Oct 12 05:51:18 hoge pppd[1029]: Modem hangup
/var/log/syslog.2.gz:Oct 10 13:35:05 hoge pppd[25955]: Hangup (SIGHUP)
/var/log/syslog.2.gz:Oct 10 13:35:05 hoge pppd[25955]: Modem hangup
/var/log/syslog.2.gz:Oct 10 23:40:06 hoge pppd[27850]: Hangup (SIGHUP)
/var/log/syslog.2.gz:Oct 10 23:40:06 hoge pppd[27850]: Modem hangup
/var/log/syslog.3.gz:Oct  9 16:00:05 hoge pppd[23185]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct  9 16:00:05 hoge pppd[23185]: Modem hangup
/var/log/syslog.3.gz:Oct 10 02:05:05 hoge pppd[24630]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 02:05:05 hoge pppd[24630]: Modem hangup
/var/log/syslog.3.gz:Oct 10 02:55:06 hoge pppd[25804]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 03:00:22 hoge pppd[25817]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 03:00:22 hoge pppd[25817]: Modem hangup
/var/log/syslog.3.gz:Oct 10 03:05:22 hoge pppd[25830]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 03:05:22 hoge pppd[25830]: Modem hangup
/var/log/syslog.3.gz:Oct 10 03:10:32 hoge pppd[25846]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 03:34:24 hoge pppd[25907]: Hangup (SIGHUP)
/var/log/syslog.3.gz:Oct 10 03:34:24 hoge pppd[25907]: Modem hangup
/var/log/syslog.4.gz:Oct  8 09:45:06 hoge pppd[2507]: Hangup (SIGHUP)
/var/log/syslog.4.gz:Oct  8 09:45:06 hoge pppd[2507]: Modem hangup
/var/log/syslog.4.gz:Oct  8 19:50:06 hoge pppd[20193]: Hangup (SIGHUP)
/var/log/syslog.4.gz:Oct  8 19:50:06 hoge pppd[20193]: Modem hangup
/var/log/syslog.4.gz:Oct  9 05:55:06 hoge pppd[21553]: Hangup (SIGHUP)
/var/log/syslog.4.gz:Oct  9 05:55:06 hoge pppd[21553]: Modem hangup
/var/log/syslog.5.gz:Oct  7 13:35:05 hoge pppd[32103]: Hangup (SIGHUP)
/var/log/syslog.5.gz:Oct  7 13:35:05 hoge pppd[32103]: Modem hangup
/var/log/syslog.5.gz:Oct  7 23:40:06 hoge pppd[1343]: Hangup (SIGHUP)
/var/log/syslog.5.gz:Oct  7 23:40:06 hoge pppd[1343]: Modem hangup
/var/log/syslog.6.gz:Oct  6 07:24:42 hoge pppd[27103]: Hangup (SIGHUP)
/var/log/syslog.6.gz:Oct  6 07:24:42 hoge pppd[27103]: Modem hangup
/var/log/syslog.6.gz:Oct  6 17:25:05 hoge pppd[29086]: Hangup (SIGHUP)
/var/log/syslog.6.gz:Oct  6 17:25:05 hoge pppd[29086]: Modem hangup
/var/log/syslog.6.gz:Oct  7 03:30:05 hoge pppd[30763]: Hangup (SIGHUP)
/var/log/syslog.6.gz:Oct  7 03:30:05 hoge pppd[30763]: Modem hangup


hoge:~$ zgrep "Connect time" /var/log/syslog /var/log/syslog.*
/var/log/syslog:Oct 13 09:57:49 hoge pppd[7493]: Connect time 600.0 minutes.
/var/log/syslog:Oct 13 20:00:05 hoge pppd[10902]: Connect time 600.0 minutes.
/var/log/syslog.0:Oct 12 15:55:05 hoge pppd[3073]: Connect time 600.0 minutes.
/var/log/syslog.0:Oct 12 23:57:20 hoge pppd[5294]: Connect time 477.3 minutes.
/var/log/syslog.1.gz:Oct 11 09:45:05 hoge pppd[29657]: Connect time 600.0 minutes.
/var/log/syslog.1.gz:Oct 11 19:50:06 hoge pppd[31413]: Connect time 600.0 minutes.
/var/log/syslog.1.gz:Oct 12 05:51:18 hoge pppd[1029]: Connect time 600.0 minutes.
/var/log/syslog.2.gz:Oct 10 13:35:05 hoge pppd[25955]: Connect time 600.0 minutes.
/var/log/syslog.2.gz:Oct 10 23:40:06 hoge pppd[27850]: Connect time 600.0 minutes.
/var/log/syslog.3.gz:Oct  9 16:00:05 hoge pppd[23185]: Connect time 600.0 minutes.
/var/log/syslog.3.gz:Oct 10 02:05:05 hoge pppd[24630]: Connect time 600.0 minutes.
/var/log/syslog.3.gz:Oct 10 02:50:07 hoge pppd[25693]: Connect time 39.6 minutes.
/var/log/syslog.3.gz:Oct 10 03:22:07 hoge pppd[25859]: Connect time 6.5 minutes.
/var/log/syslog.3.gz:Oct 10 03:34:24 hoge pppd[25907]: Connect time 9.1 minutes.
/var/log/syslog.4.gz:Oct  8 09:45:06 hoge pppd[2507]: Connect time 600.0 minutes.
/var/log/syslog.4.gz:Oct  8 19:50:06 hoge pppd[20193]: Connect time 600.0 minutes.
/var/log/syslog.4.gz:Oct  9 05:55:06 hoge pppd[21553]: Connect time 600.0 minutes.
/var/log/syslog.5.gz:Oct  7 13:35:05 hoge pppd[32103]: Connect time 600.0 minutes.
/var/log/syslog.5.gz:Oct  7 23:40:06 hoge pppd[1343]: Connect time 600.0 minutes.
/var/log/syslog.6.gz:Oct  6 07:24:42 hoge pppd[27103]: Connect time 600.0 minutes.
/var/log/syslog.6.gz:Oct  6 17:25:05 hoge pppd[29086]: Connect time 600.0 minutes.
/var/log/syslog.6.gz:Oct  7 03:30:05 hoge pppd[30763]: Connect time 600.0 minutes.