From c01d6dddf39d6d92842b3efbcddcedbcff750e62 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Tue, 28 Jul 2026 23:51:19 +0000 Subject: [PATCH 1/8] feat(client-v2,jdbc-v2): improve logging coverage on error/diagnostic paths Implements https://github.com/ClickHouse/clickhouse-java/issues/2969. Adds missing log statements and enriches existing ones so errors and key operational events are observable, without changing functional behavior or public API: client-v2: - executeRequest: log every non-2xx response once at WARN (status, query id, authority, X-ClickHouse-Exception-Code; never the body) before throwing - retry loops: include attempt #, endpoint being tried and query id; attach the last exception to the exhaustion log - startup: one INFO line summarising the resolved transport config (no secrets) - ProcessParser / user-agent version read: previously-silent catches -> DEBUG jdbc-v2: - PreparedStatement metadata fallback: log the cause, not the raw SQL - onNetworkTimeout: log the abort failure instead of losing it in the executor - writer reset/close and written-rows lookup: silent catches -> DEBUG Tests: HttpAPIClientHelperTest (server-error WARN content, success stays quiet, startup INFO present + no password), ProcessParserTest (non-numeric skip), JDBCErrorHandlingTests (metadata fallback returns untyped columns + cause logged). --- CHANGELOG.md | 14 ++ .../com/clickhouse/client/api/Client.java | 15 ++- .../data_formats/internal/ProcessParser.java | 8 +- .../api/internal/HttpAPIClientHelper.java | 71 +++++++++- .../internal/ProcessParserTest.java | 42 ++++++ .../api/internal/HttpAPIClientHelperTest.java | 127 ++++++++++++++++++ .../com/clickhouse/jdbc/ConnectionImpl.java | 4 +- .../jdbc/PreparedStatementImpl.java | 5 +- .../com/clickhouse/jdbc/StatementImpl.java | 3 +- .../clickhouse/jdbc/WriterStatementImpl.java | 8 +- .../jdbc/JDBCErrorHandlingTests.java | 35 +++++ 11 files changed, 316 insertions(+), 16 deletions(-) create mode 100644 client-v2/src/test/java/com/clickhouse/client/api/data_formats/internal/ProcessParserTest.java diff --git a/CHANGELOG.md b/CHANGELOG.md index ca4088730..a15240693 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,6 +16,20 @@ and the comma-separated `ssl_cipher_suites` connection property (client-v2 and jdbc-v2) restrict the cipher suites enabled on secure connections; when unset, the transport defaults are used. Cipher-suite selection is independent of the trust configuration and `ssl_mode`. (https://github.com/ClickHouse/clickhouse-java/issues/2882) +- **[client-v2, jdbc-v2]** Improved logging coverage on the error and diagnostic paths so failures are + observable in support cases, without changing any functional behavior or public API. In `client-v2`: + every non-2xx server response is now logged once at `WARN` before the exception is thrown — with the + status code, query id, target authority and the `X-ClickHouse-Exception-Code` header (the response body + is never logged) — so an error that is retried away and never surfaced to the caller is still diagnosable; + the per-attempt retry logs now include the attempt number, the endpoint being tried and the query id, and + the retry-exhaustion log now attaches the last exception; a single `INFO` line summarising the resolved + transport configuration (auth mode, SSL mode, proxy, connection-pool sizing, compression and LZ4 factory — + no secrets) is emitted at client startup; and previously-silent diagnostic `catch` blocks (summary-metric + parsing, HTTP-client version detection) now log at `DEBUG` with the exception attached. In `jdbc-v2`: the + prepared-statement metadata fallback now logs the underlying cause instead of the raw SQL, a connection-abort + failure during a network timeout is logged (instead of being silently swallowed by the executor), and + several previously-silent `catch` blocks (writer reset/close, written-rows lookup) now log at `DEBUG` with + the exception attached. (https://github.com/ClickHouse/clickhouse-java/issues/2969) ### Bug Fixes diff --git a/client-v2/src/main/java/com/clickhouse/client/api/Client.java b/client-v2/src/main/java/com/clickhouse/client/api/Client.java index c8fd9eee0..db5afa60e 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/Client.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/Client.java @@ -1499,8 +1499,9 @@ public CompletableFuture insert(String tableName, List data, lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId()); if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(queryId)) { if (i < maxAttempts) { - LOG.warn("Retrying.", e); selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); + LOG.warn("Insert attempt {}/{} failed (queryId: {}); retrying on endpoint {}", + i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1513,7 +1514,7 @@ public CompletableFuture insert(String tableName, List data, } String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId()); - LOG.warn(errMsg); + LOG.warn(errMsg, lastException); throw (lastException == null ? new ClientException(errMsg) : lastException); }; @@ -1705,8 +1706,9 @@ public CompletableFuture insert(String tableName, lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId()); if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(requestSettings.getQueryId())) { if (i < maxAttempts) { - LOG.warn("Retrying.", e); selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); + LOG.warn("Insert attempt {}/{} failed (queryId: {}); retrying on endpoint {}", + i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1732,7 +1734,7 @@ public CompletableFuture insert(String tableName, } String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId()); - LOG.warn(errMsg); + LOG.warn(errMsg, lastException); throw (lastException == null ? new ClientException(errMsg) : lastException); }; @@ -1849,8 +1851,9 @@ public CompletableFuture query(String sqlQuery, Map query(String sqlQuery, Map parse(String json) { long value = Long.parseLong(valueStr); result.put(key, value); } catch (NumberFormatException e) { - // ignore error + // Unknown/non-numeric summary fields are skipped; keep going so the rest still parse. + LOG.debug("Skipping summary field '{}' with non-numeric value '{}'", key, valueStr, e); } } diff --git a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java index b9650f134..21b49644f 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java @@ -157,6 +157,44 @@ public HttpAPIClientHelper(Map configuration, Object metricsRegi } this.defaultUserAgent = buildDefaultUserAgent(); + + logTransportConfigSummary(configuration, lz4Factory); + } + + /** + * Emits a single INFO line at client startup summarising the resolved transport configuration. + * Only non-sensitive settings are included - no passwords, tokens or proxy credentials. + */ + private void logTransportConfigSummary(Map configuration, LZ4Factory lz4Factory) { + if (!LOG.isInfoEnabled()) { + return; + } + + final String authMode; + if (ClientConfigProperties.SSL_AUTH.getOrDefault(configuration)) { + authMode = "SSL_CLIENT_CERT"; + } else if (ClientConfigProperties.HTTP_USE_BASIC_AUTH.getOrDefault(configuration)) { + authMode = "HTTP_BASIC"; + } else { + authMode = "DEFAULT_HEADERS"; + } + + final String proxyType = (String) configuration.get(ClientConfigProperties.PROXY_TYPE.getKey()); + final String proxySummary = proxyType == null ? "none" + : proxyType + " " + configuration.get(ClientConfigProperties.PROXY_HOST.getKey()) + + ":" + configuration.get(ClientConfigProperties.PROXY_PORT.getKey()); + + LOG.info("client-v2 transport configured: authMode={}, sslMode={}, proxy={}, connectionPool={}," + + " maxConnectionsPerRoute={}, compression=[client={}, server={}, http={}], lz4Factory={}", + authMode, + ClientConfigProperties.SSL_MODE.getOrDefault(configuration), + proxySummary, + ClientConfigProperties.CONNECTION_POOL_ENABLED.getOrDefault(configuration), + configuration.getOrDefault(ClientConfigProperties.HTTP_MAX_OPEN_CONNECTIONS.getKey(), "default"), + ClientConfigProperties.COMPRESS_CLIENT_REQUEST.getOrDefault(configuration), + ClientConfigProperties.COMPRESS_SERVER_RESPONSE.getOrDefault(configuration), + ClientConfigProperties.USE_HTTP_COMPRESSION.getOrDefault(configuration), + lz4Factory); } /** @@ -704,14 +742,21 @@ public TransportResponse executeRequest(TransportRequest transportRequest) throw requestConfig)); if (httpResponse.containsHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)) { + logServerErrorResponse(req, httpResponse); throw readError(req, httpResponse); } int statusCode = httpResponse.getCode(); + if (statusCode == HttpStatus.SC_OK) { + closeResponse = false; + return new TransportResponseImpl(httpResponse); + } + + // Any non-2xx response is an error that is about to be thrown. Log it once with enough + // context (status, query id, authority, server exception code) to diagnose it, since the + // thrown exception may be retried away and never surface to the caller. + logServerErrorResponse(req, httpResponse); switch (statusCode) { - case HttpStatus.SC_OK: - closeResponse = false; - return new TransportResponseImpl(httpResponse); case HttpStatus.SC_PROXY_AUTHENTICATION_REQUIRED: throw new ClientMisconfigurationException("Proxy authentication required. Please check your proxy settings."); case HttpStatus.SC_BAD_GATEWAY: @@ -772,6 +817,24 @@ private String getQueryId(HttpResponse httpResponse, HttpPost httpRequest) { return queryHeader == null ? "" : queryHeader.getValue(); } + /** + * Logs an error server response at WARN with enough context to diagnose it. The response body is + * intentionally not logged: it is consumed by {@link #readError} and may contain SQL/data, so only + * the status, query id, target authority and the server exception-code header are emitted. + */ + private void logServerErrorResponse(HttpPost req, ClassicHttpResponse httpResponse) { + if (!LOG.isWarnEnabled()) { + return; + } + final Header exceptionCodeHeader = httpResponse.getFirstHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE); + LOG.warn("Server returned error response: status={}, queryId='{}', authority='{}', {}={}", + httpResponse.getCode(), + getQueryId(httpResponse, req), + req.getAuthority(), + ClickHouseHttpProto.HEADER_EXCEPTION_CODE, + exceptionCodeHeader == null ? "" : exceptionCodeHeader.getValue()); + } + private static final ContentType CONTENT_TYPE = ContentType.create(ContentType.TEXT_PLAIN.getMimeType(), "UTF-8"); private void addHeaders(HttpPost req, Map requestConfig) { @@ -1116,7 +1179,7 @@ private String buildDefaultUserAgent() { httpClientVersion = tmp; } } catch (Exception e) { - // ignore + LOG.debug("Failed to read HTTP client version from client-v2-version.properties", e); } } userAgent.append(" ") diff --git a/client-v2/src/test/java/com/clickhouse/client/api/data_formats/internal/ProcessParserTest.java b/client-v2/src/test/java/com/clickhouse/client/api/data_formats/internal/ProcessParserTest.java new file mode 100644 index 000000000..a8ad07691 --- /dev/null +++ b/client-v2/src/test/java/com/clickhouse/client/api/data_formats/internal/ProcessParserTest.java @@ -0,0 +1,42 @@ +package com.clickhouse.client.api.data_formats.internal; + +import org.testng.annotations.Test; + +import java.util.Map; + +import static org.testng.Assert.assertEquals; +import static org.testng.Assert.assertFalse; +import static org.testng.Assert.assertTrue; + +public class ProcessParserTest { + + /** + * A non-numeric summary value must be skipped (and logged at DEBUG) while the remaining numeric + * fields still parse: a single malformed field must not drop the rest of the summary. + */ + @Test + public void testParseSkipsNonNumericValuesAndKeepsTheRest() { + Map parsed = ProcessParser.parse( + "{\"read_rows\":\"100\",\"bogus\":\"not_a_number\",\"read_bytes\":\"2048\"}"); + + assertEquals(parsed.get("read_rows"), Long.valueOf(100L), + "a numeric field before the bad one must parse"); + assertEquals(parsed.get("read_bytes"), Long.valueOf(2048L), + "a numeric field after the bad one must still parse"); + assertFalse(parsed.containsKey("bogus"), + "the non-numeric field must be skipped, not stored"); + } + + @Test + public void testParseReadsAllNumericFields() { + Map parsed = ProcessParser.parse("{\"read_rows\":\"7\",\"written_rows\":\"3\"}"); + assertEquals(parsed.get("read_rows"), Long.valueOf(7L)); + assertEquals(parsed.get("written_rows"), Long.valueOf(3L)); + } + + @Test + public void testParseEmptyObjectReturnsEmptyMap() { + assertTrue(ProcessParser.parse("{}").isEmpty(), + "an empty summary object must yield an empty map"); + } +} diff --git a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java index 74be3be5d..5029b240d 100644 --- a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java +++ b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java @@ -2,6 +2,7 @@ import com.clickhouse.client.api.ClientConfigProperties; import com.clickhouse.client.api.enums.SSLMode; +import com.clickhouse.client.api.http.ClickHouseHttpProto; import com.clickhouse.client.api.internal.HttpAPIClientHelper.CustomSSLConnectionFactory; import com.clickhouse.client.api.transport.Endpoint; import com.clickhouse.client.api.transport.HttpEndpoint; @@ -11,6 +12,7 @@ import org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory; import org.apache.hc.core5.http.ClassicHttpResponse; import org.apache.hc.core5.http.HttpEntity; +import org.apache.hc.core5.http.message.BasicHeader; import org.mockito.ArgumentCaptor; import org.mockito.MockedConstruction; import org.testng.Assert; @@ -21,6 +23,9 @@ import javax.net.ssl.SSLContext; import javax.net.ssl.SSLParameters; import javax.net.ssl.SSLSocket; +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.io.UnsupportedEncodingException; import java.lang.reflect.Field; import java.net.ConnectException; import java.util.ArrayList; @@ -37,8 +42,10 @@ import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; import static org.testng.Assert.assertEquals; +import static org.testng.Assert.assertFalse; import static org.testng.Assert.assertNotNull; import static org.testng.Assert.assertNull; +import static org.testng.Assert.assertTrue; public class HttpAPIClientHelperTest { @@ -287,6 +294,126 @@ public void testExecuteRequestThrowsConnectExceptionOn503() throws Exception { } } + /** + * A server error response must be logged once at WARN before the exception is thrown, carrying the + * status code, query id and the server exception-code header - so a failure that is retried away (and + * never surfaced to the caller) is still diagnosable. The response body is intentionally never logged. + */ + @Test + public void testExecuteRequestLogsServerErrorResponse() throws Exception { + HttpAPIClientHelper helper = new HttpAPIClientHelper(new HashMap<>(), null, false, LZ4Factory.fastestInstance()); + injectMockHttpClient(helper, mockErrorResponse(404, "241")); + + Map reqConfig = new HashMap<>(); + reqConfig.put(ClientConfigProperties.QUERY_ID.getKey(), "qid-log-test"); + Endpoint endpoint = new HttpEndpoint("localhost", 8123, false, "/"); + + String logged = captureStdErr(() -> { + try { + helper.executeRequest(helper.createRequest(endpoint, reqConfig, "SELECT 1")).close(); + } catch (Exception expected) { + // the server error is rethrown to the caller; we assert on what was logged before that + } + }); + + assertTrue(logged.contains("Server returned error response"), + "a server error must be logged at WARN: " + logged); + assertTrue(logged.contains("404"), "the HTTP status code must be logged: " + logged); + assertTrue(logged.contains("qid-log-test"), "the query id must be logged: " + logged); + assertTrue(logged.contains("241"), "the server exception-code header value must be logged: " + logged); + } + + /** + * Contrast case: a successful (200) response must NOT emit the server-error WARN, so normal traffic + * stays quiet and only genuine error responses are logged. + */ + @Test + public void testExecuteRequestSuccessDoesNotLogServerError() throws Exception { + HttpAPIClientHelper helper = new HttpAPIClientHelper(new HashMap<>(), null, false, LZ4Factory.fastestInstance()); + ClassicHttpResponse ok = mock(ClassicHttpResponse.class); + when(ok.getCode()).thenReturn(200); + when(ok.getEntity()).thenReturn(mock(HttpEntity.class)); + injectMockHttpClient(helper, ok); + + Endpoint endpoint = new HttpEndpoint("localhost", 8123, false, "/"); + String logged = captureStdErr(() -> { + try { + helper.executeRequest(helper.createRequest(endpoint, new HashMap<>(), "SELECT 1")).close(); + } catch (Exception e) { + // not expected for a 200 response + } + }); + + assertFalse(logged.contains("Server returned error response"), + "a successful response must not be logged as a server error: " + logged); + } + + /** + * A single transport-configuration summary is emitted at INFO on startup and must never contain + * secrets (passwords, tokens, proxy credentials). + */ + @Test + public void testStartupLogsTransportConfigSummaryWithoutSecrets() { + Map config = new HashMap<>(); + config.put(ClientConfigProperties.PASSWORD.getKey(), "s3cr3t-pw"); + + String logged = captureStdErr(() -> + new HttpAPIClientHelper(config, null, false, LZ4Factory.fastestInstance())); + + assertTrue(logged.contains("client-v2 transport configured"), + "a transport-config summary must be logged at startup: " + logged); + assertTrue(logged.contains("authMode=") && logged.contains("sslMode=") && logged.contains("lz4Factory="), + "the summary must include the resolved transport fields: " + logged); + assertFalse(logged.contains("s3cr3t-pw"), + "the transport-config summary must not leak the password: " + logged); + } + + private static ClassicHttpResponse mockErrorResponse(int statusCode, String serverExceptionCode) { + ClassicHttpResponse response = mock(ClassicHttpResponse.class); + when(response.getCode()).thenReturn(statusCode); + when(response.containsHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)).thenReturn(true); + when(response.getFirstHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)) + .thenReturn(new BasicHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE, serverExceptionCode)); + when(response.getEntity()).thenReturn(mock(HttpEntity.class)); + return response; + } + + private static void injectMockHttpClient(HttpAPIClientHelper helper, ClassicHttpResponse response) throws Exception { + CloseableHttpClient mockHttpClient = mock(CloseableHttpClient.class); + when(mockHttpClient.executeOpen(any(), any(), any())).thenReturn(response); + Field httpClientField = HttpAPIClientHelper.class.getDeclaredField("httpClient"); + httpClientField.setAccessible(true); + httpClientField.set(helper, mockHttpClient); + } + + /** + * Captures everything written to {@code System.err} (the slf4j-simple target) while {@code action} + * runs. slf4j-simple resolves {@code System.err} dynamically per log call, so the temporary swap + * reliably captures WARN/INFO output emitted during the action. + */ + private static String captureStdErr(Runnable action) { + PrintStream original = System.err; + ByteArrayOutputStream buf = new ByteArrayOutputStream(); + PrintStream capture; + try { + capture = new PrintStream(buf, true, "UTF-8"); + } catch (UnsupportedEncodingException e) { + throw new RuntimeException(e); + } + System.setErr(capture); + try { + action.run(); + } finally { + capture.flush(); + System.setErr(original); + } + try { + return buf.toString("UTF-8"); + } catch (UnsupportedEncodingException e) { + throw new RuntimeException(e); + } + } + /** * Builds an {@link HttpAPIClientHelper} and invokes {@link HttpAPIClientHelper#createHttpClient} with SSL * enabled while intercepting every {@link CustomSSLConnectionFactory} construction, returning the diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java index 791ee0f49..1f390bde1 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java @@ -695,7 +695,9 @@ public synchronized void onNetworkTimeout() { try { this.abort(networkTimeoutExecutor); } catch (SQLException e) { - throw new RuntimeException("Failed to abort connection", e); + // Runs on the executor thread: a rethrown exception would be swallowed by the executor, + // so log it here to keep the abort failure observable. + LOG.error("Failed to abort connection on network timeout", e); } }); } diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java index 4a93f5bbb..aeb7bf4ca 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java @@ -417,7 +417,10 @@ public ResultSetMetaData getMetaData() throws SQLException { connection.getSchema(), connection.getCatalog(), tSchema.getTableName(), JdbcUtils.DATA_TYPE_CLASS_MAP, connection.getTypeMap()); } catch (Exception e) { - LOG.warn("Failed to get schema for statement '{}'", originalSql); + // Do not log the raw SQL (it may carry sensitive literals); the cause is enough to + // diagnose why metadata could not be resolved before falling back to untyped columns. + LOG.warn("Failed to resolve result-set metadata for prepared statement; " + + "falling back to untyped metadata", e); } } diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java index 9bb3db82e..e7ba96b08 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java @@ -199,8 +199,9 @@ protected ResultSetImpl executeQueryImpl(String sql, QuerySettings settings) thr long writtenRows = 0L; try { writtenRows = response.getWrittenRows(); - } catch (Exception ignore) { + } catch (Exception e) { // Best effort: leave writtenRows as 0 if we can't obtain it. + LOG.debug("Failed to read written-rows count from response; defaulting to 0", e); } this.currentUpdateCount = (int) Math.min(writtenRows, Integer.MAX_VALUE); try { diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/WriterStatementImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/WriterStatementImpl.java index cbe1d1982..a01944f5d 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/WriterStatementImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/WriterStatementImpl.java @@ -37,6 +37,9 @@ import java.util.List; import java.util.concurrent.TimeUnit; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + /** * Implements data streaming through Client Writer API. * See {@link PreparedStatementImpl} @@ -44,6 +47,7 @@ */ public class WriterStatementImpl extends PreparedStatementImpl implements PreparedStatement { + private static final Logger LOG = LoggerFactory.getLogger(WriterStatementImpl.class); private ByteArrayOutputStream out; private ClickHouseBinaryFormatWriter writer; @@ -131,7 +135,7 @@ public long executeLargeUpdate() throws SQLException { try { resetWriter(); } catch (Exception e) { - // ignore + LOG.debug("Failed to reset writer after insert", e); } } return updateCount; @@ -456,7 +460,7 @@ public void close() throws SQLException { } writer = null; } catch (Exception e) { - // ignore + LOG.debug("Failed to close writer output stream", e); } } diff --git a/jdbc-v2/src/test/java/com/clickhouse/jdbc/JDBCErrorHandlingTests.java b/jdbc-v2/src/test/java/com/clickhouse/jdbc/JDBCErrorHandlingTests.java index 64282d0bf..b7bae4a66 100644 --- a/jdbc-v2/src/test/java/com/clickhouse/jdbc/JDBCErrorHandlingTests.java +++ b/jdbc-v2/src/test/java/com/clickhouse/jdbc/JDBCErrorHandlingTests.java @@ -5,7 +5,11 @@ import org.testng.Assert; import org.testng.annotations.Test; +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; import java.sql.Connection; +import java.sql.PreparedStatement; +import java.sql.ResultSetMetaData; import java.sql.SQLException; import java.sql.Statement; import java.util.Properties; @@ -48,4 +52,35 @@ public void testQueryIDPropagatedToException() throws Exception { Assert.assertEquals(queryIds.size(), requests); } + + /** + * When result-set metadata cannot be resolved because the DESCRIBE fails (here: an unknown table), + * {@code getMetaData()} must fall back to untyped metadata instead of throwing, and the failure must + * be logged at WARN with the exception cause attached (the previous log dropped the cause). + */ + @Test(groups = {"integration"}) + public void testPreparedStatementMetadataFallbackLogsCause() throws Exception { + String sql = "SELECT c FROM nonexistent_table_for_metadata_logging WHERE id = ?"; + + PrintStream original = System.err; + ByteArrayOutputStream buf = new ByteArrayOutputStream(); + ResultSetMetaData md; + System.setErr(new PrintStream(buf, true, "UTF-8")); + try (Connection conn = getJdbcConnection(); + PreparedStatement ps = conn.prepareStatement(sql)) { + md = ps.getMetaData(); + } finally { + System.setErr(original); + } + String logged = buf.toString("UTF-8"); + + // The fallback returns metadata rather than throwing or returning null. + Assert.assertNotNull(md, "metadata must fall back to untyped columns, not be null"); + + // The fallback is logged at WARN and now carries the exception cause (the old log omitted it). + Assert.assertTrue(logged.contains("Failed to resolve result-set metadata"), + "the metadata fallback must be logged at WARN: " + logged); + Assert.assertTrue(logged.contains("Exception"), + "the exception cause must be attached to the log: " + logged); + } } From f79801a0a6f9a1b57496c6fdecd469c0c2182627 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 00:21:49 +0000 Subject: [PATCH 2/8] fix(client-v2): clear SonarCloud reliability/maintainability findings on new logging code Resolves the SonarCloud Quality Gate failure on PR #2969's changes (Reliability Rating C on New Code): - logServerErrorResponse (java:S2259, RELIABILITY): guard against a null req/httpResponse so this error-path logger can never itself throw an NPE and mask the real server error it is trying to report. req flows through the null-tolerant getQueryId helper, so the analyzer (correctly) treats it as nullable at the subsequent getAuthority() deref. - logTransportConfigSummary (java:S5411 x2, MAINTAINABILITY): unbox the Boolean config values with .booleanValue() in the auth-mode conditionals, matching the existing idiom already used elsewhere in this file. No functional or public-API change; client-v2 unit tests (19) still pass. --- .../client/api/internal/HttpAPIClientHelper.java | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java index 21b49644f..1275fa652 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java @@ -171,9 +171,9 @@ private void logTransportConfigSummary(Map configuration, LZ4Fac } final String authMode; - if (ClientConfigProperties.SSL_AUTH.getOrDefault(configuration)) { + if (ClientConfigProperties.SSL_AUTH.getOrDefault(configuration).booleanValue()) { authMode = "SSL_CLIENT_CERT"; - } else if (ClientConfigProperties.HTTP_USE_BASIC_AUTH.getOrDefault(configuration)) { + } else if (ClientConfigProperties.HTTP_USE_BASIC_AUTH.getOrDefault(configuration).booleanValue()) { authMode = "HTTP_BASIC"; } else { authMode = "DEFAULT_HEADERS"; @@ -823,7 +823,9 @@ private String getQueryId(HttpResponse httpResponse, HttpPost httpRequest) { * the status, query id, target authority and the server exception-code header are emitted. */ private void logServerErrorResponse(HttpPost req, ClassicHttpResponse httpResponse) { - if (!LOG.isWarnEnabled()) { + // The logger itself must never throw on the error path and mask the real failure, so skip + // logging (rather than risk an NPE) if the level is off or either argument is unexpectedly null. + if (!LOG.isWarnEnabled() || req == null || httpResponse == null) { return; } final Header exceptionCodeHeader = httpResponse.getFirstHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE); From 2f6e164955152d54340c38013b9945bf0ab3b101 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 05:40:33 +0000 Subject: [PATCH 3/8] Address review (@chernser): scope error logging, restore switch + rethrow MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - HttpAPIClientHelper: remove the startup transport-config INFO summary (logTransportConfigSummary) — deferred to a separate "log the whole configuration in Client" story per review. - HttpAPIClientHelper.executeRequest: restore main's switch structure (SC_OK back as a case in the switch) and log a server error only for an unknown/unexpected status code (the switch default) — no longer on every non-2xx path nor on responses carrying the exception-code header (which readError already surfaces). - ConnectionImpl.onNetworkTimeout: rethrow the RuntimeException after logging so a ThreadFactory-configured UncaughtExceptionHandler still sees the abort failure. - Tests: replace the three added logging tests with one parametrized @DataProvider test pinning "only an unknown status code emits a WARN". - CHANGELOG: reflect the narrowed logging behavior. --- CHANGELOG.md | 23 +++-- .../api/internal/HttpAPIClientHelper.java | 56 ++--------- .../api/internal/HttpAPIClientHelperTest.java | 97 +++++++------------ .../com/clickhouse/jdbc/ConnectionImpl.java | 6 +- 4 files changed, 60 insertions(+), 122 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a15240693..c667ff2e7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,18 +18,17 @@ trust configuration and `ssl_mode`. (https://github.com/ClickHouse/clickhouse-java/issues/2882) - **[client-v2, jdbc-v2]** Improved logging coverage on the error and diagnostic paths so failures are observable in support cases, without changing any functional behavior or public API. In `client-v2`: - every non-2xx server response is now logged once at `WARN` before the exception is thrown — with the - status code, query id, target authority and the `X-ClickHouse-Exception-Code` header (the response body - is never logged) — so an error that is retried away and never surfaced to the caller is still diagnosable; - the per-attempt retry logs now include the attempt number, the endpoint being tried and the query id, and - the retry-exhaustion log now attaches the last exception; a single `INFO` line summarising the resolved - transport configuration (auth mode, SSL mode, proxy, connection-pool sizing, compression and LZ4 factory — - no secrets) is emitted at client startup; and previously-silent diagnostic `catch` blocks (summary-metric - parsing, HTTP-client version detection) now log at `DEBUG` with the exception attached. In `jdbc-v2`: the - prepared-statement metadata fallback now logs the underlying cause instead of the raw SQL, a connection-abort - failure during a network timeout is logged (instead of being silently swallowed by the executor), and - several previously-silent `catch` blocks (writer reset/close, written-rows lookup) now log at `DEBUG` with - the exception attached. (https://github.com/ClickHouse/clickhouse-java/issues/2969) + an unexpected (unhandled) server status code is now logged once at `WARN` before the generic error is + thrown — with the status code, query id, target authority and the `X-ClickHouse-Exception-Code` header + (the response body is never logged) — so an otherwise-opaque failure is still diagnosable; the per-attempt + retry logs now include the attempt number, the endpoint being tried and the query id, and the + retry-exhaustion log now attaches the last exception; and previously-silent diagnostic `catch` blocks + (summary-metric parsing, HTTP-client version detection) now log at `DEBUG` with the exception attached. In + `jdbc-v2`: the prepared-statement metadata fallback now logs the underlying cause instead of the raw SQL, a + connection-abort failure during a network timeout is logged (in addition to being rethrown so a configured + uncaught-exception handler still sees it), and several previously-silent `catch` blocks (writer reset/close, + written-rows lookup) now log at `DEBUG` with the exception attached. + (https://github.com/ClickHouse/clickhouse-java/issues/2969) ### Bug Fixes diff --git a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java index 1275fa652..ed3cf5e7f 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java @@ -157,44 +157,6 @@ public HttpAPIClientHelper(Map configuration, Object metricsRegi } this.defaultUserAgent = buildDefaultUserAgent(); - - logTransportConfigSummary(configuration, lz4Factory); - } - - /** - * Emits a single INFO line at client startup summarising the resolved transport configuration. - * Only non-sensitive settings are included - no passwords, tokens or proxy credentials. - */ - private void logTransportConfigSummary(Map configuration, LZ4Factory lz4Factory) { - if (!LOG.isInfoEnabled()) { - return; - } - - final String authMode; - if (ClientConfigProperties.SSL_AUTH.getOrDefault(configuration).booleanValue()) { - authMode = "SSL_CLIENT_CERT"; - } else if (ClientConfigProperties.HTTP_USE_BASIC_AUTH.getOrDefault(configuration).booleanValue()) { - authMode = "HTTP_BASIC"; - } else { - authMode = "DEFAULT_HEADERS"; - } - - final String proxyType = (String) configuration.get(ClientConfigProperties.PROXY_TYPE.getKey()); - final String proxySummary = proxyType == null ? "none" - : proxyType + " " + configuration.get(ClientConfigProperties.PROXY_HOST.getKey()) - + ":" + configuration.get(ClientConfigProperties.PROXY_PORT.getKey()); - - LOG.info("client-v2 transport configured: authMode={}, sslMode={}, proxy={}, connectionPool={}," - + " maxConnectionsPerRoute={}, compression=[client={}, server={}, http={}], lz4Factory={}", - authMode, - ClientConfigProperties.SSL_MODE.getOrDefault(configuration), - proxySummary, - ClientConfigProperties.CONNECTION_POOL_ENABLED.getOrDefault(configuration), - configuration.getOrDefault(ClientConfigProperties.HTTP_MAX_OPEN_CONNECTIONS.getKey(), "default"), - ClientConfigProperties.COMPRESS_CLIENT_REQUEST.getOrDefault(configuration), - ClientConfigProperties.COMPRESS_SERVER_RESPONSE.getOrDefault(configuration), - ClientConfigProperties.USE_HTTP_COMPRESSION.getOrDefault(configuration), - lz4Factory); } /** @@ -742,21 +704,14 @@ public TransportResponse executeRequest(TransportRequest transportRequest) throw requestConfig)); if (httpResponse.containsHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)) { - logServerErrorResponse(req, httpResponse); throw readError(req, httpResponse); } int statusCode = httpResponse.getCode(); - if (statusCode == HttpStatus.SC_OK) { - closeResponse = false; - return new TransportResponseImpl(httpResponse); - } - - // Any non-2xx response is an error that is about to be thrown. Log it once with enough - // context (status, query id, authority, server exception code) to diagnose it, since the - // thrown exception may be retried away and never surface to the caller. - logServerErrorResponse(req, httpResponse); switch (statusCode) { + case HttpStatus.SC_OK: + closeResponse = false; + return new TransportResponseImpl(httpResponse); case HttpStatus.SC_PROXY_AUTHENTICATION_REQUIRED: throw new ClientMisconfigurationException("Proxy authentication required. Please check your proxy settings."); case HttpStatus.SC_BAD_GATEWAY: @@ -774,6 +729,11 @@ public TransportResponse executeRequest(TransportRequest transportRequest) throw // others we cannot handle properly throw readError(req, httpResponse); default: + // Only an unknown/unexpected status code reaches here. The generic exception below carries + // no server context, so log it once at WARN (status, query id, authority, exception-code + // header) to keep the otherwise-opaque failure diagnosable. Handled codes above are not + // logged: they either throw a descriptive exception or are parsed by readError. + logServerErrorResponse(req, httpResponse); throw new ClientException("Unexpected result status " + statusCode); } } catch (UnknownHostException e) { diff --git a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java index 5029b240d..632c97cf1 100644 --- a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java +++ b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java @@ -16,6 +16,7 @@ import org.mockito.ArgumentCaptor; import org.mockito.MockedConstruction; import org.testng.Assert; +import org.testng.annotations.DataProvider; import org.testng.annotations.Test; import javax.net.ssl.SNIHostName; @@ -295,14 +296,29 @@ public void testExecuteRequestThrowsConnectExceptionOn503() throws Exception { } /** - * A server error response must be logged once at WARN before the exception is thrown, carrying the - * status code, query id and the server exception-code header - so a failure that is retried away (and - * never surfaced to the caller) is still diagnosable. The response body is intentionally never logged. + * Only an unknown/unexpected server status code is logged at WARN, and the log sits in the switch's + * default branch (per review). A status code the switch does not handle throws a context-free generic + * exception, so it is logged once with the status, query id and the exception-code header (the response + * body is never logged). Handled/known error paths emit no server-error WARN: a ClickHouse error carrying + * the exception-code header is surfaced by readError, a mapped status code (502) throws a descriptive + * exception, and a success (200) is not an error at all. */ - @Test - public void testExecuteRequestLogsServerErrorResponse() throws Exception { + @DataProvider(name = "serverErrorLogging") + public static Object[][] serverErrorLogging() { + return new Object[][] { + // statusCode, exceptionCodeHeader (null => header absent), expectServerErrorWarn + {480, null, true}, // unknown status code -> context-free ClientException -> logged + {400, "62", false}, // known ClickHouse error (exception-code header) -> readError surfaces it + {502, null, false}, // mapped status code -> descriptive ConnectException + {200, null, false}, // success -> not an error + }; + } + + @Test(dataProvider = "serverErrorLogging") + public void testServerErrorLoggedOnlyForUnknownStatus(int statusCode, String exceptionCode, + boolean expectServerErrorWarn) throws Exception { HttpAPIClientHelper helper = new HttpAPIClientHelper(new HashMap<>(), null, false, LZ4Factory.fastestInstance()); - injectMockHttpClient(helper, mockErrorResponse(404, "241")); + injectMockHttpClient(helper, mockResponse(statusCode, exceptionCode)); Map reqConfig = new HashMap<>(); reqConfig.put(ClientConfigProperties.QUERY_ID.getKey(), "qid-log-test"); @@ -312,68 +328,29 @@ public void testExecuteRequestLogsServerErrorResponse() throws Exception { try { helper.executeRequest(helper.createRequest(endpoint, reqConfig, "SELECT 1")).close(); } catch (Exception expected) { - // the server error is rethrown to the caller; we assert on what was logged before that + // error status codes are rethrown to the caller; we assert only on what was logged } }); - assertTrue(logged.contains("Server returned error response"), - "a server error must be logged at WARN: " + logged); - assertTrue(logged.contains("404"), "the HTTP status code must be logged: " + logged); - assertTrue(logged.contains("qid-log-test"), "the query id must be logged: " + logged); - assertTrue(logged.contains("241"), "the server exception-code header value must be logged: " + logged); - } - - /** - * Contrast case: a successful (200) response must NOT emit the server-error WARN, so normal traffic - * stays quiet and only genuine error responses are logged. - */ - @Test - public void testExecuteRequestSuccessDoesNotLogServerError() throws Exception { - HttpAPIClientHelper helper = new HttpAPIClientHelper(new HashMap<>(), null, false, LZ4Factory.fastestInstance()); - ClassicHttpResponse ok = mock(ClassicHttpResponse.class); - when(ok.getCode()).thenReturn(200); - when(ok.getEntity()).thenReturn(mock(HttpEntity.class)); - injectMockHttpClient(helper, ok); - - Endpoint endpoint = new HttpEndpoint("localhost", 8123, false, "/"); - String logged = captureStdErr(() -> { - try { - helper.executeRequest(helper.createRequest(endpoint, new HashMap<>(), "SELECT 1")).close(); - } catch (Exception e) { - // not expected for a 200 response - } - }); - - assertFalse(logged.contains("Server returned error response"), - "a successful response must not be logged as a server error: " + logged); - } - - /** - * A single transport-configuration summary is emitted at INFO on startup and must never contain - * secrets (passwords, tokens, proxy credentials). - */ - @Test - public void testStartupLogsTransportConfigSummaryWithoutSecrets() { - Map config = new HashMap<>(); - config.put(ClientConfigProperties.PASSWORD.getKey(), "s3cr3t-pw"); - - String logged = captureStdErr(() -> - new HttpAPIClientHelper(config, null, false, LZ4Factory.fastestInstance())); - - assertTrue(logged.contains("client-v2 transport configured"), - "a transport-config summary must be logged at startup: " + logged); - assertTrue(logged.contains("authMode=") && logged.contains("sslMode=") && logged.contains("lz4Factory="), - "the summary must include the resolved transport fields: " + logged); - assertFalse(logged.contains("s3cr3t-pw"), - "the transport-config summary must not leak the password: " + logged); + if (expectServerErrorWarn) { + assertTrue(logged.contains("Server returned error response"), + "an unknown status code must be logged at WARN: " + logged); + assertTrue(logged.contains(String.valueOf(statusCode)), "the HTTP status code must be logged: " + logged); + assertTrue(logged.contains("qid-log-test"), "the query id must be logged: " + logged); + } else { + assertFalse(logged.contains("Server returned error response"), + "status " + statusCode + " must not emit a server-error WARN: " + logged); + } } - private static ClassicHttpResponse mockErrorResponse(int statusCode, String serverExceptionCode) { + private static ClassicHttpResponse mockResponse(int statusCode, String serverExceptionCode) { ClassicHttpResponse response = mock(ClassicHttpResponse.class); when(response.getCode()).thenReturn(statusCode); - when(response.containsHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)).thenReturn(true); + boolean hasExceptionHeader = serverExceptionCode != null; + when(response.containsHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)).thenReturn(hasExceptionHeader); when(response.getFirstHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE)) - .thenReturn(new BasicHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE, serverExceptionCode)); + .thenReturn(hasExceptionHeader + ? new BasicHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE, serverExceptionCode) : null); when(response.getEntity()).thenReturn(mock(HttpEntity.class)); return response; } diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java index 1f390bde1..e12fe776a 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java @@ -695,9 +695,11 @@ public synchronized void onNetworkTimeout() { try { this.abort(networkTimeoutExecutor); } catch (SQLException e) { - // Runs on the executor thread: a rethrown exception would be swallowed by the executor, - // so log it here to keep the abort failure observable. + // Runs on the executor thread. Log the failure so it is observable even when the executor + // has no uncaught-exception handler, then rethrow: a custom ThreadFactory may have installed + // an UncaughtExceptionHandler that needs to see it. LOG.error("Failed to abort connection on network timeout", e); + throw new RuntimeException("Failed to abort connection", e); } }); } From d9d0edab32a720919e8ca7f32b27571d49915b40 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 06:04:46 +0000 Subject: [PATCH 4/8] Address review (@chernser): reduce comments on the new logging code Trim the narrative/verbose comments added with the logging changes so they no longer restate what the adjacent log message or method name already says, keeping only a concise line where the rationale is non-obvious. No code or behavior change. --- .../api/data_formats/internal/ProcessParser.java | 1 - .../client/api/internal/HttpAPIClientHelper.java | 13 ++++--------- .../api/internal/HttpAPIClientHelperTest.java | 9 +++------ .../java/com/clickhouse/jdbc/ConnectionImpl.java | 4 +--- .../com/clickhouse/jdbc/PreparedStatementImpl.java | 3 +-- .../java/com/clickhouse/jdbc/StatementImpl.java | 1 - 6 files changed, 9 insertions(+), 22 deletions(-) diff --git a/client-v2/src/main/java/com/clickhouse/client/api/data_formats/internal/ProcessParser.java b/client-v2/src/main/java/com/clickhouse/client/api/data_formats/internal/ProcessParser.java index 4b3f7a018..d81534fe0 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/data_formats/internal/ProcessParser.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/data_formats/internal/ProcessParser.java @@ -87,7 +87,6 @@ public static Map parse(String json) { long value = Long.parseLong(valueStr); result.put(key, value); } catch (NumberFormatException e) { - // Unknown/non-numeric summary fields are skipped; keep going so the rest still parse. LOG.debug("Skipping summary field '{}' with non-numeric value '{}'", key, valueStr, e); } } diff --git a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java index ed3cf5e7f..aabad771a 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java @@ -729,10 +729,7 @@ public TransportResponse executeRequest(TransportRequest transportRequest) throw // others we cannot handle properly throw readError(req, httpResponse); default: - // Only an unknown/unexpected status code reaches here. The generic exception below carries - // no server context, so log it once at WARN (status, query id, authority, exception-code - // header) to keep the otherwise-opaque failure diagnosable. Handled codes above are not - // logged: they either throw a descriptive exception or are parsed by readError. + // Unknown status code: log it once (the generic exception below carries no server context). logServerErrorResponse(req, httpResponse); throw new ClientException("Unexpected result status " + statusCode); } @@ -778,13 +775,11 @@ private String getQueryId(HttpResponse httpResponse, HttpPost httpRequest) { } /** - * Logs an error server response at WARN with enough context to diagnose it. The response body is - * intentionally not logged: it is consumed by {@link #readError} and may contain SQL/data, so only - * the status, query id, target authority and the server exception-code header are emitted. + * Logs a server error response at WARN (status, query id, authority, exception-code header). The body is + * not logged: {@link #readError} consumes it and it may contain SQL/data. */ private void logServerErrorResponse(HttpPost req, ClassicHttpResponse httpResponse) { - // The logger itself must never throw on the error path and mask the real failure, so skip - // logging (rather than risk an NPE) if the level is off or either argument is unexpectedly null. + // Never let the error-path logger itself throw and mask the real failure. if (!LOG.isWarnEnabled() || req == null || httpResponse == null) { return; } diff --git a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java index 632c97cf1..13695cae3 100644 --- a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java +++ b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java @@ -296,12 +296,9 @@ public void testExecuteRequestThrowsConnectExceptionOn503() throws Exception { } /** - * Only an unknown/unexpected server status code is logged at WARN, and the log sits in the switch's - * default branch (per review). A status code the switch does not handle throws a context-free generic - * exception, so it is logged once with the status, query id and the exception-code header (the response - * body is never logged). Handled/known error paths emit no server-error WARN: a ClickHouse error carrying - * the exception-code header is surfaced by readError, a mapped status code (502) throws a descriptive - * exception, and a success (200) is not an error at all. + * A server error is logged at WARN only for an unknown status code (the switch's default branch). Known + * error paths emit no server-error WARN: readError surfaces an exception-code error, a mapped code (502) + * throws a descriptive exception, and 200 is not an error. */ @DataProvider(name = "serverErrorLogging") public static Object[][] serverErrorLogging() { diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java index e12fe776a..30b656267 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/ConnectionImpl.java @@ -695,9 +695,7 @@ public synchronized void onNetworkTimeout() { try { this.abort(networkTimeoutExecutor); } catch (SQLException e) { - // Runs on the executor thread. Log the failure so it is observable even when the executor - // has no uncaught-exception handler, then rethrow: a custom ThreadFactory may have installed - // an UncaughtExceptionHandler that needs to see it. + // Log so it is observable, then rethrow so a ThreadFactory's UncaughtExceptionHandler still sees it. LOG.error("Failed to abort connection on network timeout", e); throw new RuntimeException("Failed to abort connection", e); } diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java index aeb7bf4ca..ad85bc1da 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/PreparedStatementImpl.java @@ -417,8 +417,7 @@ public ResultSetMetaData getMetaData() throws SQLException { connection.getSchema(), connection.getCatalog(), tSchema.getTableName(), JdbcUtils.DATA_TYPE_CLASS_MAP, connection.getTypeMap()); } catch (Exception e) { - // Do not log the raw SQL (it may carry sensitive literals); the cause is enough to - // diagnose why metadata could not be resolved before falling back to untyped columns. + // Don't log the raw SQL (may carry sensitive literals); the cause is enough to diagnose. LOG.warn("Failed to resolve result-set metadata for prepared statement; " + "falling back to untyped metadata", e); } diff --git a/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java b/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java index e7ba96b08..c6a927add 100644 --- a/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java +++ b/jdbc-v2/src/main/java/com/clickhouse/jdbc/StatementImpl.java @@ -200,7 +200,6 @@ protected ResultSetImpl executeQueryImpl(String sql, QuerySettings settings) thr try { writtenRows = response.getWrittenRows(); } catch (Exception e) { - // Best effort: leave writtenRows as 0 if we can't obtain it. LOG.debug("Failed to read written-rows count from response; defaulting to 0", e); } this.currentUpdateCount = (int) Math.min(writtenRows, Integer.MAX_VALUE); From 32e6f654b4f76029eb41dafb258126c0e351d7c2 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 07:13:36 +0000 Subject: [PATCH 5/8] refactor(client-v2): extract shared retry-attempt WARN helper The three insert/query retry loops each emitted the per-attempt WARN with an identical multi-line LOG.warn statement, which SonarCloud flagged as duplicated new code (3.5% > 3% Quality Gate). Move it into a single private helper (logRetryAttempt); the emitted message and level are unchanged. --- .../java/com/clickhouse/client/api/Client.java | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/client-v2/src/main/java/com/clickhouse/client/api/Client.java b/client-v2/src/main/java/com/clickhouse/client/api/Client.java index db5afa60e..b243daccf 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/Client.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/Client.java @@ -1500,8 +1500,7 @@ public CompletableFuture insert(String tableName, List data, if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(queryId)) { if (i < maxAttempts) { selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); - LOG.warn("Insert attempt {}/{} failed (queryId: {}); retrying on endpoint {}", - i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); + logRetryAttempt("Insert", i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1707,8 +1706,7 @@ public CompletableFuture insert(String tableName, if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(requestSettings.getQueryId())) { if (i < maxAttempts) { selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); - LOG.warn("Insert attempt {}/{} failed (queryId: {}); retrying on endpoint {}", - i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); + logRetryAttempt("Insert", i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1852,8 +1850,7 @@ public CompletableFuture query(String sqlQuery, Map Date: Wed, 29 Jul 2026 08:25:35 +0000 Subject: [PATCH 6/8] test(client-v2): cover logServerErrorResponse null-safety and exception-code header Drop the redundant !LOG.isWarnEnabled() pre-check from the null-guard in logServerErrorResponse: SLF4J parameterized logging is already level-gated, so the guard only needs to protect against a null request/response (the actual reliability fix). Removing it also makes every guard branch reachable from a unit test. Add a focused unit test asserting the error-path logger is null-safe (never throws and masks the real server failure) and logs the ClickHouse exception-code header value when the response carries one. --- .../api/internal/HttpAPIClientHelper.java | 4 +-- .../api/internal/HttpAPIClientHelperTest.java | 36 +++++++++++++++++++ 2 files changed, 38 insertions(+), 2 deletions(-) diff --git a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java index aabad771a..7637c77fd 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/internal/HttpAPIClientHelper.java @@ -779,8 +779,8 @@ private String getQueryId(HttpResponse httpResponse, HttpPost httpRequest) { * not logged: {@link #readError} consumes it and it may contain SQL/data. */ private void logServerErrorResponse(HttpPost req, ClassicHttpResponse httpResponse) { - // Never let the error-path logger itself throw and mask the real failure. - if (!LOG.isWarnEnabled() || req == null || httpResponse == null) { + // Null-safe: the error path must never let its own logger throw and mask the real failure. + if (req == null || httpResponse == null) { return; } final Header exceptionCodeHeader = httpResponse.getFirstHeader(ClickHouseHttpProto.HEADER_EXCEPTION_CODE); diff --git a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java index 13695cae3..f477a9506 100644 --- a/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java +++ b/client-v2/src/test/java/com/clickhouse/client/api/internal/HttpAPIClientHelperTest.java @@ -8,6 +8,7 @@ import com.clickhouse.client.api.transport.HttpEndpoint; import com.clickhouse.client.api.transport.internal.TransportRequest; import net.jpountz.lz4.LZ4Factory; +import org.apache.hc.client5.http.classic.methods.HttpPost; import org.apache.hc.client5.http.impl.classic.CloseableHttpClient; import org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory; import org.apache.hc.core5.http.ClassicHttpResponse; @@ -28,6 +29,7 @@ import java.io.PrintStream; import java.io.UnsupportedEncodingException; import java.lang.reflect.Field; +import java.lang.reflect.Method; import java.net.ConnectException; import java.util.ArrayList; import java.util.Arrays; @@ -340,6 +342,40 @@ public void testServerErrorLoggedOnlyForUnknownStatus(int statusCode, String exc } } + /** + * The server-error logger runs on the failure path, so it must be null-safe - never throw and mask the + * real error - and it must surface the ClickHouse exception-code header value when the response carries one. + */ + @Test + public void testLogServerErrorResponseIsNullSafeAndLogsExceptionCode() throws Exception { + HttpAPIClientHelper helper = new HttpAPIClientHelper(new HashMap<>(), null, false, LZ4Factory.fastestInstance()); + Method log = HttpAPIClientHelper.class.getDeclaredMethod( + "logServerErrorResponse", HttpPost.class, ClassicHttpResponse.class); + log.setAccessible(true); + HttpPost req = new HttpPost("http://localhost:8123/"); + ClassicHttpResponse responseWithCode = mockResponse(480, "241"); + + // A null request or a null response must be a silent no-op: nothing logged, nothing thrown. + assertFalse(captureStdErr(() -> invokeQuietly(log, helper, null, responseWithCode)) + .contains("Server returned error response"), "a null request must not be logged"); + assertFalse(captureStdErr(() -> invokeQuietly(log, helper, req, null)) + .contains("Server returned error response"), "a null response must not be logged"); + + // A present exception-code header must be logged by value, not as the "" placeholder. + String logged = captureStdErr(() -> invokeQuietly(log, helper, req, responseWithCode)); + assertTrue(logged.contains("Server returned error response"), "the server error must be logged: " + logged); + assertTrue(logged.contains("241"), "the exception-code header value must be logged: " + logged); + assertFalse(logged.contains(""), "a present exception-code header must not log the placeholder: " + logged); + } + + private static void invokeQuietly(Method method, Object target, Object... args) { + try { + method.invoke(target, args); + } catch (Exception e) { + throw new AssertionError("logServerErrorResponse must not throw on the error path", e); + } + } + private static ClassicHttpResponse mockResponse(int statusCode, String serverExceptionCode) { ClassicHttpResponse response = mock(ClassicHttpResponse.class); when(response.getCode()).thenReturn(statusCode); From 4bad5aae8b6898eef13561f8c060585ea8058d9f Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 16:12:24 +0000 Subject: [PATCH 7/8] Address review (@chernser): scope out retry-logging, string-concat exception log, shorten CHANGELOG - ProcessParser: log the skipped non-numeric summary field via string concatenation with the exception as the sole trailing arg; the "{}" placeholder form binds to the (String, Throwable) overload so the values would not interpolate [r3675903977]. - Client: remove logRetryAttempt and revert the per-attempt/exhaustion retry logging to main; the retry-logging change is deferred to a separate PR [r3675913687]. - CHANGELOG: shorten the entry [r3675920309]. --- CHANGELOG.md | 15 ++------------- .../java/com/clickhouse/client/api/Client.java | 18 ++++++------------ .../data_formats/internal/ProcessParser.java | 2 +- 3 files changed, 9 insertions(+), 26 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c667ff2e7..77b63929f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,19 +16,8 @@ and the comma-separated `ssl_cipher_suites` connection property (client-v2 and jdbc-v2) restrict the cipher suites enabled on secure connections; when unset, the transport defaults are used. Cipher-suite selection is independent of the trust configuration and `ssl_mode`. (https://github.com/ClickHouse/clickhouse-java/issues/2882) -- **[client-v2, jdbc-v2]** Improved logging coverage on the error and diagnostic paths so failures are - observable in support cases, without changing any functional behavior or public API. In `client-v2`: - an unexpected (unhandled) server status code is now logged once at `WARN` before the generic error is - thrown — with the status code, query id, target authority and the `X-ClickHouse-Exception-Code` header - (the response body is never logged) — so an otherwise-opaque failure is still diagnosable; the per-attempt - retry logs now include the attempt number, the endpoint being tried and the query id, and the - retry-exhaustion log now attaches the last exception; and previously-silent diagnostic `catch` blocks - (summary-metric parsing, HTTP-client version detection) now log at `DEBUG` with the exception attached. In - `jdbc-v2`: the prepared-statement metadata fallback now logs the underlying cause instead of the raw SQL, a - connection-abort failure during a network timeout is logged (in addition to being rethrown so a configured - uncaught-exception handler still sees it), and several previously-silent `catch` blocks (writer reset/close, - written-rows lookup) now log at `DEBUG` with the exception attached. - (https://github.com/ClickHouse/clickhouse-java/issues/2969) +- **[client-v2, jdbc-v2]** Added logging on previously-silent error and diagnostic paths (no functional or + public-API change). (https://github.com/ClickHouse/clickhouse-java/issues/2969) ### Bug Fixes diff --git a/client-v2/src/main/java/com/clickhouse/client/api/Client.java b/client-v2/src/main/java/com/clickhouse/client/api/Client.java index b243daccf..c8fd9eee0 100644 --- a/client-v2/src/main/java/com/clickhouse/client/api/Client.java +++ b/client-v2/src/main/java/com/clickhouse/client/api/Client.java @@ -1499,8 +1499,8 @@ public CompletableFuture insert(String tableName, List data, lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId()); if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(queryId)) { if (i < maxAttempts) { + LOG.warn("Retrying.", e); selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); - logRetryAttempt("Insert", i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1513,7 +1513,7 @@ public CompletableFuture insert(String tableName, List data, } String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId()); - LOG.warn(errMsg, lastException); + LOG.warn(errMsg); throw (lastException == null ? new ClientException(errMsg) : lastException); }; @@ -1705,8 +1705,8 @@ public CompletableFuture insert(String tableName, lastException = httpClientHelper.wrapException(msg, e, requestSettings.getQueryId()); if (httpClientHelper.shouldRetry(e, requestSettings.getAllSettings()) && requestIsNotCancelled(requestSettings.getQueryId())) { if (i < maxAttempts) { + LOG.warn("Retrying.", e); selectedEndpoint = nodeSelector.getNextAliveNode(selectedEndpoint); - logRetryAttempt("Insert", i + 1, maxAttempts + 1, queryId, selectedEndpoint, e); } else { nodeSelector.getNextAliveNode(selectedEndpoint); } @@ -1732,7 +1732,7 @@ public CompletableFuture insert(String tableName, } String errMsg = requestExMsg("Insert", maxAttempts + 1, durationSince(startTime).toMillis(), requestSettings.getQueryId()); - LOG.warn(errMsg, lastException); + LOG.warn(errMsg); throw (lastException == null ? new ClientException(errMsg) : lastException); }; @@ -1849,8 +1849,8 @@ public CompletableFuture query(String sqlQuery, Map query(String sqlQuery, Map parse(String json) { long value = Long.parseLong(valueStr); result.put(key, value); } catch (NumberFormatException e) { - LOG.debug("Skipping summary field '{}' with non-numeric value '{}'", key, valueStr, e); + LOG.debug("Skipping summary field '" + key + "' with non-numeric value '" + valueStr + "'", e); } } From 5913f7db93facc97b09e213b6923ccd2605f8842 Mon Sep 17 00:00:00 2001 From: Polyglot AI <293096396+polyglotAI-bot@users.noreply.github.com> Date: Wed, 29 Jul 2026 17:17:02 +0000 Subject: [PATCH 8/8] test(jdbc-v2): cover writer cleanup buffer-close failure paths Injects a backing buffer that throws on close so both cleanup paths in WriterStatementImpl exercise (and swallow) their defensive DEBUG-log catch blocks: executeUpdate()'s finally -> resetWriter(), and close(). Restores new-code coverage after merging main (which cleared the stale new-code set that SonarCloud was mis-attributing). --- .../jdbc/WriterStatementImplTest.java | 68 +++++++++++++++++++ 1 file changed, 68 insertions(+) diff --git a/jdbc-v2/src/test/java/com/clickhouse/jdbc/WriterStatementImplTest.java b/jdbc-v2/src/test/java/com/clickhouse/jdbc/WriterStatementImplTest.java index 458df7a98..fc56117ed 100644 --- a/jdbc-v2/src/test/java/com/clickhouse/jdbc/WriterStatementImplTest.java +++ b/jdbc-v2/src/test/java/com/clickhouse/jdbc/WriterStatementImplTest.java @@ -5,6 +5,9 @@ import org.testng.annotations.DataProvider; import org.testng.annotations.Test; +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.lang.reflect.Field; import java.sql.Connection; import java.sql.JDBCType; import java.sql.PreparedStatement; @@ -78,4 +81,69 @@ public void testInsertWithQuotedColumnNames(String sqlTemplate) throws SQLExcept } } } + + /** + * The writer's cleanup paths must be defensive: if the backing buffer fails to close, both the + * post-insert reset (in {@code executeUpdate()}'s {@code finally}) and {@link WriterStatementImpl#close()} + * must swallow the failure after logging it at DEBUG, never surfacing an I/O error from cleanup. A buffer + * that throws on close is injected to exercise both catch blocks deterministically. + */ + @Test(groups = {"integration"}) + public void testWriterCleanupSwallowsBufferCloseFailure() throws Exception { + String table = "bt_writer_cleanup_close_fail"; + Properties properties = new Properties(); + properties.setProperty(DriverProperties.BETA_ROW_BINARY_WRITER.getKey(), "true"); + properties.setProperty(ASYNC_INSERT_SETTING_KEY, ServerSettings.OFF); + try (Connection connection = getJdbcConnection(properties)) { + try (Statement stmt = connection.createStatement()) { + stmt.execute("DROP TABLE IF EXISTS " + table); + stmt.execute("CREATE TABLE " + table + " (field1 Int32) Engine MergeTree ORDER BY ()"); + } + + final int[] closeAttempts = {0}; + PreparedStatement ps = connection.prepareStatement("INSERT INTO " + table + " (field1) VALUES (?)"); + Assert.assertTrue(ps instanceof WriterStatementImpl); + + // Replace the writer's backing buffer with one that fails on close, so both cleanup paths hit + // their defensive catch blocks: executeUpdate()'s finally -> resetWriter(), and close(). + Field outField = WriterStatementImpl.class.getDeclaredField("out"); + outField.setAccessible(true); + outField.set(ps, new ByteArrayOutputStream() { + @Override + public void close() throws IOException { + closeAttempts[0]++; + throw new IOException("injected buffer close failure"); + } + }); + + // executeUpdate()'s finally resets the writer, closing the buffer; the injected failure must be + // swallowed (an empty insert may error server-side, but the close failure must never be the cause). + try { + ps.executeUpdate(); + } catch (SQLException e) { + Assert.assertFalse(hasInjectedCause(e), + "resetWriter()'s buffer-close failure must be swallowed, not surfaced: " + e); + } + + // close() also closes the buffer; it must swallow the failure and not throw. + ps.close(); + + Assert.assertTrue(closeAttempts[0] >= 2, + "both executeUpdate()'s resetWriter and close() must attempt to close the writer buffer and " + + "swallow the failure; observed close attempts = " + closeAttempts[0]); + + try (Statement stmt = connection.createStatement()) { + stmt.execute("DROP TABLE IF EXISTS " + table); + } + } + } + + private static boolean hasInjectedCause(Throwable t) { + for (Throwable c = t; c != null; c = c.getCause()) { + if (c instanceof IOException && "injected buffer close failure".equals(c.getMessage())) { + return true; + } + } + return false; + } }