OpenLiberty / open-liberty

Open Liberty is a highly composable, fast to start, dynamic application server runtime environment
https://openliberty.io
Eclipse Public License 2.0
1.14k stars 583 forks source link

CWWKS3005E message is displayed when external registry is used #15635

Open jpfloresibm opened 3 years ago

jpfloresibm commented 3 years ago

Describe the bug When using an external registry such as IAM the following wlp message is logged:

[ERROR   ] CWWKS3005E: A configuration exception has occurred. No UserRegistry implementation service is available.  Ensure that you have a user registry configured

A simple use case is using a custom TAI for authenticating users against an external registry such as IAM on cloud.

Steps to Reproduce Configure a custom TAI for authenticating users and do not configure an internal registry.

Expected behavior If custom authentication is configured then the CWWKS3005E error message should not be displayed.

Diagnostic information:

nadiramra commented 1 year ago

I am running 23.0.0.3. The problem persists. The essence of the problem is that Liberty should not be logging or issuing any messages or cutting FFDC logs unless it actually requires a registry in order to perform authentication.

In my case, I have an unprotected application that does its own authentication. A request comes in with Authorization header of Basic. The message is issued and FFDC is cut. Every request the comes in results in a message CWWKS3005E. This is not desirable and is very frustrating.

As a side note, if one adds <logging hideMessage=CWWKS3005E" />, the message is no longer logged to messages.log, instead, it gets logged to trace.log even though tracing is not active!

The class that needs to be updated is (at least that seems to be only class that issues the message): dev/com.ibm.ws.security.registry/src/com/ibm/ws/security/registry/internal/UserRegistryServiceImpl.java

and my guess is the users of this method:

public UserRegistry getUserRegistry() throws RegistryException {
    return determineActiveUserRegistry(true);
}

This method tells determineActiveUserRegistry to issue an exception. I think callers of this method should call isUserRegistryConfigured() and then do what is appropriate or change this method to have an input parameter of boolean and pass that to determineActiveUserRegistry(). Or add a method that does that.

And the ffdc stack trace is as follows:

com.ibm.ws.security.registry.RegistryException: CWWKS3005E: A configuration exception has occurred. No UserRegistry implementation service is available. Ensure that you have a user registry configured. at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.autoDetectUserRegistry(UserRegistryServiceImpl.java:414) at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.determineActiveUserRegistry(UserRegistryServiceImpl.java:368) at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.getUserRegistry(UserRegistryServiceImpl.java:387) at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.getUserRegistry(JAASServiceImpl.java:127) at com.ibm.ws.security.authentication.internal.jaas.modules.ServerCommonLoginModule.getUserRegistry(ServerCommonLoginModule.java:73) at com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule.login(UsernameAndPasswordLoginModule.java:77) at com.ibm.ws.kernel.boot.security.LoginModuleProxy.login(LoginModuleProxy.java:53) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755) at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) at javax.security.auth.login.LoginContext.login(LoginContext.java:587) at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.doLoginContext(JAASServiceImpl.java:369) at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.performLogin(JAASServiceImpl.java:355) at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.performLogin(JAASServiceImpl.java:340) at com.ibm.ws.security.authentication.internal.AuthenticationServiceImpl.performJAASLogin(AuthenticationServiceImpl.java:558) at com.ibm.ws.security.authentication.internal.AuthenticationServiceImpl.authenticate(AuthenticationServiceImpl.java:223) at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.basicAuthenticate(BasicAuthAuthenticator.java:130) at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.handleBasicAuth(BasicAuthAuthenticator.java:121) at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.authenticate(BasicAuthAuthenticator.java:74) at com.ibm.ws.webcontainer.security.WebAuthenticatorProxy.authenticate(WebAuthenticatorProxy.java:89) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.authenticateRequest(WebAppSecurityCollaboratorImpl.java:1243) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.setAuthenticatedSubjectIfNeeded(WebAppSecurityCollaboratorImpl.java:875) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.optionallyAuthenticateUnprotectedResource(WebAppSecurityCollaboratorImpl.java:832) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.determineWebReply(WebAppSecurityCollaboratorImpl.java:992) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.performSecurityChecks(WebAppSecurityCollaboratorImpl.java:698) at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.preInvoke(WebAppSecurityCollaboratorImpl.java:619) at com.ibm.wsspi.webcontainer.collaborator.CollaboratorHelper.preInvokeCollaborators(CollaboratorHelper.java:472) at com.ibm.ws.webcontainer.osgi.collaborator.CollaboratorHelperImpl.preInvokeCollaborators(CollaboratorHelperImpl.java:272) at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1220) at com.ibm.ws.webcontainer.webapp.WebApp.handleRequest(WebApp.java:5080) at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.handleRequest(DynamicVirtualHost.java:318) at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:1038) at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:283) at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1248) at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:470) at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:429) at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:569) at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:503) at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:363) at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:330) at com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:169) at com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:77) at com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:516) at com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:586) at com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:970) at com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1059) at com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:247) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)

vsmid commented 3 months ago

Describe the bug When not using user registry or with custom identity store implementation the following wlp message is logged:

[ERROR ] CWWKS3005E: A configuration exception has occurred. No UserRegistry implementation service is available. Ensure that you have a user registry configured

Steps to Reproduce For me it is happening on 24.0.0.2 version and for EAR deployment. I have a Servlet WEB module (with custom auth. implemented - not using container auth) and a Jakarta REST WEB module (with @BasicAuthenticationMechanismDefinition and a custom IdentityStore). The error happens for Servlet module only. The error persisted when I tried to add @BasicAuthenticationMechanismDefinition and a custom IdentityStore to the Servlet module.

Expected behavior If custom authentication is configured (or none at all) then the CWWKS3005E error message should not be displayed

Diagnostic information:

(Open Liberty 24.0.0.2/wlp-1.0.86.cl240220240212-1928) on Eclipse OpenJ9 VM, version 21.0.2+13-LTS (en_US)

server.xml

<?xml version="1.0" encoding="UTF-8"?>
<server description="Server">

    <featureManager>
        <feature>servlet-6.0</feature>
        <feature>restfulWS-3.1</feature>
        <feature>jsonb-3.0</feature>
        <feature>beanValidation-3.0</feature>
        <feature>mpConfig-3.1</feature>
        <feature>mpOpenAPI-3.1</feature>
        <feature>appSecurity-5.0</feature>
        <feature>appAuthentication-3.0</feature>
    </featureManager>

    <variable name="mp.openapi.extensions.liberty.merged.include" value="all"/>

    <httpEndpoint id="defaultHttpEndpoint" host="*"/>
    <applicationManager autoExpand="true"/>

    <enterpriseApplication id="server" location="app.ear" name="app">
        <classloader apiTypeVisibility="+third-party" commonLibraryRef="global"/>
    </enterpriseApplication>

    <library apiTypeVisibility="+third-party" id="global">
        <fileset dir="${shared.resource.dir}/lib/global" includes="*.jar"/>
    </library>

    <ssl id="defaultSSLConfig" trustDefaultCerts="true"/>
    <keyStore id="defaultKeyStore" password="******"/>
    <logging  consoleLogLevel="INFO" consoleFormat="SIMPLE"/>

</server>
-----Start of DE processing------ = [3/24/24, 8:24:58:962 UTC ]
Exception = com.ibm.ws.security.registry.RegistryException
Source = com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule
probeid = 116
Stack Dump = com.ibm.ws.security.registry.RegistryException: CWWKS3005E: A configuration exception has occurred. No UserRegistry implementation service is available.  Ensure that you have a user registry configured.
        at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.autoDetectUserRegistry(UserRegistryServiceImpl.java:414)
        at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.determineActiveUserRegistry(UserRegistryServiceImpl.java:368)
        at com.ibm.ws.security.registry.internal.UserRegistryServiceImpl.getUserRegistry(UserRegistryServiceImpl.java:387)
        at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.getUserRegistry(JAASServiceImpl.java:127)
        at com.ibm.ws.security.authentication.internal.jaas.modules.ServerCommonLoginModule.getUserRegistry(ServerCommonLoginModule.java:73)
        at com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule.login(UsernameAndPasswordLoginModule.java:77)
        at com.ibm.ws.kernel.boot.security.LoginModuleProxy.login(LoginModuleProxy.java:53)
        at java.base/javax.security.auth.login.LoginContext.invoke(Unknown Source)
        at java.base/javax.security.auth.login.LoginContext$4.run(Unknown Source)
        at java.base/javax.security.auth.login.LoginContext$4.run(Unknown Source)
        at java.base/java.security.AccessController.doPrivileged(Unknown Source)
        at java.base/javax.security.auth.login.LoginContext.invokePriv(Unknown Source)
        at java.base/javax.security.auth.login.LoginContext.login(Unknown Source)
        at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.doLoginContext(JAASServiceImpl.java:369)
        at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.performLogin(JAASServiceImpl.java:355)
        at com.ibm.ws.security.authentication.internal.jaas.JAASServiceImpl.performLogin(JAASServiceImpl.java:340)
        at com.ibm.ws.security.authentication.internal.AuthenticationServiceImpl.performJAASLogin(AuthenticationServiceImpl.java:558)
        at com.ibm.ws.security.authentication.internal.AuthenticationServiceImpl.authenticate(AuthenticationServiceImpl.java:223)
        at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.basicAuthenticate(BasicAuthAuthenticator.java:130)
        at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.handleBasicAuth(BasicAuthAuthenticator.java:121)
        at com.ibm.ws.webcontainer.security.internal.BasicAuthAuthenticator.authenticate(BasicAuthAuthenticator.java:74)
        at com.ibm.ws.webcontainer.security.WebAuthenticatorProxy.authenticate(WebAuthenticatorProxy.java:89)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.authenticateRequest(WebAppSecurityCollaboratorImpl.java:1239)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.setAuthenticatedSubjectIfNeeded(WebAppSecurityCollaboratorImpl.java:872)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.optionallyAuthenticateUnprotectedResource(WebAppSecurityCollaboratorImpl.java:829)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.determineWebReply(WebAppSecurityCollaboratorImpl.java:988)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.performSecurityChecks(WebAppSecurityCollaboratorImpl.java:695)
        at com.ibm.ws.webcontainer.security.WebAppSecurityCollaboratorImpl.preInvoke(WebAppSecurityCollaboratorImpl.java:622)
        at com.ibm.wsspi.webcontainer.collaborator.CollaboratorHelper.preInvokeCollaborators(CollaboratorHelper.java:472)
        at com.ibm.ws.webcontainer.osgi.collaborator.CollaboratorHelperImpl.preInvokeCollaborators(CollaboratorHelperImpl.java:290)
        at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1221)
        at com.ibm.ws.webcontainer.webapp.WebApp.handleRequest(WebApp.java:5076)
        at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.handleRequest(DynamicVirtualHost.java:328)
        at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:1038)
        at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:293)
        at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1260)
        at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:476)
        at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:435)
        at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:569)
        at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:503)
        at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:363)
        at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:330)
        at com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:169)
        at com.ibm.ws.tcpchannel.internal.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:77)
        at com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:516)
        at com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:586)
        at com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:970)
        at com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1059)
        at com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:280)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.base/java.lang.Thread.run(Unknown Source)

Dump of callerThis
Object type = com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule
  tc = class com.ibm.websphere.ras.TraceComponent@66c4354e
    strings[0] = "TraceComponent[com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule,class com.ibm.ws.security.authentication.jaas.modules.UsernameAndPasswordLoginModule,[Authentication],com.ibm.ws.security.authentication.internal.resources.AuthenticationMessages,null]"
  userRegistry = null
  username = null
  urAuthenticatedId = null
  serialVersionUID = -1034522143030294360
  tc = class com.ibm.websphere.ras.TraceComponent@ecf3fbb8
    strings[0] = "TraceComponent[com.ibm.ws.security.authentication.internal.jaas.modules.ServerCommonLoginModule,class com.ibm.ws.security.authentication.internal.jaas.modules.ServerCommonLoginModule,[Authentication],com.ibm.ws.security.authentication.internal.resources.AuthenticationMessages,null]"
  jsonWebTokenProperties = class java.lang.String[1]
    String[0] = "com.ibm.ws.authentication.internal.json.web.token"
  subjectHelper = class com.ibm.ws.security.authentication.utility.SubjectHelper@fc31f3ce
    tc = class com.ibm.websphere.ras.TraceComponent@25e299a
      strings[0] = "TraceComponent[com.ibm.ws.security.authentication.utility.SubjectHelper,class com.ibm.ws.security.authentication.utility.SubjectHelper,[],null,null]"
    serialVersionUID = -2679843572021519452
  userIdOnlyProperties = class java.lang.String[2]
    String[0] = "com.ibm.wsspi.security.cred.userId"
    String[1] = "com.ibm.ws.authentication.internal.assertion"
  customPropertiesFromSubject = false
  serialVersionUID = 2946373732615217215
  callbackHandler = class javax.security.auth.login.LoginContext$SecureCallbackHandler@19ba1031
    acc = "/* Could not access acc */"
    ch = "/* Could not access ch */"
  subject = class javax.security.auth.Subject@10767745
    serialVersionUID = "/* Could not access serialVersionUID */"
    principals = "/* Could not access principals */"
    pubCredentials = "/* Could not access pubCredentials */"
    privCredentials = "/* Could not access privCredentials */"
    readOnly = "/* Could not access readOnly */"
    PRINCIPAL_SET = "/* Could not access PRINCIPAL_SET */"
    PUB_CREDENTIAL_SET = "/* Could not access PUB_CREDENTIAL_SET */"
    PRIV_CREDENTIAL_SET = "/* Could not access PRIV_CREDENTIAL_SET */"
    NULL_PD_ARRAY = "/* Could not access NULL_PD_ARRAY */"
  sharedState = class java.util.HashMap@7c77b092
    serialVersionUID = "/* Could not access serialVersionUID */"
    DEFAULT_INITIAL_CAPACITY = "/* Could not access DEFAULT_INITIAL_CAPACITY */"
    MAXIMUM_CAPACITY = "/* Could not access MAXIMUM_CAPACITY */"
    DEFAULT_LOAD_FACTOR = "/* Could not access DEFAULT_LOAD_FACTOR */"
    TREEIFY_THRESHOLD = "/* Could not access TREEIFY_THRESHOLD */"
    UNTREEIFY_THRESHOLD = "/* Could not access UNTREEIFY_THRESHOLD */"
    MIN_TREEIFY_CAPACITY = "/* Could not access MIN_TREEIFY_CAPACITY */"
    table = "/* Could not access table */"
    entrySet = "/* Could not access entrySet */"
    size = "/* Could not access size */"
    modCount = "/* Could not access modCount */"
    threshold = "/* Could not access threshold */"
    loadFactor = "/* Could not access loadFactor */"
    keySet = "/* Could not access keySet */"
    values = "/* Could not access values */"
  options = class java.util.Collections$UnmodifiableMap@bf751b89
    serialVersionUID = "/* Could not access serialVersionUID */"
    m = "/* Could not access m */"
    keySet = "/* Could not access keySet */"
    entrySet = "/* Could not access entrySet */"
    values = "/* Could not access values */"
  temporarySubject = null
  serialVersionUID = -8873301121271047884
  $$$tc$$$ = class com.ibm.websphere.ras.TraceComponent@d860172f
    strings[0] = "TraceComponent[com.ibm.ws.security.jaas.common.modules.CommonLoginModule,class com.ibm.ws.security.jaas.common.modules.CommonLoginModule,[security],com.ibm.ws.security.jaas.common.internal.resources.JAASCommonMessages,null]"