Skip to content

Commit

Permalink
Issue #5032 - Servlet / WebApp Metrics Listener Support
Browse files Browse the repository at this point in the history
Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
  • Loading branch information
joakime committed Jul 8, 2020
1 parent 6c161ca commit c4bedc4
Show file tree
Hide file tree
Showing 8 changed files with 414 additions and 10 deletions.
@@ -1,7 +1,8 @@
org.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.StdErrLog
#org.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.JavaUtilLog
#org.eclipse.jetty.util.log.javautil.PROPERTIES=java-util-logging.properties
#org.eclipse.jetty.util.log.SOURCE=true
#org.eclipse.jetty.LEVEL=INFO
org.eclipse.jetty.LEVEL=INFO
#org.eclipse.jetty.STACKS=true
#org.eclipse.jetty.STACKS=false
#org.eclipse.jetty.io.LEVEL=DEBUG
Expand All @@ -10,3 +11,5 @@
#org.eclipse.jetty.servlets.LEVEL=DEBUG
#org.eclipse.jetty.alpn.LEVEL=DEBUG
#org.eclipse.jetty.jmx.LEVEL=DEBUG
#org.eclipse.jetty.servlet.DebugServletMetricsListener.LEVEL=DEBUG
#org.eclipse.jetty.webapp.DebugWebAppMetricsListener.LEVEL=DEBUG
@@ -0,0 +1,63 @@
package org.eclipse.jetty.servlet;

import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.servlet.listener.ServletMetricsListener;
import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.Logger;

public class DebugServletMetricsListener implements ServletMetricsListener
{
protected final Logger logger;

public DebugServletMetricsListener()
{
this(Log.getLogger(DebugServletMetricsListener.class));
}

public DebugServletMetricsListener(Logger logger)
{
this.logger = logger;
}

@Override
public void onServletContextInitTiming(ServletContextHandler servletContextHandler, long durationNanoSeconds)
{
logger.debug("App Context Init: Duration: {} - App {}", toHumanReadableMilliSeconds(durationNanoSeconds), servletContextHandler);
}

@Override
public void onServletContextInitTiming(ServletContextHandler servletContextHandler, BaseHolder<?> holder, long durationNanoSeconds)
{
logger.debug("App Component Init: Duration: {} - Component: {} - App: {}", toHumanReadableMilliSeconds(durationNanoSeconds), holder, servletContextHandler);
}

@Override
public void onFilterEnter(ServletContextHandler servletContextHandler, FilterHolder filterHolder, Request request)
{
logger.debug("Filter Entered: {} - App: {}", filterHolder, servletContextHandler);
}

@Override
public void onFilterExit(ServletContextHandler servletContextHandler, FilterHolder filterHolder, Request request)
{
logger.debug("Filter Exited: {} - App: {}", filterHolder, servletContextHandler);
}

@Override
public void onServletServiceEnter(ServletContextHandler servletContextHandler, ServletHolder servletHolder, Request request)
{
logger.debug("Servlet Entered: {} - App: {}", servletHolder, servletContextHandler);
}

@Override
public void onServletServiceExit(ServletContextHandler servletContextHandler, ServletHolder servletHolder, Request request)
{
logger.debug("Servlet Exited: {} - App: {}", servletHolder, servletContextHandler);
}

protected static String toHumanReadableMilliSeconds(long durationNanoSeconds)
{
double durationMilliSeconds = (double)durationNanoSeconds / 1_000_000;
return String.format("%.4f ms", durationMilliSeconds);
}
}
Expand Up @@ -63,6 +63,7 @@
import org.eclipse.jetty.server.handler.HandlerWrapper;
import org.eclipse.jetty.server.handler.gzip.GzipHandler;
import org.eclipse.jetty.server.session.SessionHandler;
import org.eclipse.jetty.servlet.listener.ServletMetricsListener;
import org.eclipse.jetty.util.DecoratedObjectFactory;
import org.eclipse.jetty.util.DeprecationWarning;
import org.eclipse.jetty.util.StringUtil;
Expand Down Expand Up @@ -107,6 +108,7 @@ public interface ServletContainerInitializerCaller extends LifeCycle {}
protected int _options;
protected JspConfigDescriptor _jspConfig;

private ServletMetricsListener _metricsListener;
private boolean _startListeners;

public ServletContextHandler()
Expand Down Expand Up @@ -268,11 +270,43 @@ private void relinkHandlers()
}
}

public void setMetricsListener(ServletMetricsListener metricsListener)
{
_metricsListener = metricsListener;
}

public ServletMetricsListener getMetricsListener()
{
if (_metricsListener == null)
{
ServletMetricsListener metricsListener = getBean(ServletMetricsListener.class);
if ((metricsListener == null) && (getServer() != null))
{
metricsListener = getServer().getBean(ServletMetricsListener.class);
}

_metricsListener = metricsListener;
}

return _metricsListener;
}

@Override
protected void doStart() throws Exception
{
ServletMetricsListener metricsListener = getMetricsListener();
if (metricsListener != null)
{
getServletHandler().setMetricsListener(metricsListener);
}
long durationNanoStart = System.nanoTime();
getServletContext().setAttribute(DecoratedObjectFactory.ATTR, _objFactory);
super.doStart();
if (metricsListener != null)
{
long durationNano = System.nanoTime() - durationNanoStart;
metricsListener.onServletContextInitTiming(this, durationNano);
}
}

/**
Expand Down Expand Up @@ -325,7 +359,9 @@ protected SecurityHandler newSecurityHandler()

protected ServletHandler newServletHandler()
{
return new ServletHandler();
ServletHandler servletHandler = new ServletHandler();
servletHandler.setMetricsListener(getMetricsListener());
return servletHandler;
}

/**
Expand Down Expand Up @@ -1074,7 +1110,7 @@ private void checkDynamic(String name)
{
if (isStarted())
throw new IllegalStateException();

if (ServletContextHandler.this.getServletHandler().isInitialized())
throw new IllegalStateException();

Expand Down Expand Up @@ -1415,7 +1451,7 @@ public <T extends EventListener> void addListener(T t)
{
try
{
holder.start();
holder.start();
}
catch (Exception e)
{
Expand Down
Expand Up @@ -62,6 +62,7 @@
import org.eclipse.jetty.server.UserIdentity;
import org.eclipse.jetty.server.handler.ContextHandler;
import org.eclipse.jetty.server.handler.ScopedHandler;
import org.eclipse.jetty.servlet.listener.ServletMetricsListener;
import org.eclipse.jetty.util.ArrayUtil;
import org.eclipse.jetty.util.LazyList;
import org.eclipse.jetty.util.MultiException;
Expand Down Expand Up @@ -118,6 +119,7 @@ public class ServletHandler extends ScopedHandler
private PathMappings<ServletHolder> _servletPathMap;

private ListenerHolder[] _listeners = new ListenerHolder[0];
private ServletMetricsListener _metricsListener;
private boolean _initialized = false;

@SuppressWarnings("unchecked")
Expand Down Expand Up @@ -210,6 +212,11 @@ public void setEnsureDefaultServlet(boolean ensureDefaultServlet)
_ensureDefaultServlet = ensureDefaultServlet;
}

public void setMetricsListener(ServletMetricsListener metricsListener)
{
this._metricsListener = metricsListener;
}

@Override
protected void start(LifeCycle l) throws Exception
{
Expand Down Expand Up @@ -308,7 +315,7 @@ protected synchronized void doStop()
_servlets = shs;
ServletMapping[] sms = (ServletMapping[])LazyList.toArray(servletMappings, ServletMapping.class);
_servletMappings = sms;

if (_contextHandler != null)
_contextHandler.contextDestroyed();

Expand Down Expand Up @@ -745,8 +752,14 @@ public void initialize()
{
if (!h.isStarted())
{
long durationNanoStart = System.nanoTime();
h.start();
h.initialize();
if (_metricsListener != null)
{
long durationNano = System.nanoTime() - durationNanoStart;
_metricsListener.onServletContextInitTiming(_contextHandler, h, durationNano);
}
}
}
catch (Throwable e)
Expand All @@ -755,17 +768,17 @@ public void initialize()
mx.add(e);
}
};

//Start the listeners so we can call them
Arrays.stream(_listeners).forEach(c);

//call listeners contextInitialized
if (_contextHandler != null)
_contextHandler.contextInitialized();

//Only set initialized true AFTER the listeners have been called
_initialized = true;

//Start the filters then the servlets
Stream.concat(
Arrays.stream(_filters),
Expand All @@ -774,7 +787,7 @@ public void initialize()

mx.ifExceptionThrow();
}

/**
* @return true if initialized has been called, false otherwise
*/
Expand Down Expand Up @@ -1599,6 +1612,11 @@ public void doFilter(ServletRequest request, ServletResponse response)
LOG.debug("call filter {}", _filterHolder);
Filter filter = _filterHolder.getFilter();

if (_metricsListener != null)
{
_metricsListener.onFilterEnter(_contextHandler, _filterHolder, baseRequest);
}

//if the request already does not support async, then the setting for the filter
//is irrelevant. However if the request supports async but this filter does not
//temporarily turn it off for the execution of the filter
Expand All @@ -1617,6 +1635,10 @@ public void doFilter(ServletRequest request, ServletResponse response)
else
filter.doFilter(request, response, _next);

if (_metricsListener != null)
{
_metricsListener.onFilterExit(_contextHandler, _filterHolder, baseRequest);
}
return;
}

Expand All @@ -1628,7 +1650,15 @@ public void doFilter(ServletRequest request, ServletResponse response)
{
if (LOG.isDebugEnabled())
LOG.debug("call servlet " + _servletHolder);
if (_metricsListener != null)
{
_metricsListener.onServletServiceEnter(_contextHandler, _servletHolder, baseRequest);
}
_servletHolder.handle(baseRequest, request, response);
if (_metricsListener != null)
{
_metricsListener.onServletServiceExit(_contextHandler, _servletHolder, baseRequest);
}
}
}

Expand Down
@@ -0,0 +1,100 @@
//
// ========================================================================
// Copyright (c) 1995-2020 Mort Bay Consulting Pty Ltd and others.
// ------------------------------------------------------------------------
// All rights reserved. This program and the accompanying materials
// are made available under the terms of the Eclipse Public License v1.0
// and Apache License v2.0 which accompanies this distribution.
//
// The Eclipse Public License is available at
// http://www.eclipse.org/legal/epl-v10.html
//
// The Apache License v2.0 is available at
// http://www.opensource.org/licenses/apache2.0.php
//
// You may elect to redistribute this code under either of these licenses.
// ========================================================================
//

package org.eclipse.jetty.servlet.listener;

import javax.servlet.FilterChain;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;

import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.servlet.BaseHolder;
import org.eclipse.jetty.servlet.FilterHolder;
import org.eclipse.jetty.servlet.ServletContextHandler;
import org.eclipse.jetty.servlet.ServletHolder;

/**
* Listener bean for obtaining events related to servlet initialization / timing, and
* calls (to Filters and Servlets) within the defined `ServletContextHandler`.
* <p>
* This supplements the {@link org.eclipse.jetty.server.HttpChannel.Listener}
* with events that represent behaviors within a specific `ServletContextHandler`.
* </p>
* <p>
* If there is a Bean present on the `ServletContextHandler` implementing this
* Listener it is used, otherwise the Server level Bean is used if present.
* If no bean is discovered, no listener is notified.
* </p>
*/
public interface ServletMetricsListener
{
/**
* Timing for the entire ServletContextHandler startup + initialization.
*
* @param servletContextHandler the specific context that was started + initialized.
* @param durationNanoSeconds the duration in nanoseconds for this startup.
*/
void onServletContextInitTiming(ServletContextHandler servletContextHandler, long durationNanoSeconds);

/**
* Timing for a specific Filter / Servlet / Listener that was initialized.
*
* @param servletContextHandler the specific context that was started + initialized.
* @param holder this can be a {@link FilterHolder}, a {@link org.eclipse.jetty.servlet.ServletHolder}, or a {@link org.eclipse.jetty.servlet.ListenerHolder}
* @param durationNanoSeconds the duration in nanoseconds for this initialization.
*/
void onServletContextInitTiming(ServletContextHandler servletContextHandler, BaseHolder<?> holder, long durationNanoSeconds);

/**
* Event indicating a specific {@link javax.servlet.Filter#doFilter(ServletRequest, ServletResponse, FilterChain)} ` was entered
* from the Filter chain.
*
* @param servletContextHandler the specific context that this event occurred against.
* @param filterHolder the filter that was entered
* @param request the request that caused this filter to be entered.
*/
void onFilterEnter(ServletContextHandler servletContextHandler, FilterHolder filterHolder, Request request);

/**
* Event indicating a specific {@link javax.servlet.Filter#doFilter(ServletRequest, ServletResponse, FilterChain)} ` was exited
* from the Filter chain.
*
* @param servletContextHandler the specific context that this event occurred against.
* @param filterHolder the filter that was exited
* @param request the request that caused this filter to be exited.
*/
void onFilterExit(ServletContextHandler servletContextHandler, FilterHolder filterHolder, Request request);

/**
* Event indicating a specific {@link javax.servlet.Servlet#service(ServletRequest, ServletResponse)} ` was entered.
*
* @param servletContextHandler the specific context that this event occurred against.
* @param servletHolder the servlet that was entered.
* @param request the request that entered this servlet.
*/
void onServletServiceEnter(ServletContextHandler servletContextHandler, ServletHolder servletHolder, Request request);

/**
* Event indicating a specific {@link javax.servlet.Servlet#service(ServletRequest, ServletResponse)} ` was exited.
*
* @param servletContextHandler the specific context that this event occurred against.
* @param servletHolder the servlet that was exited.
* @param request the request that exited this servlet.
*/
void onServletServiceExit(ServletContextHandler servletContextHandler, ServletHolder servletHolder, Request request);
}

0 comments on commit c4bedc4

Please sign in to comment.