You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@sling.apache.org by ch...@apache.org on 2016/02/11 05:49:25 UTC

svn commit: r1729762 - in /sling/trunk/contrib/extensions/tracer/src: main/java/org/apache/sling/tracer/internal/JSONRecording.java test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java

Author: chetanm
Date: Thu Feb 11 04:49:24 2016
New Revision: 1729762

URL: http://svn.apache.org/viewvc?rev=1729762&view=rev
Log:
SLING-5507 - Collect more details around query execution

Handle case for union queries

Modified:
    sling/trunk/contrib/extensions/tracer/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java
    sling/trunk/contrib/extensions/tracer/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java

Modified: sling/trunk/contrib/extensions/tracer/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java
URL: http://svn.apache.org/viewvc/sling/trunk/contrib/extensions/tracer/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java?rev=1729762&r1=1729761&r2=1729762&view=diff
==============================================================================
--- sling/trunk/contrib/extensions/tracer/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java (original)
+++ sling/trunk/contrib/extensions/tracer/src/main/java/org/apache/sling/tracer/internal/JSONRecording.java Thu Feb 11 04:49:24 2016
@@ -59,6 +59,7 @@ class JSONRecording implements Recording
             "org.apache.sling.resourceresolver", //Sling package would come first in stack so listed first
             "org.apache.jackrabbit.oak"
     };
+    private static final Object[] EMPTY = new Object[0];
     private static final Logger log = LoggerFactory.getLogger(JSONRecording.class);
     public static final String OAK_QUERY_PKG = "org.apache.jackrabbit.oak.query";
     private final String method;
@@ -300,7 +301,6 @@ class JSONRecording implements Recording
          * The MDC key is used in org.apache.jackrabbit.oak.query.QueryEngineImpl
          */
         static final String MDC_QUERY_ID = "oak.query.id";
-        static final String QE_LOGGER = "org.apache.jackrabbit.oak.query.QueryImpl";
         String query;
         String plan;
         String id;
@@ -319,17 +319,32 @@ class JSONRecording implements Recording
                 id = idFromMDC;
             }
 
+            //TODO Query time. Change Oak to provide this information via some
+            //dedicated Audit logging such that below reliance on impl details
+            //can be avoided
             String msg = tuple.getMessage();
-            if (Level.DEBUG == level
-                    && QE_LOGGER.equals(logger)
-                    && msg != null){
-
-                //The Log stmt are as present in org.apache.jackrabbit.oak.query.QueryImpl
-                if (msg.startsWith("query execute ")){
-                    query = msg.substring("query execute ".length());
-                    caller = determineCaller();
-                } else if (msg.startsWith("query plan ")){
-                    plan = msg.substring("query plan ".length());
+            if (Level.DEBUG == level && msg != null) {
+                Object[] args = tuple.getArgArray() == null ? EMPTY : tuple.getArgArray();
+                if (query == null){
+                    if ("org.apache.jackrabbit.oak.query.QueryEngineImpl".equals(logger)
+                            && msg.contains("Parsing") && args.length == 2){
+                        //LOG.debug("Parsing {} statement: {}", language, statement);
+                        query = nullSafeString(args[1]);
+                        caller = determineCaller();
+                    }
+                }
+
+                //Plan for union query are logged separately
+                if (plan == null){
+                    if ("org.apache.jackrabbit.oak.query.QueryImpl".equals(logger)
+                            && msg.startsWith("query plan ")){
+                        //logDebug("query execute " + statement);
+                        plan = msg.substring("query plan ".length());
+                    } else if ("org.apache.jackrabbit.oak.query.UnionQueryImpl".equals(logger)
+                            && msg.contains("query union plan") && args.length > 0){
+                        // LOG.debug("query union plan {}", getPlan());
+                        plan = nullSafeString(args[0]);
+                    }
                 }
             }
         }
@@ -343,8 +358,8 @@ class JSONRecording implements Recording
         }
 
         public void addQueryEntry(){
-            if (query != null){
-                queries.add(new QueryEntry(safeTrim(query), safeTrim(plan), caller));
+            if (query != null && plan != null){
+                queries.add(new QueryEntry(nullSafeTrim(query), nullSafeTrim(plan), caller));
                 plan = query = null;
             }
         }
@@ -353,13 +368,20 @@ class JSONRecording implements Recording
             //Push any last pending entry i.e. last query
             addQueryEntry();
         }
+    }
 
-        private String safeTrim(String s){
-            if(s == null){
-                return "";
-            }
-            return s.trim();
+    private static String nullSafeTrim(String s){
+        if(s == null){
+            return "";
+        }
+        return s.trim();
+    }
+
+    private static String nullSafeString(Object o){
+        if (o != null){
+            return o.toString();
         }
+        return null;
     }
 
 }

Modified: sling/trunk/contrib/extensions/tracer/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java
URL: http://svn.apache.org/viewvc/sling/trunk/contrib/extensions/tracer/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java?rev=1729762&r1=1729761&r2=1729762&view=diff
==============================================================================
--- sling/trunk/contrib/extensions/tracer/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java (original)
+++ sling/trunk/contrib/extensions/tracer/src/test/java/org/apache/sling/tracer/internal/JSONRecordingTest.java Thu Feb 11 04:49:24 2016
@@ -53,7 +53,8 @@ public class JSONRecordingTest {
         JSONRecording r = new JSONRecording("abc", request, true);
 
         MDC.put(MDC_QUERY_ID, "1");
-        r.log(tc, Level.DEBUG, QE_LOGGER, tuple("query execute SELECT FOO"));
+        r.log(tc, Level.DEBUG, "org.apache.jackrabbit.oak.query.QueryEngineImpl",
+                tuple("Parsing {} statement: {}",  "XPATH", "SELECT FOO"));
         r.log(tc, Level.DEBUG, QE_LOGGER, tuple("query plan FOO PLAN"));
 
         r.done();
@@ -112,4 +113,8 @@ public class JSONRecordingTest {
     private static FormattingTuple tuple(String msg){
         return MessageFormatter.format(msg, null);
     }
+
+    private static FormattingTuple tuple(String msg, String ... params){
+        return MessageFormatter.arrayFormat(msg, params);
+    }
 }