Skip to content

Commit fc020e7

Browse files
Fix log argument formatting (#1098)
## Description It appears that `JdbcLogger` expects SLF4J formatted strings (i.e. `{}` rather than `%s`) given `JulLogger` already handles the reformatting of strings via [`slf4jToJavaFormat`](https://github.com/databricks/databricks-jdbc/blob/main/src/main/java/com/databricks/jdbc/log/JulLogger.java#L247). Log strings containing `%s` are not currently being formatted correctly, the `%s` appears in logs. Co-authored-by: Thomas Powell <tpowell@palantir.com>
1 parent ccffb7d commit fc020e7

13 files changed

Lines changed: 64 additions & 41 deletions

src/main/java/com/databricks/jdbc/api/impl/DatabricksDatabaseMetaData.java

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1503,8 +1503,9 @@ public RowIdLifetime getRowIdLifetime() throws SQLException {
15031503
@Override
15041504
public ResultSet getSchemas(String catalog, String schemaPattern) throws SQLException {
15051505
LOGGER.debug(
1506-
"public ResultSet getSchemas(String catalog = %s, String schemaPattern = %s)",
1507-
catalog, schemaPattern);
1506+
"public ResultSet getSchemas(String catalog = {}, String schemaPattern = {})",
1507+
catalog,
1508+
schemaPattern);
15081509
throwExceptionIfConnectionIsClosed();
15091510

15101511
return session.getDatabricksMetadataClient().listSchemas(session, catalog, schemaPattern);

src/main/java/com/databricks/jdbc/api/impl/DatabricksStatement.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -546,7 +546,7 @@ public void handleResultSetClose(IDatabricksResultSet resultSet) throws Databric
546546

547547
@Override
548548
public void setStatementId(StatementId statementId) {
549-
LOGGER.debug("void setStatementId {%s}", statementId);
549+
LOGGER.debug("void setStatementId(Statement statementId = {})", statementId);
550550
this.statementId = statementId;
551551
}
552552

src/main/java/com/databricks/jdbc/api/impl/arrow/AbstractArrowResultChunk.java

Lines changed: 17 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -227,8 +227,12 @@ protected void setStatus(ChunkStatus targetStatus) {
227227
stateMachine.transition(targetStatus);
228228
} catch (DatabricksParsingException e) {
229229
LOGGER.warn(
230-
"Failed to transition to state [%s] from state [%s] for chunk [%d] and statement [%s]. Stack trace: %s",
231-
targetStatus, getStatus(), chunkIndex, statementId, ExceptionUtils.getStackTrace(e));
230+
"Failed to transition to state [{}] from state [{}] for chunk [{}] and statement [{}]. Stack trace: {}",
231+
targetStatus,
232+
getStatus(),
233+
chunkIndex,
234+
statementId,
235+
ExceptionUtils.getStackTrace(e));
232236
}
233237
}
234238

@@ -265,7 +269,7 @@ protected void waitForChunkReady()
265269
} catch (InterruptedException e) {
266270
LOGGER.error(
267271
e,
268-
"Chunk download interrupted for chunk index %s and statement %s",
272+
"Chunk download interrupted for chunk index {} and statement {}",
269273
chunkIndex,
270274
statementId);
271275
Thread.currentThread().interrupt();
@@ -283,11 +287,11 @@ protected void waitForChunkReady()
283287
*/
284288
protected void initializeData(InputStream inputStream)
285289
throws DatabricksSQLException, IOException {
286-
LOGGER.debug("Parsing data for chunk index %s and statement %s", chunkIndex, statementId);
290+
LOGGER.debug("Parsing data for chunk index {} and statement {}", chunkIndex, statementId);
287291
ArrowData arrowData = getRecordBatchList(inputStream, rootAllocator, statementId, chunkIndex);
288292
recordBatchList = arrowData.getValueVectors();
289293
arrowMetadata = arrowData.getMetadata();
290-
LOGGER.debug("Data parsed for chunk index %s and statement %s", chunkIndex, statementId);
294+
LOGGER.debug("Data parsed for chunk index {} and statement {}", chunkIndex, statementId);
291295
setStatus(ChunkStatus.PROCESSING_SUCCEEDED);
292296
}
293297

@@ -322,7 +326,7 @@ private ArrowData getRecordBatchList(
322326
// release resources if thread is interrupted when reading arrow data
323327
LOGGER.error(
324328
e,
325-
"Data parsing interrupted for chunk index [%s] and statement [%s]. Error [%s]",
329+
"Data parsing interrupted for chunk index [{}] and statement [{}]. Error [{}]",
326330
chunkIndex,
327331
statementId,
328332
e.getMessage());
@@ -365,8 +369,13 @@ private void logAllocatorStats(String event) {
365369
long initReservation = rootAllocator.getInitReservation();
366370

367371
LOGGER.debug(
368-
"Chunk allocator stats Log - Event: %s, Chunk Index: %s, Allocated Memory: %s, Peak Memory: %s, Headroom: %s, Init Reservation: %s",
369-
event, chunkIndex, allocatedMemory, peakMemory, headRoom, initReservation);
372+
"Chunk allocator stats Log - Event: {}, Chunk Index: {}, Allocated Memory: {}, Peak Memory: {}, Headroom: {}, Init Reservation: {}",
373+
event,
374+
chunkIndex,
375+
allocatedMemory,
376+
peakMemory,
377+
headRoom,
378+
initReservation);
370379
}
371380

372381
/** Releases all Arrow-related resources and clears the record batch list. */

src/main/java/com/databricks/jdbc/api/impl/arrow/AbstractRemoteChunkProvider.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -283,8 +283,10 @@ private void populateChunkIndexMap(TRowSet resultData, ConcurrentMap<Long, T> ch
283283
rowCount += DatabricksThriftUtil.getRowCount(resultData);
284284
for (TSparkArrowResultLink resultLink : resultData.getResultLinks()) {
285285
LOGGER.debug(
286-
"Chunk information log - Row Offset: %s, Row Count: %s, Expiry Time: %s",
287-
resultLink.getStartRowOffset(), resultLink.getRowCount(), resultLink.getExpiryTime());
286+
"Chunk information log - Row Offset: {}, Row Count: {}, Expiry Time: {}",
287+
resultLink.getStartRowOffset(),
288+
resultLink.getRowCount(),
289+
resultLink.getExpiryTime());
288290
chunkIndexMap.put(chunkCount, createChunk(statementId, chunkCount, resultLink));
289291
chunkCount++;
290292
}

src/main/java/com/databricks/jdbc/api/impl/arrow/ArrowResultChunk.java

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -146,8 +146,9 @@ private void addHeaders(HttpGet getRequest, Map<String, String> headers) {
146146
headers.forEach(getRequest::addHeader);
147147
} else {
148148
LOGGER.debug(
149-
"No encryption headers present for chunk index %s and statement %s",
150-
chunkIndex, statementId);
149+
"No encryption headers present for chunk index {} and statement {}",
150+
chunkIndex,
151+
statementId);
151152
}
152153
}
153154

src/main/java/com/databricks/jdbc/api/impl/arrow/ChunkDownloadTask.java

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -107,8 +107,9 @@ public Void call() throws DatabricksSQLException, ExecutionException, Interrupte
107107
chunk.getChunkReadyFuture().complete(null); // complete the void future successfully
108108
} else {
109109
LOGGER.info(
110-
"Uncaught exception during chunk download. Chunk index: %d, Error: %s",
111-
chunk.getChunkIndex(), Arrays.toString(uncaughtException.getStackTrace()));
110+
"Uncaught exception during chunk download. Chunk index: {}, Error: {}",
111+
chunk.getChunkIndex(),
112+
Arrays.toString(uncaughtException.getStackTrace()));
112113
// Status is set to DOWNLOAD_SUCCEEDED in the happy path. For any failure case,
113114
// explicitly set status to DOWNLOAD_FAILED here to ensure consistent error handling
114115
chunk.setStatus(ChunkStatus.DOWNLOAD_FAILED);

src/main/java/com/databricks/jdbc/api/impl/arrow/incubator/ArrowResultChunkV2.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -236,7 +236,7 @@ private void handleRetryableError(
236236
if (currentAttempt < retryConfig.maxAttempts) {
237237
long delayMs = calculateBackoffDelay(currentAttempt, retryConfig);
238238
LOGGER.warn(
239-
"Retryable error during %s for chunk %s (attempt %s/%s), retrying in %s ms. Error: %s",
239+
"Retryable error during {} for chunk {} (attempt {}/{}), retrying in {} ms. Error: {}",
240240
phase.getDescription(),
241241
chunkIndex,
242242
currentAttempt,

src/main/java/com/databricks/jdbc/api/impl/arrow/incubator/StreamingResponseConsumer.java

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -112,7 +112,10 @@ private void logDownloadStats() {
112112
double speedMBps = (chunk.bytesDownloaded / 1024.0 / 1024.0) / (durationMs / 1000.0);
113113

114114
LOGGER.debug(
115-
"Download stats for chunk %s: Size: %s MB, Duration: %s ms, Speed: %s MB/s",
116-
chunk.getChunkIndex(), chunk.bytesDownloaded / 1024.0 / 1024.0, durationMs, speedMBps);
115+
"Download stats for chunk {}: Size: {} MB, Duration: {} ms, Speed: {} MB/s",
116+
chunk.getChunkIndex(),
117+
chunk.bytesDownloaded / 1024.0 / 1024.0,
118+
durationMs,
119+
speedMBps);
117120
}
118121
}

src/main/java/com/databricks/jdbc/api/impl/volume/VolumeOperationProcessor.java

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -294,8 +294,9 @@ void executeGetOperation() {
294294
try (CloseableHttpResponse response = databricksHttpClient.execute(httpGet)) {
295295
if (!HttpUtil.isSuccessfulHttpResponse(response)) {
296296
LOGGER.error(
297-
"Failed to fetch content from volume with error {%s} for local file {%s}",
298-
response.getStatusLine().getStatusCode(), localFilePath);
297+
"Failed to fetch content from volume with error {} for local file {}",
298+
response.getStatusLine().getStatusCode(),
299+
localFilePath);
299300
status = VolumeOperationStatus.FAILED;
300301
errorMessage = "Failed to download file";
301302
return;
@@ -367,8 +368,9 @@ void executePutOperation() {
367368
status = VolumeOperationStatus.SUCCEEDED;
368369
} else {
369370
LOGGER.error(
370-
"Failed to upload file {%s} with error code: {%s}",
371-
localFilePath, response.getStatusLine().getStatusCode());
371+
"Failed to upload file {} with error code: {}",
372+
localFilePath,
373+
response.getStatusLine().getStatusCode());
372374
// TODO: Add retries
373375
status = VolumeOperationStatus.FAILED;
374376
errorMessage =
@@ -413,7 +415,7 @@ private void executeDeleteOperation() {
413415
status = VolumeOperationStatus.SUCCEEDED;
414416
} else {
415417
LOGGER.error(
416-
"Failed to delete volume with error code: {%s}",
418+
"Failed to delete volume with error code: {}",
417419
response.getStatusLine().getStatusCode());
418420
status = VolumeOperationStatus.FAILED;
419421
errorMessage = "Failed to delete volume";

src/main/java/com/databricks/jdbc/auth/EncryptedFileTokenCache.java

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -75,7 +75,7 @@ public void save(Token token) throws DatabricksException {
7575
file.setWritable(false, false);
7676
file.setWritable(true, true);
7777

78-
LOGGER.debug("Successfully saved encrypted token to cache: %s", cacheFile);
78+
LOGGER.debug("Successfully saved encrypted token to cache: {}", cacheFile);
7979
} catch (Exception e) {
8080
throw new DatabricksException("Failed to save token cache: " + e.getMessage(), e);
8181
}
@@ -85,7 +85,7 @@ public void save(Token token) throws DatabricksException {
8585
public Token load() {
8686
try {
8787
if (!Files.exists(cacheFile)) {
88-
LOGGER.debug("No token cache file found at: %s", cacheFile);
88+
LOGGER.debug("No token cache file found at: {}", cacheFile);
8989
return null;
9090
}
9191

@@ -96,19 +96,19 @@ public Token load() {
9696
try {
9797
decodedContent = decrypt(fileContent);
9898
} catch (Exception e) {
99-
LOGGER.debug("Failed to decrypt token cache: %s", e.getMessage());
99+
LOGGER.debug("Failed to decrypt token cache: {}", e.getMessage());
100100
return null;
101101
}
102102

103103
// Deserialize token from JSON
104104
String json = new String(decodedContent, StandardCharsets.UTF_8);
105105
Token token = mapper.readValue(json, Token.class);
106-
LOGGER.debug("Successfully loaded encrypted token from cache: %s", cacheFile);
106+
LOGGER.debug("Successfully loaded encrypted token from cache: {}", cacheFile);
107107
return token;
108108
} catch (Exception e) {
109109
// If there's any issue loading the token, return null
110110
// to allow a fresh token to be obtained
111-
LOGGER.debug("Failed to load token from cache: %s", e.getMessage());
111+
LOGGER.debug("Failed to load token from cache: {}", e.getMessage());
112112
return null;
113113
}
114114
}

0 commit comments

Comments
 (0)