CURATOR-726: Improve tracing for MultiTransaction and GetChildren (#513)

Author: HoustonPutman

curator-client/src/main/java/org/apache/curator/drivers/OperationTrace.java

@@ -33,8 +33,10 @@ public class OperationTrace {
 
     private int returnCode = KeeperException.Code.OK.intValue();
     private long latencyMs;
+    private int requestTransactionCount;
     private long requestBytesLength;
     private long responseBytesLength;
+    private int responseChildrenCount = -1;
     private String path;
     private boolean withWatcher;
     private long sessionId;
@@ -57,6 +59,11 @@ public OperationTrace setReturnCode(int returnCode) {
         return this;
     }
 
+    public OperationTrace setRequestTransactionCount(int transactionCount) {
+        this.requestTransactionCount = transactionCount;
+        return this;
+    }
+
     public OperationTrace setRequestBytesLength(long length) {
         this.requestBytesLength = length;
         return this;
@@ -97,6 +104,11 @@ public OperationTrace setResponseBytesLength(byte[] data) {
         return this.setResponseBytesLength(data.length);
     }
 
+    public OperationTrace setResponseChildrenCount(int responseChildrenCount) {
+        this.responseChildrenCount = responseChildrenCount;
+        return this;
+    }
+
     public OperationTrace setPath(String path) {
         this.path = path;
         return this;
@@ -124,6 +136,10 @@ public long getLatencyMs() {
         return this.latencyMs;
     }
 
+    public int getRequestTransactionCount() {
+        return this.requestTransactionCount;
+    }
+
     public long getRequestBytesLength() {
         return this.requestBytesLength;
     }
@@ -132,6 +148,10 @@ public long getResponseBytesLength() {
         return this.responseBytesLength;
     }
 
+    public int getResponseChildrenCount() {
+        return this.responseChildrenCount;
+    }
+
     public long getSessionId() {
         return this.sessionId;
     }

curator-framework/src/main/java/org/apache/curator/framework/imps/CuratorMultiTransactionImpl.java

@@ -26,7 +26,7 @@
 import java.util.concurrent.Callable;
 import java.util.concurrent.Executor;
 import org.apache.curator.RetryLoop;
-import org.apache.curator.TimeTrace;
+import org.apache.curator.drivers.OperationTrace;
 import org.apache.curator.framework.api.BackgroundCallback;
 import org.apache.curator.framework.api.CuratorEvent;
 import org.apache.curator.framework.api.CuratorEventType;
@@ -160,11 +160,13 @@ public CuratorEventType getBackgroundEventType() {
     public void performBackgroundOperation(final OperationAndData<CuratorMultiTransactionRecord> operationAndData)
             throws Exception {
         try {
-            final TimeTrace trace = client.getZookeeperClient().startTracer("CuratorMultiTransactionImpl-Background");
+            final OperationTrace trace =
+                    client.getZookeeperClient().startAdvancedTracer("CuratorMultiTransactionImpl-Background");
             AsyncCallback.MultiCallback callback = new AsyncCallback.MultiCallback() {
                 @Override
                 public void processResult(int rc, String path, Object ctx, List<OpResult> opResults) {
-                    trace.commit();
+                    trace.setRequestTransactionCount(operationAndData.getData().size())
+                            .commit();
                     List<CuratorTransactionResult> curatorResults = (opResults != null)
                             ? CuratorTransactionImpl.wrapResults(client, opResults, operationAndData.getData())
                             : null;
@@ -192,15 +194,16 @@ public void processResult(int rc, String path, Object ctx, List<OpResult> opResu
 
     private List<CuratorTransactionResult> forOperationsInForeground(final CuratorMultiTransactionRecord record)
             throws Exception {
-        TimeTrace trace = client.getZookeeperClient().startTracer("CuratorMultiTransactionImpl-Foreground");
+        OperationTrace trace =
+                client.getZookeeperClient().startAdvancedTracer("CuratorMultiTransactionImpl-Foreground");
         List<OpResult> responseData =
                 RetryLoop.callWithRetry(client.getZookeeperClient(), new Callable<List<OpResult>>() {
                     @Override
                     public List<OpResult> call() throws Exception {
                         return client.getZooKeeper().multi(record);
                     }
                 });
-        trace.commit();
+        trace.setRequestTransactionCount(record.size()).commit();
 
         return CuratorTransactionImpl.wrapResults(client, responseData, record);
     }

curator-framework/src/main/java/org/apache/curator/framework/imps/GetChildrenBuilderImpl.java

@@ -165,14 +165,15 @@ public void performBackgroundOperation(final OperationAndData<String> operationA
                 @Override
                 public void processResult(int rc, String path, Object o, List<String> strings, Stat stat) {
                     watching.commitWatcher(rc, false);
+                    if (strings == null) {
+                        strings = Lists.newArrayList();
+                    }
                     trace.setReturnCode(rc)
                             .setPath(path)
                             .setWithWatcher(watching.hasWatcher())
                             .setStat(stat)
+                            .setResponseChildrenCount(strings.size())
                             .commit();
-                    if (strings == null) {
-                        strings = Lists.newArrayList();
-                    }
                     CuratorEventImpl event = new CuratorEventImpl(
                             client,
                             CuratorEventType.CHILDREN,
@@ -241,6 +242,7 @@ public List<String> call() throws Exception {
         trace.setPath(path)
                 .setWithWatcher(watching.hasWatcher())
                 .setStat(responseStat)
+                .setResponseChildrenCount(children != null ? children.size() : 0)
                 .commit();
         return children;
     }