Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
37 changes: 19 additions & 18 deletions client-v2/src/main/java/com/clickhouse/client/api/Client.java
Original file line number Diff line number Diff line change
Expand Up @@ -221,7 +221,6 @@ private Client(Collection<Endpoint> endpoints, Map<String,String> configuration,
if (httpEndpoint.isSecure()) {
initSslContext = true;
}
LOG.debug("Adding endpoint: {}", httpEndpoint);
tmpEndpoints.add(httpEndpoint);
} else {
throw new ClientException("Unsupported endpoint type: " + ep.getClass().getName());
Expand Down Expand Up @@ -290,7 +289,7 @@ public void close() {
this.sharedOperationExecutor.shutdownNow();
}
} catch (Exception e) {
LOG.error("Failed to close shared operation executor", e);
LOG.warn("Failed to close shared operation executor", e);
}
} else {
LOG.debug("Skip closing operation executor because not owned by client");
Expand Down Expand Up @@ -1498,7 +1497,9 @@ public boolean ping(long timeout) {
return true;
}
} catch (Exception e) {
LOG.debug("Failed to connect to the server (Duration: {})", durationSince(startTime), e);
// The exception message can carry the endpoint or a server message: log only its type.
LOG.debug("Ping failed after {} ms: {}", durationSince(startTime).toMillis(),
ClientUtils.rootCauseClassName(e));
return false;
}
}
Expand Down Expand Up @@ -1658,14 +1659,15 @@ public CompletableFuture<InsertResponse> insert(String tableName, List<?> data,

spanRecorder.recordInsertSuccess(operationSpan, metrics);
metricsRecorder.recordInsertSuccess(requestSettings, tableName, metrics);
logRecoveredRetries("Insert", i, lastException);
return new InsertResponse(transportResponse, metrics);
} catch (Exception e) {
String msg = requestExMsg("Insert", (i + 1), durationSince(startTime).toMillis(), requestSettings.getQueryId());
lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId());
if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(queryId)) {
if (i < maxAttempts) {
metricsRecorder.recordInsertRetry(requestSettings, tableName, lastException);
selectedEndpoint = logRetryAndSelectNextNode("Insert", i, maxAttempts, requestSettings.getQueryId(), selectedEndpoint, e);
selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint);
} else {
nodeSelector.getNextAliveNode(selectedEndpoint);
}
Expand All @@ -1676,7 +1678,6 @@ public CompletableFuture<InsertResponse> insert(String tableName, List<?> data,
}

String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId());
LOG.warn(errMsg);
throw (lastException == null ? new ClientException(errMsg) : lastException);
} catch (RuntimeException | Error e) {
// Taken before any recorder runs, like the duration of a successful operation, which the
Expand Down Expand Up @@ -1884,14 +1885,15 @@ public CompletableFuture<InsertResponse> insert(String tableName,
requestSettings.getQueryId(), OperationType.INSERT);
spanRecorder.recordInsertSuccess(operationSpan, metrics);
metricsRecorder.recordInsertSuccess(requestSettings, tableName, metrics);
logRecoveredRetries("Insert", i, lastException);
return new InsertResponse(transportResponse, metrics);
} catch (Exception e) {
String msg = requestExMsg("Insert", (i + 1), durationSince(startTime).toMillis(), requestSettings.getQueryId());
lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId());
if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(requestSettings.getQueryId())) {
if (i < maxAttempts) {
metricsRecorder.recordInsertRetry(requestSettings, tableName, lastException);
selectedEndpoint = logRetryAndSelectNextNode("Insert (stream)", i, maxAttempts, requestSettings.getQueryId(), selectedEndpoint, e);
selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint);
} else {
nodeSelector.getNextAliveNode(selectedEndpoint);
}
Expand All @@ -1910,7 +1912,6 @@ public CompletableFuture<InsertResponse> insert(String tableName,
}

String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId());
LOG.warn(errMsg);
throw (lastException == null ? new ClientException(errMsg) : lastException);
} catch (RuntimeException | Error e) {
// Taken before any recorder runs, like the duration of a successful operation, which the
Expand Down Expand Up @@ -2042,6 +2043,7 @@ public CompletableFuture<QueryResponse> query(String sqlQuery, Map<String, Objec

spanRecorder.recordQuerySuccess(operationSpan, metrics);
metricsRecorder.recordQuerySuccess(requestSettings, metrics);
logRecoveredRetries("Query", i, lastException);
return new QueryResponse(transportResp, responseFormat, requestSettings, metrics);

} catch (Exception e) {
Expand All @@ -2051,7 +2053,7 @@ public CompletableFuture<QueryResponse> query(String sqlQuery, Map<String, Objec
if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(requestSettings.getQueryId())) {
if (i < maxAttempts) {
metricsRecorder.recordQueryRetry(requestSettings, lastException);
selectedEndpoint = logRetryAndSelectNextNode("Query", i, maxAttempts, requestSettings.getQueryId(), selectedEndpoint, e);
selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint);
} else {
nodeSelector.getNextAliveNode(selectedEndpoint);
}
Expand All @@ -2062,7 +2064,6 @@ public CompletableFuture<QueryResponse> query(String sqlQuery, Map<String, Objec
}

String errMsg = requestExMsg("Query", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId());
LOG.warn(errMsg);
throw (lastException == null ? new ClientException(errMsg) : lastException);
} catch (RuntimeException | Error e) {
// Taken before any recorder runs, like the duration of a successful operation, which the
Expand All @@ -2082,16 +2083,16 @@ public CompletableFuture<QueryResponse> query(String sqlQuery, Map<String, Objec
}

/**
* Logs a single consolidated warning for a failed but retryable request attempt and returns
* the next endpoint to try. Keeping this in one place ensures a retry is logged exactly once
* with a consistent shape across the insert and query paths.
* Logs one warning for an operation that succeeded after retries. Individual attempts are not logged, so that
* a retried operation produces at most one message. The message names only the operation, the retry count and
* the type of the last retried failure: endpoints, query IDs and exception messages can carry topology or
* application data, and the metrics and spans already record each attempt.
*/
private Endpoint logRetryAndSelectNextNode(String operation, int attemptIndex, int maxAttempts,
String queryId, Endpoint endpoint, Exception cause) {
LOG.warn("{} failed (attempt {} of {}, queryId: {}), endpoint: {}, cause: {}: {}. Retrying.",
operation, attemptIndex + 1, maxAttempts + 1, queryId, endpoint,
cause.getClass().getName(), cause.getMessage());
return nodeSelector.getNextAliveNode(endpoint);
private static void logRecoveredRetries(String operation, int retries, Throwable lastFailure) {
if (retries > 0 && LOG.isWarnEnabled()) {
LOG.warn("{} succeeded after {} {}; last retried failure: {}", operation, retries,
retries == 1 ? "retry" : "retries", ClientUtils.rootCauseClassName(lastFailure));
}
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -303,7 +303,6 @@ private <T> T readValue(ClickHouseColumn column, Class<?> typeHint, boolean stri
} catch (EOFException e) {
throw e;
} catch (Exception e) {
log.debug("Failed to read value for column {}, {}", column.getColumnName(), e.getLocalizedMessage());
throw new ClientException("Failed to read value for column " + column.getColumnName(), e);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,7 @@ public static Map<String, Long> parse(String json) {
long value = Long.parseLong(valueStr);
result.put(key, value);
} catch (NumberFormatException e) {
LOG.debug("Skipping summary field '" + key + "' with non-numeric value '" + valueStr + "'", e);
LOG.debug("Skipping summary field '{}' with a non-numeric value", key);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

move to trace level. This minor problem.

}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@ public final class ClientUtils {

private static final int DEFAULT_CAUSE_SEARCH_DEPTH = 3;

private static final int ROOT_CAUSE_SEARCH_DEPTH = 16;

private ClientUtils() {}

public static boolean isNotBlank(String str) {
Expand All @@ -28,7 +30,8 @@ public static void quietClose(Closeable closeable, Logger log) {
try {
closeable.close();
} catch (Exception e) {
log.warn("Failed to close object " + closeable, e);
// The type, not toString(): a closeable can describe a request or a response.
log.debug("Failed to close object of type {}", closeable.getClass().getName(), e);
}
}
}
Expand Down Expand Up @@ -94,4 +97,23 @@ public static <T extends Throwable> T findCause(Throwable throwable, Class<T> ty
}
return null;
}

/**
* Returns the class name of the deepest cause of {@code throwable}, following up to 16 causes. Use it to log a
* failure without its message: a message can carry SQL, values, endpoints or a server response.
*
* @param throwable - exception to start from, can be {@code null}
* @return class name of the deepest cause, or {@code "none"} if {@code throwable} is {@code null}
*/
public static String rootCauseClassName(Throwable throwable) {
if (throwable == null) {
return "none";
}
Throwable current = throwable;
for (int depth = 0; depth < ROOT_CAUSE_SEARCH_DEPTH && current.getCause() != null
&& current.getCause() != current; depth++) {
current = current.getCause();
}
return current.getClass().getName();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,6 @@
import com.clickhouse.data.ClickHouseUtils;
import com.github.luben.zstd.Zstd;
import net.jpountz.lz4.LZ4FastDecompressor;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.io.EOFException;
import java.io.IOException;
Expand All @@ -16,7 +14,6 @@

public class CompressedBlockInputStream extends InputStream {

private static final Logger LOG = LoggerFactory.getLogger(CompressedBlockInputStream.class);
private final LZ4FastDecompressor decompressor;

private final InputStream in;
Expand All @@ -25,10 +22,8 @@ public class CompressedBlockInputStream extends InputStream {

private final byte[] tmpBuffer = new byte[1];


public CompressedBlockInputStream(InputStream in, LZ4FastDecompressor decompressor, int bufferSize) {
super();
LOG.debug("Using decompressor with buffer size {}", bufferSize);
this.decompressor = decompressor;
this.in = in;
this.buffer = ByteBuffer.allocate(bufferSize);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3,16 +3,13 @@
import com.clickhouse.data.ClickHouseCityHash;
import com.github.luben.zstd.Zstd;
import net.jpountz.lz4.LZ4Compressor;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.io.IOException;
import java.io.OutputStream;
import java.nio.ByteBuffer;

public abstract class CompressedBlockOutputStream extends OutputStream {

private static final Logger LOG = LoggerFactory.getLogger(CompressedBlockOutputStream.class);
public static final int UNCOMPRESSED_BUFF_SIZE = 64 * 1024; // 64K is most optimal for LZ4 compression

private final ByteBuffer inBuffer;
Expand All @@ -23,7 +20,6 @@ public abstract class CompressedBlockOutputStream extends OutputStream {

public CompressedBlockOutputStream(OutputStream out, int bufferSize) {
super();
LOG.debug("Using compressor with buffer size {}", bufferSize);
this.inBuffer = ByteBuffer.allocate(bufferSize);
this.out = out;
this.compressedBuffer = ByteBuffer.allocate(bufferSize + CompressedBlockInputStream.HEADER_LENGTH);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ public static String getLocalhostNameOrAddress(final boolean returnAddress) {
}
}
} catch (Exception e) {
LOG.error("Failed to get local host name or address", e);
LOG.warn("Failed to get local host name or address: {}", ClientUtils.rootCauseClassName(e));

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do not do like this. We need to have stacktrace for exception like before. Just exception class name is useless. keep log warn but also preserve exception stack in log - here is should be very short

}
return "";
}
Expand Down
Loading