AW: Problem with CHAP Authentification

irosAurus irosaurus at gmx.net
Mon Jun 11 16:12:56 CEST 2012


Sorry everybody to bother you again,
But I saw that the included debug code was missing, so here is the complete
post again with the missing code.
Sorry again for the inconvenience.
Cheers iro

#########################################################

Hello everybody, 

I am trying now for days to get a hotspot with chillispot (on dd-wrt device)
and freeradius running. 

it set up a testuser and if I try a local radcheck on the ubuntu machine,
which hosts the freeradius, everything works out fine. 


maw at maweee:~$ radtest user 123 192.168.1.2 0 testsecret
Sending Access-Request of id 2 to 192.168.1.2 port 1812
	User-Name = "user"
	User-Password = "123"
	NAS-IP-Address = 127.0.1.1
	NAS-Port = 0
rad_recv: Access-Accept packet from host 192.168.1.2 port 1812, id=2,
length=20

when I logon to the wifi, I get a right IP (from 192.168.182.0/24) from the
hotspot and I am redirected to hotspotlogin.cgi, where I put in the exact
same user and password as with the radtest, but login failed. 

 I get the following debug error from freeradius: 


rad_recv: Access-Request packet from host 192.168.1.1 port 32791, id=0,
length=220
	User-Name = "user"
	CHAP-Challenge = 0x6720898bb425aacf39f9c73c8fa166dc
	CHAP-Password = 0x0020e82de25a959fe7a132d435066ceecf
	NAS-IP-Address = 0.0.0.0
	Service-Type = Login-User
	Framed-IP-Address = 192.168.182.2
	Calling-Station-Id = "70-F3-95-AC-E5-70"
	Called-Station-Id = "98-FC-11-88-6B-94"
	NAS-Identifier = "GEC_HotSpot"
	Acct-Session-Id = "4fd6138500000000"
	NAS-Port-Type = Wireless-802.11
	NAS-Port = 0
	Message-Authenticator = 0x33f2f225ef67e3c956754c385490fcc8
	WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
Mon Jun 11 15:49:49 2012 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Mon Jun 11 15:49:49 2012 : Info: +- entering group authorize {...}
Mon Jun 11 15:49:49 2012 : Info: ++[preprocess] returns ok
Mon Jun 11 15:49:49 2012 : Info: [chap] Setting 'Auth-Type := CHAP'
Mon Jun 11 15:49:49 2012 : Info: ++[chap] returns ok
Mon Jun 11 15:49:49 2012 : Info: ++[mschap] returns noop
Mon Jun 11 15:49:49 2012 : Info: [suffix] No '@' in User-Name = "user",
looking up realm NULL
Mon Jun 11 15:49:49 2012 : Info: [suffix] No such realm "NULL"
Mon Jun 11 15:49:49 2012 : Info: ++[suffix] returns noop
Mon Jun 11 15:49:49 2012 : Info: [eap] No EAP-Message, not doing EAP
Mon Jun 11 15:49:49 2012 : Info: ++[eap] returns noop
Mon Jun 11 15:49:49 2012 : Info: [sql] 	expand: %{User-Name} -> user
Mon Jun 11 15:49:49 2012 : Info: [sql] sql_set_user escaped user --> 'user'
Mon Jun 11 15:49:49 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 4
Mon Jun 11 15:49:49 2012 : Info: [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 = 'user'
ORDER BY id
Mon Jun 11 15:49:49 2012 : Info: [sql] User found in radcheck table
Mon Jun 11 15:49:49 2012 : Info: [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 = 'user'
ORDER BY id
Mon Jun 11 15:49:49 2012 : Info: [sql] 	expand: SELECT groupname
FROM radusergroup           WHERE username = '%{SQL-User-Name}'
ORDER BY priority -> SELECT groupname           FROM radusergroup
WHERE username = 'user'           ORDER BY priority
Mon Jun 11 15:49:49 2012 : Debug: rlm_sql (sql): Released sql socket id: 4
Mon Jun 11 15:49:49 2012 : Info: ++[sql] returns ok
Mon Jun 11 15:49:49 2012 : Info: ++[expiration] returns noop
Mon Jun 11 15:49:49 2012 : Info: ++[logintime] returns noop
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:49:49 2012 : Info: ++[noresetcounter] returns noop
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:49:49 2012 : Info: ++[dailycounter] returns noop
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:49:49 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:49:49 2012 : Info: ++[monthlycounter] returns noop
Mon Jun 11 15:49:49 2012 : Info: Found Auth-Type = CHAP
Mon Jun 11 15:49:49 2012 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Mon Jun 11 15:49:49 2012 : Info: +- entering group CHAP {...}
Mon Jun 11 15:49:49 2012 : Info: [chap] login attempt by "user" with CHAP
password
Mon Jun 11 15:49:49 2012 : Info: [chap] Using clear text password "123" for
user user authentication.
Mon Jun 11 15:49:49 2012 : Info: [chap] Password check failed
Mon Jun 11 15:49:49 2012 : Info: ++[chap] returns reject
Mon Jun 11 15:49:49 2012 : Info: Failed to authenticate the user.
Mon Jun 11 15:49:49 2012 : Auth: Login incorrect (rlm_chap: Wrong user
password): [user/<CHAP-Password>] (from client GEC_HotSpot port 0 cli
70-F3-95-AC-E5-70)
Mon Jun 11 15:49:49 2012 : Info: Using Post-Auth-Type Reject
Mon Jun 11 15:49:49 2012 : Info:   WARNING: Unknown value specified for
Post-Auth-Type.  Cannot perform requested action.
Mon Jun 11 15:49:49 2012 : Info: Delaying reject of request 5 for 1 seconds
Mon Jun 11 15:49:49 2012 : Debug: Going to the next request
Mon Jun 11 15:49:49 2012 : Debug: Waking up in 0.9 seconds.
Mon Jun 11 15:49:50 2012 : Info: Sending delayed reject for request 5
Sending Access-Reject of id 0 to 192.168.1.1 port 32791
Mon Jun 11 15:49:50 2012 : Debug: Waking up in 4.9 seconds.
Mon Jun 11 15:49:55 2012 : Info: Cleaning up request 5 ID 0 with timestamp
+1919
Mon Jun 11 15:49:55 2012 : Info: Ready to process requests.

when I try it with a wrong password, I get this debug error: 


Mon Jun 11 15:49:55 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.1.1 port 32791, id=0,
length=220
	User-Name = "user"
	CHAP-Challenge = 0x2fefe9f3c90a15c5f1122cb6257747b4
	CHAP-Password = 0x00aba77648197c77e2b2496605348969ce
	NAS-IP-Address = 0.0.0.0
	Service-Type = Login-User
	Framed-IP-Address = 192.168.182.2
	Calling-Station-Id = "70-F3-95-AC-E5-70"
	Called-Station-Id = "98-FC-11-88-6B-94"
	NAS-Identifier = "GEC_HotSpot"
	Acct-Session-Id = "4fd6138500000000"
	NAS-Port-Type = Wireless-802.11
	NAS-Port = 0
	Message-Authenticator = 0xbe97662ae44ea2f7fbb93fe77a4ff86d
	WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"
Mon Jun 11 15:51:18 2012 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Mon Jun 11 15:51:18 2012 : Info: +- entering group authorize {...}
Mon Jun 11 15:51:18 2012 : Info: ++[preprocess] returns ok
Mon Jun 11 15:51:18 2012 : Info: [chap] Setting 'Auth-Type := CHAP'
Mon Jun 11 15:51:18 2012 : Info: ++[chap] returns ok
Mon Jun 11 15:51:18 2012 : Info: ++[mschap] returns noop
Mon Jun 11 15:51:18 2012 : Info: [suffix] No '@' in User-Name = "user",
looking up realm NULL
Mon Jun 11 15:51:18 2012 : Info: [suffix] No such realm "NULL"
Mon Jun 11 15:51:18 2012 : Info: ++[suffix] returns noop
Mon Jun 11 15:51:18 2012 : Info: [eap] No EAP-Message, not doing EAP
Mon Jun 11 15:51:18 2012 : Info: ++[eap] returns noop
Mon Jun 11 15:51:18 2012 : Info: [sql] 	expand: %{User-Name} -> user
Mon Jun 11 15:51:18 2012 : Info: [sql] sql_set_user escaped user --> 'user'
Mon Jun 11 15:51:18 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 3
Mon Jun 11 15:51:18 2012 : Info: [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 = 'user'
ORDER BY id
Mon Jun 11 15:51:18 2012 : Info: [sql] User found in radcheck table
Mon Jun 11 15:51:18 2012 : Info: [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 = 'user'
ORDER BY id
Mon Jun 11 15:51:18 2012 : Info: [sql] 	expand: SELECT groupname
FROM radusergroup           WHERE username = '%{SQL-User-Name}'
ORDER BY priority -> SELECT groupname           FROM radusergroup
WHERE username = 'user'           ORDER BY priority
Mon Jun 11 15:51:18 2012 : Debug: rlm_sql (sql): Released sql socket id: 3
Mon Jun 11 15:51:18 2012 : Info: ++[sql] returns ok
Mon Jun 11 15:51:18 2012 : Info: ++[expiration] returns noop
Mon Jun 11 15:51:18 2012 : Info: ++[logintime] returns noop
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:51:18 2012 : Info: ++[noresetcounter] returns noop
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:51:18 2012 : Info: ++[dailycounter] returns noop
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Entering module authorize
code
Mon Jun 11 15:51:18 2012 : Debug: rlm_sqlcounter: Could not find Check item
value pair
Mon Jun 11 15:51:18 2012 : Info: ++[monthlycounter] returns noop
Mon Jun 11 15:51:18 2012 : Info: Found Auth-Type = CHAP
Mon Jun 11 15:51:18 2012 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Mon Jun 11 15:51:18 2012 : Info: +- entering group CHAP {...}
Mon Jun 11 15:51:18 2012 : Info: [chap] login attempt by "user" with CHAP
password
Mon Jun 11 15:51:18 2012 : Info: [chap] Using clear text password "123" for
user user authentication.
Mon Jun 11 15:51:18 2012 : Info: [chap] Password check failed
Mon Jun 11 15:51:18 2012 : Info: ++[chap] returns reject
Mon Jun 11 15:51:18 2012 : Info: Failed to authenticate the user.
Mon Jun 11 15:51:18 2012 : Auth: Login incorrect (rlm_chap: Wrong user
password): [user/<CHAP-Password>] (from client GEC_HotSpot port 0 cli
70-F3-95-AC-E5-70)
Mon Jun 11 15:51:18 2012 : Info: Using Post-Auth-Type Reject
Mon Jun 11 15:51:18 2012 : Info:   WARNING: Unknown value specified for
Post-Auth-Type.  Cannot perform requested action.
Mon Jun 11 15:51:18 2012 : Info: Delaying reject of request 6 for 1 seconds
Mon Jun 11 15:51:18 2012 : Debug: Going to the next request
Mon Jun 11 15:51:18 2012 : Debug: Waking up in 0.9 seconds.
Mon Jun 11 15:51:19 2012 : Info: Sending delayed reject for request 6
Sending Access-Reject of id 0 to 192.168.1.1 port 32791
Mon Jun 11 15:51:19 2012 : Debug: Waking up in 4.9 seconds.
Mon Jun 11 15:51:24 2012 : Info: Cleaning up request 6 ID 0 with timestamp
+2008
Mon Jun 11 15:51:24 2012 : Info: Ready to process requests.

has anyone an idea how to disable chap authenitification or better to fix
it? 
I would be really happy about every answer which directs me in a certain
way, because the hotspot has to work this weekend and I am getting a little
bit nervous ;) 


Cheers iro



More information about the Freeradius-Users mailing list