Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug] After inserting data, it takes a long time to retrieve the data. #45115

Open
2 of 3 tasks
Dong-GuoSheng opened this issue Dec 6, 2024 · 1 comment
Open
2 of 3 tasks

[Bug] After inserting data, it takes a long time to retrieve the data. #45115

Dong-GuoSheng opened this issue Dec 6, 2024 · 1 comment

Comments

@Dong-GuoSheng
Copy link

Dong-GuoSheng commented Dec 6, 2024 •
edited
Loading

Search before asking

  • I had searched in the issues and found no similar issues.

Version

2.1.5-rc02-d5a02e095d

What's Wrong?

I wrote a piece of data using the insert into method through the mysql client at 9:20:54, and it was successfully executed 10 seconds later.
But I couldn't find it. It was only when I checked around 9:34 that I found the data I had just inserted. The table type for the insert into statement is unique.
Doris version: 2.1.5-rc02-d5a02e095d
The cluster shares 3 be and 3 fe.
The relevant logs are as follows:
我在9:20:54时通过mysql客户端使用insert into的方式写入了一条数据，10秒后执行成功。
但查询查询不到，等到了9:34分左右的时候，我才查询到我刚才写入的数据。insert into的表类型为unique。

doris版本：2.1.5-rc02-d5a02e095d
集群共用3个be、3个fe。
相关日志如下：

2024-12-06 08:57:04,671 INFO (PUBLISH_VERSION|32) [DatabaseTransactionMgr.finishTransaction():1080] finish transaction TransactionState. transaction id: 9058526, label: label_58791eca450d4619_adee84e7487fa34b, db id: 41122805, table id list: 43591537, callback id: -1, coordinator: FE: 10.1.13.159, transaction status: VISIBLE, error replicas num: 0, replica ids: , prepare time: 1733446622916, commit time: 1733446624657, finish time: 1733446624670, reason: successfully, publish times 1, publish result QUORUM_SUCC
2024-12-06 08:57:04,671 WARN (mtmv-task-execute-1-thread-9|131) [StmtExecutor.updateProfile():1088] failed to update profile, ignore this error
java.lang.NullPointerException: null
at org.apache.doris.qe.StmtExecutor.getSummaryInfo(StmtExecutor.java:378) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.updateProfile(StmtExecutor.java:1086) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.AbstractInsertExecutor.executeSingleInsert(AbstractInsertExecutor.java:195) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.runInternal(InsertIntoTableCommand.java:219) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.run(InsertIntoTableCommand.java:105) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.runInsertCommand(InsertOverwriteTableCommand.java:211) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.insertInto(InsertOverwriteTableCommand.java:274) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.run(InsertOverwriteTableCommand.java:182) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.exec(MTMVTask.java:239) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.run(MTMVTask.java:201) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.task.AbstractTask.runTask(AbstractTask.java:167) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.runTask(MTMVTask.java:314) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:50) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:33) ~[doris-fe.jar:1.2-SNAPSHOT]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) ~[disruptor-3.4.4.jar:?]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_171]
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [OlapTable.renamePartition():884] rename partition sdos_find_view in table sdos_find_view
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [OlapTable.updateVisibleVersionAndTime():2714] updateVisibleVersionAndTime, tableName: sdos_find_view, visibleVersion, 28311, visibleVersionTime: 1733446624672
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [MTMVService.processEvent():179] processEvent, Event: TableEvent{ctlId=0, dbId=41122805, tableId=43591537} Event{eventId=43873390, eventTime=1733446624672, eventType=REPLACE_PARTITION}
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [EditLog.logReplaceTempPartition():1841] log replace temp partition, logId: 30363433, info: {
"dbId": 41122805,
"dbName": "sinoicya",
"tblId": 43591537,
"tblName": "sdos_find_view",
"partitions": [
"sdos_find_view"
],
"tempPartitions": [
"iot_temp_sdos_find_view"
],
"strictRange": false,
"useTempPartitionName": false,
"version": 28311,
"versionTime": 1733446624672
}
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [Env.replaceTempPartition():5689] finished to replace partitions [sdos_find_view] with temp partitions [iot_temp_sdos_find_view] from table: sdos_find_view
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [InsertOverwriteManager.taskSuccess():180] insert overwrite task [43873375] succeed
2024-12-06 08:57:04,672 INFO (mtmv-task-execute-1-thread-9|131) [InsertOverwriteManager.removeTask():206] remove insert overwrite task: InsertOverwriteTask{cancel=false, dbId=41122805, tableId=43591537, tempPartitionNames=[iot_temp_sdos_find_view]}
2024-12-06 08:57:04,678 INFO (mtmv-task-execute-1-thread-9|131) [MTMVService.refreshComplete():142] refreshComplete: sdos_find_view
2024-12-06 08:57:04,678 INFO (mtmv-task-execute-1-thread-9|131) [MTMVRelationManager.refreshMTMVCache():125] refreshMTMVCache,relation: org.apache.doris.mtmv.MTMVRelation@1aa8ec50, mtmvInfo: BaseTableInfo{tableId=43591537, dbId=41122805, ctlId=0}
2024-12-06 08:57:04,678 INFO (mtmv-task-execute-1-thread-9|131) [MTMVService.alterMTMV():109] alterMTMV, mtmvName: sdos_find_view, AlterMTMV: AlterMTMV{mvName=org.apache.doris.nereids.trees.plans.commands.info.TableNameInfo@58984423, refreshInfo=null, status=null, needRebuildJob=false, mvProperties=null, task=MTMVTask{dbId=41122805, mtmvId=43591537, taskContext=MTMVTaskContext{triggerMode=COMMIT, partitions=[], isComplete=false}, needRefreshPartitions=[sdos_find_view], completedPartitions=[sdos_find_view], refreshMode=COMPLETE} AbstractTask{jobId=43591541, taskId=20305746292345090, status=SUCCESS, createTimeMs=1733446621159, startTimeMs=1733446622893, finishTimeMs=1733446624673, taskType=MANUAL, errMsg='null'}, relation=org.apache.doris.mtmv.MTMVRelation@1aa8ec50}
2024-12-06 08:57:04,692 INFO (mtmv-task-execute-1-thread-1|123) [PropertyAnalyzer.analyzeDataProperty():270] Can not assign cool down timestamp to HDD storage medium, ignore user setting.
2024-12-06 08:57:04,696 INFO (mtmv-task-execute-1-thread-1|123) [InternalCatalog.createPartitionWithIndices():2052] succeed in creating partition[43873392-iot_temp_sdos_find_view], table : [43591537-sdos_find_view]
2024-12-06 08:57:04,696 INFO (mtmv-task-execute-1-thread-1|123) [InternalCatalog.addPartition():1729] succeed in creating partition[43873392], temp: true
2024-12-06 08:57:04,703 INFO (mtmv-task-execute-1-thread-1|123) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058535 with label label_bd86b4003f3f49f0_a79b45a3e97b3114 from coordinator FE: 10.1.13.159, listener id: -1
2024-12-06 08:57:04,703 INFO (mtmv-task-execute-1-thread-1|123) [OlapInsertExecutor.beforeExec():180] start insert [label_bd86b4003f3f49f0_a79b45a3e97b3114] with query id bd86b4003f3f49f0-a79b45a3e97b3114 and txn id 9058535
2024-12-06 08:57:04,703 WARN (mtmv-task-execute-1-thread-1|123) [StmtExecutor.updateProfile():1088] failed to update profile, ignore this error
java.lang.NullPointerException: null
at org.apache.doris.qe.StmtExecutor.getSummaryInfo(StmtExecutor.java:378) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.updateProfile(StmtExecutor.java:1086) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.AbstractInsertExecutor.execImpl(AbstractInsertExecutor.java:131) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.AbstractInsertExecutor.executeSingleInsert(AbstractInsertExecutor.java:187) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.runInternal(InsertIntoTableCommand.java:219) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.run(InsertIntoTableCommand.java:105) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.runInsertCommand(InsertOverwriteTableCommand.java:211) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.insertInto(InsertOverwriteTableCommand.java:274) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.run(InsertOverwriteTableCommand.java:182) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.exec(MTMVTask.java:239) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.run(MTMVTask.java:201) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.task.AbstractTask.runTask(AbstractTask.java:167) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.runTask(MTMVTask.java:314) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:50) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:33) ~[doris-fe.jar:1.2-SNAPSHOT]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) ~[disruptor-3.4.4.jar:?]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_171]
2024-12-06 08:57:04,703 INFO (mtmv-task-execute-1-thread-1|123) [Coordinator.execInternal():745] dispatch load job: bd86b4003f3f49f0-a79b45a3e97b3114 to [TNetworkAddress(hostname:10.1.13.157, port:9060), TNetworkAddress(hostname:10.1.13.159, port:9060)]
2024-12-06 08:57:04,704 INFO (mtmv-task-execute-1-thread-1|123) [Coordinator.sendFragment():876] num local sink for backend 10018 is 1
2024-12-06 08:57:04,707 INFO (thrift-server-pool-54|111235) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058536 with label sdos_new_info_load_1733446987918 from coordinator BE: 10.1.13.158, listener id: -1
2024-12-06 08:57:04,708 INFO (thrift-server-pool-18|3794) [FileGroupInfo.getFileStatusAndCalcInstance():196] number instance of file scan node is: 1, bytes per instance: 9223372036854775807
2024-12-06 08:57:04,770 INFO (report-thread|214) [ReportHandler.taskReport():582] finished to handle task report from backend 6907075, diff task num: 0. cost: 0 ms
2024-12-06 08:57:04,770 INFO (thrift-server-pool-34|5862) [ReportHandler.handleReport():206] receive report from be 6907075. type: TASK, current queue size: 1
2024-12-06 08:57:04,900 INFO (thrift-server-pool-10|1312) [DatabaseTransactionMgr.commitTransaction():798] transaction:[TransactionState. transaction id: 9058536, label: sdos_new_info_load_1733446987918, db id: 41122805, table id list: 43589035, callback id: -1, coordinator: BE: 10.1.13.158, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1733446624707, commit time: 1733446624899, finish time: -1, reason: ] successfully committed
2024-12-06 08:57:04,903 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058536, db: 41122805
2024-12-06 08:57:04,904 INFO (thrift-server-pool-24|4167) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058537 with label sdos_new_info_load_1733446988116 from coordinator BE: 10.1.13.158, listener id: -1
2024-12-06 08:57:04,905 INFO (thrift-server-pool-19|3795) [FileGroupInfo.getFileStatusAndCalcInstance():196] number instance of file scan node is: 1, bytes per instance: 9223372036854775807
2024-12-06 08:57:04,913 INFO (PUBLISH_VERSION|32) [OlapTable.updateVisibleVersionAndTime():2714] updateVisibleVersionAndTime, tableName: sdos_new_info, visibleVersion, 120628, visibleVersionTime: 1733446624913
2024-12-06 08:57:04,914 INFO (PUBLISH_VERSION|32) [MTMVService.processEvent():179] processEvent, Event: TableEvent{ctlId=0, dbId=41122805, tableId=43589035} Event{eventId=43873395, eventTime=1733446624914, eventType=DATA_CHANGE}
2024-12-06 08:57:04,914 INFO (PUBLISH_VERSION|32) [JobManager.triggerJob():259] trigger job, job id is 43591541
2024-12-06 08:57:04,914 INFO (PUBLISH_VERSION|32) [MTMVJob.createTasks():128] begin create mtmv task, jobId: 43591541, taskContext: MTMVTaskContext{triggerMode=COMMIT, partitions=[], isComplete=false}
2024-12-06 08:57:04,914 INFO (PUBLISH_VERSION|32) [MTMVJob.createTasks():137] finish create mtmv task, task: MTMVTask{dbId=41122805, mtmvId=43591537, taskContext=MTMVTaskContext{triggerMode=COMMIT, partitions=[], isComplete=false}, needRefreshPartitions=null, completedPartitions=null, refreshMode=null} AbstractTask{jobId=43591541, taskId=20305751780084259, status=PENDING, createTimeMs=1733446624914, startTimeMs=null, finishTimeMs=null, taskType=MANUAL, errMsg='null'}
2024-12-06 08:57:04,914 INFO (PUBLISH_VERSION|32) [AbstractJob.lambda$commonCreateTasks$4():231] common create task, job id is 43591541, task id is 20305751780084259
2024-12-06 08:57:05,005 INFO (thrift-server-pool-22|3926) [QeProcessorImpl.reportExecStatus():211] ReportExecStatus(): fragment_instance_id=bd86b4003f3f49f0-a79b45a3e97b3115, query id=bd86b4003f3f49f0-a79b45a3e97b3114, backend num: 2, ip: TNetworkAddress(hostname:10.1.13.159, port:45904)
2024-12-06 08:57:05,125 INFO (thrift-server-pool-25|4168) [DatabaseTransactionMgr.commitTransaction():798] transaction:[TransactionState. transaction id: 9058537, label: sdos_new_info_load_1733446988116, db id: 41122805, table id list: 43589035, callback id: -1, coordinator: BE: 10.1.13.158, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1733446624904, commit time: 1733446625124, finish time: -1, reason: ] successfully committed
2024-12-06 08:57:05,390 INFO (thrift-server-pool-27|4305) [QeProcessorImpl.reportExecStatus():211] ReportExecStatus(): fragment_instance_id=bd86b4003f3f49f0-a79b45a3e97b3116, query id=bd86b4003f3f49f0-a79b45a3e97b3114, backend num: 1, ip: TNetworkAddress(hostname:10.1.13.157, port:44468)
2024-12-06 08:57:06,922 INFO (thrift-server-pool-53|111211) [QeProcessorImpl.reportExecStatus():211] ReportExecStatus(): fragment_instance_id=bd86b4003f3f49f0-a79b45a3e97b3117, query id=bd86b4003f3f49f0-a79b45a3e97b3114, backend num: 0, ip: TNetworkAddress(hostname:10.1.13.157, port:55258)
2024-12-06 08:57:06,923 INFO (mtmv-task-execute-1-thread-1|123) [DatabaseTransactionMgr.commitTransaction():798] transaction:[TransactionState. transaction id: 9058535, label: label_bd86b4003f3f49f0_a79b45a3e97b3114, db id: 41122805, table id list: 43591537, callback id: -1, coordinator: FE: 10.1.13.159, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1733446624703, commit time: 1733446626922, finish time: -1, reason: ] successfully committed
2024-12-06 08:57:07,288 INFO (report-thread|214) [ReportHandler.taskReport():582] finished to handle task report from backend 10038, diff task num: 0. cost: 0 ms
2024-12-06 08:57:07,288 INFO (thrift-server-pool-35|6147) [ReportHandler.handleReport():206] receive report from be 10038. type: TASK, current queue size: 1
2024-12-06 08:57:09,647 INFO (report-thread|214) [ReportHandler.diskReport():587] begin to handle disk report from backend 10018
2024-12-06 08:57:09,647 INFO (thrift-server-pool-2|272) [ReportHandler.handleReport():206] receive report from be 10018. type: DISK, current queue size: 1
2024-12-06 08:57:09,647 INFO (report-thread|214) [ReportHandler.diskReport():598] finished to handle disk report from backend: 10018, disk size: 7, bad disk: [], cost: 0 ms
2024-12-06 08:57:09,647 INFO (report-thread|214) [ReportHandler.cpuReport():603] begin to handle cpu report from backend 10018
2024-12-06 08:57:09,647 INFO (report-thread|214) [ReportHandler.cpuReport():617] finished to handle cpu report from backend 10018, cost: 0 ms
2024-12-06 08:57:09,832 INFO (tablet checker|42) [TabletChecker.checkTablets():347] finished to check tablets. unhealth/total/added/in_sched/not_ready: 1/33088/0/0/0, cost: 47 ms
2024-12-06 08:57:09,993 INFO (colocate group clone checker|111) [ColocateTableCheckerAndBalancer.matchGroups():586] finished to check tablets. unhealth/total/added/in_sched/not_ready: 0/0/0/0/0, cost: 0 ms
2024-12-06 08:57:11,885 INFO (thrift-server-pool-5|384) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058538 with label xxyyyKAFKAXT2024120617334465623722720305687200109537bcp from coordinator BE: 10.1.13.159, listener id: -1
2024-12-06 08:57:11,886 INFO (thrift-server-pool-22|3926) [FileGroupInfo.getFileStatusAndCalcInstance():196] number instance of file scan node is: 1, bytes per instance: 9223372036854775807
2024-12-06 08:57:12,690 INFO (report-thread|214) [ReportHandler.diskReport():587] begin to handle disk report from backend 6907075
2024-12-06 08:57:12,690 INFO (thrift-server-pool-16|3683) [ReportHandler.handleReport():206] receive report from be 6907075. type: DISK, current queue size: 1
2024-12-06 08:57:12,690 INFO (report-thread|214) [ReportHandler.diskReport():598] finished to handle disk report from backend: 6907075, disk size: 7, bad disk: [], cost: 0 ms
2024-12-06 08:57:12,690 INFO (report-thread|214) [ReportHandler.cpuReport():603] begin to handle cpu report from backend 6907075
2024-12-06 08:57:12,690 INFO (report-thread|214) [ReportHandler.cpuReport():617] finished to handle cpu report from backend 6907075, cost: 0 ms
2024-12-06 08:57:13,237 INFO (thrift-server-pool-37|9192) [DatabaseTransactionMgr.commitTransaction():798] transaction:[TransactionState. transaction id: 9058538, label: xxyyyKAFKAXT2024120617334465623722720305687200109537bcp, db id: 13012, table id list: 17780815, callback id: -1, coordinator: BE: 10.1.13.159, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1733446631884, commit time: 1733446633236, finish time: -1, reason: ] successfully committed
2024-12-06 08:57:14,031 INFO (InsertOverwriteDropDirtyPartitions|74) [InsertOverwriteManager.runAfterCatalogReady():260] start clean insert overwrite temp partitions
2024-12-06 08:57:14,828 INFO (binlog-gcer|59) [BinlogManager.gc():373] begin gc binlog
2024-12-06 08:57:14,828 INFO (binlog-gcer|59) [BinlogManager.gc():384] gc binlog, dbBinlogMap is null
2024-12-06 08:57:14,828 INFO (binlog-gcer|59) [BinlogGcer.runAfterCatalogReady():63] no gc binlog
2024-12-06 08:57:15,771 INFO (report-thread|214) [ReportHandler.taskReport():582] finished to handle task report from backend 6907075, diff task num: 0. cost: 0 ms
2024-12-06 08:57:15,771 INFO (thrift-server-pool-4|282) [ReportHandler.handleReport():206] receive report from be 6907075. type: TASK, current queue size: 1
2024-12-06 08:57:16,922 WARN (mtmv-task-execute-1-thread-1|123) [StmtExecutor.updateProfile():1088] failed to update profile, ignore this error
java.lang.NullPointerException: null
at org.apache.doris.qe.StmtExecutor.getSummaryInfo(StmtExecutor.java:378) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.qe.StmtExecutor.updateProfile(StmtExecutor.java:1086) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.AbstractInsertExecutor.executeSingleInsert(AbstractInsertExecutor.java:195) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.runInternal(InsertIntoTableCommand.java:219) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.run(InsertIntoTableCommand.java:105) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.runInsertCommand(InsertOverwriteTableCommand.java:211) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.insertInto(InsertOverwriteTableCommand.java:274) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.nereids.trees.plans.commands.insert.InsertOverwriteTableCommand.run(InsertOverwriteTableCommand.java:182) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.exec(MTMVTask.java:239) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.run(MTMVTask.java:201) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.task.AbstractTask.runTask(AbstractTask.java:167) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.extensions.mtmv.MTMVTask.runTask(MTMVTask.java:314) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:50) ~[doris-fe.jar:1.2-SNAPSHOT]
at org.apache.doris.job.executor.DefaultTaskExecutorHandler.onEvent(DefaultTaskExecutorHandler.java:33) ~[doris-fe.jar:1.2-SNAPSHOT]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) ~[disruptor-3.4.4.jar:?]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_171]
2024-12-06 08:57:16,923 INFO (mtmv-task-execute-1-thread-1|123) [OlapTable.renamePartition():884] rename partition sdos_find_view in table sdos_find_view
2024-12-06 08:57:16,923 INFO (mtmv-task-execute-1-thread-1|123) [OlapTable.updateVisibleVersionAndTime():2714]
2024-12-06 08:57:16,924 INFO (mtmv-task-execute-1-thread-1|123) [Env.replaceTempPartition():5689] finished to replace partitions [sdos_find_view] with temp partitions [iot_temp_sdos_find_view] from table: sdos_find_view
2024-12-06 08:57:16,924 INFO (mtmv-task-execute-1-thread-1|123) [InsertOverwriteManager.taskSuccess():180] insert overwrite task [43873391] succeed
2024-12-06 08:57:16,924 INFO (mtmv-task-execute-1-thread-1|123) [InsertOverwriteManager.removeTask():206] remove insert overwrite task: InsertOverwriteTask{cancel=false, dbId=41122805, tableId=43591537, tempPartitionNames=[iot_temp_sdos_find_view]}
2024-12-06 08:57:16,930 INFO (mtmv-task-execute-1-thread-1|123) [MTMVService.refreshComplete():142] refreshComplete: sdos_find_view
2024-12-06 08:57:16,930 INFO (mtmv-task-execute-1-thread-1|123) [MTMVRelationManager.refreshMTMVCache():125] refreshMTMVCache,relation: org.apache.doris.mtmv.MTMVRelation@6e883eb6, mtmvInfo: BaseTableInfo{tableId=43591537, dbId=41122805, ctlId=0}
2024-12-06 08:57:16,930 INFO (mtmv-task-execute-1-thread-1|123) [MTMVService.alterMTMV():109] alterMTMV, mtmvName: sdos_find_view, AlterMTMV:
2024-12-06 08:57:43,318 INFO (thrift-server-pool-18|3794) [QeProcessorImpl.reportExecStatus():211] ReportExecStatus(): fragment_instance_id=9035e3a4ecf42ee-9170844d89ae96b3, query id=9035e3a4ecf42ee-9170844d89ae96b2, backend num: 0, ip: TNetworkAddress(hostname:10.1.13.158, port:47428)
2024-12-06 08:57:43,319 INFO (thrift-server-pool-209|1192577) [DatabaseTransactionMgr.commitTransaction():798] transaction:[TransactionState. transaction id: 9058541, label: label_9035e3a4ecf42ee_9170844d89ae96b2, db id: 13012, table id list: 17812626, callback id: -1, coordinator: FE: 10.1.13.159, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1733446663306, commit time: 1733446663318, finish time: -1, reason: ] successfully committed
2024-12-06 08:57:44,031 INFO (InsertOverwriteDropDirtyPartitions|74) [InsertOverwriteManager.runAfterCatalogReady():260] start clean insert overwrite temp partitions
2024-12-06 08:57:44,828 INFO (binlog-gcer|59) [BinlogManager.gc():373] begin gc binlog
2024-12-06 08:57:44,829 INFO (binlog-gcer|59) [BinlogManager.gc():384] gc binlog, dbBinlogMap is null
2024-12-06 08:57:44,829 INFO (binlog-gcer|59) [BinlogGcer.runAfterCatalogReady():63] no gc binlog
2024-12-06 08:57:45,289 INFO (report-thread|214) [ReportHandler.taskReport():582] finished to handle task report from backend 10038, diff task num: 0. cost: 0 ms
2024-12-06 08:57:45,289 INFO (thrift-server-pool-3|281) [ReportHandler.handleReport():206] receive report from be 10038. type: TASK, current queue size: 1
2024-12-06 08:57:48,748 INFO (report-thread|214) [ReportHandler.taskReport():582] finished to handle task report from backend 10018, diff task num: 0. cost: 0 ms
2024-12-06 08:57:48,748 INFO (thrift-server-pool-15|3681) [ReportHandler.handleReport():206] receive report from be 10018. type: TASK, current queue size: 1
2024-12-06 08:57:49,940 INFO (tablet checker|42) [TabletChecker.checkTablets():347] finished to check tablets. unhealth/total/added/in_sched/not_ready: 1/33087/0/0/0, cost: 62 ms
2024-12-06 08:57:49,994 INFO (colocate group clone checker|111) [ColocateTableCheckerAndBalancer.matchGroups():586] finished to check tablets. unhealth/total/added/in_sched/not_ready: 0/0/0/0/0, cost: 0 ms
2024-12-06 08:57:52,727 INFO (report-thread|214) [ReportHandler.storagePolicyReport():317] backend[10018] reports policies [], report resources: []
2024-12-06 08:57:52,727 INFO (thrift-server-pool-52|111183) [ReportHandler.handleReport():206] receive report from be 10018. type: TABLET, current queue size: 1
2024-12-06 08:57:52,727 INFO (report-thread|214) [ReportHandler.tabletReport():426] backend[10018] reports 23769 tablet(s). report version: 17291678973465
2024-12-06 08:57:52,741 INFO (report-thread|214) [TabletInvertedIndex.tabletReport():376] finished to do tablet diff with backend[10018]. fe tablet num: 23767, backend tablet num: 23769. sync: 0. metaDel: 0. foundInMeta: 23767. migration: 0. backend partition num: 7966, backend need update: 1. found invalid transactions 0. found republish transactions 0. tabletToUpdate: 0. need recovery: 0. cost: 6 ms
2024-12-06 08:57:52,746 INFO (report-thread|214) [ReportHandler.deleteFromBackend():957] failed add to meta. tablet[43873362], backend[10018]
2024-12-06 08:57:52,746 INFO (report-thread|214) [ReportHandler.deleteFromBackend():973] delete tablet[43873362] from backend[10018] because not found in meta
2024-12-06 08:57:52,746 INFO (report-thread|214) [ReportHandler.deleteFromBackend():957] failed add to meta. tablet[43873377], backend[10018]
2024-12-06 08:57:52,746 INFO (report-thread|214) [ReportHandler.deleteFromBackend():973] delete tablet[43873377] from backend[10018] because not found in meta
2024-12-06 08:57:52,752 INFO (report-thread|214) [ReportHandler.deleteFromBackend():982] delete 2 tablet(s) and add 0 replica(s) to meta from backend[10018]
2024-12-06 08:57:52,753 INFO (report-thread|214) [ReportHandler.tabletReport():532] finished to handle tablet report from backend[10018] cost: 26 ms
2024-12-06 08:57:52,759 INFO (report-thread|214) [ReportHandler.storagePolicyReport():317] backend[6907075] reports policies [], report resources: []
2024-12-06 08:57:52,759 INFO (thrift-server-pool-14|3645) [ReportHandler.handleReport():206] receive report from be 6907075. type: TABLET, current queue size: 1
2024-12-06 08:57:52,759 INFO (report-thread|214) [ReportHandler.tabletReport():426] backend[6907075] reports 22794 tablet(s). report version: 17291679013501
2024-12-06 08:57:52,774 INFO (report-thread|214) [TabletInvertedIndex.tabletReport():376] finished to do tablet diff with backend[6907075]. fe tablet num: 22792, backend tablet num: 22794. sync: 0. metaDel: 0. foundInMeta: 22792. migration: 0. backend partition num: 8369, backend need update: 0. found invalid transactions 0. found republish transactions 0. tabletToUpdate: 0. need recovery: 0. cost: 5 ms
2024-12-06 08:57:52,776 INFO (report-thread|214) [ReportHandler.deleteFromBackend():957] failed add to meta. tablet[43852284], backend[6907075]
2024-12-06 08:57:52,776 INFO (report-thread|214) [ReportHandler.deleteFromBackend():973] delete tablet[43852284] from backend[6907075] because not found in meta
2024-12-06 08:57:52,779 INFO (report-thread|214) [ReportHandler.deleteFromBackend():957] failed add to meta. tablet[43872928], backend[6907075]
2024-12-06 08:57:52,779 INFO (report-thread|214) [ReportHandler.deleteFromBackend():973] delete tablet[43872928] from backend[6907075] because not found in meta
2024-12-06 08:57:52,785 INFO (report-thread|214) [ReportHandler.deleteFromBackend():982] delete 2 tablet(s) and add 0 replica(s) to meta from backend[6907075]
2024-12-06 08:57:52,785 INFO (report-thread|214) [ReportHandler.tabletReport():532] finished to handle tablet report from backend[6907075] cost: 26 ms
2024-12-06 08:57:53,504 INFO (thrift-server-pool-180|1034239) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058542 with label xxyyyKAFKAXT2024120617334465447672720305669594841802bcp from coordinator BE: 10.1.13.158, listener id: -1
2024-12-06 08:57:53,505 INFO (thrift-server-pool-37|9192) [DatabaseTransactionMgr.beginTransaction():404] begin transaction: txn id 9058543 with label xxyyyKAFKAXT2024120617334465587632720305683590929623bcp from coordinator BE: 10.1.13.159, listener id: -1
2024-12-06 08:57:53,506 INFO (thrift-server-pool-10|1312) [FileGroupInfo.getFileStatusAndCalcInstance():196] number instance of file scan node is: 1, bytes per instance: 9223372036854775807
2024-12-06 08:57:53,507 INFO (thrift-server-pool-26|4285) [FileGroupInfo.getFileStatusAndCalcInstance():196] number instance of file scan node is: 1, bytes per instance: 9223372036854775807
2024-12-06 08:57:53,542 INFO (thrift-server-pool-31|5855) [DatabaseTransactionMgr.abortTransaction():1621] abort transaction: TransactionState. transaction id: 9058543, label: xxyyyKAFKAXT2024120617334465587632720305683590929623bcp, db id: 13012, table id list: 32742617, callback id: -1, coordinator: BE: 10.1.13.159, transaction status: ABORTED, error replicas num: 0, replica ids: , prepare time: 1733446673505, commit time: -1, finish time: 1733446673541, reason: [DATA_QUALITY_ERROR]too many filtered rows successfully
……
2024-12-06 09:33:47,838 INFO (mtmv-task-execute-1-thread-2|124) [MTMVTask.runTask():304] mtmv task runTask, taskId: 20305751780084259
2024-12-06 09:33:47,839 INFO (PUBLISH_VERSION|32) [JobScheduler.lambda$schedulerInstantJob$2():167] dispatch instant job, job id is 43591541, job name is inner_mtmv_43591537, task id is 20305751780084259
2024-12-06 09:33:47,839 INFO (PUBLISH_VERSION|32) [DatabaseTransactionMgr.finishTransaction():1080] finish transaction TransactionState. transaction id: 9058536, label: sdos_new_info_load_1733446987918, db id: 41122805, table id list: 43589035, callback id: -1, coordinator: BE: 10.1.13.158, transaction status: VISIBLE, error replicas num: 0, replica ids: , prepare time: 1733446624707, commit time: 1733446624899, finish time: 1733446624913, reason: successfully, publish times 1, publish result QUORUM_SUCC
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058794, db: 29143768
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058537, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058535, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058539, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058540, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058546, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058547, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058549, db: 41122805
2024-12-06 09:33:47,850 INFO (PUBLISH_VERSION|32) [PublishVersionDaemon.genPublishTask():171] send publish tasks for transaction: 9058550, db: 41122805
159精简分析2.txt

What You Expected?

After successful execution, you can immediately (or within 1 second) query the data that was just inserted.
Insert执行成功后，可以立即（或1秒内）查询到刚才insert的数据。

How to Reproduce?

No response

Anything Else?

No response

Are you willing to submit PR?

  • Yes I am willing to submit a PR!

Code of Conduct
@Dong-GuoSheng
Copy link
Author

The txn id is 90587, then label is label_aac6699bcda3494f_bef497ab3a245c3e

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@Dong-GuoSheng