Re: Server logs say users authenticate, but they don't (Now with more details!)
G'day Ernie,
Can you sniff on the AS5300 and ensure the Access-Accept packets are arriving before the 3 second (default) timeout?
Yes, we tried that. The access-accept packets aren't arriving at all!
Does it work if you temporarily disable the Simultaneous-Use check?
No, that doesn't work either.
Hi Ernie, * Run radiusd -X and check that Access-Accept is being sent, and how long after the Access-Request this is. * Verify with tcpdump that the packet is actually getting onto the wire. * Check for iptables rules/access-lists that might be dropping/rejecting the packets. * Make sure your AS5300 and freeradius are configured to use the same port numbers. freeradius shouldn't be seeing the Access-Request if not, but it might be worth a look. Ernie Dunbar wrote:
G'day Ernie,
Can you sniff on the AS5300 and ensure the Access-Accept packets are arriving before the 3 second (default) timeout?
Yes, we tried that. The access-accept packets aren't arriving at all!
Does it work if you temporarily disable the Simultaneous-Use check?
No, that doesn't work either.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia. Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au
Okay, after doing these tests, we can see that the Cisco is now accepting the packets. However, the AS5300 is now telling us "no appropriate authorization type for user". Here's the logs from the AS5300 (XX.XX.XX.X is the new server, XX.XX.XX.Y is the backup that was offline for the duration of the test): *Jan 3 16:30:43: RADIUS: Trying next server (XX.XX.XX.X) for id 20 *Jan 3 16:30:43: RADIUS: Retransmit id 20 *Jan 3 16:30:43: RADIUS: Received from id 20 XX.XX.XX.X:1812, Access-Accept, len 20 *Jan 3 16:30:43: RADIUS: saved authorization data for user 616D09DC at 614184A4 *Jan 3 16:30:43: RADIUS: no appropriate authorization type for user. *Jan 3 16:30:43: RADIUS: ustruct sharecount=1 *Jan 3 16:30:43: RADIUS: Initial Transmit Async56 id 21 XX.XX.XX.Y:1645, Access-Request, len 88 *Jan 3 16:30:43: Attribute 4 6 CCF4E9FE *Jan 3 16:30:43: Attribute 5 6 00000038 *Jan 3 16:30:43: Attribute 61 6 00000000 *Jan 3 16:30:43: Attribute 1 11 72737461 *Jan 3 16:30:43: Attribute 30 9 36383131 *Jan 3 16:30:43: Attribute 2 18 A3B5B2A0 *Jan 3 16:30:43: Attribute 6 6 00000002 *Jan 3 16:30:43: Attribute 7 6 00000001 *Jan 3 16:30:44: %ISDN-6-DISCONNECT: Interface Serial2:5 disconnected from unknown , call lasted 53 seconds *Jan 3 16:30:44: isdn_Call_disconnect()
Hi Ernie,
* Run radiusd -X and check that Access-Accept is being sent, and how long after the Access-Request this is.
* Verify with tcpdump that the packet is actually getting onto the wire.
* Check for iptables rules/access-lists that might be dropping/rejecting the packets.
* Make sure your AS5300 and freeradius are configured to use the same port numbers. freeradius shouldn't be seeing the Access-Request if not, but it might be worth a look.
Ernie Dunbar wrote:
G'day Ernie,
Can you sniff on the AS5300 and ensure the Access-Accept packets are arriving before the 3 second (default) timeout?
Yes, we tried that. The access-accept packets aren't arriving at all!
Does it work if you temporarily disable the Simultaneous-Use check?
No, that doesn't work either.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia.
Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
G'day Ernie, What value are you sending for Service-Type? Best way to check is radiusd -X, and watch for the Access-Accept that freeradius sends, in case your authorization config isn't quite right. Cheers, James. Ernie Dunbar wrote:
Okay, after doing these tests, we can see that the Cisco is now accepting the packets.
However, the AS5300 is now telling us "no appropriate authorization type for user". Here's the logs from the AS5300 (XX.XX.XX.X is the new server, XX.XX.XX.Y is the backup that was offline for the duration of the test):
*Jan 3 16:30:43: RADIUS: Trying next server (XX.XX.XX.X) for id 20 *Jan 3 16:30:43: RADIUS: Retransmit id 20 *Jan 3 16:30:43: RADIUS: Received from id 20 XX.XX.XX.X:1812, Access-Accept, len 20 *Jan 3 16:30:43: RADIUS: saved authorization data for user 616D09DC at 614184A4 *Jan 3 16:30:43: RADIUS: no appropriate authorization type for user. *Jan 3 16:30:43: RADIUS: ustruct sharecount=1 *Jan 3 16:30:43: RADIUS: Initial Transmit Async56 id 21 XX.XX.XX.Y:1645, Access-Request, len 88 *Jan 3 16:30:43: Attribute 4 6 CCF4E9FE *Jan 3 16:30:43: Attribute 5 6 00000038 *Jan 3 16:30:43: Attribute 61 6 00000000 *Jan 3 16:30:43: Attribute 1 11 72737461 *Jan 3 16:30:43: Attribute 30 9 36383131 *Jan 3 16:30:43: Attribute 2 18 A3B5B2A0 *Jan 3 16:30:43: Attribute 6 6 00000002 *Jan 3 16:30:43: Attribute 7 6 00000001 *Jan 3 16:30:44: %ISDN-6-DISCONNECT: Interface Serial2:5 disconnected from unknown , call lasted 53 seconds *Jan 3 16:30:44: isdn_Call_disconnect()
Hi Ernie,
* Run radiusd -X and check that Access-Accept is being sent, and how long after the Access-Request this is.
* Verify with tcpdump that the packet is actually getting onto the wire.
* Check for iptables rules/access-lists that might be dropping/rejecting the packets.
* Make sure your AS5300 and freeradius are configured to use the same port numbers. freeradius shouldn't be seeing the Access-Request if not, but it might be worth a look.
Ernie Dunbar wrote:
G'day Ernie,
Can you sniff on the AS5300 and ensure the Access-Accept packets are arriving before the 3 second (default) timeout? Yes, we tried that. The access-accept packets aren't arriving at all!
Does it work if you temporarily disable the Simultaneous-Use check? No, that doesn't work either.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia.
Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia. Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au
Here's the output from `freeradius -X` for one attempted user login: rad_recv: Access-Request packet from host AS5300:1645, id=32, length=88 NAS-IP-Address = AS5300 NAS-Port = 47 NAS-Port-Type = Async User-Name = "Pheilmann" Called-Station-Id = "6811527" User-Password = "XXXXXXX" Service-Type = Framed-User Framed-Protocol = PPP Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 radius_xlat: 'Pheilmann' rlm_sql (sql): sql_set_user escaped user --> 'Pheilmann' radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'Pheilmann' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_mysql: query: SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'Pheilmann' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'Pheilmann' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'Pheilmann' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = 'Pheilmann' ORDER BY id' rlm_sql_mysql: query: SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = 'Pheilmann' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'Pheilmann' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'Pheilmann' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id 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 auth: type Local auth: user supplied User-Password matches local User-Password Login OK: [Pheilmann/XXXXXXX] (from client dialup port 47) Sending Access-Accept of id 32 to AS5300:1645 Finished request 0 Going to the next request It looks to me that it's only sending Access-Accept back to the AS5300. I would expect that's what it's supposed to do.
G'day Ernie,
What value are you sending for Service-Type? Best way to check is radiusd -X, and watch for the Access-Accept that freeradius sends, in case your authorization config isn't quite right.
Cheers, James.
Ernie Dunbar wrote:
Okay, after doing these tests, we can see that the Cisco is now accepting the packets.
However, the AS5300 is now telling us "no appropriate authorization type for user". Here's the logs from the AS5300 (XX.XX.XX.X is the new server, XX.XX.XX.Y is the backup that was offline for the duration of the test):
*Jan 3 16:30:43: RADIUS: Trying next server (XX.XX.XX.X) for id 20 *Jan 3 16:30:43: RADIUS: Retransmit id 20 *Jan 3 16:30:43: RADIUS: Received from id 20 XX.XX.XX.X:1812, Access-Accept, len 20 *Jan 3 16:30:43: RADIUS: saved authorization data for user 616D09DC at 614184A4 *Jan 3 16:30:43: RADIUS: no appropriate authorization type for user. *Jan 3 16:30:43: RADIUS: ustruct sharecount=1 *Jan 3 16:30:43: RADIUS: Initial Transmit Async56 id 21 XX.XX.XX.Y:1645, Access-Request, len 88 *Jan 3 16:30:43: Attribute 4 6 CCF4E9FE *Jan 3 16:30:43: Attribute 5 6 00000038 *Jan 3 16:30:43: Attribute 61 6 00000000 *Jan 3 16:30:43: Attribute 1 11 72737461 *Jan 3 16:30:43: Attribute 30 9 36383131 *Jan 3 16:30:43: Attribute 2 18 A3B5B2A0 *Jan 3 16:30:43: Attribute 6 6 00000002 *Jan 3 16:30:43: Attribute 7 6 00000001 *Jan 3 16:30:44: %ISDN-6-DISCONNECT: Interface Serial2:5 disconnected from unknown , call lasted 53 seconds *Jan 3 16:30:44: isdn_Call_disconnect()
Hi Ernie,
* Run radiusd -X and check that Access-Accept is being sent, and how long after the Access-Request this is.
* Verify with tcpdump that the packet is actually getting onto the wire.
* Check for iptables rules/access-lists that might be dropping/rejecting the packets.
* Make sure your AS5300 and freeradius are configured to use the same port numbers. freeradius shouldn't be seeing the Access-Request if not, but it might be worth a look.
Ernie Dunbar wrote:
G'day Ernie,
Can you sniff on the AS5300 and ensure the Access-Accept packets are arriving before the 3 second (default) timeout? Yes, we tried that. The access-accept packets aren't arriving at all!
Does it work if you temporarily disable the Simultaneous-Use check? No, that doesn't work either.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia.
Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- James Wakefield, Unix Administrator, Information Technology Services Division Deakin University, Geelong, Victoria 3217 Australia.
Phone: 03 5227 8690 International: +61 3 5227 8690 Fax: 03 5227 8866 International: +61 3 5227 8866 E-mail: james.wakefield@deakin.edu.au Website: http://www.deakin.edu.au - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (2)
-
Ernie Dunbar -
James Wakefield