Hi All,
I wonder if you can help us with a Radius server failover configuration on our virtual 9800-CL. Specifically the 'automate-tester' command on the first Radius Server (ISE):
!
radius server 1
address ipv4 1.1.1.1 auth-port 1812 acct-port 1813
automate-tester username cisco
key £££
!
radius server 2
address ipv4 2.2.2.2 auth-port 1812 acct-port 1813
key £££
!
radius server 3
address ipv4 3.3.3.3 auth-port 1812 acct-port 1813
key £££
!
radius-server dead-criteria tries 3
radius-server retransmit 2
radius-server timeout 3
radius-server deadtime 1
The Radius servers are ISE, which is receiving the message and responding with "Access-Reject". This is seen on the debugs in the WLC 9800, in particular the messages showing 'failed decrypt':
Aug 16 15:26:44.766: RADIUS/ENCODE: Best Local IP-Address 5.5.5.5 for Radius-Server 1.1.1.1
Aug 16 15:26:44.766: RADIUS: nas-port-id(87) is not found in the request
Aug 16 15:26:44.766: RADIUS(00000000): Send Access-Request to 1.1.1.1:1812 id 1645/185, len 51 <<<<<<<<<<<<<<<<<<<<<<<<<<
RADIUS: authenticator 7F F7 8B 1D 9E CB 45 83 - CB CB 2F 4D 9F CC 0F 2A
Aug 16 15:26:44.766: RADIUS: User-Password [2] 18 *
Aug 16 15:26:44.766: RADIUS: User-Name [1] 7 "cisco"
Aug 16 15:26:44.767: RADIUS: NAS-IP-Address [4] 6 5.5.5.5
Aug 16 15:26:44.767: RADIUS(00000000): Sending a IPv4 Radius Packet
Aug 16 15:26:44.767: RADIUS(00000000): Started 3 sec timeout
Aug 16 15:26:44.767: RADIUS/ENCODE: Best Local IP-Address 5.5.5.5 for Radius-Server 1.1.1.1
Aug 16 15:26:44.767: RADIUS(00000000): Send Accounting-Request to 1.1.1.1:1813 id 1646/23, len 67
RADIUS: authenticator AC B0 90 08 AA 74 3E 93 - 5B F9 E4 48 98 DE 74 F9
Aug 16 15:26:44.767: RADIUS: User-Name [1] 7 "cisco"
Aug 16 15:26:44.767: RADIUS: Acct-Status-Type [40] 6 Watchdog [3]
Aug 16 15:26:44.767: RADIUS: Acct-Session-Id [44] 10 "00000000"
Aug 16 15:26:44.768: RADIUS: Acct-Authentic [45] 6 RADIUS [1]
Aug 16 15:26:44.768: RADIUS: Service-Type [6] 6 Framed [2]
Aug 16 15:26:44.768: RADIUS: NAS-IP-Address [4] 6 5.5.5.5
Aug 16 15:26:44.768: RADIUS: Acct-Delay-Time [41] 6 0
Aug 16 15:26:44.768: RADIUS(00000000): Sending a IPv4 Radius Packet
Aug 16 15:26:44.768: RADIUS(00000000): Started 3 sec timeout
Aug 16 15:26:44.780: RADIUS: Received from id 1645/185 1.1.1.1:1812, Access-Reject, len 20 <<<<<<<<<<<<<<<<<<<<<<<<<<
RADIUS: authenticator 66 F1 3A 70 95 36 EB 13 - 7C 8B 54 97 3F 5F CF 7D
Aug 16 15:26:44.780: RADIUS: response-authenticator decrypt fail, pak len 20 <<<<<<<<<<<<<<<<<<<<<<<<<<
Aug 16 15:26:44.780: RADIUS: packet dump: 03B9001466F13A709536EB137C8B54973F5FCF7D
Aug 16 15:26:44.781: RADIUS: expected digest: FFFFFFA87AFFFFFFAF4D426154FFFFFFA6FFFFFFE8033FFFFFFFE0012C7575
Aug 16 15:26:44.782: RADIUS: response authen: 66FFFFFFF13A70FFFFFF9536FFFFFFEB137CFFFFFF8B54FFFFFF973F5FFFFFFFCF7D
Aug 16 15:26:44.782: RADIUS: request authen: 7FF78B1D9ECB4583CBCB2F4D9FCC0F2A
Aug 16 15:26:44.783: RADIUS: Response (185) failed decrypt <<<<<<<<<<<<<<<<<<<<<<<<<<
Aug 16 15:26:47.808: RADIUS(00000000): Request timed out!
Aug 16 15:26:47.808: RADIUS: Retransmit to (1.1.1.1:1812,1813) for id 1645/185
RADIUS: authenticator 7F F7 8B 1D 9E CB 45 83 - CB CB 2F 4D 9F CC 0F 2A
Aug 16 15:26:47.809: RADIUS: User-Password [2] 18 *
Aug 16 15:26:47.809: RADIUS: User-Name [1] 7 "cisco"
Aug 16 15:26:47.809: RADIUS: NAS-IP-Address [4] 6 5.5.5.5
Aug 16 15:26:47.809: RADIUS(00000000): Started 3 sec timeout
Aug 16 15:26:47.809: RADIUS(00000000): Request timed out! <<<<<<<<<<<<<<<<<<<<<<<<<<
Aug 16 15:26:47.809: RADIUS: acct-timeout for 7F7CA594150C now 3, acct-jitter 0, acct-delay-time (at 7F7CA594155B) now 3
Aug 16 15:26:47.809: RADIUS: Retransmit to (1.1.1.1:1812,1813) for id 1646/24
RADIUS: authenticator 30 51 BC 29 29 DE 99 B5 - 9C C8 8E B8 6C 32 3A 65
Aug 16 15:26:47.809: RADIUS: User-Name [1] 7 "cisco"
Aug 16 15:26:47.809: RADIUS: Acct-Status-Type [40] 6 Watchdog [3]
Aug 16 15:26:47.809: RADIUS: Acct-Session-Id [44] 10 "00000000"
Aug 16 15:26:47.809: RADIUS: Acct-Authentic [45] 6 RADIUS [1]
Aug 16 15:26:47.810: RADIUS: Service-Type [6] 6 Framed [2]
Aug 16 15:26:47.810: RADIUS: NAS-IP-Address [4] 6 5.5.5.5
Aug 16 15:26:47.810: RADIUS: Acct-Delay-Time [41] 6 3
Aug 16 15:26:47.810: RADIUS(00000000): Started 3 sec timeout
Aug 16 15:26:47.820: RADIUS: Received from id 1645/185 1.1.1.1:1812, Access-Reject, len 20 <<<<<<<<<<<<<<<<<<<<<<<<<<
RADIUS: authenticator 66 F1 3A 70 95 36 EB 13 - 7C 8B 54 97 3F 5F CF 7D
Aug 16 15:26:47.820: RADIUS: response-authenticator decrypt fail, pak len 20 <<<<<<<<<<<<<<<<<<<<<<<<<<
Aug 16 15:26:47.820: RADIUS: packet dump: 03B9001466F13A709536EB137C8B54973F5FCF7D
Aug 16 15:26:47.821: RADIUS: expected digest: FFFFFFA87AFFFFFFAF4D426154FFFFFFA6FFFFFFE8033FFFFFFFE0012C7575
Aug 16 15:26:47.821: RADIUS: response authen: 66FFFFFFF13A70FFFFFF9536FFFFFFEB137CFFFFFF8B54FFFFFF973F5FFFFFFFCF7D
Aug 16 15:26:47.821: RADIUS: request authen: 7FF78B1D9ECB4583CBCB2F4D9FCC0F2A
Aug 16 15:26:47.821: RADIUS: Response (185) failed decrypt
And even though the logs show that a 'Access-Reject' was received, the counters in 'show aaa servers' does not register this:
RADIUS: id 4, priority 1, host 1.1.1.1, auth-port 1812, acct-port 1813, hostname 1_1.1.1.1
State: current DEAD, duration 470s, previous duration 7999s <<<<<<<<<<<<<<<<<<< DEAD
Dead: total time 470s, count 1
Platform State from SMD: current UP, duration 8469s, previous duration 0s
SMD Platform Dead: total time 0s, count 0
Platform State from WNCD (1) : current DEAD <<<<<<<<<<<<<<<<<<<
Platform State from WNCD (2) : current UP
Platform State from WNCD (3) : current UP
Platform State from WNCD (4) : current UP
Platform State from WNCD (5) : current UP
Platform State from WNCD (6) : current UP
Platform State from WNCD (7) : current UP
Platform State from WNCD (8) : current UP, duration 270299s, previous duration 6038s
Platform Dead: total time 270299s, count 1
Quarantined: No
Authen: request 128, timeouts 127, failover 0, retransmission 86 <<<<<<<<<<<<<<<<<<<
Response: accept 0, reject 0, challenge 0
Response: unexpected 0, server error 0, incorrect 127, time 0ms <<<<<<<<<<<<<<<<<<<
Transaction: success 0, failure 41 <<<<<<<<<<<<<<<<<<<
Throttled: transaction 0, timeout 0, failure 0
Malformed responses: 0
Bad authenticators: 112
Author: request 6, timeouts 6, failover 1, retransmission 4
Response: accept 0, reject 0, challenge 0
Response: unexpected 0, server error 0, incorrect 0, time 0ms
Transaction: success 0, failure 2
Throttled: transaction 0, timeout 0, failure 0
Malformed responses: 0
Bad authenticators: 0
Account: request 23, timeouts 23, failover 0, retransmission 16
Request: start 0, interim 0, stop 0
Response: start 0, interim 0, stop 0
Response: unexpected 0, server error 0, incorrect 0, time 0ms
Transaction: success 0, failure 7
Throttled: transaction 0, timeout 0, failure 0
Malformed responses: 0
Bad authenticators: 0
Elapsed time since counters last cleared: 2h21m
Estimated Outstanding Access Transactions: 1
Estimated Outstanding Accounting Transactions: 0
Estimated Throttled Access Transactions: 0
Estimated Throttled Accounting Transactions: 0
Maximum Throttled Transactions: access 0, accounting 0
Consecutive Response Failures: total 48
SMD Platform : max 0, current 0 total 0
WNCD Platform: max 35, current 35 total 35
IOSD Platform : max 13, current 13 total 13
Consecutive Timeouts: total 154
SMD Platform : max 0, current 0 total 0
WNCD Platform: max 109, current 109 total 109
IOSD Platform : max 45, current 45 total 45
Requests per minute past 24 hours:
high - 0 hours, 8 minutes ago: 10
low - 2 hours, 21 minutes ago: 0
average: 0
Any ideas on how I can understand what's causing this mismatch and not registering the Radius messages as 'Reject'? As I understand, the automate-tester command will mark a Radius server UP when an Access-Reject is received as it's looking for any type of Radius response. However in this scenario, it doesn't register the responses properly and is marking the WLC 9800 as down..
