Payara 6: When downloading a file with tou/guestbook enabled, works but throws server log error.

[kcondon]

When downloading a file with tou/guestbook enabled, when popup appears, throws server log error but it appears to work:
gb_tou_popup_log_err.txt

[scolapasta]

Adding to 6.0 either to fix or to determine that we won't fix for this release.

[kcondon]

This does not happen with payara5

[pdurbin]

Just chiming in that I can reproduce this on develop as of b62b561. The error is the same as reported above:

[#|2023-08-30T14:55:46.027+0000|SEVERE|Payara 6.2023.8|jakarta.enterprise.resource.webcontainer.faces.context|_ThreadID=89;_ThreadName=http-thread-pool::http-listener-1(1);_TimeMillis=1693407346027;_LevelValue=1000;|
  com.sun.faces.application.view.ViewHandlingStrategyNotFoundException
com.sun.faces.application.view.ViewHandlingStrategyNotFoundException
	at java.base/java.util.Optional.orElseThrow(Unknown Source)
	at com.sun.faces.application.view.ViewHandlingStrategyManager.getStrategy(ViewHandlingStrategyManager.java:57)
	at com.sun.faces.application.view.ViewDeclarationLanguageFactoryImpl.getViewDeclarationLanguage(ViewDeclarationLanguageFactoryImpl.java:45)
	at com.sun.faces.application.view.MultiViewHandler.getViewDeclarationLanguage(MultiViewHandler.java:407)
	at com.sun.faces.application.view.MultiViewHandler.derivePhysicalViewId(MultiViewHandler.java:449)
	at com.sun.faces.application.view.MultiViewHandler.deriveViewId(MultiViewHandler.java:422)
	at org.ocpsoft.rewrite.faces.RewriteViewHandler.deriveViewId(RewriteViewHandler.java:155)
	at jakarta.faces.application.ViewHandlerWrapper.deriveViewId(ViewHandlerWrapper.java:172)
	at jakarta.faces.application.ViewHandlerWrapper.deriveViewId(ViewHandlerWrapper.java:172)
	at com.sun.faces.application.NavigationHandlerImpl.findImplicitMatch(NavigationHandlerImpl.java:945)
	at com.sun.faces.application.NavigationHandlerImpl.getViewId(NavigationHandlerImpl.java:611)
	at com.sun.faces.application.NavigationHandlerImpl.handleNavigation(NavigationHandlerImpl.java:226)
	at com.sun.faces.application.NavigationHandlerImpl.handleNavigation(NavigationHandlerImpl.java:200)
	at com.ocpsoft.pretty.faces2.application.PrettyNavigationHandler.handleNavigation(PrettyNavigationHandler.java:65)
	at org.ocpsoft.rewrite.faces.RewriteNavigationHandler.handleNavigation(RewriteNavigationHandler.java:64)
	at com.sun.faces.application.ActionListenerImpl.invokeNavigationHandling(ActionListenerImpl.java:93)
	at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:62)
	at jakarta.faces.component.UICommand.broadcast(UICommand.java:205)
	at jakarta.faces.component.UIData.broadcast(UIData.java:1032)
	at jakarta.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:858)
	at jakarta.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1332)
	at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:56)
	at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:72)
	at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:159)
	at jakarta.faces.webapp.FacesServlet.executeLifecyle(FacesServlet.java:691)
	at jakarta.faces.webapp.FacesServlet.service(FacesServlet.java:449)
	at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1554)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:331)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:211)
	at org.glassfish.tyrus.servlet.TyrusServletFilter.doFilter(TyrusServletFilter.java:83)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:253)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:211)
	at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:226)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:253)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:211)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:257)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:166)
	at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:757)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:577)
	at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:158)
	at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:372)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:239)
	at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
	at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:174)
	at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:153)
	at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:196)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:88)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:246)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:178)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:118)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:96)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:51)
	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:510)
	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:82)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:83)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:101)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:535)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:515)
	at java.base/java.lang.Thread.run(Unknown Source)
|#]

I do see some rewrite lines:

	at org.ocpsoft.rewrite.faces.RewriteViewHandler.deriveViewId(RewriteViewHandler.java:155)
	at org.ocpsoft.rewrite.faces.RewriteNavigationHandler.handleNavigation(RewriteNavigationHandler.java:64)
	at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:226)

So I wonder if I should report this upstream or not. For this issue:

• encourage Rewrite library to release a non-snapshot of 6.0.0 #9804

[pdurbin]

at com.sun.faces.application.view.ViewHandlingStrategyManager.getStrategy(ViewHandlingStrategyManager.java:57)

Here's line 57 upstream in Mojarra:

https://github.com/eclipse-ee4j/mojarra/blob/4.0.3-RELEASE/impl/src/main/java/com/sun/faces/application/view/ViewHandlingStrategyManager.java#L57

[pdurbin]

at org.ocpsoft.rewrite.faces.RewriteViewHandler.deriveViewId(RewriteViewHandler.java:155)

Here's line 155 upstream in Rewrite:

https://github.com/ocpsoft/rewrite/blob/6.0.0.Alpha1/integration-faces/src/main/java/org/ocpsoft/rewrite/faces/RewriteViewHandler.java#L155

[landreev]

So, this is also rewrite/prettyfaces-related - ?
I haven't tried it myself yet, but am I reading it correctly, that the download ends up working correctly, with the guestbook entry properly written? - if that is the case, I would vote for delaying figuring this out (maybe adding a release note telling people that they may see noise in the logs, and suggesting adding a silencing rule for jakarta.enterprise.resource.webcontainer.faces.context to their logging.properties)

[pdurbin]

Yes. We currently still document how to reduce logging for Shibboleth (I don't know if it's still necessary these days or not) at https://guides.dataverse.org/en/5.14/installation/shibboleth.html#sslengine-warning-workaround

From sprint planning just now it sounds like we're open to a PR that does this, that reduces the logging level. In this case, though, the warning is SEVERE (the highest), so I'm not sure if this trick will work. 🤔

[landreev]

So my suggestion is to add a short release note:

In this release some third party library code is used in the UI of the application that is still in beta releases. While everything appears to work properly, we have seen some cases of excessively verbose logging. For example, downloading a file with Terms of Use/Guestbook enabled works, but a very long exception stack trace ends up in server.log. The following line can be added to domain1/config/logging.properties to suppress these messages:

jakarta.enterprise.resource.webcontainer.faces.level=OFF

[landreev]

One extra data point is that this stacktrace is triggered when the guestbook popup pops up for the user. The redirect from the popup to the download api works fine, just like the download redirect on a file with no TOU.