How To
ForgeRock Identity Platform
Does not apply to Identity Cloud

How do I enable message level debugging for the RADIUS server in AM 6.x?

Last updated Jan 12, 2023

The purpose of this article is to provide information on enabling message level debugging for the Remote Authentication Dial-In User Service (RADIUS) server service in AM.

1 reader recommends this article
Note

This article does not apply to AM 7 and later, because AM 7 and later uses Logback for configuring debug logging. See Debug Logging for further information.

Enabling message level debugging

The Radius debug log shows all messages related to the RADIUS server service, specifically for the amRadiusCommon and amRadiusServer instances. You can enable message level debugging for all logs as described in How do I enable Message level debugging in AM 6.x debug files? or you can just set it for the RADIUS server as follows:

  1. Log into AM as the admin user (called amadmin by default).
  2. Navigate to: <protocol>://host.fqdn:port/am/Debug.jsp, for example: https://am.example.com:8443/am/Debug.jsp.
  3. Select Radius from the Category field.
  4. Select Message from the Level field and click Submit to change the debug level.
Note

The Debug.jsp page always shows the debug level as Error, regardless of its actual setting.

The Radius debug log is located in the /path/to/am/debug directory by default.

Once you have reproduced the problem and captured the debug logs, you should revert the debug level to Error to avoid filling up the disks where the debug logs are stored.

Debug logs for a working RADIUS server

The following log shows a successful configuration of the RADIUS Server Service for comparison purposes: See The RADIUS Server Service

amRadiusServer:08/23/2016 10:06:17:581 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetReceived() called by EventBus amRadiusServer:08/23/2016 10:06:17:583 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetReceived() - total now 1 amRadiusServer:08/23/2016 10:06:17:584 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] WARNING: No Defined RADIUS Client matches IP address /127.0.0.1. Dropping request. amRadiusServer:08/23/2016 10:16:25:817 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-247] Entering globalConfigChange() amRadiusServer:08/23/2016 10:16:25:818 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-247] Leaving globalConfigChange() amRadiusServer:08/23/2016 10:16:25:818 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Exiting ConfigChangeListener.waitForConfigChange, returning RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:25:831 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-247] Entering globalConfigChange() amRadiusServer:08/23/2016 10:16:25:831 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-247] Leaving globalConfigChange() amRadiusServer:08/23/2016 10:16:25:839 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-244] Entering globalConfigChange() amRadiusServer:08/23/2016 10:16:25:840 AM PDT: Thread[smIdmThreadPool,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-244] Leaving globalConfigChange() amRadiusServer:08/23/2016 10:16:26:820 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:26:840 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] New RADIUS configuration loaded.[RadiusServiceConfig YES 1812 P( 1, 10, 10, 20), C( /127.0.0.1=RadiusTestServer, letmein, true, org.forgerock.openam.radius.server.spi .handlers.OpenAMAuthHandler, {realm=/, chain=ldapService})] amRadiusServer:08/23/2016 10:16:26:840 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Updating client configs. amRadiusServer:08/23/2016 10:16:26:840 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Entering ConfigChangeListener.waitForConfigChange() amRadiusServer:08/23/2016 10:16:26:840 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Exiting ConfigChangeListener.waitForConfigChange, returning RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:27:841 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:27:842 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] New RADIUS configuration loaded.[RadiusServiceConfig YES 1812 P( 1, 10, 10, 20), C( /127.0.0.1=RadiusTestServer, letmein, true, org.forgerock.openam.radius.server.spi .handlers.OpenAMAuthHandler, {realm=/, chain=ldapService})] amRadiusServer:08/23/2016 10:16:27:842 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Updating client configs. amRadiusServer:08/23/2016 10:16:27:842 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Entering ConfigChangeListener.waitForConfigChange() amRadiusServer:08/23/2016 10:16:27:842 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Exiting ConfigChangeListener.waitForConfigChange, returning RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:28:843 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] RADIUS Config Changed. Loading... amRadiusServer:08/23/2016 10:16:28:844 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] New RADIUS configuration loaded.[RadiusServiceConfig YES 1812 P( 1, 10, 10, 20), C( /127.0.0.1=RadiusTestServer, letmein, true, org.forgerock.openam.radius.server.spi .handlers.OpenAMAuthHandler, {realm=/, chain=ldapService})] amRadiusServer:08/23/2016 10:16:28:844 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Updating client configs. amRadiusServer:08/23/2016 10:16:28:844 AM PDT: Thread[RADIUS-RadiusServerManager,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-33] Entering ConfigChangeListener.waitForConfigChange()

The following log shows a successful authentication attempt by the RADIUS client:

Log Packet Contents for this Client is enabled so that the contents of the packets are logged to the Radius debug log.

amRadiusServer:08/23/2016 10:19:34:958 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving RadiusRequestHandler.getValidPacket() amRadiusServer:08/23/2016 10:19:34:958 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering RadiusRequestHandler.getAccessRequestHandler() amRadiusServer:08/23/2016 10:19:34:959 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving RadiusRequestHandler.getAccessRequestHandler() amRadiusServer:08/23/2016 10:19:34:960 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Constructing RadiusResponse.RadiusResponse() amRadiusServer:08/23/2016 10:19:34:960 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering OpenAMAuthHandler.handle amRadiusServer:08/23/2016 10:19:34:961 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Constructed AuthRequestReceivedEvent.AuthRequestReceivedEvent() amRadiusServer:08/23/2016 10:19:34:961 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetAccepted() called by EventBus amRadiusServer:08/23/2016 10:19:34:962 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetAccepted() - total now 1 amRadiusServer:08/23/2016 10:19:34:962 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering OpenAMAuthHandler.startAuthProcess amRadiusServer:08/23/2016 10:19:35:002 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving OpenAMAuthHandler.startAuthProcess amRadiusServer:08/23/2016 10:19:35:002 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering gatherUserInput(); amRadiusServer:08/23/2016 10:19:35:002 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] --- callbacks == null in gatherUserInput amRadiusServer:08/23/2016 10:19:35:002 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] --- NextCallbackSet not-available in gatherUserInput - move to finalization amRadiusServer:08/23/2016 10:19:35:002 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering OpenAMAuthHandler.finalizeAuthProcess() amRadiusServer:08/23/2016 10:19:35:003 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering ContextHolder.getUniversalId() amRadiusServer:08/23/2016 10:19:35:003 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving ContextHolder.getUniversalId() amRadiusServer:08/23/2016 10:19:35:005 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving OpenAMAuthHandler.handle(); amRadiusServer:08/23/2016 10:19:35:005 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Entering RadiusRequestHandler.postHandledEvent() amRadiusServer:08/23/2016 10:19:35:006 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Constructed AuthRequestAcceptedEvent.AuthRequestAcceptedEvent() amRadiusServer:08/23/2016 10:19:35:006 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.authRequestAccepted() called by EventBus amRadiusServer:08/23/2016 10:19:35:006 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] ID: 1497378375RadiusServerEventRegistrar.authRequestAccepted() - incrementing. Total accepted 1 amRadiusServer:08/23/2016 10:19:35:006 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Leaving RadiusRequestHandler.postHandledEvent() amRadiusServer:08/23/2016 10:19:35:007 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] WARNING: Packet to RadiusTestServer: ACCESS_ACCEPT [1] amRadiusServer:08/23/2016 10:19:35:007 AM PDT: Thread[pool-11-thread-1,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Sending response of type ACCESS_ACCEPT to RadiusTestServer amRadiusServer:08/23/2016 10:19:35:009 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] Constructing PacketProcessedEvent.PacketProcessedEvent() amRadiusServer:08/23/2016 10:19:35:009 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetProcessed() called by EventBus amRadiusServer:08/23/2016 10:19:35:009 AM PDT: Thread[RADIUS-1812-Listener,5,main]: TransactionId[4dcc2bd6-f055-4ae9-a68d-ea037341fc3e-657] RadiusServerEventRegistrar.packetProcessed() - total now 1

See Also

OTP based authentication modules prompt user twice when using RADIUS server with AM (All versions)

How do I record troubleshooting information in AM (All versions)?

Troubleshooting the RADIUS Server Service

Related Training

N/A

Related Issue Tracker IDs

N/A
Copyright and Trademarks Copyright © 2023 ForgeRock, all rights reserved.