users file: =~ and User-Password

[Stefan Winter]

Hi,

I'm trying to understand what exactly happens in the users file when 
processing User-Password. The situation I'm seeing here is in a rather 
complex scenario, and the results are not quite what I would expect. In 
short, when a MS-CHAP'ed request comes in and users contains a check
User-Password =~ (foo|bar), then even though there is no User-Password 
attribute in the request itself, it matches.
The long story, for those still reading, is:
* mySQL database with our "nice" users. Nice means, they have a single 
password for all of our services (ASMTP, IMAP, VPN, Dial-Up, Groupware).
* some users have for ancient reasons two different passwords, one for 
VPN&Dial-Up, one for the rest.
* these users are handled in the users file, with
  uname User-Password =~ (foo|bar), Auth-Type := Accept
* The processing order in authorize and authenticate is:

authorize {
        preprocess
        nas_auth_log
        suffix
        mschap
        files
        eap
        sql
}

authenticate {
        Auth-Type MS-CHAP {
                mschap
        }
        eap
}

Now, -X shows that first authorize->mschap comes into action and sets the 
Auth-Type to MS-CHAP (fine). It does *NOT* set a User-Password attribute 
because this can only be retrieved later during authorize->sql. 
The next module to come is authorize->files. There, in my opinion, the 
above-mentioned line that contains User-Password =~ (foo|bar) SHOULD NOT 
match, because there is no User-Password attribute in the request.
But: users DOES match (when one of the passwords matches the CHAP challenge) 
and sets Auth-Type to Accept. This can only mean that files does some 
auto-validating against the CHAP challenge, where it should only make a 
simple string comparison (not even that, since the attribute isn't even 
there, it should just do nothing).
Now you could say, so what, the user gets accepted after all, so why do you 
care? The reason is that as soon as Auth-Type is set to Accept, 
authenticate->mschap isn't called any more, and so the encryption seeds and 
and attributes are not set. That way, people end up being accepted by RADIUS, 
but the VPN concentrator denies access anyways.
I'm aware I can get around this by using Auth-Type = Accept, to not override 
the previously-set MS-CHAP.
But the real cause is in that a "users" line matches that, according to the 
documentation of the =~ operator, shouldn't. If you explain me now that the 
magic MS-CHAP validation is intentional, no problem: I would even submit a 
documentation patch explaining things. But just leaving the hand-waiving 
undocumented is not good IMHO.

For complete reference, here's the -X run-through of the case in question 
(hints line 4 sets a VSA RESTENA-Service-Type to VPN):

rad_recv: Access-Request packet from host 158.64.X.Y:1026, id=116, length=152
        User-Name = "foobar"
        NAS-Port = 1801
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Tunnel-Client-Endpoint:0 = "158.64.A.B"
        MS-CHAP-Challenge = 0xbla44babcdefb327e8c48eobfuscated
        MS-CHAP2-Response = 0xwhatever
        NAS-IP-Address = 158.64.X.Y
        NAS-Port-Type = Virtual
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 30048
  hints: Matched DEFAULT at 4
  modcall[authorize]: module "preprocess" returns ok for request 30048
radius_xlat:  '/var/log/radius/radacct/20060323/VPN-service/auth-detail'
rlm_detail: /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/auth-detail 
expands to /var/log/radius/radacct/20060323/VPN-service/auth-detail
  modcall[authorize]: module "nas_auth_log" returns ok for request 30048
    rlm_realm: No '@' in User-Name = "foobar", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 30048
  rlm_mschap: Found MS-CHAP attributes.  Setting 'Auth-Type  = MS-CHAP'
  modcall[authorize]: module "mschap" returns ok for request 30048
    users: Matched entry foobar at line 115
  modcall[authorize]: module "files" returns ok for request 30048
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 30048
radius_xlat:  'foobar'
rlm_sql (sql-normal-vpn): sql_set_user escaped user --> 'foobar'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE 
Username = 'foobar' ORDER BY id'
rlm_sql (sql-normal-vpn): Reserving sql socket id: 4
radius_xlat:  'SELECT 
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op  
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'foobar' AND 
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat:  'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE 
Username = 'foobar' ORDER BY id'
radius_xlat:  'SELECT 
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op  
FROM radgroupreply,usergroup WHERE usergroup.Username = 'foobar' AND 
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql-normal-vpn): Released sql socket id: 4
  modcall[authorize]: module "sql-normal-vpn" returns ok for request 30048
modcall: leaving group authorize (returns ok) for request 30048
  rad_check_password:  Found Auth-Type Accept
  rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [foobar] (from client moria port 1801)
  Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 30048
radius_xlat:  '/var/log/radius/radacct/20060323/VPN-service/reply-detail'
rlm_detail: /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/reply-detail 
expands to /var/log/radius/radacct/20060323/VPN-service/reply-detail
  modcall[post-auth]: module "nas_reply_log" returns ok for request 30048
rlm_sql (sql-normal-vpn): Processing sql_postauth
radius_xlat:  'foobar'
rlm_sql (sql-normal-vpn): sql_set_user escaped user --> 'foobar'
radius_xlat:  'INSERT into radpostauth (id, user, pass, reply, date) values 
('', 'foobar', 'VPN', 'Access-Accept', NOW())'
rlm_sql (sql-normal-vpn) in sql_postauth: query is INSERT into radpostauth 
(id, user, pass, reply, date) values ('', 'foobar', 'VPN', 'Access-Accept', 
NOW())
rlm_sql (sql-normal-vpn): Reserving sql socket id: 3
rlm_sql (sql-normal-vpn): Released sql socket id: 3
  modcall[post-auth]: module "sql-normal-vpn" returns ok for request 30048
modcall: leaving group post-auth (returns ok) for request 30048
Sending Access-Accept of id 116 to 158.64.1.53 port 1026
Finished request 30048
Going to the next request
--- Walking the entire request list ---

Greetings,

Stefan Winter

-- 
Stefan WINTER

RESTENA Foundation - Réseau Téléinformatique de l'Education Nationale et de 
la Recherche
R&D Engineer

6, rue Richard Coudenhove-Kalergi
L-1359 Luxembourg
email: stefan.winter at restena.lu     Tel.:     +352 424409-1
http://www.restena.lu               Fax:      +352 422473