Remote Access error 778

Hi

I have pptpd running on Debian. The authentication is done by using winbind to our Active Directory. The server has been working perfectly for years until recently.

I upgraded to the newest stable release by running apt-get dist-upgrade and broke a number of things – vpn being one.

Versions:

Samba: 3.2.5

pptpd: 1.3.4

pppd: 2.2.4

kernel: 2.6.24

Windows Vista clients get the following error when making the vpn connection:  Remote Access error 778 - It was not possible to verify the identity of the server.

I’ve enabled tracing on the client and the only thing I see is the following from svchost_RASCHAP.LOG:

######################################################

[4320] 07-29 15:57:22:608: GetChallengeResponse=0

02 CB 00 40 31 07 C4 9D E0 E2 C6 F6 A4 EE 2B 9A |...@1.........+.|

10 B7 51 E5 D5 00 00 00 00 00 00 00 00 1A 48 D3 |..Q...........H.|

9C B1 C5 98 79 BC 21 8C BD B8 69 C9 32 81 B8 A0 |....y.!...i.2...|

01 94 4D 18 70 00 47 45 4E 44 41 43 5C 70 76 6C |..M.p.MYDOMAIN\pvl|

[4320] 07-29 15:57:22:639: ChapMakeMessage,RBuf=00000000053C68C2

[4320] 07-29 15:57:22:639: ChapCMakeMessage...

[4320] 07-29 15:57:22:639: CS_ResponseSent

[4320] 07-29 15:57:22:639: Message received...

03 CB 00 3F 53 3D 37 41 32 44 34 45 31 37 33 45 |...?S=7A2D4E173E|

45 43 30 32 38 37 42 39 33 30 35 34 46 35 38 44 |EC0287B93054F58D|

45 34 41 37 39 37 30 41 44 38 42 36 42 35 20 4D |E4A7970AD8B6B5 M|

3D 41 63 63 65 73 73 20 67 72 61 6E 74 65 64 00 |=Access granted.|

[4320] 07-29 15:57:22:639: CHAP: Signature received...

7A 2D 4E 17 3E EC 02 87 B9 30 54 F5 8D E4 A7 97 |z-N.>....0T.....|

0A D8 B6 B5 00 00 00 00 00 00 00 00 00 00 00 00 |................|

[4320] 07-29 15:57:22:639: CHAP: Signature should be...

2F 14 14 C1 24 DE 18 45 E4 CC 38 10 C1 F5 3B DC |/...$..E..8...;.|

37 AA CC 19 00 00 00 00 00 00 00 00 00 00 00 00 |7...............|

[4320] 07-29 15:57:22:642: ChapEnd

###################################################

I cannot find any info regarding the CHAP signature. I have spent hours looking for the problem, but nothing seems to work. I have checked my samba/winbind config and everything seems fine. I am able to log into the machine via ssh using domain users, so it doesn’t seem to be an authentication issue. The logs also seem to indicate that the authentication is OK. I looks like the identification of the server is failing, but I’m not sure why. What is the server identification based on?

What should I do to solve this problem?

Thanks

Pierre-Andre

The server log:

Jul 29 16:39:36 localhost pptpd[29614]: MGR: Launching /usr/sbin/pptpctrl to handle client

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: local address = 192.168.114.1

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: remote address = 192.168.114.2

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: pppd options file = /etc/ppp/pptpd-options

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 1)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Made a START CTRL CONN RPLY packet

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: I wrote 156 bytes to the client.

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Sent packet to client

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 7)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Set parameters to 100000000 maxbps, 64 window size

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Made a OUT CALL RPLY packet

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: pty_fd = 6

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: tty_fd = 7

Jul 29 16:39:36 localhost pptpd[29615]: CTRL (PPPD Launcher): program binary = /usr/sbin/pppd

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: I wrote 32 bytes to the client.

Jul 29 16:39:36 localhost pptpd[29615]: CTRL (PPPD Launcher): local address = 192.168.114.1

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Sent packet to client

Jul 29 16:39:36 localhost pptpd[29615]: CTRL (PPPD Launcher): remote address = 192.168.114.2

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 15)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Got a SET LINK INFO packet with standard ACCMs

Jul 29 16:39:36 localhost pppd[29615]: using channel 128

Jul 29 16:39:36 localhost pppd[29615]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0xa19a2469> <pcomp> <accomp>]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #0

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP ConfReq id=0x0 <mru 1400> <magic 0x1eda4fa3> <pcomp> <accomp> <callback CBCP>]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #1

Jul 29 16:39:36 localhost pppd[29615]: sent [LCP ConfRej id=0x0 <callback CBCP>]

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0xa19a2469> <pcomp> <accomp>]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #2

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP ConfReq id=0x1 <mru 1400> <magic 0x1eda4fa3> <pcomp> <accomp>]

Jul 29 16:39:36 localhost pppd[29615]: sent [LCP ConfAck id=0x1 <mru 1400> <magic 0x1eda4fa3> <pcomp> <accomp>]

Jul 29 16:39:36 localhost pppd[29615]: sent [LCP EchoReq id=0x0 magic=0xa19a2469]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #3

Jul 29 16:39:36 localhost pppd[29615]: sent [CHAP Challenge id=0x33 <26fa1a32bc57975f16545a1baf2ac7cb>, name = "vpn.mydomain.com"]

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 15)

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP Ident id=0x2 magic=0x1eda4fa3 "MSRASV5.20"]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #4

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP Ident id=0x3 magic=0x1eda4fa3 "MSRAS-0-KATANA"]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #5

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP Ident id=0x4 magic=0x1eda4fa3 "\37777777751\37777777672\37777777766Z\021\37777777736\003A\37777777676\37777777700\0258n\37777777614\37777777704\37777777703"]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #6

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP EchoRep id=0x0 magic=0x1eda4fa3]

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #7

Jul 29 16:39:36 localhost pppd[29615]: rcvd [CHAP Response id=0x33 <ff4e74edc397c7ed2ba721bc1f8e54b20000000000000000c1473a3beb3fc44a1267931edb1ab1bccd3bfc0fae790a3200>, name = "MYDOMAIN\\pvl"]

Jul 29 16:39:36 localhost pppd[29615]: sent [CHAP Success id=0x33 "S=F837F1CB020BC4EC734301CF5EB9C2409EFB41E8 M=Access granted"]

Jul 29 16:39:36 localhost pppd[29615]: sent [CCP ConfReq id=0x1 <mppe +H -M +S -L -D -C>]

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 15)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Got a SET LINK INFO packet with standard ACCMs

Jul 29 16:39:36 localhost pptpd[29614]: GRE: accepting packet #8

Jul 29 16:39:36 localhost pppd[29615]: rcvd [LCP TermReq id=0x5 1e da 4f a3 00 3c cd 74 00 00 03 0a]

Jul 29 16:39:36 localhost pppd[29615]: sent [LCP TermAck id=0x5]

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received PPTP Control Message (type: 12)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Made a CALL DISCONNECT RPLY packet

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Received CALL CLR request (closing call)

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Reaping child PPP[29615]

Jul 29 16:39:36 localhost pptpd[29614]: CTRL: Exiting now

Jul 29 16:39:36 localhost pptpd[28123]: MGR: Reaped child 29614