You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@pegasus.apache.org by GitBox <gi...@apache.org> on 2022/06/01 07:55:03 UTC
[GitHub] [incubator-pegasus] daggarwal387 opened a new issue, #990: WaitForFlushMemTables finishing before result is committed to Manifest
daggarwal387 opened a new issue, #990:
URL: https://github.com/apache/incubator-pegasus/issues/990
While using the ExportColumnFamily API I observed that the result is missing the newly flushed memtable. Upon further investigation, I found that WaitForFlushMemTables is finishing before the flush has actually committed the result to the Manifest. Following are the logs for the column family that experienced it(there are some additional logs added for debugging).
`2022/05/31-16:28:39.080669 4f8a700 [ties/checkpoint/checkpoint_impl.cc:357] [0_0] export column family onto export directory /tmp/bringup/0/disks/0/scribe/newscribe/bucket_0/db_sender_sst_file
2022/05/31-16:28:39.080729 4f8a700 [_impl/db_impl_compaction_flush.cc:1310] [0_0] Manual flush start.
2022/05/31-16:28:39.095206 4f8a700 [_impl/db_impl_write.cc:1614] [0_0] New memtable created with log file: #113. Immutable memtables: 0.
2022/05/31-16:28:39.095227 4f8a700 [_impl/db_impl_compaction_flush.cc:1596] [0_0] Flush request queued.
2022/05/31-16:28:39.112425 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.095402) [_impl/db_impl_compaction_flush.cc:2208] Calling FlushMemTableToOutputFile with column family [0_0], flush slots available 10, compaction slots available 1, flush slots scheduled 10, compaction slots scheduled 0
2022/05/31-16:28:39.112432 7f5694e41700 [ush_job.cc:322] [0_0] [JOB 320] Flushing memtable with next log file: 113 and mem_table_id: 10
2022/05/31-16:28:39.112450 7f5694e41700 [ush_job.cc:351] [0_0] [JOB 320] Level-0 flush table #114: started
2022/05/31-16:28:39.116592 4d70700 [_impl/db_impl_write.cc:1614] [0_0] New memtable created with log file: #115. Immutable memtables: 1.
2022/05/31-16:28:39.116620 4d70700 [_impl/db_impl_compaction_flush.cc:1596] [0_0] Flush request queued.
2022/05/31-16:28:39.127211 7f5696e45700 (Original Log Time 2022/05/31-16:28:39.116846) [_impl/db_impl_compaction_flush.cc:2208] Calling FlushMemTableToOutputFile with column family [0_0], flush slots available 10, compaction slots available 1, flush slots scheduled 10, compaction slots scheduled 0
2022/05/31-16:28:39.127218 7f5696e45700 [ush_job.cc:322] [0_0] [JOB 331] Flushing memtable with next log file: 115 and mem_table_id: 11
2022/05/31-16:28:39.127238 7f5696e45700 [ush_job.cc:351] [0_0] [JOB 331] Level-0 flush table #116: started
2022/05/31-16:28:39.130535 7f5694e41700 [ush_job.cc:392] [0_0] [JOB 320] Level-0 flush table #114: 235965 bytes OK
2022/05/31-16:28:39.140412 7f5696e45700 [ush_job.cc:392] [0_0] [JOB 331] Level-0 flush table #116: 2489 bytes OK
2022/05/31-16:28:39.154308 7f5696e45700 (Original Log Time 2022/05/31-16:28:39.150687) [_impl/db_impl_compaction_flush.cc:204] [0_0] Level summary: base level 4 level multiplier 8.00 max bytes base 4096000 files[1 0 0 0 1] max score 0.12
2022/05/31-16:28:39.154415 4f8a700 [_impl/db_impl_compaction_flush.cc:1866] [0_0]Flush finished. Num not flushed: 1, earliest_memtable_id_now: 11, mem_table_we_flushed: 10
2022/05/31-16:28:39.154423 4f8a700 [_impl/db_impl_compaction_flush.cc:1320] [0_0] Manual flush finished, status: OK
2022/05/31-16:28:39.154474 4f8a700 [ties/checkpoint/checkpoint_impl.cc:380] [0_0] HardLinking /000100.sst
2022/05/31-16:28:39.154551 4f8a700 [ties/checkpoint/checkpoint_impl.cc:380] [0_0] HardLinking /000090.sst
2022/05/31-16:28:39.166255 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.137073) [mtable_list.cc:383] [0_0] Level-0 commit table #114 has started, mem_id: 10
2022/05/31-16:28:39.166260 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.154210) [mtable_list.cc:439] [0_0] Level-0 commit table #114: memtable #1memtable_id: 10 done
2022/05/31-16:28:39.166263 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.154215) [mtable_list.cc:383] [0_0] Level-0 commit table #116 has started, mem_id: 11
2022/05/31-16:28:39.166265 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.166175) [mtable_list.cc:439] [0_0] Level-0 commit table #116: memtable #1memtable_id: 11 done
2022/05/31-16:28:39.166270 7f5694e41700 (Original Log Time 2022/05/31-16:28:39.166208) [_impl/db_impl_compaction_flush.cc:204] [0_0] Level summary: base level 4 level multiplier 8.00 max bytes base 4096000 files[3 0 0 0 1] max score 0.38
2022/05/31-16:28:39.166273 4f8a700 [ties/checkpoint/checkpoint_impl.cc:435] [0_0] Export succeeded.
2022/05/31-16:28:39.166309 4d70700 [_impl/db_impl_compaction_flush.cc:1866] [0_0]Flush finished. Num not flushed: 0, earliest_memtable_id_now: 18446744073709551615, mem_table_we_flushed: 11
2022/05/31-16:28:39.166321 4d70700 [_impl/db_impl_compaction_flush.cc:1443] [0_0] Manual compaction starting`
So if you look here, the memtable with GetID() as 10 is the one that was selected for manual flush from ExportColumnFamily. During committing the logline "Level-0 commit table #114 has started, mem_id: 10" the memtable is at the back of the memlist but a few lines before it "Flush finished. Num not flushed: 1, earliest_memtable_id_now: 11, mem_table_we_flushed: 10" the GetEarliestMemTableID gave us 11.
I am using 6.4.6 rocksdb version with some additional logging and attaching the complete LOG file also in case that helps.
[LOG.zip](https://github.com/apache/incubator-pegasus/files/8812140/LOG.zip)
.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org
For additional commands, e-mail: dev-help@pegasus.apache.org
[GitHub] [incubator-pegasus] daggarwal387 closed issue #990: WaitForFlushMemTables finishing before result is committed to Manifest
Posted by GitBox <gi...@apache.org>.
daggarwal387 closed issue #990: WaitForFlushMemTables finishing before result is committed to Manifest
URL: https://github.com/apache/incubator-pegasus/issues/990
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org
For additional commands, e-mail: dev-help@pegasus.apache.org