Strange password when authenticating via pppoe-server.

[Ivan Kalik]

Post the whole debug including the request. You have chopped off the
front bit.

Ivan Kalik
Kalik Informatika ISP


Dana 12/7/2008, "Maciej Drobniuch" <maciej at drobniuch.pl> piše:

>
>Hi!
>Now I have a new problem.
>When auth via radiusclient, everyting works fine:
>
>>radtest steve testing localhost 1813 somesecret
>
>Sat Jul 12 12:07:31 2008 : Debug:   modsingle[authenticate]: calling pap
>(rlm_pap) for request 4
>Sat Jul 12 12:07:31 2008 : Debug: rlm_pap: login attempt with password
>"testing"
>Sat Jul 12 12:07:31 2008 : Debug: rlm_pap: Using clear text password
>"testing"
>Sat Jul 12 12:07:31 2008 : Debug: rlm_pap: User authenticated successfully
>Sat Jul 12 12:07:31 2008 : Debug:   modsingle[authenticate]: returned from
>pap (rlm_pap) for request 4
>Sat Jul 12 12:07:31 2008 : Debug: ++[pap] returns ok
>Sat Jul 12 12:07:31 2008 : Debug: +- entering group post-auth
>Sat Jul 12 12:07:31 2008 : Debug:   modsingle[post-auth]: calling exec
>(rlm_exec) for request 4
>Sat Jul 12 12:07:31 2008 : Debug:   modsingle[post-auth]: returned from
>exec (rlm_exec) for request 4
>Sat Jul 12 12:07:31 2008 : Debug: ++[exec] returns noop
>Sending Access-Accept of id 146 to 127.0.0.1 port 32770
>        Service-Type = Framed-User
>        Framed-Protocol = PPP
>        Framed-IP-Address = 172.16.3.33
>        Framed-IP-Netmask = 255.255.255.0
>        Framed-Routing = Broadcast-Listen
>        Framed-Filter-Id = "std.ppp"
>        Framed-MTU = 1500
>        Framed-Compression = Van-Jacobson-TCP-IP
>
>I've also tried to auth using this command(and the login is also
>successful):
>echo User-Name = "steve", CHAP-Password = "testing" | radclient localhost
>auth somesecret
>
>But when i've had tried to login from a client (windows xp) station using
>the pppoe-server(on the server) the debug output looks like this:
>Force PAP(require-pap) on pppoe-server:
>Sat Jul 12 12:11:23 2008 : Debug: auth: type "PAP"
>Sat Jul 12 12:11:23 2008 : Debug: +- entering group PAP
>Sat Jul 12 12:11:23 2008 : Debug:   modsingle[authenticate]: calling pap
>(rlm_pap) for request 7
>Sat Jul 12 12:11:23 2008 : Debug: rlm_pap: login attempt with password
>"��23�tn?? 8ťĞ1R�"
>Sat Jul 12 12:11:23 2008 : Debug: rlm_pap: Using clear text password
>"testing"
>Sat Jul 12 12:11:23 2008 : Debug: rlm_pap: Passwords don't match
>Sat Jul 12 12:11:23 2008 : Debug:   modsingle[authenticate]: returned from
>pap (rlm_pap) for request 7
>Sat Jul 12 12:11:23 2008 : Debug: ++[pap] returns reject
>Sat Jul 12 12:11:23 2008 : Debug: auth: Failed to validate the user.
>Sat Jul 12 12:11:23 2008 : Debug:   WARNING: Unprintable characters in the
>password.      Double-check the shared secret on the server and the NAS!
>Sat Jul 12 12:11:23 2008 : Debug:   Found Post-Auth-Type Reject
>Sat Jul 12 12:11:23 2008 : Debug: +- entering group REJECT
>Sat Jul 12 12:11:23 2008 : Debug:   modsingle[post-auth]: calling
>attr_filter.access_reject (rlm_attr_filter) for request 7
>Sat Jul 12 12:11:23 2008 : Debug:       expand: %{User-Name} -> steve
>Sat Jul 12 12:11:23 2008 : Debug:  attr_filter: Matched entry DEFAULT at
>line 11
>Sat Jul 12 12:11:23 2008 : Debug:   modsingle[post-auth]: returned from
>attr_filter.access_reject (rlm_attr_filter) for request 7
>Sat Jul 12 12:11:23 2008 : Debug: ++[attr_filter.access_reject] returns
>updated
>Force CHAP(require-chap) on PPPoE server:
>Sat Jul 12 12:13:04 2008 : Debug: auth: type "CHAP"
>Sat Jul 12 12:13:04 2008 : Debug: +- entering group CHAP
>Sat Jul 12 12:13:04 2008 : Debug:   modsingle[authenticate]: calling chap
>(rlm_chap) for request 0
>Sat Jul 12 12:13:04 2008 : Debug:   rlm_chap: login attempt by "steve" with
>CHAP password
>Sat Jul 12 12:13:04 2008 : Debug:   rlm_chap: Using clear text password
>"testing" for user steve authentication.
>Sat Jul 12 12:13:04 2008 : Debug:   rlm_chap: Password check failed
>Sat Jul 12 12:13:04 2008 : Debug:   modsingle[authenticate]: returned from
>chap (rlm_chap) for request 0
>Sat Jul 12 12:13:04 2008 : Debug: ++[chap] returns reject
>Sat Jul 12 12:13:04 2008 : Debug: auth: Failed to validate the user.
>Sat Jul 12 12:13:04 2008 : Debug:   Found Post-Auth-Type Reject
>Sat Jul 12 12:13:04 2008 : Debug: +- entering group REJECT
>Sat Jul 12 12:13:04 2008 : Debug:   modsingle[post-auth]: calling
>attr_filter.access_reject (rlm_attr_filter) for request 0
>Sat Jul 12 12:13:04 2008 : Debug:       expand: %{User-Name} -> steve
>Sat Jul 12 12:13:04 2008 : Debug:  attr_filter: Matched entry DEFAULT at
>line 11
>Sat Jul 12 12:13:04 2008 : Debug:   modsingle[post-auth]: returned from
>attr_filter.access_reject (rlm_attr_filter) for request 0
>Sat Jul 12 12:13:04 2008 : Debug: ++[attr_filter.access_reject] returns
>updated
>Sending Access-Reject of id 57 to 127.0.0.1 port 32770
>Sat Jul 12 12:13:04 2008 : Debug: Finished request 0.
>Sat Jul 12 12:13:04 2008 : Debug: Going to the next request
>Sat Jul 12 12:13:04 2008 : Debug: Waking up in 4.9 seconds.
>Sat Jul 12 12:13:09 2008 : Debug: Cleaning up request 0 ID 57 with
>timestamp +8
>Sat Jul 12 12:13:09 2008 : Debug: Ready to process requests.
>
>What's wrong again?
>Thanks !
>
>-- 
>------------------------
>Maciej Drobniuch
>
>-
>List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html