From 6178aa03474b2a7614ca315d8dca01f498ddb443 Mon Sep 17 00:00:00 2001 From: Jim Blake Date: Mon, 5 May 2014 16:53:36 -0400 Subject: [PATCH] Add SearchEngine logging to the Developer Panel --- webapp/config/example.developer.properties | 82 +---- .../impl/logging/RDFServiceLogger.java | 116 +------ .../searchengine/SearchEngineLogger.java | 297 ++++++++++++++++++ .../searchengine/SearchEngineWrapper.java | 38 ++- .../base/BaseSearchFacetField.java | 10 + .../base/BaseSearchInputDocument.java | 6 + .../base/BaseSearchInputField.java | 6 + .../searchengine/base/BaseSearchResponse.java | 6 + .../base/BaseSearchResultDocument.java | 6 + .../vitro/webapp/utils/developer/Key.java | 57 ++++ .../developer/loggers/StackTraceUtility.java | 139 ++++++++ .../webapp/utils/searchengine/Formatter.java | 145 +++++++++ webapp/web/js/developer/developerPanel.js | 14 + .../page/partials/developerPanel.ftl | 45 ++- 14 files changed, 774 insertions(+), 193 deletions(-) create mode 100644 webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineLogger.java create mode 100644 webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/loggers/StackTraceUtility.java create mode 100644 webapp/src/edu/cornell/mannlib/vitro/webapp/utils/searchengine/Formatter.java diff --git a/webapp/config/example.developer.properties b/webapp/config/example.developer.properties index 78a1d2a72..ae395081c 100644 --- a/webapp/config/example.developer.properties +++ b/webapp/config/example.developer.properties @@ -11,6 +11,9 @@ # WARNING: Some of these options can seriously degrade performance. They should # not be enabled in a production instance of VIVO. # +# For more information go to +# https://wiki.duraspace.org/display/VIVO/The+Developer+Panel +# # ----------------------------------------------------------------------------- # @@ -18,18 +21,7 @@ # General options #------------------------------------------------------------------------------ -# -# The "master switch" for developer mode. If this is not set to true, then none -# of the other properties have any effect. -# # developer.enabled = true - -# -# If developer mode is enabled, this will determine who can modify the -# developer settings. If 'true', then any user can modify the settings. If -# false, then only a site administrator (or root) can modify the settings. -# The default is 'false'. -# # developer.permitAnonymousControl @@ -37,20 +29,7 @@ # Freemarker #------------------------------------------------------------------------------ -# -# Add HTML comments to each Freemarker template, so you can see what each -# templates to the page, by viewing the source of the page in the browser. -# The default is 'false'. -# # developer.insertFreemarkerDelimiters = true - -# -# Defeat the Freemarker template cache, so each template is read from disk -# on each request. This permits developers to immediately see the effect of -# changes to the template. The default is 'false', which means that a cached -# copy of each template will be used for 60 seconds before the disk is checked -# for a new version. -# # developer.defeatFreemarkerCache = true @@ -58,17 +37,7 @@ # Page configuration #------------------------------------------------------------------------------ -# -# Turn on logging of custom list view configuration files. Each time a property -# uses a list view other than the default, note it in the log. The default is -# 'false'. -# # developer.pageContents.logCustomListView = true - -# -# Turn on logging of custom short views. Each time an individual uses a short -# view other than the default, note it in the log. The default is 'false'. -# # developer.pageContents.logCustomShortView = true @@ -76,19 +45,7 @@ # Internationalization #------------------------------------------------------------------------------ -# -# Defeat the cache of language-specific text strings, so the language file -# is read from disk on each request. This permits developers to immediately -# see the effect of changes to the text strings. The default is 'false', which -# means that the language file is only read when VIVO starts up, or when a new -# theme is selected. -# # developer.i18n.defeatCache = true - -# -# Write a line to the log every time a template or a controller requests a -# language-specific string from the properties files. -# # developer.i18n.logStringRequests @@ -96,40 +53,7 @@ # Logging SPARQL queries #------------------------------------------------------------------------------ -# -# Turn on logging of all SPARQL queries. The logging is at the INFO level. -# Each entry includes: -# - the elapsed time spent on the query, in seconds, -# - the name of the method on RDFService that received the query, -# - the format of the result stream from the RDFService method, -# - the text of the query. -# Note that all access to the content models is done through SPARQL queries, -# but some go through translation layers before reaching the RDFService for -# logging and execution. The default is 'false'. -# # developer.loggingRDFService.enable = true - -# -# If SPARQL query logging is enabled, this will add a stack trace to each log -# entry. The stack trace is abridged, so it starts after the -# ApplicationFilterChain, omits any Jena classes, and ends at the RDFService. -# The default is 'false'. -# # developer.loggingRDFService.stackTrace = true - -# -# If SPARQL query logging is enabled, restrict the number of log entries by -# matching a regular expression against the query string. If the expression -# doesn't match the string, then no log entry is made. The default is "", -# which means no restriction. -# # developer.loggingRDFService.queryRestriction = .* - -# -# If SPARQL query logging is enabled, restrict the number of log entries by -# matching a regular expression against the stack trace. The abridged stack -# trace is concatenated into a single string of fully qualified class names -# and method names. If the expression doesn't match the string, then no log -# entry is made. The default is "", which means no restriction. -# # developer.loggingRDFService.stackRestriction = .* diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/RDFServiceLogger.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/RDFServiceLogger.java index 35c2b9701..4daebd9fe 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/RDFServiceLogger.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/rdfservice/impl/logging/RDFServiceLogger.java @@ -4,9 +4,7 @@ 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 org.apache.commons.lang.StringUtils; @@ -15,6 +13,7 @@ import org.apache.commons.logging.LogFactory; import edu.cornell.mannlib.vitro.webapp.utils.developer.DeveloperSettings; import edu.cornell.mannlib.vitro.webapp.utils.developer.Key; +import edu.cornell.mannlib.vitro.webapp.utils.developer.loggers.StackTraceUtility; /** * Writes the log message for the LoggingRDFService. @@ -43,26 +42,32 @@ import edu.cornell.mannlib.vitro.webapp.utils.developer.Key; public class RDFServiceLogger implements AutoCloseable { private static final Log log = LogFactory.getLog(RDFServiceLogger.class); - private final Object[] args; + private static boolean isEnabled() { + return log.isInfoEnabled() + && DeveloperSettings.getInstance().getBoolean( + Key.LOGGING_RDF_ENABLE); + } + + private final Object[] args; + private final StackTraceUtility stackTrace; - private boolean isEnabled; private boolean traceRequested; private Pattern queryStringRestriction; private Pattern callStackRestriction; - private String methodName; - private List trace = Collections.emptyList(); - private long startTime; public RDFServiceLogger(Object... args) { this.args = args; + this.stackTrace = new StackTraceUtility(LoggingRDFService.class, + isEnabled()); try { getProperties(); - if (isEnabled && log.isInfoEnabled()) { - loadStackTrace(); - if (passesQueryRestriction() && passesStackRestriction()) { + if (isEnabled()) { + if (passesQueryRestriction() + && stackTrace + .passesStackRestriction(callStackRestriction)) { this.startTime = System.currentTimeMillis(); } } @@ -73,7 +78,6 @@ public class RDFServiceLogger implements AutoCloseable { private void getProperties() { DeveloperSettings settings = DeveloperSettings.getInstance(); - isEnabled = settings.getBoolean(Key.LOGGING_RDF_ENABLE); traceRequested = settings.getBoolean(Key.LOGGING_RDF_STACK_TRACE); queryStringRestriction = patternFromSettings(settings, Key.LOGGING_RDF_QUERY_RESTRICTION); @@ -95,61 +99,6 @@ public class RDFServiceLogger implements AutoCloseable { } } - private void loadStackTrace() { - StackTraceElement[] stack = Thread.currentThread().getStackTrace(); - List list = new ArrayList( - Arrays.asList(stack)); - - trimStackTraceAtBeginning(list); - trimStackTraceAtEnd(list); - removeJenaClassesFromStackTrace(list); - - if (list.isEmpty()) { - this.methodName = "UNKNOWN"; - } else { - this.methodName = list.get(0).getMethodName(); - } - - this.trace = list; - log.debug("Stack array: " + Arrays.toString(stack)); - log.debug("Stack trace: " + this.trace); - } - - private void trimStackTraceAtBeginning(List list) { - ListIterator 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 list) { - ListIterator 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 void removeJenaClassesFromStackTrace(List list) { - ListIterator iter = list.listIterator(); - while (iter.hasNext()) { - StackTraceElement ste = iter.next(); - if (ste.getClassName().startsWith("com.hp.hpl.jena.")) { - iter.remove(); - } - } - } - private boolean passesQueryRestriction() { if (queryStringRestriction == null) { return true; @@ -168,23 +117,6 @@ public class RDFServiceLogger implements AutoCloseable { return StringUtils.join(stringArgs, " "); } - private boolean passesStackRestriction() { - if (callStackRestriction == null) { - return true; - } - String q = assembleCallStackString(); - return callStackRestriction.matcher(q).find(); - } - - private String assembleCallStackString() { - StringBuilder stack = new StringBuilder(); - for (StackTraceElement ste : trace) { - stack.append(ste.getClassName()).append(" ") - .append(ste.getMethodName()).append(" "); - } - return stack.deleteCharAt(stack.length() - 1).toString(); - } - @Override public void close() { try { @@ -194,28 +126,14 @@ public class RDFServiceLogger implements AutoCloseable { float elapsedSeconds = (endTime - startTime) / 1000.0F; String cleanArgs = Arrays.deepToString(args).replaceAll( "[\\n\\r\\t]+", " "); - String formattedTrace = formatStackTrace(); + String formattedTrace = stackTrace.format(traceRequested); log.info(String.format("%8.3f %s %s %s", elapsedSeconds, - methodName, cleanArgs, formattedTrace)); + stackTrace.getMethodName(), cleanArgs, formattedTrace)); } } catch (Exception e) { log.error("Failed to write log record", e); } } - private String formatStackTrace() { - StringBuilder sb = new StringBuilder(); - - if (traceRequested) { - for (StackTraceElement ste : trace) { - sb.append(String.format("\n line %4d, %s", - ste.getLineNumber(), ste.getClassName())); - } - sb.append("\n ..."); - } - - return sb.toString(); - } - } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineLogger.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineLogger.java new file mode 100644 index 000000000..2dd2047a3 --- /dev/null +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineLogger.java @@ -0,0 +1,297 @@ +/* $This file is distributed under the terms of the license in /doc/license.txt$ */ + +package edu.cornell.mannlib.vitro.webapp.searchengine; + +import java.util.ArrayList; +import java.util.Arrays; +import java.util.Collection; +import java.util.Collections; +import java.util.List; +import java.util.regex.Pattern; + +import org.apache.commons.lang.StringUtils; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchInputDocument; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchQuery; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchResponse; +import edu.cornell.mannlib.vitro.webapp.utils.developer.DeveloperSettings; +import edu.cornell.mannlib.vitro.webapp.utils.developer.Key; +import edu.cornell.mannlib.vitro.webapp.utils.developer.loggers.StackTraceUtility; +import edu.cornell.mannlib.vitro.webapp.utils.searchengine.Formatter; + +/** + * Logging the SearchEngine, for the Developer's panel. + */ +public abstract class SearchEngineLogger implements AutoCloseable { + private static final Log log = LogFactory.getLog(SearchEngineLogger.class); + + // ---------------------------------------------------------------------- + // Factory + // ---------------------------------------------------------------------- + public static SearchEngineLogger doAdd(SearchInputDocument[] docs) { + return new AddLogger(Arrays.asList(docs)); + } + + public static SearchEngineLogger doAdd(Collection docs) { + return new AddLogger(docs); + } + + public static SearchEngineLogger doDeleteById(String[] ids) { + return new DeleteIdsLogger(Arrays.asList(ids)); + } + + public static SearchEngineLogger doDeleteById(Collection ids) { + return new DeleteIdsLogger(ids); + } + + public static SearchEngineLogger doDeleteByQuery(String query) { + return new DeleteQueryLogger(query); + } + + public static SearchEngineLogger doQuery(SearchQuery query) { + return new QueryLogger(query); + } + + // ---------------------------------------------------------------------- + // Abstract instance + // ---------------------------------------------------------------------- + + private final long startTime; + protected final boolean enabled; + + public SearchEngineLogger(Key enableKey) { + this.startTime = System.currentTimeMillis(); + this.enabled = log.isInfoEnabled() + && DeveloperSettings.getInstance().getBoolean(enableKey); + } + + protected float elapsedSeconds() { + long endTime = System.currentTimeMillis(); + return (endTime - startTime) / 1000.0F; + } + + @Override + public void close() { + if (enabled) { + try { + writeToLog(); + } catch (Exception e) { + log.error("Failed to write log record", e); + } + } + + } + + public void setSearchResponse(SearchResponse response) { + throw new UnsupportedOperationException(this.getClass().getSimpleName() + + " does not support setSearchResponse()"); + } + + protected abstract void writeToLog(); + + // ---------------------------------------------------------------------- + // Concrete sub-classes + // ---------------------------------------------------------------------- + + private static class AddLogger extends SearchEngineLogger { + private final List docs; + private final boolean passesRestrictions; + + AddLogger(Collection docs) { + super(Key.SEARCH_INDEX_ENABLE); + + this.docs = restrictDocsByUriOrName(docs); + + this.passesRestrictions = enabled && passesDocumentRestriction() + && this.docs.size() > 0; + } + + private List restrictDocsByUriOrName( + Collection rawDocs) { + if (!enabled) { + return Collections.emptyList(); + } + + String restriction = DeveloperSettings.getInstance().getString( + Key.SEARCH_INDEX_URI_OR_NAME_RESTRICTION); + if (restriction.isEmpty()) { + return new ArrayList<>(rawDocs); + } + + List list = new ArrayList<>(); + for (SearchInputDocument doc : rawDocs) { + if (passesUriOrNameRestriction(doc, restriction)) { + list.add(doc); + } + } + return list; + } + + private boolean passesUriOrNameRestriction(SearchInputDocument doc, + String restriction) { + try { + return Pattern.matches(restriction, Formatter.format(doc)); + } catch (Exception e) { + log.warn("Failed to test URI or Name restriction: '" + + restriction + "'", e); + return true; + } + } + + private boolean passesDocumentRestriction() { + String restriction = DeveloperSettings.getInstance().getString( + Key.SEARCH_INDEX_DOCUMENT_RESTRICTION); + if (!restriction.isEmpty()) { + try { + return Pattern.matches(restriction, docContents()); + } catch (Exception e) { + log.warn("Failed to test document restriction: '" + + restriction + "'", e); + } + } + return true; + } + + @Override + public void writeToLog() { + if (!passesRestrictions) { + return; + } + if (showDocumentContents()) { + log.info(String.format("%8.3f added %d documents: \n%s", + elapsedSeconds(), docs.size(), docContents())); + } else { + log.info(String.format("%8.3f added %d documents: \n%s", + elapsedSeconds(), docs.size(), docUris())); + } + } + + private boolean showDocumentContents() { + return DeveloperSettings.getInstance().getBoolean( + Key.SEARCH_INDEX_SHOW_DOCUMENTS); + } + + private String docUris() { + StringBuilder sb = new StringBuilder(); + for (SearchInputDocument doc : docs) { + sb.append(Formatter.getValueFromField(doc, "URI")) + .append(" - ") + .append(Formatter.getValueFromField(doc, "nameRaw")) + .append("\n"); + } + return sb.toString(); + } + + private String docContents() { + StringBuilder sb = new StringBuilder(); + for (SearchInputDocument doc : docs) { + sb.append(Formatter.format(doc)); + } + return sb.toString(); + } + + } + + private static class DeleteIdsLogger extends SearchEngineLogger { + private final List ids; + + DeleteIdsLogger(Collection ids) { + super(Key.SEARCH_DELETIONS_ENABLE); + this.ids = new ArrayList<>(ids); + } + + @Override + public void writeToLog() { + log.info(String.format( + "%8.3f deleted these %d search documents: %s\n", + elapsedSeconds(), ids.size(), StringUtils.join(ids, ", "))); + } + } + + private static class DeleteQueryLogger extends SearchEngineLogger { + private final String query; + + DeleteQueryLogger(String query) { + super(Key.SEARCH_DELETIONS_ENABLE); + this.query = query; + } + + @Override + public void writeToLog() { + log.info(String.format( + "%8.3f delete documents as found by this query: %s\n", + elapsedSeconds(), query)); + } + } + + public static class QueryLogger extends SearchEngineLogger { + private final SearchQuery query; + private final StackTraceUtility stackTrace; + private final boolean passesRestrictions; + + private SearchResponse response; + + QueryLogger(SearchQuery query) { + super(Key.SEARCH_ENGINE_ENABLE); + this.query = query; + this.stackTrace = new StackTraceUtility(SearchEngineWrapper.class, + enabled); + this.passesRestrictions = enabled && passesQueryRestriction() + && passesStackRestriction(); + log.debug("QueryLogger: enabled=" + enabled + ", query=" + query + + ", passes=" + passesRestrictions); + } + + private boolean passesStackRestriction() { + return stackTrace.passesStackRestriction(DeveloperSettings + .getInstance().getString( + Key.SEARCH_ENGINE_STACK_RESTRICTION)); + } + + private boolean passesQueryRestriction() { + String restriction = DeveloperSettings.getInstance().getString( + Key.SEARCH_ENGINE_QUERY_RESTRICTION); + if (StringUtils.isEmpty(restriction)) { + return true; + } + try { + return Pattern.matches(restriction, Formatter.format(query)); + } catch (Exception e) { + log.warn("Failed to test query restriction: '" + restriction + + "'", e); + return true; + } + } + + @Override + public void setSearchResponse(SearchResponse response) { + this.response = response; + } + + @Override + public void writeToLog() { + if (!passesRestrictions) { + return; + } + String results = (showSearchResults()) ? Formatter.format(response) + : " returned " + response.getResults().size() + + " results.\n"; + String trace = stackTrace.format(showStackTrace()); + log.info(String.format("%8.3f %s%s%s", elapsedSeconds(), + Formatter.format(query), results, trace)); + } + + private boolean showSearchResults() { + return DeveloperSettings.getInstance().getBoolean( + Key.SEARCH_ENGINE_ADD_RESULTS); + } + + private boolean showStackTrace() { + return DeveloperSettings.getInstance().getBoolean( + Key.SEARCH_ENGINE_ADD_STACK_TRACE); + } + } + +} diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineWrapper.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineWrapper.java index 6cbd9b52b..df1bb4878 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineWrapper.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/SearchEngineWrapper.java @@ -116,15 +116,19 @@ public class SearchEngineWrapper implements SearchEngine { @Override public void add(SearchInputDocument... docs) throws SearchEngineException { - confirmActive(); - innerEngine.add(docs); + try (SearchEngineLogger l = SearchEngineLogger.doAdd(docs)) { + confirmActive(); + innerEngine.add(docs); + } } @Override public void add(Collection docs) throws SearchEngineException { - confirmActive(); - innerEngine.add(docs); + try (SearchEngineLogger l = SearchEngineLogger.doAdd(docs)) { + confirmActive(); + innerEngine.add(docs); + } } @Override @@ -141,20 +145,26 @@ public class SearchEngineWrapper implements SearchEngine { @Override public void deleteById(String... ids) throws SearchEngineException { - confirmActive(); - innerEngine.deleteById(ids); + try (SearchEngineLogger l = SearchEngineLogger.doDeleteById(ids)) { + confirmActive(); + innerEngine.deleteById(ids); + } } @Override public void deleteById(Collection ids) throws SearchEngineException { - confirmActive(); - innerEngine.deleteById(ids); + try (SearchEngineLogger l = SearchEngineLogger.doDeleteById(ids)) { + confirmActive(); + innerEngine.deleteById(ids); + } } @Override public void deleteByQuery(String query) throws SearchEngineException { - confirmActive(); - innerEngine.deleteByQuery(query); + try (SearchEngineLogger l = SearchEngineLogger.doDeleteByQuery(query)) { + confirmActive(); + innerEngine.deleteByQuery(query); + } } @Override @@ -171,8 +181,12 @@ public class SearchEngineWrapper implements SearchEngine { @Override public SearchResponse query(SearchQuery query) throws SearchEngineException { - confirmActive(); - return innerEngine.query(query); + try (SearchEngineLogger l = SearchEngineLogger.doQuery(query)) { + confirmActive(); + SearchResponse response = innerEngine.query(query); + l.setSearchResponse(response); + return response; + } } } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchFacetField.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchFacetField.java index 55caed27e..642219488 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchFacetField.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchFacetField.java @@ -29,6 +29,11 @@ public class BaseSearchFacetField implements SearchFacetField { return values; } + @Override + public String toString() { + return "BaseSearchFacetField[name=" + name + ", values=" + values + "]"; + } + /** * A foundation class for implementing SearchFacetField.Count. */ @@ -51,5 +56,10 @@ public class BaseSearchFacetField implements SearchFacetField { return count; } + @Override + public String toString() { + return "BaseCount[name=" + name + ", count=" + count + "]"; + } + } } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputDocument.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputDocument.java index 70656b6e8..a41054ff3 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputDocument.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputDocument.java @@ -77,4 +77,10 @@ public class BaseSearchInputDocument implements SearchInputDocument { return new BaseSearchInputField(name); } + @Override + public String toString() { + return "BaseSearchInputDocument[fieldMap=" + fieldMap + + ", documentBoost=" + documentBoost + "]"; + } + } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputField.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputField.java index 69dd3857e..b0ce82393 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputField.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchInputField.java @@ -61,4 +61,10 @@ public class BaseSearchInputField implements SearchInputField { } } + @Override + public String toString() { + return "BaseSearchInputField[name=" + name + ", valueList=" + + valueList + ", boost=" + boost + "]"; + } + } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResponse.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResponse.java index 955b1f20a..77273fd64 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResponse.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResponse.java @@ -48,4 +48,10 @@ public class BaseSearchResponse implements SearchResponse { return new ArrayList<>(facetFields.values()); } + @Override + public String toString() { + return "BaseSearchResponse[highlighting=" + highlighting + + ", facetFields=" + facetFields + ", results=" + results + "]"; + } + } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResultDocument.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResultDocument.java index 6c33823b6..a3ba2b951 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResultDocument.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/searchengine/base/BaseSearchResultDocument.java @@ -72,4 +72,10 @@ public class BaseSearchResultDocument implements SearchResultDocument { return fieldValuesMap; } + @Override + public String toString() { + return "BaseSearchResultDocument [uniqueId=" + uniqueId + + ", fieldValuesMap=" + fieldValuesMap + "]"; + } + } diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/Key.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/Key.java index fed8dabd1..9c19c51ad 100644 --- a/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/Key.java +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/Key.java @@ -86,6 +86,63 @@ public enum Key { PAGE_CONTENTS_LOG_CUSTOM_SHORT_VIEW( "developer.pageContents.logCustomShortView", true), + /** + * Tell the SearchEngineLogger to log all indexing operations. + */ + SEARCH_INDEX_ENABLE("developer.searchIndex.enable", true), + + /** + * Add the document contents to the log of indexing operations. + */ + SEARCH_INDEX_SHOW_DOCUMENTS("developer.searchIndex.showDocuments", true), + + /** + * Log indexing operations only if the document contents match this regular + * expression. + */ + SEARCH_INDEX_URI_OR_NAME_RESTRICTION( + "developer.searchIndex.uriOrNameRestriction", false), + + /** + * Log indexing operations only if the document contents match this regular + * expression. + */ + SEARCH_INDEX_DOCUMENT_RESTRICTION( + "developer.searchIndex.documentRestriction", false), + + /** + * Tell the SearchEngineLogger to log all index deletions. + */ + SEARCH_DELETIONS_ENABLE("developer.searchDeletions.enable", true), + + /** + * Tell the SearchEngineLogger to log all search operations. + */ + SEARCH_ENGINE_ENABLE("developer.searchEngine.enable", true), + + /** + * Add the stack trace to the log of search operations. + */ + SEARCH_ENGINE_ADD_STACK_TRACE("developer.searchEngine.addStackTrace", true), + + /** + * Add the search results to the log of search operations. + */ + SEARCH_ENGINE_ADD_RESULTS("developer.searchEngine.addResults", true), + + /** + * Log search operations only if the query matches this regular expression. + */ + SEARCH_ENGINE_QUERY_RESTRICTION("developer.searchEngine.queryRestriction", + false), + + /** + * Log search operations only if the stack trace matches this regular + * expression. + */ + SEARCH_ENGINE_STACK_RESTRICTION("developer.searchEngine.stackRestriction", + false), + /** * Enable the PolicyDecisionLogger. */ diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/loggers/StackTraceUtility.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/loggers/StackTraceUtility.java new file mode 100644 index 000000000..8797c9c00 --- /dev/null +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/developer/loggers/StackTraceUtility.java @@ -0,0 +1,139 @@ +/* $This file is distributed under the terms of the license in /doc/license.txt$ */ + +package edu.cornell.mannlib.vitro.webapp.utils.developer.loggers; + +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 org.apache.commons.lang.StringUtils; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + +/** + * Records and process the stack trace so a developer's logger can (1) test + * against it, and (2) display it. + * + * If the "enabled" flag is not set, no processing is done, and the stack trace + * is empty. That way, there is essentially no overhead in creating a disabled + * instance. + */ +public class StackTraceUtility { + private static final Log log = LogFactory.getLog(StackTraceUtility.class); + + private final Class lowestClassInStackTrace; + private final List stackTrace; + private final String methodName; + + public StackTraceUtility(Class lowestClassInStackTrace, boolean enabled) { + this.lowestClassInStackTrace = lowestClassInStackTrace; + + this.stackTrace = enabled ? loadStackTrace() : Collections + . emptyList(); + + this.methodName = (this.stackTrace.isEmpty()) ? "UNKNOWN" + : this.stackTrace.get(0).getMethodName(); + + } + + private List loadStackTrace() { + StackTraceElement[] stack = Thread.currentThread().getStackTrace(); + List list = new ArrayList( + Arrays.asList(stack)); + + trimStackTraceAtBeginning(list); + trimStackTraceAtEnd(list); + removeJenaClassesFromStackTrace(list); + + log.debug("Stack array: " + Arrays.toString(stack)); + log.debug("Stack trace: " + list); + return Collections.unmodifiableList(list); + } + + private void trimStackTraceAtBeginning(List list) { + ListIterator iter = list.listIterator(); + while (iter.hasNext()) { + StackTraceElement ste = iter.next(); + if (ste.getClassName().equals(lowestClassInStackTrace.getName())) { + break; + } else { + iter.remove(); + } + } + } + + private void trimStackTraceAtEnd(List list) { + ListIterator 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 void removeJenaClassesFromStackTrace(List list) { + ListIterator iter = list.listIterator(); + while (iter.hasNext()) { + StackTraceElement ste = iter.next(); + if (ste.getClassName().startsWith("com.hp.hpl.jena.")) { + iter.remove(); + } + } + } + + public boolean passesStackRestriction(String restriction) { + if (StringUtils.isEmpty(restriction)) { + return true; + } else { + try { + return passesStackRestriction(Pattern.compile(restriction)); + } catch (Exception e) { + log.warn("Failed when testing stack restriction: '" + + restriction + "'"); + return true; + } + } + + } + + public boolean passesStackRestriction(Pattern restriction) { + if (restriction == null) { + return true; + } + String q = assembleCallStackString(); + return restriction.matcher(q).find(); + } + + private String assembleCallStackString() { + StringBuilder stack = new StringBuilder(); + for (StackTraceElement ste : stackTrace) { + stack.append(ste.getClassName()).append(" ") + .append(ste.getMethodName()).append(" "); + } + return stack.deleteCharAt(stack.length() - 1).toString(); + } + + public String format(boolean requested) { + StringBuilder sb = new StringBuilder(); + if (requested) { + for (StackTraceElement ste : stackTrace) { + sb.append(String.format(" line %4d, %s \n", + ste.getLineNumber(), ste.getClassName())); + } + sb.append(" ...\n"); + } + return sb.toString(); + } + + public String getMethodName() { + return this.methodName; + } + +} diff --git a/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/searchengine/Formatter.java b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/searchengine/Formatter.java new file mode 100644 index 000000000..e23e47bde --- /dev/null +++ b/webapp/src/edu/cornell/mannlib/vitro/webapp/utils/searchengine/Formatter.java @@ -0,0 +1,145 @@ +/* $This file is distributed under the terms of the license in /doc/license.txt$ */ + +package edu.cornell.mannlib.vitro.webapp.utils.searchengine; + +import java.util.Collection; +import java.util.Map; +import java.util.Set; +import java.util.TreeMap; + +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchFacetField; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchInputDocument; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchInputField; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchQuery; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchQuery.Order; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchResponse; +import edu.cornell.mannlib.vitro.webapp.modules.searchEngine.SearchResultDocument; + +/** + * Produce readable displays of objects related to the search engine. + */ +public class Formatter { + public static String format(SearchInputDocument doc) { + StringBuilder sb = new StringBuilder(); + sb.append("SearchInputDocument: Name='" + + getValueFromField(doc, "nameRaw") + "', URI='" + + getValueFromField(doc, "URI") + "', boost='" + + doc.getDocumentBoost() + "', " + doc.getFieldMap().size() + + " fields \n"); + + for (SearchInputField field : new TreeMap<>(doc.getFieldMap()).values()) { + sb.append(format(field, " ").append('\n')); + } + + return sb.toString(); + } + + public static String getValueFromField(SearchInputDocument doc, + String fieldName) { + SearchInputField field = doc.getField(fieldName); + if (field == null) { + return "UNKNOWN"; + } else { + Object value = field.getFirstValue(); + return (value == null) ? "UNKNOWN" : String.valueOf(value); + } + } + + public static String format(SearchInputField field) { + return format(field, "").toString(); + } + + private static StringBuilder format(SearchInputField field, String padding) { + StringBuilder sb = new StringBuilder(); + sb.append(padding).append( + "SearchInputField: Name='" + field.getName() + "', boost='" + + field.getBoost() + "', " + field.getValues().size() + + " values \n"); + + for (Object value : field.getValues()) { + sb.append(padding).append(" '").append(String.valueOf(value)) + .append("' \n"); + } + return sb; + } + + public static String format(SearchQuery query) { + Set returnFields = query.getFieldsToReturn(); + Map sortFields = query.getSortFields(); + Set filters = query.getFilters(); + Set facets = query.getFacetFields(); + return "SearchQuery start='" + + query.getStart() + + "', rows='" + + query.getRows() + + "', text='" + + query.getQuery() + + (returnFields.isEmpty() ? "', No return fields" + : ("', return fields=" + returnFields)) + + (sortFields.isEmpty() ? ", No sort fields" + : (", sort fields=" + sortFields)) + + (filters.isEmpty() ? ", No filters" + : (", filters=" + filters)) + + (facets.isEmpty() ? ", No facets" : (", facets=" + facets + + " facet limit=" + query.getFacetLimit() + + ", facet minimum=" + query.getFacetMinCount())) + + "\n"; + } + + public static String format(SearchResponse response) { + StringBuilder sb = new StringBuilder(); + sb.append("SearchResponse: " + response.getResults().size() + + " results, " + response.getFacetFields().size() + + " facet fields, " + response.getHighlighting().size() + + " highlights\n"); + for (SearchFacetField facet : response.getFacetFields()) { + sb.append(format(facet, " ")); + } + for (SearchResultDocument result : response.getResults()) { + sb.append(format(result, " ")); + } + return sb.toString(); + } + + private static StringBuilder format(SearchFacetField facet, String padding) { + StringBuilder sb = new StringBuilder(); + sb.append(padding).append("SearchFacetField: name=") + .append(facet.getName()).append(", ") + .append(facet.getValues().size()).append(" values"); + return sb; + } + + private static String format(SearchResultDocument doc, String padding) { + StringBuilder sb = new StringBuilder(); + int valuesCount = 0; + for (Collection values : doc.getFieldValuesMap().values()) { + valuesCount += values.size(); + } + sb.append("SearchResultDocument: Name='" + + getValueFromField(doc, "nameRaw") + "', URI='" + + getValueFromField(doc, "URI") + "', " + + doc.getFieldNames().size() + " fields with " + valuesCount + + " values \n"); + + for (String fieldName : new TreeMap<>(doc.getFieldValuesMap()).keySet()) { + sb.append(padding).append( + "Field: Name='" + fieldName + "', " + + doc.getFieldValues(fieldName).size() + + " values \n"); + + for (Object value : doc.getFieldValues(fieldName)) { + sb.append(padding).append(" '").append(String.valueOf(value)) + .append("' \n"); + } + } + + return sb.toString(); + } + + public static String getValueFromField(SearchResultDocument doc, + String fieldName) { + Object value = doc.getFirstValue(fieldName); + return (value == null) ? "UNKNOWN" : String.valueOf(value); + } + +} diff --git a/webapp/web/js/developer/developerPanel.js b/webapp/web/js/developer/developerPanel.js index 0e6bf1a81..3bfa0721f 100644 --- a/webapp/web/js/developer/developerPanel.js +++ b/webapp/web/js/developer/developerPanel.js @@ -53,12 +53,26 @@ function DeveloperPanel(developerAjaxUrl) { document.getElementById("developer_i18n_defeatCache").disabled = !developerEnabled; document.getElementById("developer_i18n_logStringRequests").disabled = !developerEnabled; document.getElementById("developer_loggingRDFService_enable").disabled = !developerEnabled; + document.getElementById("developer_searchIndex_enable").disabled = !developerEnabled; + document.getElementById("developer_searchDeletions_enable").disabled = !developerEnabled; + document.getElementById("developer_searchEngine_enable").disabled = !developerEnabled; document.getElementById("developer_authorization_logDecisions_enable").disabled = !developerEnabled; var rdfServiceEnabled = developerEnabled && document.getElementById("developer_loggingRDFService_enable").checked; document.getElementById("developer_loggingRDFService_stackTrace").disabled = !rdfServiceEnabled; document.getElementById("developer_loggingRDFService_queryRestriction").disabled = !rdfServiceEnabled; document.getElementById("developer_loggingRDFService_stackRestriction").disabled = !rdfServiceEnabled; + + var searchIndexEnabled = developerEnabled && document.getElementById("developer_searchIndex_enable").checked; + document.getElementById("developer_searchIndex_showDocuments").disabled = !searchIndexEnabled; + document.getElementById("developer_searchIndex_uriOrNameRestriction").disabled = !searchIndexEnabled; + document.getElementById("developer_searchIndex_documentRestriction").disabled = !searchIndexEnabled; + + var searchEngineEnabled = developerEnabled && document.getElementById("developer_searchEngine_enable").checked; + document.getElementById("developer_searchEngine_addStackTrace").disabled = !searchEngineEnabled; + document.getElementById("developer_searchEngine_addResults").disabled = !searchEngineEnabled; + document.getElementById("developer_searchEngine_queryRestriction").disabled = !searchEngineEnabled; + document.getElementById("developer_searchEngine_stackRestriction").disabled = !searchEngineEnabled; var authLoggingEnabled = developerEnabled && document.getElementById("developer_authorization_logDecisions_enable").checked; document.getElementById("developer_authorization_logDecisions_skipInconclusive").disabled = !authLoggingEnabled; diff --git a/webapp/web/templates/freemarker/page/partials/developerPanel.ftl b/webapp/web/templates/freemarker/page/partials/developerPanel.ftl index ae2d05fe0..a474a57b6 100644 --- a/webapp/web/templates/freemarker/page/partials/developerPanel.ftl +++ b/webapp/web/templates/freemarker/page/partials/developerPanel.ftl @@ -36,6 +36,7 @@
@@ -79,11 +80,10 @@
SPARQL Queries - <@showCheckbox "developer_loggingRDFService_enable", - "Log each query" /> + <@showCheckbox "developer_loggingRDFService_enable", "Log each query" />
<@showCheckbox "developer_loggingRDFService_stackTrace", - "Add stack trace" /> + "Show stack trace" /> <@showTextbox "developer_loggingRDFService_queryRestriction", "Restrict by query string" /> <@showTextbox "developer_loggingRDFService_stackRestriction", @@ -93,6 +93,45 @@
+
+
+
+ Indexing + <@showCheckbox "developer_searchIndex_enable", "Log indexing." /> +
+ <@showCheckbox "developer_searchIndex_showDocuments", + "Show document contents" /> + <@showTextbox "developer_searchIndex_uriOrNameRestriction", + "Restrict by URI or name" /> + <@showTextbox "developer_searchIndex_documentRestriction", + "Restrict by document contents" /> +
+ <@showCheckbox "developer_searchDeletions_enable", "Log deletions." /> +
+ +
+ Links +
+ Rebuild search index +
+
+ +
+
+ Searching + <@showCheckbox "developer_searchEngine_enable", "Log searches" /> +
+ <@showCheckbox "developer_searchEngine_addStackTrace", "Show stack trace" /> + <@showCheckbox "developer_searchEngine_addResults", "Show search results" /> + <@showTextbox "developer_searchEngine_queryRestriction", + "Restrict by query string" /> + <@showTextbox "developer_searchEngine_stackRestriction", + "Restrict by calling stack" /> +
+
+
+
+
<@showCheckbox "developer_authorization_logDecisions_enable", "Write policy decisions to the log" />