From f0a4b30cdc7c14a67d8641d761cc75d1a5a969f2 Mon Sep 17 00:00:00 2001 From: Grant Ingersoll Date: Thu, 17 Apr 2008 12:37:38 +0000 Subject: [PATCH] SOLR-267: Logging updates, now logs how many hits, plus some other logging changes to reduce double logging git-svn-id: https://svn.apache.org/repos/asf/lucene/solr/trunk@649066 13f79535-47bb-0310-9956-ffa450edef68 --- CHANGES.txt | 7 +- src/java/org/apache/solr/core/SolrCore.java | 35 +++++--- .../handler/component/QueryComponent.java | 2 +- .../solr/request/SolrQueryResponse.java | 38 +++++++- .../apache/solr/request/JSONWriterTest.java | 4 +- .../solr/servlet/SolrDispatchFilter.java | 88 +++++++++++-------- 6 files changed, 117 insertions(+), 57 deletions(-) diff --git a/CHANGES.txt b/CHANGES.txt index 0be158268d7..ac6d728ba95 100644 --- a/CHANGES.txt +++ b/CHANGES.txt @@ -355,8 +355,11 @@ Bug Fixes when no RequestHandler is mapped to "/update") now logs error correctly. (hossman) -26. SOLR-509: Moved firstSearcher event notification to the end of the SolrCore constructor (Koji Sekiguchi via gsingers) - +27. SOLR-267: Changed logging to report number of hits, and also provide a mechanism to add log messages to be output by the SolrCore via a NamedList toLog + member variable. (Will Johnson, yseeley, gsingers) + +28. SOLR-509: Moved firstSearcher event notification to the end of the SolrCore constructor (Koji Sekiguchi via gsingers) + Other Changes 1. SOLR-135: Moved common classes to org.apache.solr.common and altered the build scripts to make two jars: apache-solr-1.3.jar and diff --git a/src/java/org/apache/solr/core/SolrCore.java b/src/java/org/apache/solr/core/SolrCore.java index e2426425512..66197a3eb68 100644 --- a/src/java/org/apache/solr/core/SolrCore.java +++ b/src/java/org/apache/solr/core/SolrCore.java @@ -128,7 +128,7 @@ public final class SolrCore { /** * Gets the configuration resource name used by this core instance. - * @see getConfigResource + * @see #getConfigResource() */ @Deprecated public String getConfigFile() { @@ -151,7 +151,7 @@ public final class SolrCore { /** * Gets the schema resource name used by this core instance. - * @see getSchemaResource + * @see #getSchemaResource() */ @Deprecated public String getSchemaFile() { @@ -396,7 +396,7 @@ public final class SolrCore { // Finally tell anyone who wants to know loader.inform( loader ); loader.inform( this ); - + // execute firstSearcher event //TODO: It may not always be the case that this is the only time the first searcher event needs to fire. doFirstSearcherEvent(getSearcher().get()); @@ -498,7 +498,7 @@ public final class SolrCore { * Returns a Request object based on the admin/pingQuery section * of the Solr config file. * - * @use {@link PingRequestHandler} instead + * @use {@link org.apache.solr.handler.PingRequestHandler} instead */ @Deprecated public SolrQueryRequest getPingQueryRequest() { @@ -948,12 +948,23 @@ public final class SolrCore { // setup response header and handle request final NamedList responseHeader = new SimpleOrderedMap(); rsp.add("responseHeader", responseHeader); + NamedList toLog = rsp.getToLog(); + //toLog.add("core", getName()); + toLog.add("webapp", req.getContext().get("webapp")); + toLog.add("path", req.getContext().get("path")); + toLog.add("params", "{" + req.getParamString() + "}"); handler.handleRequest(req,rsp); - setResponseHeaderValues(handler,responseHeader,req,rsp); - - log.info(logid+"" + req.getContext().get("path") + " " + setResponseHeaderValues(handler,req,rsp); + StringBuilder sb = new StringBuilder(); + for (int i=0; i responseHeader,SolrQueryRequest req, SolrQueryResponse rsp) { + protected void setResponseHeaderValues(SolrRequestHandler handler, SolrQueryRequest req, SolrQueryResponse rsp) { // TODO should check that responseHeader has not been replaced by handler - + NamedList responseHeader = rsp.getResponseHeader(); final int qtime=(int)(rsp.getEndTime() - req.getStartTime()); responseHeader.add("status",rsp.getException()==null ? 0 : 500); responseHeader.add("QTime",qtime); - + rsp.getToLog().add("status",rsp.getException()==null ? 0 : 500); + rsp.getToLog().add("QTime",qtime); + SolrParams params = req.getParams(); if( params.getBool(CommonParams.HEADER_ECHO_HANDLER, false) ) { responseHeader.add("handler", handler.getName() ); diff --git a/src/java/org/apache/solr/handler/component/QueryComponent.java b/src/java/org/apache/solr/handler/component/QueryComponent.java index 59f971b9112..f1fe181d816 100644 --- a/src/java/org/apache/solr/handler/component/QueryComponent.java +++ b/src/java/org/apache/solr/handler/component/QueryComponent.java @@ -165,7 +165,7 @@ public class QueryComponent extends SearchComponent } rsp.add("response",rb.getResults().docList); - + rsp.getToLog().add("hits", rb.getResults().docList.size()); boolean fsv = req.getParams().getBool(ResponseBuilder.FIELD_SORT_VALUES,false); if(fsv){ diff --git a/src/java/org/apache/solr/request/SolrQueryResponse.java b/src/java/org/apache/solr/request/SolrQueryResponse.java index f6b7859d87b..ccb162e0d87 100644 --- a/src/java/org/apache/solr/request/SolrQueryResponse.java +++ b/src/java/org/apache/solr/request/SolrQueryResponse.java @@ -60,7 +60,12 @@ public class SolrQueryResponse { * @see #setAllValues * @see Note on Returnable Data */ - protected NamedList values = new SimpleOrderedMap(); + protected NamedList values = new SimpleOrderedMap(); + + /** + * Container for storing information that should be logged by Solr before returning. + */ + protected NamedList toLog = new SimpleOrderedMap(); protected Set defaultReturnFields; @@ -73,6 +78,11 @@ public class SolrQueryResponse { String errMsg; ***/ + public SolrQueryResponse() { + add("responseHeader", new SimpleOrderedMap()); + } + + /** * Gets data to be returned in this response * @see Note on Returnable Data @@ -167,6 +177,28 @@ public class SolrQueryResponse { } return this.endtime; } - - + + /** Repsonse header to be logged */ + public NamedList getResponseHeader() { + SimpleOrderedMap header = (SimpleOrderedMap) values.get("responseHeader"); + return header; + } + + /** Add a value to be logged. + * + * @param name name of the thing to log + * @param val value of the thing to log + */ + public void addToLog(String name, Object val) { + toLog.add(name, val); + } + + /** Get loggable items. + * + * @return things to log + */ + public NamedList getToLog() { + return toLog; + } + } diff --git a/src/test/org/apache/solr/request/JSONWriterTest.java b/src/test/org/apache/solr/request/JSONWriterTest.java index ddf995ec2e1..87c7522850d 100644 --- a/src/test/org/apache/solr/request/JSONWriterTest.java +++ b/src/test/org/apache/solr/request/JSONWriterTest.java @@ -42,12 +42,12 @@ public class JSONWriterTest extends AbstractSolrTestCase { rsp.add("data2", Double.NEGATIVE_INFINITY); rsp.add("data3", Float.POSITIVE_INFINITY); w.write(buf, req, rsp); - assertEquals(buf.toString(), "{'data1':float('NaN'),'data2':-float('Inf'),'data3':float('Inf')}"); + assertEquals(buf.toString(), "{'responseHeader':{},'data1':float('NaN'),'data2':-float('Inf'),'data3':float('Inf')}"); w = new RubyResponseWriter(); buf = new StringWriter(); w.write(buf, req, rsp); - assertEquals(buf.toString(), "{'data1'=>(0.0/0.0),'data2'=>-(1.0/0.0),'data3'=>(1.0/0.0)}"); + assertEquals(buf.toString(), "{'responseHeader'=>{},'data1'=>(0.0/0.0),'data2'=>-(1.0/0.0),'data3'=>(1.0/0.0)}"); } diff --git a/src/webapp/src/org/apache/solr/servlet/SolrDispatchFilter.java b/src/webapp/src/org/apache/solr/servlet/SolrDispatchFilter.java index c4d8e01d1f8..bcb9baed110 100644 --- a/src/webapp/src/org/apache/solr/servlet/SolrDispatchFilter.java +++ b/src/webapp/src/org/apache/solr/servlet/SolrDispatchFilter.java @@ -35,6 +35,7 @@ import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; import org.apache.solr.common.SolrException; +import org.apache.solr.common.util.NamedList; import org.apache.solr.common.params.CommonParams; import org.apache.solr.core.MultiCore; import org.apache.solr.core.SolrConfig; @@ -46,21 +47,21 @@ import org.apache.solr.servlet.cache.Method; /** * This filter looks at the incoming URL maps them to handlers defined in solrconfig.xml - * + * * @since solr 1.2 */ -public class SolrDispatchFilter implements Filter +public class SolrDispatchFilter implements Filter { final Logger log = Logger.getLogger(SolrDispatchFilter.class.getName()); - + protected SolrCore singlecore; protected MultiCore multicore; protected String pathPrefix = null; // strip this from the beginning of a path protected String abortErrorMessage = null; protected final WeakHashMap parsers = new WeakHashMap(); protected String solrConfigFilename = null; - - public void init(FilterConfig config) throws ServletException + + public void init(FilterConfig config) throws ServletException { log.info("SolrDispatchFilter.init()"); @@ -69,10 +70,10 @@ public class SolrDispatchFilter implements Filter // web.xml configuration this.pathPrefix = config.getInitParameter( "path-prefix" ); this.solrConfigFilename = config.getInitParameter("solrconfig-filename"); - + // multicore instantiation this.multicore = initMultiCore(config); - + if(multicore != null && multicore.isEnabled() ) { abortOnConfigurationError = false; singlecore = null; @@ -98,7 +99,7 @@ public class SolrDispatchFilter implements Filter SolrConfig.severeErrors.add( t ); SolrCore.log( t ); } - + // Optionally abort if we found a sever error if( abortOnConfigurationError && SolrConfig.severeErrors.size() > 0 ) { StringWriter sw = new StringWriter(); @@ -112,13 +113,13 @@ public class SolrDispatchFilter implements Filter } else { out.println( "in solrconfig.xml\n" ); } - + for( Throwable t : SolrConfig.severeErrors ) { out.println( "-------------------------------------------------------------" ); t.printStackTrace( out ); } out.flush(); - + // Servlet containers behave slightly differently if you throw an exception during // initialization. Resin will display that error for every page, jetty prints it in // the logs, but continues normally. (We will see a 404 rather then the real error) @@ -127,7 +128,7 @@ public class SolrDispatchFilter implements Filter abortErrorMessage = sw.toString(); //throw new ServletException( abortErrorMessage ); } - + log.info("SolrDispatchFilter.init() done"); } @@ -159,13 +160,13 @@ public class SolrDispatchFilter implements Filter singlecore = null; } } - + public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException { if( abortErrorMessage != null ) { ((HttpServletResponse)response).sendError( 500, abortErrorMessage ); return; } - + if( request instanceof HttpServletRequest) { HttpServletRequest req = (HttpServletRequest)request; HttpServletResponse resp = (HttpServletResponse)response; @@ -173,26 +174,26 @@ public class SolrDispatchFilter implements Filter SolrQueryRequest solrReq = null; try { - String path = req.getServletPath(); + String path = req.getServletPath(); if( req.getPathInfo() != null ) { // this lets you handle /update/commit when /update is a servlet - path += req.getPathInfo(); + path += req.getPathInfo(); } if( pathPrefix != null && path.startsWith( pathPrefix ) ) { path = path.substring( pathPrefix.length() ); } - + int idx = path.indexOf( ':' ); if( idx > 0 ) { // save the portion after the ':' for a 'handler' path parameter path = path.substring( 0, idx ); } - + // By default use the single core. If multicore is enabled, look for one. final SolrCore core; if (multicore != null && multicore.isEnabled()) { req.setAttribute("org.apache.solr.MultiCore", multicore); - + // if this is the multi-core admin page, it will handle it if( path.equals( multicore.getAdminPath() ) ) { handler = multicore.getMultiCoreHandler(); @@ -217,7 +218,7 @@ public class SolrDispatchFilter implements Filter else { core = singlecore; } - + // With a valid core... if( core != null ) { final SolrConfig config = core.getSolrConfig(); @@ -228,7 +229,7 @@ public class SolrDispatchFilter implements Filter parser = new SolrRequestParsers(config); parsers.put( core, parser ); } - + // Determine the handler from the url path if not set // (we might already have selected the multicore handler) if( handler == null && path.length() > 1 ) { // don't match "" or "/" as valid path @@ -244,18 +245,18 @@ public class SolrDispatchFilter implements Filter handler = core.getRequestHandler( qt ); if( handler == null ) { throw new SolrException( SolrException.ErrorCode.BAD_REQUEST, "unknown handler: "+qt); - } + } } } } - + // With a valid handler and a valid core... - if( handler != null ) { + if( handler != null ) { // if not a /select, create the request if( solrReq == null ) { solrReq = parser.parse( core, path, req ); } - + final Method reqMethod = Method.getMethod(req.getMethod()); if (Method.POST != reqMethod) { HttpCacheHeaderUtil.setCacheControlHeader(config, resp); @@ -266,11 +267,20 @@ public class SolrDispatchFilter implements Filter !HttpCacheHeaderUtil.doCacheHeaderValidation(solrReq, req, resp)) { SolrQueryResponse solrRsp = new SolrQueryResponse(); /* even for HEAD requests, we need to execute the handler to - * ensure we don't get an error (and to make sure the correct + * ensure we don't get an error (and to make sure the correct * QueryResponseWriter is selectedand we get the correct * Content-Type) */ this.execute( req, handler, solrReq, solrRsp ); + // add info to http headers + try { + NamedList solrRspHeader = solrRsp.getResponseHeader(); + for (int i=0; i * SolrRequestFilter * /xxx/* * - * + * * Make sure to set the PathPrefix to "/xxx" either with this function * or in web.xml. - * + * * * path-prefix * /xxx * - * + * */ public void setPathPrefix(String pathPrefix) { this.pathPrefix = pathPrefix;