PPPoE Server problem.All of the tunnels go down by 3 min

oxigeno20 · July 6, 2010, 6:43pm

Hello everybody!
my pppoe customers are kicked out for my RouterOS X86
my plataform is: AMD x4 2Gb RAM SATA Disk
ROS 3.30

The pppoe Server, Kickout of the tunnels PPPoE by 2 or 3 minutes.. and then all clientes are logged in again.
I have 2 ethernet configured like PPPoE Server.
The first One is for the wireless clientes, and the other for the wired LAN. Each One of this ethernets cards are connected with an separated Switch.

I have changed the CPU, Motherboard, HD (new licence, level 4)
The only thing i preserved are ethernet cards. are TP-Link 10/100/1000.

In the attached file you can see the chart or count of simultaneous tunnels and the hour when go
down.

This is the log file for the last kicked out tunnels.

",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <magic 0x20beddb7>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0411>: sent LCP EchoReq id=0x24"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <magic 0x26e13158>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <023d>: LCP timer"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <023d>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-bichi101214>: terminating..."""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe: eoip_ospf_linkgua: sent PADT to 00:0E:2E:EE:C2:69"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     session-id=0x3d02"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     relay-session-id=81 86 00 0e 2e a8 81 43"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <023d>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <023d>: LCP down event in starting state"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-bichi101214>: disconnected"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0427>: rcvd LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1400>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0xe1e9a942>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0427>: sent LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1480>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0x6dd470bb>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <auth pap>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0277>: rcvd IPCP ConfAck id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <addr 192.168.110.1>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0201>: rcvd LCP EchoRep id=0x16"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <magic 0xd64b8304>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042c>: rcvd LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1412>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0xc79556d9>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042c>: sent LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1480>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0x2b2a2304>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <0420>: rcvd LCP ConfAck id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1480>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0x3121bc17>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <auth pap>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0420>: LCP opened"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042d>: rcvd LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1492>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0x1e491b98>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042d>: sent LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1480>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042b>: rcvd LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1412>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0xfdf95f66>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042b>: sent LCP ConfReq id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1480>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0x1e66ae2d>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <auth pap>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <042b>: sent LCP ConfAck id=0x1"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <mru 1412>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:    <magic 0xfdf95f66>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <02ce>: rcvd LCP EchoReq id=0x0"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <magic 0x1ef0b300>"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:  <02ce>: sent LCP EchoRep id=0x0"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug,packet pppoe:     <magic 0x6d69cbe7>"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe: eoip_ospf_linkgua: rcvd PADT from 00:15:6D:D8:98:25"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     session-id=0x7802"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     host-uniq=0x6c050000"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     [b]generic-error=RP-PPPoE: System call error: Bad file descriptor"""[/b]
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     relay-session-id=00 0e 2e f2 a0 31 00 00 00 00 00 00"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0278>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0278>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0278>: LCP down event in starting state"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-8>: disconnected"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe: local: rcvd PADR from 08:10:74:6B:91:69"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     session-id=0x0000"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     service-name="""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     host-uniq=0xf2030000"""
",13:37:52,192.168.110.1,""pppoe,info pppoe: PPPoE connection established from 08:10:74:6B:91:69"""
",13:37:52,192.168.110.1,""pppoe,info pppoe: PPPoE connection from 08:10:74:6B:91:69 was already active - closing previous one"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0374>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-gramburger101151>: terminating... - disconnected"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0374>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <0374>: LCP down event in starting state"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-gramburger101151>: disconnected"""
",13:37:52,192.168.110.1,""pppoe,ppp,info pppoe: <pppoe-8>: waiting for call..."""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <042f>: LCP lowerup"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <042f>: LCP open"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe: local: sent PADS to 08:10:74:6B:91:69"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     session-id=0x2f04"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     host-uniq=0xf2030000"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     service-name="""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe: local: rcvd PADR from 00:1F:16:45:7C:2C"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     session-id=0x0000"""
",13:37:52,192.168.110.1,""pppoe,debug,packet pppoe:     service-name="""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <02c2>: LCP lowerdown"""
",13:37:52,192.168.110.1,""pppoe,ppp,debug pppoe: <02c2>: LCP down event in starting state"""

best regards
Nicolas

sorry for my bad english.

normis · July 7, 2010, 9:07am

The log shows only part of the reason, please make a supout.rif file when more logs are gathered, and send that to support.

oxigeno20 · July 7, 2010, 1:13pm

i have made the downgrade to ROS 2.28 and fixed the problem.

thank you!!

oxigeno20 · July 8, 2010, 12:54am

Sorry, i re post!
the problem is again!.
I’m now in ROS 3.28

i have some news.
My PPPoE server make 300 tunnels simultaneously
In any moment of the day, between 40 to 50 tunnels (most of them routers) are disconnected. This shut take 3.. 4 minutes.. and then all of these clientes are logged in again.

i sended the support.rif to suppor
Thank you.

fuzzz · November 11, 2010, 7:50am

I have the same problem.
Is there a solution for this problem?