From bae0994fb91bceefcde5a27ee0ca8ee51bf0247d Mon Sep 17 00:00:00 2001 From: fhanik Date: Sat, 27 Mar 2010 01:50:13 +0000 Subject: [PATCH] Add in some debug, what is causing some TCK failures is a request/response pair not being recycled properly git-svn-id: https://svn.apache.org/repos/asf/tomcat/trunk@928120 13f79535-47bb-0310-9956-ffa450edef68 --- .../apache/catalina/connector/CoyoteAdapter.java | 2 +- java/org/apache/catalina/connector/Request.java | 1 + .../org/apache/catalina/core/AsyncContextImpl.java | 24 ++++++++++++++++------ .../org/apache/catalina/valves/AccessLogValve.java | 15 ++++++++++++-- java/org/apache/coyote/ajp/AjpProcessor.java | 2 +- .../apache/coyote/http11/Http11NioProcessor.java | 2 +- java/org/apache/coyote/http11/Http11Processor.java | 2 +- java/org/apache/coyote/http11/Http11Protocol.java | 8 ++++++-- 8 files changed, 42 insertions(+), 14 deletions(-) diff --git a/java/org/apache/catalina/connector/CoyoteAdapter.java b/java/org/apache/catalina/connector/CoyoteAdapter.java index aebfffa92..b71fe1d00 100644 --- a/java/org/apache/catalina/connector/CoyoteAdapter.java +++ b/java/org/apache/catalina/connector/CoyoteAdapter.java @@ -344,7 +344,7 @@ public class CoyoteAdapter implements Adapter { } finally { req.getRequestProcessor().setWorkerThreadName(null); // Recycle the wrapper request and response - if (!comet && !async) { + if (!success || (!comet && !async)) { request.recycle(); response.recycle(); } else { diff --git a/java/org/apache/catalina/connector/Request.java b/java/org/apache/catalina/connector/Request.java index 62ad7eb3c..f343338a1 100644 --- a/java/org/apache/catalina/connector/Request.java +++ b/java/org/apache/catalina/connector/Request.java @@ -490,6 +490,7 @@ public class Request asyncSupported = null; if (asyncContext!=null) asyncContext.recycle(); + asyncContext = null; } diff --git a/java/org/apache/catalina/core/AsyncContextImpl.java b/java/org/apache/catalina/core/AsyncContextImpl.java index 5abda6f28..c699bdede 100644 --- a/java/org/apache/catalina/core/AsyncContextImpl.java +++ b/java/org/apache/catalina/core/AsyncContextImpl.java @@ -66,18 +66,22 @@ public class AsyncContextImpl implements AsyncContext { private Request request; public AsyncContextImpl(Request request) { + if (log.isDebugEnabled()) { + log.debug("AsyncContext created["+request.getRequestURI()+"?"+request.getQueryString()+"]", new DebugException()); + } //TODO SERVLET3 - async this.request = request; } @Override public void complete() { + if (log.isDebugEnabled()) { + log.debug("AsyncContext Complete Called["+state.get()+"; "+request.getRequestURI()+"?"+request.getQueryString()+"]", new DebugException()); + } if (state.get()==AsyncState.COMPLETING) { //do nothing - } else if (state.compareAndSet(AsyncState.STARTED, AsyncState.COMPLETING)) { - // TODO SERVLET3 - async - doInternalComplete(false); - } else if (state.compareAndSet(AsyncState.DISPATCHED, AsyncState.COMPLETING)) { + } else if (state.compareAndSet(AsyncState.DISPATCHED, AsyncState.COMPLETING) || + state.compareAndSet(AsyncState.STARTED, AsyncState.COMPLETING)) { // TODO SERVLET3 - async AtomicBoolean dispatched = new AtomicBoolean(false); request.getCoyoteRequest().action(ActionCode.ACTION_ASYNC_COMPLETE,dispatched); @@ -104,12 +108,16 @@ public class AsyncContextImpl implements AsyncContext { @Override public void dispatch(ServletContext context, String path) { + if (log.isDebugEnabled()) { + log.debug("AsyncContext Dispatch Called["+state.get()+"; "+path+"; "+request.getRequestURI()+"?"+request.getQueryString()+"]", new DebugException()); + } + // TODO SERVLET3 - async if (state.compareAndSet(AsyncState.STARTED, AsyncState.DISPATCHING) || state.compareAndSet(AsyncState.DISPATCHED, AsyncState.DISPATCHING)) { if (request.getAttribute(ASYNC_REQUEST_URI)==null) { - request.setAttribute(ASYNC_REQUEST_URI, request.getRequestURI()); + request.setAttribute(ASYNC_REQUEST_URI, request.getRequestURI()+"?"+request.getQueryString()); request.setAttribute(ASYNC_CONTEXT_PATH, request.getContextPath()); request.setAttribute(ASYNC_SERVLET_PATH, request.getServletPath()); request.setAttribute(ASYNC_QUERY_STRING, request.getQueryString()); @@ -166,6 +174,10 @@ public class AsyncContextImpl implements AsyncContext { @Override public void start(final Runnable run) { + if (log.isDebugEnabled()) { + log.debug("AsyncContext Start Called["+state.get()+"; "+request.getRequestURI()+"?"+request.getQueryString()+"]", new DebugException()); + } + if (state.compareAndSet(AsyncState.STARTED, AsyncState.DISPATCHING) || state.compareAndSet(AsyncState.DISPATCHED, AsyncState.DISPATCHING)) { // TODO SERVLET3 - async @@ -386,5 +398,5 @@ public class AsyncContextImpl implements AsyncContext { this.servletResponse = response; event = new AsyncEvent(this, request, response); } - + public static class DebugException extends Exception {} } diff --git a/java/org/apache/catalina/valves/AccessLogValve.java b/java/org/apache/catalina/valves/AccessLogValve.java index 5bae26b6c..1fb23bcba 100644 --- a/java/org/apache/catalina/valves/AccessLogValve.java +++ b/java/org/apache/catalina/valves/AccessLogValve.java @@ -124,7 +124,7 @@ public class AccessLogValve extends ValveBase { //------------------------------------------------------ Constructor public AccessLogValve() { - super(false); + super(true); } // ----------------------------------------------------- Instance Variables @@ -543,13 +543,24 @@ public class AccessLogValve extends ValveBase { @Override public void invoke(Request request, Response response) throws IOException, ServletException { - + final String t1Name = AccessLogValve.class.getName()+".t1"; if (getState().isAvailable() && getEnabled()) { // Pass this request on to the next valve in our pipeline long t1 = System.currentTimeMillis(); + boolean asyncdispatch = request.isAsyncDispatching(); + if (!asyncdispatch) { + request.setAttribute(t1Name, new Long(t1)); + } getNext().invoke(request, response); + //we're not done with the request + if (request.isAsyncDispatching()) { + return; + } else if (asyncdispatch && request.getAttribute(t1Name)!=null) { + t1 = ((Long)request.getAttribute(t1Name)).longValue(); + } + long t2 = System.currentTimeMillis(); long time = t2 - t1; diff --git a/java/org/apache/coyote/ajp/AjpProcessor.java b/java/org/apache/coyote/ajp/AjpProcessor.java index 2bd43fc58..6f44911a4 100644 --- a/java/org/apache/coyote/ajp/AjpProcessor.java +++ b/java/org/apache/coyote/ajp/AjpProcessor.java @@ -674,7 +674,7 @@ public class AjpProcessor implements ActionHook { dispatch.set(true); endpoint.processSocket(this.socket, SocketStatus.STOP); } else { - dispatch.set(true); + dispatch.set(false); } } else if (actionCode == ActionCode.ACTION_ASYNC_SETTIMEOUT) { //TODO SERVLET3 - async diff --git a/java/org/apache/coyote/http11/Http11NioProcessor.java b/java/org/apache/coyote/http11/Http11NioProcessor.java index b27a00561..3eeb5bd75 100644 --- a/java/org/apache/coyote/http11/Http11NioProcessor.java +++ b/java/org/apache/coyote/http11/Http11NioProcessor.java @@ -778,7 +778,7 @@ public class Http11NioProcessor extends AbstractHttp11Processor implements Actio dispatch.set(true); endpoint.processSocket(this.socket, SocketStatus.STOP, true); } else { - dispatch.set(true); + dispatch.set(false); } } else if (actionCode == ActionCode.ACTION_ASYNC_SETTIMEOUT) { //TODO SERVLET3 - async diff --git a/java/org/apache/coyote/http11/Http11Processor.java b/java/org/apache/coyote/http11/Http11Processor.java index 2e8f8015b..54bd9a907 100644 --- a/java/org/apache/coyote/http11/Http11Processor.java +++ b/java/org/apache/coyote/http11/Http11Processor.java @@ -619,7 +619,7 @@ public class Http11Processor extends AbstractHttp11Processor implements ActionHo dispatch.set(true); endpoint.processSocket(this.socket, SocketStatus.STOP); } else { - dispatch.set(true); + dispatch.set(false); } } else if (actionCode == ActionCode.ACTION_ASYNC_SETTIMEOUT) { //TODO SERVLET3 - async diff --git a/java/org/apache/coyote/http11/Http11Protocol.java b/java/org/apache/coyote/http11/Http11Protocol.java index 399079e04..2a8e3f928 100644 --- a/java/org/apache/coyote/http11/Http11Protocol.java +++ b/java/org/apache/coyote/http11/Http11Protocol.java @@ -242,6 +242,7 @@ public class Http11Protocol extends AbstractHttp11Protocol { public SocketState process(SocketWrapper socket, SocketStatus status) { Http11Processor processor = connections.remove(socket); + boolean recycle = true; try { if (processor == null) { processor = recycledProcessors.poll(); @@ -262,6 +263,7 @@ public class Http11Protocol extends AbstractHttp11Protocol { if (state == SocketState.LONG) { connections.put(socket, processor); socket.setAsync(true); + recycle = false; } else { connections.remove(socket); socket.setAsync(false); @@ -291,8 +293,10 @@ public class Http11Protocol extends AbstractHttp11Protocol { // if(proto.adapter != null) proto.adapter.recycle(); // processor.recycle(); - processor.action(ActionCode.ACTION_STOP, null); - recycledProcessors.offer(processor); + if (recycle) { + processor.action(ActionCode.ACTION_STOP, null); + recycledProcessors.offer(processor); + } } return SocketState.CLOSED; } -- 2.11.0