446564 Refactored RequestLog Mechanism

RequestLog can now be set on the HttpChannel and is called during the onCommitted callback.
The RequestLog may be set either on the server or via an updated RequestLogHandler that can
be applied to a specific context.
This commit is contained in:
Greg Wilkins 2014-10-31 13:29:38 +11:00
parent 947a872203
commit e3bda4efbe
10 changed files with 368 additions and 47 deletions

View File

@ -109,6 +109,7 @@ public class HttpChannelOverHTTP2 extends HttpChannel
@Override
protected void commit(MetaData.Response info)
{
super.commit(info);
if (LOG.isDebugEnabled())
{
LOG.debug("HTTP2 Commit Response #{}/{}:{}{} {} {}{}{}",

View File

@ -7,26 +7,18 @@
<Configure id="Server" class="org.eclipse.jetty.server.Server">
<!-- =========================================================== -->
<!-- Configure Request Log -->
<!-- Configure Request Log for Server -->
<!-- (Use RequestLogHandler for a context specific RequestLog -->
<!-- =========================================================== -->
<Ref refid="Handlers">
<Call name="addHandler">
<Arg>
<New id="RequestLog" class="org.eclipse.jetty.server.handler.RequestLogHandler">
<Set name="requestLog">
<New id="RequestLogImpl" class="org.eclipse.jetty.server.AsyncNCSARequestLog">
<Set name="filename"><Property name="jetty.base" default="." /><Property name="requestlog.filename" default="/logs/yyyy_mm_dd.request.log"/></Set>
<Set name="filenameDateFormat"><Property name="requestlog.filenameDateFormat" default="yyyy_MM_dd"/></Set>
<Set name="retainDays"><Property name="requestlog.retain" default="90"/></Set>
<Set name="append"><Property name="requestlog.append" default="false"/></Set>
<Set name="extended"><Property name="requestlog.extended" default="false"/></Set>
<Set name="logCookies"><Property name="requestlog.cookies" default="false"/></Set>
<Set name="LogTimeZone"><Property name="requestlog.timezone" default="GMT"/></Set>
</New>
</Set>
</New>
</Arg>
</Call>
</Ref>
<Set name="RequestLog">
<New id="RequestLog" class="org.eclipse.jetty.server.AsyncNCSARequestLog">
<Set name="filename"><Property name="jetty.base" default="." /><Property name="requestlog.filename" default="/logs/yyyy_mm_dd.request.log"/></Set>
<Set name="filenameDateFormat"><Property name="requestlog.filenameDateFormat" default="yyyy_MM_dd"/></Set>
<Set name="retainDays"><Property name="requestlog.retain" default="90"/></Set>
<Set name="append"><Property name="requestlog.append" default="false"/></Set>
<Set name="extended"><Property name="requestlog.extended" default="false"/></Set>
<Set name="logCookies"><Property name="requestlog.cookies" default="false"/></Set>
<Set name="LogTimeZone"><Property name="requestlog.timezone" default="GMT"/></Set>
</New>
</Set>
</Configure>

View File

@ -78,7 +78,15 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
public abstract void write(String requestEntry) throws IOException;
/* ------------------------------------------------------------ */
private void append(StringBuilder buf,String s)
{
if (s==null || s.length()==0)
buf.append('-');
else
buf.append(s);
}
/**
* Writes the request and response information to the output stream.
*
@ -101,7 +109,7 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
if (_logServer)
{
buf.append(request.getServerName());
append(buf,request.getServerName());
buf.append(' ');
}
@ -117,10 +125,7 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
buf.append(addr);
buf.append(" - ");
Authentication authentication = request.getAuthentication();
if (authentication instanceof Authentication.User)
buf.append(((Authentication.User)authentication).getUserIdentity().getUserPrincipal().getName());
else
buf.append("-");
append(buf,(authentication instanceof Authentication.User)?((Authentication.User)authentication).getUserIdentity().getUserPrincipal().getName():null);
buf.append(" [");
if (_logDateCache != null)
@ -129,18 +134,21 @@ public abstract class AbstractNCSARequestLog extends AbstractLifeCycle implement
buf.append(request.getTimeStamp());
buf.append("] \"");
buf.append(request.getMethod());
append(buf,request.getMethod());
buf.append(' ');
buf.append(request.getHttpURI().toString());
append(buf,request.getHttpURI().toString());
buf.append(' ');
buf.append(request.getProtocol());
append(buf,request.getProtocol());
buf.append("\" ");
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)));
if (status >=0)
{
buf.append((char)('0' + ((status / 100) % 10)));
buf.append((char)('0' + ((status / 10) % 10)));
buf.append((char)('0' + (status % 10)));
}
else
buf.append(status);
if (written >= 0)
{

View File

@ -113,6 +113,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
input.init(_state);
_request = new Request(this, input);
_response = new Response(this, new HttpOutput(this));
_requestLog=_connector==null?null:_connector.getServer().getRequestLog();
}
public HttpChannelState getState()
@ -231,7 +232,7 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
_request.recycle();
_response.recycle();
_committedMetaData=null;
_requestLog=null;
_requestLog=_connector==null?null:_connector.getServer().getRequestLog();
_written=0;
}
@ -501,12 +502,11 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
public void onRequest(MetaData.Request request)
{
_requests.incrementAndGet();
_request.setTimeStamp(System.currentTimeMillis());
_request.setMetaData(request);
if (_configuration.getSendDateHeader())
_response.getHttpFields().put(_connector.getServer().getDateField());
_request.setMetaData(request);
}
public void onContent(HttpInput.Content content)

View File

@ -36,12 +36,16 @@ import org.eclipse.jetty.http.HttpURI;
import org.eclipse.jetty.http.HttpVersion;
import org.eclipse.jetty.http.MetaData;
import org.eclipse.jetty.io.EndPoint;
import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.Logger;
/**
* A HttpChannel customized to be transported over the HTTP/1 protocol
*/
class HttpChannelOverHttp extends HttpChannel implements HttpParser.RequestHandler, HttpParser.ProxyHandler
{
private static final Logger LOG = Log.getLogger(HttpChannelOverHttp.class);
private final HttpConnection _httpConnection;
private final HttpFields _fields = new HttpFields();
private HttpField _connection;
@ -226,6 +230,16 @@ class HttpChannelOverHttp extends HttpChannel implements HttpParser.RequestHandl
public void badMessage(int status, String reason)
{
_httpConnection._generator.setPersistent(false);
try
{
// Need to call onRequest, so RequestLog can reports as much as possible
onRequest(_metadata);
}
catch (Exception e)
{
LOG.ignore(e);
}
onBadMessage(status,reason);
}

View File

@ -990,7 +990,12 @@ public class Request implements HttpServletRequest
@Override
public String getProtocol()
{
return _metadata==null?null:_metadata.getVersion().toString();
if (_metadata==null)
return null;
HttpVersion version = _metadata.getVersion();
if (version==null)
return null;
return version.toString();
}
/* ------------------------------------------------------------ */
@ -1636,21 +1641,29 @@ public class Request implements HttpServletRequest
uri.setPath(path);
}
else
{
setPathInfo("");
throw new BadMessageException(400,"Bad URI");
}
info=path;
}
else if (!path.startsWith("/"))
{
System.err.println(request);
if (!"*".equals(path) && !HttpMethod.CONNECT.is(getMethod()))
{
setPathInfo(path);
throw new BadMessageException(400,"Bad URI");
}
info=path;
}
else
info = URIUtil.canonicalPath(path);// TODO should this be done prior to decoding???
if (info == null)
{
setPathInfo(path);
throw new BadMessageException(400,"Bad URI");
}
setPathInfo(info);
}

View File

@ -18,13 +18,15 @@
package org.eclipse.jetty.server;
import org.eclipse.jetty.util.component.LifeCycle;
import org.eclipse.jetty.server.handler.RequestLogHandler;
/**
* A <code>RequestLog</code> can be attached to a {@link org.eclipse.jetty.server.handler.RequestLogHandler} to enable
* logging of requests/responses.
* @see RequestLogHandler#setRequestLog(RequestLog)
* @see Server#setRequestLog(RequestLog)
*/
public interface RequestLog extends LifeCycle
public interface RequestLog
{
public void log(Request request, int status, long written);
}

View File

@ -85,6 +85,7 @@ public class Server extends HandlerWrapper implements Attributes
private boolean _stopAtShutdown;
private boolean _dumpAfterStart=false;
private boolean _dumpBeforeStop=false;
private RequestLog _requestLog;
private volatile DateField _dateField;
@ -121,8 +122,6 @@ public class Server extends HandlerWrapper implements Attributes
setConnectors(new Connector[]{connector});
}
/* ------------------------------------------------------------ */
public Server(@Name("threadpool") ThreadPool pool)
{
@ -131,6 +130,18 @@ public class Server extends HandlerWrapper implements Attributes
setServer(this);
}
/* ------------------------------------------------------------ */
public RequestLog getRequestLog()
{
return _requestLog;
}
/* ------------------------------------------------------------ */
public void setRequestLog(RequestLog requestLog)
{
updateBean(_requestLog,requestLog);
_requestLog = requestLog;
}
/* ------------------------------------------------------------ */
@ManagedAttribute("version of this server")

View File

@ -32,17 +32,19 @@ import org.eclipse.jetty.server.HttpChannel;
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.util.component.AbstractLifeCycle;
import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.Logger;
/**
* RequestLogHandler.
* This handler can be used to wrap an individual context for context logging.
* To set a {@link RequestLog} instance for the entire {@link Server}, use
* {@link Server#setRequestLog(RequestLog)} instead of this handler.
*
*
* @see Server#setRequestLog(RequestLog)
* @org.apache.xbean.XBean
*/
public class RequestLogHandler extends HandlerWrapper

View File

@ -0,0 +1,278 @@
//
// ========================================================================
// Copyright (c) 1995-2014 Mort Bay Consulting Pty. Ltd.
// ------------------------------------------------------------------------
// 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.server.handler;
import static org.hamcrest.Matchers.containsString;
import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.startsWith;
import static org.junit.Assert.*;
import java.io.IOException;
import java.io.InputStream;
import java.io.PrintWriter;
import java.util.Arrays;
import java.util.concurrent.Exchanger;
import java.util.concurrent.TimeUnit;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import org.eclipse.jetty.server.AbstractNCSARequestLog;
import org.eclipse.jetty.server.LocalConnector;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.Server;
import org.hamcrest.Matchers;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
public class RequestLogTest
{
Exchanger<String> _log;
Server _server;
LocalConnector _connector;
@Before
public void before() throws Exception
{
_log = new Exchanger<String>();
_server = new Server();
_connector = new LocalConnector(_server);
_server.addConnector(_connector);
_server.setRequestLog(new Log());
_server.setHandler(new TestHandler());
_server.start();
}
@After
public void after() throws Exception
{
_server.stop();
}
@Test
public void testNotHandled() throws Exception
{
_connector.getResponses("GET /foo HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo HTTP/1.0\" 404 "));
}
@Test
public void testSmallData() throws Exception
{
_connector.getResponses("GET /foo?data=42 HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo?"));
assertThat(log,containsString(" 200 42 "));
}
@Test
public void testBigData() throws Exception
{
_connector.getResponses("GET /foo?data=102400 HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo?"));
assertThat(log,containsString(" 200 102400 "));
}
@Test
public void testStatus() throws Exception
{
_connector.getResponses("GET /foo?status=206 HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo?"));
assertThat(log,containsString(" 206 0 "));
}
@Test
public void testStatusData() throws Exception
{
_connector.getResponses("GET /foo?status=206&data=42 HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo?"));
assertThat(log,containsString(" 206 42 "));
}
@Test
public void testBadRequest() throws Exception
{
_connector.getResponses("XXXXXXXXXXXX\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("\"- - -\""));
assertThat(log,containsString(" 400 0 "));
}
@Test
public void testBadCharacter() throws Exception
{
_connector.getResponses("METHOD /f\00o HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("\"- - -\""));
assertThat(log,containsString(" 400 0 "));
}
@Test
public void testBadVersion() throws Exception
{
_connector.getResponses("METHOD /foo HTTP/9\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("\"- - -\""));
assertThat(log,containsString(" 400 0 "));
}
@Test
public void testLongURI() throws Exception
{
char[] chars = new char[10000];
Arrays.fill(chars,'o');
String ooo = new String(chars);
_connector.getResponses("METHOD /f"+ooo+" HTTP/1.0\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("\"- - -\""));
assertThat(log,containsString(" 414 0 "));
}
@Test
public void testLongHeader() throws Exception
{
char[] chars = new char[10000];
Arrays.fill(chars,'o');
String ooo = new String(chars);
_connector.getResponses("METHOD /foo HTTP/1.0\name: f+"+ooo+"\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("\"METHOD /foo HTTP/1.0\""));
assertThat(log,containsString(" 413 0 "));
}
@Test
public void testBadRequestNoHost() throws Exception
{
_connector.getResponses("GET /foo HTTP/1.1\n\n");
String log = _log.exchange(null,5,TimeUnit.SECONDS);
assertThat(log,containsString("GET /foo "));
assertThat(log,containsString(" 400 0 "));
}
private class Log extends AbstractNCSARequestLog
{
{
super.setExtended(true);
}
@Override
protected boolean isEnabled()
{
return true;
}
@Override
public void write(String requestEntry) throws IOException
{
try
{
_log.exchange(requestEntry);
}
catch(Exception e)
{
e.printStackTrace();
}
}
}
private class TestHandler extends AbstractHandler
{
@Override
public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
{
String q = request.getQueryString();
if (q==null)
return;
baseRequest.setHandled(true);
for (String action : q.split("\\&"))
{
String[] param = action.split("=");
String name=param[0];
String value=param.length>1?param[1]:null;
switch(name)
{
case "status":
{
response.setStatus(Integer.parseInt(value));
break;
}
case "data":
{
int data = Integer.parseInt(value);
PrintWriter out = response.getWriter();
int w=0;
while (w<data)
{
if ((data-w)>17)
{
w+=17;
out.print("0123456789ABCDEF\n");
}
else
{
w++;
out.print("\n");
}
}
break;
}
case "throw":
{
try
{
throw (Throwable)(Class.forName(value).newInstance());
}
catch(ServletException | IOException | Error | RuntimeException e)
{
throw e;
}
catch(Throwable e)
{
throw new ServletException(e);
}
}
case "flush":
{
response.flushBuffer();
break;
}
case "read":
{
InputStream in = request.getInputStream();
while (in.read()>=0);
break;
}
}
}
}
}
}