From e5091cb4834d0eaf3aaac0a79f82e27e9b6f7373 Mon Sep 17 00:00:00 2001 From: Caideyipi <87789683+Caideyipi@users.noreply.github.com> Date: Fri, 3 Jul 2026 13:00:05 +0800 Subject: [PATCH] Reduce pipe load success log noise --- .../plan/analyze/load/LoadTsFileAnalyzer.java | 49 +++++++++---- .../load/LoadTsFileDispatcherImpl.java | 68 ++++++++++++------- .../scheduler/load/LoadTsFileScheduler.java | 27 ++++++-- .../storageengine/dataregion/DataRegion.java | 36 +++++++--- .../pipe/receiver/IoTDBFileReceiver.java | 10 +-- .../pipe/receiver/IoTDBReceiverAgent.java | 4 +- 6 files changed, 134 insertions(+), 60 deletions(-) diff --git a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/analyze/load/LoadTsFileAnalyzer.java b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/analyze/load/LoadTsFileAnalyzer.java index b1bdd077dc48d..812b62ff721d2 100644 --- a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/analyze/load/LoadTsFileAnalyzer.java +++ b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/analyze/load/LoadTsFileAnalyzer.java @@ -237,7 +237,11 @@ public IAnalysis analyzeFileByFile(IAnalysis analysis) { return analysis; } - LOGGER.info(DataNodeQueryMessages.LOAD_ANALYSIS_STAGE_ALL_TSFILES_HAVE_BEEN_ANALYZED); + if (isGeneratedByPipe) { + LOGGER.debug(DataNodeQueryMessages.LOAD_ANALYSIS_STAGE_ALL_TSFILES_HAVE_BEEN_ANALYZED); + } else { + LOGGER.info(DataNodeQueryMessages.LOAD_ANALYSIS_STAGE_ALL_TSFILES_HAVE_BEEN_ANALYZED); + } setTsFileModelInfoToStatement(); if (reconstructStatementIfMiniFileConverted()) { @@ -318,22 +322,16 @@ private boolean doAnalyzeFileByFile(IAnalysis analysis) { if (LOGGER.isWarnEnabled()) { LOGGER.warn(DataNodeQueryMessages.TSFILE_IS_EMPTY, tsFile.getPath()); } - if (LOGGER.isInfoEnabled()) { - LOGGER.info( - "Load - Analysis Stage: {}/{} tsfiles have been analyzed, progress: {}%", - i + 1, tsfileNum, String.format("%.3f", (i + 1) * 100.00 / tsfileNum)); - } + logAnalyzeProgress(i + 1, tsfileNum); + continue; } final long startTime = System.nanoTime(); try { analyzeSingleTsFile(tsFile, i); - if (LOGGER.isInfoEnabled()) { - LOGGER.info( - "Load - Analysis Stage: {}/{} tsfiles have been analyzed, progress: {}%", - i + 1, tsfileNum, String.format("%.3f", (i + 1) * 100.00 / tsfileNum)); - } + logAnalyzeProgress(i + 1, tsfileNum); + } catch (AuthException e) { setFailAnalysisForAuthException(analysis, e); return false; @@ -370,14 +368,39 @@ private boolean doAnalyzeFileByFile(IAnalysis analysis) { return true; } + private void logAnalyzeProgress(final int analyzedTsFileNum, final int totalTsFileNum) { + if (isGeneratedByPipe && !LOGGER.isDebugEnabled()) { + return; + } + if (!isGeneratedByPipe && !LOGGER.isInfoEnabled()) { + return; + } + + final String progress = String.format("%.3f", analyzedTsFileNum * 100.00 / totalTsFileNum); + if (isGeneratedByPipe) { + LOGGER.debug( + "Load - Analysis Stage: {}/{} tsfiles have been analyzed, progress: {}%", + analyzedTsFileNum, totalTsFileNum, progress); + } else { + LOGGER.info( + "Load - Analysis Stage: {}/{} tsfiles have been analyzed, progress: {}%", + analyzedTsFileNum, totalTsFileNum, progress); + } + } + private void analyzeSingleTsFile(final File tsFile, int i) throws Exception { final SessionInfo sessionInfo = context.getSession(); try (final TsFileSequenceReader reader = new TsFileSequenceReader(tsFile.getAbsolutePath())) { // check whether the tsfile is tree-model or not final Map tableSchemaMap = reader.getTableSchemaMap(); final boolean isTableModelFile = Objects.nonNull(tableSchemaMap) && !tableSchemaMap.isEmpty(); - LOGGER.info( - "TsFile {} is a {}-model file.", tsFile.getPath(), isTableModelFile ? "table" : "tree"); + if (isGeneratedByPipe) { + LOGGER.debug( + "TsFile {} is a {}-model file.", tsFile.getPath(), isTableModelFile ? "table" : "tree"); + } else { + LOGGER.info( + "TsFile {} is a {}-model file.", tsFile.getPath(), isTableModelFile ? "table" : "tree"); + } // can be reused when constructing tsfile resource final TsFileSequenceReaderTimeseriesMetadataIterator timeseriesMetadataIterator = diff --git a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileDispatcherImpl.java b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileDispatcherImpl.java index bd5356ccff49b..220fcccd41fc3 100644 --- a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileDispatcherImpl.java +++ b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileDispatcherImpl.java @@ -74,7 +74,7 @@ import static com.google.common.util.concurrent.Futures.immediateFuture; -public class LoadTsFileDispatcherImpl implements IFragInstanceDispatcher { +public class LoadTsFileDispatcherImpl implements IFragInstanceDispatcher, AutoCloseable { private static final Logger LOGGER = LoggerFactory.getLogger(LoadTsFileDispatcherImpl.class); @@ -88,7 +88,7 @@ public class LoadTsFileDispatcherImpl implements IFragInstanceDispatcher { private final int localhostInternalPort; private final IClientManager internalServiceClientManager; - private final ExecutorService executor; + private ExecutorService executor; private final boolean isGeneratedByPipe; public LoadTsFileDispatcherImpl( @@ -97,11 +97,17 @@ public LoadTsFileDispatcherImpl( this.internalServiceClientManager = internalServiceClientManager; this.localhostIpAddr = IoTDBDescriptor.getInstance().getConfig().getInternalAddress(); this.localhostInternalPort = IoTDBDescriptor.getInstance().getConfig().getInternalPort(); - this.executor = - IoTDBThreadPoolFactory.newCachedThreadPool(LoadTsFileDispatcherImpl.class.getName()); this.isGeneratedByPipe = isGeneratedByPipe; } + private synchronized ExecutorService getOrCreateExecutor() { + if (executor == null || executor.isShutdown()) { + executor = + IoTDBThreadPoolFactory.newCachedThreadPool(LoadTsFileDispatcherImpl.class.getName()); + } + return executor; + } + public void setUuid(String uuid) { this.uuid = uuid; } @@ -109,24 +115,26 @@ public void setUuid(String uuid) { @Override public Future dispatch( SubPlan root, List instances) { - return executor.submit( - () -> { - for (FragmentInstance instance : instances) { - try (SetThreadName threadName = - new SetThreadName( - "load-dispatcher" + "-" + instance.getId().getFullId() + "-" + uuid)) { - dispatchOneInstance(instance); - } catch (FragmentInstanceDispatchException e) { - return new FragInstanceDispatchResult(e.getFailureStatus()); - } catch (Exception t) { - LOGGER.warn(DataNodeQueryMessages.CANNOT_DISPATCH_FI_FOR_LOAD_OPERATION, t); - return new FragInstanceDispatchResult( - RpcUtils.getStatus( - TSStatusCode.INTERNAL_SERVER_ERROR, "Unexpected errors: " + t.getMessage())); - } - } - return new FragInstanceDispatchResult(true); - }); + return getOrCreateExecutor() + .submit( + () -> { + for (FragmentInstance instance : instances) { + try (SetThreadName threadName = + new SetThreadName( + "load-dispatcher" + "-" + instance.getId().getFullId() + "-" + uuid)) { + dispatchOneInstance(instance); + } catch (FragmentInstanceDispatchException e) { + return new FragInstanceDispatchResult(e.getFailureStatus()); + } catch (Exception t) { + LOGGER.warn(DataNodeQueryMessages.CANNOT_DISPATCH_FI_FOR_LOAD_OPERATION, t); + return new FragInstanceDispatchResult( + RpcUtils.getStatus( + TSStatusCode.INTERNAL_SERVER_ERROR, + "Unexpected errors: " + t.getMessage())); + } + } + return new FragInstanceDispatchResult(true); + }); } private void dispatchOneInstance(FragmentInstance instance) @@ -152,7 +160,11 @@ private void dispatchOneInstance(FragmentInstance instance) } public void dispatchLocally(FragmentInstance instance) throws FragmentInstanceDispatchException { - LOGGER.info(DataNodeQueryMessages.RECEIVE_LOAD_NODE_FROM_UUID, uuid); + if (isGeneratedByPipe) { + LOGGER.debug(DataNodeQueryMessages.RECEIVE_LOAD_NODE_FROM_UUID, uuid); + } else { + LOGGER.info(DataNodeQueryMessages.RECEIVE_LOAD_NODE_FROM_UUID, uuid); + } ConsensusGroupId groupId = ConsensusGroupId.Factory.createFromTConsensusGroupId( @@ -360,6 +372,14 @@ private static void adjustTimeoutIfNecessary(Throwable e) { @Override public void abort() { - // Do nothing + close(); + } + + @Override + public synchronized void close() { + if (executor != null) { + executor.shutdownNow(); + executor = null; + } } } diff --git a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileScheduler.java b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileScheduler.java index e2db158475aca..205b9e8ec3f2d 100644 --- a/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileScheduler.java +++ b/iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/scheduler/load/LoadTsFileScheduler.java @@ -251,11 +251,19 @@ public void start() { if (isLoadSingleTsFileSuccess) { node.clean(); - LOGGER.info( - "Load TsFile {} Successfully, load process [{}/{}]", - filePath, - i + 1, - tsFileNodeListSize); + if (isGeneratedByPipe) { + LOGGER.debug( + "Load TsFile {} Successfully, load process [{}/{}]", + filePath, + i + 1, + tsFileNodeListSize); + } else { + LOGGER.info( + "Load TsFile {} Successfully, load process [{}/{}]", + filePath, + i + 1, + tsFileNodeListSize); + } } else { isLoadSuccess = false; failedTsFileNodeIndexes.add(i); @@ -308,6 +316,7 @@ public void start() { } } } finally { + dispatcher.close(); LoadTsFileMemoryManager.getInstance().releaseDataCacheMemoryBlock(); } } @@ -398,7 +407,11 @@ private boolean dispatchOnePieceNode( private boolean secondPhase( boolean isFirstPhaseSuccess, String uuid, TsFileResource tsFileResource) { - LOGGER.info(DataNodeQueryMessages.START_DISPATCHING_LOAD_COMMAND_FOR_UUID, uuid); + if (isGeneratedByPipe) { + LOGGER.debug(DataNodeQueryMessages.START_DISPATCHING_LOAD_COMMAND_FOR_UUID, uuid); + } else { + LOGGER.info(DataNodeQueryMessages.START_DISPATCHING_LOAD_COMMAND_FOR_UUID, uuid); + } final File tsFile = tsFileResource.getTsFile(); final TLoadCommandReq loadCommandReq = new TLoadCommandReq( @@ -662,7 +675,7 @@ private LoadTsFileStatement buildRetryTreeLoadStatement( @Override public void stop(Throwable t) { - // Do nothing + dispatcher.abort(); } @Override 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 03807c60d74c1..d7eb05664e13e 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 @@ -4144,10 +4144,17 @@ public void loadNewTsFile( 0); if (!newFileName.equals(tsfileToBeInserted.getName())) { - logger.info( - "TsFile {} must be renamed to {} for loading into the unsequence list.", - tsfileToBeInserted.getName(), - newFileName); + if (isGeneratedByPipe) { + logger.debug( + "TsFile {} must be renamed to {} for loading into the unsequence list.", + tsfileToBeInserted.getName(), + newFileName); + } else { + logger.info( + "TsFile {} must be renamed to {} for loading into the unsequence list.", + tsfileToBeInserted.getName(), + newFileName); + } newTsFileResource.setFile( fsFactory.getFile(tsfileToBeInserted.getParentFile(), newFileName)); } @@ -4196,7 +4203,11 @@ public void loadNewTsFile( } onTsFileLoaded(newTsFileResource, isFromConsensus, lastReader); - logger.info(StorageEngineMessages.TSFILE_LOADED_IN_UNSEQ_LIST, newFileName); + if (isGeneratedByPipe) { + logger.debug(StorageEngineMessages.TSFILE_LOADED_IN_UNSEQ_LIST, newFileName); + } else { + logger.info(StorageEngineMessages.TSFILE_LOADED_IN_UNSEQ_LIST, newFileName); + } } catch (final DiskSpaceInsufficientException e) { logger.error( "Failed to append the tsfile {} to database processor {} because the disk space is insufficient.", @@ -4350,10 +4361,17 @@ private boolean loadTsFileToUnSequence( return false; } - logger.info( - "Load tsfile in unsequence list, move file from {} to {}", - tsFileToLoad.getAbsolutePath(), - targetFile.getAbsolutePath()); + if (isGeneratedByPipe) { + logger.debug( + "Load tsfile in unsequence list, move file from {} to {}", + tsFileToLoad.getAbsolutePath(), + targetFile.getAbsolutePath()); + } else { + logger.info( + "Load tsfile in unsequence list, move file from {} to {}", + tsFileToLoad.getAbsolutePath(), + targetFile.getAbsolutePath()); + } LoadTsFileRateLimiter.getInstance().acquire(tsFileResource.getTsFile().length()); diff --git a/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBFileReceiver.java b/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBFileReceiver.java index 8304161c9d0db..591d9d19a558f 100644 --- a/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBFileReceiver.java +++ b/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBFileReceiver.java @@ -441,7 +441,7 @@ protected final void updateWritingFileIfNeeded(final String fileName, final bool return; } - LOGGER.info( + LOGGER.debug( PipeMessages.RECEIVER_WRITING_FILE_NOT_EXIST, receiverId.get(), fileName, @@ -458,7 +458,7 @@ protected final void updateWritingFileIfNeeded(final String fileName, final bool // This may be useless, because receiver file dir is created when handshake. just in case. if (!receiverFileDirWithIdSuffix.get().exists()) { if (receiverFileDirWithIdSuffix.get().mkdirs()) { - LOGGER.info( + LOGGER.debug( PipeMessages.RECEIVER_FILE_DIR_CREATED, receiverId.get(), receiverFileDirWithIdSuffix.get().getPath()); @@ -473,7 +473,7 @@ protected final void updateWritingFileIfNeeded(final String fileName, final bool writingFile = targetPath.toFile(); writingFileWriter = new RandomAccessFile(writingFile, "rw"); - LOGGER.info( + LOGGER.debug( PipeMessages.RECEIVER_WRITING_FILE_CREATED, receiverId.get(), writingFile.getPath()); } @@ -630,7 +630,7 @@ protected final TPipeTransferResp handleTransferFileSealV1(final PipeTransferFil final TSStatus status = loadFileV1(req, fileAbsolutePath); if (status.getCode() == TSStatusCode.SUCCESS_STATUS.getStatusCode()) { shouldDeleteSealedFile = false; - LOGGER.info(PipeMessages.RECEIVER_SEAL_FILE_SUCCESS, receiverId.get(), fileAbsolutePath); + LOGGER.debug(PipeMessages.RECEIVER_SEAL_FILE_SUCCESS, receiverId.get(), fileAbsolutePath); } else { PipeLogger.log( LOGGER::warn, @@ -738,7 +738,7 @@ protected final TPipeTransferResp handleTransferFileSealV2(final PipeTransferFil final TSStatus status = loadFileV2(req, fileAbsolutePaths); if (status.getCode() == TSStatusCode.SUCCESS_STATUS.getStatusCode()) { - LOGGER.info(PipeMessages.RECEIVER_SEAL_FILE_SUCCESS, receiverId.get(), fileAbsolutePaths); + LOGGER.debug(PipeMessages.RECEIVER_SEAL_FILE_SUCCESS, receiverId.get(), fileAbsolutePaths); } else { PipeLogger.log( LOGGER::warn, diff --git a/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBReceiverAgent.java b/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBReceiverAgent.java index c51f36d78f004..e718300978b05 100644 --- a/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBReceiverAgent.java +++ b/iotdb-core/node-commons/src/main/java/org/apache/iotdb/commons/pipe/receiver/IoTDBReceiverAgent.java @@ -117,14 +117,14 @@ public static void cleanPipeReceiverDir(final File receiverFileDir) { FileUtils.deleteDirectory(receiverFileDir); return null; }); - LOGGER.info(PipeMessages.CLEAN_RECEIVER_DIR_SUCCESS, receiverFileDir); + LOGGER.debug(PipeMessages.CLEAN_RECEIVER_DIR_SUCCESS, receiverFileDir); } catch (final Exception e) { LOGGER.warn(PipeMessages.CLEAN_RECEIVER_DIR_FAILED, receiverFileDir, e); } try { FileUtils.forceMkdir(receiverFileDir); - LOGGER.info(PipeMessages.CREATE_RECEIVER_DIR_SUCCESS, receiverFileDir); + LOGGER.debug(PipeMessages.CREATE_RECEIVER_DIR_SUCCESS, receiverFileDir); } catch (final IOException e) { LOGGER.warn(PipeMessages.CREATE_RECEIVER_DIR_FAILED, receiverFileDir, e); }