search

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 588 forks source link

WELD-001303 "No active contexts for RequestScoped" during pod startup #29335

Open jwalcorn opened 1 month ago

jwalcorn commented 1 month ago

Describe the bug

Whenever my Portfolio pod starts, I see this ContextsNotActiveException. This happens before I've driven any traffic to the pod (before it has even passed its MP Health readiness check). It seems benign - stuff does work once normal http/https traffic arrives. It's just something is freaking out during application startup, related to something about the CDI context. This seems to have started happening when I upgraded to Jakarta 10 (making the move from javax.* to jakarta.* packages, and thus the move to Servlet 6 and MicroProfile 6.1 and such.

If there is a stack trace, please include the FULL stack trace (without any [internal classes] lines in it). To find the full stack trace, you may need to check in $WLP_OUTPUT_DIR/messages.log

[AUDIT ] CWWKZ0001I: Application Portfolio started in 103.868 seconds. [INFO ] RESTEASY002225: Deploying jakarta.ws.rs.core.Application: class com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService$Proxy$_$$_WeldClientProxy [INFO ] FFDC1015I: An FFDC Incident has been created: "org.jboss.weld.contexts.ContextNotActiveException: WELD-001303: No active contexts for scope type jakarta.enterprise.context.RequestScoped com.ibm.ws.webcontainer.servlet.ServletWrapper.init 181" at ffdc_24.08.0819.37.24.0.log [ERROR ] SRVE0271E: Uncaught init() exception created by servlet [com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService] in application [Portfolio]: org.jboss.weld.contexts.ContextNotActiveException: WELD-001303: No active contexts for scope type jakarta.enterprise.context.RequestScoped at org.jboss.weld.manager.BeanManagerImpl.getContext(BeanManagerImpl.java:628) at org.jboss.weld.bean.ContextualInstanceStrategy$DefaultContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:89) at org.jboss.weld.bean.ContextualInstanceStrategy$CachingContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:164) at org.jboss.weld.bean.ContextualInstance.getIfExists(ContextualInstance.java:63) at org.jboss.weld.bean.proxy.ContextBeanInstance.getInstance(ContextBeanInstance.java:87) at org.jboss.weld.bean.proxy.ProxyMethodHandler.getInstance(ProxyMethodHandler.java:131) at com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService$Proxy$$$_WeldClientProxy.getClasses(Unknown Source) at org.jboss.resteasy.core.ResteasyDeploymentImpl.processApplication(ResteasyDeploymentImpl.java:670) at [internal classes]

Steps to Reproduce

Happens whenever my Kube pod starts.

Expected behavior A clear and concise description of what you expected to happen.

I'd like the server to start cleanly, without exceptions and FFDC logs being generated

Diagnostic information:

Additional context
Add any other context about the problem here.

jwalcorn commented 1 month ago

Note the application (its source, server.xml, etc) is at https://github.com/IBMStockTrader/portfolio. And here's the full pod log:

Launching defaultServer (Open Liberty 24.0.0.3/wlp-1.0.87.cl240320240311-1901) on Eclipse OpenJ9 VM, version 17.0.10+7 (en_US) [AUDIT ] CWWKE0001I: The server defaultServer has been launched. [AUDIT ] CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/defaultServer/configDropins/defaults/keystore.xml [AUDIT ] CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/defaultServer/configDropins/defaults/open-default-port.xml [AUDIT ] CWWKG0028A: Processing included configuration resource: /opt/ol/wlp/usr/servers/defaultServer/includes/basic.xml [AUDIT ] CWWKG0028A: Processing included configuration resource: /opt/ol/wlp/usr/servers/defaultServer/includes/db2.xml [INFO ] CWWKE0002I: The kernel started after 6.917 seconds [INFO ] CWWKF0007I: Feature update started. [INFO ] CWWKS0007I: The security service is starting... [AUDIT ] CWWKZ0058I: Monitoring dropins for applications. [INFO ] DYNA1001I: WebSphere Dynamic Cache instance named baseCache initialized successfully. [INFO ] DYNA1071I: The cache provider default is being used. [INFO ] DYNA1056I: Dynamic Cache (object cache) initialized successfully. [INFO ] CWWKS5786I: The MicroProfile JWT version 2.1 mpConfigProxy was processed successfully. [INFO ] CWWKS4103I: Creating the LTPA keys. This may take a few seconds. [INFO ] CWWKS1123I: The collective authentication plugin with class name NullCollectiveAuthenticationPlugin has been activated. [INFO ] CWPKI0830I: Certificate with the CN=acid.zalan.do SubjectDN from the cert_defaultTrustStore environment variable is being added to the defaultTrustStore keystore. [INFO ] CWPKI0830I: Certificate with the CN=localhost SubjectDN from the cert_defaultTrustStore environment variable is being added to the defaultTrustStore keystore. [INFO ] CWPKI0830I: Certificate with the CN=localhost SubjectDN from the cert_defaultTrustStore environment variable is being added to the defaultTrustStore keystore. [INFO ] Successfully loaded default keystore: /opt/ol/wlp/usr/servers/defaultServer/resources/security/key.p12 of type: pkcs12 [INFO ] CWWKS6012I: The JSON Web Token (JWT) consumer service is available. [INFO ] CWWKS5500I: The MicroProfile JWT configuration [MicroProfileJwtService] was successfully processed. [INFO ] CWWKS5500I: The MicroProfile JWT configuration [defaultMpJwt] was successfully processed. [INFO ] CWWKS5500I: The MicroProfile JWT configuration [stockTraderJWT] was successfully processed. [INFO ] CWWKS6002I: The JSON Web Token (JWT) endpoint service is available. [AUDIT ] CWWKS4104A: LTPA keys created in 8.293 seconds. LTPA key file: /opt/ol/wlp/output/defaultServer/resources/security/ltpa.keys [INFO ] CWWKS4105I: LTPA configuration is ready after 8.355 seconds. [INFO ] SESN8501I: The session manager did not find a persistent storage location; HttpSession objects will be stored in the local application server's memory. [INFO ] CWPMI2003I: Monitoring metrics can be retrieved through mpMetrics. [INFO ] CWWKS1655I: The default Java Authentication SPI for Containers (JASPIC) AuthConfigFactory class com.ibm.ws.security.jaspi.ProviderRegistry is being used because the Java security property authconfigprovider.factory is not set. [INFO ] SRVE0169I: Loading Web Module: OpenAPIUI. [INFO ] SRVE0250I: Web Module OpenAPIUI has been bound to default_host. [INFO ] SRVE0169I: Loading Web Module: MicroProfileOpenAPI. [INFO ] SRVE0250I: Web Module MicroProfileOpenAPI has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/openapi/ui/ [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/openapi/ [INFO ] SRVE0169I: Loading Web Module: health. [INFO ] SRVE0250I: Web Module health has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/health/ [INFO ] CWWKZ0018I: Starting application Portfolio. [INFO ] CWWKZ0136I: The Portfolio application is using the archive file at the /opt/ol/wlp/usr/servers/defaultServer/apps/Portfolio.war location. [INFO ] SRVE0169I: Loading Web Module: PublicMicroProfileMetrics. [INFO ] SRVE0250I: Web Module PublicMicroProfileMetrics has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/metrics/ [INFO ] SESN0176I: A new session context will be created for application key default_host/openapi [INFO ] SESN0176I: A new session context will be created for application key default_host/openapi/ui [INFO ] SRVE0169I: Loading Web Module: ibm/api. [INFO ] SRVE0250I: Web Module ibm/api has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/ibm/api/ [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] SESN0176I: A new session context will be created for application key default_host/health [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] SRVE0169I: Loading Web Module: io.openliberty.security.jwt.internal. [INFO ] SRVE0250I: Web Module io.openliberty.security.jwt.internal has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/jwt/ [INFO ] DYNA1056I: Dynamic Cache (object cache) initialized successfully. [INFO ] SESN0176I: A new session context will be created for application key default_host/metrics [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the com.ibm.ws.microprofile.openapi.ui application. [INFO ] SRVE0242I: [io.openliberty.microprofile.openapi.2.0.internal.servlet.jakarta] [/openapi] [ApplicationServlet]: Initialization successful. [INFO ] SRVE0242I: [io.openliberty.microprofile.health.3.1.internal.jakarta] [/health] [HealthCheckReadinessServlet]: Initialization successful. [INFO ] SRVE0242I: [io.openliberty.microprofile.metrics.5.0.public.internal] [/metrics] [PublicMetricsRESTProxyServlet]: Initialization successful. [INFO ] SRVE0242I: [io.openliberty.microprofile.health.3.1.internal.jakarta] [/health] [HealthCheckServlet]: Initialization successful. [INFO ] SRVE0242I: [io.openliberty.microprofile.health.3.1.internal.jakarta] [/health] [HealthCheckStartupServlet]: Initialization successful. [INFO ] SRVE0242I: [io.openliberty.microprofile.health.3.1.internal.jakarta] [/health] [HealthCheckLivenessServlet]: Initialization successful. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the io.openliberty.microprofile.metrics.5.0.public.internal application. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the io.openliberty.microprofile.openapi.2.0.internal.servlet.jakarta application. [INFO ] SESN0176I: A new session context will be created for application key default_host/ibm/api [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] SESN0176I: A new session context will be created for application key default_host/jwt [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the io.openliberty.microprofile.health.3.1.internal.jakarta application. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the com.ibm.ws.rest.handler.jakarta application. [INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the io.openliberty.security.jwt.internal application. [INFO ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at /opt/ol/wlp/output/defaultServer/logs/state/plugin-cfg.xml. [INFO ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at /opt/ol/wlp/output/defaultServer/logs/state/plugin-cfg.xml. [INFO ] J2CA8050I: An authentication alias should be used instead of defining a user name and password on dataSource[PortfolioDB]. [INFO ] CWWKO0219I: TCP Channel defaultHttpEndpoint has been started and is now listening for requests on host (IPv6) port 9080. [INFO ] CWWKO0219I: TCP Channel defaultHttpEndpoint-ssl has been started and is now listening for requests on host (IPv6) port 9443. [AUDIT ] CWWKZ0022W: Application Portfolio has not started in 30.566 seconds. [AUDIT ] CWWKF1037I: The server added the [appSecurity-5.0, cdi-4.0, expressionLanguage-5.0, jdbc-4.3, json-1.0, jsonb-3.0, jsonp-2.1, jwt-1.0, microProfile-6.1, monitor-1.0, mpConfig-3.1, mpFaultTolerance-4.0, mpHealth-4.0, mpJwt-2.1, mpMetrics-5.1, mpOpenAPI-3.1, mpRestClient-3.0, mpTelemetry-1.1, persistence-3.1, persistenceContainer-3.1, restfulWS-3.1, restfulWSClient-3.1, servlet-6.0, transportSecurity-1.0] features to the existing feature set. [AUDIT ] CWWKF0012I: The server installed the following features: [appSecurity-5.0, cdi-4.0, distributedMap-1.0, expressionLanguage-5.0, jdbc-4.3, jndi-1.0, json-1.0, jsonb-3.0, jsonp-2.1, jwt-1.0, microProfile-6.1, monitor-1.0, mpConfig-3.1, mpFaultTolerance-4.0, mpHealth-4.0, mpJwt-2.1, mpMetrics-5.1, mpOpenAPI-3.1, mpRestClient-3.0, mpTelemetry-1.1, persistence-3.1, persistenceContainer-3.1, restfulWS-3.1, restfulWSClient-3.1, servlet-6.0, ssl-1.0, transportSecurity-1.0]. [AUDIT ] CWWKF0013I: The server removed the following features: [appClientSupport-1.0, appSecurity-2.0, appSecurity-3.0, batch-1.0, beanValidation-2.0, cdi-2.0, concurrent-1.0, ejb-3.2, ejbHome-3.2, ejbLite-3.2, ejbPersistentTimer-3.2, ejbRemote-3.2, el-3.0, j2eeManagement-1.1, jacc-1.5, jaspic-1.1, javaMail-1.6, javaee-8.0, jaxb-2.2, jaxrs-2.1, jaxrsClient-2.1, jaxws-2.2, jca-1.7, jcaInboundSecurity-1.0, jdbc-4.2, jms-2.0, jpa-2.2, jpaContainer-2.2, jsf-2.3, jsonb-1.0, jsonp-1.1, jsp-2.3, managedBeans-1.0, mdb-3.2, servlet-4.0, wasJmsClient-2.0, wasJmsSecurity-1.0, wasJmsServer-1.0, webProfile-8.0, websocket-1.1]. [INFO ] CWWKF0008I: Feature update completed in 79.006 seconds. [AUDIT ] CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 85.922 seconds. [INFO ] CWRLS0010I: Performing recovery processing for local WebSphere server (defaultServer). [INFO ] CWRLS0007I: No existing recovery log files found in /opt/ol/wlp/output/defaultServer/tranlog/tranlog. Cold starting the recovery log. [INFO ] CWRLS0006I: Creating new recovery log file /opt/ol/wlp/output/defaultServer/tranlog/tranlog/log1. [INFO ] CWRLS0006I: Creating new recovery log file /opt/ol/wlp/output/defaultServer/tranlog/tranlog/log2. [INFO ] CWRLS0007I: No existing recovery log files found in /opt/ol/wlp/output/defaultServer/tranlog/partnerlog. Cold starting the recovery log. [INFO ] CWRLS0006I: Creating new recovery log file /opt/ol/wlp/output/defaultServer/tranlog/partnerlog/log1. [INFO ] CWRLS0006I: Creating new recovery log file /opt/ol/wlp/output/defaultServer/tranlog/partnerlog/log2. [INFO ] CWRLS0012I: All persistent services have been directed to perform recovery processing for this WebSphere server (defaultServer). [INFO ] WTRN0135I: Transaction service recovering no transactions. [WARNING ] You have specified multiple ids for the entity class [com.ibm.hybrid.cloud.sample.stocktrader.portfolio.json.Stock] without specifying an @IdClass. By doing this you may lose the ability to find by identity, distributed cache support etc. Note: You may however use EntityManager find operations by passing a list of primary key fields. Else, you will have to use JPQL queries to read your entities. For other id options see @PrimaryKey. [INFO ] WELD-000900: 5.1.1 (SP1) [INFO ] Publishing to Trade History topic enabled: false [INFO ] Cash Account microservice enabled: true [INFO ] Using Stock Quote URL from config map: http://cjot-stock-quote-service:9080/stock-quote [INFO ] CWWKO1660I: The application Portfolio was processed and an OpenAPI document was produced. [INFO ] SRVE0169I: Loading Web Module: Portfolio. [INFO ] SRVE0250I: Web Module Portfolio has been bound to default_host. [AUDIT ] CWWKT0016I: Web application available (default_host): http://cjot-portfolio-58777cf6fc-7srk4:9080/portfolio/ [INFO ] SESN0176I: A new session context will be created for application key defaulthost/portfolio [INFO ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation. [INFO ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at /opt/ol/wlp/output/defaultServer/logs/state/plugin-cfg.xml. [AUDIT ] CWWKZ0001I: Application Portfolio started in 103.868 seconds. [INFO ] RESTEASY002225: Deploying jakarta.ws.rs.core.Application: class com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService$Proxy$$$_WeldClientProxy [INFO ] FFDC1015I: An FFDC Incident has been created: "org.jboss.weld.contexts.ContextNotActiveException: WELD-001303: No active contexts for scope type jakarta.enterprise.context.RequestScoped com.ibm.ws.webcontainer.servlet.ServletWrapper.init 181" at ffdc_24.08.0819.37.24.0.log [ERROR ] SRVE0271E: Uncaught init() exception created by servlet [com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService] in application [Portfolio]: org.jboss.weld.contexts.ContextNotActiveException: WELD-001303: No active contexts for scope type jakarta.enterprise.context.RequestScoped at org.jboss.weld.manager.BeanManagerImpl.getContext(BeanManagerImpl.java:628) at org.jboss.weld.bean.ContextualInstanceStrategy$DefaultContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:89) at org.jboss.weld.bean.ContextualInstanceStrategy$CachingContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:164) at org.jboss.weld.bean.ContextualInstance.getIfExists(ContextualInstance.java:63) at org.jboss.weld.bean.proxy.ContextBeanInstance.getInstance(ContextBeanInstance.java:87) at org.jboss.weld.bean.proxy.ProxyMethodHandler.getInstance(ProxyMethodHandler.java:131) at com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService$Proxy$$$_WeldClientProxy.getClasses(Unknown Source) at org.jboss.resteasy.core.ResteasyDeploymentImpl.processApplication(ResteasyDeploymentImpl.java:670) at [internal classes]

[ERROR ] SRVE0276E: Error while initializing Servlet [com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService]: jakarta.servlet.ServletException: SRVE0207E: Uncaught initialization exception created by servlet at com.ibm.ws.webcontainer.servlet.ServletWrapper.init(ServletWrapper.java:370) at [internal classes] Caused by: org.jboss.weld.contexts.ContextNotActiveException: WELD-001303: No active contexts for scope type jakarta.enterprise.context.RequestScoped at org.jboss.weld.manager.BeanManagerImpl.getContext(BeanManagerImpl.java:628) at org.jboss.weld.bean.ContextualInstanceStrategy$DefaultContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:89) at org.jboss.weld.bean.ContextualInstanceStrategy$CachingContextualInstanceStrategy.getIfExists(ContextualInstanceStrategy.java:164) at org.jboss.weld.bean.ContextualInstance.getIfExists(ContextualInstance.java:63) at org.jboss.weld.bean.proxy.ContextBeanInstance.getInstance(ContextBeanInstance.java:87) at org.jboss.weld.bean.proxy.ProxyMethodHandler.getInstance(ProxyMethodHandler.java:131) at com.ibm.hybrid.cloud.sample.stocktrader.portfolio.PortfolioService$Proxy$_$$_WeldClientProxy.getClasses(Unknown Source) at org.jboss.resteasy.core.ResteasyDeploymentImpl.processApplication(ResteasyDeploymentImpl.java:670) ... 1 more

[INFO ] CWMOT5100I: The MicroProfile Telemetry Tracing feature is enabled but not configured to generate traces for the Portfolio application. [INFO ] CWWKS9123I: For URL /* in application Portfolio, the following HTTP methods are uncovered, and not accessible: HEAD OPTIONS TRACE j

jwalcorn commented 1 month ago

Also, I'm not sure why I get those messages about a bunch of features I don't use being removed in the pod log. Is there something I can do in my Dockerfile to make it not try loading those unneeded features and then have to remove them? I'm referring to this line:

[AUDIT ] CWWKF0013I: The server removed the following features: [appClientSupport-1.0, appSecurity-2.0, appSecurity-3.0, batch-1.0, beanValidation-2.0, cdi-2.0, concurrent-1.0, ejb-3.2, ejbHome-3.2, ejbLite-3.2, ejbPersistentTimer-3.2, ejbRemote-3.2, el-3.0, j2eeManagement-1.1, jacc-1.5, jaspic-1.1, javaMail-1.6, javaee-8.0, jaxb-2.2, jaxrs-2.1, jaxrsClient-2.1, jaxws-2.2, jca-1.7, jcaInboundSecurity-1.0, jdbc-4.2, jms-2.0, jpa-2.2, jpaContainer-2.2, jsf-2.3, jsonb-1.0, jsonp-1.1, jsp-2.3, managedBeans-1.0, mdb-3.2, servlet-4.0, wasJmsClient-2.0, wasJmsSecurity-1.0, wasJmsServer-1.0, webProfile-8.0, websocket-1.1].

I am using the full version of the Open Liberty docker image (not the kernel-slim), so that might be related? The relevant line of my Dockerfile:

FROM openliberty/open-liberty:24.0.0.3-full-java17-openj9-ubi

jhanders34 commented 1 month ago

Also, I'm not sure why I get those messages about a bunch of features I don't use being removed in the pod log. Is there something I can do in my Dockerfile to make it not try loading those unneeded features and then have to remove them?

I will answer that one first. I believe javaee-8.0 may be primed in the image to have those feature put into the shared classes cache. I could be wrong though. I assume that this message is coming out only during the build of the Docker container and not during the starting of your built container. Starting with kernel and using features.sh to install the features would be the main way to avoid this of course.

jhanders34 commented 1 month ago

As to your original complain, the main issue here is that the Application subclass PortfolioService is also a REST resource. Application subclasses should be ApplicationScoped, not RequestScoped. If you put the Application as its own class instead of being a REST resource, I believe your problem will go away. You would have @ApplicationPath on your new Application extension and not have @RequestScoped on it. The you still have @Path and @RequestScoped on PortfolioService for you actual REST resource.

jhanders34 commented 1 month ago

From the RESTful Web Service 3.1 specification, section 11.2.3:

Providers and Application subclasses MUST be singletons or use application scope.
jwalcorn commented 1 month ago

OK, thanks for the quick response, Jared. Good to talk with you again - hope all is going well. I'll make some updates to my app as you suggested and try stuff out again. Thanks!