Skip to content

Commit edb8931

Browse files
authored
[Test](Export) add some debug logs for export (#47400)
add some debug logs for export
1 parent b6318e7 commit edb8931

File tree

2 files changed

+35
-1
lines changed

2 files changed

+35
-1
lines changed

fe/fe-core/src/main/java/org/apache/doris/load/ExportTaskExecutor.java

+34
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,8 @@
4141

4242
import com.google.common.collect.Lists;
4343
import lombok.extern.slf4j.Slf4j;
44+
import org.apache.logging.log4j.LogManager;
45+
import org.apache.logging.log4j.Logger;
4446

4547
import java.util.List;
4648
import java.util.Map;
@@ -50,6 +52,7 @@
5052

5153
@Slf4j
5254
public class ExportTaskExecutor implements TransientTaskExecutor {
55+
private static final Logger LOG = LogManager.getLogger(ExportTaskExecutor.class);
5356

5457
List<StatementBase> selectStmtLists;
5558

@@ -78,22 +81,32 @@ public Long getId() {
7881

7982
@Override
8083
public void execute() throws JobException {
84+
LOG.debug("[Export Task] taskId: {} starting execution", taskId);
8185
if (isCanceled.get()) {
86+
LOG.debug("[Export Task] taskId: {} was already canceled before execution", taskId);
8287
throw new JobException("Export executor has been canceled, task id: {}", taskId);
8388
}
89+
LOG.debug("[Export Task] taskId: {} updating state to EXPORTING", taskId);
8490
exportJob.updateExportJobState(ExportJobState.EXPORTING, taskId, null, null, null);
8591
List<OutfileInfo> outfileInfoList = Lists.newArrayList();
8692
for (int idx = 0; idx < selectStmtLists.size(); ++idx) {
93+
LOG.debug("[Export Task] taskId: {} processing statement {}/{}",
94+
taskId, idx + 1, selectStmtLists.size());
8795
if (isCanceled.get()) {
96+
LOG.debug("[Export Task] taskId: {} canceled during execution at statement {}", taskId, idx + 1);
8897
throw new JobException("Export executor has been canceled, task id: {}", taskId);
8998
}
9099
// check the version of tablets, skip if the consistency is in partition level.
91100
if (exportJob.getExportTable().isManagedTable() && !exportJob.isPartitionConsistency()) {
101+
LOG.debug("[Export Task] taskId: {} checking tablet versions for statement {}", taskId, idx + 1);
92102
try {
93103
Database db = Env.getCurrentEnv().getInternalCatalog().getDbOrAnalysisException(
94104
exportJob.getTableName().getDb());
95105
OlapTable table = db.getOlapTableOrAnalysisException(exportJob.getTableName().getTbl());
106+
LOG.debug("[Export Lock] taskId: {}, table: {} about to acquire readLock",
107+
taskId, table.getName());
96108
table.readLock();
109+
LOG.debug("[Export Lock] taskId: {}, table: {} acquired readLock", taskId, table.getName());
97110
try {
98111
List<Long> tabletIds;
99112
LogicalPlanAdapter logicalPlanAdapter = (LogicalPlanAdapter) selectStmtLists.get(idx);
@@ -108,18 +121,26 @@ public void execute() throws JobException {
108121
long nowVersion = partition.getVisibleVersion();
109122
long oldVersion = exportJob.getPartitionToVersion().get(partition.getName());
110123
if (nowVersion != oldVersion) {
124+
LOG.debug("[Export Lock] taskId: {}, table: {} about to release readLock"
125+
+ "due to version mismatch", taskId, table.getName());
111126
exportJob.updateExportJobState(ExportJobState.CANCELLED, taskId, null,
112127
CancelType.RUN_FAIL, "The version of tablet {" + tabletId + "} has changed");
113128
throw new JobException("Export Job[{}]: Tablet {} has changed version, old version = {}"
114129
+ ", now version = {}", exportJob.getId(), tabletId, oldVersion, nowVersion);
115130
}
116131
}
117132
} catch (Exception e) {
133+
LOG.debug("[Export Lock] taskId: {}, table: {} about to release readLock"
134+
+ "due to exception: {}", taskId, table.getName(), e.getMessage());
118135
exportJob.updateExportJobState(ExportJobState.CANCELLED, taskId, null,
119136
ExportFailMsg.CancelType.RUN_FAIL, e.getMessage());
120137
throw new JobException(e);
121138
} finally {
139+
LOG.debug("[Export Lock] taskId: {}, table: {} releasing readLock in finally block",
140+
taskId, table.getName());
122141
table.readUnlock();
142+
LOG.debug("[Export Lock] taskId: {}, table: {} released readLock successfully",
143+
taskId, table.getName());
123144
}
124145
} catch (AnalysisException e) {
125146
exportJob.updateExportJobState(ExportJobState.CANCELLED, taskId, null,
@@ -129,26 +150,39 @@ public void execute() throws JobException {
129150
}
130151

131152
try (AutoCloseConnectContext r = buildConnectContext()) {
153+
LOG.debug("[Export Task] taskId: {} executing statement {}", taskId, idx + 1);
132154
stmtExecutor = new StmtExecutor(r.connectContext, selectStmtLists.get(idx));
133155
stmtExecutor.execute();
134156
if (r.connectContext.getState().getStateType() == MysqlStateType.ERR) {
157+
LOG.debug("[Export Task] taskId: {} failed with MySQL error: {}", taskId,
158+
r.connectContext.getState().getErrorMessage());
135159
exportJob.updateExportJobState(ExportJobState.CANCELLED, taskId, null,
136160
ExportFailMsg.CancelType.RUN_FAIL, r.connectContext.getState().getErrorMessage());
137161
return;
138162
}
163+
LOG.debug("[Export Task] taskId: {} statement {} executed successfully", taskId, idx + 1);
139164
OutfileInfo outfileInfo = getOutFileInfo(r.connectContext.getResultAttachedInfo());
165+
LOG.debug("[Export Task] taskId: {} got outfile info for statement {}:"
166+
+ "fileNumber={}, totalRows={}, fileSize={}",
167+
taskId, idx + 1, outfileInfo.getFileNumber(),
168+
outfileInfo.getTotalRows(), outfileInfo.getFileSize());
140169
outfileInfoList.add(outfileInfo);
141170
} catch (Exception e) {
171+
LOG.debug("[Export Task] taskId: {} failed with exception during statement {}: {}",
172+
taskId, idx + 1, e.getMessage(), e);
142173
exportJob.updateExportJobState(ExportJobState.CANCELLED, taskId, null,
143174
ExportFailMsg.CancelType.RUN_FAIL, e.getMessage());
144175
throw new JobException(e);
145176
}
146177
}
147178
if (isCanceled.get()) {
179+
LOG.debug("[Export Task] taskId: {} canceled after processing all statements", taskId);
148180
throw new JobException("Export executor has been canceled, task id: {}", taskId);
149181
}
182+
LOG.debug("[Export Task] taskId: {} completed successfully, updating state to FINISHED", taskId);
150183
exportJob.updateExportJobState(ExportJobState.FINISHED, taskId, outfileInfoList, null, null);
151184
isFinished.getAndSet(true);
185+
LOG.debug("[Export Task] taskId: {} execution completed", taskId);
152186
}
153187

154188
@Override

regression-test/pipeline/p0/conf/fe.conf

+1-1
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@ JAVA_OPTS_FOR_JDK_17="-Djavax.security.auth.useSubjectCredsOnly=false -Xmx8192m
3434

3535
sys_log_level = INFO
3636
sys_log_mode = NORMAL
37-
sys_log_verbose_modules = org.apache.doris.common.profile,org.apache.doris.qe.QeProcessorImpl
37+
sys_log_verbose_modules = org.apache.doris.common.profile,org.apache.doris.qe.QeProcessorImpl,org.apache.doris.load.ExportTaskExecutor
3838
arrow_flight_sql_port = 8081
3939
catalog_trash_expire_second=1
4040
#enable ssl for test

0 commit comments

Comments
 (0)