Hi !, I experiment a strange problem which have appeared since some weeks.
All Access-Reject sent to my AC/AP by the radius server take a lot of time to arrive and there is a timeout on my AC/AP. This is very strange because all Access-Accept are well-received without any timeout and any error by the AC/AP. And, I test on my lan with Ntradping, and the same problem of timeout appears after an Access-Reject. But also, when I launch Freeradius on debug mode, there is no timeout and all Access-Reject are well-received. This is the configuration I use : freeradius 1.0.3 database : Postgresql release 8.0.3 Access Controller/Access Point colubris(CN3200) Thank you for your help. Sincerily, Patrice Tcherkezian ------------------------------------------------------------ Below, an debug output with a successful connection : ------------------------------------------------------------ rad_recv: Access-Request packet from host 192.168.10.60:2631, id=8, length=48 User-Name = "estelle" CHAP-Password = 0x438c4b60518a10782d6e01d0cf399bdc14 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 rlm_chap: Setting 'Auth-Type := CHAP' modcall[authorize]: module "chap" returns ok for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: No '@' in User-Name = "estelle", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 0 radius_xlat: 'estelle' rlm_sql (sql): sql_set_user escaped user --> 'estelle' radius_xlat: 'SELECT radcheck.id, radcheck.UserName, radcheck.Attribute, radcheck.Value, radcheck.Op ??FROM radcheck , "user" ??WHERE radcheck.Username = 'estelle' AND radcheck.Username = "user".Username AND "user".state_account = 1 ??ORDER BY id' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = radius_xlat: 'SELECT radgroupcheck.id, radgroupcheck.GroupName, ??radgroupcheck.Attribute, radgroupcheck.Value,radgroupcheck.Op ??FROM radgroupcheck, usergroup ??WHERE usergroup.Username = 'estelle' AND usergroup.GroupName = radgroupcheck.GroupName ??ORDER BY radgroupcheck.id' rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = radius_xlat: 'SELECT id, UserName, Attribute, Value, Op ??FROM radreply ??WHERE Username = 'estelle' ??ORDER BY id' rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = radius_xlat: 'SELECT radgroupreply.id, radgroupreply.GroupName, radgroupreply.Attribute, ??radgroupreply.Value, radgroupreply.Op ??FROM radgroupreply,usergroup ??WHERE usergroup.Username = 'estelle' AND usergroup.GroupName = radgroupreply.GroupName ??ORDER BY radgroupreply.id' rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = rlm_sql (sql): Released sql socket id: 4 modcall[authorize]: module "sql" returns ok for request 0 modcall: group authorize returns ok for request 0 rad_check_password: Found Auth-Type Local auth: type Local auth: user supplied CHAP-Password matches local User-Password Login OK: [estelle] (from client postedario port 0) Processing the post-auth section of radiusd.conf modcall: entering group post-auth for request 0 rlm_sql (sql): Processing sql_postauth radius_xlat: 'estelle' rlm_sql (sql): sql_set_user escaped user --> 'estelle' radius_xlat: 'INSERT into radpostauth (username, pass, reply, authdate,mac_address,ip_user,hotspot_name) ??values ('estelle', 'Chap-Password', 'Access-Accept', NOW(),'', NULLIF('', '')::inet,'')' rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (username, pass, reply, authdate,mac_address,ip_user,hotspot_name) ??values ('estelle', 'Chap-Password', 'Access-Accept', NOW(),'', NULLIF('', '')::inet,'') rlm_sql (sql): Reserving sql socket id: 3 rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: affected rows = 1 rlm_sql (sql): Released sql socket id: 3 modcall[post-auth]: module "sql" returns ok for request 0 modcall: group post-auth returns ok for request 0 Sending Access-Accept of id 8 to 192.168.10.60:2631 Session-Timeout := 4813 Idle-Timeout := 600 Framed-Protocol := PPP Service-Type := Framed-User Framed-MTU := 1500 Colubris-AVPair += "use-access-list=visiteurs" Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... ------------------------------------------------------------ Below, an debug output with a refused connection : ------------------------------------------------------------ rad_recv: Access-Request packet from host 192.168.10.60:2638, id=9, length=46 User-Name = "voila" CHAP-Password = 0x4f2988cb3ca0e0e7bfd22eea9dda72b19f Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 rlm_chap: Setting 'Auth-Type := CHAP' modcall[authorize]: module "chap" returns ok for request 1 modcall[authorize]: module "mschap" returns noop for request 1 rlm_realm: No '@' in User-Name = "voila", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 1 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 1 radius_xlat: 'voila' rlm_sql (sql): sql_set_user escaped user --> 'voila' radius_xlat: 'SELECT radcheck.id, radcheck.UserName, radcheck.Attribute, radcheck.Value, radcheck.Op ??FROM radcheck , "user" ??WHERE radcheck.Username = 'voila' AND radcheck.Username = "user".Username AND "user".state_account = 1 ??ORDER BY id' rlm_sql (sql): Reserving sql socket id: 2 rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = rlm_sql (sql): User voila not found in radcheck radius_xlat: 'SELECT radgroupcheck.id, radgroupcheck.GroupName, ??radgroupcheck.Attribute, radgroupcheck.Value,radgroupcheck.Op ??FROM radgroupcheck, usergroup ??WHERE usergroup.Username = 'voila' AND usergroup.GroupName = radgroupcheck.GroupName ??ORDER BY radgroupcheck.id' rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = radius_xlat: 'SELECT radgroupreply.id, radgroupreply.GroupName, radgroupreply.Attribute, ??radgroupreply.Value, radgroupreply.Op ??FROM radgroupreply,usergroup ??WHERE usergroup.Username = 'voila' AND usergroup.GroupName = radgroupreply.GroupName ??ORDER BY radgroupreply.id' rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: affected rows = rlm_sql (sql): User voila not found in radgroupcheck rlm_sql (sql): User not found rlm_sql (sql): Released sql socket id: 2 modcall[authorize]: module "sql" returns notfound for request 1 modcall: group authorize returns ok for request 1 rad_check_password: Found Auth-Type CHAP auth: type "CHAP" Processing the authenticate section of radiusd.conf modcall: entering group Auth-Type for request 1 rlm_chap: login attempt by "voila" with CHAP password rlm_chap: Could not find clear text password for user voila modcall[authenticate]: module "chap" returns invalid for request 1 modcall: group Auth-Type returns invalid for request 1 auth: Failed to validate the user. Login incorrect (rlm_chap: Clear text password not available): [voila/<CHAP-Password>] (from client postedario port 0) Processing the post-auth section of radiusd.conf modcall: entering group Post-Auth-Type for request 1 rlm_sql (sql): Processing sql_postauth radius_xlat: 'voila' rlm_sql (sql): sql_set_user escaped user --> 'voila' radius_xlat: 'INSERT into radpostauth (username, pass, reply, authdate,mac_address,ip_user,hotspot_name) ??values ('voila', 'Chap-Password', 'Access-Reject', NOW(),'', NULLIF('', '')::inet,'')' rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (username, pass, reply, authdate,mac_address,ip_user,hotspot_name) ??values ('voila', 'Chap-Password', 'Access-Reject', NOW(),'', NULLIF('', '')::inet,'') rlm_sql (sql): Reserving sql socket id: 1 rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: affected rows = 1 rlm_sql (sql): Released sql socket id: 1 modcall[post-auth]: module "sql" returns ok for request 1 modcall: group Post-Auth-Type returns ok for request 1 Delaying request 1 for 1 seconds Finished request 1 Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Sending Access-Reject of id 9 to 192.168.10.60:2638 Waking up in 4 seconds... --- Walking the entire request list --- Cleaning up request 1 ID 9 with timestamp 42efb05d Nothing to do. Sleeping until we see a request. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html