PPTP Patch

Dear Astaro Users,

first of all I want to apologize for the long waiting time but this error
was a  tough one and it took us a longer to solve the problem.

Don't worry this won't become the standard way to publish patches [;)]
but the PPTP error became such a substantial problem that we think it might
be useful to publish it before the next schedulded up2date will be released.

Note, this is not an official release!

README
http://www.n-zsolt.de/downloads/readme_pptp_patch.txt

PATCH
http://www.n-zsolt.de/downloads/pptp_patch.tar.gz

Your feedback about its functionality is really appreciated.

read you
o|iver
    
Parents
  • Hi,

    This may seem like a silly question but what issue does this address?

    I've a couple of PPTP isses. For example, a pptp client at home (win2000) cannot connect to an Astaro pptp server when trying to connect through a NATing ADSL router - but is OK when dialing up to the internet via modem . The odd thing is that the ADSL router has passthru and the same Win2000 box can connect to an NT RRAS/PPTP server thru the same ADSL router.  
  • For further info, the errors I'm getting are, on the client
    619: The specified port is not connected

    and in the ASL log (4.010)

    Aug 28 14:49:37 (none) pptpd[6253]: MGR: Launching /usr/local/sbin/pptpctrl to handle client
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: local address = 10.146.5.1
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: remote address = 10.146.5.2
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: pppd options file = /etc/ppp/options
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Client 195.153.124.200 control connection started
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Received PPTP Control Message (type: 1)
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Made a START CTRL CONN RPLY packet
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: I wrote 156 bytes to the client.
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Sent packet to client
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Received PPTP Control Message (type: 7)
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Set parameters to 1525 maxbps, 64 window size
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Made a OUT CALL RPLY packet
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Starting call (launching pppd, opening GRE)
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: pty_fd = 5
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: tty_fd = 6
    Aug 28 14:49:37 (none) pptpd[6254]: CTRL (PPPD Launcher): Connection speed = 115200
    Aug 28 14:49:37 (none) pptpd[6254]: CTRL (PPPD Launcher): local address = 10.146.5.1
    Aug 28 14:49:37 (none) pptpd[6254]: CTRL (PPPD Launcher): remote address = 10.146.5.2
    Aug 28 14:49:37 (none) pppd[6254]: pppd 2.4.2b1 started by (unknown), uid 0
    Aug 28 14:49:37 (none) pppd[6254]: using channel 7
    Aug 28 14:49:37 (none) pppd[6254]: Starting negotiation on /dev/ttyp0
    Aug 28 14:49:37 (none) pppd[6254]: sent [LCP ConfReq id=0x1        ]
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: I wrote 32 bytes to the client.
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Sent packet to client
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Received PPTP Control Message (type: 15)
    Aug 28 14:49:37 (none) pptpd[6253]: CTRL: Got a SET LINK INFO packet with standard ACCMs
    Aug 28 14:49:40 (none) pppd[6254]: sent [LCP ConfReq id=0x1        ]
    Aug 28 14:50:07 (none) pptpd[6253]: GRE: read(fd=5,buffer=804dbe0,len=8196) from PTY failed: status = -1 error = Input/output error
    Aug 28 14:50:07 (none) pptpd[6253]: CTRL: PTY read or GRE write failed (pty,gre)=(5,6)
    Aug 28 14:50:07 (none) pptpd[6253]: CTRL: Closing child ppp with pid 6254
    Aug 28 14:50:07 (none) pptpd[6253]: CTRL: Client 195.153.124.200 control connection finished
    Aug 28 14:50:07 (none) pptpd[6253]: CTRL: Exiting now
    Aug 28 14:50:07 (none) pptpd[6021]: MGR: Reaped child 6253
    Aug 28 14:50:07 (none) pppd[6254]: LCP: timeout sending Config-Requests 
    Aug 28 14:50:07 (none) pppd[6254]: Connection terminated.
    Aug 28 14:50:07 (none) pppd[6254]: Exit. 
  • Thanks, out of interest, what was the issue? 
  • Hi norwich,

    the patch solves a problem which occurrs exactly in the way that you describe it: Error 619 ("The specified port is not connected") on the Windows Client, and the entry "GRE: read(...) from PTY failed: status = -1 error = Input/output error" on ASL. However, there can be several reasons for this error to occurr, including misconfigurations (what's in common: in all cases the GRE return packets don't reach the PPP daemon). The exact reason can only be located when extensive logging is enabled.

    Stephan
        
  • Another quick question - I've downloaded the patch onto a workstation but what's the best method to get in onto the astaro box? 
  • Hi norwich,

    the best way is to use secure copy (scp or Winscp). You need to enable ssh access on your ASL for it.

    Stephan
        
  • No luck - still failing. It's still failing on a connection from a laptop dialed into the Internet using a regular modem ISP. The full pptp logs are:

    Aug 29 10:47:56 (none) pptpd[30075]: MGR: Launching /usr/local/sbin/pptpctrl to handle client
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: local address = 10.146.5.1
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: remote address = 10.146.5.3
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: pppd options file = /etc/ppp/options
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: Client 81.174.194.169 control connection started
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: Received PPTP Control Message (type: 1)
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: Made a START CTRL CONN RPLY packet
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: I wrote 156 bytes to the client.
    Aug 29 10:47:56 (none) pptpd[30075]: CTRL: Sent packet to client
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Received PPTP Control Message (type: 7)
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Set parameters to 1525 maxbps, 64 window size
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Made a OUT CALL RPLY packet
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Starting call (launching pppd, opening GRE)
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: pty_fd = 5
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: tty_fd = 6
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: I wrote 32 bytes to the client.
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Sent packet to client
    Aug 29 10:47:57 (none) pptpd[30087]: CTRL (PPPD Launcher): Connection speed = 115200
    Aug 29 10:47:57 (none) pptpd[30087]: CTRL (PPPD Launcher): local address = 10.146.5.1
    Aug 29 10:47:57 (none) pptpd[30087]: CTRL (PPPD Launcher): remote address = 10.146.5.3
    Aug 29 10:47:57 (none) pppd[30087]: pppd 2.4.2b1 started by (unknown), uid 0
    Aug 29 10:47:57 (none) pppd[30087]: using channel 13
    Aug 29 10:47:57 (none) pppd[30087]: Starting negotiation on /dev/ttyp0
    Aug 29 10:47:57 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Received PPTP Control Message (type: 15)
    Aug 29 10:47:57 (none) pptpd[30075]: CTRL: Got a SET LINK INFO packet with standard ACCMs
    Aug 29 10:47:57 (none) pptpd[30075]: GRE: Discarding duplicate packet
    Aug 29 10:47:59 (none) pppd[30087]: rcvd [LCP ConfReq id=0x1      ]
    Aug 29 10:47:59 (none) pppd[30087]: sent [LCP ConfRej id=0x1 ]
    Aug 29 10:48:00 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:02 (none) pppd[30087]: rcvd [LCP ConfReq id=0x2      ]
    Aug 29 10:48:02 (none) pppd[30087]: sent [LCP ConfRej id=0x2 ]
    Aug 29 10:48:03 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:06 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:06 (none) pppd[30087]: rcvd [LCP ConfReq id=0x3      ]
    Aug 29 10:48:06 (none) pppd[30087]: sent [LCP ConfRej id=0x3 ]
    Aug 29 10:48:09 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:10 (none) pppd[30087]: rcvd [LCP ConfReq id=0x4      ]
    Aug 29 10:48:10 (none) pppd[30087]: sent [LCP ConfRej id=0x4 ]
    Aug 29 10:48:12 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:14 (none) pppd[30087]: rcvd [LCP ConfReq id=0x5      ]
    Aug 29 10:48:14 (none) pppd[30087]: sent [LCP ConfRej id=0x5 ]
    Aug 29 10:48:15 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:18 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:18 (none) pppd[30087]: rcvd [LCP ConfReq id=0x6      ]
    Aug 29 10:48:18 (none) pppd[30087]: sent [LCP ConfRej id=0x6 ]
    Aug 29 10:48:21 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:22 (none) pppd[30087]: rcvd [LCP ConfReq id=0x7      ]
    Aug 29 10:48:22 (none) pppd[30087]: sent [LCP ConfRej id=0x7 ]
    Aug 29 10:48:24 (none) pppd[30087]: sent [LCP ConfReq id=0x1        ]
    Aug 29 10:48:26 (none) pppd[30087]: rcvd [LCP ConfReq id=0x8      ]
    Aug 29 10:48:26 (none) pppd[30087]: sent [LCP ConfRej id=0x8 ]
    Aug 29 10:48:27 (none) pptpd[29677]: MGR: Reaped child 30075
    Aug 29 10:48:27 (none) pptpd[30075]: GRE: read(fd=5,buffer=804dbe0,len=8196) from PTY failed: status = -1 error = Input/output error
    Aug 29 10:48:27 (none) pptpd[30075]: CTRL: PTY read or GRE write failed (pty,gre)=(5,6)
    Aug 29 10:48:27 (none) pptpd[30075]: CTRL: Closing child ppp with pid 30087
    Aug 29 10:48:27 (none) pptpd[30075]: CTRL: Client 81.174.194.169 control connection finished
    Aug 29 10:48:27 (none) pptpd[30075]: CTRL: Exiting now
    Aug 29 10:48:27 (none) pppd[30087]: LCP: timeout sending Config-Requests 
    Aug 29 10:48:27 (none) pppd[30087]: Connection terminated.
    Aug 29 10:48:27 (none) pppd[30087]: Exit.  
  • Hi norwich,

    your client is requesting callback, and the ASL rejects it. Disable the callback feature on your Windows machine (client), and everything should work fine.

    Stephan
       
  • Thanks, Odd though... I didn't think you could request a callback with the standard windows pptp network connection - and he shouldn't have had permission to change the settings.

    I'll check out what he's done. 
  • Strange - I cannot find anywhere in Windows2000 where you request callback. I know it's off-topic but does anybody know where this is set. Thanks. 
  • norwich,

    actually Windows 2000 should fall back to non-callback automatically. Strange that it behaves this way. The setting for callback in Windows 2000 can be
    found at the following location:

    - Start menu ->Select "Settings"
    - Open the "Network and dial-up connections" window
    - Select "Advanced" in the title bar menu
    - Select "Dial-up preferences"
    - Select "Callback"

    It could also be that the GRE packets from the server to the client don't make
    it through. Can you check whether the packets can be seen on the network ?

    Hope this helps,
    Stephan
      
  • Hi,

    Still getting the same problem - I'll try and see if I can detect if the GRE packets are coming back - though nothing else had changed when this started failing.

    What would be the best way to determine if the patching had worked  correctly? 
Reply Children
  • Hi.

    I have a problem. 
    My asl hangs up several times a day.

    Here is the log:
    2003-Sep 20 16:54:14 (none) pppd[577]: pppd 2.4.1 started by root, uid 0
    2003-Sep 20 16:54:14 (none) pppd[577]: Using interface ppp0
    2003-Sep 20 16:54:14 (none) pppd[577]: Connect: ppp0  /dev/ttyp0
    2003-Sep 20 16:54:15 (none) pppd[577]: local  IP address XXX.XXX.XXX.XXX
    2003-Sep 20 16:54:15 (none) pppd[577]: remote IP address XXX.X.XX.X
    2003-Sep 20 17:21:26 (none) pppd[577]: Modem hangup
    2003-Sep 20 17:21:26 (none) pppd[577]: Connection terminated.
    2003-Sep 20 17:21:26 (none) pppd[577]: Connect time 27.2 minutes.
    2003-Sep 20 17:21:26 (none) pppd[577]: Sent 17567204 bytes, received 76041771 bytes.
    2003-Sep 20 17:21:26 (none) pppd[577]: Exit.
    2003-Sep 20 17:36:46 (none) pppd[14825]: pppd 2.4.1 started by root, uid 0
    2003-Sep 20 17:36:46 (none) pppd[14825]: Using interface ppp0
    2003-Sep 20 17:36:46 (none) pppd[14825]: Connect: ppp0  /dev/ttyp0
    2003-Sep 20 17:36:47 (none) pppd[14825]: local  IP address XXX.XXX.XXX.XXX
    2003-Sep 20 17:36:47 (none) pppd[14825]: remote IP address XXX.X.XX.X
    2003-Sep 20 17:41:38 (none) pppd[14825]: Modem hangup
    2003-Sep 20 17:41:38 (none) pppd[14825]: Connection terminated.
    2003-Sep 20 17:41:38 (none) pppd[14825]: Connect time 4.9 minutes.
    2003-Sep 20 17:41:38 (none) pppd[14825]: Sent 1672521 bytes, received 2488700 bytes.
    2003-Sep 20 17:41:38 (none) pppd[14825]: Exit.
    2003-Sep 20 17:56:58 (none) pppd[20594]: pppd 2.4.1 started by root, uid 0
    2003-Sep 20 17:56:58 (none) pppd[20594]: Using interface ppp0
    2003-Sep 20 17:56:58 (none) pppd[20594]: Connect: ppp0  /dev/ttyp0
    2003-Sep 20 17:56:59 (none) pppd[20594]: local  IP address XXX.XXX.XXX.XXX
    2003-Sep 20 17:56:59 (none) pppd[20594]: remote IP address XXX.X.XX.X
    2003-Sep 20 20:29:52 (none) pppd[20594]: Modem hangup
    2003-Sep 20 20:29:52 (none) pppd[20594]: Connection terminated.
    2003-Sep 20 20:29:52 (none) pppd[20594]: Connect time 152.9 minutes.
    2003-Sep 20 20:29:52 (none) pppd[20594]: Sent 105306766 bytes, received 427988992 bytes.
    2003-Sep 20 20:29:52 (none) pppd[20594]: Exit.

    I don´t know why. Does the Patch solve my problem?
    I´m running asl 4.015 on a Duron 1,3.
    Currently there is only one client(WinXP Pro).
    I´ve changed the reconnect (in /var/chroot-ppoe/bin/DSL.sh) to 120seconds but asl needs 15minutes to reconnect...

    Tobi  
  • Hi norwich,

    Enter the following command (via terminal or ssh access):
    md5sum /lib/modules/2.4/kernel/net/ipv4/netfilter/iptable_nat.o

    It gives the MD5 sum of the module. Expected result for the patched version is:

    cd3605f757b13062bd2f753056d27f41

    If you get this result, then your system is patched OK.
    You may need to reboot the system though, if you experienced "module busy" errors while installing the patch.

    Regards,
    Stephan