By: Monika Leung user 13 Jan 2023 at 6:56 a.m. CST

2 Responses
Monika Leung gravatar
Hello, I have an issue where gluu-radius is only able to process the first authentication request after the service is started or restarted (with `systemctl restart gluu-radius`). All subsequent authentication requests are rejected even if the password is correct. I also noticed that it doesn't matter if the first authentication was successful or not. Below are the logs from `gluu-radius.log` for the second request, which is always rejected (I have removed some user info and IPs). There are some warnings about expired keys, but I don't think they cause the issue, since gluu-radius had been working fine before even with the warnings. (I would be happy to renew the keys, but I can't find out how.) Not sure if it is related, but we upgraded Gluu from version 4.2.3 to 4.3.1 (with the `upg4xto431.py` script). Unfortunately, I can't remember if this behaviour started immediately after the upgrade or later. Any idea how to solve this? ``` [INFO ] 2023-01-13 12:26:33.082 [Radius Auth Listener] RadiusServer - received packet from /<CLIENT_IP>:58885 on local address 0.0.0.0/0.0.0.0:1812: Access-Request, ID 37 User-Name: <USERNAME> User-Password: <PASSWORD> [DEBUG] 2023-01-13 12:26:33.085 [Radius Auth Listener] SuperGluuAccessRequestFilter - Performing one-step authentication for user {<USERNAME>} [WARN ] 2023-01-13 12:26:33.238 [Radius Auth Listener] AbstractCryptoProvider - WARNING! Expired Key is used, alias: 8204a6e8-0e89-4a5c-82ab-29d69078aea2_sig_rs512 Expires On: 2022-03-12 12:35:20 Today's Date: 2023-01-13 12:26:33 [WARN ] 2023-01-13 12:26:33.362 [Finalizer] i18n - RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself. [DEBUG] 2023-01-13 12:26:33.362 [Finalizer] PoolingHttpClientConnectionManager - Connection manager is shutting down [DEBUG] 2023-01-13 12:26:33.370 [Finalizer] DefaultManagedHttpClientConnection - http-outgoing-0: Close connection [DEBUG] 2023-01-13 12:26:33.371 [Finalizer] PoolingHttpClientConnectionManager - Connection manager shut down [WARN ] 2023-01-13 12:26:33.371 [Finalizer] i18n - RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself. [DEBUG] 2023-01-13 12:26:33.371 [Finalizer] PoolingHttpClientConnectionManager - Connection manager is shutting down [DEBUG] 2023-01-13 12:26:33.371 [Finalizer] DefaultManagedHttpClientConnection - http-outgoing-2: Close connection [DEBUG] 2023-01-13 12:26:33.375 [Finalizer] PoolingHttpClientConnectionManager - Connection manager shut down [WARN ] 2023-01-13 12:26:33.375 [Finalizer] i18n - RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself. [DEBUG] 2023-01-13 12:26:33.375 [Finalizer] PoolingHttpClientConnectionManager - Connection manager is shutting down [DEBUG] 2023-01-13 12:26:33.375 [Finalizer] DefaultManagedHttpClientConnection - http-outgoing-1: Close connection [DEBUG] 2023-01-13 12:26:33.378 [Finalizer] PoolingHttpClientConnectionManager - Connection manager shut down [WARN ] 2023-01-13 12:26:33.379 [Finalizer] i18n - RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself. [WARN ] 2023-01-13 12:26:33.400 [Radius Auth Listener] AbstractCryptoProvider - WARNING! Expired Key is used, alias: 8204a6e8-0e89-4a5c-82ab-29d69078aea2_sig_rs512 Expires On: 2022-03-12 12:35:20 Today's Date: 2023-01-13 12:26:33 [DEBUG] 2023-01-13 12:26:33.420 [Radius Auth Listener] i18n - Interceptor Context: org.jboss.resteasy.core.interception.jaxrs.ClientWriterInterceptorContext, Method : proceed [DEBUG] 2023-01-13 12:26:33.420 [Radius Auth Listener] i18n - MessageBodyWriter: org.jboss.resteasy.core.providerfactory.SortedKey [DEBUG] 2023-01-13 12:26:33.420 [Radius Auth Listener] i18n - MessageBodyWriter: org.jboss.resteasy.plugins.providers.JaxrsFormProvider [DEBUG] 2023-01-13 12:26:33.420 [Radius Auth Listener] i18n - Provider : org.jboss.resteasy.plugins.providers.JaxrsFormProvider, Method : writeTo [DEBUG] 2023-01-13 12:26:33.420 [Radius Auth Listener] i18n - Provider : org.jboss.resteasy.plugins.providers.FormUrlEncodedProvider, Method : writeTo [DEBUG] 2023-01-13 12:26:33.421 [Radius Auth Listener] RequestAddCookies - CookieSpec selected: default [DEBUG] 2023-01-13 12:26:33.421 [Radius Auth Listener] RequestAuthCache - Auth cache not set in the context [DEBUG] 2023-01-13 12:26:33.421 [Radius Auth Listener] PoolingHttpClientConnectionManager - Connection request: [route: {s}->https://<GLUU_HOSTNAME>:443][total available: 0; route allocated: 0 of 20; total allocated: 0 of 100] [DEBUG] 2023-01-13 12:26:33.422 [Radius Auth Listener] i18n - RESTEASY004672: Client send processing failure. java.lang.IllegalStateException: Connection pool shut down at org.apache.http.util.Asserts.check(Asserts.java:34) ~[httpcore-4.4.14.jar:4.4.14] at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:269) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:176) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.13.jar:4.5.13] at org.jboss.resteasy.client.jaxrs.engines.ManualClosingApacheHttpClient43Engine.invoke(ManualClosingApacheHttpClient43Engine.java:268) [resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:488) [resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:65) [resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.gluu.oxauth.client.TokenClient.exec(TokenClient.java:270) [oxauth-client-4.3.1.Final.jar:?] at org.gluu.oxauth.client.supergluu.SuperGluuAuthClient.initiateAuthentication(SuperGluuAuthClient.java:110) [supergluu-auth-client-4.3.1.Final.jar:?] at org.gluu.radius.server.filter.SuperGluuAccessRequestFilter.performOneStepAuth(SuperGluuAccessRequestFilter.java:61) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.filter.SuperGluuAccessRequestFilter.processAccessRequest(SuperGluuAccessRequestFilter.java:40) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.GluuRadiusServer.onAccessRequest(GluuRadiusServer.java:86) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.RadiusEventListenerManager.accessRequestNotification(RadiusEventListenerManager.java:35) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.tinyradius.TinyRadiusServerAdapter$TinyRadiusServerImpl.accessRequestReceived(TinyRadiusServerAdapter.java:55) [super-gluu-radius-server.jar:?] at org.tinyradius.util.RadiusServer.handlePacket(RadiusServer.java:374) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer.listen(RadiusServer.java:334) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer.listenAuth(RadiusServer.java:277) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer$1.run(RadiusServer.java:103) [tinyradius-1.0.jar:?] [ERROR] 2023-01-13 12:26:33.431 [Radius Auth Listener] TokenClient - RESTEASY004655: Unable to invoke request: java.lang.IllegalStateException: Connection pool shut down javax.ws.rs.ProcessingException: RESTEASY004655: Unable to invoke request: java.lang.IllegalStateException: Connection pool shut down at org.jboss.resteasy.client.jaxrs.engines.ManualClosingApacheHttpClient43Engine.invoke(ManualClosingApacheHttpClient43Engine.java:287) ~[resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:488) ~[resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:65) ~[resteasy-client-4.5.7.Final.jar:4.5.7.Final] at org.gluu.oxauth.client.TokenClient.exec(TokenClient.java:270) [oxauth-client-4.3.1.Final.jar:?] at org.gluu.oxauth.client.supergluu.SuperGluuAuthClient.initiateAuthentication(SuperGluuAuthClient.java:110) [supergluu-auth-client-4.3.1.Final.jar:?] at org.gluu.radius.server.filter.SuperGluuAccessRequestFilter.performOneStepAuth(SuperGluuAccessRequestFilter.java:61) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.filter.SuperGluuAccessRequestFilter.processAccessRequest(SuperGluuAccessRequestFilter.java:40) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.GluuRadiusServer.onAccessRequest(GluuRadiusServer.java:86) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.RadiusEventListenerManager.accessRequestNotification(RadiusEventListenerManager.java:35) [super-gluu-radius-server.jar:?] at org.gluu.radius.server.tinyradius.TinyRadiusServerAdapter$TinyRadiusServerImpl.accessRequestReceived(TinyRadiusServerAdapter.java:55) [super-gluu-radius-server.jar:?] at org.tinyradius.util.RadiusServer.handlePacket(RadiusServer.java:374) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer.listen(RadiusServer.java:334) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer.listenAuth(RadiusServer.java:277) [tinyradius-1.0.jar:?] at org.tinyradius.util.RadiusServer$1.run(RadiusServer.java:103) [tinyradius-1.0.jar:?] Caused by: java.lang.IllegalStateException: Connection pool shut down at org.apache.http.util.Asserts.check(Asserts.java:34) ~[httpcore-4.4.14.jar:4.4.14] at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:269) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:176) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.13.jar:4.5.13] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.13.jar:4.5.13] at org.jboss.resteasy.client.jaxrs.engines.ManualClosingApacheHttpClient43Engine.invoke(ManualClosingApacheHttpClient43Engine.java:268) ~[resteasy-client-4.5.7.Final.jar:4.5.7.Final] ... 13 more [DEBUG] 2023-01-13 12:26:33.432 [Radius Auth Listener] SuperGluuAuthClient - SuperGluu initial auth failed. No response [DEBUG] 2023-01-13 12:26:33.433 [Radius Auth Listener] SuperGluuAccessRequestFilter - Authentication failed for user {<USERNAME>} [INFO ] 2023-01-13 12:26:33.433 [Radius Auth Listener] RadiusServer - send response: Access-Reject, ID 37 ```

By Michael Schwartz Account Admin 13 Jan 2023 at 3:55 p.m. CST

Michael Schwartz gravatar
On Debian? We don't really support that. Also, this Radius component is not really that robust... it's mostly for testing. We recommend [Radiator](https://www.open.com.au/radiator/) for most deployments. They publish a script to call the Gluu Server for Super Gluu.

By Monika Leung user 18 Jan 2023 at 8:32 a.m. CST

Monika Leung gravatar
Yes, on Debian. I see, we will look into it. Thank you for the info!