Subject: Radcheck gives Accept but still moves onto Radgroupcheck
Mike Poole
mpoole at pavlovmedia.com
Fri Jun 13 20:46:53 CEST 2014
file /var/log/freeradius/radacct/sql-relay: No such file or directory
Brent -
The reject isn't coming from group check, it fails out when it tries to write to the sql-relay file that doesn't exist. You should turn off sql-relay or configure it.
If part of the sql process fails (as I've been painfully doing here with my MT the last two days) the whole process will result in an Access Reject.
Notice the reject comes directly after the statement above.
Also, any time a "user found in radcheck" is sent, the next query will be processed.
Mike
Message: 4
Date: Wed, 11 Jun 2014 17:04:30 -0600
From: "Brent Wilkinson" <brent at air2data.com>
To: "'FreeRadius users mailing list'"
<freeradius-users at lists.freeradius.org>
Subject: Radcheck gives Accept but still moves onto Radgroupcheck
Message-ID: <000601cf85c9$8104cd50$830e67f0$@com>
Content-Type: text/plain; charset="us-ascii"
I am setting up a new Radius server or a mikrotik hotspot system. I am getting a wierd issue that I have not been able to solve or find hints to what to do to fix it. I have setup the system with mysql. I see the radcheck happen and show it retrieved a record. ( I have verified the sql statments do actually pull something). I am not sending any reply so nothing is found in that table. At this point from what I understand in reading how the sql module works at this point it should send back a Access-Accept. Unfortunatly it does not and continues to do group checks and I end up with a reject.
Hoping someone can give me a idea of what I need to look at or what I can read up more on to track the issue I am having down.
Here is the debug:
rad_recv: Access-Request packet from host 76.8.212.170 port 36910, id=78,
length=189
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "1C:4B:D6:A5:CD:BF"
Called-Station-Id = "10631"
NAS-Port-Id = "ether2"
User-Name = "1"
NAS-Port = 2152726611
Acct-Session-Id = "80500053"
Framed-IP-Address = 10.69.103.254
Mikrotik-Host-IP = 10.69.103.254
CHAP-Challenge = 0x95b4afa9e0e37e62da70a83197931d11
CHAP-Password = 0x21b4c5ed3e3175b1b7672103936286b74e
Service-Type = Login-User
WISPr-Logoff-URL = "http://10.69.100.1/logout"
NAS-Identifier = "MikroTik"
NAS-IP-Address = 192.168.99.163
# Executing section authorize from file
/etc/freeradius/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "1", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[files] returns noop
[sql] expand: %{User-Name} -> 1
[sql] sql_set_user escaped user --> '1'
rlm_sql (sql): Reserving sql socket id: 3
[sql] expand: SELECT id, username, attribute, value, op FROM
radcheck WHERE username = '%{SQL-User-Name}' and
PID='%{Called-Station-Id}' ORDER BY id -> SELECT id, username,
attribute, value, op FROM radcheck WHERE username = '1'
and PID='10631' ORDER BY id
rlm_sql_mysql: query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = '1' and PID='10631' ORDER
BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op FROM
radreply WHERE username = '%{SQL-User-Name}' and
PID='%{Called-Station-Id}' ORDER BY id -> SELECT id, username,
attribute, value, op FROM radreply WHERE username = '1'
and PID='10631' ORDER BY id
rlm_sql_mysql: query: SELECT id, username, attribute, value, op
FROM radreply WHERE username = '1' and PID='10631' ORDER
BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username = '1'
ORDER BY priority
rlm_sql_mysql: query: SELECT groupname FROM radusergroup
WHERE username = '1' ORDER BY priority
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 = CHAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group CHAP {...}
[chap] login attempt by "1" with CHAP password
[chap] Using clear text password "1" for user 1 authentication.
[chap] chap user 1 authenticated succesfully
++[chap] returns ok
# Executing section post-auth from file
/etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
[sql] expand: %{User-Name} -> 1
[sql] sql_set_user escaped user --> '1'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[sql] expand: %{Chap-Password} -> 0x21b4c5ed3e3175b1b7672103936286b74e
[sql] expand: INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Accept', '2014-06-11 18:42:31')
[sql] expand: /var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Accept', '2014-06-11 18:42:31')
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql_mysql: query: INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Accept', '2014-06-11 18:42:31')
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log] expand: %{User-Name} -> 1
[sql_log] expand: %{%{User-Name}:-DEFAULT} -> 1
[sql_log] sql_set_user escaped user --> '1'
[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) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}',
'%{reply:Packet-Type}', '%S'); -> INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES ('1',
'Chap-Password', 'Access-Accept', '2014-06-11
18:42:31');
[sql_log] expand: /var/log/freeradius/radacct/sql-relay ->
/var/log/freeradius/radacct/sql-relay
[sql_log] Couldn't open file /var/log/freeradius/radacct/sql-relay: No such file or directory
++[sql_log] returns fail
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group REJECT {...}
[sql] expand: %{User-Name} -> 1
[sql] sql_set_user escaped user --> '1'
[sql] expand: %{User-Password} ->
[sql] ... expanding second conditional
[sql] expand: %{Chap-Password} -> 0x21b4c5ed3e3175b1b7672103936286b74e
[sql] expand: INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Reject', '2014-06-11 18:42:31')
[sql] expand: /var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Reject', '2014-06-11 18:42:31')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql_mysql: query: INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES (
'1', '0x21b4c5ed3e3175b1b7672103936286b74e',
'Access-Reject', '2014-06-11 18:42:31')
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
[attr_filter.access_reject] expand: %{User-Name} -> 1
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 78 to 76.8.212.170 port 36910
Waking up in 4.9 seconds.
Cleaning up request 0 ID 78 with timestamp +6
Ready to process requests.
Thanks
Brent
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20140611/9f91e681/attachment.html>
------------------------------
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
End of Freeradius-Users Digest, Vol 110, Issue 44
*************************************************
More information about the Freeradius-Users
mailing list