no group matching - we set read group = yes - but no group attributes is checked or taken :-(
Krystof Klima - WIFIPROFI.CZ
klima at wifiprofi.cz
Tue Mar 18 22:57:16 CET 2014
We set all to clean versions, one clear version FC14 with Radiusd 2.1.12 on
one server, it is good
Second is clear version on new FC20 with Radiusd 3.0.1 on next server.and
doesnt work
We use recomended "schema.sql" we use basic config using MySQL
See log.there is checking groups in FC14 . You can see "User found in group
tarif1"
[suffix] No '@' in User-Name = "tester", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[sql] expand: %{User-Name} -> tester
[sql] sql_set_user escaped user --> 'tester'
rlm_sql (sql): Reserving sql socket id: 3
[sql] expand: SELECT id, username, attribute, value, op FROM
radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
-> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'tester' ORDER BY id
WARNING: Found User-Password == "...".
WARNING: Are you sure you don't mean Cleartext-Password?
WARNING: See "man rlm_pap" for more information.
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op FROM
radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
-> SELECT id, username, attribute, value, op FROM radreply
WHERE username = 'tester' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username = 'tester'
ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = 'tarif1' ORDER BY
id
[sql] User found in group tarif1
[sql] expand: SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = 'tarif1' ORDER BY
id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING: Auth-Type already set. Not setting to PAP
++[pap] returns noop
Found Auth-Type = MSCHAP
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!
!!! Replacing User-Password in config items with Cleartext-Password.
!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!
!!! Please update your configuration so that the "known good"
!!!
!!! clear text password is in Cleartext-Password, and not in User-Password.
!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group MS-CHAP {...}
[mschap] Creating challenge hash with username: tester
[mschap] Told to do MS-CHAPv2 for tester with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
Login OK: [tester/<via Auth-Type = mschap>] (from client sdc_privatni port
2147483791 cli 00:0C:42:20:96:D3)
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
[sql] expand: %{User-Name} -> tester
[sql] sql_set_user escaped user --> 'tester'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[sql] expand: %{Chap-Password} ->
[sql] expand: INSERT INTO radpostauth
(username, pass, reply, authdate,DHCP_SERVER,REZE_SE,DHCP_RELAY)
VALUES ( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}',
'%S','%{NAS-IP-Address}','%{NAS-Identifier}','%{Called-Station-Id}') ->
INSERT INTO radpostauth (username, pass, reply,
authdate,DHCP_SERVER,REZE_SE,DHCP_RELAY) VALUES (
'tester', '',
'Access-Accept', '2014-03-18
22:38:16','10.10.10.253','mt-dilna.vlaskovi.cz','service1')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate,DHCP_SERVER,REZE_SE,DHCP_RELAY)
VALUES ( 'tester', '',
'Access-Accept', '2014-03-18
22:38:16','10.10.10.253','mt-dilna.vlaskovi.cz','service1')
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log] expand: %{User-Name} -> tester
[sql_log] expand: %{%{User-Name}:-DEFAULT} -> tester
[sql_log] sql_set_user escaped user --> 'tester'
[sql_log] WARNING: Deprecated conditional expansion ":-". See "man unlang"
for details
[sql_log] ... expanding second conditional
[sql_log] expand: Chap-Password -> Chap-Password
[sql_log] expand: INSERT INTO radpostauth
(username, pass, reply, authdate, test) VALUES
('%{User-Name}', '%{User-Password:-Chap-Password}',
'%{reply:Packet-Type}', '%S', '%{NAS-IP-Address}'); -> INSERT INTO
radpostauth (username, pass, reply, authdate, test)
VALUES ('tester', 'Chap-Password',
'Access-Accept', '2014-03-18 22:38:16', '10.10.10.253');
[sql_log] expand: /var/log/radius/radacct/sql-relay ->
/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
++[exec] returns noop
Sending Access-Accept of id 52 to 172.30.0.54 port 42156
Mikrotik-Rate-Limit = "7M/14M"
MS-CHAP2-Success =
0x01533d33353031344234424632324342313046394530304237324242323742413631444532
393131394238
MS-MPPE-Recv-Key = 0xd3b4972527affe2bdc87fe3eeffc5e49
MS-MPPE-Send-Key = 0x7472d58842d4fd4b15afa46ceda6f263
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000006
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
And second log from FC20 where is not checked. Looks like doesnt check
groupname > directly fall to next proces
5) sql : expand: "SELECT id, username, attribute, value, op FROM
radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" -> 'SELECT id,
username, attribute, value, op FROM radcheck WHERE username = 'tester' ORDER
BY id'
Tue Mar 18 21:25:19 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
id, username, attribute, value, op FROM radcheck WHERE username = 'tester'
ORDER BY id'
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : User found in radcheck table
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : Check items matched
Tue Mar 18 21:25:19 2014 : Debug: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Tue Mar 18 21:25:19 2014 : Debug: Parsed xlat tree:
Tue Mar 18 21:25:19 2014 : Debug: literal: 'SELECT id, username, attribute,
value, op FROM radreply WHERE username = ''
Tue Mar 18 21:25:19 2014 : Debug: attribute: SQL-User-Name
Tue Mar 18 21:25:19 2014 : Debug: {
Tue Mar 18 21:25:19 2014 : Debug: ref 2
Tue Mar 18 21:25:19 2014 : Debug: list 1
Tue Mar 18 21:25:19 2014 : Debug: tag -128
Tue Mar 18 21:25:19 2014 : Debug: }
Tue Mar 18 21:25:19 2014 : Debug: literal: '' ORDER BY id'
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : expand: "SELECT id,
username, attribute, value, op FROM radreply WHERE username =
'%{SQL-User-Name}' ORDER BY id" -> 'SELECT id,
username, attribute, value, op FROM radreply WHERE username = 'tester' ORDER
BY id'
Tue Mar 18 21:25:19 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
id, username, attribute, value, op FROM radreply WHERE username = 'tester'
ORDER BY id'
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : User found in radreply table
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : ... falling-through to group
processing
Tue Mar 18 21:25:19 2014 : Debug: SELECT groupname FROM radusergroup WHERE
username = BINARY '%{SQL-User-Name}' ORDER BY priority
Tue Mar 18 21:25:19 2014 : Debug: Parsed xlat tree:
Tue Mar 18 21:25:19 2014 : Debug: literal: 'SELECT groupname FROM
radusergroup WHERE username = BINARY ''
Tue Mar 18 21:25:19 2014 : Debug: attribute: SQL-User-Name
Tue Mar 18 21:25:19 2014 : Debug: {
Tue Mar 18 21:25:19 2014 : Debug: ref 2
Tue Mar 18 21:25:19 2014 : Debug: list 1
Tue Mar 18 21:25:19 2014 : Debug: tag -128
Tue Mar 18 21:25:19 2014 : Debug: }
Tue Mar 18 21:25:19 2014 : Debug: literal: '' ORDER BY priority'
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : expand: "SELECT groupname
FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY
priority" -> 'SELECT groupname FR
OM radusergroup WHERE username = BINARY 'tester' ORDER BY priority'
Tue Mar 18 21:25:19 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
groupname FROM radusergroup WHERE username = BINARY 'tester' ORDER BY
priority'
Tue Mar 18 21:25:19 2014 : Debug: (5) sql : ... falling-through to profile
processing
Tue Mar 18 21:25:19 2014 : Debug: rlm_sql (sql): Released connection (8)
Tue Mar 18 21:25:19 2014 : Info: rlm_sql (sql): Opening additional
connection (9)
Tue Mar 18 21:25:19 2014 : Debug: rlm_sql_mysql: Starting connect to MySQL
server
Regards,
Kryštof Klíma ****
poskytování poradenství v oblasti sítí Lan a Wan, servis a prodej výpočetní
techniky
Mobil: +420 774 331 774 E-mail: <mailto:klima at wifiprofi.cz>
klima at wifiprofi.cz
From: Krystof Klima - WIFIPROFI.CZ [mailto:klima at wifiprofi.cz]
Sent: Monday, March 17, 2014 9:10 PM
To: 'freeradius-devel at lists.freeradius.org'
Subject: no group matching - we set read group = yes - but no group
attributes is checked or taken :-(
Importance: High
Hello,
We are using Freeradius from 1.x version, after new release of Fedora 20, we
reinstalled.all we connected well, but only group items is not checked /I am
sending all my config in this mail/ and radiusd doesnt write log "raddact"
We stop our old database for sure, for sure we install new blind original
Freeradius 3.0.1 "schema.sql" without success /user in database works - we
are accepted with user - only no log/
Can You help me ?? we solved this three weeks and we are unhappy from our
work.
List of debug :
driver = "rlm_sql_mysql"
Mon Mar 17 20:26:44 2014 : Debug: server = "localhost"
Mon Mar 17 20:26:44 2014 : Debug: port = "3306"
Mon Mar 17 20:26:44 2014 : Debug: login = "radius"
Mon Mar 17 20:26:44 2014 : Debug: password = "radius"
Mon Mar 17 20:26:44 2014 : Debug: radius_db = "radius_test"
Mon Mar 17 20:26:44 2014 : Debug: read_groups = yes
Mon Mar 17 20:26:44 2014 : Debug: read_clients = yes
Mon Mar 17 20:26:44 2014 : Debug: delete_stale_sessions = yes
Mon Mar 17 20:26:44 2014 : Debug: sql_user_name = "%{User-Name}"
Mon Mar 17 20:26:44 2014 : Debug: default_user_profile = ""
Mon Mar 17 20:26:44 2014 : Debug: client_query = "SELECT id, nasname,
shortname, type, secret, server FROM nas"
Mon Mar 17 20:26:44 2014 : Debug: authorize_check_query = "SELECT id,
username, attribute, value, op FROM radcheck WHERE username =
'%{SQL-User-Name}' ORDER BY id"
Mon Mar 17 20:26:44 2014 : Debug: authorize_reply_query = "SELECT id,
username, attribute, value, op FROM radreply WHERE username =
'%{SQL-User-Name}' ORDER BY id"
Mon Mar 17 20:26:44 2014 : Debug: authorize_group_check_query =
"SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE
groupname = '%{Sql-Group}' ORDER BY id
"
Mon Mar 17 20:26:44 2014 : Debug: authorize_group_reply_query =
"SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE
groupname = '%{Sql-Group}' ORDER BY id
"
Mon Mar 17 20:26:44 2014 : Debug: group_membership_query = "SELECT
groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY
priority"
Mon Mar 17 20:26:44 2014 : Debug: simul_count_query = ""
Mon Mar 17 20:26:45 2014 : Debug: simul_verify_query = "SELECT
radacctid, acctsessionid, username, nasipaddress, nasportid,
framedipaddress, callingstationid, framedprotoc
ol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS
NULL"
Mon Mar 17 20:26:45 2014 : Debug: safe_characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
And important part with authorinizg.looks like group is empty, but executing
query on SSH will show DATA
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : expand: "SELECT id,
username, attribute, value, op FROM radcheck WHERE username =
'%{SQL-User-Name}' ORDER BY id" -> 'SELECT id,
username, attribute, value, op FROM radcheck WHERE username = 'tester' ORDER
BY id'
Mon Mar 17 20:26:50 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
id, username, attribute, value, op FROM radcheck WHERE username = 'tester'
ORDER BY id'
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : User found in radcheck table
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : Check items matched
Mon Mar 17 20:26:50 2014 : Debug: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Mon Mar 17 20:26:50 2014 : Debug: Parsed xlat tree:
Mon Mar 17 20:26:50 2014 : Debug: literal: 'SELECT id, username, attribute,
value, op FROM radreply WHERE username = ''
Mon Mar 17 20:26:50 2014 : Debug: attribute: SQL-User-Name
Mon Mar 17 20:26:50 2014 : Debug: {
Mon Mar 17 20:26:50 2014 : Debug: ref 2
Mon Mar 17 20:26:50 2014 : Debug: list 1
Mon Mar 17 20:26:50 2014 : Debug: tag -128
Mon Mar 17 20:26:50 2014 : Debug: }
Mon Mar 17 20:26:50 2014 : Debug: literal: '' ORDER BY id'
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : expand: "SELECT id,
username, attribute, value, op FROM radreply WHERE username =
'%{SQL-User-Name}' ORDER BY id" -> 'SELECT id,
username, attribute, value, op FROM radreply WHERE username = 'tester' ORDER
BY id'
Mon Mar 17 20:26:50 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
id, username, attribute, value, op FROM radreply WHERE username = 'tester'
ORDER BY id'
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : ... falling-through to group
processing
Mon Mar 17 20:26:50 2014 : Debug: SELECT groupname FROM radusergroup WHERE
username = '%{SQL-User-Name}' ORDER BY priority
Mon Mar 17 20:26:50 2014 : Debug: Parsed xlat tree:
Mon Mar 17 20:26:50 2014 : Debug: literal: 'SELECT groupname FROM
radusergroup WHERE username = ''
Mon Mar 17 20:26:50 2014 : Debug: attribute: SQL-User-Name
Mon Mar 17 20:26:50 2014 : Debug: {
Mon Mar 17 20:26:50 2014 : Debug: ref 2
Mon Mar 17 20:26:50 2014 : Debug: list 1
Mon Mar 17 20:26:50 2014 : Debug: tag -128
Mon Mar 17 20:26:50 2014 : Debug: }
Mon Mar 17 20:26:50 2014 : Debug: literal: '' ORDER BY priority'
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : expand: "SELECT groupname
FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" ->
'SELECT groupname FROM radu
sergroup WHERE username = 'tester' ORDER BY priority'
Mon Mar 17 20:26:50 2014 : Debug: rlm_sql (sql): Executing query: 'SELECT
groupname FROM radusergroup WHERE username = 'tester' ORDER BY priority'
Mon Mar 17 20:26:50 2014 : Debug: (0) sql : ... falling-through to profile
processing
Mon Mar 17 20:26:50 2014 : Debug: rlm_sql (sql): Released connection (1)
Mon Mar 17 20:26:50 2014 : Info: rlm_sql (sql): Closing connection (0): Too
many free connections (2 > 0)
Mon Mar 17 20:26:50 2014 : Debug: rlm_sql_mysql: Socket destructor called,
closing socket
Mon Mar 17 20:26:50 2014 : Debug: (0) modsingle[authorize]: returned from
sql (rlm_sql) for request 0
Mon Mar 17 20:26:50 2014 : Debug: (0) [sql] = ok
Mon Mar 17 20:26:50 2014 : Debug: (0) modsingle[authorize]: calling
expiration (rlm_expiration) for request
Regards,
Kryštof Klíma ****
poskytování poradenství v oblasti sítí Lan a Wan, servis a prodej výpočetní
techniky
Mobil: +420 774 331 774 E-mail: <mailto:klima at wifiprofi.cz>
klima at wifiprofi.cz
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/mailman/private/freeradius-devel/attachments/20140318/06140004/attachment-0001.html>
More information about the Freeradius-Devel
mailing list