Unusal IP address is seen in the RADIUS log file in RSA Authentication Manager 8.x

[#1]

Article Number

000031672

Applies To

RSA Product Set: SecurID
RSA Product/Service Type: Authentication Manager
RSA Version/Condition: 8.x

Issue

An administrator is seeing an unusual IP address in the RADIUS log file.  For example:

11/05/2015 11:32:12 Sent accept response for user rsatest to client 192.168.1.10

Cause

RADIUS clients can send RADIUS authentication packets with a RADIUS attribute called NAS-IP-Address (where the address field is four octets; i.e., an IP address).

Per RFC-2865, the RADIUS attribute NAS-IP-Address indicates the identifying IP address of the Network Access Server (NAS) which is requesting authentication of the user, and SHOULD be unique to the NAS within the scope of the RADIUS server. The NAS-IP-Address attribute is only used in Access-Request packets (either the NAS-IP-Address or NAS-Identifier MUST be present in an Access-Request packet).

RSA RADIUS is taking the NAS-IP-Address attribute and performing a RADIUS client lookup in the Authentication Manager database and where it cannot find a RADIUS client name it uses the IP address in the accept response, hence the IP address being seen in the RADIUS log file.

Resolution

Further investigation can be performed by enabling RADIUS debug on the RSA RADIUS server (debug instructions provided below).

This debug will generate a breakdown of the RADIUS authentication packet, showing the incoming source IP address of the Network Access Server (NAS) and the NAS-IP-Address attribute and its value as well as the RADIUS client lookup performed by the RSA RADIUS.

In the example here, a debug of a single RADIUS authentication and authentication response from RSA RADIUS:

11/05/2015 12:18:28 -----------------------------------------------------------
11/05/2015 12:18:28 Authentication Request
11/05/2015 12:18:28 Received from: ip=192.168.40.240 port=63897
11/05/2015 12:18:28
11/05/2015 12:18:28 Raw Packet :
11/05/2015 12:18:28 000: 010c0035 20202020 20203134 34363638 |...5      144668|
11/05/2015 12:18:28 010: 36333038 01097273 61746573 74021268 |6308..rsatest..h|
11/05/2015 12:18:28 020: 52e08258 d9163fc8 4b56d651 dd106004 |R..X..?.KV.Q..`.|
11/05/2015 12:18:28 030: 06c0a801 0a                         |.....           |
11/05/2015 12:18:28
11/05/2015 12:18:28 -----------------------------------------------------------
11/05/2015 12:18:28 ../radauthd.c radAuthHandleRequest() 3057 Entering
11/05/2015 12:18:28 Looking up shared secret
11/05/2015 12:18:28 Looking for RAS client 192.168.40.240 in DB
11/05/2015 12:18:28 Matched 192.168.40.240 to RAS client RADIUS-CLIENT
11/05/2015 12:18:28 Parsing request
11/05/2015 12:18:28 Initializing cache entry
11/05/2015 12:18:28 Doing inventory check on request
11/05/2015 12:18:28 Getting info on requesting client
11/05/2015 12:18:28 NAS-IP-Address in request: 192.168.1.10
11/05/2015 12:18:28 Looking for RAS client 192.168.1.10 in DB
11/05/2015 12:18:28 -----------------------------------------------------------
11/05/2015 12:18:28 Authentication Request
11/05/2015 12:18:28 Received From: ip=192.168.40.240 port=63897
11/05/2015 12:18:28 Packet : Code = 0x1 ID = 0xc
11/05/2015 12:18:28 Client Name = 192.168.1.10 Dictionary Name = Radius.dct
11/05/2015 12:18:28 Vector =
11/05/2015 12:18:28 000: 20202020 20203134 34363638 36333038 |      1446686308|
11/05/2015 12:18:28 Parsed Packet =
11/05/2015 12:18:28 User-Name : String Value = rsatest
11/05/2015 12:18:28 User-Password : Value =
11/05/2015 12:18:28 000: 6852e082 58d9163f c84b56d6 51dd1060 |hR..X..?.KV.Q..`|
11/05/2015 12:18:28 NAS-IP-Address : IPAddress = 192.168.1.10
11/05/2015 12:18:28 -----------------------------------------------------------
11/05/2015 12:18:28 Determining user class
11/05/2015 12:18:28 Authenticating user rsatest with authentication method SecurID
11/05/2015 12:18:28 Beginning instance of SecurID authentication
11/05/2015 12:18:28 Performing SecurID user authentication for DEFAULT (rsatest)
11/05/2015 12:18:29 SecurID profile DEFAULT for user rsatest success
11/05/2015 12:18:29 SecurID authentication for user rsatest success
11/05/2015 12:18:29 Terminated instance of SecurID authentication
11/05/2015 12:18:29 Determined that rsatest authenticated by plug-in module is the user
11/05/2015 12:18:29 Getting profile info for requesting user
11/05/2015 12:18:29 Merging saved attributes with user info
11/05/2015 12:18:29 Merging profile info with user info
11/05/2015 12:18:29 Comparing checklist items with user/profile items
11/05/2015 12:18:29 Appending echo values, if any
11/05/2015 12:18:29 User RSATEST being passed to attribute editing authentication methods
11/05/2015 12:18:29 Class subattribute: DistName : String Value = rsatest
11/05/2015 12:18:29 Class subattribute: AuthType : String Value = 18
11/05/2015 12:18:29 Class subattribute: TransactionId : Value =
11/05/2015 12:18:29 000: 58fe4319 365fce4b 00000001          |X.C.6_.K....    |
11/05/2015 12:18:29 Sent accept response for user rsatest to client 192.168.1.10
11/05/2015 12:18:29 -----------------------------------------------------------
11/05/2015 12:18:29 Authentication Response
11/05/2015 12:18:29 Packet : Code = 0x2 ID = 0xc
11/05/2015 12:18:29 Vector =
11/05/2015 12:18:29 000: 17eba818 4d85e316 d4eb2206 c9f2234f |....M....."...#O|
11/05/2015 12:18:29 Class : Value =
11/05/2015 12:18:29 000: 53425232 434cacbf c8b1c9d9 bfcea5c0 |SBR2CL..........|
11/05/2015 12:18:29 010: 11802501 80038198 ce800280 0881b99c |..%.............|
11/05/2015 12:18:29 020: ec97a395 e6f41280 0e81acbf c8b1c9d9 |................|
11/05/2015 12:18:29 030: bfcea5c0 80808084                   |........        |
11/05/2015 12:18:29 -----------------------------------------------------------
11/05/2015 12:18:29 -----------------------------------------------------------
11/05/2015 12:18:29 Authentication Response
11/05/2015 12:18:29 Sent to: ip=192.168.40.240 port=63897
11/05/2015 12:18:29
11/05/2015 12:18:29 Raw Packet :
11/05/2015 12:18:29 000: 020c004e 17eba818 4d85e316 d4eb2206 |...N....M.....".|
11/05/2015 12:18:29 010: c9f2234f 193a5342 5232434c acbfc8b1 |..#O.:SBR2CL....|
11/05/2015 12:18:29 020: c9d9bfce a5c01180 25018003 8198ce80 |........%.......|
11/05/2015 12:18:29 030: 02800881 b99cec97 a395e6f4 12800e81 |................|
11/05/2015 12:18:29 040: acbfc8b1 c9d9bfce a5c08080 8084     |..............  |
11/05/2015 12:18:29
11/05/2015 12:18:29 -----------------------------------------------------------
11/05/2015 12:18:29 Packet containing 78 bytes successfully sent
11/05/2015 12:18:29 ../radauthd.c radAuthHandleRequest() 3812 Exiting

From the trace we see the following:

• The authentication request came from a NAS with IP address 192.168.40.240.
• RSA RADIUS matched IP address 192.168.40.240 to a RADIUS client called RADIUS-CLIENT (in the database)
• A NAS-IP-Address attribute with IP address 192.168.1.10 was found in the authentication request and RSA RADIUS performs a lookup in the database (no RADIUS client found).
• RSA RADIUS and the Authentication Manager instance process the authentication request.
• The RADIUS log file shows an accept response sent to client 192.168.1.10; however, the authentication response was sent to 192.168.40.240.

An administrator could check the RADIUS client configuration to determine why the NAS-IP-Address is different from the source IP address. It may be possible that RADIUS client is part of a cluster or has multiple network card interfaces with different IP addresses configured where one of the other IP addresses was set for the NAS-IP-Address.

Should you need to ensure the source IP address in the authentication request matches the IP address set for the NAS-IP-Address RADIUS attribute then please contact the vendor of the RADIUS client for assistance in reviewing the RADIUS client configuration.
 

Enabling RADIUS debug on the RSA RADIUS server  

See 000012942 - Enable RADIUS debug/verbose logs with RSA Authentication Manager 8.x.

The RSA RADIUS log files are located in /opt/rsa/am/radius. The log files are named yyyymmdd.log, where the file name is the date it was created.  If today's date is 10 November 2015, then the log file would be called named 20151110.log.
 

In a large deployment of RSA Authentication Manager, these RADIUS log files can grow quite large.  Remember to change the LogLevel and TraceLevel value back to 0 in the radius.ini file, then stop and start the RSA RADIUS server to turn off the RADIUS enhanced logging and tracing.