From c67cac422848eb8bf8fb11dd6b6f6ffb1522eb84 Mon Sep 17 00:00:00 2001 From: Takayuki Tanabe Date: Thu, 18 Jan 2024 14:09:37 +0900 Subject: [PATCH] fix: log message https://github.com/project-tsurugi/tsurugi-issues/issues/441 --- src/concurrency_control/bg_work/bg_commit.cpp | 7 ++-- src/concurrency_control/interface/delete.cpp | 10 +++-- src/concurrency_control/interface/insert.cpp | 3 +- .../interface/long_tx/helper.cpp | 2 +- .../interface/long_tx/termination.cpp | 4 +- .../interface/session_management.cpp | 2 +- src/concurrency_control/interface/storage.cpp | 20 +++++----- .../interface/termination.cpp | 2 +- src/concurrency_control/interface/update.cpp | 4 +- src/concurrency_control/sequence.cpp | 37 +++++++++++++------ src/concurrency_control/transaction_state.cpp | 10 +++-- src/concurrency_control/wp_meta.cpp | 2 +- src/datastore/limestone/datastore.cpp | 12 ++++-- 13 files changed, 73 insertions(+), 42 deletions(-) diff --git a/src/concurrency_control/bg_work/bg_commit.cpp b/src/concurrency_control/bg_work/bg_commit.cpp index fb0394d4c..9dea35c2c 100644 --- a/src/concurrency_control/bg_work/bg_commit.cpp +++ b/src/concurrency_control/bg_work/bg_commit.cpp @@ -53,7 +53,7 @@ void bg_commit::register_tx(Token token) { auto* ti = static_cast(token); // check from long if (ti->get_tx_type() != transaction_options::transaction_type::LONG) { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix << "library programming error"; return; } @@ -64,7 +64,7 @@ void bg_commit::register_tx(Token token) { std::make_tuple(ti->get_long_tx_id(), token)); if (!ret.second) { // already exist - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix << "library programming error"; } } } @@ -115,7 +115,8 @@ void bg_commit::worker() { transaction_options::transaction_type::LONG || !ti->get_requested_commit()) { // not long or not requested commit. - LOG(ERROR) << log_location_prefix << "unexpected error. " + LOG(ERROR) << log_location_prefix + << "library programming error. " << ti->get_tx_type() << ", " << std::boolalpha << ti->get_requested_commit() << ", tx_id:" << tx_id; diff --git a/src/concurrency_control/interface/delete.cpp b/src/concurrency_control/interface/delete.cpp index 002350113..0b1ba8236 100644 --- a/src/concurrency_control/interface/delete.cpp +++ b/src/concurrency_control/interface/delete.cpp @@ -67,7 +67,9 @@ inline Status process_after_write(session* ti, write_set_obj* wso) { Storage st = wso->get_storage(); Record* rec_ptr = wso->get_rec_ptr(); auto rs = ti->get_write_set().erase(wso); - if (rs != Status::OK) { LOG(ERROR) << "unexpected error: " << rs; } + if (rs != Status::OK) { + LOG(ERROR) << "library programming error. about strand?: " << rs; + } if (!rc) { // if this was update ti->get_write_set().push({st, OP_TYPE::DELETE, rec_ptr}); // NOLINT @@ -92,7 +94,9 @@ static void process_before_return_not_found(session* const ti, wp::page_set_meta* psm{}; auto rc = wp::find_page_set_meta(storage, psm); if (rc != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "unexpected error. library programming error or " + "usage error (mixed ddl and dml?)"; return; } // get range read by info @@ -144,7 +148,7 @@ Status delete_record_body(Token token, Storage storage, if (rc == Status::WARN_STORAGE_NOT_FOUND) { return Status::WARN_STORAGE_NOT_FOUND; } - LOG(ERROR) << log_location_prefix << "unexpected error: " << rc; + LOG(ERROR) << log_location_prefix << "library programming error: " << rc; return Status::ERR_FATAL; } diff --git a/src/concurrency_control/interface/insert.cpp b/src/concurrency_control/interface/insert.cpp index 837c41b26..f31858a3c 100644 --- a/src/concurrency_control/interface/insert.cpp +++ b/src/concurrency_control/interface/insert.cpp @@ -121,7 +121,8 @@ Status insert_body(Token const token, Storage const storage, // NOLINT // register read_by_set register_read_if_ltx(ti, rec_ptr); } else { - LOG(ERROR) << log_location_prefix << "unexpected path"; + LOG(ERROR) << log_location_prefix + << "library programming error"; return Status::ERR_FATAL; } // end: make read set diff --git a/src/concurrency_control/interface/long_tx/helper.cpp b/src/concurrency_control/interface/long_tx/helper.cpp index fc1aeb4c3..b970dbe60 100644 --- a/src/concurrency_control/interface/long_tx/helper.cpp +++ b/src/concurrency_control/interface/long_tx/helper.cpp @@ -119,7 +119,7 @@ void update_wp_at_commit(session* const ti, std::set const& sts) { itr = ti->get_wp_set().erase(itr); continue; } - LOG(ERROR) << log_location_prefix << "unexpected code path"; + LOG(ERROR) << log_location_prefix << "library programming error"; itr->second->get_wp_lock().unlock(); } ++itr; diff --git a/src/concurrency_control/interface/long_tx/termination.cpp b/src/concurrency_control/interface/long_tx/termination.cpp index 60c3a4677..1b2ab32ce 100644 --- a/src/concurrency_control/interface/long_tx/termination.cpp +++ b/src/concurrency_control/interface/long_tx/termination.cpp @@ -811,7 +811,7 @@ extern Status commit(session* const ti) { goto END_COMMIT; // NOLINT } if (rc != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error. " << rc; + LOG(ERROR) << log_location_prefix << "library programming error. " << rc; return rc; } @@ -915,7 +915,7 @@ extern Status commit(session* const ti) { // set transaction result ti->set_result(reason_code::UNKNOWN); } else { - LOG(ERROR) << "unexpected code path"; + LOG(ERROR) << "library programming error."; } END_COMMIT: // NOLINT diff --git a/src/concurrency_control/interface/session_management.cpp b/src/concurrency_control/interface/session_management.cpp index 88922b25b..accb32b7c 100644 --- a/src/concurrency_control/interface/session_management.cpp +++ b/src/concurrency_control/interface/session_management.cpp @@ -84,7 +84,7 @@ Status leave_body(Token const token) { // NOLINT if (itr.get_tx_type() != transaction_options::transaction_type::LONG) { LOG(ERROR) << log_location_prefix - << "unexpected error"; + << "library programming error"; } // the ltx commit was submitted, wait result. do { diff --git a/src/concurrency_control/interface/storage.cpp b/src/concurrency_control/interface/storage.cpp index 5b4687491..bed765fa3 100644 --- a/src/concurrency_control/interface/storage.cpp +++ b/src/concurrency_control/interface/storage.cpp @@ -39,18 +39,18 @@ void write_storage_metadata(std::string_view key, Storage st, value.append(payload); auto ret = tx_begin({s, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error."; + LOG(ERROR) << log_location_prefix << "library programming error."; } ret = upsert(s, storage::meta_storage, key, value); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unreachable path"; + LOG(ERROR) << log_location_prefix << "library programming error."; return; } if (commit(s) == Status::OK) { leave(s); return; } // else - LOG(ERROR) << log_location_prefix << "unreachable path"; + LOG(ERROR) << log_location_prefix << "library programming error"; } void remove_storage_metadata(std::string_view key) { @@ -59,7 +59,7 @@ void remove_storage_metadata(std::string_view key) { std::string value{}; auto ret = tx_begin({s, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error."; + LOG(ERROR) << log_location_prefix << "library programming error."; } ret = delete_record(s, storage::meta_storage, key); if (ret != Status::OK) { @@ -73,7 +73,7 @@ void remove_storage_metadata(std::string_view key) { leave(s); return; } // else - LOG(ERROR) << log_location_prefix << "unreachable path"; + LOG(ERROR) << log_location_prefix << "library programming error"; } Status create_storage_body(std::string_view const key, Storage& storage, @@ -148,7 +148,8 @@ Status get_storage_body(std::string_view const key, Storage& out) { } Status get_storage(std::string_view key, Storage& out) { - shirakami_log_entry << "get_storage " << shirakami_binstring(key) << ", out: " << out; + shirakami_log_entry << "get_storage " << shirakami_binstring(key) + << ", out: " << out; auto ret = get_storage_body(key, out); shirakami_log_exit << "get_storage, " << ret; return ret; @@ -180,7 +181,7 @@ Status storage_get_options_body(Storage storage, storage_option& options) { for (;;) { ret = tx_begin({s, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error."; + LOG(ERROR) << log_location_prefix << "library programming error."; } ret = search_key(s, storage::meta_storage, key, value); if (ret != Status::OK) { @@ -246,7 +247,8 @@ Status storage_set_options_body(Storage storage, // store and log information ret = tx_begin({s, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error. " << ret; + LOG(ERROR) << log_location_prefix << "library programming error. " + << ret; } ret = upsert(s, storage::meta_storage, key, value); if (ret != Status::OK) { @@ -257,7 +259,7 @@ Status storage_set_options_body(Storage storage, leave(s); return Status::OK; } // else - LOG(ERROR) << log_location_prefix << "unreachable path"; + LOG(ERROR) << log_location_prefix << "library programming error."; return Status::ERR_FATAL; } diff --git a/src/concurrency_control/interface/termination.cpp b/src/concurrency_control/interface/termination.cpp index 3558bca42..0ebd0c5c0 100644 --- a/src/concurrency_control/interface/termination.cpp +++ b/src/concurrency_control/interface/termination.cpp @@ -111,7 +111,7 @@ Status commit_body(Token const token, // NOLINT // set about diagnostics. it must commit ti->set_diag_tx_state_kind(TxState::StateKind::WAITING_DURABLE); } else { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix << "library programming error"; return Status::ERR_FATAL; } diff --git a/src/concurrency_control/interface/update.cpp b/src/concurrency_control/interface/update.cpp index 67068c281..1cd85e106 100644 --- a/src/concurrency_control/interface/update.cpp +++ b/src/concurrency_control/interface/update.cpp @@ -32,7 +32,9 @@ static void process_before_return_not_found(session* const ti, wp::page_set_meta* psm{}; auto rc = wp::find_page_set_meta(storage, psm); if (rc != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "library programming error or" + "usage error (mixed dml and ddl?)"; return; } // get range read by info diff --git a/src/concurrency_control/sequence.cpp b/src/concurrency_control/sequence.cpp index f0f27c898..62df17a4b 100644 --- a/src/concurrency_control/sequence.cpp +++ b/src/concurrency_control/sequence.cpp @@ -153,7 +153,10 @@ Status sequence::sequence_map_push(SequenceId const id, std::make_pair(epoch, std::make_tuple(version, value))); if (!ret2.second) { // This object must be operated by here. - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "When it tried to manipulate an object inserted into " + "map, it was already manipulated by someone else."; + // maybe lack of mutex control return Status::ERR_FATAL; } return Status::OK; @@ -260,7 +263,7 @@ Status sequence::create_sequence(SequenceId* id) { // generate sequence id auto ret = sequence::generate_sequence_id(*id); if (ret == Status::ERR_FATAL) { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix << "sequence id depletion"; return ret; } @@ -292,23 +295,30 @@ Status sequence::create_sequence(SequenceId* id) { sizeof(initial_value)); ret = tx_begin({token, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error. " << ret; + LOG(ERROR) << log_location_prefix + << "There is no way that short tx will fail to start here. " + << ret; } ret = upsert(token, storage::sequence_storage, key, value); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior: " << ret; + LOG(ERROR) << log_location_prefix + << "There is no way that upsert will fail to start here: " + << ret; return Status::ERR_FATAL; } ret = commit(token); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "There is no way that 1 upsert only" + "stx will fail here"; return Status::ERR_FATAL; } // cleanup transaction handle ret = leave(token); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "There is no way that leave will fail here"; return Status::ERR_FATAL; } @@ -394,16 +404,19 @@ Status sequence::delete_sequence(SequenceId const id) { sizeof(value)); ret = tx_begin({token, transaction_options::transaction_type::SHORT}); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error. " << ret; + LOG(ERROR) << log_location_prefix + << "there is no way stx begin will fail here. " << ret; } ret = upsert(token, storage::sequence_storage, key, new_value); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "there is no way stx's upsert will fail here"; return Status::ERR_FATAL; } ret = commit(token); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "there is no way commit will fail here."; return Status::ERR_FATAL; } @@ -411,14 +424,16 @@ Status sequence::delete_sequence(SequenceId const id) { auto epoch = static_cast(token)->get_mrc_tid().get_epoch(); ret = sequence::sequence_map_update(id, epoch, version, value); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unreachable path"; + LOG(ERROR) << log_location_prefix + << "there is no way sequence map update will fail here."; return Status::ERR_FATAL; } // cleanup transaction handle ret = leave(token); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected behavior"; + LOG(ERROR) << log_location_prefix + << "there is no way leave will fail here."; return Status::ERR_FATAL; } diff --git a/src/concurrency_control/transaction_state.cpp b/src/concurrency_control/transaction_state.cpp index a4fd7a114..874bb2fff 100644 --- a/src/concurrency_control/transaction_state.cpp +++ b/src/concurrency_control/transaction_state.cpp @@ -105,8 +105,9 @@ Status check_tx_state_body(TxStateHandle handle, TxState& out) { out.set_kind(TxState::StateKind::DURABLE); // for external } #else - // if no logging, it must not be waiting_durable status - LOG(ERROR) << log_location_prefix << "unexpected path"; + LOG(ERROR) + << log_location_prefix + << "if no logging, it must not be waiting_durabule status"; return Status::ERR_FATAL; #endif } @@ -133,8 +134,9 @@ Status check_tx_state_body(TxStateHandle handle, TxState& out) { out.set_kind(TxState::StateKind::DURABLE); // for external } #else - // if no logging, it must not be waiting_durable status - LOG(ERROR) << log_location_prefix << "unexpected path"; + LOG(ERROR) + << log_location_prefix + << "if no logging, it must not be waiting_durable status"; return Status::ERR_FATAL; #endif } diff --git a/src/concurrency_control/wp_meta.cpp b/src/concurrency_control/wp_meta.cpp index 79522eb3c..23c8260a7 100644 --- a/src/concurrency_control/wp_meta.cpp +++ b/src/concurrency_control/wp_meta.cpp @@ -156,7 +156,7 @@ wp_meta::register_wp_result_and_remove_wp(wp_result_elem_type const& elem) { return Status::OK; } } - LOG(ERROR) << log_location_prefix << "unexpected code path"; + LOG(ERROR) << log_location_prefix << "concurrent program error"; return Status::WARN_NOT_FOUND; } diff --git a/src/datastore/limestone/datastore.cpp b/src/datastore/limestone/datastore.cpp index 6a39b275c..bc645e1e3 100644 --- a/src/datastore/limestone/datastore.cpp +++ b/src/datastore/limestone/datastore.cpp @@ -135,7 +135,8 @@ void recovery_from_datastore() { if (storage::key_handle_map_push_storage(key, st2) != Status::OK) { // Does DML create key handle map entry? - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "library programming error."; return; } } else { @@ -148,7 +149,8 @@ void recovery_from_datastore() { * shirakami::storage::exist_storage(st2) said not exist, * but it can't register_storage. */ - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "library programming error"; return; } if (storage::key_handle_map_push_storage(key, st2) != @@ -158,7 +160,8 @@ void recovery_from_datastore() { * shirakami::register_storage(st2, {id, payload}) was * succeeded but it can't create entry of this map. */ - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "library programming error"; return; } put_data(storage::meta_storage, key, new_value); @@ -176,7 +179,8 @@ void recovery_from_datastore() { sizeof(version)); auto ret = sequence::sequence_map_push(id, 0, version, value); if (ret != Status::OK) { - LOG(ERROR) << log_location_prefix << "unexpected error"; + LOG(ERROR) << log_location_prefix + << "library programming error"; return; } } else {