Access-Reject in attempted PAP cleartext setup?

[Vincent Fox]

Hello!

I am unable to make even a simple PAP cleartext setup
work and cannot figure out what I am doing wrong.  The note
about it should "just work" well not for me so far.....

I simply did an apt-get and settings are nearly all defaults.
I did add a secret to clients.conf for 127.0.0.1
I tried both settings in modules/pap for auto_header
of yes and no.

I get this error:

root at slim:/etc/raddb# radtest vf5 testing123 localhost 1812 testing123
Sending Access-Request of id 214 to 127.0.0.1 port 1812
        User-Name = "vf5"
        User-Password = "testing123"
        NAS-IP-Address = 10.70.1.9
        NAS-Port = 1812
rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=214, length=32
        Reply-Message = "Hello, vf5"

Simple entry added to default users file:
vf5     Cleartext-Password := "testing123"
                Reply-Message = "Hello, %{User-Name}"

proot at slim:/etc/raddb/modules# apt-cache show freeradius
Package: freeradius
Priority: optional
Section: net
Installed-Size: 2668
Maintainer: Ubuntu Core Developers <ubuntu-devel-discuss at lists.ubuntu.com>
Original-Maintainer: Stephen Gran <sgran at debian.org>
Architecture: i386
Version: 2.1.0+dfsg-0ubuntu2
Provides: radius-server
Depends: lsb-base (>= 3.0-6), libc6 (>= 2.4), libfreeradius2 (= 2.1.0+dfsg-0ubuntu2), libgdbm3, libltdl7 (>= 2.2.4), libpam0g (>= 0.99.7.1), libperl5.10 (>= 5.10.0), python2.5 (>= 2.5), freeradius-common
Recommends: freeradius-utils
Suggests: freeradius-ldap, freeradius-mysql, freeradius-krb5, freeradius-postgresql
Filename: pool/main/f/freeradius/freeradius_2.1.0+dfsg-0ubuntu2_i386.deb
Size: 1148040
MD5sum: 7576890ba8dccbfb9078b92ba4680bc8
SHA1: 9255fee9508af63e2cf0ff09fe22be8c3b10055f
SHA256: 1e1d156ebe3b3bded135adc4b752a62a703dd8cb7253a60f2ec754c1ee0f932a
Description: a high-performance and highly configurable RADIUS server
 A high-performance RADIUS server with support for...
  - many vendor-specific attributes
  - proxying and replicating requests by any criteria
  - authentication on system passwd, SQL, Kerberos, LDAP, users file, or PAM
  - multiple DEFAULT configurations
  - regexp matching in string attributes
 and lots more.
Bugs: mailto:ubuntu-users at lists.ubuntu.com
Origin: Ubuntu

And radiusd -XXX output shows:
Sat Nov 22 20:14:09 2008 : Debug: Listening on authentication address * port 1812
Sat Nov 22 20:14:09 2008 : Debug: Listening on accounting address * port 1813
Sat Nov 22 20:14:09 2008 : Debug: Listening on proxy address * port 1814
Sat Nov 22 20:14:09 2008 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 53924, id=214, length=55
        User-Name = "vf5"
        User-Password = "testing123"
        NAS-IP-Address = 10.70.1.9
        NAS-Port = 1812
Sat Nov 22 20:14:19 2008 : Info: +- entering group authorize {...}
Sat Nov 22 20:14:19 2008 : Info: ++[preprocess] returns ok
Sat Nov 22 20:14:19 2008 : Info: ++[chap] returns noop
Sat Nov 22 20:14:19 2008 : Info: ++[mschap] returns noop
Sat Nov 22 20:14:19 2008 : Info: [suffix] No '@' in User-Name = "vf5", looking up realm NULL
Sat Nov 22 20:14:19 2008 : Info: [suffix] No such realm "NULL"
Sat Nov 22 20:14:19 2008 : Info: ++[suffix] returns noop
Sat Nov 22 20:14:19 2008 : Info: [eap] No EAP-Message, not doing EAP
Sat Nov 22 20:14:19 2008 : Info: ++[eap] returns noop
Sat Nov 22 20:14:19 2008 : Info: ++[unix] returns updated
Sat Nov 22 20:14:19 2008 : Info: [files] users: Matched entry vf5 at line 93
Sat Nov 22 20:14:19 2008 : Debug:       expand: Hello, %{User-Name} -> Hello, vf5
Sat Nov 22 20:14:19 2008 : Info: ++[files] returns ok
Sat Nov 22 20:14:19 2008 : Info: ++[expiration] returns noop
Sat Nov 22 20:14:19 2008 : Info: ++[logintime] returns noop
Sat Nov 22 20:14:19 2008 : Info: ++[pap] returns updated
Sat Nov 22 20:14:19 2008 : Info: Found Auth-Type = PAP
Sat Nov 22 20:14:19 2008 : Info: +- entering group PAP {...}
Sat Nov 22 20:14:19 2008 : Info: [pap] login attempt with password "testing123"
Sat Nov 22 20:14:19 2008 : Info: [pap] Using CRYPT encryption.
Sat Nov 22 20:14:19 2008 : Info: [pap] Passwords don't match
Sat Nov 22 20:14:19 2008 : Info: ++[pap] returns reject
Sat Nov 22 20:14:19 2008 : Info: Failed to authenticate the user.
Sat Nov 22 20:14:19 2008 : Info: Using Post-Auth-Type Reject
Sat Nov 22 20:14:19 2008 : Info: +- entering group REJECT {...}
Sat Nov 22 20:14:19 2008 : Debug:       expand: %{User-Name} -> vf5
Sat Nov 22 20:14:19 2008 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Sat Nov 22 20:14:19 2008 : Info: ++[attr_filter.access_reject] returns updated
Sat Nov 22 20:14:19 2008 : Info: Delaying reject of request 0 for 3 seconds
Sat Nov 22 20:14:19 2008 : Debug: Going to the next request
Sat Nov 22 20:14:19 2008 : Debug: Waking up in 0.9 seconds.
Sat Nov 22 20:14:20 2008 : Debug: Waking up in 1.9 seconds.
Sat Nov 22 20:14:22 2008 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 214 to 127.0.0.1 port 53924
        Reply-Message = "Hello, vf5"
Sat Nov 22 20:14:22 2008 : Debug: Waking up in 4.9 seconds.
Sat Nov 22 20:14:27 2008 : Info: Cleaning up request 0 ID 214 with timestamp +10
Sat Nov 22 20:14:27 2008 : Debug: Ready to process requests.