From 149492e25c2c89e4cc0b55a2d722ddda8b29ec49 Mon Sep 17 00:00:00 2001
From: Alan Davis <alan.davis@alfresco.com>
Date: Thu, 20 Feb 2014 14:43:50 +0000
Subject: [PATCH] Merged HEAD-BUG-FIX (Cloud33/4.3) to HEAD (Cloud33/4.3)   
 62928: Merged PLATFORM1 (Cloud33) to HEAD-BUG-FIX (Cloud33/4.3)       62580:
 ACE-482: now logs timings for search types other than hybrid.

git-svn-id: https://svn.alfresco.com/repos/alfresco-enterprise/alfresco/HEAD/root@62983 c4b6b30b-aa2e-2d43-bbcb-ca4b014f7261
---
 .../solr/DbOrIndexSwitchingQueryLanguage.java | 53 +++++++++++++++++--
 1 file changed, 48 insertions(+), 5 deletions(-)

diff --git a/source/java/org/alfresco/repo/search/impl/solr/DbOrIndexSwitchingQueryLanguage.java b/source/java/org/alfresco/repo/search/impl/solr/DbOrIndexSwitchingQueryLanguage.java
index 8ac9eb4df9..74dfcff616 100644
--- a/source/java/org/alfresco/repo/search/impl/solr/DbOrIndexSwitchingQueryLanguage.java
+++ b/source/java/org/alfresco/repo/search/impl/solr/DbOrIndexSwitchingQueryLanguage.java
@@ -108,7 +108,16 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
                 {
                     logger.debug("Using SOLR query: "+dbQueryLanguage.getName()+" for "+searchParameters);
                 }
-                return indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                StopWatch stopWatch = new StopWatch("index only");
+                stopWatch.start();
+                ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                stopWatch.stop();
+                if (logger.isDebugEnabled())
+                {
+                    logger.debug("SOLR returned " + results.length() + " results in " +
+                                 stopWatch.getLastTaskTimeMillis() + "ms");
+                }
+                return results;
             }
             else
             {
@@ -121,7 +130,16 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
                 {
                     logger.debug("Trying db query for "+dbQueryLanguage.getName()+" for "+searchParameters);
                 }
-                return dbQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                StopWatch stopWatch = new StopWatch("database only");
+                stopWatch.start();
+                ResultSet results = dbQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                stopWatch.stop();
+                if (logger.isDebugEnabled())
+                {
+                    logger.debug("DB returned " + results.length() + " results in " +
+                                 stopWatch.getLastTaskTimeMillis() + "ms");
+                }
+                return results;
             }
             else
             {
@@ -136,6 +154,7 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
         case DEFAULT:
         case TRANSACTIONAL_IF_POSSIBLE:
         default:
+            StopWatch stopWatch = new StopWatch("DB if possible");
             if(dbQueryLanguage != null)
             {
                 try
@@ -144,7 +163,15 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
                     {
                         logger.debug("Trying db query for "+dbQueryLanguage.getName()+" for "+searchParameters);
                     }
-                    return dbQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                    stopWatch.start();
+                    ResultSet results = dbQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                    stopWatch.stop();
+                    if (logger.isDebugEnabled())
+                    {
+                        logger.debug("DB returned " + results.length() + " results in " +
+                                     stopWatch.getLastTaskTimeMillis() + "ms");
+                    }
+                    return results;
                 }
                 catch(QueryModelException qme)
                 {
@@ -160,7 +187,15 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
                         {
                             logger.debug("Using SOLR query: "+dbQueryLanguage.getName()+" for "+searchParameters);
                         }
-                        return indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                        stopWatch.start();
+                        ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                        stopWatch.stop();
+                        if (logger.isDebugEnabled())
+                        {
+                            logger.debug("SOLR returned " + results.length() + " results in " +
+                                         stopWatch.getLastTaskTimeMillis() + "ms");
+                        }
+                        return results;
                     }
                 }
             }
@@ -172,7 +207,15 @@ public class DbOrIndexSwitchingQueryLanguage extends AbstractLuceneQueryLanguage
                     {
                         logger.debug("(No DB QL) Using SOLR query: "+dbQueryLanguage.getName()+" for "+searchParameters);
                     }
-                    return indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                    stopWatch.start();
+                    ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
+                    stopWatch.stop();
+                    if (logger.isDebugEnabled())
+                    {
+                        logger.debug("SOLR returned " + results.length() + " results in " +
+                                     stopWatch.getLastTaskTimeMillis() + "ms");
+                    }
+                    return results;
                 }
             }
             throw new QueryModelException("No query language available");