improve message debug information

src/java/org/apache/cassandra/db/virtual/QueriesTable.java

@@ -36,11 +36,11 @@
  *     cqlsh> select * from system_views.queries;
  *
  *  thread_id                    | duration_micros | task
- * ------------------------------+-----------------+--------------------------------------------------------------------
- *  Native-Transport-Requests-17 |            6325 |         QUERY select * from system_views.queries; [pageSize = 100]
- *   Native-Transport-Requests-4 |           14681 | EXECUTE f4...e452637f1f2444 with 0 values at consistency LOCAL_ONE
- *   Native-Transport-Requests-6 |           14678 | EXECUTE f4...e452637f1f2444 with 0 values at consistency LOCAL_ONE
- *                  ReadStage-10 |           16535 |                            SELECT * FROM keyspace.table LIMIT 5000
+ * ------------------------------+-----------------+---------------------------------------------------------------------------------------
+ *  Native-Transport-Requests-17 |            6325 |       QUERY SELECT * FROM system_views.queries; WITH pageSize = 100 AT CONSISTENCY ONE
+ *   Native-Transport-Requests-4 |           14681 | EXECUTE INSERT INTO tbl (key, val) VALUES (?, ?) WITH [0x00, 'str'] AT CONSISTENCY ONE
+ *   Native-Transport-Requests-6 |           14678 | LOGGED BATCH of [INSERT INTO tbl2 (key, val) VALUES (0x00 0x00), INSERT INTO tbl2 (key, val) VALUES (?, ?) WITH [0x00 0x00]] AT CONSISTENCY ONE
+ *                  ReadStage-10 |           16535 |                                                SELECT * FROM keyspace.table LIMIT 5000
  * </pre>
  */
 public class QueriesTable extends AbstractVirtualTable

src/java/org/apache/cassandra/transport/Message.java

@@ -37,13 +37,16 @@
 import io.netty.handler.codec.MessageToMessageDecoder;
 import io.netty.handler.codec.MessageToMessageEncoder;
 
+import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Predicate;
 import com.google.common.collect.ImmutableSet;
+import com.google.common.collect.Lists;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import org.apache.cassandra.concurrent.DebuggableTask;
 import org.apache.cassandra.concurrent.LocalAwareExecutorService;
+import org.apache.cassandra.config.Config;
 import org.apache.cassandra.config.DatabaseDescriptor;
 import org.apache.cassandra.exceptions.OverloadedException;
 import org.apache.cassandra.metrics.ClientMetrics;
@@ -64,6 +67,10 @@
 public abstract class Message
 {
     protected static final Logger logger = LoggerFactory.getLogger(Message.class);
+    /**
+     * Max length to display values for debug strings
+     **/
+    public final static int MAX_VALUE_LEN = Integer.getInteger(Config.PROPERTY_PREFIX + "max_cql_debug_length", 128);
 
     /**
      * When we encounter an unexpected IOException we look for these {@link Throwable#getMessage() messages}
@@ -905,4 +912,38 @@ public boolean apply(Throwable exception)
             return true;
         }
     }
+
+
+    protected static String truncateCqlLiteral(String value)
+    {
+        return truncateCqlLiteral(value, MAX_VALUE_LEN);
+    }
+
+    /**
+     * chars that wrap a CQL literal
+     */
+    private static List<Character> LITERAL_END = Lists.newArrayList('\'', ']', '}', ')');
+
+    @VisibleForTesting
+    protected static String truncateCqlLiteral(final String value, int max)
+    {
+        if (value.length() <= max)
+            return value;
+
+        String result = value;
+        // Do not interrupt a escaped '
+        int truncateAt = max;
+        for (;value.charAt(truncateAt) == '\'' && truncateAt < value.length()-1; truncateAt++);
+
+        result = value.substring(0, truncateAt) + "...";
+
+        // both string literals or blobs are expected to exceed this size, while blobs are fine as is the string
+        // literals will be truncating their trailing '. Collections have (), {}, and []'s
+        char last = value.charAt(value.length() - 1);
+        if (LITERAL_END.contains(last))
+        {
+            result += last;
+        }
+        return result;
+    }
 }

src/java/org/apache/cassandra/transport/messages/BatchMessage.java

@@ -30,6 +30,7 @@
 import org.apache.cassandra.cql3.Attributes;
 import org.apache.cassandra.cql3.BatchQueryOptions;
 import org.apache.cassandra.cql3.CQLStatement;
+import org.apache.cassandra.cql3.ColumnSpecification;
 import org.apache.cassandra.cql3.QueryHandler;
 import org.apache.cassandra.cql3.QueryOptions;
 import org.apache.cassandra.cql3.QueryProcessor;
@@ -260,14 +261,34 @@ private void logException(QueryState state, Exception e)
     @Override
     public String toString()
     {
-        StringBuilder sb = new StringBuilder();
-        sb.append("BATCH of [");
-        for (int i = 0; i < queryOrIdList.size(); i++)
+        QueryHandler handler = ClientState.getCQLQueryHandler();
+        StringBuilder sb = new StringBuilder(batchType.toString());
+        sb.append(" BATCH of [");
+        for (int q = 0; q < queryOrIdList.size(); q++)
         {
-            if (i > 0) sb.append(", ");
-            sb.append(queryOrIdList.get(i)).append(" with ").append(values.get(i).size()).append(" values");
+            if (q > 0) sb.append(", ");
+
+            Object query = queryOrIdList.get(q);
+            if (query instanceof String)
+                sb.append(query);
+            else
+            {
+                QueryHandler.Prepared prepared = handler.getPrepared((MD5Digest) query);
+                if (null == prepared)
+                    throw new PreparedQueryNotFoundException((MD5Digest) query);
+                List<ByteBuffer> queryValues = this.values.get(q);
+                List<String> values = new ArrayList<>(prepared.statement.getBindVariables().size());
+                for (int i = 0; i < prepared.statement.getBindVariables().size(); i++)
+                {
+                    ColumnSpecification cs = prepared.statement.getBindVariables().get(i);
+                    String boundValue = cs.type.asCQL3Type().toCQLLiteral(queryValues.get(i), options.getProtocolVersion());
+                    boundValue = truncateCqlLiteral(boundValue);
+                    values.add(boundValue);
+                }
+                sb.append(prepared.rawCQLStatement).append(" WITH ").append(values);
+            }
         }
-        sb.append("] at consistency ").append(options.getConsistency());
+        sb.append("] AT CONSISTENCY ").append(options.getConsistency());
         return sb.toString();
     }
 

src/java/org/apache/cassandra/transport/messages/ExecuteMessage.java

@@ -17,6 +17,8 @@
  */
 package org.apache.cassandra.transport.messages;
 
+import java.util.Map;
+
 import com.google.common.collect.ImmutableMap;
 
 import io.netty.buffer.ByteBuf;
@@ -195,20 +197,25 @@ private void traceQuery(QueryState state, QueryHandler.Prepared prepared)
 
         builder.put("query", prepared.rawCQLStatement);
 
+        builder.putAll(values(prepared));
+
+        Tracing.instance.begin("Execute CQL3 prepared query", state.getClientAddress(), builder.build());
+    }
+
+    private Map<String, String> values(QueryHandler.Prepared prepared)
+    {
+        ImmutableMap.Builder<String, String> builder = ImmutableMap.builder();
         for (int i = 0; i < prepared.statement.getBindVariables().size(); i++)
         {
             ColumnSpecification cs = prepared.statement.getBindVariables().get(i);
             String boundName = cs.name.toString();
             String boundValue = cs.type.asCQL3Type().toCQLLiteral(options.getValues().get(i), options.getProtocolVersion());
-            if (boundValue.length() > 1000)
-                boundValue = boundValue.substring(0, 1000) + "...'";
-
+            boundValue = truncateCqlLiteral(boundValue);
             //Here we prefix boundName with the index to avoid possible collission in builder keys due to
             //having multiple boundValues for the same variable
             builder.put("bound_var_" + i + '_' + boundName, boundValue);
         }
-
-        Tracing.instance.begin("Execute CQL3 prepared query", state.getClientAddress(), builder.build());
+        return builder.build();
     }
 
     private void logSuccess(QueryState state, QueryHandler.Prepared prepared, long requestStartTime)
@@ -256,6 +263,12 @@ private void logException(QueryState state, Exception e)
     @Override
     public String toString()
     {
-        return String.format("EXECUTE %s with %d values at consistency %s", statementId, options.getValues().size(), options.getConsistency());
+        QueryHandler handler = ClientState.getCQLQueryHandler();
+        QueryHandler.Prepared prepared = handler.getPrepared(statementId);
+        if (prepared == null)
+            throw new PreparedQueryNotFoundException(statementId);
+
+        return String.format("EXECUTE %s WITH %s AT CONSISTENCY %s", prepared.rawCQLStatement,
+                             values(prepared).values(), options.getConsistency());
     }
 }

src/java/org/apache/cassandra/transport/messages/PrepareMessage.java

@@ -156,6 +156,6 @@ private void logException(QueryState state, Exception e)
     @Override
     public String toString()
     {
-        return "PREPARE " + query;
+        return String.format("PREPARE %s IN %s", query, keyspace);
     }
 }

src/java/org/apache/cassandra/transport/messages/QueryMessage.java

@@ -169,6 +169,8 @@ private void logException(QueryState state, Exception e)
     @Override
     public String toString()
     {
-        return String.format("QUERY %s [pageSize = %d]", query, options.getPageSize());
+        return String.format("QUERY %s WITH pageSize = %d AT CONSISTENCY %s", query,
+                             options.getPageSize(),
+                             options.getConsistency().name());
     }
 }