[pptp-server] Strange problem ...

[Marek Butas]

Hi,

I have one problem. Yesterday one of the home users experienced
strange behavior. First he got on server and was there for about 30
minutes. No problems, authentification OK.
Then he diconnected himself and tried to connect again. And then he
could not get inside! He tried ti several times, but no luck. In the
morning I looked in the logs and found that he connected himself for
those 30 minutes, but also that he could not get in afterwords.

Here is a part of the log. In the FAQ, they say, that this is problem
on the firewall (iptables), but I checked, it is still the same (no
reboots, no restarting) and in the logs I can see that pptp packets
went through it. I'm logging GRE packets, establishing new connection

Oct 16 22:46:15 indus pptpd[13832]: MGR: Launching /usr/sbin/pptpctrl
to handle client
Oct 16 22:46:15 indus pptpd[13832]: CTRL: local address = 10.0.1.2
Oct 16 22:46:15 indus pptpd[13832]: CTRL: remote address = 10.0.1.21
Oct 16 22:46:15 indus pptpd[13832]: CTRL: Client 10.0.1.1 control
connection started
Oct 16 22:46:15 indus pptpd[13832]: CTRL: Received PPTP Control
Message (type: 1)
Oct 16 22:46:15 indus pptpd[13832]: CTRL: Made a START CTRL CONN RPLY
packet
Oct 16 22:46:15 indus pptpd[13832]: CTRL: I wrote 156 bytes to the
client.
Oct 16 22:46:15 indus pptpd[13832]: CTRL: Sent packet to client
Oct 16 22:46:16 indus pptpd[13832]: CTRL: Received PPTP Control
Message (type: 7)
Oct 16 22:46:16 indus pptpd[13832]: CTRL: Set parameters to 1525
maxbps, 64 window size
Oct 16 22:46:16 indus pptpd[13832]: CTRL: Made a OUT CALL RPLY packet
Oct 16 22:46:16 indus pptpd[13832]: CTRL: Starting call (launching
pppd, opening GRE)
Oct 16 22:46:16 indus pptpd[13832]: CTRL: pty_fd = 4
Oct 16 22:46:16 indus pptpd[13832]: CTRL: tty_fd = 5
Oct 16 22:46:16 indus pptpd[13833]: CTRL (PPPD Launcher): Connection
speed = 115200
Oct 16 22:46:16 indus pptpd[13833]: CTRL (PPPD Launcher): local
address = 10.0.1.2
Oct 16 22:46:16 indus pptpd[13833]: CTRL (PPPD Launcher): remote
address = 10.0.1.21
Oct 16 22:46:16 indus pptpd[13832]: CTRL: I wrote 32 bytes to the
client.
Oct 16 22:46:16 indus pptpd[13832]: CTRL: Sent packet to client
Oct 16 22:46:16 indus pppd[13833]: pppd 2.4.0 started by root, uid 0
Oct 16 22:46:16 indus pppd[13833]: using channel 5
Oct 16 22:46:16 indus pppd[13833]: Using interface ppp0
Oct 16 22:46:16 indus pppd[13833]: Connect: ppp0 <--> /dev/pts/1
Oct 16 22:46:16 indus pppd[13833]: sent [LCP ConfReq id=0x1 <asyncmap
0x0> <auth chap 81> <magic 0x63353e5c> <pcomp> <accomp>]
Oct 16 22:46:43 indus last message repeated 9 times
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Received PPTP Control
Message (type: 12)
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Made a CALL DISCONNECT RPLY
packet
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Received CALL CLR request
(closing call)
Oct 16 22:46:46 indus pptpd[13832]: CTRL: I wrote 148 bytes to the
client.
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Sent packet to client
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Error with select(),
quitting
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Client 10.0.1.1 control
connection finished
Oct 16 22:46:46 indus pptpd[13832]: CTRL: Exiting now
Oct 16 22:46:46 indus pptpd[692]: MGR: Reaped child 13832
Oct 16 22:46:46 indus pppd[13833]: Modem hangup
client.

Regards
MArek Butas

______________________________________________________________________
Nejenom anglicko-cesky slovnik: http://slovnik.seznam.cz