All Downloads are FREE. Search and download functionalities are using the official Maven repository.

com.datastax.driver.core.QueryLogger Maven / Gradle / Ivy

Go to download

A driver for DataStax Enterprise (DSE) and Apache Cassandra 1.2+ clusters that works exclusively with the Cassandra Query Language version 3 (CQL3) and Cassandra's binary protocol, supporting DSE-specific features such as geospatial types, DSE Graph and DSE authentication.

There is a newer version: 2.4.0
Show newest version
/*
 * Copyright DataStax, Inc.
 *
 * This software can be used solely with DataStax Enterprise. Please consult the license at
 * http://www.datastax.com/terms/datastax-dse-driver-license-terms
 */
package com.datastax.driver.core;

import com.google.common.annotations.VisibleForTesting;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.nio.ByteBuffer;
import java.util.Iterator;
import java.util.List;

import static java.util.concurrent.TimeUnit.NANOSECONDS;

/**
 * A configurable {@link LatencyTracker} that logs all executed statements.
 * 

* Typically, client applications would instantiate one single query logger (using its {@link Builder}), * configure it and register it on the relevant {@link Cluster} instance, e.g.: *

*

 * Cluster cluster = ...
 * QueryLogger queryLogger = QueryLogger.builder()
 *     .withConstantThreshold(...)
 *     .withMaxQueryStringLength(...)
 *     .build();
 * cluster.register(queryLogger);
 * 
*

* Refer to the {@link Builder} documentation for more information on * configuration settings for the query logger. *

* Once registered, the query logger will log every {@link RegularStatement}, {@link BoundStatement} or {@link BatchStatement} * executed by the driver; * note that it will never log other types of statement, null statements nor any special statement used internally by the driver. *

* There is one log for each request to a Cassandra node; because the driver sometimes retries the same statement on multiple nodes, * a single statement execution (for example, a single call to {@link Session#execute(Statement)}) can produce multiple logs on * different nodes. *

* For more flexibility, the query logger uses 3 different {@link Logger} instances: *

*

    *
  1. {@link #NORMAL_LOGGER}: used to log normal queries, i.e., queries that completed successfully * within a configurable threshold in milliseconds.
  2. *
  3. {@link #SLOW_LOGGER}: used to log slow queries, i.e., queries that completed successfully * but that took longer than a configurable threshold in milliseconds to complete.
  4. *
  5. {@link #ERROR_LOGGER}: used to log unsuccessful queries, i.e., * queries that did not completed normally and threw an exception. * Note this this logger will also print the full stack trace of the reported exception.
  6. *
*

*

* The appropriate logger is chosen according to the following algorithm: *

    *
  1. if an exception has been thrown: use {@link #ERROR_LOGGER};
  2. *
  3. otherwise, if the reported latency is greater than the configured threshold in milliseconds: use {@link #SLOW_LOGGER};
  4. *
  5. otherwise, use {@link #NORMAL_LOGGER}.
  6. *
*

*

* All loggers are activated by setting their levels to {@code DEBUG} or {@code TRACE} (including {@link #ERROR_LOGGER}). * If the level is set to {@code TRACE} and the statement being logged is a {@link BoundStatement}, * then the query parameters (if any) will be logged as well (names and actual values). *

*

* Constant thresholds vs. Dynamic thresholds *

* Currently the QueryLogger can track slow queries in two different ways: * using a {@link Builder#withConstantThreshold(long)} constant threshold} in milliseconds (which is the default * behavior), or using a {@link Builder#withDynamicThreshold(PercentileTracker, double) dynamic threshold} * based on latency percentiles. *

* This class is thread-safe. * * @since 2.0.10 */ public abstract class QueryLogger implements LatencyTracker { /** * The default latency threshold in milliseconds beyond which queries are considered 'slow' * and logged as such by the driver. */ public static final long DEFAULT_SLOW_QUERY_THRESHOLD_MS = 5000; /** * The default latency percentile beyond which queries are considered 'slow' * and logged as such by the driver. */ public static final double DEFAULT_SLOW_QUERY_THRESHOLD_PERCENTILE = 99.0; /** * The default maximum length of a CQL query string that can be logged verbatim * by the driver. Query strings longer than this value will be truncated * when logged. */ public static final int DEFAULT_MAX_QUERY_STRING_LENGTH = 500; /** * The default maximum length of a query parameter value that can be logged verbatim * by the driver. Parameter values longer than this value will be truncated * when logged. */ public static final int DEFAULT_MAX_PARAMETER_VALUE_LENGTH = 50; /** * The default maximum number of query parameters that can be logged * by the driver. Queries with a number of parameters higher than this value * will not have all their parameters logged. */ public static final int DEFAULT_MAX_LOGGED_PARAMETERS = 50; // Loggers /** * The logger used to log normal queries, i.e., queries that completed successfully * within a configurable threshold in milliseconds. *

* This logger is activated by setting its level to {@code DEBUG} or {@code TRACE}. * Additionally, if the level is set to {@code TRACE} and the statement being logged is a {@link BoundStatement} * or a {@link SimpleStatement}, then the query parameters (if any) will be logged. For a {@link BoundStatement} * names and actual values are logged and for a {@link SimpleStatement} values are logged in positional order * and named values are logged with names and value. *

* The name of this logger is {@code com.datastax.driver.core.QueryLogger.NORMAL}. */ public static final Logger NORMAL_LOGGER = LoggerFactory.getLogger("com.datastax.driver.core.QueryLogger.NORMAL"); /** * The logger used to log slow queries, i.e., queries that completed successfully * but whose execution time exceeded a configurable threshold in milliseconds. *

* This logger is activated by setting its level to {@code DEBUG} or {@code TRACE}. * Additionally, if the level is set to {@code TRACE} and the statement being logged is a {@link BoundStatement} * or a {@link SimpleStatement}, then the query parameters (if any) will be logged. For a {@link BoundStatement} * names and actual values are logged and for a {@link SimpleStatement} values are logged in positional order * and named values are logged with names and value. *

* The name of this logger is {@code com.datastax.driver.core.QueryLogger.SLOW}. */ public static final Logger SLOW_LOGGER = LoggerFactory.getLogger("com.datastax.driver.core.QueryLogger.SLOW"); /** * The logger used to log unsuccessful queries, i.e., queries that did not complete normally and threw an exception. *

* This logger is activated by setting its level to {@code DEBUG} or {@code TRACE}. * Additionally, if the level is set to {@code TRACE} and the statement being logged is a {@link BoundStatement} * or a {@link SimpleStatement}, then the query parameters (if any) will be logged. For a {@link BoundStatement} * names and actual values are logged and for a {@link SimpleStatement} values are logged in positional order * and named values are logged with names and value. * Note this this logger will also print the full stack trace of the reported exception. *

* The name of this logger is {@code com.datastax.driver.core.QueryLogger.ERROR}. */ public static final Logger ERROR_LOGGER = LoggerFactory.getLogger("com.datastax.driver.core.QueryLogger.ERROR"); // Message templates private static final String NORMAL_TEMPLATE = "[%s] [%s] Query completed normally, took %s ms: %s"; private static final String SLOW_TEMPLATE_MILLIS = "[%s] [%s] Query too slow, took %s ms: %s"; private static final String SLOW_TEMPLATE_PERCENTILE = "[%s] [%s] Query too slow, took %s ms (%s percentile = %s ms): %s"; private static final String ERROR_TEMPLATE = "[%s] [%s] Query error after %s ms: %s"; @VisibleForTesting static final String TRUNCATED_OUTPUT = "... [truncated output]"; @VisibleForTesting static final String FURTHER_PARAMS_OMITTED = " [further parameters omitted]"; protected volatile Cluster cluster; private volatile ProtocolVersion protocolVersion; protected volatile int maxQueryStringLength; protected volatile int maxParameterValueLength; protected volatile int maxLoggedParameters; /** * Private constructor. Instances of QueryLogger should be obtained via the {@link #builder()} method. */ private QueryLogger(int maxQueryStringLength, int maxParameterValueLength, int maxLoggedParameters) { this.maxQueryStringLength = maxQueryStringLength; this.maxParameterValueLength = maxParameterValueLength; this.maxLoggedParameters = maxLoggedParameters; } /** * Creates a new {@link QueryLogger.Builder} instance. *

* This is a convenience method for {@code new QueryLogger.Builder()}. * * @return the new QueryLogger builder. * @throws NullPointerException if {@code cluster} is {@code null}. */ public static QueryLogger.Builder builder() { return new QueryLogger.Builder(); } @Override public void onRegister(Cluster cluster) { this.cluster = cluster; } @Override public void onUnregister(Cluster cluster) { // nothing to do } /** * A QueryLogger that uses a constant threshold in milliseconds * to track slow queries. * This implementation is the default and should be preferred to {@link DynamicThresholdQueryLogger} * which is still in beta state. */ public static class ConstantThresholdQueryLogger extends QueryLogger { private volatile long slowQueryLatencyThresholdMillis; private ConstantThresholdQueryLogger(int maxQueryStringLength, int maxParameterValueLength, int maxLoggedParameters, long slowQueryLatencyThresholdMillis) { super(maxQueryStringLength, maxParameterValueLength, maxLoggedParameters); this.setSlowQueryLatencyThresholdMillis(slowQueryLatencyThresholdMillis); } /** * Return the threshold in milliseconds beyond which queries are considered 'slow' * and logged as such by the driver. * The default value is {@link #DEFAULT_SLOW_QUERY_THRESHOLD_MS}. * * @return The threshold in milliseconds beyond which queries are considered 'slow' * and logged as such by the driver. */ public long getSlowQueryLatencyThresholdMillis() { return slowQueryLatencyThresholdMillis; } /** * Set the threshold in milliseconds beyond which queries are considered 'slow' * and logged as such by the driver. * * @param slowQueryLatencyThresholdMillis Slow queries threshold in milliseconds. * It must be strictly positive. * @throws IllegalArgumentException if {@code slowQueryLatencyThresholdMillis <= 0}. */ public void setSlowQueryLatencyThresholdMillis(long slowQueryLatencyThresholdMillis) { if (slowQueryLatencyThresholdMillis <= 0) throw new IllegalArgumentException("Invalid slowQueryLatencyThresholdMillis, should be > 0, got " + slowQueryLatencyThresholdMillis); this.slowQueryLatencyThresholdMillis = slowQueryLatencyThresholdMillis; } @Override protected void maybeLogNormalOrSlowQuery(Host host, Statement statement, long latencyMs) { if (latencyMs > slowQueryLatencyThresholdMillis) { maybeLogSlowQuery(host, statement, latencyMs); } else { maybeLogNormalQuery(host, statement, latencyMs); } } protected void maybeLogSlowQuery(Host host, Statement statement, long latencyMs) { if (SLOW_LOGGER.isDebugEnabled()) { String message = String.format(SLOW_TEMPLATE_MILLIS, cluster.getClusterName(), host, latencyMs, statementAsString(statement)); logQuery(statement, null, SLOW_LOGGER, message); } } } /** * A QueryLogger that uses a dynamic threshold in milliseconds * to track slow queries. *

* Dynamic thresholds are based on per-host latency percentiles, as computed * by {@link PercentileTracker}. */ public static class DynamicThresholdQueryLogger extends QueryLogger { private volatile double slowQueryLatencyThresholdPercentile; private volatile PercentileTracker percentileLatencyTracker; private DynamicThresholdQueryLogger(int maxQueryStringLength, int maxParameterValueLength, int maxLoggedParameters, double slowQueryLatencyThresholdPercentile, PercentileTracker percentileLatencyTracker) { super(maxQueryStringLength, maxParameterValueLength, maxLoggedParameters); this.setSlowQueryLatencyThresholdPercentile(slowQueryLatencyThresholdPercentile); this.setPercentileLatencyTracker(percentileLatencyTracker); } /** * Return the percentile tracker to use for recording per-host latency histograms. * Cannot be {@code null}. * * @return the percentile tracker to use. */ public PercentileTracker getPercentileLatencyTracker() { return percentileLatencyTracker; } /** * Set the percentile tracker to use for recording per-host latency histograms. * Cannot be {@code null}. * * @param percentileLatencyTracker the percentile tracker instance to use. * @throws IllegalArgumentException if {@code percentileLatencyTracker == null}. */ public void setPercentileLatencyTracker(PercentileTracker percentileLatencyTracker) { if (percentileLatencyTracker == null) throw new IllegalArgumentException("perHostPercentileLatencyTracker cannot be null"); this.percentileLatencyTracker = percentileLatencyTracker; } /** * Return the threshold percentile beyond which queries are considered 'slow' * and logged as such by the driver. * The default value is {@link #DEFAULT_SLOW_QUERY_THRESHOLD_PERCENTILE}. * * @return threshold percentile beyond which queries are considered 'slow' * and logged as such by the driver. */ public double getSlowQueryLatencyThresholdPercentile() { return slowQueryLatencyThresholdPercentile; } /** * Set the threshold percentile beyond which queries are considered 'slow' * and logged as such by the driver. * * @param slowQueryLatencyThresholdPercentile Slow queries threshold percentile. * It must be comprised between 0 inclusive and 100 exclusive. * @throws IllegalArgumentException if {@code slowQueryLatencyThresholdPercentile < 0 || slowQueryLatencyThresholdPercentile >= 100}. */ public void setSlowQueryLatencyThresholdPercentile(double slowQueryLatencyThresholdPercentile) { if (slowQueryLatencyThresholdPercentile < 0.0 || slowQueryLatencyThresholdPercentile >= 100.0) throw new IllegalArgumentException("Invalid slowQueryLatencyThresholdPercentile, should be >= 0 and < 100, got " + slowQueryLatencyThresholdPercentile); this.slowQueryLatencyThresholdPercentile = slowQueryLatencyThresholdPercentile; } @Override protected void maybeLogNormalOrSlowQuery(Host host, Statement statement, long latencyMs) { long threshold = percentileLatencyTracker.getLatencyAtPercentile(host, statement, null, slowQueryLatencyThresholdPercentile); if (threshold >= 0 && latencyMs > threshold) { maybeLogSlowQuery(host, statement, latencyMs, threshold); } else { maybeLogNormalQuery(host, statement, latencyMs); } } protected void maybeLogSlowQuery(Host host, Statement statement, long latencyMs, long threshold) { if (SLOW_LOGGER.isDebugEnabled()) { String message = String.format(SLOW_TEMPLATE_PERCENTILE, cluster.getClusterName(), host, latencyMs, slowQueryLatencyThresholdPercentile, threshold, statementAsString(statement)); logQuery(statement, null, SLOW_LOGGER, message); } } @Override public void onRegister(Cluster cluster) { super.onRegister(cluster); cluster.register(percentileLatencyTracker); } // Don't unregister the latency tracker in onUnregister, we can't guess if it's being used by another component // or not. } /** * Helper class to build {@link QueryLogger} instances with a fluent API. */ public static class Builder { private int maxQueryStringLength = DEFAULT_MAX_QUERY_STRING_LENGTH; private int maxParameterValueLength = DEFAULT_MAX_PARAMETER_VALUE_LENGTH; private int maxLoggedParameters = DEFAULT_MAX_LOGGED_PARAMETERS; private long slowQueryLatencyThresholdMillis = DEFAULT_SLOW_QUERY_THRESHOLD_MS; private double slowQueryLatencyThresholdPercentile = DEFAULT_SLOW_QUERY_THRESHOLD_PERCENTILE; private PercentileTracker percentileLatencyTracker; private boolean constantThreshold = true; /** * Enables slow query latency tracking based on constant thresholds. *

* Note: You should either use {@link #withConstantThreshold(long) constant thresholds} * or {@link #withDynamicThreshold(PercentileTracker, double) dynamic thresholds}, * not both. * * @param slowQueryLatencyThresholdMillis The threshold in milliseconds beyond which queries are considered 'slow' * and logged as such by the driver. * The default value is {@link #DEFAULT_SLOW_QUERY_THRESHOLD_MS} * @return this {@link Builder} instance (for method chaining). */ public Builder withConstantThreshold(long slowQueryLatencyThresholdMillis) { this.slowQueryLatencyThresholdMillis = slowQueryLatencyThresholdMillis; constantThreshold = true; return this; } /** * Enables slow query latency tracking based on dynamic thresholds. *

* Dynamic thresholds are based on latency percentiles, as computed by {@link PercentileTracker}. *

* Note: You should either use {@link #withConstantThreshold(long) constant thresholds} or * {@link #withDynamicThreshold(PercentileTracker, double) dynamic thresholds}, not both. * * @param percentileLatencyTracker the {@link PercentileTracker} instance to use for recording * latency histograms. Cannot be {@code null}. * It will get {@link Cluster#register(LatencyTracker) registered} * with the cluster at the same time as this logger. * @param slowQueryLatencyThresholdPercentile Slow queries threshold percentile. * It must be comprised between 0 inclusive and 100 exclusive. * The default value is {@link #DEFAULT_SLOW_QUERY_THRESHOLD_PERCENTILE} * @return this {@link Builder} instance (for method chaining). */ public Builder withDynamicThreshold(PercentileTracker percentileLatencyTracker, double slowQueryLatencyThresholdPercentile) { this.percentileLatencyTracker = percentileLatencyTracker; this.slowQueryLatencyThresholdPercentile = slowQueryLatencyThresholdPercentile; constantThreshold = false; return this; } /** * Set the maximum length of a CQL query string that can be logged verbatim * by the driver. Query strings longer than this value will be truncated * when logged. * * @param maxQueryStringLength The maximum length of a CQL query string * that can be logged verbatim by the driver. * It must be strictly positive or {@code -1}, * in which case the query is never truncated * (use with care). * The default value is {@link #DEFAULT_MAX_QUERY_STRING_LENGTH}. * @return this {@link Builder} instance (for method chaining). */ public Builder withMaxQueryStringLength(int maxQueryStringLength) { this.maxQueryStringLength = maxQueryStringLength; return this; } /** * Set the maximum length of a query parameter value that can be logged verbatim * by the driver. Parameter values longer than this value will be truncated * when logged. * * @param maxParameterValueLength The maximum length of a query parameter value * that can be logged verbatim by the driver. * It must be strictly positive or {@code -1}, * in which case the parameter value is never truncated * (use with care). * The default value is {@link #DEFAULT_MAX_PARAMETER_VALUE_LENGTH}. * @return this {@link Builder} instance (for method chaining). */ public Builder withMaxParameterValueLength(int maxParameterValueLength) { this.maxParameterValueLength = maxParameterValueLength; return this; } /** * Set the maximum number of query parameters that can be logged * by the driver. Queries with a number of parameters higher than this value * will not have all their parameters logged. * * @param maxLoggedParameters The maximum number of query parameters that can be logged * by the driver. It must be strictly positive or {@code -1}, * in which case all parameters will be logged, regardless of their number * (use with care). * The default value is {@link #DEFAULT_MAX_LOGGED_PARAMETERS}. * @return this {@link Builder} instance (for method chaining). */ public Builder withMaxLoggedParameters(int maxLoggedParameters) { this.maxLoggedParameters = maxLoggedParameters; return this; } /** * Build the {@link QueryLogger} instance. * * @return the {@link QueryLogger} instance. * @throws IllegalArgumentException if the builder is unable to build a valid instance due to incorrect settings. */ public QueryLogger build() { if (constantThreshold) { return new ConstantThresholdQueryLogger(maxQueryStringLength, maxParameterValueLength, maxLoggedParameters, slowQueryLatencyThresholdMillis); } else { return new DynamicThresholdQueryLogger(maxQueryStringLength, maxParameterValueLength, maxLoggedParameters, slowQueryLatencyThresholdPercentile, percentileLatencyTracker); } } } // Getters and Setters /** * Return the maximum length of a CQL query string that can be logged verbatim * by the driver. Query strings longer than this value will be truncated * when logged. * The default value is {@link #DEFAULT_MAX_QUERY_STRING_LENGTH}. * * @return The maximum length of a CQL query string that can be logged verbatim * by the driver. */ public int getMaxQueryStringLength() { return maxQueryStringLength; } /** * Set the maximum length of a CQL query string that can be logged verbatim * by the driver. Query strings longer than this value will be truncated * when logged. * * @param maxQueryStringLength The maximum length of a CQL query string * that can be logged verbatim by the driver. * It must be strictly positive or {@code -1}, * in which case the query is never truncated * (use with care). * @throws IllegalArgumentException if {@code maxQueryStringLength <= 0 && maxQueryStringLength != -1}. */ public void setMaxQueryStringLength(int maxQueryStringLength) { if (maxQueryStringLength <= 0 && maxQueryStringLength != -1) throw new IllegalArgumentException("Invalid maxQueryStringLength, should be > 0 or -1, got " + maxQueryStringLength); this.maxQueryStringLength = maxQueryStringLength; } /** * Return the maximum length of a query parameter value that can be logged verbatim * by the driver. Parameter values longer than this value will be truncated * when logged. * The default value is {@link #DEFAULT_MAX_PARAMETER_VALUE_LENGTH}. * * @return The maximum length of a query parameter value that can be logged verbatim * by the driver. */ public int getMaxParameterValueLength() { return maxParameterValueLength; } /** * Set the maximum length of a query parameter value that can be logged verbatim * by the driver. Parameter values longer than this value will be truncated * when logged. * * @param maxParameterValueLength The maximum length of a query parameter value * that can be logged verbatim by the driver. * It must be strictly positive or {@code -1}, * in which case the parameter value is never truncated * (use with care). * @throws IllegalArgumentException if {@code maxParameterValueLength <= 0 && maxParameterValueLength != -1}. */ public void setMaxParameterValueLength(int maxParameterValueLength) { if (maxParameterValueLength <= 0 && maxParameterValueLength != -1) throw new IllegalArgumentException("Invalid maxParameterValueLength, should be > 0 or -1, got " + maxParameterValueLength); this.maxParameterValueLength = maxParameterValueLength; } /** * Return the maximum number of query parameters that can be logged * by the driver. Queries with a number of parameters higher than this value * will not have all their parameters logged. * The default value is {@link #DEFAULT_MAX_LOGGED_PARAMETERS}. * * @return The maximum number of query parameters that can be logged * by the driver. */ public int getMaxLoggedParameters() { return maxLoggedParameters; } /** * Set the maximum number of query parameters that can be logged * by the driver. Queries with a number of parameters higher than this value * will not have all their parameters logged. * * @param maxLoggedParameters the maximum number of query parameters that can be logged * by the driver. It must be strictly positive or {@code -1}, * in which case all parameters will be logged, regardless of their number * (use with care). * @throws IllegalArgumentException if {@code maxLoggedParameters <= 0 && maxLoggedParameters != -1}. */ public void setMaxLoggedParameters(int maxLoggedParameters) { if (maxLoggedParameters <= 0 && maxLoggedParameters != -1) throw new IllegalArgumentException("Invalid maxLoggedParameters, should be > 0 or -1, got " + maxLoggedParameters); this.maxLoggedParameters = maxLoggedParameters; } /** * {@inheritDoc} */ @Override public void update(Host host, Statement statement, Exception exception, long newLatencyNanos) { if (cluster == null) throw new IllegalStateException("This method should only be called after the logger has been registered with a cluster"); if (statement instanceof StatementWrapper) statement = ((StatementWrapper) statement).getWrappedStatement(); long latencyMs = NANOSECONDS.toMillis(newLatencyNanos); if (exception == null) { maybeLogNormalOrSlowQuery(host, statement, latencyMs); } else { maybeLogErrorQuery(host, statement, exception, latencyMs); } } protected abstract void maybeLogNormalOrSlowQuery(Host host, Statement statement, long latencyMs); protected void maybeLogNormalQuery(Host host, Statement statement, long latencyMs) { if (NORMAL_LOGGER.isDebugEnabled()) { String message = String.format(NORMAL_TEMPLATE, cluster.getClusterName(), host, latencyMs, statementAsString(statement)); logQuery(statement, null, NORMAL_LOGGER, message); } } protected void maybeLogErrorQuery(Host host, Statement statement, Exception exception, long latencyMs) { if (ERROR_LOGGER.isDebugEnabled() && !(exception instanceof CancelledSpeculativeExecutionException)) { String message = String.format(ERROR_TEMPLATE, cluster.getClusterName(), host, latencyMs, statementAsString(statement)); logQuery(statement, exception, ERROR_LOGGER, message); } } protected void logQuery(Statement statement, Exception exception, Logger logger, String message) { boolean showParameterValues = logger.isTraceEnabled(); if (showParameterValues) { StringBuilder params = new StringBuilder(); if (statement instanceof BoundStatement) { appendParameters((BoundStatement) statement, params, maxLoggedParameters); } else if (statement instanceof SimpleStatement) { appendParameters((SimpleStatement) statement, params, maxLoggedParameters); } else if (statement instanceof BatchStatement) { BatchStatement batchStatement = (BatchStatement) statement; int remaining = maxLoggedParameters; for (Statement inner : batchStatement.getStatements()) { if (inner instanceof BoundStatement) { remaining = appendParameters((BoundStatement) inner, params, remaining); } else if (inner instanceof SimpleStatement) { remaining = appendParameters((SimpleStatement) inner, params, remaining); } } } if (params.length() > 0) params.append("]"); logger.trace(message + params, exception); } else { logger.debug(message, exception); } } protected String statementAsString(Statement statement) { StringBuilder sb = new StringBuilder(); if (statement instanceof BatchStatement) { BatchStatement bs = (BatchStatement) statement; int statements = bs.getStatements().size(); int boundValues = countBoundValues(bs); sb.append("[" + statements + " statements, " + boundValues + " bound values] "); } else if (statement instanceof BoundStatement) { int boundValues = ((BoundStatement) statement).wrapper.values.length; sb.append("[" + boundValues + " bound values] "); } else if (statement instanceof SimpleStatement) { int boundValues = ((SimpleStatement) statement).valuesCount(); sb.append("[" + boundValues + " bound values] "); } append(statement, sb, maxQueryStringLength); return sb.toString(); } protected int countBoundValues(BatchStatement bs) { int count = 0; for (Statement s : bs.getStatements()) { if (s instanceof BoundStatement) count += ((BoundStatement) s).wrapper.values.length; else if (s instanceof SimpleStatement) count += ((SimpleStatement) s).valuesCount(); } return count; } protected int appendParameters(BoundStatement statement, StringBuilder buffer, int remaining) { if (remaining == 0) return 0; ColumnDefinitions metadata = statement.preparedStatement().getVariables(); int numberOfParameters = metadata.size(); if (numberOfParameters > 0) { List definitions = metadata.asList(); int numberOfLoggedParameters; if (remaining == -1) { numberOfLoggedParameters = numberOfParameters; } else { numberOfLoggedParameters = Math.min(remaining, numberOfParameters); remaining -= numberOfLoggedParameters; } for (int i = 0; i < numberOfLoggedParameters; i++) { if (buffer.length() == 0) buffer.append(" ["); else buffer.append(", "); String value = statement.isSet(i) ? parameterValueAsString(definitions.get(i), statement.wrapper.values[i]) : ""; buffer.append(String.format("%s:%s", metadata.getName(i), value)); } if (numberOfLoggedParameters < numberOfParameters) { buffer.append(FURTHER_PARAMS_OMITTED); } } return remaining; } protected String parameterValueAsString(ColumnDefinitions.Definition definition, ByteBuffer raw) { String valueStr; if (raw == null || raw.remaining() == 0) { valueStr = "NULL"; } else { DataType type = definition.getType(); CodecRegistry codecRegistry = cluster.getConfiguration().getCodecRegistry(); TypeCodec codec = codecRegistry.codecFor(type); int maxParameterValueLength = this.maxParameterValueLength; if (type.equals(DataType.blob()) && maxParameterValueLength != -1) { // prevent large blobs from being converted to strings int maxBufferLength = Math.max(2, (maxParameterValueLength - 2) / 2); boolean bufferTooLarge = raw.remaining() > maxBufferLength; if (bufferTooLarge) { raw = (ByteBuffer) raw.duplicate().limit(maxBufferLength); } Object value = codec.deserialize(raw, protocolVersion()); valueStr = codec.format(value); if (bufferTooLarge) { valueStr = valueStr + TRUNCATED_OUTPUT; } } else { Object value = codec.deserialize(raw, protocolVersion()); valueStr = codec.format(value); if (maxParameterValueLength != -1 && valueStr.length() > maxParameterValueLength) { valueStr = valueStr.substring(0, maxParameterValueLength) + TRUNCATED_OUTPUT; } } } return valueStr; } protected int appendParameters(SimpleStatement statement, StringBuilder buffer, int remaining) { if (remaining == 0) return 0; int numberOfParameters = statement.valuesCount(); if (numberOfParameters > 0) { int numberOfLoggedParameters; if (remaining == -1) { numberOfLoggedParameters = numberOfParameters; } else { numberOfLoggedParameters = remaining > numberOfParameters ? numberOfParameters : remaining; remaining -= numberOfLoggedParameters; } Iterator valueNames = null; if (statement.usesNamedValues()) { valueNames = statement.getValueNames().iterator(); } for (int i = 0; i < numberOfLoggedParameters; i++) { if (buffer.length() == 0) buffer.append(" ["); else buffer.append(", "); if (valueNames != null && valueNames.hasNext()) { String valueName = valueNames.next(); buffer.append(String.format("%s:%s", valueName, parameterValueAsString(statement.getObject(valueName)))); } else { buffer.append(parameterValueAsString(statement.getObject(i))); } } if (numberOfLoggedParameters < numberOfParameters) { buffer.append(FURTHER_PARAMS_OMITTED); } } return remaining; } protected String parameterValueAsString(Object value) { String valueStr; if (value == null) { valueStr = "NULL"; } else { CodecRegistry codecRegistry = cluster.getConfiguration().getCodecRegistry(); TypeCodec codec = codecRegistry.codecFor(value); int maxParameterValueLength = this.maxParameterValueLength; if (codec.cqlType.equals(DataType.blob()) && maxParameterValueLength != -1) { // prevent large blobs from being converted to strings ByteBuffer buf = (ByteBuffer) value; int maxBufferLength = Math.max(2, (maxParameterValueLength - 2) / 2); boolean bufferTooLarge = buf.remaining() > maxBufferLength; if (bufferTooLarge) { value = (ByteBuffer) buf.duplicate().limit(maxBufferLength); } valueStr = codec.format(value); if (bufferTooLarge) { valueStr = valueStr + TRUNCATED_OUTPUT; } } else { valueStr = codec.format(value); if (maxParameterValueLength != -1 && valueStr.length() > maxParameterValueLength) { valueStr = valueStr.substring(0, maxParameterValueLength) + TRUNCATED_OUTPUT; } } } return valueStr; } private ProtocolVersion protocolVersion() { // Since the QueryLogger can be registered before the Cluster was initialized, we can't retrieve // it at construction time. Cache it field at first use (a volatile field is good enough since we // don't need mutual exclusion). if (protocolVersion == null) { protocolVersion = cluster.getConfiguration().getProtocolOptions().getProtocolVersion(); // At least one connection was established when QueryLogger is invoked assert protocolVersion != null : "protocol version should be defined"; } return protocolVersion; } protected int append(Statement statement, StringBuilder buffer, int remaining) { if (statement instanceof RegularStatement) { RegularStatement rs = (RegularStatement) statement; String query = rs.getQueryString(); remaining = append(query.trim(), buffer, remaining); } else if (statement instanceof BoundStatement) { remaining = append(((BoundStatement) statement).preparedStatement().getQueryString().trim(), buffer, remaining); } else if (statement instanceof BatchStatement) { BatchStatement batchStatement = (BatchStatement) statement; remaining = append("BEGIN", buffer, remaining); switch (batchStatement.batchType) { case UNLOGGED: append(" UNLOGGED", buffer, remaining); break; case COUNTER: append(" COUNTER", buffer, remaining); break; } remaining = append(" BATCH", buffer, remaining); for (Statement stmt : batchStatement.getStatements()) { remaining = append(" ", buffer, remaining); remaining = append(stmt, buffer, remaining); } remaining = append(" APPLY BATCH", buffer, remaining); } else { // Unknown types of statement // Call toString() as a last resort remaining = append(statement.toString(), buffer, remaining); } if (buffer.charAt(buffer.length() - 1) != ';') { remaining = append(";", buffer, remaining); } return remaining; } protected int append(CharSequence str, StringBuilder buffer, int remaining) { if (remaining == -2) { // capacity exceeded } else if (remaining == -1) { // unlimited capacity buffer.append(str); } else if (str.length() > remaining) { buffer.append(str, 0, remaining).append(TRUNCATED_OUTPUT); remaining = -2; } else { buffer.append(str); remaining -= str.length(); } return remaining; } }