Merge branch 'maint-rel-1.6' into develop

webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/RDFServiceUtils.java

@@ -23,6 +23,7 @@ import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFService.ModelSerialization
 import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFService.ResultFormat;
 import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFServiceException;
 import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFServiceFactory;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.LoggingRDFServiceFactory;
 
 public class RDFServiceUtils {
 
@@ -34,7 +35,18 @@ public class RDFServiceUtils {
        
     public static RDFServiceFactory getRDFServiceFactory(ServletContext context) {
         Object o = context.getAttribute(RDFSERVICEFACTORY_ATTR);
-        return (o instanceof RDFServiceFactory) ? (RDFServiceFactory) o : null;
+        if (o instanceof RDFServiceFactory) {
+        	RDFServiceFactory factory = (RDFServiceFactory) o;
+        	
+			/*
+			 * Every factory is wrapped in a logger, so we can dynamically
+			 * enable or disable logging.
+			 */
+        	return new LoggingRDFServiceFactory(context, factory);
+        } else {
+        	log.error("Expecting an RDFServiceFactory on the context, but found " + o);
+        	return null;
+        }
     }
     
     public static void setRDFServiceFactory(ServletContext context, 

webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/LoggingRDFService.java

@@ -0,0 +1,125 @@
+/* $This file is distributed under the terms of the license in /doc/license.txt$ */
+
+package edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging;
+
+import java.io.InputStream;
+import java.util.List;
+
+import javax.servlet.ServletContext;
+
+import edu.cornell.mannlib.vitro.webapp.rdfservice.ChangeListener;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.ChangeSet;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFService;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFServiceException;
+
+/**
+ * This RDFService wrapper adds instrumentation to the time-consuming methods of
+ * the inner RDFService.
+ * 
+ * For the other methods, it just delegates to the inner RDFService.
+ */
+public class LoggingRDFService implements RDFService {
+	private final ServletContext ctx;
+	private final RDFService innerService;
+
+	LoggingRDFService(ServletContext ctx, RDFService innerService) {
+		this.ctx = ctx;
+		this.innerService = innerService;
+	}
+
+	// ----------------------------------------------------------------------
+	// Timed methods
+	// ----------------------------------------------------------------------
+
+	@Override
+	public boolean changeSetUpdate(ChangeSet changeSet)
+			throws RDFServiceException {
+		try (RDFServiceLogger l = new RDFServiceLogger(ctx, changeSet)) {
+			return innerService.changeSetUpdate(changeSet);
+		}
+	}
+
+	@Override
+	public InputStream sparqlConstructQuery(String query,
+			ModelSerializationFormat resultFormat) throws RDFServiceException {
+		try (RDFServiceLogger l = new RDFServiceLogger(ctx, resultFormat, query)) {
+			return innerService.sparqlConstructQuery(query, resultFormat);
+		}
+	}
+
+	@Override
+	public InputStream sparqlDescribeQuery(String query,
+			ModelSerializationFormat resultFormat) throws RDFServiceException {
+		try (RDFServiceLogger l = new RDFServiceLogger(ctx, resultFormat, query)) {
+			return innerService.sparqlDescribeQuery(query, resultFormat);
+		}
+	}
+
+	@Override
+	public InputStream sparqlSelectQuery(String query, ResultFormat resultFormat)
+			throws RDFServiceException {
+		try (RDFServiceLogger l = new RDFServiceLogger(ctx, resultFormat, query)) {
+			return innerService.sparqlSelectQuery(query, resultFormat);
+		}
+	}
+
+	@Override
+	public boolean sparqlAskQuery(String query) throws RDFServiceException {
+		try (RDFServiceLogger l = new RDFServiceLogger(ctx, query)) {
+			return innerService.sparqlAskQuery(query);
+		}
+	}
+
+	// ----------------------------------------------------------------------
+	// Untimed methods
+	// ----------------------------------------------------------------------
+
+	@Override
+	public void newIndividual(String individualURI, String individualTypeURI)
+			throws RDFServiceException {
+		innerService.newIndividual(individualURI, individualTypeURI);
+	}
+
+	@Override
+	public void newIndividual(String individualURI, String individualTypeURI,
+			String graphURI) throws RDFServiceException {
+		innerService.newIndividual(individualURI, individualTypeURI, graphURI);
+	}
+
+	@Override
+	public List<String> getGraphURIs() throws RDFServiceException {
+		return innerService.getGraphURIs();
+	}
+
+	@Override
+	public void getGraphMetadata() throws RDFServiceException {
+		innerService.getGraphMetadata();
+	}
+
+	@Override
+	public String getDefaultWriteGraphURI() throws RDFServiceException {
+		return innerService.getDefaultWriteGraphURI();
+	}
+
+	@Override
+	public void registerListener(ChangeListener changeListener)
+			throws RDFServiceException {
+		innerService.registerListener(changeListener);
+	}
+
+	@Override
+	public void unregisterListener(ChangeListener changeListener)
+			throws RDFServiceException {
+		innerService.unregisterListener(changeListener);
+	}
+
+	@Override
+	public ChangeSet manufactureChangeSet() {
+		return innerService.manufactureChangeSet();
+	}
+
+	@Override
+	public void close() {
+		innerService.close();
+	}
+}

webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/LoggingRDFServiceFactory.java

@@ -0,0 +1,48 @@
+/* $This file is distributed under the terms of the license in /doc/license.txt$ */
+
+package edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging;
+
+import javax.servlet.ServletContext;
+
+import edu.cornell.mannlib.vitro.webapp.rdfservice.ChangeListener;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFService;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFServiceException;
+import edu.cornell.mannlib.vitro.webapp.rdfservice.RDFServiceFactory;
+
+/**
+ * If the RDFServiceFactory is wrapped in this, then all RDFServices will be
+ * wrapped in a LoggingRDFService.
+ */
+public class LoggingRDFServiceFactory implements RDFServiceFactory {
+	private final ServletContext ctx;
+	private final RDFServiceFactory factory;
+
+	public LoggingRDFServiceFactory(ServletContext ctx,
+			RDFServiceFactory factory) {
+		this.ctx = ctx;
+		this.factory = factory;
+	}
+
+	@Override
+	public RDFService getRDFService() {
+		return new LoggingRDFService(ctx, factory.getRDFService());
+	}
+
+	@Override
+	public RDFService getShortTermRDFService() {
+		return new LoggingRDFService(ctx, factory.getShortTermRDFService());
+	}
+
+	@Override
+	public void registerListener(ChangeListener changeListener)
+			throws RDFServiceException {
+		factory.registerListener(changeListener);
+	}
+
+	@Override
+	public void unregisterListener(ChangeListener changeListener)
+			throws RDFServiceException {
+		factory.unregisterListener(changeListener);
+	}
+
+}

webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/RDFServiceLogger.java

@@ -0,0 +1,175 @@
+/* $This file is distributed under the terms of the license in /doc/license.txt$ */
+
+package edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging;
+
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Collections;
+import java.util.List;
+import java.util.ListIterator;
+import java.util.regex.Pattern;
+
+import javax.servlet.ServletContext;
+
+import org.apache.commons.lang.StringUtils;
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+
+import edu.cornell.mannlib.vitro.webapp.config.ConfigurationProperties;
+
+/**
+ * Writes the log message for the LoggingRDFService.
+ * 
+ * If not enabled, or if the logging level is insufficient, this does nothing.
+ * 
+ * If enabled, it checks for restrictions. If there is a restriction pattern
+ * (regular expression), the a log message will only be printed if one of the
+ * fully-qualified class names in the stack trace matches that pattern.
+ * 
+ * If everything passes muster, the constructor will record the time that the
+ * instance was created.
+ * 
+ * When close() is called, if a start time was recorded, then a log record is
+ * produced. This contains the elapsed time, the name of the method, and any
+ * arguments passed to the constructor. It may also include a stack trace, if
+ * requested.
+ * 
+ * The stack trace is abbreviated. It will reach into this class, and will not
+ * extend past the first reference to the ApplicationFilterChain. Perhaps it
+ * should be abbreviated further?
+ */
+public class RDFServiceLogger implements AutoCloseable {
+	private static final Log log = LogFactory.getLog(RDFServiceLogger.class);
+
+	private static final String PROPERTY_ENABLED = "developer.loggingRDFService.enable";
+	private static final String PROPERTY_STACK_TRACE = "developer.loggingRDFService.stackTrace";
+	private static final String PROPERTY_RESTRICTION = "developer.loggingRDFService.restriction";
+
+	private final ServletContext ctx;
+	private final Object[] args;
+
+	private boolean isEnabled;
+	private boolean traceRequested;
+	private Pattern restriction;
+
+	private String methodName;
+	private List<StackTraceElement> trace = Collections.emptyList();
+
+	private long startTime;
+
+	public RDFServiceLogger(ServletContext ctx, Object... args) {
+		this.ctx = ctx;
+		this.args = args;
+
+		getProperties();
+
+		if (isEnabled && log.isInfoEnabled()) {
+			loadStackTrace();
+			if (passesRestrictions()) {
+				this.startTime = System.currentTimeMillis();
+			}
+		}
+	}
+
+	private void getProperties() {
+		ConfigurationProperties props = ConfigurationProperties.getBean(ctx);
+		isEnabled = Boolean.valueOf(props.getProperty(PROPERTY_ENABLED));
+		traceRequested = Boolean.valueOf(props
+				.getProperty(PROPERTY_STACK_TRACE));
+
+		String restrictionString = props.getProperty(PROPERTY_RESTRICTION);
+		if (StringUtils.isNotBlank(restrictionString)) {
+			try {
+				restriction = Pattern.compile(restrictionString);
+			} catch (Exception e) {
+				log.error("Failed to compile the pattern for "
+						+ PROPERTY_RESTRICTION + " = " + restriction + " " + e);
+				isEnabled = false;
+			}
+		}
+	}
+
+	private void loadStackTrace() {
+		StackTraceElement[] stack = Thread.currentThread().getStackTrace();
+		List<StackTraceElement> list = new ArrayList<StackTraceElement>(
+				Arrays.asList(stack));
+
+		trimStackTraceAtBeginning(list);
+		trimStackTraceAtEnd(list);
+
+		if (list.isEmpty()) {
+			this.methodName = "UNKNOWN";
+		} else {
+			this.methodName = list.get(0).getMethodName();
+		}
+
+		this.trace = list;
+	}
+
+	private void trimStackTraceAtBeginning(List<StackTraceElement> list) {
+		ListIterator<StackTraceElement> iter = list.listIterator();
+		while (iter.hasNext()) {
+			StackTraceElement ste = iter.next();
+			if (ste.getClassName().equals(LoggingRDFService.class.getName())) {
+				break;
+			} else {
+				iter.remove();
+			}
+		}
+	}
+
+	private void trimStackTraceAtEnd(List<StackTraceElement> list) {
+		ListIterator<StackTraceElement> iter = list.listIterator();
+		boolean trimming = false;
+		while (iter.hasNext()) {
+			StackTraceElement ste = iter.next();
+			if (trimming) {
+				iter.remove();
+			} else if (ste.getClassName().contains("ApplicationFilterChain")) {
+				trimming = true;
+			}
+		}
+	}
+
+	private boolean passesRestrictions() {
+		if (restriction == null) {
+			return true;
+		}
+		for (StackTraceElement ste : trace) {
+			if (restriction.matcher(ste.getClassName()).matches()) {
+				return true;
+			}
+		}
+		return false;
+	}
+
+	@Override
+	public void close() {
+		if (startTime != 0L) {
+			long endTime = System.currentTimeMillis();
+
+			float elapsedSeconds = (endTime - startTime) / 1000.0F;
+			String cleanArgs = Arrays.deepToString(args).replaceAll(
+					"[\\n\\r\\t]+", " ");
+			String formattedTrace = formatStackTrace();
+
+			log.info(String.format("%8.3f %s %s %s", elapsedSeconds,
+					methodName, cleanArgs, formattedTrace));
+		}
+	}
+
+	private String formatStackTrace() {
+		StringBuilder sb = new StringBuilder();
+
+		if (traceRequested) {
+			for (StackTraceElement ste : trace) {
+				sb.append(String.format("\n   %d %s", ste.getLineNumber(),
+						ste.getClassName()));
+			}
+			sb.append("\n   ...");
+		}
+
+		return sb.toString();
+	}
+
+}