poptop - received RADIUS server response with invalid length

[Ben Thompson]

Hi

We are running a poptop vpn server which authenticates via radiusclient
and freeradius. Some people have reported problems logging in
so I decided to investigate. Here is a log from the vpn server :-

Nov 14 11:26:12 nassrv3 pppd[15621]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0xa7836037> <pcomp> <accomp>]
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0xa7836037> <pcomp> <accomp>]
Nov 14 11:26:12 nassrv3 pppd[15621]: sent [LCP EchoReq id=0x0 magic=0xa7836037]
Nov 14 11:26:12 nassrv3 pppd[15621]: sent [CHAP Challenge id=0x9 <f426157bf1a8cd0fbc8d2276a48e731a>, name = "pptpd"]
Nov 14 11:26:12 nassrv3 pptpd[15620]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [LCP Ident id=0x2 magic=0x76cf2fdd "MSRASV5.10"]
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [LCP Ident id=0x3 magic=0x76cf2fdd "MSRAS-0-ANNA"]
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [LCP EchoRep id=0x0 magic=0x76cf2fdd]
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [CHAP Response id=0x9 <4166d4713ef8cec048e88644889a7fbc0000000000000000adcaef9a0709f7576bad0ce28f82ed7e5fb6e8c193a192bb00>, name = "ozw1"]
Nov 14 11:26:12 nassrv3 pppd[15621]: rc_check_reply: received RADIUS server response with invalid length
Nov 14 11:26:12 nassrv3 pppd[15621]: rc_avpair_gen: received attribute with invalid length
Nov 14 11:26:12 nassrv3 pppd[15621]: Peer ozw1 failed CHAP authentication
Nov 14 11:26:12 nassrv3 pppd[15621]: sent [CHAP Failure id=0x9 ""]
Nov 14 11:26:12 nassrv3 pppd[15621]: sent [LCP TermReq id=0x2 "Authentication failed"]
Nov 14 11:26:12 nassrv3 pppd[15621]: rcvd [LCP TermAck id=0x2 "Authentication failed"]
Nov 14 11:26:12 nassrv3 pppd[15621]: Connection terminated.
Nov 14 11:26:12 nassrv3 pppd[15621]: Exit.
Nov 14 11:26:12 nassrv3 pptpd[15620]: GRE: read(fd=6,buffer=5109c0,len=8196) from PTY failed: status = -1 error = Input/output error, usually caused by unexpected termination of pppd, check option syntax and pppd logs
Nov 14 11:26:12 nassrv3 pptpd[15620]: CTRL: PTY read or GRE write failed (pty,gre)=(6,7)
Nov 14 11:26:12 nassrv3 pptpd[15620]: CTRL: Reaping child PPP[15621]
Nov 14 11:26:12 nassrv3 pptpd[15620]: CTRL: Client 81.132.112.97 control connection finished


Here is the relevent part of radius.log :-

Wed Nov 14 11:26:12 2007 : Auth: Login OK: [ozw1] (from client vpnvirtualip port 0 cli 1.18)


Here is a packet capture showing the radius conversation :-

11:26:12.567346 IP vpn.york.ac.uk.33286 > nasaaa2.york.ac.uk.radius: RADIUS, Access Request (1), id: 0xc1 length: 140
11:26:12.568107 IP nasaaa2.york.ac.uk.radius > vpn.york.ac.uk.33286: RADIUS, Access Accept (2), id: 0xc1 length: 179
11:26:12.568122 IP vpn.york.ac.uk > nasaaa2.york.ac.uk: ICMP vpn.york.ac.uk udp port 33286 unreachable, length 215


Can anyone suggest what might be the problem here? I don't understand the "upd port unreachable"
or the "received RADIUS server response with invalid length" messages.

Thanks

Ben Thompson