search

eclipse-ee4j / mojarra

Mojarra, a Jakarta Faces implementation
Other
162 stars 110 forks source link

Mojarra 2.3.14.SP01: Setting WildFly-21.0.0.Final to loglevel FINEST results in wrong EL evaluation #5101

Closed Toru47 closed 2 years ago

Toru47 commented 2 years ago

MyBean.java:

import java.io.Serializable;
import java.util.Arrays;
import java.util.List;
import java.util.Objects;

import javax.faces.annotation.FacesConfig;
import javax.faces.annotation.FacesConfig.Version;
import javax.faces.view.ViewScoped;
import javax.inject.Named;

@Named
@ViewScoped
@FacesConfig(version = Version.JSF_2_3)
public class MyBean implements Serializable {
    private static final long serialVersionUID = 6796531750392077878L;

    public List<String> lst(Integer foo) {
        Objects.requireNonNull(foo);
        return Arrays.asList("1", "2");
    }
}

index.xhtml:

<!DOCTYPE html>
<html xmlns="http://www.w3.org/1999/xhtml"
  xmlns:h="http://xmlns.jcp.org/jsf/html"
  xmlns:f="http://xmlns.jcp.org/jsf/core">
<h:body>
<h:form>
  <h:dataTable value="#{[]}" var="foo">
    <h:column>
      <h:selectOneListbox value="#{viewScope.foobar}">
        <f:selectItems value="#{myBean.lst(foo)}" /> <!-- Called in FINEST loglevel. But why? -->
      </h:selectOneListbox>
    </h:column>
  </h:dataTable>
  </h:form>
</h:body>
</html>

Setting Wildfly loglevel to e.g. INFO or DEBUG myBean#lst is not called. That is what I do expect because h:dataTable list is empty. Setting loglevel to FINEST results in a NPE because myBean#lst is evaluated. But why? The h:dataTable list is still empty.

18:17:34,741 ERROR [io.undertow.request] (default task-1) UT005023: Exception handling request to /EmptyWebProject/: javax.servlet.ServletException
    at javax.faces.api@3.0.0.SP04//javax.faces.webapp.FacesServlet.executeLifecyle(FacesServlet.java:725)
    at javax.faces.api@3.0.0.SP04//javax.faces.webapp.FacesServlet.service(FacesServlet.java:451)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
    at io.opentracing.contrib.opentracing-jaxrs2//io.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:52)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
    at io.undertow.core@2.2.2.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.core@2.2.2.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.core@2.2.2.Final//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.core@2.2.2.Final//io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
    at io.undertow.core@2.2.2.Final//io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
    at io.undertow.core@2.2.2.Final//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at io.undertow.core@2.2.2.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
    at io.undertow.core@2.2.2.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
    at io.undertow.core@2.2.2.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530)
    at org.wildfly.extension.undertow@21.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
    at io.undertow.servlet@2.2.2.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
    at io.undertow.core@2.2.2.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
    at io.undertow.core@2.2.2.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:841)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
    at org.jboss.xnio@3.8.2.Final//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
    at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.NullPointerException
    at java.base/java.util.Objects.requireNonNull(Objects.java:221)
    at deployment.EmptyWebProject.war//MyBean.lst(MyBean.java:18)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at javax.el.api@2.0.0.Final//javax.el.ELUtil.invokeMethod(ELUtil.java:245)
    at javax.el.api@2.0.0.Final//javax.el.BeanELResolver.invoke(BeanELResolver.java:338)
    at javax.el.api@2.0.0.Final//javax.el.CompositeELResolver.invoke(CompositeELResolver.java:198)
    at org.glassfish.jakarta.el@3.0.3.jbossorg-2//com.sun.el.parser.AstValue.getValue(AstValue.java:110)
    at org.glassfish.jakarta.el@3.0.3.jbossorg-2//com.sun.el.parser.AstValue.getValue(AstValue.java:177)
    at org.glassfish.jakarta.el@3.0.3.jbossorg-2//com.sun.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:183)
    at org.jboss.weld.core@3.1.5.Final//org.jboss.weld.module.web.el.WeldValueExpression.getValue(WeldValueExpression.java:50)
    at org.jboss.weld.core@3.1.5.Final//org.jboss.weld.module.web.el.WeldValueExpression.getValue(WeldValueExpression.java:50)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.facelets.el.TagValueExpression.getValue(TagValueExpression.java:73)
    at javax.faces.api@3.0.0.SP04//javax.faces.component.ComponentStateHelper.eval(ComponentStateHelper.java:170)
    at javax.faces.api@3.0.0.SP04//javax.faces.component.ComponentStateHelper.eval(ComponentStateHelper.java:157)
    at javax.faces.api@3.0.0.SP04//javax.faces.component.UISelectItems.getValue(UISelectItems.java:108)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.renderkit.SelectItemsIterator.initializeItems(SelectItemsIterator.java:187)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.renderkit.SelectItemsIterator.hasNext(SelectItemsIterator.java:112)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:239)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:300)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:300)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:300)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:300)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:300)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.util.DebugUtil.printTree(DebugUtil.java:212)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:112)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.lifecycle.Phase.doPhase(Phase.java:76)
    at com.sun.jsf-impl@2.3.14.SP01//com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:199)
    at javax.faces.api@3.0.0.SP04//javax.faces.webapp.FacesServlet.executeLifecyle(FacesServlet.java:708)
    ... 50 more
mnriem commented 2 years ago

As you have set the log level to DEBUG you have asked the Mojarra runtime to print the component tree. In order to do that it has to walk each of the nodes in the tree and determine what has to be printed. It appears your model is not taking into account that the component tree can be walked before, during and after any of the lifecycle phases.

Toru47 commented 2 years ago

Thanks for your answer. Okay, I understand that f:selectItems is obviously a taghandler which is executed during view build time. But why only in JSF debug mode? If I run WildFly not in debug mode the method myBean#lst is not called. Or is f:selectItems an UIComponent? But if so why is the method myBean#lst then called at view build time? Sorry, I'am a little bit confused.

mnriem commented 2 years ago

As the dataTable value is an empty list during regular render response it will not ask for the h:column because it already knows there is nothing to add to the response. This is why in normal operation you do not see the call happening.