[RADIATOR] Client erratic selection of handlers

Fri Aug 28 03:22:58 CDT 2009

Hi,

I've having some erratic behaviour with Handler selection. I fetch most of my client IP from SQL with ClientListSQL (about 900), but some special clients, I manually define in the configuration so I can set "Identifier" labels so they can be treated correctly and get special handling.

When I start Radiator, all seems fine, and it works for a period. But later, perhaps after another refresh from the SQL, Radiator seem to be no longer able to recognise the client, and cannot find the handler.

If I "restart" radiator, no config changes, it starts to work again, but after a period will stop working. It does not seem to affect all the special cases, just the "ACE" case as show in the config at the bottom.

Does anyone know what might be going on?

Cheers, Michael

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

THIS is a functioning request that occurs after I restart Radiator.

Fri Aug 28 15:38:53 2009: DEBUG: Gigawords - Check for Counter Wrap.
Fri Aug 28 15:38:53 2009: DEBUG: Packet dump:
*** Received from 172.31.146.131 port 1031 ....
Code:       Access-Request
Identifier: 171
Authentic:  <181><4><219>@+<0><0>\<175>"<210>\<132><19><179>V
Attributes:
	User-Name = "ocsic"
	User-Password = XXXXXXXXXXXXXXXXXXXXXX
	NAS-Port-Type = Virtual
	NAS-Port = 0
	Service-Type = NAS-Prompt-User
	NAS-IP-Address = 172.31.146.131

Fri Aug 28 15:38:53 2009: DEBUG: Handling request with Handler 'Client-Identifier=ACE-Interfaces'
Fri Aug 28 15:38:53 2009: DEBUG: Handling with Radius::AuthLSA: 
Fri Aug 28 15:38:53 2009: DEBUG: Radius::AuthLSA looks for match with ocsic [ocsic]
Fri Aug 28 15:38:53 2009: DEBUG: Radius::AuthLSA ACCEPT: : ocsic [ocsic]
Fri Aug 28 15:38:53 2009: DEBUG: AuthBy LSA result: ACCEPT, 
Fri Aug 28 15:38:53 2009: DEBUG: Access accepted for ocsic
Fri Aug 28 15:38:53 2009: DEBUG: Packet dump:
*** Sending to 172.31.146.131 port 1031 ....
Code:       Access-Accept
Identifier: 171
Authentic:  g<11>M`<202><154><137><199><167><152><163><179>M<234><225><138>
Attributes:
	cisco-avpair = "shell:Admin=Admin default-domain"

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

A little later, a ClientListSQL refresh occurs

Fri Aug 28 15:40:04 2009: DEBUG: ClientListSQL automatic refresh
Fri Aug 28 15:40:04 2009: DEBUG: ClientListSQL removes previously added Client nh-av29-2.sw.utas.edu.au
[LOTS of lines removed]
Fri Aug 28 15:40:06 2009: DEBUG: ClientListSQL removes previously added Client cm-mz-2.sw.utas.edu.au.
Fri Aug 28 15:40:06 2009: DEBUG: Adding Clients from SQL database
Fri Aug 28 15:40:06 2009: DEBUG: Query is: 'select 
	NASIDENTIFIER,
	SECRET,
	IGNOREACCTSIGNATURE,
	DUPINTERVAL,
	DEFAULTREALM,
	NASTYPE,
	SNMPCOMMUNITY,
	LIVINGSTONOFFS,
	LIVINGSTONHOLE,
	FRAMEDGROUPBASEADDRESS,
	FRAMEDGROUPMAXPORTSPERCLASSC,
	REWRITEUSERNAME,
	NOIGNOREDUPLICATES,
	PREHANDLERHOOK from RADCLIENTLIST': 
Fri Aug 28 15:40:06 2009: ERR: Execute failed for 'select 
	NASIDENTIFIER,
	SECRET,
	IGNOREACCTSIGNATURE,
	DUPINTERVAL,
	DEFAULTREALM,
	NASTYPE,
	SNMPCOMMUNITY,
	LIVINGSTONOFFS,
	LIVINGSTONHOLE,
	FRAMEDGROUPBASEADDRESS,
	FRAMEDGROUPMAXPORTSPERCLASSC,
	REWRITEUSERNAME,
	NOIGNOREDUPLICATES,
	PREHANDLERHOOK from RADCLIENTLIST': Lost connection to MySQL server during query
Fri Aug 28 15:40:06 2009: DEBUG: ClientListSQL adds Client nh-av29-2.sw.utas.edu.au
Fri Aug 28 15:40:06 2009: DEBUG: ClientListSQL adds Client nh-av29-1.sw.utas.edu.au
[LOTS of lines removed]
Fri Aug 28 15:40:09 2009: DEBUG: ClientListSQL adds Client cm-mz-2.sw.utas.edu.au.
Fri Aug 28 15:40:09 2009: DEBUG: Automatic ClientListSQL refresh has succeeded, using new Client list

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

NOW, another identical looking request come in, but now the handler cannot be found!!!

*** Received from 172.31.146.131 port 1031 ....
Code:       Access-Request
Identifier: 203
Authentic:  <197>2j<202><191>4<207>D<210><233><23>*<138><8><171><247>
Attributes:
	User-Name = "ocsic"
	User-Password = XXXXXXXXXXXXXXXXX
	NAS-Port-Type = Virtual
	NAS-Port = 0
	Service-Type = NAS-Prompt-User
	NAS-IP-Address = 172.31.146.131

Fri Aug 28 15:41:35 2009: WARNING: Could not find a handler for ocsic: request is ignored
Fri Aug 28 15:41:36 2009: DEBUG: Gigawords - Check for Counter Wrap.
Fri Aug 28 15:41:36 2009: DEBUG: Packet dump:
*** Received from 172.31.146.131 port 1031 ....
Code:       Access-Request
Identifier: 203
Authentic:  <197>2j<202><191>4<207>D<210><233><23>*<138><8><171><247>
Attributes:
	User-Name = "ocsic"
	User-Password = XXXXXXXXXXXXXXXXXXXXXX
	NAS-Port-Type = Virtual
	NAS-Port = 0
	Service-Type = NAS-Prompt-User
	NAS-IP-Address = 172.31.146.131

Fri Aug 28 15:41:36 2009: WARNING: Could not find a handler for ocsic: request is ignored
Fri Aug 28 15:41:37 2009: DEBUG: Gigawords - Check for Counter Wrap.
Fri Aug 28 15:41:37 2009: DEBUG: Packet dump:

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

Here is the client loading section of the configuration

PreClientHook file:"%D/scripts/gigawords-hook.pl"

# Get client (switch/router/PDU) information from SQL
<ClientListSQL>
      Include "%D/configs/DataBase-Config.cfg"
      RefreshPeriod 3600
</ClientListSQL>

# Manually define all WLC/WiSM here
<Client 172.31.3.3>
	Identifier Internal-Wireless-Network
	Secret	XXXXXXX
	DupInterval 10
	IdenticalClients 172.31.3.2
</Client>

# Manually define all FWSM here
<Client 172.31.255.21>
	Identifier Firewall-Modules
	Secret	XXXXXXX
	DupInterval 10
	IdenticalClients 172.31.255.22
</Client>

# Manually define all ACE Interfaces here
<Client 172.31.2.220>
	IdenticalClients 172.31.146.130, 172.31.146.131, 172.31.146.132
	Identifier ACE-Interfaces
	Secret	XXXXXXXX
	DupInterval 5
</Client>

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

Here is the handler...

<Handler Client-Identifier=ACE-Interfaces>
      SessionDatabase  Null-Session-DB
      RejectHasReason
      <AuthBy LSA>
           NoDefault
           EAPType PAP
           Group ITS-NetFWAdmin
      </AuthBy>
      AddToReply cisco-avpair="shell:Admin=Admin default-domain"
</Handler>

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