org.eclipse.jetty.server.handler.StateTrackingHandler Maven / Gradle / Ivy
Show all versions of jetty-server Show documentation
//
// ========================================================================
// Copyright (c) 1995 Mort Bay Consulting Pty Ltd and others.
//
// This program and the accompanying materials are made available under the
// terms of the Eclipse Public License v. 2.0 which is available at
// https://www.eclipse.org/legal/epl-2.0, or the Apache License, Version 2.0
// which is available at https://www.apache.org/licenses/LICENSE-2.0.
//
// SPDX-License-Identifier: EPL-2.0 OR Apache-2.0
// ========================================================================
//
package org.eclipse.jetty.server.handler;
import java.io.IOException;
import java.nio.ByteBuffer;
import java.util.ArrayList;
import java.util.EventListener;
import java.util.List;
import java.util.Map;
import java.util.Objects;
import java.util.Queue;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicBoolean;
import org.eclipse.jetty.server.Handler;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.Response;
import org.eclipse.jetty.util.Callback;
import org.eclipse.jetty.util.annotation.ManagedAttribute;
import org.eclipse.jetty.util.annotation.ManagedObject;
import org.eclipse.jetty.util.component.Dumpable;
import org.eclipse.jetty.util.component.DumpableCollection;
import org.eclipse.jetty.util.thread.Invocable;
import org.eclipse.jetty.util.thread.Scheduler;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
/**
* A troubleshooting {@link Handler.Wrapper} that tracks whether
* {@link Handler}/{@link Request}/{@link Response} asynchronous APIs
* are properly used by applications.
* The violation of these tracked APIs are reported to a {@link Listener}
* instance; the default listener implementation emits warning logs.
* {@code StateTrackingHandler} can be linked in at any point in
* the {@code Handler} chain, and even be present in multiple instances,
* likely configured differently.
* For example, to troubleshoot wrong usages of the callback passed to method
* {@link #handle(Request, Response, Callback)}, a {@code StateTrackingHandler}
* should be configured as the outermost {@code Handler}.
* This is because the {@code handle(...)} call propagates inwards.
* In this way, {@code StateTrackingHandler} can wrap the callback passed
* to inner {@code Handler}s and verify that it is eventually completed.
* On the other hand, to troubleshoot custom {@code Handler} implementations
* that perform wrapping of {@link Response#write(boolean, ByteBuffer, Callback)},
* a {@code StateTrackingHandler} should be configured after the custom
* {@code Handler} implementation.
* This is because the {@code write(...)} call propagates outwards.
* In this way, {@code StateTrackingHandler} can wrap the {@code write(...)}
* call before forwarding it to outer {@code Handler}s and eventually to the
* Jetty implementation, and verify that it is eventually completed.
*
* @see Listener
*/
@ManagedObject
public class StateTrackingHandler extends Handler.Wrapper
{
private static final Logger LOG = LoggerFactory.getLogger(StateTrackingHandler.class);
private final Map stateInfos = new ConcurrentHashMap<>();
private final Listener listener;
private long handlerCallbackTimeout;
private boolean completeHandlerCallbackAtTimeout;
private long demandCallbackTimeout;
private long writeTimeout;
private long writeCallbackTimeout;
/**
* Creates a new instance with a default {@link Listener}
* that logs events at warning level.
*/
public StateTrackingHandler()
{
this(new WarnListener());
}
/**
* Creates a new instance with the given {@link Listener}.
*
* @param listener the event listener
*/
public StateTrackingHandler(Listener listener)
{
this.listener = listener;
}
/**
* @return the timeout in ms for the completion of the {@link #handle(Request, Response, Callback)} callback
*/
@ManagedAttribute("The timeout in ms for the completion of the handle() callback")
public long getHandlerCallbackTimeout()
{
return handlerCallbackTimeout;
}
public void setHandlerCallbackTimeout(long timeout)
{
this.handlerCallbackTimeout = timeout;
}
/**
* @return whether the {@link #handle(Request, Response, Callback)} callback is completed
* in case the {@link #getHandlerCallbackTimeout()} expires
* @see #getHandlerCallbackTimeout()
*/
@ManagedAttribute("Whether the handle() callback is completed in case of timeout")
public boolean isCompleteHandlerCallbackAtTimeout()
{
return completeHandlerCallbackAtTimeout;
}
public void setCompleteHandlerCallbackAtTimeout(boolean completeHandlerCallbackAtTimeout)
{
this.completeHandlerCallbackAtTimeout = completeHandlerCallbackAtTimeout;
}
/**
* @return the timeout in ms for the execution of the demand callback passed to {@link Request#demand(Runnable)}
*/
@ManagedAttribute("The timeout in ms for the execution of the demand callback")
public long getDemandCallbackTimeout()
{
return demandCallbackTimeout;
}
public void setDemandCallbackTimeout(long timeout)
{
this.demandCallbackTimeout = timeout;
}
/**
* @return the timeout in ms for the execution of a {@link Response#write(boolean, ByteBuffer, Callback)} call
*/
@ManagedAttribute("The timeout in ms for the execution of a response write")
public long getWriteTimeout()
{
return writeTimeout;
}
public void setWriteTimeout(long timeout)
{
this.writeTimeout = timeout;
}
/**
* @return the timeout in ms for the execution of the response write callback passed to {@link Response#write(boolean, ByteBuffer, Callback)}
*/
@ManagedAttribute("The timeout in ms for the execution of the response write callback")
public long getWriteCallbackTimeout()
{
return writeCallbackTimeout;
}
public void setWriteCallbackTimeout(long timeout)
{
this.writeCallbackTimeout = timeout;
}
@Override
public boolean handle(Request originalRequest, Response originalResponse, Callback originalCallback) throws Exception
{
StateInfo stateInfo = new StateInfo(originalRequest);
stateInfos.put(originalRequest, stateInfo);
Request.addCompletionListener(originalRequest, x -> stateInfos.remove(originalRequest));
Request request = originalRequest;
if (demandCallbackTimeout > 0)
request = new RequestWrapper(stateInfo);
Response response = originalResponse;
if (writeTimeout > 0 || writeCallbackTimeout > 0)
response = new ResponseWrapper(stateInfo, originalResponse);
HandlerCallback callback = new HandlerCallback(stateInfo, originalCallback);
stateInfo.handlerCallback = callback;
try
{
boolean handled = super.handle(request, response, callback);
callback.setHandled(handled);
if (!handled)
{
// Check if the callback was completed.
ThreadInfo completionThreadInfo = callback.getCompletionThreadInfo();
if (completionThreadInfo != null)
notifyInvalidHandlerReturnValue(stateInfo.request, completionThreadInfo);
}
return handled;
}
catch (Throwable x)
{
stateInfos.remove(originalRequest);
notifyHandlerException(stateInfo.request, x, callback.getCompletionThreadInfo());
throw x;
}
}
private void notifyInvalidHandlerReturnValue(Request request, ThreadInfo completionThreadInfo)
{
try
{
listener.onInvalidHandlerReturnValue(request, completionThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyHandlerException(Request request, Throwable failure, ThreadInfo completionThreadInfo)
{
try
{
listener.onHandlerException(request, failure, completionThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyHandlerCallbackNotCompleted(Request request, ThreadInfo handlerThreadInfo)
{
try
{
listener.onHandlerCallbackNotCompleted(request, handlerThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyDemandCallbackBlocked(Request request, ThreadInfo demandThreadInfo, ThreadInfo runThreadInfo)
{
try
{
listener.onDemandCallbackBlocked(request, demandThreadInfo, runThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyWriteBlocked(Request request, ThreadInfo writeThreadInfo, ThreadInfo writingThreadInfo)
{
try
{
listener.onWriteBlocked(request, writeThreadInfo, writingThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyWriteCallbackNotCompleted(Request request, Throwable failure, ThreadInfo writeThreadInfo)
{
try
{
listener.onWriteCallbackNotCompleted(request, failure, writeThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
private void notifyWriteCallbackBlocked(Request request, Throwable writeFailure, ThreadInfo writeThreadInfo, ThreadInfo callbackThreadInfo)
{
try
{
listener.onWriteCallbackBlocked(request, writeFailure, writeThreadInfo, callbackThreadInfo);
}
catch (Throwable x)
{
LOG.info("failure while notifying {}", listener, x);
}
}
@Override
public void dump(Appendable out, String indent) throws IOException
{
dumpObjects(out, indent, new DumpableCollection("requests", stateInfos.values()));
}
@Override
public String toString()
{
return "%s@%x".formatted(getClass().getSimpleName(), hashCode());
}
public static class ThreadInfo
{
private final String info;
private final StackTraceElement[] stackFrames;
private ThreadInfo(Thread thread)
{
this.info = thread.toString();
this.stackFrames = thread.getStackTrace();
}
public String getInfo()
{
return info;
}
public StackTraceElement[] getStackFrames()
{
return stackFrames;
}
@Override
public String toString()
{
return toString("");
}
private String toString(String indent)
{
StringBuilder builder = new StringBuilder();
builder.append(getInfo()).append(System.lineSeparator());
for (StackTraceElement stackFrame : getStackFrames())
{
builder.append(indent).append("\tat ").append(stackFrame).append(System.lineSeparator());
}
return builder.toString();
}
}
/**
* Listener of events emitted by {@link StateTrackingHandler}.
* The methods of this interface are named after the wrong API usages
* tracked by {@code StateTrackingHandler}.
*/
public interface Listener extends EventListener
{
/**
* Invoked when the {@link Handler} chain returns {@code false},
* but the handler callback has been completed.
* This event is always enabled.
*
* @param request the current request
* @param completionThreadInfo the {@link ThreadInfo} of the thread that completed the handler callback
*/
default void onInvalidHandlerReturnValue(Request request, ThreadInfo completionThreadInfo)
{
}
/**
* Invoked when the {@link Handler} chain throws an exception from
* the {@link Handler#handle(Request, Response, Callback)} method.
* This event is always enabled.
*
* @param request the current request
* @param failure the exception thrown
* @param completionThreadInfo the {@link ThreadInfo} of the thread that completed the handler callback,
* or {@code null} if the handler callback has not been completed
*/
default void onHandlerException(Request request, Throwable failure, ThreadInfo completionThreadInfo)
{
}
/**
* Invoked when the {@link Handler} callback is not completed within
* the timeout specified with {@link #getHandlerCallbackTimeout()}.
* This event is enabled only when {@link #getHandlerCallbackTimeout()}
* is non-{@code null}.
* When handler thread has already returned from the handler chain,
* the thread info parameter is {@code null}.
* Otherwise, the handler thread has not returned yet and may be blocked,
* and the thread info parameter is not {@code null}.
* Note: when present, the thread info stack trace may not be accurate,
* as the thread blockage might have resolved just before the thread info
* was taken.
*
* @param request the current request
* @param handlerThreadInfo the handler thread info, or {@code null}
* if the handler thread already returned from the handler chain
*/
default void onHandlerCallbackNotCompleted(Request request, ThreadInfo handlerThreadInfo)
{
}
/**
* Invoked when the {@link Request#demand(Runnable) request demand callback}
* {@code run()} method blocks for longer than the timeout specified with
* {@link #getDemandCallbackTimeout()}.
* This event is enabled only when {@link #getDemandCallbackTimeout()}
* is non-{@code null}.
* Note: the thread info stack trace of the thread that is running the
* demand callback may not be accurate, as the thread blockage might have
* resolved just before the thread info was taken.
*
* @param request the current request
* @param demandThreadInfo the thread info of the thread that called {@link Request#demand(Runnable)}
* @param runThreadInfo the thread info of the thread running the demand callback
*/
default void onDemandCallbackBlocked(Request request, ThreadInfo demandThreadInfo, ThreadInfo runThreadInfo)
{
}
/**
* Invoked when the {@link Response#write(boolean, ByteBuffer, Callback)} call
* blocks for longer than the timeout specified with {@link #getWriteTimeout()}.
* This event is enabled only when {@link #getWriteTimeout()} is non-{@code null}.
* Note: the thread info stack trace of the thread that is writing may not be
* accurate, as the thread blockage might have resolved just before the thread
* info was taken.
*
* @param request the current request
* @param writeThreadInfo the thread info of the thread that called {@link Response#write(boolean, ByteBuffer, Callback)}
* @param writingThreadInfo the thread info of the thread tht is writing
*/
default void onWriteBlocked(Request request, ThreadInfo writeThreadInfo, ThreadInfo writingThreadInfo)
{
}
/**
* Invoked when the write callback passed to {@link Response#write(boolean, ByteBuffer, Callback)}
* is not completed for longer than the timeout specified with {@link #getWriteTimeout()}.
* This event is enabled only when {@link #getWriteTimeout()} is non-{@code null}.
* Note that the write might have been fully performed, but since the callback is not
* completed, this case is indistinguishable from the case where the callback is not complete
* because the write has not been fully performed.
*
* @param request the current request
* @param writeFailure the write failure, or {@code null} if the write succeeded
* @param writeThreadInfo the thread info of the thread that called {@link Response#write(boolean, ByteBuffer, Callback)}
*/
default void onWriteCallbackNotCompleted(Request request, Throwable writeFailure, ThreadInfo writeThreadInfo)
{
}
/**
* Invoked when the write callback passed to {@link Response#write(boolean, ByteBuffer, Callback)}
* blocks for longer than the timeout specified with {@link #getWriteCallbackTimeout()}.
* This event is enabled only when {@link #getWriteCallbackTimeout()} is non-{@code null}.
* Note: the thread info stack trace of the thread that is running the write callback may not be
* accurate, as the thread blockage might have resolved just before the thread info was taken.
*
* @param request the current request
* @param writeFailure the write failure, or {@code null} if the write succeeded
* @param writeThreadInfo the thread info of the thread that called {@link Response#write(boolean, ByteBuffer, Callback)}
* @param callbackThreadInfo the thread info of the thread invoking the write callback
*/
default void onWriteCallbackBlocked(Request request, Throwable writeFailure, ThreadInfo writeThreadInfo, ThreadInfo callbackThreadInfo)
{
}
}
private static class WarnListener implements Listener
{
@Override
public void onInvalidHandlerReturnValue(Request request, ThreadInfo completionThreadInfo)
{
LOG.warn("handler callback completed but false returned for: {}{}completed by: {}",
request,
System.lineSeparator(),
completionThreadInfo
);
}
@Override
public void onHandlerException(Request request, Throwable failure, ThreadInfo completionThreadInfo)
{
String format = "handler exception thrown for {}";
List