Topic: SME 7 PPTP sessions not completing

[Ness]

I have a problem which is similar to others posted on this forum.

See also http://forums.contribs.org/index.php?topic=33474.0


I'm still having built a fresh SME 7 server trying to remote access it from an XP Client on my SME 6.0.1 system.

Initially the VPN session stopped at XP's "Verifying username and password" messagebox. After the timeout, I get an XP Error 721

A day later, all was well with no changes to settings.

If I'm looking at th eright log file entries, it shows this for the successful connection:

Code: [Select]



Sep  4 13:06:05 jaws pptpd[9763]: CTRL: Client [MY.WAN.IP.ADD] control connection started
Sep  4 13:06:05 jaws pptpd[9763]: CTRL: Starting call (launching pppd, opening GRE)
Sep  4 13:06:05 jaws pppd[9764]: Plugin radius.so loaded.
Sep  4 13:06:05 jaws pppd[9764]: RADIUS plugin initialized.
Sep  4 13:06:05 jaws pppd[9764]: pppd 2.4.3 started by root, uid 0
Sep  4 13:06:05 jaws kernel: divert: not allocating divert_blk for non-ethernet device ppp0
Sep  4 13:06:05 jaws pppd[9764]: Using interface ppp0
Sep  4 13:06:05 jaws pppd[9764]: Connect: ppp0 <--> /dev/pts/0
Sep  4 13:06:05 jaws pptpd[9763]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
Sep  4 13:06:05 jaws pppd[9764]: MPPE 128-bit stateless compression enabled
Sep  4 13:06:07 jaws pppd[9764]: found interface eth0 for proxy arp
Sep  4 13:06:07 jaws pppd[9764]: local  IP address 192.168.0.1
Sep  4 13:06:07 jaws pppd[9764]: remote IP address 192.168.0.95
Sep  4 13:06:07 jaws esmith::event[9788]: Processing event: ip-up.pptpd ppp0 /dev/pts/0 460800 192.168.0.1 192.168.0.95 pptpd
Sep  4 13:06:07 jaws esmith::event[9788]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Sep  4 13:06:07 jaws esmith::event[9788]: expanding /etc/rc.d/init.d/masq  
Sep  4 13:06:07 jaws esmith::event[9788]: generic_template_expand=action|Event|ip-up.pptpd|Action|generic_template_expand|Start|1157371567 472620|End|1157371567 869071|Elapsed|0.396451
Sep  4 13:06:07 jaws esmith::event[9788]: Running event handler: /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access
Sep  4 13:06:08 jaws /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access[9791]: /home/e-smith/db/configuration: OLD pptpd=service|Interfaces||TCPPort|1723|access|public|sessions|5|status|enabled
Sep  4 13:06:08 jaws /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access[9791]: /home/e-smith/db/configuration: NEW pptpd=service|Interfaces|ppp0|TCPPort|1723|access|public|sessions|5|status|enabled
Sep  4 13:06:08 jaws esmith::event[9788]: S70pptp-interface-access=action|Event|ip-up.pptpd|Action|S70pptp-interface-access|Start|1157371567 869395|End|1157371568 25250|Elapsed|0.155855
Sep  4 13:06:08 jaws esmith::event[9788]: Running event handler: /etc/e-smith/events/actions/adjust-services
Sep  4 13:06:08 jaws esmith::event[9788]: adjusting non-supervised masq (adjust)  
Sep  4 13:06:08 jaws esmith::event[9788]: adjust-services=action|Event|ip-up.pptpd|Action|adjust-services|Start|1157371568 25616|End|1157371568 663181|Elapsed|0.637565
Sep  4 13:07:11 jaws pppd[9764]: LCP terminated by peer (\M-|jz^@<M-Mt^@^@^@^@)
Sep  4 13:07:11 jaws pppd[9764]: Connect time 1.1 minutes.
Sep  4 13:07:11 jaws pppd[9764]: Sent 1450 bytes, received 8179 bytes.
Sep  4 13:07:11 jaws pptpd[9763]: CTRL: Reaping child PPP[9764]
Sep  4 13:07:11 jaws pppd[9764]: Modem hangup
Sep  4 13:07:11 jaws pppd[9764]: Connection terminated.

 

Five days on and its (still) back to the same XP message box, again after the timeout, I get an XP Error 721

Looking at the var/logs/messages at the time of the failure I see the following

Code: [Select]



Sep  5 08:41:38 jaws pptpd[3673]: MGR: No free connection slots or IPs - no more clients can connect!
Sep  5 08:41:38 jaws pptpd[4601]: CTRL: Client [MY.WAN.IP.ADD] control connection started
Sep  5 08:41:38 jaws pptpd[4601]: CTRL: Starting call (launching pppd, opening GRE)
Sep  5 08:41:38 jaws pppd[4602]: Plugin radius.so loaded.
Sep  5 08:41:38 jaws pppd[4602]: RADIUS plugin initialized.
Sep  5 08:41:38 jaws pppd[4602]: pppd 2.4.3 started by root, uid 0
Sep  5 08:41:38 jaws kernel: divert: not allocating divert_blk for non-ethernet device ppp0
Sep  5 08:41:38 jaws pppd[4602]: Using interface ppp0
Sep  5 08:41:38 jaws pppd[4602]: Connect: ppp0 <--> /dev/pts/0
Sep  5 08:42:08 jaws pppd[4602]: LCP: timeout sending Config-Requests
Sep  5 08:42:15 jaws pppd[4602]: Modem hangup
Sep  5 08:42:15 jaws pptpd[4601]: CTRL: Reaping child PPP[4602]
Sep  5 08:42:15 jaws pppd[4602]: Failed to open /dev/pts/0: No such file or directory
Sep  5 08:42:15 jaws pppd[4602]: tcflush failed: Bad file descriptor
Sep  5 08:42:15 jaws kernel: divert: no divert_blk to free, ppp0 not ethernet
Sep  5 08:42:15 jaws pppd[4602]: Exit.
Sep  5 08:42:15 jaws pptpd[4601]: CTRL: Client [MY.WAN.IP.ADD] control connection finished



I changed the number of clients to 2 and retried:

Code: [Select]


Sep  5 08:52:42 jaws pptpd[5030]: CTRL: Client [MY.WAN.IP.ADD] control connection started
Sep  5 08:52:42 jaws pptpd[5030]: CTRL: Starting call (launching pppd, opening GRE)
Sep  5 08:52:42 jaws pppd[5031]: Plugin radius.so loaded.
Sep  5 08:52:42 jaws pppd[5031]: RADIUS plugin initialized.
Sep  5 08:52:42 jaws pppd[5031]: pppd 2.4.3 started by root, uid 0
Sep  5 08:52:42 jaws kernel: divert: not allocating divert_blk for non-ethernet device ppp0
Sep  5 08:52:42 jaws pppd[5031]: Using interface ppp0
Sep  5 08:52:42 jaws pppd[5031]: Connect: ppp0 <--> /dev/pts/0
Sep  5 08:53:12 jaws pppd[5031]: LCP: timeout sending Config-Requests
Sep  5 08:53:20 jaws pppd[5031]: Modem hangup
Sep  5 08:53:20 jaws pptpd[5030]: CTRL: Reaping child PPP[5031]
Sep  5 08:53:20 jaws pppd[5031]: Failed to open /dev/pts/0: No such file or directory
Sep  5 08:53:20 jaws pppd[5031]: tcflush failed: Bad file descriptor
Sep  5 08:53:20 jaws kernel: divert: no divert_blk to free, ppp0 not ethernet
Sep  5 08:53:20 jaws pppd[5031]: Exit.
Sep  5 08:53:20 jaws pptpd[5030]: CTRL: Client [MY.WAN.IP.ADD] control connection finished



The only change to the server since install is the addition of AWSTATS.

Can anyone shed light on this.

I'm worried about the error messages about "Bad File Descriptor", but don't know what relevance this has.

Chris

[jonic]

I am having the exact same problem.
When I look at the error logs I get the "Failed to open /dev/pts/1" type of error.
Sometimes it works, sometimes it doesn't. From what I've seen these errors pop up if I have already a vpn connection established (and sometimes even if no connection is established). The number of vpn connections is set in server-manager to 6 - but I can't get more than one connection to work concurrently.

Did you manage to solve your problem, Ness?

[Ness]

Did I solve it, no.

Does it work when it 'feels like it'? Yes. I expect I get a connection about 50% of the time.

I haven't changed anything here, no new server configs, no changes to PC settings..

Puzzling.

Chris

[jonic]

I am not accessing the server through another SME box. If there is already a vpn connection established I get the "Failed to open /dev/pts/1: No such file or directory" error. Is anybody else experiencing this?

[raem]

Run
iptstate
to review the status of connections

[jonic]

I have run iptstate. It shows there is one vpn connection (my own). If I try to make another vpn connection, it fails and it also disconnects the previous one. This is what I get in the logs :

Code: [Select]


Oct 17 12:09:18 server pptpd[15512]: CTRL: Starting call (launching pppd, opening GRE)
Oct 17 12:09:18 server pppd[15513]: Plugin radius.so loaded.
Oct 17 12:09:18 server pppd[15513]: RADIUS plugin initialized.
Oct 17 12:09:18 server pppd[15513]: pppd 2.4.3 started by root, uid 0
Oct 17 12:09:18 server kernel: divert: not allocating divert_blk for non-ethernet device ppp0
Oct 17 12:09:18 server pppd[15513]: Using interface ppp0
Oct 17 12:09:18 server pppd[15513]: Connect: ppp0 <--> /dev/pts/0
Oct 17 12:09:21 server pptpd[15512]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
Oct 17 12:09:21 server pppd[15513]: MPPE 128-bit stateless compression enabled
Oct 17 12:09:23 server pppd[15513]: found interface eth0 for proxy arp
Oct 17 12:09:23 server pppd[15513]: local  IP address 192.168.161.1
Oct 17 12:09:23 server pppd[15513]: remote IP address 192.168.161.93
Oct 17 12:09:24 server esmith::event[15537]: Processing event: ip-up.pptpd ppp0 /dev/pts/0 460800 192.168.161.1 192.168.161.93 pptpd
Oct 17 12:09:24 server esmith::event[15537]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Oct 17 12:09:24 server esmith::event[15537]: expanding /etc/rc.d/init.d/masq  
Oct 17 12:09:24 server esmith::event[15537]: generic_template_expand=action|Event|ip-up.pptpd|Action|generic_template_expand|Start|1161076164 82131|End|1161076164 750299|Elapsed|0.668168
Oct 17 12:09:24 server esmith::event[15537]: Running event handler: /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access
Oct 17 12:09:24 server /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access[15539]: /home/e-smith/db/configuration: OLD pptpd=service|Interfaces||TCPPort|1723|access|public|sessions|7|status|enabled
Oct 17 12:09:24 server /etc/e-smith/events/ip-up.pptpd/S70pptp-interface-access[15539]: /home/e-smith/db/configuration: NEW pptpd=service|Interfaces|ppp0|TCPPort|1723|access|public|sessions|7|status|enabled
Oct 17 12:09:25 server esmith::event[15537]: S70pptp-interface-access=action|Event|ip-up.pptpd|Action|S70pptp-interface-access|Start|1161076164 751483|End|1161076165 7146|Elapsed|0.255663
Oct 17 12:09:25 server esmith::event[15537]: Running event handler: /etc/e-smith/events/actions/adjust-services
Oct 17 12:09:25 server esmith::event[15537]: adjusting non-supervised masq (adjust)  
Oct 17 12:09:26 server esmith::event[15537]: adjust-services=action|Event|ip-up.pptpd|Action|adjust-services|Start|1161076165 8404|End|1161076166 344646|Elapsed|1.336242
Oct 17 12:09:34 server pptpd[15693]: CTRL: Client 82.76.129.135 control connection started
Oct 17 12:09:34 server pptpd[15693]: CTRL: Starting call (launching pppd, opening GRE)
Oct 17 12:09:34 server pppd[15694]: Plugin radius.so loaded.
Oct 17 12:09:34 server pppd[15694]: RADIUS plugin initialized.
Oct 17 12:09:34 server pppd[15694]: pppd 2.4.3 started by root, uid 0
Oct 17 12:09:34 server kernel: divert: not allocating divert_blk for non-ethernet device ppp1
Oct 17 12:09:34 server pppd[15694]: Using interface ppp1
Oct 17 12:09:34 server pppd[15694]: Connect: ppp1 <--> /dev/pts/1
Oct 17 12:09:34 server pppd[15513]: Connect time 0.2 minutes.
Oct 17 12:09:34 server pppd[15513]: Sent 0 bytes, received 6302 bytes.
Oct 17 12:09:34 server pppd[15513]: MPPE disabled
Oct 17 12:09:34 server pptpd[15512]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
Oct 17 12:09:34 server esmith::event[15716]: Processing event: ip-down ppp0 /dev/pts/0 460800 192.168.161.1 192.168.161.93 pptpd
Oct 17 12:09:34 server esmith::event[15716]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Oct 17 12:09:34 server esmith::event[15716]: expanding /etc/rc.d/init.d/masq  
Oct 17 12:09:35 server esmith::event[15716]: generic_template_expand=action|Event|ip-down|Action|generic_template_expand|Start|1161076174 720068|End|1161076175 381121|Elapsed|0.661053
Oct 17 12:09:35 server esmith::event[15716]: Running event handler: /etc/e-smith/events/ip-down/S50isdn-down-notify
Oct 17 12:09:35 server esmith::event[15716]: S50isdn-down-notify=action|Event|ip-down|Action|S50isdn-down-notify|Start|1161076175 382309|End|1161076175 578705|Elapsed|0.196396
Oct 17 12:09:35 server esmith::event[15716]: Running event handler: /etc/e-smith/events/ip-down/S70pptp-interface-access
Oct 17 12:09:35 server /etc/e-smith/events/ip-down/S70pptp-interface-access[15719]: /home/e-smith/db/configuration: OLD pptpd=service|Interfaces|ppp0|TCPPort|1723|access|public|sessions|7|status|enabled
Oct 17 12:09:35 server /etc/e-smith/events/ip-down/S70pptp-interface-access[15719]: /home/e-smith/db/configuration: NEW pptpd=service|Interfaces||TCPPort|1723|access|public|sessions|7|status|enabled
Oct 17 12:09:35 server esmith::event[15716]: S70pptp-interface-access=action|Event|ip-down|Action|S70pptp-interface-access|Start|1161076175 580029|End|1161076175 834633|Elapsed|0.254604
Oct 17 12:09:35 server esmith::event[15716]: Running event handler: /etc/e-smith/events/actions/adjust-services
Oct 17 12:09:36 server esmith::event[15716]: adjusting non-supervised masq (adjust)  
Oct 17 12:09:36 server pptpd[15512]: CTRL: Reaping child PPP[15513]
Oct 17 12:09:36 server pppd[15513]: Modem hangup
Oct 17 12:09:36 server pppd[15513]: Connection terminated.
Oct 17 12:09:36 server pppd[15513]: Connect time 0.3 minutes.
Oct 17 12:09:36 server pppd[15513]: Sent 10 bytes, received 6704 bytes.
Oct 17 12:09:36 server kernel: divert: no divert_blk to free, ppp0 not ethernet
Oct 17 12:09:37 server esmith::event[15716]: adjust-services=action|Event|ip-down|Action|adjust-services|Start|1161076175 835908|End|1161076177 279937|Elapsed|1.444029
Oct 17 12:09:37 server pppd[15513]: Exit.
Oct 17 12:09:37 server pptpd[15512]: CTRL: Client 82.76.129.135 control connection finished


This happened when the two machines, I was trying to connect where on the same local network. I tried also with two machines directly connected to the internet, and the second machine could not connect, but the first one wasn't disconnected.

Any ideas?

[jonic]

I' ve tested this on another SME server and it has the same problem. Maybe it's some contrib that's causing this. I have the same contribs on both servers:
- awstats
- e-smith-lazy_admin_tools
- smeserver-loginscript
- smeserver-remoteuseraccess
- smeserver-sarg
- smeserver-userpanel
- smeserver-userpanels
- smeserver-vacation

Anyway I resolved all my problems by installing openvpn, following the excellent guide from sme.firewall-services.com.

[raem]

jonic

> Maybe it's some contrib that's causing this.

Not sure if this is your scenario, and I also think what I'm saying here is correct.
sme server only supports one VPN connection from the same remote host.
You can have multiple VPN connections from different remote sites/hosts.

If so, that's probably why OpenVPN works for your situation.

[jonic]

I've guessed that multiple connections from the same ip were problematic, but I had problems connecting even from different ips at the same time, and sometimes it didn't work at all (meaning couldn't get even one connection). The problem seemed to be related to the ip. If I tried to connect from a new ip, I couldn't, but after a time it worked. The problem was I had to connect from a laptop that was getting a different ip every time, and I just couldn't get it to work, so I had to install openvpn, and all my problems were solved .

[brianr]

I also am having sporadic problems connecting to a number of SMEservers remotely - both SME7 and also SME6 (although it "seems" to happen more frequently with the SME7 ones). I normally connect through an SME7, but occasionally it happens from my laptop connected directly (through a router) to the internet.  On the other hand often I cannot connect through the SMEServer, but can connect directly. Strange?

I also already knew that you could not connect to the same server more than once from the same IP address, so that is NOT the problem (does OpenVPN solve this problem?).

I think one of the originators of this thread should open a bug report (and copy this thread in).

[raem]

brianr

> I also am having sporadic problems connecting to a number of
> SMEservers remotely - both SME7 and also SME6 (although it "seems" > to happen more frequently with the SME7 ones).

Have you taken the right steps to ensure the required ports/protocols are forwarded in your router(s), search on VPN for details.

If you are having problems with sme7 VPN then why not open a bug report.

[jonic]

I also already knew that you could not connect to the same server more than once from the same IP address, so that is NOT the problem (does OpenVPN solve this problem?).

Yes, it does.

[brianr]

brianr

> I also am having sporadic problems connecting to a number of
> SMEservers remotely - both SME7 and also SME6 (although it "seems" > to happen more frequently with the SME7 ones).

Have you taken the right steps to ensure the required ports/protocols are forwarded in your router(s), search on VPN for details.

yes, 'cos it works sometimes and not others.

As this is not my thread and others have done more investigation, I thought it would be more sensible if one of them logged the bug.  However if no-one steps up to the crease in a day or two I will.

[raem]

brianr

> yes, 'cos it works sometimes and not others.

Is that an asumption that the routers must be set correctly because VPN works sometimes, or did you actually forward the correct ports & protocols required (TCP 1723 & protocol 47). Some routers need firmware updates to work reliably with VPN.

http://forums.contribs.org/index.php?topic=26830.msg109906#msg109906

[brianr]

brianr

> yes, 'cos it works sometimes and not others.

Is that an asumption that the routers must be set correctly because VPN works sometimes, or did you actually forward the correct ports & protocols required (TCP 1723 & protocol 47). Some routers need firmware updates to work reliably with VPN.

http://forums.contribs.org/index.php?topic=26830.msg109906#msg109906

Yes, everything is fine, I have around 12 of these servers out in the field, and most of them are using the same router, which I have lots of experience configuring, and when they where all on SME6, the VPN was solid.