This is an automated email from the ASF dual-hosted git repository.
jinsongzhou pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/amoro.git
The following commit(s) were added to refs/heads/master by this push:
new f3cfd7823 [AMORO-3695][Improvement]: Reduce unnecessary details in the
log output (#3696)
f3cfd7823 is described below
commit f3cfd7823d7ccf73f8fc23e985539381f1d29325
Author: cxxiii <[email protected]>
AuthorDate: Mon Aug 4 10:40:27 2025 +0800
[AMORO-3695][Improvement]: Reduce unnecessary details in the log output
(#3696)
* reduce log output
* adjust log output content
* optimize log expression
* optimize expression
---
.../apache/amoro/server/optimizing/KeyedTableCommit.java | 16 +++++++++++++---
.../apache/amoro/server/optimizing/OptimizingQueue.java | 9 ++++-----
.../amoro/server/optimizing/UnKeyedTableCommit.java | 9 +++++++--
.../amoro/server/table/DefaultOptimizingState.java | 4 ++--
dist/src/main/amoro-bin/conf/log4j2.xml | 11 +++++++++++
5 files changed, 37 insertions(+), 12 deletions(-)
diff --git
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/KeyedTableCommit.java
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/KeyedTableCommit.java
index ac7781f3a..c05a853cc 100644
---
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/KeyedTableCommit.java
+++
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/KeyedTableCommit.java
@@ -84,9 +84,15 @@ public class KeyedTableCommit extends UnKeyedTableCommit {
@Override
public void commit() throws OptimizingCommitException {
if (tasks.isEmpty()) {
- LOG.info("{} found no tasks to commit", table.id());
+ LOG.info("No tasks to commit for table {}", table.id());
+ return;
}
- LOG.info("{} found tasks to commit from snapshot {}", table.id(),
fromSnapshotId);
+ long startTime = System.currentTimeMillis();
+ LOG.info(
+ "Starting to commit table {} with {} tasks from snapshot {}.",
+ table.id(),
+ tasks.size(),
+ fromSnapshotId);
// In the scene of moving files to hive, the files will be renamed
List<DataFile> hiveNewDataFiles = moveFile2HiveIfNeed();
@@ -139,9 +145,13 @@ public class KeyedTableCommit extends UnKeyedTableCommit {
try {
executeCommit(addedDataFiles, removedDataFiles, addedDeleteFiles,
removedDeleteFiles);
+ LOG.info(
+ "Successfully committed table {} in {} ms.",
+ table.id(),
+ System.currentTimeMillis() - startTime);
} catch (Exception e) {
// Only failures to clean files will trigger a retry
- LOG.warn("Optimize commit table {} failed, give up commit.", table.id(),
e);
+ LOG.warn("Failed to commit table {}.", table.id(), e);
if (needMoveFile2Hive()) {
correctHiveData(addedDataFiles, addedDeleteFiles);
diff --git
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/OptimizingQueue.java
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/OptimizingQueue.java
index a3f3e2ccd..ff5305e2a 100644
---
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/OptimizingQueue.java
+++
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/OptimizingQueue.java
@@ -269,16 +269,15 @@ public class OptimizingQueue extends PersistentBase {
.map(item -> item + "")
.collect(Collectors.joining(","));
LOG.info(
- "Completed planning on table {} with {} tasks with a
total cost of {} ms, skipping {} tables,"
- + " id list:{}",
+ "Completed planning on table {} with {} tasks with a
total cost of {} ms, skipping {} tables.",
tableRuntime.getTableIdentifier(),
process.getTaskMap().size(),
currentTime - startTime,
- skipTables.size(),
- skipIds);
+ skipTables.size());
+ LOG.debug("Skipped planning table IDs:{}", skipIds);
} else if (throwable == null) {
LOG.info(
- "Skip planning table {} with a total cost of {} ms.",
+ "Skipping planning table {} with a total cost of {} ms.",
tableRuntime.getTableIdentifier(),
currentTime - startTime);
}
diff --git
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/UnKeyedTableCommit.java
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/UnKeyedTableCommit.java
index 4583af858..97b7b8855 100644
---
a/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/UnKeyedTableCommit.java
+++
b/amoro-ams/src/main/java/org/apache/amoro/server/optimizing/UnKeyedTableCommit.java
@@ -186,7 +186,8 @@ public class UnKeyedTableCommit {
}
public void commit() throws OptimizingCommitException {
- LOG.info("{} get tasks to commit {}", table.id(), tasks);
+ long startTime = System.currentTimeMillis();
+ LOG.info("Starting to commit table {} with {} tasks.", table.id(),
tasks.size());
List<DataFile> hiveNewDataFiles = moveFile2HiveIfNeed();
// collect files
@@ -231,11 +232,15 @@ public class UnKeyedTableCommit {
transaction, removedDataFiles, addedDataFiles, removedDeleteFiles,
addedDeleteFiles);
}
transaction.commitTransaction();
+ LOG.info(
+ "Successfully committed table {} in {} ms.",
+ table.id(),
+ System.currentTimeMillis() - startTime);
} catch (Exception e) {
if (needMoveFile2Hive()) {
correctHiveData(addedDataFiles, addedDeleteFiles);
}
- LOG.warn("Optimize commit table {} failed, give up commit.", table.id(),
e);
+ LOG.warn("Failed to commit table {}.", table.id(), e);
throw new OptimizingCommitException("unexpected commit error ", e);
}
}
diff --git
a/amoro-ams/src/main/java/org/apache/amoro/server/table/DefaultOptimizingState.java
b/amoro-ams/src/main/java/org/apache/amoro/server/table/DefaultOptimizingState.java
index b36de90f2..1953049a6 100644
---
a/amoro-ams/src/main/java/org/apache/amoro/server/table/DefaultOptimizingState.java
+++
b/amoro-ams/src/main/java/org/apache/amoro/server/table/DefaultOptimizingState.java
@@ -382,7 +382,7 @@ public class DefaultOptimizingState extends
StatedPersistentBase implements Proc
currentSnapshotId = doRefreshSnapshots(baseTable);
if (currentSnapshotId != lastSnapshotId || currentChangeSnapshotId !=
changeSnapshotId) {
- LOG.info(
+ LOG.debug(
"Refreshing table {} with base snapshot id {} and change snapshot
id {}",
tableIdentifier,
currentSnapshotId,
@@ -392,7 +392,7 @@ public class DefaultOptimizingState extends
StatedPersistentBase implements Proc
} else {
currentSnapshotId = doRefreshSnapshots((UnkeyedTable) table);
if (currentSnapshotId != lastSnapshotId) {
- LOG.info(
+ LOG.debug(
"Refreshing table {} with base snapshot id {}", tableIdentifier,
currentSnapshotId);
return true;
}
diff --git a/dist/src/main/amoro-bin/conf/log4j2.xml
b/dist/src/main/amoro-bin/conf/log4j2.xml
index 2ebe3ae2c..3b454595a 100644
--- a/dist/src/main/amoro-bin/conf/log4j2.xml
+++ b/dist/src/main/amoro-bin/conf/log4j2.xml
@@ -109,11 +109,22 @@
<AppenderRef ref="amoroMetricReporter"/>
</logger>
+ <logger name="org.apache.iceberg.metrics.LoggingMetricsReporter"
level="info" additivity="false">
+ <!-- iceberg rest metric reporter logs -->
+ <AppenderRef ref="amoroMetricReporter"/>
+ </logger>
+
<logger name="org.apache.spark" level="warn" additivity="false">
<AppenderRef ref="infoFileAppender"/>
<AppenderRef ref="consoleAppender" level="${CONSOLE_LEVEL}"/>
</logger>
+ <logger name="org.apache.iceberg.BaseMetastoreCatalog" level="debug"/>
+
+ <logger name="org.apache.iceberg.BaseMetastoreTableOperations"
level="debug"/>
+
+ <logger name="org.apache.iceberg.SnapshotScan" level="debug"/>
+
<Root level="debug">
<!--By default, debug logs are not printed-->
<!--<AppenderRef ref="debugFileAppender" level="debug"/>-->
