diff --git a/include/libjungle/db_config.h b/include/libjungle/db_config.h index 367f286..65acb91 100644 --- a/include/libjungle/db_config.h +++ b/include/libjungle/db_config.h @@ -17,6 +17,7 @@ limitations under the License. #pragma once #include "record.h" +#include "status.h" #include #include @@ -141,6 +142,7 @@ class DBConfig { , purgeDeletedDocImmediately(true) , fastIndexScan(false) , seqLoadingDelayFactor(0) + , safeMode(false) { tableSizeRatio.push_back(2.5); levelSizeRatio.push_back(10.0); @@ -565,6 +567,14 @@ class DBConfig { * The custom manifest files should be created by `cloneManifest()` API. */ std::string customManifestPath; + + /** + * If DB files are corrupted, Jungle will try to avoid the process crash + * as much as possible. + * This mode will slow down operations, thus should not be used in + * real production environment. + */ + bool safeMode; }; class GlobalConfig { diff --git a/src/db_internal.h b/src/db_internal.h index 3e43280..70742da 100644 --- a/src/db_internal.h +++ b/src/db_internal.h @@ -287,6 +287,9 @@ class Iterator::IteratorInternal { avl_tree curWindow; avl_node* windowCursor; Iterator* parent; + + // Intolerable error detected. If set, we cannot proceed iteration. + Status fatalError; }; struct GlobalBatchStatus { diff --git a/src/iterator.cc b/src/iterator.cc index cda97ae..0fc0d89 100644 --- a/src/iterator.cc +++ b/src/iterator.cc @@ -63,6 +63,14 @@ Status Iterator::init(DB* dd, p->db->p->tableMgr, start_key, end_key ); + if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + DELETE(ctx_table->tableItr); + DELETE(ctx_table); + close(); + return s; + } + if (s) s = ctx_table->tableItr->get(ctx_table->lastRec); if (s) { avl_node* avl_ret = @@ -144,6 +152,7 @@ Status Iterator::initSN(DB* db, } Status Iterator::get(Record& rec_out) { + if (!p->fatalError.ok()) return p->fatalError; if (!p || !p->db) return Status::NOT_INITIALIZED; if (!p->windowCursor) return Status::KEY_NOT_FOUND; if (p && p->db) p->db->p->updateOpHistory(); @@ -160,6 +169,7 @@ Status Iterator::get(Record& rec_out) { } Status Iterator::prev() { + if (!p->fatalError.ok()) return p->fatalError; if (!p || !p->db) return Status::NOT_INITIALIZED; if (!p->windowCursor) return Status::OUT_OF_RANGE; if (p && p->db) p->db->p->updateOpHistory(); @@ -196,12 +206,22 @@ Status Iterator::prev() { if (item->tableItr) { s = item->tableItr->get(item->lastRec); } - assert(s); avl_cmp_func* cmp_func = (p->type == ItrInt::BY_SEQ) ? (ItrInt::ItrItem::cmpSeq) : (ItrInt::ItrItem::cmpKey); avl_node* avl_ret = avl_insert(&p->curWindow, &item->an, cmp_func); + + if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + p->fatalError = s; + cur_key.free(); + + // To make next `get()` call return error, + // return this function without error. + return Status(); + } + assert(avl_ret == &item->an); (void)avl_ret; cursor = avl_last(&p->curWindow); @@ -257,6 +277,7 @@ Status Iterator::prev() { } Status Iterator::next() { + if (!p->fatalError.ok()) return p->fatalError; if (!p || !p->db) return Status::NOT_INITIALIZED; if (!p->windowCursor) return Status::OUT_OF_RANGE; if (p && p->db) p->db->p->updateOpHistory(); @@ -293,12 +314,22 @@ Status Iterator::next() { if (item->tableItr) { s = item->tableItr->get(item->lastRec); } - assert(s); avl_cmp_func* cmp_func = (p->type == ItrInt::BY_SEQ) ? (ItrInt::ItrItem::cmpSeq) : (ItrInt::ItrItem::cmpKey); avl_node* avl_ret = avl_insert(&p->curWindow, &item->an, cmp_func); + + if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + p->fatalError = s; + cur_key.free(); + + // To make next `get()` call return error, + // return this function without error. + return Status(); + } + assert(avl_ret == &item->an); (void)avl_ret; cursor = avl_first(&p->curWindow); diff --git a/src/jungle.cc b/src/jungle.cc index b125ba3..63e8410 100644 --- a/src/jungle.cc +++ b/src/jungle.cc @@ -731,12 +731,20 @@ Status DB::getNearestRecordByKey(const SizedBuf& key, Record::Holder h_rec_from_log(rec_from_log); uint64_t chknum = (sn)?(sn->chkNum):(NOT_INITIALIZED); std::list* l_list = (sn)?(sn->logList):(nullptr); - p->logMgr->getNearest(chknum, l_list, key, rec_from_log, opt); + Status ls = p->logMgr->getNearest(chknum, l_list, key, rec_from_log, opt); + if (!ls.ok() && ls != Status::KEY_NOT_FOUND) { + // Intolerable error. + return ls; + } Record rec_from_table; Record::Holder h_rec_from_table(rec_from_table); DB* snap_handle = (this->sn)?(this):(nullptr); - p->tableMgr->getNearest(snap_handle, key, rec_from_table, opt, meta_only); + Status ts = p->tableMgr->getNearest(snap_handle, key, rec_from_table, opt, meta_only); + if (!ts.ok() && ts != Status::KEY_NOT_FOUND) { + // Intolerable error. + return ts; + } if (rec_from_log.empty() && rec_from_table.empty()) { // Not found from both. @@ -793,7 +801,7 @@ Status DB::getNearestRecordByKey(const SizedBuf& key, // Choose the one from table. rec_from_table.moveTo(rec_out); } - return s; + return Status::OK; } Status DB::getRecordsByPrefix(const SizedBuf& prefix, diff --git a/src/table_file.cc b/src/table_file.cc index 69ca237..26231c9 100644 --- a/src/table_file.cc +++ b/src/table_file.cc @@ -268,6 +268,17 @@ TableFile::~TableFile() { DELETE(tlbByKey); } +Status TableFile::toJungleStatus(fdb_status fdb_s) { + switch (fdb_s) { + case FDB_RESULT_CHECKSUM_ERROR: + return Status::CHECKSUM_ERROR; + case FDB_RESULT_FILE_CORRUPTION: + return Status::FILE_CORRUPTION; + default: + return Status::ERROR; + } +} + std::string TableFile::getTableFileName(const std::string& path, uint64_t prefix_num, uint64_t table_file_num) @@ -1146,7 +1157,12 @@ Status TableFile::get(DB* snap_handle, } } if (fs != FDB_RESULT_SUCCESS) { - return Status::KEY_NOT_FOUND; + if (fs == FDB_RESULT_KEY_NOT_FOUND) { + return Status::KEY_NOT_FOUND; + } + // Otherwise, error. + _log_err(myLog, "fdb_get failed: %d", fs); + return toJungleStatus(fs); } try { @@ -1274,7 +1290,12 @@ Status TableFile::getNearest(DB* snap_handle, } } if (fs != FDB_RESULT_SUCCESS) { - return Status::KEY_NOT_FOUND; + if (fs == FDB_RESULT_KEY_NOT_FOUND) { + return Status::KEY_NOT_FOUND; + } + // Otherwise, error. + _log_err(myLog, "fdb_get failed: %d", fs); + return toJungleStatus(fs); } try { @@ -1367,7 +1388,12 @@ Status TableFile::getPrefix(DB* snap_handle, doc, nearest_opt); if (fs != FDB_RESULT_SUCCESS) { - return Status::KEY_NOT_FOUND; + if (fs == FDB_RESULT_KEY_NOT_FOUND) { + return Status::KEY_NOT_FOUND; + } + // Otherwise, error. + _log_err(myLog, "fdb_get failed: %d", fs); + return toJungleStatus(fs); } // Find next greater key. diff --git a/src/table_file.h b/src/table_file.h index 537f762..28db056 100644 --- a/src/table_file.h +++ b/src/table_file.h @@ -86,6 +86,8 @@ class TableFile { static uint64_t getBfSizeByWss(const DBConfig* db_config, uint64_t wss); + static Status toJungleStatus(fdb_status fdb_s); + FdbHandle* getIdleHandle(); void returnHandle(FdbHandle* f_handle); @@ -287,6 +289,8 @@ class TableFile { fdb_iterator* fdbItr; uint64_t minSeq; uint64_t maxSeq; + + bool safeMode; }; Status updateSnapshot(); diff --git a/src/table_file_iterator.cc b/src/table_file_iterator.cc index 9506265..3b6a9da 100644 --- a/src/table_file_iterator.cc +++ b/src/table_file_iterator.cc @@ -29,6 +29,7 @@ TableFile::Iterator::Iterator() , fdbItr(nullptr) , minSeq(NOT_INITIALIZED) , maxSeq(NOT_INITIALIZED) + , safeMode(false) {} TableFile::Iterator::~Iterator() { @@ -41,6 +42,9 @@ Status TableFile::Iterator::init(DB* snap_handle, const SizedBuf& end_key) { tFile = t_file; + safeMode = (tFile && tFile->tableMgr) + ? tFile->tableMgr->getDbConfig()->safeMode : false; + fdb_status fs; Status s; @@ -167,10 +171,15 @@ Status TableFile::Iterator::get(Record& rec_out) { fdb_doc tmp_doc; memset(&tmp_doc, 0x0, sizeof(tmp_doc)); - fdb_doc *doc = &tmp_doc; + fdb_doc *doc = safeMode ? nullptr : &tmp_doc; fs = fdb_iterator_get(fdbItr, &doc); if (fs != FDB_RESULT_SUCCESS) { - return Status::ERROR; + if (fs == FDB_RESULT_KEY_NOT_FOUND) { + return Status::KEY_NOT_FOUND; + } + // Otherwise, error. + _log_err(tFile->myLog, "fdb_iterator_get failed: %d", fs); + return toJungleStatus(fs); } rec_out.kv.key.set(doc->keylen, doc->key); @@ -201,11 +210,17 @@ Status TableFile::Iterator::get(Record& rec_out) { ? Record::DELETION : Record::INSERTION; + if (safeMode && doc) { + free(doc); + } return Status(); } catch (Status s) { rec_out.kv.free(); rec_out.meta.free(); + if (safeMode && doc) { + free(doc); + } return s; } } @@ -221,10 +236,15 @@ Status TableFile::Iterator::getMeta(Record& rec_out, fdb_doc tmp_doc; memset(&tmp_doc, 0x0, sizeof(tmp_doc)); - fdb_doc *doc = &tmp_doc; + fdb_doc *doc = safeMode ? nullptr : &tmp_doc; fs = fdb_iterator_get_metaonly(fdbItr, &doc); if (fs != FDB_RESULT_SUCCESS) { - return Status::ERROR; + if (fs == FDB_RESULT_KEY_NOT_FOUND) { + return Status::KEY_NOT_FOUND; + } + // Otherwise, error. + _log_err(tFile->myLog, "fdb_iterator_get failed: %d", fs); + return toJungleStatus(fs); } rec_out.kv.key.set(doc->keylen, doc->key); @@ -248,6 +268,10 @@ Status TableFile::Iterator::getMeta(Record& rec_out, ? Record::DELETION : Record::INSERTION; + if (safeMode && doc) { + free(doc); + } + return Status(); } diff --git a/src/table_iterator.cc b/src/table_iterator.cc index 956e071..f6d2ebe 100644 --- a/src/table_iterator.cc +++ b/src/table_iterator.cc @@ -35,7 +35,7 @@ TableMgr::Iterator::~Iterator() { close(); } -void TableMgr::Iterator::addTableItr(DB* snap_handle, TableInfo* t_info) { +Status TableMgr::Iterator::addTableItr(DB* snap_handle, TableInfo* t_info) { // Open iterator. TableFile::Iterator* t_itr = new TableFile::Iterator(); if (type == BY_SEQ) { @@ -47,6 +47,8 @@ void TableMgr::Iterator::addTableItr(DB* snap_handle, TableInfo* t_info) { ItrItem* ctx = new ItrItem(); ctx->tInfo = t_info; ctx->tItr = t_itr; + tables[t_info->level].push_back(ctx); + // If this iterator is out-of-range, `lastRec` will be empty. Status s = t_itr->get(ctx->lastRec); if (s) { @@ -55,8 +57,11 @@ void TableMgr::Iterator::addTableItr(DB* snap_handle, TableInfo* t_info) { ? (ItrItem::cmpSeq) : (ItrItem::cmpKey); avl_insert(&curWindow, &ctx->an, cmp_func); + } else if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + return s; } - tables[t_info->level].push_back(ctx); + return Status::OK; } Status TableMgr::Iterator::init(DB* snap_handle, @@ -112,17 +117,28 @@ Status TableMgr::Iterator::initInternal(DB* snap_handle, endKey.alloc(end_key); try { + Status s; size_t n_levels = tMgr->mani->getNumLevels(); tables.resize(n_levels); if (snap_handle) { // Snapshot assert(snap_handle->sn->tableList); + Status failed; for (auto& entry: *snap_handle->sn->tableList) { TableInfo* t_info = entry; - addTableItr(snap_handle, t_info); + // WARNING: + // We should do `addTableItr` for all tables in `t_info_ret`, + // to let them be closed during `close()` call. + s = addTableItr(snap_handle, t_info); + if (failed.ok() && !s.ok()) failed = s; } snapTableList = snap_handle->sn->tableList; + + if (!failed.ok()) { + TC(failed); + } + } else { // Normal for (size_t ii=0; iimani->getTablesRange(ii, start_key, end_key, t_info_ret); } + Status failed; for (auto& entry: t_info_ret) { TableInfo* t_info = entry; - addTableItr(snap_handle, t_info); + // WARNING: + // We should do `addTableItr` for all tables in `t_info_ret`, + // to let them be closed during `close()` call. + s = addTableItr(snap_handle, t_info); + if (failed.ok() && !s.ok()) failed = s; + } + + if (!failed.ok()) { + TC(failed); } } } @@ -146,13 +171,13 @@ Status TableMgr::Iterator::initInternal(DB* snap_handle, return Status(); } catch (Status s) { - startKey.free(); - endKey.free(); + close(); return s; } } Status TableMgr::Iterator::get(Record& rec_out) { + if (!fatalError.ok()) return fatalError; if (!windowCursor) return Status::KEY_NOT_FOUND; ItrItem* item = _get_entry(windowCursor, ItrItem, an); @@ -161,6 +186,8 @@ Status TableMgr::Iterator::get(Record& rec_out) { } Status TableMgr::Iterator::prev() { + if (!fatalError.ok()) return fatalError; + Status s; ItrItem* cur_item = _get_entry(windowCursor, ItrItem, an); @@ -187,13 +214,23 @@ Status TableMgr::Iterator::prev() { item->flags = ItrItem::none; item->lastRec.free(); s = item->tItr->get(item->lastRec); - assert(s); avl_cmp_func* cmp_func = (type == BY_SEQ) ? (ItrItem::cmpSeq) : (ItrItem::cmpKey); avl_insert(&curWindow, &item->an, cmp_func); cursor = avl_last(&curWindow); + + if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + fatalError = s; + cur_key.free(); + + // To make next `get()` call return error, + // return this function without error. + return Status(); + } + } else { item->flags |= ItrItem::no_more_prev; cursor = avl_prev(&item->an); @@ -234,6 +271,8 @@ Status TableMgr::Iterator::prev() { } Status TableMgr::Iterator::next() { + if (!fatalError.ok()) return fatalError; + Status s; ItrItem* cur_item = _get_entry(windowCursor, ItrItem, an); @@ -260,13 +299,23 @@ Status TableMgr::Iterator::next() { item->flags = ItrItem::none; item->lastRec.free(); s = item->tItr->get(item->lastRec); - assert(s); avl_cmp_func* cmp_func = (type == BY_SEQ) ? (ItrItem::cmpSeq) : (ItrItem::cmpKey); avl_insert(&curWindow, &item->an, cmp_func); cursor = avl_first(&curWindow); + + if (s == Status::CHECKSUM_ERROR || s == Status::FILE_CORRUPTION) { + // Intolerable error. + fatalError = s; + cur_key.free(); + + // To make next `get()` call return error, + // return this function without error. + return Status(); + } + } else { item->flags |= ItrItem::no_more_next; cursor = avl_next(&item->an); diff --git a/src/table_mgr.cc b/src/table_mgr.cc index e6df692..0bd5a0f 100644 --- a/src/table_mgr.cc +++ b/src/table_mgr.cc @@ -452,12 +452,22 @@ Status TableMgr::get(DB* snap_handle, new_rec.moveTo(latest_rec); for (TableInfo* tt: tables) tt->done(); break; + } else if (s != Status::KEY_NOT_FOUND) { + // This is intolerable error. + for (TableInfo* tt: tables) tt->done(); + return s; } } // Smallest table doesn't exist or exists but doesn't have the key. } + bool found_intolerable_error = false; for (TableInfo* table: tables) { + if (found_intolerable_error) { + table->done(); + continue; + } + if (sm_table && table == sm_table) { // We already searched smallest normal table, skip. sm_table->done(); @@ -480,9 +490,21 @@ Status TableMgr::get(DB* snap_handle, // `latest_rec` is newer. new_rec.kv.key.clear(); new_rec.free(); + + if (s != Status::KEY_NOT_FOUND) { + // This is intolerable error. + found_intolerable_error = true; + } } table->done(); } + + if (found_intolerable_error) { + latest_rec.kv.key.clear(); + latest_rec.free(); + return s; + } + if (!latest_rec.empty()) break; } if (latest_rec.empty()) return Status::KEY_NOT_FOUND; @@ -554,7 +576,13 @@ Status TableMgr::getNearest(DB* snap_handle, s = mani->getTablesNearest(ii, key, tables, s_opt); if (!s) continue; + bool found_intolerable_error = false; for (TableInfo* table: tables) { + if (found_intolerable_error) { + table->done(); + continue; + } + Record returned_rec; // WARNING: SHOULD NOT free `key` here // as it is given by caller. @@ -565,9 +593,17 @@ Status TableMgr::getNearest(DB* snap_handle, meta_only ); if (s) { update_cur_nearest(returned_rec); + } else if (s != Status::KEY_NOT_FOUND) { + // This is intolerable error. + found_intolerable_error = true; } table->done(); } + + if (found_intolerable_error) { + cur_nearest.free(); + return s; + } } if (cur_nearest.empty()) return Status::KEY_NOT_FOUND; @@ -591,12 +627,19 @@ Status TableMgr::getPrefix(DB* snap_handle, if (!s) continue; bool stopped = false; + bool found_intolerable_error = false; for (TableInfo* table: tables) { - if (!stopped) { + if (!stopped && !found_intolerable_error) { s = table->file->getPrefix(snap_handle, prefix, cb_func); } table->done(); if (s == Status::OPERATION_STOPPED) stopped = true; + if (!s.ok() && s != Status::KEY_NOT_FOUND) { + found_intolerable_error = true; + } + } + if (found_intolerable_error) { + return s; } if (stopped) break; } diff --git a/src/table_mgr.h b/src/table_mgr.h index 5e9e76d..c395f13 100644 --- a/src/table_mgr.h +++ b/src/table_mgr.h @@ -411,7 +411,7 @@ class TableMgr { Record lastRec; }; - void addTableItr(DB* snap_handle, TableInfo* t_info); + Status addTableItr(DB* snap_handle, TableInfo* t_info); Status initInternal(DB* snap_handle, TableMgr* table_mgr, uint64_t min_seq, @@ -442,6 +442,9 @@ class TableMgr { SizedBuf endKey; avl_tree curWindow; avl_node* windowCursor; + + // Intolerable error detected. If set, we cannot proceed iteration. + Status fatalError; }; protected: diff --git a/tests/jungle/corruption_test.cc b/tests/jungle/corruption_test.cc index 66ce64c..1140841 100644 --- a/tests/jungle/corruption_test.cc +++ b/tests/jungle/corruption_test.cc @@ -18,6 +18,7 @@ limitations under the License. #include "internal_helper.h" +#include #include #include @@ -352,6 +353,125 @@ int log_manifest_corruption_across_file_test() { return 0; } +int table_file_corruption_test(size_t failing_idx) { + std::string filename; + TEST_SUITE_PREPARE_PATH(filename); + + jungle::Status s; + jungle::DB* db; + + // Open DB. + jungle::DBConfig config; + TEST_CUSTOM_DB_CONFIG(config); + + // Without this flag, iterators will crash upon corruption. + config.safeMode = true; + + CHK_Z(jungle::DB::open(&db, filename, config)); + + // Write multiple log files. + const size_t NUM = 10000; + const std::string VALUE(1000, 'x'); + for (size_t ii=0; iisetSN(ii+1, jungle::KV("key" + TestSuite::lzStr(6, ii), VALUE))); + } + CHK_Z(db->sync(false)); + + // Flush into table. + CHK_Z( db->flushLogs() ); + + CHK_Z(jungle::DB::close(db)); + + // Corrupt the first table file (this is the value of `key000002`). + uint64_t offset = 0x0; + if (failing_idx == 2) offset = 0x9100; + if (failing_idx == 96) offset = 0x10070; + CHK_Z(inject_crc_error(filename + "/table0000_00000000", offset)); + + CHK_Z(jungle::DB::open(&db, filename, config)); + + // Point get, key 2 should return checksum error, while all the others are ok. + auto verify = [&VALUE, failing_idx] + (jungle::Status s, size_t ii, const jungle::SizedBuf& value_out) { + if (ii == failing_idx) { + CHK_EQ(jungle::Status::CHECKSUM_ERROR, s.getValue()); + } else { + CHK_Z(s); + CHK_EQ(jungle::SizedBuf(VALUE), value_out); + } + return 0; + }; + + // Point get, key=2 should fail. + for (size_t ii = 0; ii < NUM; ++ii) { + TestSuite::setInfo("ii=%zu", ii); + + jungle::SizedBuf value_out; + s = db->get(jungle::SizedBuf("key" + TestSuite::lzStr(6, ii)), value_out); + CHK_Z(verify(s, ii, value_out)); + value_out.free(); + } + + { + // get nearest and prefix leverage iterator, it can return checksum error earlier. + jungle::Record rec_out; + + for (size_t ii = 0; ii < NUM; ++ii) { + s = db->getNearestRecordByKey( + jungle::SizedBuf("key" + TestSuite::lzStr(6, ii)), rec_out); + rec_out.free(); + if (!s.ok()) break; + } + CHK_EQ(jungle::Status::CHECKSUM_ERROR, s.getValue()); + + for (size_t ii = 0; ii < NUM; ++ii) { + s = db->getRecordsByPrefix( + jungle::SizedBuf("key" + TestSuite::lzStr(6, ii)), + [&rec_out](const jungle::SearchCbParams& p) { + rec_out.free(); + p.rec.copyTo(rec_out); + return jungle::SearchCbDecision::NEXT; + }); + rec_out.free(); + if (!s.ok()) break; + } + CHK_EQ(jungle::Status::CHECKSUM_ERROR, s.getValue()); + } + + // Iterator (without safe mode, it will crash). + jungle::Iterator itr; + s = itr.init(db, jungle::SizedBuf(), jungle::SizedBuf()); + if (failing_idx == 2) { + CHK_EQ(jungle::Status::CHECKSUM_ERROR, s.getValue()); + } else { + CHK_Z(s); + + size_t count = 0; + do { + TestSuite::setInfo("count=%zu", count); + jungle::Record rec_out; + jungle::Record::Holder h(rec_out); + s = itr.get(rec_out); + if (!s.ok()) { + CHK_EQ(jungle::Status::CHECKSUM_ERROR, s.getValue()); + break; + } + + count++; + } while (itr.next().ok()); + // Iteration should have been aborted in the middle. + CHK_SM(count, NUM); + CHK_Z(itr.close()); + } + + // Close. + CHK_Z(jungle::DB::close(db)); + CHK_Z(jungle::shutdown()); + + TEST_SUITE_CLEANUP_PATH(); + return 0; +} + int incomplete_log_test() { std::string filename; TEST_SUITE_PREPARE_PATH(filename); @@ -1303,6 +1423,10 @@ int main(int argc, char** argv) { ts.doTest("log manifest corruption across multi log files test", log_manifest_corruption_across_file_test); + ts.doTest("table file corruption test", + table_file_corruption_test, + TestRange({2, 96})); + ts.doTest("incomplete log test", incomplete_log_test);