PAP Authentication Question

[Derek Bolichowski]

Hi there,
We are currently using FreeRadius to authenticate ADSL modems at customer locations to our ADSL service via PAP Auth.  We have had this working for some time now.  Recently, I have noticed a number of Auth Login Incorrect entries.  It seems that whenever a modem tries to authenticate using username at realm.com<mailto:username at realm.com> / somepassword, we get a RADIUS auth request one second before with 'realm.com' / radius-secret.

Example seen here:

rad_recv: Access-Request packet from host 192.168.9.6 port 1645, id=37, length=214
        User-Name = "ourrealm.com"
        User-Password = "secret"
        Calling-Station-Id = "GigabitEthernet 5/0/4.4210116:421-116#587310171#804 GE1 WNDSON1431W-WNDSON1434W##pppoe 00:24:c9:90:ca:72#"
        Connect-Info = "1000000000"
        NAS-Port-Type = Virtual
        NAS-Port = 693
        NAS-Port-Id = "Uniq-Sess-ID693"
        Service-Type = Dialout-Framed-User
        NAS-IP-Address = 192.168.9.6
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/192.168.9.6/auth-detail-20140630
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/192.168.9.6/auth-detail-20140630
[auth_log]      expand: %t -> Mon Jun 30 19:44:09 2014
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "ourrealm.com", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
No authenticate method (Auth-Type) configuration found for the request: Rejecting the user
Failed to authenticate the user.
Login incorrect: [ourrealm.com/secret] (from client cisco-router port 693 cli GigabitEthernet 5/0/4.4210116:421-116#587310171#804 GE1 WNDSON1431W-WNDSON1434W##pppoe 00:24:c9:90:ca:72#)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> ourrealm.com
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 0 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 0
Sending Access-Reject of id 37 to 192.168.9.6 port 1645
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.9.6 port 1645, id=38, length=226
        Framed-Protocol = PPP
        User-Name = "validuser at ourrealm.com"
        User-Password = "validpassword"
        Calling-Station-Id = "GigabitEthernet 5/0/4.4210116:421-116#587310171#804 GE1 WNDSON1431W-WNDSON1434W##pppoe 00:24:c9:90:ca:72#"
        Connect-Info = "1000000000"
        NAS-Port-Type = Virtual
        NAS-Port = 693
        NAS-Port-Id = "Uniq-Sess-ID693"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.9.6
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/192.168.9.6/auth-detail-20140630
[auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/192.168.9.6/auth-detail-20140630
[auth_log]      expand: %t -> Mon Jun 30 19:44:10 2014
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "ourrealm.com" for User-Name = "validuser at ourrealm.com"
[suffix] No such realm "ourrealm.com"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
[files] users: Matched entry validuser at ourrealm.com at line 87
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
Found Auth-Type = PAP
+- entering group PAP {...}
[pap] login attempt with password "validpassword"
[pap] Using clear text password "validpassword"
[pap] User authenticated successfully
++[pap] returns ok
Login OK: [validuser at ourrealm.com/validpassword] (from client cisco-router port 693 cli GigabitEthernet 5/0/4.4210116:421-116#587310171#804 GE1 WNDSON1431W-WNDSON1434W##pppoe 00:24:c9:90:ca:72#)
+- entering group post-auth {...}
[reply_log]     expand: /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/radius/radacct/192.168.9.6/reply-detail-20140630
[reply_log] /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/radius/radacct/192.168.9.6/reply-detail-20140630
[reply_log]     expand: %t -> Mon Jun 30 19:44:10 2014
++[reply_log] returns ok
++[exec] returns noop
Sending Access-Accept of id 38 to 192.168.9.6 port 1645
        Framed-IP-Address = 10.40.100.82
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 37 with timestamp +32
Cleaning up request 1 ID 38 with timestamp +33
Ready to process requests.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20140701/ad6aa723/attachment-0001.html>