Mysql and usage of radgroupcheck

14 Nov 2006

      I have set up Freeradius working fine with a users-file. I did some tests
to change to Mysql and all was ok, until I want to add some conditions for
users in more than one group.

This looks like a simple setup for Mysql, but it's not working as I
thought it would:

mysql> select * from usergroup;
+----------+-----------+----------+
| UserName | GroupName | priority |
+----------+-----------+----------+
| user1    | Group1    |        1 |
| user1    | Group2    |        2 |
+----------+-----------+----------+
2 rows in set (0.00 sec)

mysql> select * from radcheck;
+----+----------+---------------+----+------------+
| id | UserName | Attribute     | op | Value      |
+----+----------+---------------+----+------------+
|  1 | user1    | User-Password | == | paswoordje |
+----+----------+---------------+----+------------+
1 row in set (0.00 sec)

mysql> select * from radreply;
Empty set (0.00 sec)

mysql> select * from radgroupcheck;
+----+-----------+----------------+----+--------------+
| id | GroupName | Attribute      | op | Value        |
+----+-----------+----------------+----+--------------+
|  1 | Group1    | NAS-IP-Address | == | 172.16.224.1 |
|  2 | Group2    | NAS-IP-Address | == | 172.16.224.2 |
+----+-----------+----------------+----+--------------+
2 rows in set (0.01 sec)

mysql> select * from radgroupreply;
+----+-----------+-----------+----+----------+
| id | GroupName | Attribute | op | Value    |
+----+-----------+-----------+----+----------+
|  1 | Group1    | Class     | := | groepje1 |
|  2 | Group2    | Class     | := | groepje2 |
+----+-----------+-----------+----+----------+
2 rows in set (0.00 sec)

I use ntradping to check the setup.

When I use NAS-IP-Address = 172.16.224.1 I get the correct class
(groepje1), but when I use the NAS-IP-Address = 172.16.224.2 I get a
reject and not as I was expecting the class-attribute groepje2.

I can't figure out why this is the case.

The debug output is not helping me, either. Anyone a suggestion on solving
this?

---- DEBUG output for NAS-IP-Address = 172.16.224.1--------------

rad_recv: Access-Request packet from host 157.193.39.138:3674, id=65,
length=51
        User-Name = "user1"
        User-Password = "paswoordje"
        NAS-IP-Address = 172.16.224.1
Tue Nov 14 16:37:17 2006 : Debug:   Processing the authorize section of
radiusd.conf
Tue Nov 14 16:37:17 2006 : Debug: modcall: entering group authorize for
request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module
"preprocess" returns ok for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling chap
(rlm_chap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
chap (rlm_chap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "chap"
returns noop for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling mschap
(rlm_mschap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
mschap (rlm_mschap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "mschap"
returns noop for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling suffix
(rlm_realm) for request 37
Tue Nov 14 16:37:17 2006 : Debug:     rlm_realm: No '@' in User-Name =
"user1", looking up realm NULL
Tue Nov 14 16:37:17 2006 : Debug:     rlm_realm: No such realm "NULL"
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
suffix (rlm_realm) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "suffix"
returns noop for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "eap"
returns noop for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "files"
returns notfound for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: calling sql
(rlm_sql) for request 37
Tue Nov 14 16:37:17 2006 : Debug: radius_xlat:  'user1'
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'user1'
Tue Nov 14 16:37:17 2006 : Debug: radius_xlat:  'SELECT id, UserName,
Attribute, Value, op           FROM radcheck           WHERE Username =
'user1'           ORDER BY id'
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql (sql): Reserving sql socket id:
2
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql_mysql: query:  SELECT id,
UserName, Attribute, Value, op           FROM radcheck           WHERE
Username = 'user1'           ORDER BY id
Tue Nov 14 16:37:17 2006 : Debug: radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql_mysql: query:  SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id
Tue Nov 14 16:37:17 2006 : Debug: radius_xlat:  'SELECT id, UserName,
Attribute, Value, op           FROM radreply           WHERE Username =
'user1'           ORDER BY id'
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql_mysql: query:  SELECT id,
UserName, Attribute, Value, op           FROM radreply           WHERE
Username = 'user1'           ORDER BY id
Tue Nov 14 16:37:17 2006 : Debug: radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql_mysql: query:  SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id
Tue Nov 14 16:37:17 2006 : Debug: rlm_sql (sql): Released sql socket id: 2
Tue Nov 14 16:37:17 2006 : Debug:   modsingle[authorize]: returned from
sql (rlm_sql) for request 37
Tue Nov 14 16:37:17 2006 : Debug:   modcall[authorize]: module "sql"
returns ok for request 37
Tue Nov 14 16:37:17 2006 : Debug: modcall: leaving group authorize
(returns ok) for request 37
Tue Nov 14 16:37:17 2006 : Debug: auth: type Local
Tue Nov 14 16:37:17 2006 : Debug: auth: user supplied User-Password
matches local User-Password
Tue Nov 14 16:37:17 2006 : Auth: Login OK: [user1] (from client ntradping
port 0)
Sending Access-Accept of id 65 to 157.193.39.138 port 3674
        Class := 0x67726f65706a6531

---- DEBUG output for NAS-IP-Address = 172.16.224.2--------------

rad_recv: Access-Request packet from host 157.193.39.138:3675, id=66,
length=51
        User-Name = "user1"
        User-Password = "paswoordje"
        NAS-IP-Address = 172.16.224.2
Tue Nov 14 16:45:11 2006 : Debug:   Processing the authorize section of
radiusd.conf
Tue Nov 14 16:45:11 2006 : Debug: modcall: entering group authorize for
request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module
"preprocess" returns ok for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling chap
(rlm_chap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
chap (rlm_chap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "chap"
returns noop for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling
mschap (rlm_mschap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
mschap (rlm_mschap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "mschap"
returns noop for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling suffix
(rlm_realm) for request 38
Tue Nov 14 16:45:11 2006 : Debug:     rlm_realm: No '@' in User-Name =
"user1", looking up realm NULL
Tue Nov 14 16:45:11 2006 : Debug:     rlm_realm: No such realm "NULL"
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
suffix (rlm_realm) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "suffix"
returns noop for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "eap"
returns noop for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "files"
returns notfound for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: calling sql
(rlm_sql) for request 38
Tue Nov 14 16:45:11 2006 : Debug: radius_xlat:  'user1'
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql (sql): sql_set_user escaped user
--> 'user1'
Tue Nov 14 16:45:11 2006 : Debug: radius_xlat:  'SELECT id, UserName,
Attribute, Value, op           FROM radcheck           WHERE Username =
'user1'           ORDER BY id'
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql (sql): Reserving sql socket id:
1
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql_mysql: query:  SELECT id,
UserName, Attribute, Value, op           FROM radcheck           WHERE
Username = 'user1'           ORDER BY id
Tue Nov 14 16:45:11 2006 : Debug: radius_xlat:  'SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql_mysql: query:  SELECT
radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op
FROM radgroupcheck,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id
Tue Nov 14 16:45:11 2006 : Debug: radius_xlat:  'SELECT id, UserName,
Attribute, Value, op           FROM radreply           WHERE Username =
'user1'           ORDER BY id'
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql_mysql: query:  SELECT id,
UserName, Attribute, Value, op           FROM radreply           WHERE
Username = 'user1'           ORDER BY id
Tue Nov 14 16:45:11 2006 : Debug: radius_xlat:  'SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql_mysql: query:  SELECT
radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op
FROM radgroupreply,usergroup WHERE usergroup.Username = 'user1' AND
usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id
Tue Nov 14 16:45:11 2006 : Debug: rlm_sql (sql): Released sql socket id: 1
Tue Nov 14 16:45:11 2006 : Info: rlm_sql (sql): No matching entry in the
database for request from user [user1]
Tue Nov 14 16:45:11 2006 : Debug:   modsingle[authorize]: returned from
sql (rlm_sql) for request 38
Tue Nov 14 16:45:11 2006 : Debug:   modcall[authorize]: module "sql"
returns notfound for request 38
Tue Nov 14 16:45:11 2006 : Debug: modcall: leaving group authorize
(returns ok) for request 38
Tue Nov 14 16:45:11 2006 : Debug: auth: No authenticate method (Auth-Type)
configuration found for the request: Rejecting the user
Tue Nov 14 16:45:11 2006 : Debug: auth: Failed to validate the user.
Tue Nov 14 16:45:11 2006 : Auth: Login incorrect: [user1] (from client
ntradping port 0)
Tue Nov 14 16:45:11 2006 : Debug: Delaying request 38 for 1 seconds
Tue Nov 14 16:45:11 2006 : Debug: Finished request 38
Tue Nov 14 16:45:11 2006 : Debug: Going to the next request
Tue Nov 14 16:45:11 2006 : Debug: --- Walking the entire request list ---
Tue Nov 14 16:45:11 2006 : Debug: Waking up in 1 seconds...
Tue Nov 14 16:45:12 2006 : Debug: --- Walking the entire request list ---
Tue Nov 14 16:45:12 2006 : Debug: Waking up in 1 seconds...
Tue Nov 14 16:45:13 2006 : Debug: --- Walking the entire request list ---
Sending Access-Reject of id 66 to 157.193.39.138 port 3675

Anne-Mie

Mysql and usage of radgroupcheck

Anne-Mie Vandermeeren