This is an automated email from the ASF dual-hosted git repository.
tanxinyu pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/iotdb.git
The following commit(s) were added to refs/heads/master by this push:
new d67f0556d0a Optimize log according to real scenarios (#11808)
d67f0556d0a is described below
commit d67f0556d0a30e974539f2cf86a31c97331428c5
Author: ZhangHongYin <[email protected]>
AuthorDate: Fri Dec 29 16:19:50 2023 +0800
Optimize log according to real scenarios (#11808)
---
.../consensus/iot/IoTConsensusServerImpl.java | 2 +-
.../event/common/heartbeat/PipeHeartbeatEvent.java | 4 +-
.../pipe/resource/wal/PipeWALResourceManager.java | 4 +-
.../db/storageengine/dataregion/DataRegion.java | 2 -
.../dataregion/flush/CompressionRatio.java | 4 +-
.../dataregion/flush/MemTableFlushTask.java | 38 +++++++++-------
.../dataregion/memtable/TsFileProcessor.java | 53 ++++++++--------------
.../iotdb/tsfile/write/writer/TsFileIOWriter.java | 2 +-
8 files changed, 50 insertions(+), 59 deletions(-)
diff --git
a/iotdb-core/consensus/src/main/java/org/apache/iotdb/consensus/iot/IoTConsensusServerImpl.java
b/iotdb-core/consensus/src/main/java/org/apache/iotdb/consensus/iot/IoTConsensusServerImpl.java
index 4e43306d7c5..800754ddba6 100644
---
a/iotdb-core/consensus/src/main/java/org/apache/iotdb/consensus/iot/IoTConsensusServerImpl.java
+++
b/iotdb-core/consensus/src/main/java/org/apache/iotdb/consensus/iot/IoTConsensusServerImpl.java
@@ -206,7 +206,7 @@ public class IoTConsensusServerImpl {
writeToStateMachineStartTime - getStateMachineLockTime);
IndexedConsensusRequest indexedConsensusRequest =
buildIndexedConsensusRequestForLocalRequest(request);
- if (indexedConsensusRequest.getSearchIndex() % 10000 == 0) {
+ if (indexedConsensusRequest.getSearchIndex() % 100000 == 0) {
logger.info(
"DataRegion[{}]: index after build: safeIndex:{}, searchIndex: {}",
thisNode.getGroupId(),
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/event/common/heartbeat/PipeHeartbeatEvent.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/event/common/heartbeat/PipeHeartbeatEvent.java
index e9e6bb9d6c5..3e9f3b29d4b 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/event/common/heartbeat/PipeHeartbeatEvent.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/event/common/heartbeat/PipeHeartbeatEvent.java
@@ -94,8 +94,8 @@ public class PipeHeartbeatEvent extends EnrichedEvent {
public boolean internallyDecreaseResourceReferenceCount(String
holderMessage) {
// PipeName == null indicates that the event is the raw event at disruptor,
// not the event copied and passed to the extractor
- if (shouldPrintMessage && pipeName != null && LOGGER.isInfoEnabled()) {
- LOGGER.info(this.toString());
+ if (shouldPrintMessage && pipeName != null && LOGGER.isDebugEnabled()) {
+ LOGGER.debug(this.toString());
}
return true;
}
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/resource/wal/PipeWALResourceManager.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/resource/wal/PipeWALResourceManager.java
index 592b86bdae7..0c34edda8a3 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/resource/wal/PipeWALResourceManager.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/pipe/resource/wal/PipeWALResourceManager.java
@@ -70,8 +70,8 @@ public abstract class PipeWALResourceManager {
try {
if (entry.getValue().invalidateIfPossible()) {
iterator.remove();
- } else {
- LOGGER.info(
+ } else if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug(
"WAL (memtableId {}) is still referenced {} times",
entry.getKey(),
entry.getValue().getReferenceCount());
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/DataRegion.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/DataRegion.java
index acac85f500e..84adee4591d 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/DataRegion.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/DataRegion.java
@@ -1415,7 +1415,6 @@ public class DataRegion implements IDataRegionForQuery {
if
(!workUnsequenceTsFileProcessors.containsKey(tsFileProcessor.getTimeRangeId()))
{
timePartitionIdVersionControllerMap.remove(tsFileProcessor.getTimeRangeId());
}
- logger.info("close a sequence tsfile processor {}", databaseName + "-" +
dataRegionId);
} else {
closingUnSequenceTsFileProcessor.add(tsFileProcessor);
future = tsFileProcessor.asyncClose();
@@ -2330,7 +2329,6 @@ public class DataRegion implements IDataRegionForQuery {
tsFileProcessor.isSequence(),
tsFileResource.getTsFile().getName());
}
- logger.info("signal closing database condition in {}", databaseName + "-"
+ dataRegionId);
}
protected int executeCompaction() {
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/CompressionRatio.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/CompressionRatio.java
index 32e1cf80416..dfc37ba428e 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/CompressionRatio.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/CompressionRatio.java
@@ -95,8 +95,8 @@ public class CompressionRatio {
String.format(
Locale.ENGLISH, RATIO_FILE_PATH_FORMAT, totalMemorySize.get(),
totalDiskSize));
persist(oldFile, newFile);
- if (LOGGER.isInfoEnabled()) {
- LOGGER.info("Compression ratio is {}", (double) totalMemorySize.get() /
totalDiskSize);
+ if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug("Compression ratio is {}", (double) totalMemorySize.get() /
totalDiskSize);
}
}
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/MemTableFlushTask.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/MemTableFlushTask.java
index 1cf48033c63..454702e72f3 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/MemTableFlushTask.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/flush/MemTableFlushTask.java
@@ -110,12 +110,14 @@ public class MemTableFlushTask {
memTable.getSeriesNumber() == 0
? 0
: memTable.getTotalPointsNum() / memTable.getSeriesNumber();
- LOGGER.info(
- "The memTable size of SG {} is {}, the avg series points num in chunk
is {}, total timeseries number is {}",
- storageGroup,
- memTable.memSize(),
- avgSeriesPointsNum,
- memTable.getSeriesNumber());
+ if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug(
+ "The memTable size of SG {} is {}, the avg series points num in
chunk is {}, total timeseries number is {}",
+ storageGroup,
+ memTable.memSize(),
+ avgSeriesPointsNum,
+ memTable.getSeriesNumber());
+ }
WRITING_METRICS.recordFlushingMemTableStatus(
storageGroup,
memTable.memSize(),
@@ -214,11 +216,13 @@ public class MemTableFlushTask {
Tag.NAME.toString(),
"flush");
- LOGGER.info(
- "Database {} memtable {} flushing a memtable has finished! Time
consumption: {}ms",
- storageGroup,
- memTable,
- System.currentTimeMillis() - start);
+ if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug(
+ "Database {} memtable {} flushing a memtable has finished! Time
consumption: {}ms",
+ storageGroup,
+ memTable,
+ System.currentTimeMillis() - start);
+ }
}
/** encoding task (second task of pipeline) */
@@ -285,11 +289,13 @@ public class MemTableFlushTask {
recordFlushPointsMetric();
- LOGGER.info(
- "Database {}, flushing memtable {} into disk: Encoding data cost
" + "{} ms.",
- storageGroup,
- writer.getFile().getName(),
- memSerializeTime);
+ if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug(
+ "Database {}, flushing memtable {} into disk: Encoding data
cost " + "{} ms.",
+ storageGroup,
+ writer.getFile().getName(),
+ memSerializeTime);
+ }
WRITING_METRICS.recordFlushCost(WritingMetrics.FLUSH_STAGE_ENCODING,
memSerializeTime);
}
};
diff --git
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/memtable/TsFileProcessor.java
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/memtable/TsFileProcessor.java
index 16119d9bd02..1f11f696abb 100644
---
a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/memtable/TsFileProcessor.java
+++
b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/storageengine/dataregion/memtable/TsFileProcessor.java
@@ -792,10 +792,12 @@ public class TsFileProcessor {
return false;
}
if (workMemTable.shouldFlush()) {
- logger.info(
- "The memtable size {} of tsfile {} reaches the mem control
threshold",
- workMemTable.memSize(),
- tsFileResource.getTsFile().getAbsolutePath());
+ if (logger.isDebugEnabled()) {
+ logger.debug(
+ "The memtable size {} of tsfile {} reaches the mem control
threshold",
+ workMemTable.memSize(),
+ tsFileResource.getTsFile().getAbsolutePath());
+ }
return true;
}
if (!enableMemControl && workMemTable.memSize() >=
getMemtableSizeThresholdBasedOnSeriesNum()) {
@@ -824,14 +826,6 @@ public class TsFileProcessor {
public boolean shouldClose() {
long fileSize = tsFileResource.getTsFileSize();
long fileSizeThreshold = sequence ? config.getSeqTsFileSize() :
config.getUnSeqTsFileSize();
-
- if (fileSize >= fileSizeThreshold) {
- logger.info(
- "{} fileSize {} >= fileSizeThreshold {}",
- tsFileResource.getTsFilePath(),
- fileSize,
- fileSizeThreshold);
- }
return fileSize >= fileSizeThreshold;
}
@@ -926,7 +920,6 @@ public class TsFileProcessor {
// When invoke closing TsFile after insert data to memTable, we
shouldn't flush until invoke
// flushing memTable in System module.
Future<?> future = addAMemtableIntoFlushingList(tmpMemTable);
- logger.info("Memtable {} has been added to flushing list",
tmpMemTable);
shouldClose = true;
return future;
} catch (Exception e) {
@@ -1353,12 +1346,14 @@ public class TsFileProcessor {
private void updateCompressionRatio() {
try {
double compressionRatio = ((double) totalMemTableSize) / writer.getPos();
- logger.info(
- "The compression ratio of tsfile {} is {}, totalMemTableSize: {},
the file size: {}",
- writer.getFile().getAbsolutePath(),
- compressionRatio,
- totalMemTableSize,
- writer.getPos());
+ if (logger.isDebugEnabled()) {
+ logger.debug(
+ "The compression ratio of tsfile {} is {}, totalMemTableSize: {},
the file size: {}",
+ writer.getFile().getAbsolutePath(),
+ compressionRatio,
+ totalMemTableSize,
+ writer.getPos());
+ }
String dataRegionId = dataRegionInfo.getDataRegion().getDataRegionId();
WritingMetrics.getInstance()
.recordTsFileCompressionRatioOfFlushingMemTable(dataRegionId,
compressionRatio);
@@ -1374,12 +1369,14 @@ public class TsFileProcessor {
/** end file and write some meta */
private void endFile() throws IOException, TsFileProcessorException {
- logger.info("Start to end file {}", tsFileResource);
- long closeStartTime = System.currentTimeMillis();
+ if (logger.isDebugEnabled()) {
+ logger.debug("Start to end file {}", tsFileResource);
+ }
writer.endFile();
tsFileResource.serialize();
- logger.info("Ended file {}", tsFileResource);
-
+ if (logger.isDebugEnabled()) {
+ logger.debug("Ended file {}", tsFileResource);
+ }
// remove this processor from Closing list in StorageGroupProcessor,
// mark the TsFileResource closed, no need writer anymore
for (CloseFileListener closeFileListener : closeFileListeners) {
@@ -1390,16 +1387,6 @@ public class TsFileProcessor {
tsFileProcessorInfo.clear();
dataRegionInfo.closeTsFileProcessorAndReportToSystem(this);
}
- if (logger.isInfoEnabled()) {
- long closeEndTime = System.currentTimeMillis();
- logger.info(
- "Database {} close the file {}, TsFile size is {}, "
- + "time consumption of flushing metadata is {}ms",
- storageGroupName,
- tsFileResource.getTsFile().getAbsoluteFile(),
- writer.getFile().length(),
- closeEndTime - closeStartTime);
- }
writer = null;
}
diff --git
a/iotdb-core/tsfile/src/main/java/org/apache/iotdb/tsfile/write/writer/TsFileIOWriter.java
b/iotdb-core/tsfile/src/main/java/org/apache/iotdb/tsfile/write/writer/TsFileIOWriter.java
index e1d54fcf790..12b79a9fc80 100644
---
a/iotdb-core/tsfile/src/main/java/org/apache/iotdb/tsfile/write/writer/TsFileIOWriter.java
+++
b/iotdb-core/tsfile/src/main/java/org/apache/iotdb/tsfile/write/writer/TsFileIOWriter.java
@@ -349,7 +349,7 @@ public class TsFileIOWriter implements AutoCloseable {
}
canWrite = false;
long cost = System.currentTimeMillis() - startTime;
- logger.info("Time for flushing metadata is {} ms", cost);
+ logger.debug("Time for flushing metadata is {} ms", cost);
}
private void checkInMemoryPathCount() {
