Guten Tag David Haller,
Am Donnerstag, 13. Mai 2004 um 20:46 schrieb David Haller:
Hallo,
jetzt war ja einige Zeit Ruhe, deswegen nochmal kurz, was in der
letzten Folge passierte:
das ppp0 - Device läuft, bekommt dann eine neue IP, startet sich also
selber neu (oder macht irgendwas ähnliches, egal) und läuft weiter
-über Wochen hinweg
manchmal verabschiedete sich das Device aber einfach und ich konnte
leider nicht erkennen, woran das lag. Habe ich dann einfach mal
"rcpppoed start" (restart war nicht nötig, es hatte sich völlig
verabschiedet) ausgeführt, hatte ich binnen Sekunden wieder einen
Internetzugang.
Daraufhin habe ich mich mit der Fehlerbeschreibung an die Liste
gewandt, woraufhin ich dann die Option debug in /etc/ppp/options
anschalten sollte, was ich auch tat. Diese ist nun einige Zeit
mitgelaufen, bis dieser Fehler eben das nächste Mal aufgetreten ist
(das Log findet sich am Ende dieser Mail).
Am Thu, 13 May 2004, Stefan Schilling schrieb:
Am Donnerstag, 13. Mai 2004 um 19:57 schrieb Andreas Koenecke:
* Donnerstag, 13. Mai 2004 um 18:22 (+0200) schrieb Stefan Schilling:
[..]
May 13 05:14:17 debian pppd[17741]: LCP terminated by peer
[ ... ]
May 13 05:14:26 debian pppd[17741]: Remote message: Can't process request now, try again later.
May 13 05:14:26 debian pppd[17741]: PAP authentication failed
[ ... ] u.s.w...
Sieht so aus, als wuerdest du es zu oft, zu schnell hintereinander
versuchen und wirst deshalb geblockt.
das habe ich leider nicht gefunden. Allerdings wurde der u.s.
/var/log/messages - Auszug generiert, nachdem der Rechner grade neu
hochgefahren war, was ja ca. 3min dauert. Auch danach war es mir bis
frühs um 7:30Uhr (danach habe ich den Rechner bis 14:00Uhr
ausgelassen, dann gings) nicht möglich, mich einzuwählen.
Ausserdem haben der AC oder der
Radius (der die Auth uebernimmt) schon auch mal Macken.
Stell am besten ein, dass zwischen den Versuchen ein paar Minuten
Pause gemacht wird.
wo finde ich diese Option? Ich habe in /etc/pppoed.conf und der
/etc/ppp/options nachgeschaut, beide kannten die Option "pause" nicht.
Es sieht so aus, als wenn der AC nicht mehr will. Genaueres kann man
evtl. sagen, wenn du "debug" in "/etc/ppp/options" einfügst und dann nochmal
einen Auszug aus "/var/log/messages" postest.
[..]
ich sag schonmal tschüss, das Log ist doch rel. lang...
Stefan
nachdem nun also ein paar Wochen keine Probleme aufgetreten sind, hier
nun das Log von gestern abend:
Jun 1 23:20:14 debian pppd[2978]: Plugin pppoe.so loaded.
Jun 1 23:20:14 debian pppd[2978]: PPPoE Plugin Initialized
Jun 1 23:20:14 debian pppd[2978]: Plugin passwordfd.so loaded.
Jun 1 23:20:14 debian pppd[2978]: pppd 2.4.0 started by root, uid 0
Jun 1 23:20:14 debian pppd[2978]: Using interface ppp0
Jun 1 23:20:14 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:20:14 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:20:14 debian pppd[2978]: local IP address 192.168.99.1
Jun 1 23:20:14 debian pppd[2978]: remote IP address 192.168.99.99
Jun 1 23:20:14 debian pppd[2978]: Starting link
Jun 1 23:20:14 debian pppd[2978]: Sending PADI
Jun 1 23:20:14 debian modify_resolvconf: Service pppoed modified /etc/resolv.conf. See info block in this file
Jun 1 23:20:14 debian pppd[2978]: HOST_UNIQ successful match
Jun 1 23:20:14 debian pppd[2978]: HOST_UNIQ successful match
Jun 1 23:20:14 debian pppd[2978]: Got connection: a20
Jun 1 23:20:14 debian pppd[2978]: Connecting PPPoE socket: 00:90:1a:40:05:28 200a eth1 0x8084bd0
Jun 1 23:20:14 debian pppd[2978]: using channel 21
Jun 1 23:20:14 debian pppd[2978]: Connect: ppp0 <--> eth1
Jun 1 23:20:14 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:20:14 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:20:14 debian pppd[2978]: sent [LCP ConfReq id=0x1 ]
Jun 1 23:20:14 debian pppd[2978]: rcvd [LCP ConfReq id=0x34 <auth pap> ]
Jun 1 23:20:14 debian pppd[2978]: sent [LCP ConfAck id=0x34 <auth pap> ]
Jun 1 23:20:14 debian pppd[2978]: rcvd [LCP ConfAck id=0x1 ]
Jun 1 23:20:14 debian pppd[2978]: sent [LCP EchoReq id=0x0 magic=0xfd31816e]
Jun 1 23:20:14 debian pppd[2978]: cbcp_lowerup
Jun 1 23:20:14 debian pppd[2978]: want: 2
Jun 1 23:20:14 debian pppd[2978]: sent [PAP AuthReq id=0x1 user="user@tiscali.de" password=<hidden>]
Jun 1 23:20:14 debian pppd[2978]: rcvd [LCP EchoRep id=0x0 magic=0x5a2a44c3]
Jun 1 23:20:16 debian pppd[2978]: rcvd [LCP ConfReq id=0x2 <auth pap> ]
Jun 1 23:20:16 debian pppd[2978]: cbcp_lowerdown
Jun 1 23:20:16 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:20:16 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:20:16 debian pppd[2978]: sent [LCP ConfReq id=0x2 ]
Jun 1 23:20:16 debian pppd[2978]: sent [LCP ConfAck id=0x2 <auth pap> ]
Jun 1 23:20:16 debian pppd[2978]: rcvd [LCP ConfNak id=0x2 ]
Jun 1 23:20:16 debian pppd[2978]: sent [LCP ConfReq id=0x3 ]
Jun 1 23:20:17 debian pppd[2978]: rcvd [LCP ConfAck id=0x3 ]
Jun 1 23:20:17 debian pppd[2978]: sent [LCP EchoReq id=0x0 magic=0xd953c3ab]
Jun 1 23:20:17 debian pppd[2978]: cbcp_lowerup
Jun 1 23:20:17 debian pppd[2978]: want: 2
Jun 1 23:20:17 debian pppd[2978]: sent [PAP AuthReq id=0x2 user="user@tiscali.de" password=<hidden>]
Jun 1 23:20:17 debian pppd[2978]: rcvd [LCP EchoRep id=0x0 magic=0x659b7041]
Jun 1 23:20:17 debian pppd[2978]: rcvd [PAP AuthAck id=0x2 ""]
Jun 1 23:20:17 debian pppd[2978]: sent [IPCP ConfReq id=0x1 ]
Jun 1 23:20:17 debian pppd[2978]: rcvd [LCP TermReq id=0xe5]
Jun 1 23:20:17 debian pppd[2978]: LCP terminated by peer
Jun 1 23:20:17 debian pppd[2978]: cbcp_lowerdown
Jun 1 23:20:17 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:20:17 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:20:17 debian pppd[2978]: sent [LCP TermAck id=0xe5]
Jun 1 23:20:17 debian pppd[2978]: rcvd [LCP TermReq id=0x35]
Jun 1 23:20:17 debian pppd[2978]: sent [LCP TermAck id=0x35]
Jun 1 23:20:19 debian pppd[2978]: Connection terminated.
Jun 1 23:20:19 debian pppd[2978]: Doing disconnect
[... das wiederholt sich jetzt einige Male, bis er dann irgendwann
aufgibt...]
Jun 1 23:21:29 debian pppd[2978]: Starting link
Jun 1 23:21:29 debian pppd[2978]: Sending PADI
Jun 1 23:21:29 debian pppd[2978]: HOST_UNIQ successful match
Jun 1 23:21:29 debian pppd[2978]: HOST_UNIQ successful match
Jun 1 23:21:29 debian pppd[2978]: Got connection: a4e
Jun 1 23:21:29 debian pppd[2978]: Connecting PPPoE socket: 00:90:1a:40:05:28 4e0a eth1 0x8084bd0
Jun 1 23:21:29 debian pppd[2978]: using channel 30
Jun 1 23:21:29 debian pppd[2978]: Connect: ppp0 <--> eth1
Jun 1 23:21:29 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:21:29 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:21:29 debian pppd[2978]: sent [LCP ConfReq id=0x1c ]
Jun 1 23:21:29 debian pppd[2978]: rcvd [LCP ConfReq id=0xf2 <auth pap> ]
Jun 1 23:21:29 debian pppd[2978]: sent [LCP ConfAck id=0xf2 <auth pap> ]
Jun 1 23:21:29 debian pppd[2978]: rcvd [LCP ConfAck id=0x1c ]
Jun 1 23:21:29 debian pppd[2978]: sent [LCP EchoReq id=0x0 magic=0x488503f3]
Jun 1 23:21:29 debian pppd[2978]: cbcp_lowerup
Jun 1 23:21:29 debian pppd[2978]: want: 2
Jun 1 23:21:29 debian pppd[2978]: sent [PAP AuthReq id=0x16
user="user@tiscali.de" password=<hidden>]
Jun 1 23:21:29 debian pppd[2978]: rcvd [LCP EchoRep id=0x0 magic=0x5f902fad]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP ConfReq id=0x2 <auth pap> ]
Jun 1 23:21:32 debian pppd[2978]: cbcp_lowerdown
Jun 1 23:21:32 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:21:32 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:21:32 debian pppd[2978]: sent [LCP ConfReq id=0x1d ]
Jun 1 23:21:32 debian pppd[2978]: sent [LCP ConfAck id=0x2 <auth pap> ]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP ConfNak id=0x1d ]
Jun 1 23:21:32 debian pppd[2978]: sent [LCP ConfReq id=0x1e ]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP ConfAck id=0x1e ]
Jun 1 23:21:32 debian pppd[2978]: sent [LCP EchoReq id=0x0 magic=0x5dcaebe4]
Jun 1 23:21:32 debian pppd[2978]: cbcp_lowerup
Jun 1 23:21:32 debian pppd[2978]: want: 2
Jun 1 23:21:32 debian pppd[2978]: sent [PAP AuthReq id=0x17
user="user@tiscali.de" password=<hidden>]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP EchoRep id=0x0 magic=0x2a526b6]
Jun 1 23:21:32 debian pppd[2978]: rcvd [PAP AuthAck id=0x17 ""]
Jun 1 23:21:32 debian pppd[2978]: sent [IPCP ConfReq id=0xa ]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP TermReq id=0xd6]
Jun 1 23:21:32 debian pppd[2978]: LCP terminated by peer
Jun 1 23:21:32 debian pppd[2978]: cbcp_lowerdown
Jun 1 23:21:32 debian pppd[2978]: Couldn't increase MTU to 1500
Jun 1 23:21:32 debian pppd[2978]: Couldn't increase MRU to 1500
Jun 1 23:21:32 debian pppd[2978]: sent [LCP TermAck id=0xd6]
Jun 1 23:21:32 debian pppd[2978]: rcvd [LCP TermReq id=0xf3]
Jun 1 23:21:32 debian pppd[2978]: sent [LCP TermAck id=0xf3]
Jun 1 23:21:34 debian pppd[2978]: Connection terminated.
Jun 1 23:21:34 debian pppd[2978]: Doing disconnect
Jun 1 23:21:34 debian pppd[2978]: Exit.
