<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><meta http-equiv=Content-Type content="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 12 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri","sans-serif";
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-US link=blue vlink=purple><div class=WordSection1><p class=MsoNormal>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.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>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.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Here is the debug:<o:p></o:p></p><p class=MsoNormal>rad_recv: Access-Request packet from host 76.8.212.170 port 36910, id=78, length=189<o:p></o:p></p><p class=MsoNormal> NAS-Port-Type = Wireless-802.11<o:p></o:p></p><p class=MsoNormal> Calling-Station-Id = "1C:4B:D6:A5:CD:BF"<o:p></o:p></p><p class=MsoNormal> Called-Station-Id = "10631"<o:p></o:p></p><p class=MsoNormal> NAS-Port-Id = "ether2"<o:p></o:p></p><p class=MsoNormal> User-Name = "1"<o:p></o:p></p><p class=MsoNormal> NAS-Port = 2152726611<o:p></o:p></p><p class=MsoNormal> Acct-Session-Id = "80500053"<o:p></o:p></p><p class=MsoNormal> Framed-IP-Address = 10.69.103.254<o:p></o:p></p><p class=MsoNormal> Mikrotik-Host-IP = 10.69.103.254<o:p></o:p></p><p class=MsoNormal> CHAP-Challenge = 0x95b4afa9e0e37e62da70a83197931d11<o:p></o:p></p><p class=MsoNormal> CHAP-Password = 0x21b4c5ed3e3175b1b7672103936286b74e<o:p></o:p></p><p class=MsoNormal> Service-Type = Login-User<o:p></o:p></p><p class=MsoNormal> WISPr-Logoff-URL = "http://10.69.100.1/logout"<o:p></o:p></p><p class=MsoNormal> NAS-Identifier = "MikroTik"<o:p></o:p></p><p class=MsoNormal> NAS-IP-Address = 192.168.99.163<o:p></o:p></p><p class=MsoNormal># Executing section authorize from file /etc/freeradius/sites-enabled/default<o:p></o:p></p><p class=MsoNormal>+- entering group authorize {...}<o:p></o:p></p><p class=MsoNormal>++[preprocess] returns ok<o:p></o:p></p><p class=MsoNormal>[chap] Setting 'Auth-Type := CHAP'<o:p></o:p></p><p class=MsoNormal>++[chap] returns ok<o:p></o:p></p><p class=MsoNormal>++[mschap] returns noop<o:p></o:p></p><p class=MsoNormal>++[digest] returns noop<o:p></o:p></p><p class=MsoNormal>[suffix] No '@' in User-Name = "1", looking up realm NULL<o:p></o:p></p><p class=MsoNormal>[suffix] No such realm "NULL"<o:p></o:p></p><p class=MsoNormal>++[suffix] returns noop<o:p></o:p></p><p class=MsoNormal>[eap] No EAP-Message, not doing EAP<o:p></o:p></p><p class=MsoNormal>++[eap] returns noop<o:p></o:p></p><p class=MsoNormal>++[files] returns noop<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{User-Name} -> 1<o:p></o:p></p><p class=MsoNormal>[sql] sql_set_user escaped user --> '1'<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Reserving sql socket id: 3<o:p></o:p></p><p class=MsoNormal>[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<o:p></o:p></p><p class=MsoNormal>rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '1' and PID='10631' ORDER BY id<o:p></o:p></p><p class=MsoNormal>[sql] User found in radcheck table<o:p></o:p></p><p class=MsoNormal>[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<o:p></o:p></p><p class=MsoNormal>rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = '1' and PID='10631' ORDER BY id<o:p></o:p></p><p class=MsoNormal>[sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '1' ORDER BY priority<o:p></o:p></p><p class=MsoNormal>rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = '1' ORDER BY priority<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Released sql socket id: 3<o:p></o:p></p><p class=MsoNormal>++[sql] returns ok<o:p></o:p></p><p class=MsoNormal>++[expiration] returns noop<o:p></o:p></p><p class=MsoNormal>++[logintime] returns noop<o:p></o:p></p><p class=MsoNormal>[pap] WARNING: Auth-Type already set. Not setting to PAP<o:p></o:p></p><p class=MsoNormal>++[pap] returns noop<o:p></o:p></p><p class=MsoNormal>Found Auth-Type = CHAP<o:p></o:p></p><p class=MsoNormal># Executing group from file /etc/freeradius/sites-enabled/default<o:p></o:p></p><p class=MsoNormal>+- entering group CHAP {...}<o:p></o:p></p><p class=MsoNormal>[chap] login attempt by "1" with CHAP password<o:p></o:p></p><p class=MsoNormal>[chap] Using clear text password "1" for user 1 authentication.<o:p></o:p></p><p class=MsoNormal>[chap] chap user 1 authenticated succesfully<o:p></o:p></p><p class=MsoNormal>++[chap] returns ok<o:p></o:p></p><p class=MsoNormal># Executing section post-auth from file /etc/freeradius/sites-enabled/default<o:p></o:p></p><p class=MsoNormal>+- entering group post-auth {...}<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{User-Name} -> 1<o:p></o:p></p><p class=MsoNormal>[sql] sql_set_user escaped user --> '1'<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{User-Password} -> <o:p></o:p></p><p class=MsoNormal>[sql] ... expanding second conditional<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{Chap-Password} -> 0x21b4c5ed3e3175b1b7672103936286b74e<o:p></o:p></p><p class=MsoNormal>[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')<o:p></o:p></p><p class=MsoNormal>[sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql<o:p></o:p></p><p class=MsoNormal>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')<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Reserving sql socket id: 2<o:p></o:p></p><p class=MsoNormal>rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1', '0x21b4c5ed3e3175b1b7672103936286b74e', 'Access-Accept', '2014-06-11 18:42:31')<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Released sql socket id: 2<o:p></o:p></p><p class=MsoNormal>++[sql] returns ok<o:p></o:p></p><p class=MsoNormal>[sql_log] Processing sql_log_postauth<o:p></o:p></p><p class=MsoNormal>[sql_log] expand: %{User-Name} -> 1<o:p></o:p></p><p class=MsoNormal>[sql_log] expand: %{%{User-Name}:-DEFAULT} -> 1<o:p></o:p></p><p class=MsoNormal>[sql_log] sql_set_user escaped user --> '1'<o:p></o:p></p><p class=MsoNormal>[sql_log] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details<o:p></o:p></p><p class=MsoNormal>[sql_log] ... expanding second conditional<o:p></o:p></p><p class=MsoNormal>[sql_log] expand: Chap-Password -> Chap-Password<o:p></o:p></p><p class=MsoNormal>[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');<o:p></o:p></p><p class=MsoNormal>[sql_log] expand: /var/log/freeradius/radacct/sql-relay -> /var/log/freeradius/radacct/sql-relay<o:p></o:p></p><p class=MsoNormal>[sql_log] Couldn't open file /var/log/freeradius/radacct/sql-relay: No such file or directory<o:p></o:p></p><p class=MsoNormal>++[sql_log] returns fail<o:p></o:p></p><p class=MsoNormal>Using Post-Auth-Type Reject<o:p></o:p></p><p class=MsoNormal># Executing group from file /etc/freeradius/sites-enabled/default<o:p></o:p></p><p class=MsoNormal>+- entering group REJECT {...}<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{User-Name} -> 1<o:p></o:p></p><p class=MsoNormal>[sql] sql_set_user escaped user --> '1'<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{User-Password} -> <o:p></o:p></p><p class=MsoNormal>[sql] ... expanding second conditional<o:p></o:p></p><p class=MsoNormal>[sql] expand: %{Chap-Password} -> 0x21b4c5ed3e3175b1b7672103936286b74e<o:p></o:p></p><p class=MsoNormal>[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')<o:p></o:p></p><p class=MsoNormal>[sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql<o:p></o:p></p><p class=MsoNormal>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')<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Reserving sql socket id: 1<o:p></o:p></p><p class=MsoNormal>rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '1', '0x21b4c5ed3e3175b1b7672103936286b74e', 'Access-Reject', '2014-06-11 18:42:31')<o:p></o:p></p><p class=MsoNormal>rlm_sql (sql): Released sql socket id: 1<o:p></o:p></p><p class=MsoNormal>++[sql] returns ok<o:p></o:p></p><p class=MsoNormal>[attr_filter.access_reject] expand: %{User-Name} -> 1<o:p></o:p></p><p class=MsoNormal> attr_filter: Matched entry DEFAULT at line 11<o:p></o:p></p><p class=MsoNormal>++[attr_filter.access_reject] returns updated<o:p></o:p></p><p class=MsoNormal>Delaying reject of request 0 for 1 seconds<o:p></o:p></p><p class=MsoNormal>Going to the next request<o:p></o:p></p><p class=MsoNormal>Waking up in 0.9 seconds.<o:p></o:p></p><p class=MsoNormal>Sending delayed reject for request 0<o:p></o:p></p><p class=MsoNormal>Sending Access-Reject of id 78 to 76.8.212.170 port 36910<o:p></o:p></p><p class=MsoNormal>Waking up in 4.9 seconds.<o:p></o:p></p><p class=MsoNormal>Cleaning up request 0 ID 78 with timestamp +6<o:p></o:p></p><p class=MsoNormal>Ready to process requests.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Thanks<o:p></o:p></p><p class=MsoNormal>Brent <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p></div></body></html>