[Samba] Regression of 5616?

[Robert LeBlanc]

On Wed, Jun 2, 2010 at 5:04 PM, Robert LeBlanc <robert at leblancnet.us> wrote:

> I'm wondering if I'm seeing a regression of 5616 with 3.4.8. I'm trying to
> set-up pptpd with winbind, which I'm doing on two machines on Debian lenny,
> and I'm trying on Debian Squeeze now. The Windows client is saying "Error
> 778: It was not possible to verify the identity of the server." The logs say
> that everything is ok, and that the client is hanging up the connection. Is
> something not getting passed correctly like in bug 5616?
>
> Jun  2 16:56:05 debian pppd[17472]: pppd 2.4.4 started by root, uid 0
> Jun  2 16:56:05 debian pppd[17472]: using channel 17
> Jun  2 16:56:05 debian pppd[17472]: Using interface ppp0
> Jun  2 16:56:05 debian pppd[17472]: Connect: ppp0 <--> /dev/pts/2
> Jun  2 16:56:05 debian pppd[17472]: sent [LCP ConfReq id=0x1 <asyncmap 0x0>
> <auth chap MS-v2> <magic 0xa2912b7> <pcomp> <accomp>]
> Jun  2 16:56:05 debian pptpd[17470]: GRE: Bad checksum from pppd.
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP ConfReq id=0x0 <mru 1400>
> <magic 0x648b71fd> <pcomp> <accomp> <callback CBCP>]
> Jun  2 16:56:05 debian pppd[17472]: sent [LCP ConfRej id=0x0 <callback
> CBCP>]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0>
> <auth chap MS-v2> <magic 0xa2912b7> <pcomp> <accomp>]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP ConfReq id=0x1 <mru 1400>
> <magic 0x648b71fd> <pcomp> <accomp>]
> Jun  2 16:56:05 debian pppd[17472]: sent [LCP ConfAck id=0x1 <mru 1400>
> <magic 0x648b71fd> <pcomp> <accomp>]
> Jun  2 16:56:05 debian pppd[17472]: sent [LCP EchoReq id=0x0
> magic=0xa2912b7]
> Jun  2 16:56:05 debian pppd[17472]: sent [CHAP Challenge id=0x75
> <d33a4de16233bb406c42b02c9801acd4>, name = "debian"]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP Ident id=0x2 magic=0x648b71fd
> "MSRASV5.10"]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP Ident id=0x3 magic=0x648b71fd
> "MSRAS-0-WINCOMP"]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP EchoRep id=0x0
> magic=0x648b71fd]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [CHAP Response id=0x75
> <69dbcaab0e152ea056654a46c4ca7bae00000000000000006d7bcc32ef97cfafde7c34570aaa0c55e83b8475da22923300>,
> name = "DOMAIN\\user"]
> Jun  2 16:56:05 debian pptpd[17470]: CTRL: Ignored a SET LINK INFO packet
> with real ACCMs!
> Jun  2 16:56:05 debian pppd[17472]: sent [CHAP Success id=0x75
> "S=B68D646C4DC626290C5BCD1148AE833C004B1E70 M=Access granted"]
> Jun  2 16:56:05 debian pppd[17472]: sent [CCP ConfReq id=0x1 <mppe +H -M +S
> -L -D -C>]
> Jun  2 16:56:05 debian pppd[17472]: rcvd [LCP TermReq id=0x4
> "d\37777777613q\37777777775\000<\37777777715t\000\000\003\n"]
> Jun  2 16:56:05 debian pppd[17472]: LCP terminated by peer
> (dM-^KqM-}^@<M-Mt^@^@^C^J)
> Jun  2 16:56:05 debian pppd[17472]: sent [LCP TermAck id=0x4]
> Jun  2 16:56:05 debian pptpd[17470]: CTRL: Reaping child PPP[17472]
> Jun  2 16:56:05 debian pppd[17472]: Modem hangup
> Jun  2 16:56:05 debian pppd[17472]: Connection terminated.
> Jun  2 16:56:05 debian pppd[17472]: Connect time 0.0 minutes.
> Jun  2 16:56:05 debian pppd[17472]: Sent 10 bytes, received 0 bytes.
> Jun  2 16:56:06 debian pppd[17472]: Exit.
>
> Any ideas? I'm not sure what else to try, I'm coming up empty handed with
> Google.
>
>
I forgot to try this using chap_secrets and include that. When using
chap_secrets I can log in and everything works as expected. When I include
the winbind.so plug-in, I can't login. Here is the logs from a sucessful
PPTP connection using chap_secrets.

Jun  3 11:10:35 debian pppd[17826]: Connect: ppp0 <--> /dev/pts/1
Jun  3 11:10:35 debian pppd[17826]: sent [LCP ConfReq id=0x1 <asyncmap 0x0>
<auth chap MS-v2> <magic 0x122bc19f> <pcomp> <accomp>]
Jun  3 11:10:35 debian pptpd[17825]: GRE: Bad checksum from pppd.
Jun  3 11:10:35 debian pppd[17826]: rcvd [LCP ConfReq id=0x0 <mru 1400>
<magic 0x1f614592> <pcomp> <accomp> <callback CBCP>]
Jun  3 11:10:35 debian pppd[17826]: sent [LCP ConfRej id=0x0 <callback
CBCP>]
Jun  3 11:10:35 debian pppd[17826]: rcvd [LCP ConfReq id=0x1 <mru 1400>
<magic 0x1f614592> <pcomp> <accomp>]
Jun  3 11:10:35 debian pppd[17826]: sent [LCP ConfAck id=0x1 <mru 1400>
<magic 0x1f614592> <pcomp> <accomp>]
Jun  3 11:10:38 debian pppd[17826]: sent [LCP ConfReq id=0x1 <asyncmap 0x0>
<auth chap MS-v2> <magic 0x122bc19f> <pcomp> <accomp>]
Jun  3 11:10:38 debian pptpd[17825]: CTRL: Ignored a SET LINK INFO packet
with real ACCMs!
Jun  3 11:10:38 debian pppd[17826]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0>
<auth chap MS-v2> <magic 0x122bc19f> <pcomp> <accomp>]
Jun  3 11:10:38 debian pppd[17826]: sent [LCP EchoReq id=0x0
magic=0x122bc19f]
Jun  3 11:10:38 debian pppd[17826]: sent [CHAP Challenge id=0xb6
<ee0fbc4ca5a3cecbb50d6a5d681dfceb>, name = "debian"]
Jun  3 11:10:38 debian pppd[17826]: rcvd [LCP Ident id=0x2 magic=0x1f614592
"MSRASV5.10"]
Jun  3 11:10:38 debian pppd[17826]: rcvd [LCP Ident id=0x3 magic=0x1f614592
"MSRAS-0-WINCOMP"]
Jun  3 11:10:38 debian pppd[17826]: rcvd [LCP EchoRep id=0x0
magic=0x1f614592]
Jun  3 11:10:38 debian pppd[17826]: rcvd [CHAP Response id=0xb6
<4d9f569d005db37bc1a3fd0475dd288f0000000000000000f7a35e82608b4ba7e6137ef1dbd642f03341be46e2c763bf00>,
name = "chap_user"]
Jun  3 11:10:38 debian pppd[17826]: sent [CHAP Success id=0xb6
"S=5BB1A4A6F2B0B1915352569321C0E90C7F2D0A50 M=Access granted"]
Jun  3 11:10:38 debian pppd[17826]: sent [CCP ConfReq id=0x1 <mppe +H -M +S
-L -D -C>]
Jun  3 11:10:38 debian pppd[17826]: rcvd [CCP ConfReq id=0x4 <mppe +H +M +S
+L -D +C>]
Jun  3 11:10:38 debian pppd[17826]: sent [CCP ConfNak id=0x4 <mppe +H -M +S
-L -D -C>]
Jun  3 11:10:38 debian pppd[17826]: rcvd [IPCP ConfReq id=0x5 <addr 0.0.0.0>
<ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Jun  3 11:10:38 debian pppd[17826]: sent [IPCP TermAck id=0x5]
Jun  3 11:10:38 debian pppd[17826]: rcvd [CCP ConfAck id=0x1 <mppe +H -M +S
-L -D -C>]
Jun  3 11:10:38 debian pppd[17826]: rcvd [CCP ConfReq id=0x6 <mppe +H -M +S
-L -D -C>]
Jun  3 11:10:38 debian pppd[17826]: sent [CCP ConfAck id=0x6 <mppe +H -M +S
-L -D -C>]
Jun  3 11:10:38 debian pppd[17826]: MPPE 128-bit stateless compression
enabled
Jun  3 11:10:38 debian pppd[17826]: sent [IPCP ConfReq id=0x1 <compress VJ
0f 01> <addr 192.168.54.1>]
Jun  3 11:10:38 debian pppd[17826]: rcvd [IPCP ConfRej id=0x1 <compress VJ
0f 01>]
Jun  3 11:10:38 debian pppd[17826]: sent [IPCP ConfReq id=0x2 <addr
192.168.54.1>]
Jun  3 11:10:38 debian pppd[17826]: rcvd [IPCP ConfAck id=0x2 <addr
192.168.54.1>]
Jun  3 11:10:40 debian pppd[17826]: rcvd [IPCP ConfReq id=0x7 <addr 0.0.0.0>
<ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Jun  3 11:10:40 debian pppd[17826]: sent [IPCP ConfRej id=0x7 <ms-dns1
0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Jun  3 11:10:40 debian pppd[17826]: rcvd [IPCP ConfReq id=0x8 <addr
0.0.0.0>]
Jun  3 11:10:40 debian pppd[17826]: sent [IPCP ConfNak id=0x8 <addr
192.168.54.181>]
Jun  3 11:10:40 debian pppd[17826]: rcvd [IPCP ConfReq id=0x9 <addr
192.168.54.181>]
Jun  3 11:10:40 debian pppd[17826]: sent [IPCP ConfAck id=0x9 <addr
192.168.54.181>]
Jun  3 11:10:40 debian pppd[17826]: found interface eth0.69 for proxy arp
Jun  3 11:10:40 debian pppd[17826]: local  IP address 192.168.54.1
Jun  3 11:10:40 debian pppd[17826]: remote IP address 192.168.54.181
Jun  3 11:10:40 debian pppd[17826]: pptpd-logwtmp.so ip-up ppp0 chap_user
x.x.x.x
Jun  3 11:10:40 debian pppd[17826]: Script /etc/ppp/ip-up started (pid
17829)
Jun  3 11:10:40 debian pppd[17826]: Script /etc/ppp/ip-up finished (pid
17829), status = 0x0

I did a tcpdump of the failing PPTP session and I could not find any useful
information, I can send that to a dev if needed.

Thanks,

Robert LeBlanc
Life Sciences & Undergraduate Education Computer Support
Brigham Young University