Всем привет! У меня имеется проблема по стыковке DSL-2740U и ОАО "Северо-западный телеком", услуга "Авангард" Ленинградская область.
Короче, суть проблемы: тип соединения PPoE, модем круглые сутки включен, но связисты с 2-х до 3-х часов ночи принудительно рвут сессию, дабы подключились заново. Так вот: модем после такого дела бывает новую сессию не начинает (Authentication failure), а бывает и начинает. Прошивка в данный момент DRU_DSL-2740U_2.30b327.bin , но проблема аналогична и на прошивках 2.22 и 1.26. Аналогичное поведение и при ручном разрыве сессии (хочу соединяюсь хочу нет, хотя обычно не хочет). Жатие на кнопочку UP или задание команд из telneta никакого эффекта не дают. В то же время, мой "старый" DSL-500T восстанавливат связь всегда, да и из Виндовса авторизация проходит чётко. Проблема временно решается путём перезагрузки модема, тогда аутентификация проходит с первого раза. Неоднократные попытки обнуления настроек, так же ни к чему не привели. Пытался экспериментировать с Authentication Method, вроде бы с CHAP лучше восстанавливается, но это "вроде..." В остальном претензий нет. Всё работает чётко.
Кто виноват?
Что делать?
Лог после неудачной попытки (режим Debugging):
Jan 1 00:00:20 user warn kernel: dgasp: kerSysRegisterDyingGaspHandler: dsl0 registered
Jan 1 00:00:20 user warn kernel: ip_tables: (C) 2000-2002 Netfilter core team
Jan 1 00:00:20 user warn kernel: ip_conntrack version 2.1 (253 buckets, 0 max) - 368 bytes per conntrack
Jan 1 00:00:20 user warn kernel: ip_conntrack_pptp version 2.1 loaded
Jan 1 00:00:20 user warn kernel: ip_nat_pptp version 2.0 loaded
Jan 1 00:00:20 user warn kernel: ip_conntrack_h323: init
Jan 1 00:00:20 user warn kernel: ip_nat_h323: initialize the module!
Jan 1 00:00:20 user warn kernel: ip_conntrack_rtsp v0.01 loading
Jan 1 00:00:20 user crit kernel: ADSL G.994 training
Jan 1 00:00:20 user warn kernel: ip_nat_rtsp v0.01 loading
Jan 1 00:00:20 user warn kernel: ipt_time loading
Jan 1 00:00:20 user crit kernel: ADSL G.992 started
Jan 1 00:00:20 user crit kernel: ADSL G.992 channel analysis
Jan 1 00:00:20 user info kernel: device eth0 entered promiscuous mode
Jan 1 00:00:20 user info kernel: br0: port 1(eth0) entering learning state
Jan 1 00:00:20 user info kernel: br0: topology change detected, propagating
Jan 1 00:00:20 user info kernel: rding state
Jan 1 00:00:20 user crit kernel: ADSL link up, interleaved, us=512, ds=2048
Jan 1 00:00:20 user info kernel: device nas_8_35 entered promiscuous mode
Jan 1 00:00:20 user info kernel: br0: port 2(nas_8_35) entering learning state
Jan 1 00:00:20 user info kernel: br0: topology change detected, propagating
Jan 1 00:00:20 user info kernel: br0: port 2(nas_8_35) entering forwarding state
Jan 1 00:00:20 user info kernel: device eth0 left promiscuous mode
Jan 1 00:00:20 user info kernel: br0: port 1(eth0) entering disabled state
Jan 1 00:00:20 user info kernel: device eth0 entered promiscuous mode
Jan 1 00:00:20 user info kernel: br0: port 1(eth0) entering learning state
Jan 1 00:00:20 user info kernel: br0: topology change detected, propagating
Jan 1 00:00:20 user info kernel: br0: port 1(eth0) entering forwarding state
Jan 1 00:00:20 user info kernel: device wl0 entered promiscuous mode
Jan 1 00:00:21 user debug syslog: fwscheduler
Jan 1 00:00:21 user debug syslog: pppd plugin pppoe nas_8_35 linkname nas_8_35 interface_name 8_35_1 nodetach user ПОЛЬЗОВАТЕЛЬ password ПАРОЛЬ debug persist mtu 1375 usepeerdns refuse-eap lcp-echo-interval 15 lcp-echo-failure 4 holdoff 3 o
Jan 1 00:00:22 daemon info pppd[548]: RP-PPPoE plugin version 3.3 compiled against pppd 2.4.3
Jan 1 00:00:22 daemon info pppd[548]: Plugin pppoe called.
Jan 1 00:00:22 daemon notice pppd[548]: pppd 2.4.3 started by admin, uid 0
Jan 1 00:00:22 user debug syslog: iptables -t nat -I DNS_RELAY 1 -i br0 -d 89.20.31.1 -p udp --dport 53 -j DNAT --to 128.9.0.107
Jan 1 00:00:23 daemon info pppd[548]: Sent PADT
Jan 1 00:00:23 daemon debug pppd[548]: PADS: Service-Name: ''
Jan 1 00:00:23 daemon info pppd[548]: PPP session is 42434
Jan 1 00:00:23 daemon debug pppd[548]: using channel 1
Jan 1 00:00:23 daemon info pppd[548]: Using interface ppp_8_35_1
Jan 1 00:00:23 daemon notice pppd[548]: Connect: ppp_8_35_1 <--> nas_8_35
Jan 1 00:00:23 daemon warn pppd[548]: Couldn't increase MTU to 1500
Jan 1 00:00:23 daemon warn pppd[548]: Couldn't increase MRU to 1500
Jan 1 00:00:23 daemon debug pppd[548]: sent [LCP ConfReq id=0x1 ]
Jan 1 00:00:23 daemon debug pppd[548]: rcvd [LCP ConfAck id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [LCP ConfReq id=0x2 ]
Jan 1 00:00:25 daemon debug pppd[548]: sent [LCP ConfAck id=0x2 ]
Jan 1 00:00:25 daemon warn pppd[548]: Couldn't increase MRU to 1500
Jan 1 00:00:25 daemon debug pppd[548]: sent [LCP EchoReq id=0x0 magic=0x48555d5e]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [CHAP Challenge id=0x1 , name = "Tihvin-Lucent"]
Jan 1 00:00:25 daemon debug pppd[548]: sent [CHAP Response id=0x1 , name = "name"]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [LCP EchoRep id=0x0 magic=0x90e8eb6b]
Jan 1 00:00:25 user info kernel: HTB init, kernel part version 3.17
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [CHAP Success id=0x1 ""]
Jan 1 00:00:25 daemon info pppd[548]: CHAP authentication succeeded
Jan 1 00:00:25 daemon notice pppd[548]: peer from calling number 00:11:5C:B6:B5:40 authorized
Jan 1 00:00:25 daemon debug pppd[548]: sent [CCP ConfReq id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: sent [IPCP ConfReq id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [IPCP ConfReq id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: sent [IPCP ConfAck id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [LCP ProtRej id=0x3 80 fd 01 01 00 0a 12 06 00 00 00 01]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [IPCP ConfNak id=0x1 ]
Jan 1 00:00:25 daemon debug pppd[548]: sent [IPCP ConfReq id=0x2 ]
Jan 1 00:00:25 daemon debug pppd[548]: rcvd [IPCP ConfAck id=0x2 ]
Jan 1 00:00:25 daemon notice pppd[548]: local IP address 212.58.211.152
Jan 1 00:00:25 daemon notice pppd[548]: remote IP address 212.58.222.212
Jan 1 00:00:25 daemon notice pppd[548]: primary DNS address 212.48.192.8
Jan 1 00:00:25 daemon notice pppd[548]: secondary DNS address 212.58.192.12
Jan 1 00:00:25 daemon debug pppd[548]: Script /etc/ppp/ip-up started (pid 632)
Jan 1 00:00:25 daemon debug pppd[548]: Script /etc/ppp/ip-up finished (pid 632), status = 0x0
Jan 1 00:00:26 user debug syslog: ifconfig ppp_8_35_1 mtu 1375 &
Jan 1 00:00:28 user debug syslog: ddnsd /var/ddnsd.cfg /var/ddnsd.cache &
Jan 1 00:00:28 user debug syslog: route add default gw 212.58.222.212 2>/dev/null
Jan 1 00:00:28 user debug syslog: route add -net netmask 255.255.255.255 dev ppp_8_35_1 2>/dev/null
Jan 1 00:00:28 user debug syslog: iptables -F CH_TCPMSS
Jan 1 00:00:28 user debug syslog: iptables -A CH_TCPMSS -o ppp_8_35_1 -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu
Jan 1 00:00:28 user debug syslog: iptables -A CH_TCPMSS -i ppp_8_35_1 -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu
Jan 1 00:00:28 user debug syslog: iptables -A CH_TCPMSS -j RETURN
Jan 1 00:00:28 user debug syslog: echo > /proc/net/ip_conntrack
Jan 1 00:00:28 user debug syslog: echo "4096" > /proc/sys/net/ipv4/ip_conntrack_max
Jan 1 00:00:28 user debug syslog: iptables -t nat -F DNS_RELAY
Jan 1 00:00:28 user debug syslog: iptables -t nat -A DNS_RELAY -j RETURN
Jan 1 00:00:28 user debug syslog: iptables -t nat -D ENABLE_NAT -o ppp_8_35_1 -s 89.20.31.0/255.255.255.240 -j MASQUERADE 2>/dev/null
Jan 1 00:00:28 user debug syslog: iptables -t nat -I ENABLE_NAT -o ppp_8_35_1 -s 89.20.31.0/255.255.255.240 -j MASQUERADE
Jan 1 00:00:28 user debug syslog: iptables -t nat -D ENABLE_NAT -j RETURN 2>/dev/null
Jan 1 00:00:29 user debug syslog: iptables -t nat -A ENABLE_NAT -j RETURN
Jan 1 00:00:29 user debug syslog: iptables -t nat -F DNS_RELAY
Jan 1 00:00:29 user debug syslog: iptables -t nat -I DNS_RELAY 1 -i br0 -d 89.20.31.1 -p udp --dport 53 -j DNAT --to 212.58.199.18
Jan 1 00:00:29 user debug syslog: iptables -t nat -A DNS_RELAY -j RETURN
Jan 1 00:00:29 user debug syslog: /bin/dnsprobe &
Jan 1 00:00:29 user notice dnsprobe[734]: dnsprobe started!
Jan 1 00:00:30 user debug syslog: iptables -F SIP_ALLOW
Jan 1 00:00:30 user debug syslog: iptables -A SIP_ALLOW -j RETURN
Jan 1 00:00:30 user debug syslog: iptables -F SIP_ALLOW
Jan 1 00:00:30 user debug syslog: iptables -I SIP_ALLOW 1 -i ppp_8_35_1 -p udp --dport 5060 -j ACCEPT 2>/dev/null
Jan 1 00:00:30 user debug syslog: iptables -t nat -F SIP_ALLOW
Jan 1 00:00:30 user debug syslog: iptables -t nat -I SIP_ALLOW 1 -i br0 -p udp --dport 5060 -j REDIRECT --to-ports 5060 2>/dev/null
Jan 1 00:00:30 user debug syslog: iptables -t nat -A SIP_ALLOW -j RETURN
Jan 1 00:00:30 user debug syslog: iptables -A SIP_ALLOW -j RETURN
Jan 1 00:00:30 user debug syslog: siproxd --config /var/siproxd/siproxd.conf &
Jan 1 00:00:31 user debug syslog: iptables -F TR069_ALLOW
Feb 22 20:55:20 user debug syslog: iptables -I TR069_ALLOW 1 -j ACCEPT -i ppp_8_35_1 -p tcp --dport 30005
Feb 22 20:55:20 user notice syslog: siproxd.c:180 INFO:siproxd-0.5.13-2935 i686-pc-linux-gnu starting up
Feb 22 20:55:20 user debug syslog: iptables -I TR069_ALLOW 1 -j ACCEPT -i ppp_8_35_1 -p udp -s 89.20.31.1/28 --dport 30006
Feb 22 20:55:20 user debug syslog: iptables -A TR069_ALLOW -j RETURN
Feb 22 20:55:20 user notice syslog: siproxd.c:216 INFO:daemonized, pid=858
Feb 22 20:55:20 user debug syslog: echo "0"> /var/ppp/pptpstate
Feb 22 20:55:20 user debug syslog: chmod +rx /var/ppp/ip-up.local
Feb 22 20:55:21 user notice syslog: sock.c:65 INFO:bound to port 5060
Feb 22 20:55:21 user notice syslog: register.c:72 WARNING:registration file not found, starting with empty table
Feb 22 20:55:21 user notice syslog: siproxd.c:263 INFO:siproxd-0.5.13-2935 i686-pc-linux-gnu started
Feb 22 20:55:21 daemon err user: tr69c: Unable to retrieve attributes in scratch PAD
Feb 22 20:55:21 daemon err user: Stored Parameter Attribute data is corrupt or missing
Feb 22 21:00:56 user crit kernel: ADSL link down
Feb 22 21:00:56 user debug syslog: echo "0" > /var/ppp/pptpstate
Feb 22 21:00:56 user warn kernel: BcmAdsl_Initialize=0xC00613F8, g_pFnNotifyCallback=0xC0079C74
Feb 22 21:00:56 user warn kernel: AnnexCParam=0x7FFF7EB8 AnnexAParam=0x00000985 adsl2=0x00000001
Feb 22 21:00:56 user warn kernel: dgasp: kerSysRegisterDyingGaspHandler: dsl0 registered
Feb 22 21:00:56 daemon notice pppd[548]: Terminating connection due to link down.
Feb 22 21:00:56 daemon info pppd[548]: Connect time 4810860.6 minutes.
Feb 22 21:00:56 daemon info pppd[548]: Sent 1809887 bytes, received 61032207 bytes.
Feb 22 21:00:57 daemon debug pppd[548]: Script /etc/ppp/ip-down started (pid 1010)
Feb 22 21:00:57 daemon warn pppd[548]: Couldn't increase MTU to 1500
Feb 22 21:00:57 daemon warn pppd[548]: Couldn't increase MRU to 1500
Feb 22 21:00:57 daemon debug pppd[548]: sent [LCP TermReq id=0x2 "Link down"]
Feb 22 21:00:57 daemon debug pppd[548]: Script /etc/ppp/ip-down finished (pid 1010), status = 0x0
Feb 22 21:00:58 user crit kernel: ADSL G.994 training
Feb 22 21:01:00 daemon debug pppd[548]: sent [LCP TermReq id=0x3 "Link down"]
Feb 22 21:01:00 user warn dnsprobe[734]: dns query failed
Feb 22 21:01:00 user crit kernel: ADSL G.992 started
Feb 22 21:01:02 user warn dnsprobe[734]: dns query failed
Feb 22 21:01:03 daemon notice pppd[548]: Connection terminated....
Feb 22 21:01:03 user warn kernel: dev_shutdown, dec ppp device refcnt, dev->refcnt=11
Feb 22 21:01:03 user crit kernel: ADSL G.992 channel analysis
Feb 22 21:01:04 user warn dnsprobe[734]: dns query failed
Feb 22 21:01:04 user notice dnsprobe[734]: Primary DNS server Is Down... Switching To Secondary DNS server
Feb 22 21:01:07 user crit kernel: ADSL link up, interleaved, us=512, ds=2048
Feb 22 21:01:08 user debug syslog: iptables -t nat -I DNS_RELAY 1 -i br0 -d 89.20.31.1 -p udp --dport 53 -j DNAT --to 128.9.0.107
Feb 22 21:01:09 daemon info pppd[548]: Sent PADT
Feb 22 21:01:09 daemon debug pppd[548]: PADS: Service-Name: ''
Feb 22 21:01:09 daemon info pppd[548]: PPP session is 42503
Feb 22 21:01:09 daemon debug pppd[548]: using channel 2
Feb 22 21:01:09 daemon info pppd[548]: Using interface ppp_8_35_1
Feb 22 21:01:09 daemon notice pppd[548]: Connect: ppp_8_35_1 <--> nas_8_35
Feb 22 21:01:09 daemon warn pppd[548]: Couldn't increase MTU to 1500
Feb 22 21:01:09 daemon warn pppd[548]: Couldn't increase MRU to 1500
Feb 22 21:01:09 daemon debug pppd[548]: sent [LCP ConfReq id=0x4 ]
Feb 22 21:01:09 daemon debug pppd[548]: rcvd [LCP ConfAck id=0x4 ]
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [LCP ConfReq id=0x2 ]
Feb 22 21:01:11 daemon debug pppd[548]: sent [LCP ConfAck id=0x2 ]
Feb 22 21:01:11 daemon warn pppd[548]: Couldn't increase MRU to 1500
Feb 22 21:01:11 daemon debug pppd[548]: sent [LCP EchoReq id=0x0 magic=0x5cd9512e]
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [CHAP Challenge id=0x1 , name = "Tihvin-Lucent"]
Feb 22 21:01:11 daemon debug pppd[548]: sent [CHAP Response id=0x1 <9d94beb7e3b18ede7c10155a1e1365dd>, name = "name"]
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [LCP EchoRep id=0x0 magic=0x90ee5f2a]
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [CHAP Failure id=0x1 "Authentication failed"]
Feb 22 21:01:11 daemon info pppd[548]: CHAP authentication failed: Authentication failed
Feb 22 21:01:11 daemon warn pppd[548]: Couldn't increase MTU to 1500
Feb 22 21:01:11 daemon warn pppd[548]: Couldn't increase MRU to 1500
Feb 22 21:01:11 daemon debug pppd[548]: sent [LCP TermReq id=0x5 "Failed to authenticate ourselves to peer"]
Feb 22 21:01:11 daemon err pppd[548]: User name and password authentication failed.
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [LCP TermReq id=0x3]
Feb 22 21:01:11 daemon debug pppd[548]: sent [LCP TermAck id=0x3]
Feb 22 21:01:11 daemon debug pppd[548]: rcvd [LCP TermAck id=0x5]
Feb 22 21:01:11 daemon notice pppd[548]: Connection terminated....
Feb 22 21:01:11 daemon info pppd[548]: Exit.
Feb 22 21:01:36 user warn dnsprobe[734]: dns query failed
Feb 22 21:01:38 user warn dnsprobe[734]: dns query failed
Feb 22 21:01:40 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:12 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:14 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:16 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:48 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:50 user warn dnsprobe[734]: dns query failed
Feb 22 21:02:52 user warn dnsprobe[734]: dns query failed
На прошедшую синхронизацию ADSL не обращайте внимания, это я выдёргивал RJ-11 с разъёма, чтоб эмитировать ситуацию.
Последний раз редактировалось Alekzunder Чт май 20, 2010 08:32, всего редактировалось 3 раз(а).
|