No subject


Sun Jul 8 18:14:56 CDT 2012


Traceroute from host to client looks like this:
>traceroute to cj369830-a.reston1.va.home.com (24.18.171.224), 30 hops max, 38 byte packets
> 1  router (209.183.239.1)  0.852 ms  0.847 ms  0.815 ms
> 2  25.e0b7d1.client.atlantech.net (209.183.224.37)  1373.663 ms  1824.948 ms  1697.663 ms
> 3  main1-249-121.iad.above.net (209.249.121.4)  1252.968 ms *  2415.199 ms
> 4  core3-main1-oc12.iad.above.net (209.249.203.57)  2306.019 ms  1641.936 ms  1917.992 ms
> 5  athome-above-oc3.iad.above.net (209.249.203.82)  1891.989 ms  1672.884 ms  1596.815 ms
> 6  bb1-pos2-0.pg1.md.home.net (24.7.72.58)  2051.103 ms  1566.377 ms  1788.442 ms
> 7  ubr1.reston1.va.home.net (24.5.80.31)  1687.607 ms  1447.874 ms  1264.169 ms
> 8  cj369830-a.reston1.va.home.com (24.18.171.224)  1229.936 ms  1004.121 ms *

Can anyone suggest troubleshooting procedures to localize the dropping of
GRE packets, if that's what it is? AFAIK, the router firewall is set up
only to "block outgoing NetBIOS", which I presume is only outgoing packets
on Ports 137 and 138 and should not affect 1723/GRE. Please feel free to
try to get a password-failed login on the server (a strong password is set
up).

-----------
/etc/pptpd.conf:
>debug
>localip 10.0.0.80-89
>remoteip 10.0.0.70-79

I've also tried
>localip 	192.168.1.80-89		
>remoteip 192.168.1.70-79    
with the same local success and external failure.

/etc/ppp/chap-secrets:
>chris   mail.ezmort.com XXXXXX        *

/etc/ppp/options:
>lock
>debug
>name mail.ezmort.com
>auth
>+chap
>+chapms
>+chapms-v2
>mppe-40
>mppe-128
>mppe-stateless
># require-chap
>proxyarp


Logs from Error 650 session follow.

Win98B client pptplog.txt:
>05-18-2000 21:53:51.59 - Microsoft Dial Up Adapter log opened.
>05-18-2000 21:53:51.59 - Server type is  PPP (Point to Point Protocol).
>05-18-2000 21:53:51.59 - FSA : Software compression disabled.
>05-18-2000 21:53:51.59 - FSA : Protocol disabled by user - skipping control protocol 803f (NBFCP).
>05-18-2000 21:53:51.59 - FSA : Adding Control Protocol 8021 (IPCP) to control protocol chain.
>05-18-2000 21:53:51.59 - FSA : Protocol not bound - skipping control protocol 802b (IPXCP).
>05-18-2000 21:53:51.59 - FSA : Adding Control Protocol c029 (CallbackCP) to control protocol chain.
>05-18-2000 21:53:51.59 - FSA : Encrypted Password required.
>05-18-2000 21:53:51.59 - FSA : Encrypted Password required.
>05-18-2000 21:53:51.59 - FSA : Adding Control Protocol c223 (CHAP) to control protocol chain.
>05-18-2000 21:53:51.59 - FSA : Adding Control Protocol c021 (LCP) to control protocol chain.
>05-18-2000 21:53:51.59 - LCP : Layer started.
>05-18-2000 21:53:51.59 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:53:51.59 - Data 0000: c0 21 01 01 00 0e 05 06 | .!......
>05-18-2000 21:53:51.59 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:53:54.59 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:53:54.59 - Data 0000: c0 21 01 02 00 0e 05 06 | .!......
>05-18-2000 21:53:54.59 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:53:57.59 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:53:57.59 - Data 0000: c0 21 01 03 00 0e 05 06 | .!......
>05-18-2000 21:53:57.59 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:00.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:00.60 - Data 0000: c0 21 01 04 00 0e 05 06 | .!......
>05-18-2000 21:54:00.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:03.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:03.60 - Data 0000: c0 21 01 05 00 0e 05 06 | .!......
>05-18-2000 21:54:03.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:06.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:06.60 - Data 0000: c0 21 01 06 00 0e 05 06 | .!......
>05-18-2000 21:54:06.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:09.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:09.60 - Data 0000: c0 21 01 07 00 0e 05 06 | .!......
>05-18-2000 21:54:09.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:12.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:12.60 - Data 0000: c0 21 01 08 00 0e 05 06 | .!......
>05-18-2000 21:54:12.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:15.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:15.60 - Data 0000: c0 21 01 09 00 0e 05 06 | .!......
>05-18-2000 21:54:15.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:18.60 - PPP : Transmitting Control Packet of length: 16
>05-18-2000 21:54:18.60 - Data 0000: c0 21 01 0a 00 0e 05 06 | .!......
>05-18-2000 21:54:18.60 - Data 0008: 15 95 4b 57 07 02 08 02 | .KW....
>05-18-2000 21:54:21.60 - LCP : Layer finished.
>05-18-2000 21:54:21.61 - Remote access driver is shutting down.
>05-18-2000 21:54:21.61 - CRC Errors             0
>05-18-2000 21:54:21.61 - Timeout Errors         0
>05-18-2000 21:54:21.61 - Alignment Errors       0
>05-18-2000 21:54:21.61 - Overrun Errors         0
>05-18-2000 21:54:21.61 - Framing Errors         0
>05-18-2000 21:54:21.61 - Buffer Overrun Errors  0
>05-18-2000 21:54:21.61 - Incomplete Packets     0
>05-18-2000 21:54:21.61 - Bytes Received         0
>05-18-2000 21:54:21.61 - Bytes Transmittted     180
>05-18-2000 21:54:21.61 - Frames Received        0
>05-18-2000 21:54:21.61 - Frames Transmitted     10
>05-18-2000 21:54:21.61 - LCP : Layer started.
>05-18-2000 21:54:21.61 - Microsoft Dial Up Adapter log closed.

/var/log/messages:
>May 18 21:53:17 linux syslogd 1.3-3: restart.
>May 18 21:53:41 linux dhcpd: DHCPACK on 10.0.0.202 to 00:40:05:41:5a:3d via eth0
>May 18 21:53:54 linux pptpd[2574]: CTRL: Client 24.18.171.224 control connection started
>May 18 21:53:54 linux pptpd[2574]: CTRL: Starting call (launching pppd, opening GRE)
>May 18 21:53:55 linux pppd[2575]: pppd 2.3.10 started by root, uid 0
>May 18 21:53:55 linux pppd[2575]: Using interface ppp0
>May 18 21:53:55 linux pppd[2575]: Connect: ppp0 <--> /dev/pts/1
>May 18 21:54:25 linux pptpd[2574]: CTRL: Error with select(), quitting
>May 18 21:54:25 linux pptpd[2574]: CTRL: Client 24.18.171.224 control connection finished
>May 18 21:54:25 linux pppd[2575]: Modem hangup
>May 18 21:54:25 linux pppd[2575]: Connection terminated.
>May 18 21:54:25 linux pppd[2575]: Exit.

/var/log/pptpd.log:
>May 18 21:53:54 linux pptpd[2574]: CTRL: local address = 192.168.1.81
>May 18 21:53:54 linux pptpd[2574]: CTRL: remote address = 192.168.1.71
>May 18 21:53:54 linux pptpd[2574]: CTRL: Client 24.18.171.224 control connection started
>May 18 21:53:54 linux pptpd[2574]: CTRL: Received PPTP Control Message (type: 1)
>May 18 21:53:54 linux pptpd[2574]: CTRL: Made a START CTRL CONN RPLY packet
>May 18 21:53:54 linux pptpd[2574]: CTRL: I wrote 156 bytes to the client.
>May 18 21:53:54 linux pptpd[2574]: CTRL: Sent packet to client
>May 18 21:53:54 linux pptpd[2574]: CTRL: Received PPTP Control Message (type: 7)
>May 18 21:53:54 linux pptpd[2574]: CTRL: Set parameters to 0 maxbps, 16 window size
>May 18 21:53:54 linux pptpd[2574]: CTRL: Made a OUT CALL RPLY packet
>May 18 21:53:54 linux pptpd[2574]: CTRL: Starting call (launching pppd, opening GRE)
>May 18 21:53:54 linux pptpd[2574]: CTRL: pty_fd = 4
>May 18 21:53:54 linux pptpd[2574]: CTRL: tty_fd = 5
>May 18 21:53:54 linux pptpd[2574]: CTRL: I wrote 32 bytes to the client.
>May 18 21:53:54 linux pptpd[2574]: CTRL: Sent packet to client
>May 18 21:53:54 linux pptpd[2575]: CTRL (PPPD Launcher): Connection speed = 115200
>May 18 21:53:54 linux pptpd[2575]: CTRL (PPPD Launcher): local address = 192.168.1.81
>May 18 21:53:54 linux pptpd[2575]: CTRL (PPPD Launcher): remote address = 192.168.1.71
>May 18 21:54:25 linux pptpd[2574]: CTRL: Received PPTP Control Message (type: 12)
>May 18 21:54:25 linux pptpd[2574]: CTRL: Made a CALL DISCONNECT RPLY packet
>May 18 21:54:25 linux pptpd[2574]: CTRL: Received CALL CLR request (closing call)
>May 18 21:54:25 linux pptpd[2574]: CTRL: I wrote 148 bytes to the client.
>May 18 21:54:25 linux pptpd[2574]: CTRL: Sent packet to client
>May 18 21:54:25 linux pptpd[2574]: CTRL: Error with select(), quitting
>May 18 21:54:25 linux pptpd[2574]: CTRL: Client 24.18.171.224 control connection finished
>May 18 21:54:25 linux pptpd[2574]: CTRL: Exiting now

/var/log/pptpd.log if I telnet to mail.ezmort.com:1723; drops after any two
chars sent:
>May 18 22:05:54 linux pptpd[2628]: MGR: Launching /usr/sbin/pptpctrl to handle client
>May 18 22:05:54 linux pptpd[2628]: CTRL: local address = 10.0.0.81
>May 18 22:05:54 linux pptpd[2628]: CTRL: remote address = 10.0.0.71
>May 18 22:05:54 linux pptpd[2628]: CTRL: Client 24.18.171.224 control connection started
>May 18 22:05:57 linux pptpd[2628]: CTRL: Incomplete ctrl packet length, retry later
>May 18 22:05:57 linux pptpd[2628]: CTRL: PPTP Control Message type -1073742884 not supported.
>May 18 22:05:59 linux pptpd[2628]: CTRL: Read in previous incomplete ctrl packet
>May 18 22:05:59 linux pptpd[2628]: CTRL: Control packet > PPTP_MAX_CTRL_PCKT_SIZE (length = 27243)
>May 18 22:05:59 linux pptpd[2628]: CTRL: couldn't read packet header (exit)
>May 18 22:05:59 linux pptpd[2628]: CTRL: CTRL read failed
>May 18 22:05:59 linux pptpd[2628]: CTRL: Client 24.18.171.224 control connection finished
>May 18 22:05:59 linux pptpd[2628]: CTRL: Exiting now
>May 18 22:05:59 linux pptpd[2615]: MGR: Reaped child 2628




More information about the pptp-server mailing list