You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@jena.apache.org by an...@apache.org on 2013/05/16 16:29:22 UTC
svn commit: r1483388 - in
/jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets:
HttpServletResponseTracker.java SPARQL_ServletBase.java WebRequest.java
Author: andy
Date: Thu May 16 14:29:22 2013
New Revision: 1483388
URL: http://svn.apache.org/r1483388
Log:
Record start and finish timepoints of request execution (inc sending results).
Add to final log message for each request.
Added:
jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/WebRequest.java
Modified:
jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/HttpServletResponseTracker.java
jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/SPARQL_ServletBase.java
Modified: jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/HttpServletResponseTracker.java
URL: http://svn.apache.org/viewvc/jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/HttpServletResponseTracker.java?rev=1483388&r1=1483387&r2=1483388&view=diff
==============================================================================
--- jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/HttpServletResponseTracker.java (original)
+++ jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/HttpServletResponseTracker.java Thu May 16 14:29:22 2013
@@ -19,8 +19,6 @@
package org.apache.jena.fuseki.servlets;
import java.io.IOException ;
-import java.util.HashMap ;
-import java.util.Map ;
import javax.servlet.http.HttpServletResponse ;
import javax.servlet.http.HttpServletResponseWrapper ;
@@ -31,30 +29,27 @@ import org.apache.jena.atlas.logging.Log
public class HttpServletResponseTracker extends HttpServletResponseWrapper
{
- Map <String, String> headers = new HashMap<String, String>() ;
- int statusCode = -1 ;
- String message = null ;
- int contentLength = -1 ;
- String contentType = null ;
+ private final WebRequest webRequest ;
- public HttpServletResponseTracker(HttpServletResponse response)
+ public HttpServletResponseTracker(WebRequest webRequest, HttpServletResponse response)
{
super(response) ;
+ this.webRequest = webRequest ;
}
@Override
public void sendError(int sc, String msg) throws IOException
{
- statusCode = sc ;
- message = msg ;
+ webRequest.statusCode = sc ;
+ webRequest.message = msg ;
super.sendError(sc, msg) ;
}
@Override
public void sendError(int sc) throws IOException
{
- statusCode = sc ;
- message = null ;
+ webRequest.statusCode = sc ;
+ webRequest.message = null ;
super.sendError(sc) ;
}
@@ -62,6 +57,7 @@ public class HttpServletResponseTracker
public void setHeader(String name, String value)
{
super.setHeader(name, value) ;
+ webRequest.headers.put(name, value) ;
}
@Override
@@ -73,8 +69,8 @@ public class HttpServletResponseTracker
@Override
public void setStatus(int sc)
{
- statusCode = sc ;
- message = null ;
+ webRequest.statusCode = sc ;
+ webRequest.message = null ;
super.setStatus(sc) ;
}
@@ -82,22 +78,22 @@ public class HttpServletResponseTracker
@Deprecated
public void setStatus(int sc, String sm)
{
- statusCode = sc ;
- message = sm ;
+ webRequest.statusCode = sc ;
+ webRequest.message = sm ;
super.setStatus(sc, sm) ;
}
@Override
public void setContentLength(int len)
{
- contentLength = len ;
+ webRequest.contentLength = len ;
super.setContentLength(len) ;
}
@Override
public void setContentType(String type)
{
- contentType = type ;
+ webRequest.contentType = type ;
super.setContentType(type) ;
}
Modified: jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/SPARQL_ServletBase.java
URL: http://svn.apache.org/viewvc/jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/SPARQL_ServletBase.java?rev=1483388&r1=1483387&r2=1483388&view=diff
==============================================================================
--- jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/SPARQL_ServletBase.java (original)
+++ jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/SPARQL_ServletBase.java Thu May 16 14:29:22 2013
@@ -54,38 +54,54 @@ public abstract class SPARQL_ServletBase
protected void doCommon(HttpServletRequest request, HttpServletResponse response)
//throws ServletException, IOException
{
- long id = allocRequestId(request, response);
- printRequest(id, request) ;
-
- HttpServletResponseTracker responseTracked = new HttpServletResponseTracker(response) ;
- response = responseTracked ;
- initResponse(request, response) ;
- Context cxt = ARQ.getContext() ;
-
try {
- validate(request) ;
- doCommonWorker(id, request, response) ;
- } catch (QueryCancelledException ex) {
- // Also need the per query info ...
- String message = String.format("The query timed out (restricted to %s ms)", cxt.get(ARQ.queryTimeout));
- // Possibility :: response.setHeader("Retry-after", "600") ; // 5 minutes
- responseSendError(response, HttpSC.SERVICE_UNAVAILABLE_503, message);
- } catch (ActionErrorException ex) {
- if ( ex.exception != null )
- ex.exception.printStackTrace(System.err) ;
- // Log message done by printResponse in a moment.
- if ( ex.message != null )
- responseSendError(response, ex.rc, ex.message) ;
- else
- responseSendError(response, ex.rc) ;
- } catch (Throwable ex) {
- // This should not happen.
- //ex.printStackTrace(System.err) ;
- log.warn(format("[%d] RC = %d : %s", id, HttpSC.INTERNAL_SERVER_ERROR_500, ex.getMessage()), ex) ;
- responseSendError(response, HttpSC.INTERNAL_SERVER_ERROR_500, ex.getMessage()) ;
+ long id = allocRequestId(request, response);
+
+ // Lifecycle
+ WebRequest wRequest = allocWebAction(id, request, response) ;
+ // then add to doCommonWorker
+ // work with HttpServletResponseTracker
+
+ printRequest(wRequest) ;
+ wRequest.setStartTime() ;
+
+ response = wRequest.getResponse() ;
+ initResponse(request, response) ;
+ Context cxt = ARQ.getContext() ;
+
+ try {
+ validate(request) ;
+ doCommonWorker(id, request, response) ;
+ } catch (QueryCancelledException ex) {
+ // Also need the per query info ...
+ String message = String.format("The query timed out (restricted to %s ms)", cxt.get(ARQ.queryTimeout));
+ // Possibility :: response.setHeader("Retry-after", "600") ; // 5 minutes
+ responseSendError(response, HttpSC.SERVICE_UNAVAILABLE_503, message);
+ } catch (ActionErrorException ex) {
+ if ( ex.exception != null )
+ ex.exception.printStackTrace(System.err) ;
+ // Log message done by printResponse in a moment.
+ if ( ex.message != null )
+ responseSendError(response, ex.rc, ex.message) ;
+ else
+ responseSendError(response, ex.rc) ;
+ } catch (Throwable ex) {
+ // This should not happen.
+ //ex.printStackTrace(System.err) ;
+ log.warn(format("[%d] RC = %d : %s", id, HttpSC.INTERNAL_SERVER_ERROR_500, ex.getMessage()), ex) ;
+ responseSendError(response, HttpSC.INTERNAL_SERVER_ERROR_500, ex.getMessage()) ;
+ }
+
+ wRequest.setFinishTime() ;
+ printResponse(wRequest) ;
+ } catch (Throwable th) {
+ log.error("Internal error", th) ;
}
+ }
- printResponse(id, responseTracked) ;
+ /** Return a fresh WebAction for this request */
+ protected WebRequest allocWebAction(long id, HttpServletRequest request, HttpServletResponse response) {
+ return new WebRequest(id, request, response) ;
}
protected abstract void validate(HttpServletRequest request) ;
@@ -121,25 +137,25 @@ public abstract class SPARQL_ServletBase
response.sendError(HttpServletResponse.SC_METHOD_NOT_ALLOWED, "HTTP PATCH not supported");
}
- private void printRequest(long id, HttpServletRequest request)
+ private void printRequest(WebRequest wAction)
{
- String url = wholeRequestURL(request) ;
- String method = request.getMethod() ;
+ String url = wholeRequestURL(wAction.getRequest()) ;
+ String method = wAction.getRequest().getMethod() ;
- log.info(format("[%d] %s %s", id, method, url)) ;
+ log.info(format("[%d] %s %s", wAction.id, method, url)) ;
if ( verbose_debug )
{
- Enumeration<String> en = request.getHeaderNames() ;
+ Enumeration<String> en = wAction.getRequest().getHeaderNames() ;
for ( ; en.hasMoreElements() ; )
{
String h = en.nextElement() ;
- Enumeration<String> vals = request.getHeaders(h) ;
+ Enumeration<String> vals = wAction.getRequest().getHeaders(h) ;
if ( ! vals.hasMoreElements() )
- log.info(format("[%d] ",id, h)) ;
+ log.info(format("[%d] ", wAction.id, h)) ;
else
{
for ( ; vals.hasMoreElements() ; )
- log.info(format("[%d] %-20s %s", id, h, vals.nextElement())) ;
+ log.info(format("[%d] %-20s %s", wAction.id, h, vals.nextElement())) ;
}
}
}
@@ -154,24 +170,37 @@ public abstract class SPARQL_ServletBase
setVaryHeader(response) ;
}
- private void printResponse(long id, HttpServletResponseTracker response)
+ private void printResponse(WebRequest wRequest)
{
+ long time = wRequest.getTime() ;
+
+ HttpServletResponseTracker response = wRequest.getResponse() ;
if ( verbose_debug )
{
- if ( response.contentType != null )
- log.info(format("[%d] %-20s %s", id, HttpNames.hContentType, response.contentType)) ;
- if ( response.contentLength != -1 )
- log.info(format("[%d] %-20s %d", id, HttpNames.hContentLengh, response.contentLength)) ;
- for ( Map.Entry<String, String> e: response.headers.entrySet() )
- log.info(format("[%d] %-20s %s", id, e.getKey(), e.getValue())) ;
+ if ( wRequest.contentType != null )
+ log.info(format("[%d] %-20s %s", wRequest.id, HttpNames.hContentType, wRequest.contentType)) ;
+ if ( wRequest.contentLength != -1 )
+ log.info(format("[%d] %-20s %d", wRequest.id, HttpNames.hContentLengh, wRequest.contentLength)) ;
+ for ( Map.Entry<String, String> e: wRequest.getHeaders().entrySet() )
+ log.info(format("[%d] %-20s %s", wRequest.id, e.getKey(), e.getValue())) ;
}
-
- if ( response.message == null )
- log.info(String.format("[%d] %d %s", id, response.statusCode, HttpSC.getMessage(response.statusCode))) ;
+
+ String timeStr = fmtMillis(time) ;
+
+ if ( wRequest.message == null )
+ log.info(String.format("[%d] %d %s (%s) ", wRequest.id, wRequest.statusCode, HttpSC.getMessage(wRequest.statusCode), timeStr)) ;
else
- log.info(String.format("[%d] %d %s", id, response.statusCode, response.message)) ;
+ log.info(String.format("[%d] %d %s (%s) ", wRequest.id, wRequest.statusCode, wRequest.message, timeStr)) ;
}
+ private static String fmtMillis(long time)
+ {
+ // Millis only? seconds only?
+ if ( time < 1000 )
+ return String.format("%,d ms", time) ;
+ return String.format("%,.3f s", time/1000.0) ;
+ }
+
/** Map request to uri in the registry.
* null means no mapping done (passthrough).
*/
Added: jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/WebRequest.java
URL: http://svn.apache.org/viewvc/jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/WebRequest.java?rev=1483388&view=auto
==============================================================================
--- jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/WebRequest.java (added)
+++ jena/trunk/jena-fuseki/src/main/java/org/apache/jena/fuseki/servlets/WebRequest.java Thu May 16 14:29:22 2013
@@ -0,0 +1,102 @@
+/**
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.jena.fuseki.servlets;
+
+import java.util.HashMap ;
+import java.util.Map ;
+
+import javax.servlet.http.HttpServletRequest ;
+import javax.servlet.http.HttpServletResponse ;
+
+import org.apache.jena.atlas.logging.Log ;
+
+public class WebRequest
+{
+ // ActionLifescycle?
+
+ // This is the object created for an action.
+ Map <String, String> headers = new HashMap<String, String>() ;
+ public final long id ;
+
+ private boolean startTimeIsSet = false ;
+ private boolean finishTimeIsSet = false ;
+
+ private long startTime = -2 ;
+ private long finishTime = -2 ;
+
+ // Outcome.
+ int statusCode = -1 ;
+ String message = null ;
+ int contentLength = -1 ;
+ String contentType = null ;
+
+ // In production, don't hold onto large objects like the request or response for too long.
+ private HttpServletRequest request ;
+ private HttpServletResponseTracker response ;
+
+ public WebRequest(long id, HttpServletRequest request , HttpServletResponse response )
+ {
+ this.id = id ;
+ this.request = request ;
+ this.response = new HttpServletResponseTracker(this, response) ;
+ }
+
+ /** Reduce to a size that can be kept around for sometime */
+ public void minimize()
+ {
+ this.request = null ;
+ this.response = null ;
+ }
+
+ public void setStartTime() {
+ if ( startTimeIsSet )
+ Log.warn(this, "Start time reset") ;
+ startTimeIsSet = true ;
+ this.startTime = System.nanoTime() ;
+ }
+
+ public void setFinishTime() {
+ if ( finishTimeIsSet )
+ Log.warn(this, "Finish time reset") ;
+ finishTimeIsSet = true ;
+ this.finishTime = System.nanoTime() ;
+ }
+
+ /** Return the recorded time taken in milliseconds.
+ * {@linkplain #setStartTime} and {@linkplain #setFinishTime}
+ * must have been called.
+ */
+ public long getTime()
+ {
+ if ( ! startTimeIsSet )
+ Log.warn(this, "Start time not set") ;
+ if ( ! finishTimeIsSet )
+ Log.warn(this, "Finish time not set") ;
+ return (finishTime-startTime)/(1000*1000) ;
+ }
+
+ public Map <String, String> getHeaders() { return headers ; }
+
+ public HttpServletRequest getRequest() { return request ; }
+
+ public HttpServletResponseTracker getResponse() { return response ; }
+
+
+}
+