445823 Moved RequestLog calling to HttpChannel

Simplified the RequestLogHandler.  It no longer set's async listeners or tries to catch exeptions etc.
Instead it simply sets the RequestLog instance on the HttpChannel.   The HttpChannel#onCompleted method
then uses the log (if set) as the last thing before recycling the connection.  It uses the actual
bytes written (eg after compression) and the actual status sent (eg if sent from a bad message).
This commit is contained in:
Greg Wilkins 2014-10-26 17:30:50 +11:00
parent 4323e450c5
commit 34a8da2ba2
12 changed files with 66 additions and 130 deletions

View File

@ -83,10 +83,10 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
* Writes the request and response information to the output stream.
*
* @see org.eclipse.jetty.server.RequestLog#log(org.eclipse.jetty.server.Request,
* org.eclipse.jetty.server.Response)
* int, long)
*/
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
try
{
@ -136,30 +136,28 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
buf.append(request.getProtocol());
buf.append("\" ");
int status = response.getStatus();
if (status <= 0)
status = 404;
buf.append((char)('0' + ((status / 100) % 10)));
buf.append((char)('0' + ((status / 10) % 10)));
buf.append((char)('0' + (status % 10)));
long responseLength = response.getLongContentLength();
if (responseLength >= 0)
if (written >= 0)
{
buf.append(' ');
if (responseLength > 99999)
buf.append(responseLength);
if (written > 99999)
buf.append(written);
else
{
if (responseLength > 9999)
buf.append((char)('0' + ((responseLength / 10000) % 10)));
if (responseLength > 999)
buf.append((char)('0' + ((responseLength / 1000) % 10)));
if (responseLength > 99)
buf.append((char)('0' + ((responseLength / 100) % 10)));
if (responseLength > 9)
buf.append((char)('0' + ((responseLength / 10) % 10)));
buf.append((char)('0' + (responseLength) % 10));
if (written > 9999)
buf.append((char)('0' + ((written / 10000) % 10)));
if (written > 999)
buf.append((char)('0' + ((written / 1000) % 10)));
if (written > 99)
buf.append((char)('0' + ((written / 100) % 10)));
if (written > 9)
buf.append((char)('0' + ((written / 10) % 10)));
buf.append((char)('0' + (written) % 10));
}
buf.append(' ');
}
@ -168,7 +166,7 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
if (_extended)
logExtended(request, response, buf);
logExtended(request, buf);
if (_logCookies)
{
@ -216,12 +214,10 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
* Writes extended request and response information to the output stream.
*
* @param request request object
* @param response response object
* @param b StringBuilder to write to
* @throws IOException
*/
protected void logExtended(Request request,
Response response,
StringBuilder b) throws IOException
{
String referer = request.getHeader(HttpHeader.REFERER.toString());

View File

@ -25,6 +25,7 @@ import java.nio.channels.ClosedChannelException;
import java.util.List;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicInteger;
import javax.servlet.DispatcherType;
import javax.servlet.RequestDispatcher;
import javax.servlet.http.HttpServletRequest;
@ -43,6 +44,7 @@ import org.eclipse.jetty.io.EofException;
import org.eclipse.jetty.server.HttpChannelState.Action;
import org.eclipse.jetty.server.handler.ContextHandler;
import org.eclipse.jetty.server.handler.ErrorHandler;
import org.eclipse.jetty.util.BufferUtil;
import org.eclipse.jetty.util.Callback;
import org.eclipse.jetty.util.SharedBlockingCallback.Blocker;
import org.eclipse.jetty.util.log.Log;
@ -96,6 +98,9 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
private final Response _response;
private MetaData.Response _committedInfo;
private RequestLog _requestLog;
/** Bytes written after interception (eg after compression) */
private long _written;
public HttpChannel(Connector connector, HttpConfiguration configuration, EndPoint endPoint, HttpTransport transport, HttpInput input)
{
@ -133,6 +138,21 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
return _transport;
}
public RequestLog getRequestLog()
{
return _requestLog;
}
public void setRequestLog(RequestLog requestLog)
{
_requestLog = requestLog;
}
public MetaData.Response getCommittedInfo()
{
return _committedInfo;
}
/**
* Get the idle timeout.
* <p>This is implemented as a call to {@link EndPoint#getIdleTimeout()}, but may be
@ -212,6 +232,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
_response.recycle();
_committedInfo=null;
_requestLog=null;
_written=0;
}
@Override
@ -401,7 +422,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
finally
{
_request.setHandled(true);
_transport.completed();
onCompleted();
}
}
@ -507,8 +528,9 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
public void onCompleted()
{
if (_requestLog!=null)
_requestLog.log(_request,_response);
if (_requestLog!=null )
_requestLog.log(_request,_committedInfo==null?-1:_committedInfo.getStatus(), _written);
_transport.completed();
}
public void onEarlyEOF()
@ -545,6 +567,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
_state.completed();
else
throw new IllegalStateException();
onCompleted();
}
}
@ -555,7 +578,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
{
// We need an info to commit
if (info==null)
info = _response.newResponseInfo();
info = _response.newResponseMetaData();
commit(info);
// wrap callback to process 100 responses
@ -563,7 +586,6 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
final Callback committed = (status<200&&status>=100)?new Commit100Callback(callback):new CommitCallback(callback);
// committing write
_committedInfo=info;
_transport.send(info, _request.isHead(), content, complete, committed);
}
else if (info==null)
@ -597,6 +619,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
protected void commit (MetaData.Response info)
{
_committedInfo=info;
if (LOG.isDebugEnabled())
LOG.debug("Commit {} to {}",info,this);
}
@ -616,6 +639,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
@Override
public void write(ByteBuffer content, boolean complete, Callback callback)
{
_written+=BufferUtil.length(content);
sendResponse(null,content,complete,callback);
}

View File

@ -514,7 +514,6 @@ public class HttpChannelState
event.completed();
}
_channel.onCompleted();
}
protected void recycle()

View File

@ -64,7 +64,10 @@ public class HttpOutput extends ServletOutputStream implements Runnable
private final HttpChannel _channel;
private final SharedBlockingCallback _writeBlock;
private Interceptor _filter;
/** Bytes written via the write API (excludes bytes written via sendContent). Used to autocommit once content length is written. */
private long _written;
private ByteBuffer _aggregate;
private int _bufferSize;
private int _commitSize;

View File

@ -26,5 +26,5 @@ import org.eclipse.jetty.util.component.LifeCycle;
*/
public interface RequestLog extends LifeCycle
{
public void log(Request request, Response response);
public void log(Request request, int status, long written);
}

View File

@ -1239,7 +1239,7 @@ public class Response implements HttpServletResponse
_out.resetBuffer();
}
protected MetaData.Response newResponseInfo()
protected MetaData.Response newResponseMetaData()
{
return new MetaData.Response(_channel.getRequest().getHttpVersion(), getStatus(), getReason(), _fields, getLongContentLength());
}

View File

@ -28,6 +28,7 @@ import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import org.eclipse.jetty.server.AsyncContextState;
import org.eclipse.jetty.server.HttpChannel;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.RequestLog;
import org.eclipse.jetty.server.Response;
@ -46,41 +47,7 @@ import org.eclipse.jetty.util.log.Logger;
*/
public class RequestLogHandler extends HandlerWrapper
{
private static final Logger LOG = Log.getLogger(RequestLogHandler.class);
private RequestLog _requestLog;
private final AsyncListener _listener = new AsyncListener()
{
@Override
public void onTimeout(AsyncEvent event) throws IOException
{
}
@Override
public void onStartAsync(AsyncEvent event) throws IOException
{
event.getAsyncContext().addListener(this);
}
@Override
public void onError(AsyncEvent event) throws IOException
{
HttpServletResponse response = (HttpServletResponse)event.getAsyncContext().getResponse();
if (!response.isCommitted())
response.setStatus(500);
}
@Override
public void onComplete(AsyncEvent event) throws IOException
{
AsyncContextState context = (AsyncContextState)event.getAsyncContext();
Request request=context.getHttpChannelState().getBaseRequest();
Response response=request.getResponse();
_requestLog.log(request,response);
}
};
/* ------------------------------------------------------------ */
/*
@ -90,29 +57,9 @@ public class RequestLogHandler extends HandlerWrapper
public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response)
throws IOException, ServletException
{
try
{
super.handle(target, baseRequest, request, response);
}
catch(Error|IOException|ServletException|RuntimeException e)
{
if (!response.isCommitted() && !baseRequest.getHttpChannelState().isAsync())
response.setStatus(500);
throw e;
}
finally
{
if (_requestLog != null && baseRequest.getDispatcherType().equals(DispatcherType.REQUEST))
{
if (baseRequest.getHttpChannelState().isAsync())
{
if (baseRequest.getHttpChannelState().isInitial())
baseRequest.getAsyncContext().addListener(_listener);
}
else
_requestLog.log(baseRequest, (Response)response);
}
}
baseRequest.getHttpChannel().setRequestLog(_requestLog);
if (_handler!=null)
_handler.handle(target,baseRequest, request, response);
}
/* ------------------------------------------------------------ */
@ -128,35 +75,5 @@ public class RequestLogHandler extends HandlerWrapper
return _requestLog;
}
/* ------------------------------------------------------------ */
@Override
protected void doStart() throws Exception
{
if (_requestLog==null)
{
LOG.warn("!RequestLog");
_requestLog=new NullRequestLog();
}
super.doStart();
}
/* ------------------------------------------------------------ */
@Override
protected void doStop() throws Exception
{
super.doStop();
if (_requestLog instanceof NullRequestLog)
_requestLog=null;
}
/* ------------------------------------------------------------ */
/* ------------------------------------------------------------ */
/* ------------------------------------------------------------ */
private static class NullRequestLog extends AbstractLifeCycle implements RequestLog
{
@Override
public void log(Request request, Response response)
{
}
}
}

View File

@ -43,7 +43,6 @@ import javax.servlet.http.HttpServletResponse;
import org.eclipse.jetty.server.Connector;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.RequestLog;
import org.eclipse.jetty.server.Response;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.util.IO;
@ -72,9 +71,9 @@ public class BadRequestLogHandlerTest
public List<String> captured = new ArrayList<>();
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getHttpURI(),request.getProtocol(),response.getStatus()));
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getHttpURI(),request.getProtocol(),status));
}
}

View File

@ -76,9 +76,9 @@ public class RequestLogHandlerTest
public List<String> captured = new ArrayList<>();
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),response.getStatus()));
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),status));
}
}
@ -663,9 +663,9 @@ public class RequestLogHandlerTest
server.addBean(errorDispatcher);
ContextHandlerCollection contexts = new ContextHandlerCollection();
ContextHandler errorContext = new ContextHandler("errorok");
ContextHandler errorContext = new ContextHandler("/errorok");
errorContext.setHandler(new OKErrorHandler());
ContextHandler testContext = new ContextHandler("test");
ContextHandler testContext = new ContextHandler("/test");
testContext.setHandler(testHandler);
contexts.addHandler(errorContext);
contexts.addHandler(testContext);

View File

@ -45,7 +45,6 @@ import javax.servlet.http.HttpServletResponseWrapper;
import org.eclipse.jetty.server.Connector;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.RequestLog;
import org.eclipse.jetty.server.Response;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.server.handler.RequestLogHandler;
@ -107,9 +106,9 @@ public class AsyncServletTest
@After
public void tearDown() throws Exception
{
_server.stop();
assertEquals(_expectedLogs,_log.size());
Assert.assertThat(_log.get(0), Matchers.containsString(_expectedCode));
_server.stop();
}
@Test
@ -888,9 +887,9 @@ public class AsyncServletTest
class Log extends AbstractLifeCycle implements RequestLog
{
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
_log.add(response.getStatus()+" "+response.getContentCount()+" "+request.getRequestURI());
_log.add(status+" "+written+" "+request.getRequestURI());
}
}
}

View File

@ -77,9 +77,9 @@ public class ServletRequestLogTest
public List<String> captured = new ArrayList<>();
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),response.getStatus()));
captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),status));
}
}

View File

@ -26,7 +26,6 @@ import java.util.List;
import org.eclipse.jetty.server.Connector;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.RequestLog;
import org.eclipse.jetty.server.Response;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.server.handler.RequestLogHandler;
@ -194,9 +193,9 @@ public class ContinuationTest extends ContinuationBase
class Log extends AbstractLifeCycle implements RequestLog
{
@Override
public void log(Request request, Response response)
public void log(Request request, int status, long written)
{
_log.add(response.getStatus()+" "+response.getContentCount()+" "+request.getRequestURI());
_log.add(status+" "+written+" "+request.getRequestURI());
}
}