LifeCycle.Listener not called for Filter/Servlet/Listener lifecycle events

[joakime]

Jetty version
9.4.30

Description
The change to using BaseHolder and manually starting / stopping / destroying means that we no longer get LifeCycle.Listener events for the start/stop of the Filter/Servlet/Listeners on Jetty.

Example:

https://github.com/eclipse/jetty.project/blob/ae43b70a9f8907b8a2444f051bebab60f4a9162c/jetty-servlet/src/main/java/org/eclipse/jetty/servlet/ServletHandler.java#L742-L757

[joakime]

I would like to see a more detailed servlet component API for monitoring flows and timings.

Something that would report ...

• Listener init (start / finished) - timing also timing
• Filter initialized (start / finished) - timing would be useful here
• Filter doChain called (start / finished) - timing again
• Servlet init (start / finished) - timing also useful here
• Servlet service called (start / finished) - timing is useful here too (would be nice to also see RequestDispatcher based dispatches as well)

Currently this is really only possible by extending ...

• WebAppContext
• ServletContextHandler
• ServletHandler
• ServletHandler.Chain
• FilterHolder
• ServletHolder
• ListenerHolder

[janbartel]

@joakime I don't understand the problem. It is perfectly possible to add LifeCycle.Listeners for Servlets, Filters etc :

        LifeCycle.Listener listener = new LifeCycle.Listener()
        {
            @Override
            public void lifeCycleStopping(LifeCycle event)
            {
                System.err.println(event + ": STOPPING");
            }

            @Override
            public void lifeCycleStopped(LifeCycle event)
            {
                System.err.println(event + ":Stopped");
            }

            @Override
            public void lifeCycleStarting(LifeCycle event)
            {
                System.err.println(event + ": STARTING");
            }

            @Override
            public void lifeCycleStarted(LifeCycle event)
            {
                System.err.println(event + ": STARTED");
            }

            @Override
            public void lifeCycleFailure(LifeCycle event, Throwable cause)
            {
                System.err.println(event + ": FAILURE");
            }
        };
        ServletHolder debugHolder = new ServletHolder("debug", DumpServlet.class);
        debugHolder.addLifeCycleListener(listener);
        context.addServlet(debugHolder, "/dump/*");

        FilterHolder tf = context.addFilter(TestFilter.class, "/test/*", EnumSet.of(REQUEST));
        tf.addLifeCycleListener(listener);

[joakime]

@janbartel the point of the issue is that this functionality is now broken for things that result in a BaseHolder.
Filter for sure is broken, and I suspect Servlet / Listener are broken in their own way too.

Example for Filter.

package jetty;

import java.io.IOException;
import java.util.EnumSet;
import javax.servlet.DispatcherType;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;

import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.servlet.DefaultServlet;
import org.eclipse.jetty.servlet.ServletContextHandler;
import org.eclipse.jetty.util.component.LifeCycle;
import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.Logger;

public class FilterLifeCycleListenerDemo
{
    public static void main(String[] args) throws Exception
    {
        Server server = new Server(8080);

        ServletContextHandler contextHandler = new ServletContextHandler();
        contextHandler.addLifeCycleListener(new MyListener());
        contextHandler.setContextPath("/");
        contextHandler.addFilter(MyFilter.class, "/*", EnumSet.of(DispatcherType.REQUEST));
        contextHandler.addServlet(DefaultServlet.class, "/");

        server.setHandler(contextHandler);
        server.start();
        server.join();
    }

    public static class MyListener implements LifeCycle.Listener
    {
        private static final Logger LOG = Log.getLogger(MyListener.class);

        @Override
        public void lifeCycleStarting(LifeCycle event)
        {
            LOG.info("STARTING {}", event);
        }

        @Override
        public void lifeCycleStarted(LifeCycle event)
        {
            LOG.info("STARTED {}", event);
        }

        @Override
        public void lifeCycleFailure(LifeCycle event, Throwable cause)
        {
            LOG.info("FAILURE {}", event, cause);
        }

        @Override
        public void lifeCycleStopping(LifeCycle event)
        {
            LOG.info("STOPPING {}", event);
        }

        @Override
        public void lifeCycleStopped(LifeCycle event)
        {
            LOG.info("STOPPED {}", event);
        }
    }

    public static class MyFilter implements Filter
    {
        @Override
        public void init(FilterConfig filterConfig)
        {
        }

        @Override
        public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException
        {
            chain.doFilter(request, response);
        }

        @Override
        public void destroy()
        {
        }
    }

}

Results in output ...

2020-07-06 06:53:17.309:INFO::main: Logging initialized @209ms to org.eclipse.jetty.util.log.StdErrLog
2020-07-06 06:53:17.372:INFO:oejs.Server:main: jetty-9.4.30.v20200611; built: 2020-06-11T12:34:51.929Z; git: 271836e4c1f4612f12b7bb13ef5a92a927634b0d; jvm 11.0.7+10
2020-07-06 06:53:17.384:INFO:j.FilterLifeCycleListenerDemo$MyListener:main: STARTING o.e.j.s.ServletContextHandler@55040f2f{/,null,UNAVAILABLE}
2020-07-06 06:53:17.413:INFO:oejsh.ContextHandler:main: Started o.e.j.s.ServletContextHandler@55040f2f{/,null,AVAILABLE}
2020-07-06 06:53:17.413:INFO:j.FilterLifeCycleListenerDemo$MyListener:main: STARTED o.e.j.s.ServletContextHandler@55040f2f{/,null,AVAILABLE}
2020-07-06 06:53:17.429:INFO:oejs.AbstractConnector:main: Started ServerConnector@4c762604{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2020-07-06 06:53:17.432:INFO:oejs.Server:main: Started @337ms

I'm reasonably sure (not 100%) that in the past the LifeCycle.Listener on the ServletContextHandler would notify for events on Filter/Servlet/Listener and allow a single place to pay attention to all lifecycle events on that context, even if your embedded-jetty code wasn't the one adding/registering the the Filter or Servlet (from dynamic registration or annotations for example).

With this behavior change and with the recent change in Decorator (see issue #5021) libraries like Guice no longer have visibility to all of the servlet components (like they used to).

[gregw]

@joakime I don't see how that example would ever have worked because the LifeCycle.Listener is on the context, so it will only be told if the context starts and stops.

What we do have is Container.InheritedListener which added to the context would also be added to all containers underneath it... which would end up at the ServletHandler having the Container.InheritedListener which is also a Container.Listener, so previously it would have been given addBean events for the holders.... and perhaps some custom version of this then added a LifeCycle.Listener to those added holders.

So now, we don't add the holders as beans, so nobody sees an addBean event, so nobody has an opportunity to add the LifeCycle.Listener, but if they did, as @janbartel has shown it would work.

Hmmm this also probably means that we can't have JMX beans for our holders either!!!! who made that silly change.... oh it was me :(

So it would be good to have the holders as managed beans again.... but we have to work out why the change was made? Was it only to get the nice formatting on the dump? or was there another reason due to their complex lifecycles?

So I think we should definitely make the Holder beans again and I note the start protection is still in ServletHandler, expecting the holders to be beans. But the new dump format is really nice.... so it would be good to keep that, but then we would need a way to exclude the holder beans from the generic dump, so the ServletHandler dump can well order and label them.

[joakime]

I too feel that the current dump format for ServletContextHandler is superior to the old one.

I'm good with this being the way it should be, and will shift my efforts to something that doesn't rely on LifeCycle.Listener, or Container.InheritedListener.

The last commit I can find where Holder's were Managed Beans is ...

https://github.com/eclipse/jetty.project/blob/baca9cae3982a51a39c406f9f3a457caa4fbf700/jetty-servlet/src/main/java/org/eclipse/jetty/servlet/ServletHandler.java#L770-L785

This commit removed them as beans ...

9d37feb

[janbartel]

Merged.