Beginner Question: "Hotspot Login Failed"
Sean Wingert
seanw at norris-stevens.com
Thu Sep 9 17:59:06 CEST 2010
Hi All,
In my testing lab (yes, I'm new to FreeRadius), usernames entered (e.g. with attribute User-Password in sql radcheck table) via my NAS (dd-wrt with Chillispot) refuse to authenticate (error below), whereas attribute=Auth-Type (what DaloRadius calls a "PIN") works fine. I'm using the packaged MySQL (5.0.51a-24+lenny3) with FreeRadius (2.0.4+dfsg-6)and freeradius-dialupadmin (2.0.4+dfsg-6) on Debian Lenny, along with Daloradius 0.9-8 for GUI frontend.
Below is the Daloradius-populated mysql table (again, only 4321 works fine, regardless of password entered):
+----+----------+--------------------+----+----------------------------------+
| id | username | attribute | op | value |
+----+----------+--------------------+----+----------------------------------+
| 9 | aaa | MD5-Password | := | 47bce5c74f589f4867dbd57e9ca9f808 |
| 7 | 123 | User-Password | := | 123 |
| 8 | 4321 | Auth-Type | := | Accept |
| 10 | bbb | SHA1-Password | := | bbb |
| 11 | ccc | CHAP-Password | := | ccc |
| 12 | eee | Cleartext-Password | := | eee |
+----+----------+--------------------+----+----------------------------------+
6 rows in set (0.00 sec)
==================================
Debug output of working connection
==================================
rad_recv: Access-Request packet from host 192.168.0.72 port 2112, id=0, length=191
User-Name = "4321"
User-Password = "\223=\0322\343\233\361a\365\323\320\333_\245×¼"
NAS-IP-Address = 0.0.0.0
Service-Type = Login-User
Framed-IP-Address = 192.168.182.3
Calling-Station-Id = "C4-17-FE-1C-5C-9D"
Called-Station-Id = "00-24-A5-6F-81-0A"
NAS-Identifier = "1"
Acct-Session-Id = "4c890e8900000000"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
Message-Authenticator = 0x468b4f124525571d6d37d6d1ec69cbdd
WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
+- entering group authorize
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "4321", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
++[files] returns noop
expand: %{User-Name} -> 4321
rlm_sql (sql): sql_set_user escaped user --> '4321'
rlm_sql (sql): Reserving sql socket id: 3
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 = '4321' ORDER BY id
rlm_sql (sql): User found in radcheck table
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 = '4321' ORDER BY id
expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '4321' ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
rlm_pap: Found existing Auth-Type, not changing it.
++[pap] returns noop
rad_check_password: Found Auth-Type Accept
rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [4321/\223=\0322\343\233\361a\365\323\320\333_\245×¼] (from client Subnet port 0 cli C4-17-FE-1C-5C-9D)
+- entering group post-auth
rlm_sql (sql): Processing sql_postauth
expand: %{User-Name} -> 4321
rlm_sql (sql): sql_set_user escaped user --> '4321'
expand: %{User-Password} -> =93=3D=1A2=E3=9B=F1a=F5=D3=D0=DB_=A5=D7=BC
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 ( '4321', '=93=3D=1A2=E3=9B=F1a=F5=D3=D0=DB_=A5=D7=BC', 'Access-Accept', '2010-09-09 08:36:57')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '4321', '=93=3D=1A2=E3=9B=F1a=F5=D3=D0=DB_=A5=D7=BC', 'Access-Accept', '2010-09-09 08:36:57')
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 0 to 192.168.0.72 port 2112
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 192.168.0.72 port 2110, id=8, length=125
Acct-Status-Type = Start
User-Name = "4321"
Calling-Station-Id = "C4-17-FE-1C-5C-9D"
Called-Station-Id = "00-24-A5-6F-81-0A"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
NAS-Port-Id = "00000000"
NAS-IP-Address = 0.0.0.0
NAS-Identifier = "1"
Framed-IP-Address = 192.168.182.3
Acct-Session-Id = "4c890e8900000000"
+- entering group preacct
++[preprocess] returns ok
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.0.72,NAS-IP-Address = 0.0.0.0,Acct-Session-Id = "4c890e8900000000",User-Name = "4321"'
rlm_acct_unique: Acct-Unique-Session-ID = "d3e9d3ef96f2f8d9".
++[acct_unique] returns ok
rlm_realm: No '@' in User-Name = "4321", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
+- entering group accounting
expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.0.72/detail-20100909
rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.0.72/detail-20100909
expand: %t -> Thu Sep 9 08:36:57 2010
++[detail] returns ok
++[unix] returns ok
expand: /var/log/freeradius/radutmp -> /var/log/freeradius/radutmp
expand: %{User-Name} -> 4321
++[radutmp] returns ok
expand: %{User-Name} -> 4321
rlm_sql (sql): sql_set_user escaped user --> '4321'
expand: %{Acct-Delay-Time} ->
expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}') -> INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('4c890e8900000000', 'd3e9d3ef96f2f8d9', '4321', '', '0.0.0.0', '0', 'Wireless-802.11', '2010-09-09 08:36:57', NULL, '0', '', '', '', '0', '0', '00-24-A5-6F-81-0A', 'C4-17-FE-1C-5C-9D', '', '', '', '192.168.182.3', '0', '0', '')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
expand: %{User-Name} -> 4321
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 8 to 192.168.0.72 port 2110
Finished request 2.
Cleaning up request 2 ID 8 with timestamp +2711
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 1 ID 0 with timestamp +2711
Ready to process requests.
==================================
debug output of broken connection
==================================
rad_recv: Accounting-Request packet from host 192.168.0.72 port 2110, id=9, length=173
Acct-Status-Type = Stop
User-Name = "4321"
Calling-Station-Id = "C4-17-FE-1C-5C-9D"
Called-Station-Id = "00-24-A5-6F-81-0A"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
NAS-Port-Id = "00000000"
NAS-IP-Address = 0.0.0.0
NAS-Identifier = "1"
Framed-IP-Address = 192.168.182.3
Acct-Session-Id = "4c890e8900000000"
Acct-Input-Octets = 436077
Acct-Output-Octets = 4958088
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Acct-Input-Packets = 3923
Acct-Output-Packets = 6229
Acct-Session-Time = 863
Acct-Terminate-Cause = User-Request
+- entering group preacct
++[preprocess] returns ok
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.0.72,NAS-IP-Address = 0.0.0.0,Acct-Session-Id = "4c890e8900000000",User-Name = "4321"'
rlm_acct_unique: Acct-Unique-Session-ID = "d3e9d3ef96f2f8d9".
++[acct_unique] returns ok
rlm_realm: No '@' in User-Name = "4321", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
+- entering group accounting
expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.0.72/detail-20100909
rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.0.72/detail-20100909
expand: %t -> Thu Sep 9 08:51:21 2010
++[detail] returns ok
++[unix] returns ok
expand: /var/log/freeradius/radutmp -> /var/log/freeradius/radutmp
expand: %{User-Name} -> 4321
++[radutmp] returns ok
expand: %{User-Name} -> 4321
rlm_sql (sql): sql_set_user escaped user --> '4321'
expand: %{Acct-Input-Gigawords} -> 0
expand: %{Acct-Input-Octets} -> 436077
expand: %{Acct-Output-Gigawords} -> 0
expand: %{Acct-Output-Octets} -> 4958088
expand: %{Acct-Delay-Time} ->
expand: UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET acctstoptime = '2010-09-09 08:51:21', acctsessiontime = '863', acctinputoctets = '0' << 32 | '436077', acctoutputoctets = '0' << 32 | '4958088', acctterminatecause = 'User-Request', acctstopdelay = '0', connectinfo_stop = '' WHERE acctsessionid = '4c890e8900000000' AND username = '4321' AND nasipaddress = '0.0.0.0'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
expand: %{User-Name} -> 4321
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 9 to 192.168.0.72 port 2110
Finished request 0.
Cleaning up request 0 ID 9 with timestamp +9
Going to the next request
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.0.72 port 2112, id=0, length=190
User-Name = "123"
User-Password = "\236\326v\220t\221ê P\277\307;?\025`"
NAS-IP-Address = 0.0.0.0
Service-Type = Login-User
Framed-IP-Address = 192.168.182.3
Calling-Station-Id = "C4-17-FE-1C-5C-9D"
Called-Station-Id = "00-24-A5-6F-81-0A"
NAS-Identifier = "1"
Acct-Session-Id = "4c891e9900000000"
NAS-Port-Type = Wireless-802.11
NAS-Port = 0
Message-Authenticator = 0xdc1dfade75373068738e32d415253503
WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
+- entering group authorize
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "123", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
++[files] returns noop
expand: %{User-Name} -> 123
rlm_sql (sql): sql_set_user escaped user --> '123'
rlm_sql (sql): Reserving sql socket id: 3
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 = '123' ORDER BY id
rlm_sql (sql): User found in radcheck table
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 = '123' ORDER BY id
expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '123' ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
rad_check_password: Found Auth-Type
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! 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. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
auth: type "PAP"
+- entering group PAP
rlm_pap: login attempt with password "?Öv?t?ê?P¿Ç;??`"
rlm_pap: Using clear text password "123"
rlm_pap: Passwords don't match
++[pap] returns reject
auth: Failed to validate the user.
Login incorrect (rlm_pap: CLEAR TEXT password check failed): [123/\236\326v\220t\221ê?P\277\307;?\025`] (from client Subnet port 0 cli C4-17-FE-1C-5C-9D)
WARNING: Unprintable characters in the password. Double-check the shared secret on the server and the NAS!
Found Post-Auth-Type Reject
+- entering group REJECT
expand: %{User-Name} -> 123
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 1 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 1
Sending Access-Reject of id 0 to 192.168.0.72 port 2112
Waking up in 4.9 seconds.
Cleaning up request 1 ID 0 with timestamp +34
Ready to process requests.
This message is intended only for the individual or entity to which it is addressed and may contain information that is privileged, confidential and exempt from disclosure under applicable law. If you are not the intended recipient, or the agent responsible for delivering the message to the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited, and you are requested to return the original message to the sender.
More information about the Freeradius-Users
mailing list