You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pegasus.apache.org by la...@apache.org on 2023/01/16 06:52:39 UTC
[incubator-pegasus] branch master updated: refactor(log): use LOG_INFO_F instead of LOG_INFO (3/3) (#1311)
This is an automated email from the ASF dual-hosted git repository.
laiyingchun pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-pegasus.git
The following commit(s) were added to refs/heads/master by this push:
new 9df5bdaab refactor(log): use LOG_INFO_F instead of LOG_INFO (3/3) (#1311)
9df5bdaab is described below
commit 9df5bdaab599bd9a69933456c92c713acc237439
Author: Yingchun Lai <la...@apache.org>
AuthorDate: Mon Jan 16 14:52:34 2023 +0800
refactor(log): use LOG_INFO_F instead of LOG_INFO (3/3) (#1311)
---
src/aio/test/aio.cpp | 2 +-
src/block_service/block_service_manager.cpp | 2 +-
src/block_service/fds/fds_service.cpp | 2 +-
src/block_service/hdfs/hdfs_service.cpp | 4 +-
src/block_service/local/local_service.cpp | 8 +-
src/common/fs_manager.cpp | 28 +-
src/failure_detector/failure_detector.cpp | 40 ++-
.../failure_detector_multimaster.cpp | 16 +-
src/http/pprof_http_service.cpp | 12 +-
src/meta/server_state.cpp | 246 ++++++++----------
src/perf_counter/test/perf_counter_test.cpp | 8 +-
src/redis_protocol/proxy_lib/proxy_layer.cpp | 4 +-
src/redis_protocol/proxy_lib/redis_parser.cpp | 125 ++++-----
src/redis_protocol/proxy_ut/redis_proxy_test.cpp | 2 +-
src/replica/backup/cold_backup_context.cpp | 263 ++++++++++---------
src/replica/duplication/duplication_sync_timer.cpp | 2 +-
src/replica/replica_stub.cpp | 285 ++++++++++-----------
.../storage/simple_kv/simple_kv.server.impl.cpp | 2 +-
src/replica/storage/simple_kv/test/case.cpp | 20 +-
src/replica/storage/simple_kv/test/case.h | 5 +
src/replica/storage/simple_kv/test/checker.cpp | 6 +-
src/replica/storage/simple_kv/test/client.cpp | 8 +-
src/replica/storage/simple_kv/test/common.h | 10 +
src/replica/storage/simple_kv/test/injector.cpp | 2 -
.../storage/simple_kv/test/simple_kv.main.cpp | 2 +-
.../simple_kv/test/simple_kv.server.impl.cpp | 38 +--
src/reporter/pegasus_counter_reporter.cpp | 11 +-
src/runtime/fault_injector.cpp | 63 +++--
src/runtime/rpc/asio_rpc_session.cpp | 4 +-
src/runtime/rpc/network.cpp | 47 ++--
src/runtime/rpc/raw_message_parser.cpp | 4 +-
src/runtime/rpc/rpc_engine.cpp | 34 +--
src/runtime/security/init.cpp | 8 +-
src/runtime/service_api_c.cpp | 8 +-
src/runtime/test/async_call.cpp | 12 +-
src/runtime/test/netprovider.cpp | 14 +-
src/runtime/test/rpc.cpp | 6 +-
src/runtime/test/test_utils.h | 8 +-
src/runtime/tool_api.cpp | 2 +-
src/runtime/tracer.cpp | 165 ++++++------
src/server/available_detector.cpp | 66 ++---
src/server/compaction_operation.cpp | 4 +-
src/server/hotspot_partition_calculator.cpp | 2 +-
src/server/info_collector.cpp | 6 +-
src/server/main.cpp | 3 +-
src/server/pegasus_server_impl.cpp | 70 ++---
src/test/kill_test/data_verifier.cpp | 104 ++++----
src/test/kill_test/kill_testor.cpp | 4 +-
src/test/kill_test/killer_handler_shell.cpp | 17 +-
src/test/kill_test/partition_kill_testor.cpp | 8 +-
src/test/kill_test/process_kill_testor.cpp | 39 +--
src/test/pressure_test/main.cpp | 12 +-
src/utils/api_utilities.h | 1 -
src/utils/command_manager.h | 5 +-
src/utils/fail_point.cpp | 16 +-
.../distributed_lock_service_zookeeper.cpp | 2 +-
src/zookeeper/lock_struct.cpp | 136 +++++-----
src/zookeeper/test/distributed_lock_zookeeper.cpp | 14 +-
src/zookeeper/zookeeper_session.cpp | 6 +-
59 files changed, 969 insertions(+), 1074 deletions(-)
diff --git a/src/aio/test/aio.cpp b/src/aio/test/aio.cpp
index a7e13cbee..fad929c08 100644
--- a/src/aio/test/aio.cpp
+++ b/src/aio/test/aio.cpp
@@ -188,7 +188,7 @@ TEST(core, operation_failed)
t = ::dsn::file::read(fp2, buffer, 512, 100, LPC_AIO_TEST, nullptr, io_callback, 0);
t->wait();
- LOG_INFO("error code: %s", err->to_string());
+ LOG_INFO_F("error code: {}", *err);
file::close(fp);
file::close(fp2);
fail::teardown();
diff --git a/src/block_service/block_service_manager.cpp b/src/block_service/block_service_manager.cpp
index 297dff78b..2f41f7c87 100644
--- a/src/block_service/block_service_manager.cpp
+++ b/src/block_service/block_service_manager.cpp
@@ -52,7 +52,7 @@ block_service_manager::block_service_manager()
block_service_manager::~block_service_manager()
{
- LOG_INFO("close block service manager.");
+ LOG_INFO_F("close block service manager.");
zauto_write_lock l(_fs_lock);
_fs_map.clear();
}
diff --git a/src/block_service/fds/fds_service.cpp b/src/block_service/fds/fds_service.cpp
index 3611deafd..73adeb3dd 100644
--- a/src/block_service/fds/fds_service.cpp
+++ b/src/block_service/fds/fds_service.cpp
@@ -561,7 +561,7 @@ error_code fds_file_object::put_content(/*in-out*/ std::istream &is,
return err;
}
- LOG_INFO("start to synchronize meta data after successfully wrote data to fds");
+ LOG_INFO_F("start to synchronize meta data after successfully wrote data to fds");
err = get_file_meta();
if (err == ERR_OK) {
transfered_bytes = _size;
diff --git a/src/block_service/hdfs/hdfs_service.cpp b/src/block_service/hdfs/hdfs_service.cpp
index 54a06a4b6..3403e4970 100644
--- a/src/block_service/hdfs/hdfs_service.cpp
+++ b/src/block_service/hdfs/hdfs_service.cpp
@@ -113,7 +113,7 @@ void hdfs_service::close()
// This method should be carefully called.
// Calls to hdfsDisconnect() by individual threads would terminate
// all other connections handed out via hdfsConnect() to the same URI.
- LOG_INFO("Try to disconnect hdfs.");
+ LOG_INFO_F("Try to disconnect hdfs.");
int result = hdfsDisconnect(_fs);
if (result == -1) {
LOG_ERROR_F("Fail to disconnect from the hdfs file system, error: {}.",
@@ -335,7 +335,7 @@ error_code hdfs_file_object::write_data_in_batches(const char *data,
return ERR_FS_INTERNAL;
}
- LOG_INFO("start to synchronize meta data after successfully wrote data to hdfs");
+ LOG_INFO_F("start to synchronize meta data after successfully wrote data to hdfs");
return get_file_meta();
}
diff --git a/src/block_service/local/local_service.cpp b/src/block_service/local/local_service.cpp
index 566b3e6b6..ce4d73f57 100644
--- a/src/block_service/local/local_service.cpp
+++ b/src/block_service/local/local_service.cpp
@@ -78,7 +78,7 @@ error_code local_service::initialize(const std::vector<std::string> &args)
_root = args[0];
if (_root.empty()) {
- LOG_INFO("initialize local block service succeed with empty root");
+ LOG_INFO_F("initialize local block service succeed with empty root");
} else {
if (::dsn::utils::filesystem::directory_exists(_root)) {
LOG_WARNING("old local block service root dir has already exist, path(%s)",
@@ -88,7 +88,7 @@ error_code local_service::initialize(const std::vector<std::string> &args)
"local block service create directory({}) fail",
_root);
}
- LOG_INFO("local block service initialize succeed with root(%s)", _root.c_str());
+ LOG_INFO_F("local block service initialize succeed with root({})", _root);
}
return ERR_OK;
}
@@ -110,10 +110,10 @@ dsn::task_ptr local_service::list_dir(const ls_request &req,
resp.err = ERR_OK;
if (::dsn::utils::filesystem::file_exists(dir_path)) {
- LOG_INFO("list_dir: invalid parameter(%s)", dir_path.c_str());
+ LOG_INFO_F("list_dir: invalid parameter({})", dir_path);
resp.err = ERR_INVALID_PARAMETERS;
} else if (!::dsn::utils::filesystem::directory_exists(dir_path)) {
- LOG_INFO("directory does not exist, dir = %s", dir_path.c_str());
+ LOG_INFO_F("directory does not exist, dir = {}", dir_path);
resp.err = ERR_OBJECT_NOT_FOUND;
} else {
if (!::dsn::utils::filesystem::get_subfiles(dir_path, children, false)) {
diff --git a/src/common/fs_manager.cpp b/src/common/fs_manager.cpp
index cd485728f..783e77c5b 100644
--- a/src/common/fs_manager.cpp
+++ b/src/common/fs_manager.cpp
@@ -177,10 +177,7 @@ dsn::error_code fs_manager::initialize(const std::vector<std::string> &data_dirs
utils::filesystem::get_normalized_path(data_dirs[i], norm_path);
dir_node *n = new dir_node(tags[i], norm_path);
_dir_nodes.emplace_back(n);
- LOG_INFO("%s: mark data dir(%s) as tag(%s)",
- dsn_primary_address().to_string(),
- norm_path.c_str(),
- tags[i].c_str());
+ LOG_INFO_F("{}: mark data dir({}) as tag({})", dsn_primary_address(), norm_path, tags[i]);
}
_available_data_dirs = data_dirs;
@@ -221,11 +218,7 @@ void fs_manager::add_replica(const gpid &pid, const std::string &pid_dir)
pid.get_partition_index(),
n->tag.c_str());
} else {
- LOG_INFO("%s: add gpid(%d.%d) to dir_node(%s)",
- dsn_primary_address().to_string(),
- pid.get_app_id(),
- pid.get_partition_index(),
- n->tag.c_str());
+ LOG_INFO_F("{}: add gpid({}) to dir_node({})", dsn_primary_address(), pid, n->tag);
}
}
}
@@ -258,12 +251,11 @@ void fs_manager::allocate_dir(const gpid &pid, const std::string &type, /*out*/
}
}
- LOG_INFO(
- "%s: put pid(%d.%d) to dir(%s), which has %u replicas of current app, %u replicas totally",
- dsn_primary_address().to_string(),
- pid.get_app_id(),
- pid.get_partition_index(),
- selected->tag.c_str(),
+ LOG_INFO_F(
+ "{}: put pid({}) to dir({}), which has {} replicas of current app, {} replicas totally",
+ dsn_primary_address(),
+ pid,
+ selected->tag,
least_app_replicas_count,
least_total_replicas_count);
@@ -283,11 +275,7 @@ void fs_manager::remove_replica(const gpid &pid)
pid,
n->tag);
if (r != 0) {
- LOG_INFO("%s: remove gpid(%d.%d) from dir(%s)",
- dsn_primary_address().to_string(),
- pid.get_app_id(),
- pid.get_partition_index(),
- n->tag.c_str());
+ LOG_INFO_F("{}: remove gpid({}) from dir({})", dsn_primary_address(), pid, n->tag);
}
remove_count += r;
}
diff --git a/src/failure_detector/failure_detector.cpp b/src/failure_detector/failure_detector.cpp
index bd89323bd..c042bbbbd 100644
--- a/src/failure_detector/failure_detector.cpp
+++ b/src/failure_detector/failure_detector.cpp
@@ -170,7 +170,7 @@ bool failure_detector::switch_master(::dsn::rpc_address from,
_masters.insert(std::make_pair(to, it->second));
_masters.erase(from);
- LOG_INFO("switch master successfully, from[%s], to[%s]", from.to_string(), to.to_string());
+ LOG_INFO_F("switch master successfully, from[{}], to[{}]", from, to);
} else {
LOG_WARNING("switch master failed as from node is not registered yet, from[%s], to[%s]",
from.to_string(),
@@ -184,10 +184,8 @@ bool failure_detector::is_time_greater_than(uint64_t ts, uint64_t base) { return
void failure_detector::report(::dsn::rpc_address node, bool is_master, bool is_connected)
{
- LOG_INFO("%s %sconnected: %s",
- is_master ? "master" : "worker",
- is_connected ? "" : "dis",
- node.to_string());
+ LOG_INFO_F(
+ "{} {}connected: {}", is_master ? "master" : "worker", is_connected ? "" : "dis", node);
}
/*
@@ -374,9 +372,9 @@ void failure_detector::on_ping_internal(const beacon_msg &beacon, /*out*/ beacon
// update last_beacon_recv_time
itr->second.last_beacon_recv_time = now;
- LOG_INFO("master %s update last_beacon_recv_time=%" PRId64,
- itr->second.node.to_string(),
- itr->second.last_beacon_recv_time);
+ LOG_INFO_F("master {} update last_beacon_recv_time={}",
+ itr->second.node,
+ itr->second.last_beacon_recv_time);
if (itr->second.is_alive == false) {
itr->second.is_alive = true;
@@ -385,9 +383,7 @@ void failure_detector::on_ping_internal(const beacon_msg &beacon, /*out*/ beacon
on_worker_connected(node);
}
} else {
- LOG_INFO("now[%" PRId64 "] <= last_recv_time[%" PRId64 "]",
- now,
- itr->second.last_beacon_recv_time);
+ LOG_INFO_F("now[{}] <= last_recv_time[{}]", now, itr->second.last_beacon_recv_time);
}
}
@@ -442,9 +438,9 @@ bool failure_detector::end_ping_internal(::dsn::error_code err, const beacon_ack
if (!is_time_greater_than(beacon_send_time, record.last_send_time_for_beacon_with_ack)) {
// out-dated beacon acks, do nothing
- LOG_INFO("ignore out dated beacon acks, send_time(%lld), last_beacon(%lld)",
- beacon_send_time,
- record.last_send_time_for_beacon_with_ack);
+ LOG_INFO_F("ignore out dated beacon acks, send_time({}), last_beacon({})",
+ beacon_send_time,
+ record.last_send_time_for_beacon_with_ack);
return false;
}
@@ -465,9 +461,9 @@ bool failure_detector::end_ping_internal(::dsn::error_code err, const beacon_ack
record.last_send_time_for_beacon_with_ack = beacon_send_time;
record.rejected = false;
- LOG_INFO("worker %s send beacon succeed, update last_send_time=%" PRId64,
- record.node.to_string(),
- record.last_send_time_for_beacon_with_ack);
+ LOG_INFO_F("worker {} send beacon succeed, update last_send_time={}",
+ record.node,
+ record.last_send_time_for_beacon_with_ack);
uint64_t now = dsn_now_ms();
// we should ensure now is greater than record.last_beacon_recv_time to aviod integer overflow
@@ -490,10 +486,10 @@ bool failure_detector::unregister_master(::dsn::rpc_address node)
if (it != _masters.end()) {
it->second.send_beacon_timer->cancel(true);
_masters.erase(it);
- LOG_INFO("unregister master[%s] successfully", node.to_string());
+ LOG_INFO_F("unregister master[{}] successfully", node);
return true;
} else {
- LOG_INFO("unregister master[%s] failed, cannot find it in FD", node.to_string());
+ LOG_INFO_F("unregister master[{}] failed, cannot find it in FD", node);
return false;
}
}
@@ -568,10 +564,8 @@ void failure_detector::send_beacon(::dsn::rpc_address target, uint64_t time)
beacon.to_addr = target;
beacon.__set_start_time(static_cast<int64_t>(dsn::utils::process_start_millis()));
- LOG_INFO("send ping message, from[%s], to[%s], time[%" PRId64 "]",
- beacon.from_addr.to_string(),
- beacon.to_addr.to_string(),
- time);
+ LOG_INFO_F(
+ "send ping message, from[{}], to[{}], time[{}]", beacon.from_addr, beacon.to_addr, time);
::dsn::rpc::call(target,
RPC_FD_FAILURE_DETECTOR_PING,
diff --git a/src/failure_detector/failure_detector_multimaster.cpp b/src/failure_detector/failure_detector_multimaster.cpp
index 907bb3d80..da72a0f58 100644
--- a/src/failure_detector/failure_detector_multimaster.cpp
+++ b/src/failure_detector/failure_detector_multimaster.cpp
@@ -74,14 +74,14 @@ void slave_failure_detector_with_multimaster::end_ping(::dsn::error_code err,
const fd::beacon_ack &ack,
void *)
{
- LOG_INFO("end ping result, error[%s], time[%" PRId64
- "], ack.this_node[%s], ack.primary_node[%s], ack.is_master[%s], ack.allowed[%s]",
- err.to_string(),
- ack.time,
- ack.this_node.to_string(),
- ack.primary_node.to_string(),
- ack.is_master ? "true" : "false",
- ack.allowed ? "true" : "false");
+ LOG_INFO_F("end ping result, error[{}], time[{}], ack.this_node[{}], ack.primary_node[{}], "
+ "ack.is_master[{}], ack.allowed[{}]",
+ err,
+ ack.time,
+ ack.this_node,
+ ack.primary_node,
+ ack.is_master ? "true" : "false",
+ ack.allowed ? "true" : "false");
zauto_lock l(failure_detector::_lock);
if (!failure_detector::end_ping_internal(err, ack))
diff --git a/src/http/pprof_http_service.cpp b/src/http/pprof_http_service.cpp
index 4f11dc69b..b57773ba2 100644
--- a/src/http/pprof_http_service.cpp
+++ b/src/http/pprof_http_service.cpp
@@ -73,7 +73,7 @@ static int extract_symbols_from_binary(std::map<uintptr_t, std::string> &addr_ma
std::string cmd = "nm -C -p ";
cmd.append(lib_info.path);
std::stringstream ss;
- LOG_INFO("executing `%s`", cmd.c_str());
+ LOG_INFO_F("executing `{}`", cmd);
const int rc = utils::pipe_execute(cmd.c_str(), ss);
if (rc < 0) {
LOG_ERROR("fail to popen `%s`", cmd.c_str());
@@ -162,7 +162,7 @@ static int extract_symbols_from_binary(std::map<uintptr_t, std::string> &addr_ma
addr_map[lib_info.end_addr] = std::string();
}
tm.stop();
- LOG_INFO("Loaded %s in %zdms", lib_info.path.c_str(), tm.m_elapsed());
+ LOG_INFO_F("Loaded {} in {}ms", lib_info.path, tm.m_elapsed().count());
return 0;
}
@@ -259,11 +259,11 @@ static void load_symbols()
}
tm2.stop();
if (num_removed) {
- LOG_INFO("Removed %zd entries in %zdms", num_removed, tm2.m_elapsed());
+ LOG_INFO_F("Removed {} entries in {}ms", num_removed, tm2.m_elapsed().count());
}
tm.stop();
- LOG_INFO("Loaded all symbols in %zdms", tm.m_elapsed());
+ LOG_INFO_F("Loaded all symbols in {}ms", tm.m_elapsed().count());
}
static void find_symbols(std::string *out, std::vector<uintptr_t> &addr_list)
@@ -401,7 +401,7 @@ ssize_t read_command_line(char *buf, size_t len, bool with_args)
}
}
if ((size_t)nr == len) {
- LOG_INFO("buf is not big enough");
+ LOG_INFO_F("buf is not big enough");
return -1;
}
return nr;
@@ -432,7 +432,7 @@ void pprof_http_service::growth_handler(const http_request &req, http_response &
}
MallocExtension *malloc_ext = MallocExtension::instance();
- LOG_INFO("received requests for growth profile");
+ LOG_INFO_F("received requests for growth profile");
malloc_ext->GetHeapGrowthStacks(&resp.body);
_in_pprof_action.store(false);
diff --git a/src/meta/server_state.cpp b/src/meta/server_state.cpp
index 120b742ce..ec11f038f 100644
--- a/src/meta/server_state.cpp
+++ b/src/meta/server_state.cpp
@@ -1922,10 +1922,7 @@ void server_state::on_update_configuration(
}
if (is_partition_config_equal(pc, cfg_request->config)) {
- LOG_INFO("duplicated update request for gpid(%d.%d), ballot: %" PRId64 "",
- gpid.get_app_id(),
- gpid.get_partition_index(),
- pc.ballot);
+ LOG_INFO_F("duplicated update request for gpid({}), ballot: {}", gpid, pc.ballot);
response.err = ERR_OK;
//
// NOTICE:
@@ -1934,21 +1931,18 @@ void server_state::on_update_configuration(
//
response.config = pc;
} else if (pc.ballot + 1 != cfg_request->config.ballot) {
- LOG_INFO(
- "update configuration for gpid(%d.%d) reject coz ballot not match, request ballot: "
- "%" PRId64 ", meta ballot: %" PRId64 "",
- gpid.get_app_id(),
- gpid.get_partition_index(),
- cfg_request->config.ballot,
- pc.ballot);
+ LOG_INFO_F("update configuration for gpid({}) reject coz ballot not match, request ballot: "
+ "{}, meta ballot: {}",
+ gpid,
+ cfg_request->config.ballot,
+ pc.ballot);
response.err = ERR_INVALID_VERSION;
response.config = pc;
} else if (config_status::pending_remote_sync == cc.stage) {
- LOG_INFO("another request is syncing with remote storage, ignore current request, "
- "gpid(%d.%d), request ballot(%" PRId64 ")",
- gpid.get_app_id(),
- gpid.get_partition_index(),
- cfg_request->config.ballot);
+ LOG_INFO_F("another request is syncing with remote storage, ignore current request, "
+ "gpid({}), request ballot({})",
+ gpid,
+ cfg_request->config.ballot);
// we don't reply the replica server, expect it to retry
msg->release_ref();
return;
@@ -1982,12 +1976,10 @@ void server_state::on_partition_node_dead(std::shared_ptr<app_state> &app,
if (!pc.primary.is_invalid())
downgrade_secondary_to_inactive(app, pidx, address);
else if (is_secondary(pc, address)) {
- LOG_INFO(
- "gpid(%d.%d): secondary(%s) is down, ignored it due to no primary for this "
- "partition available",
- pc.pid.get_app_id(),
- pc.pid.get_partition_index(),
- address.to_string());
+ LOG_INFO_F("gpid({}): secondary({}) is down, ignored it due to no primary for this "
+ "partition available",
+ pc.pid,
+ address);
} else {
CHECK(false, "no primary/secondary on this node, node address = {}", address);
}
@@ -2004,7 +1996,7 @@ void server_state::on_change_node_state(rpc_address node, bool is_alive)
if (!is_alive) {
auto iter = _nodes.find(node);
if (iter == _nodes.end()) {
- LOG_INFO("node(%s) doesn't exist in the node state, just ignore", node.to_string());
+ LOG_INFO_F("node({}) doesn't exist in the node state, just ignore", node);
} else {
node_state &ns = iter->second;
ns.set_alive(false);
@@ -2061,10 +2053,10 @@ server_state::construct_apps(const std::vector<query_app_info_response> &query_a
auto iter = _all_apps.find(info.app_id);
if (iter == _all_apps.end()) {
std::shared_ptr<app_state> app = app_state::create(info);
- LOG_INFO("create app info from (%s) for id(%d): %s",
- replica_nodes[i].to_string(),
- info.app_id,
- boost::lexical_cast<std::string>(info).c_str());
+ LOG_INFO_F("create app info from ({}) for id({}): {}",
+ replica_nodes[i],
+ info.app_id,
+ boost::lexical_cast<std::string>(info));
_all_apps.emplace(app->app_id, app);
max_app_id = std::max(app->app_id, max_app_id);
} else {
@@ -2134,7 +2126,7 @@ server_state::construct_apps(const std::vector<query_app_info_response> &query_a
checked_names.emplace(app->app_name, app_id);
}
- LOG_INFO("construct apps done, max_app_id = %d", max_app_id);
+ LOG_INFO_F("construct apps done, max_app_id = {}", max_app_id);
return dsn::ERR_OK;
}
@@ -2154,13 +2146,13 @@ error_code server_state::construct_partitions(
CHECK(_all_apps.find(r.pid.get_app_id()) != _all_apps.end(), "");
bool is_accepted = collect_replica({&_all_apps, &_nodes}, replica_nodes[i], r);
if (is_accepted) {
- LOG_INFO("accept replica(%s) from node(%s)",
- boost::lexical_cast<std::string>(r).c_str(),
- replica_nodes[i].to_string());
+ LOG_INFO_F("accept replica({}) from node({})",
+ boost::lexical_cast<std::string>(r),
+ replica_nodes[i]);
} else {
- LOG_INFO("ignore replica(%s) from node(%s)",
- boost::lexical_cast<std::string>(r).c_str(),
- replica_nodes[i].to_string());
+ LOG_INFO_F("ignore replica({}) from node({})",
+ boost::lexical_cast<std::string>(r),
+ replica_nodes[i]);
}
}
}
@@ -2173,16 +2165,16 @@ error_code server_state::construct_partitions(
"invalid app status, status = {}",
enum_to_string(app->status));
if (app->status == app_status::AS_DROPPING) {
- LOG_INFO("ignore constructing partitions for dropping app(%d)", app->app_id);
+ LOG_INFO_F("ignore constructing partitions for dropping app({})", app->app_id);
} else {
for (partition_configuration &pc : app->partitions) {
bool is_succeed =
construct_replica({&_all_apps, &_nodes}, pc.pid, app->max_replica_count);
if (is_succeed) {
- LOG_INFO("construct partition(%d.%d) succeed: %s",
- app->app_id,
- pc.pid.get_partition_index(),
- boost::lexical_cast<std::string>(pc).c_str());
+ LOG_INFO_F("construct partition({}.{}) succeed: {}",
+ app->app_id,
+ pc.pid.get_partition_index(),
+ boost::lexical_cast<std::string>(pc));
if (pc.last_drops.size() + 1 < pc.max_replica_count) {
std::ostringstream oss;
oss << "WARNING: partition(" << app->app_id << "."
@@ -2216,12 +2208,11 @@ error_code server_state::construct_partitions(
}
}
- LOG_INFO(
- "construct partition done, succeed_count = %d, failed_count = %d, skip_lost_partitions "
- "= %s",
- succeed_count,
- failed_count,
- (skip_lost_partitions ? "true" : "false"));
+ LOG_INFO_F("construct partition done, succeed_count = {}, failed_count = {}, "
+ "skip_lost_partitions = {}",
+ succeed_count,
+ failed_count,
+ skip_lost_partitions ? "true" : "false");
if (failed_count > 0 && !skip_lost_partitions) {
return dsn::ERR_TRY_AGAIN;
@@ -2244,7 +2235,7 @@ server_state::sync_apps_from_replica_nodes(const std::vector<dsn::rpc_address> &
dsn::task_tracker tracker;
for (int i = 0; i < n_replicas; ++i) {
- LOG_INFO("send query app and replica request to node(%s)", replica_nodes[i].to_string());
+ LOG_INFO_F("send query app and replica request to node({})", replica_nodes[i]);
auto app_query_req = std::make_unique<query_app_info_request>();
app_query_req->meta_server = dsn_primary_address();
@@ -2254,11 +2245,11 @@ server_state::sync_apps_from_replica_nodes(const std::vector<dsn::rpc_address> &
[app_rpc, i, &replica_nodes, &query_app_errors, &query_app_responses](
error_code err) mutable {
auto resp = app_rpc.response();
- LOG_INFO(
- "received query app response from node(%s), err(%s), apps_count(%d)",
- replica_nodes[i].to_string(),
- err.to_string(),
- (int)resp.apps.size());
+ LOG_INFO_F(
+ "received query app response from node({}), err({}), apps_count({})",
+ replica_nodes[i],
+ err,
+ resp.apps.size());
query_app_errors[i] = err;
if (err == dsn::ERR_OK) {
query_app_responses[i] = std::move(resp);
@@ -2274,11 +2265,11 @@ server_state::sync_apps_from_replica_nodes(const std::vector<dsn::rpc_address> &
[replica_rpc, i, &replica_nodes, &query_replica_errors, &query_replica_responses](
error_code err) mutable {
auto resp = replica_rpc.response();
- LOG_INFO(
- "received query replica response from node(%s), err(%s), replicas_count(%d)",
- replica_nodes[i].to_string(),
- err.to_string(),
- (int)resp.replicas.size());
+ LOG_INFO_F(
+ "received query replica response from node({}), err({}), replicas_count({})",
+ replica_nodes[i],
+ err,
+ resp.replicas.size());
query_replica_errors[i] = err;
if (err == dsn::ERR_OK) {
query_replica_responses[i] = std::move(resp);
@@ -2323,12 +2314,11 @@ server_state::sync_apps_from_replica_nodes(const std::vector<dsn::rpc_address> &
}
}
- LOG_INFO(
- "sync apps and replicas from replica nodes done, succeed_count = %d, failed_count = %d, "
- "skip_bad_nodes = %s",
- succeed_count,
- failed_count,
- (skip_bad_nodes ? "true" : "false"));
+ LOG_INFO_F("sync apps and replicas from replica nodes done, succeed_count = {}, failed_count = "
+ "{}, skip_bad_nodes = {}",
+ succeed_count,
+ failed_count,
+ skip_bad_nodes ? "true" : "false");
if (failed_count > 0 && !skip_bad_nodes) {
return dsn::ERR_TRY_AGAIN;
@@ -2355,10 +2345,10 @@ server_state::sync_apps_from_replica_nodes(const std::vector<dsn::rpc_address> &
void server_state::on_start_recovery(const configuration_recovery_request &req,
configuration_recovery_response &resp)
{
- LOG_INFO("start recovery, node_count = %d, skip_bad_nodes = %s, skip_lost_partitions = %s",
- (int)req.recovery_set.size(),
- req.skip_bad_nodes ? "true" : "false",
- req.skip_lost_partitions ? "true" : "false");
+ LOG_INFO_F("start recovery, node_count = {}, skip_bad_nodes = {}, skip_lost_partitions = {}",
+ req.recovery_set.size(),
+ req.skip_bad_nodes ? "true" : "false",
+ req.skip_lost_partitions ? "true" : "false");
resp.err = sync_apps_from_replica_nodes(
req.recovery_set, req.skip_bad_nodes, req.skip_lost_partitions, resp.hint_message);
@@ -2381,7 +2371,7 @@ void server_state::on_start_recovery(const configuration_recovery_request &req,
void server_state::clear_proposals()
{
- LOG_INFO("clear all exist proposals");
+ LOG_INFO_F("clear all exist proposals");
zauto_write_lock l(_lock);
for (auto &kv : _exist_apps) {
std::shared_ptr<app_state> &app = kv.second;
@@ -2395,9 +2385,9 @@ bool server_state::can_run_balancer()
for (auto iter = _nodes.begin(); iter != _nodes.end();) {
if (!iter->second.alive()) {
if (iter->second.partition_count() != 0) {
- LOG_INFO(
- "don't do replica migration coz dead node(%s) has %d partitions not removed",
- iter->second.addr().to_string(),
+ LOG_INFO_F(
+ "don't do replica migration coz dead node({}) has {} partitions not removed",
+ iter->second.addr(),
iter->second.partition_count());
return false;
}
@@ -2409,7 +2399,7 @@ bool server_state::can_run_balancer()
// table stability check
int c = count_staging_app();
if (c != 0) {
- LOG_INFO("don't do replica migration coz %d table(s) is(are) in staging state", c);
+ LOG_INFO_F("don't do replica migration coz {} table(s) is(are) in staging state", c);
return false;
}
return true;
@@ -2448,14 +2438,14 @@ bool server_state::check_all_partitions()
// first the cure stage
if (level <= meta_function_level::fl_freezed) {
- LOG_INFO("service is in level(%s), don't do any cure or balancer actions",
- _meta_function_level_VALUES_TO_NAMES.find(level)->second);
+ LOG_INFO_F("service is in level({}), don't do any cure or balancer actions",
+ _meta_function_level_VALUES_TO_NAMES.find(level)->second);
return false;
}
- LOG_INFO("start to check all partitions, add_secondary_enable_flow_control = %s, "
- "add_secondary_max_count_for_one_node = %d",
- _add_secondary_enable_flow_control ? "true" : "false",
- _add_secondary_max_count_for_one_node);
+ LOG_INFO_F("start to check all partitions, add_secondary_enable_flow_control = {}, "
+ "add_secondary_max_count_for_one_node = {}",
+ _add_secondary_enable_flow_control ? "true" : "false",
+ _add_secondary_max_count_for_one_node);
_meta_svc->get_partition_guardian()->clear_ddd_partitions();
int send_proposal_count = 0;
std::vector<configuration_proposal_action> add_secondary_actions;
@@ -2465,10 +2455,10 @@ bool server_state::check_all_partitions()
for (auto &app_pair : _exist_apps) {
std::shared_ptr<app_state> &app = app_pair.second;
if (app->status == app_status::AS_CREATING || app->status == app_status::AS_DROPPING) {
- LOG_INFO("ignore app(%s)(%d) because it's status is %s",
- app->app_name.c_str(),
- app->app_id,
- ::dsn::enum_to_string(app->status));
+ LOG_INFO_F("ignore app({})({}) because it's status is {}",
+ app->app_name,
+ app->app_id,
+ ::dsn::enum_to_string(app->status));
continue;
}
for (unsigned int i = 0; i != app->partition_count; ++i) {
@@ -2496,9 +2486,7 @@ bool server_state::check_all_partitions()
healthy_partitions++;
}
} else {
- LOG_INFO("ignore gpid(%d.%d) as it's stage is pending_remote_sync",
- pc.pid.get_app_id(),
- pc.pid.get_partition_index());
+ LOG_INFO_F("ignore gpid({}) as it's stage is pending_remote_sync", pc.pid);
}
}
total_partitions += app->partition_count;
@@ -2531,14 +2519,12 @@ bool server_state::check_all_partitions()
partition_configuration &pc = *get_config(_all_apps, pid);
if (_add_secondary_enable_flow_control &&
add_secondary_running_nodes[action.node] >= _add_secondary_max_count_for_one_node) {
- LOG_INFO(
- "do not send %s proposal for gpid(%d.%d) for flow control reason, target = "
- "%s, node = %s",
- ::dsn::enum_to_string(action.type),
- pc.pid.get_app_id(),
- pc.pid.get_partition_index(),
- action.target.to_string(),
- action.node.to_string());
+ LOG_INFO_F("do not send {} proposal for gpid({}) for flow control reason, target = "
+ "{}, node = {}",
+ ::dsn::enum_to_string(action.type),
+ pc.pid,
+ action.target,
+ action.node);
continue;
}
std::shared_ptr<app_state> app = get_app(pid.get_app_id());
@@ -2559,43 +2545,43 @@ bool server_state::check_all_partitions()
}
}
- LOG_INFO("check all partitions done, send_proposal_count = %d, add_secondary_count = %d, "
- "ignored_add_secondary_count = %d",
- send_proposal_count,
- add_secondary_count,
- ignored_add_secondary_count);
+ LOG_INFO_F("check all partitions done, send_proposal_count = {}, add_secondary_count = {}, "
+ "ignored_add_secondary_count = {}",
+ send_proposal_count,
+ add_secondary_count,
+ ignored_add_secondary_count);
// then the balancer stage
if (level < meta_function_level::fl_steady) {
- LOG_INFO("don't do replica migration coz meta server is in level(%s)",
- _meta_function_level_VALUES_TO_NAMES.find(level)->second);
+ LOG_INFO_F("don't do replica migration coz meta server is in level({})",
+ _meta_function_level_VALUES_TO_NAMES.find(level)->second);
return false;
}
if (healthy_partitions != total_partitions) {
- LOG_INFO("don't do replica migration coz %d of %d partitions aren't healthy",
- total_partitions - healthy_partitions,
- total_partitions);
+ LOG_INFO_F("don't do replica migration coz {}/{} partitions aren't healthy",
+ total_partitions - healthy_partitions,
+ total_partitions);
return false;
}
if (!can_run_balancer()) {
- LOG_INFO("don't do replica migration coz can_run_balancer() returns false");
+ LOG_INFO_F("don't do replica migration coz can_run_balancer() returns false");
return false;
}
if (level == meta_function_level::fl_steady) {
- LOG_INFO("check if any replica migration can be done when meta server is in level(%s)",
- _meta_function_level_VALUES_TO_NAMES.find(level)->second);
+ LOG_INFO_F("check if any replica migration can be done when meta server is in level({})",
+ _meta_function_level_VALUES_TO_NAMES.find(level)->second);
_meta_svc->get_balancer()->check({&_all_apps, &_nodes}, _temporary_list);
- LOG_INFO("balance checker operation count = %d", _temporary_list.size());
+ LOG_INFO_F("balance checker operation count = {}", _temporary_list.size());
// update balance checker operation count
_meta_svc->get_balancer()->report(_temporary_list, true);
return false;
}
if (_meta_svc->get_balancer()->balance({&_all_apps, &_nodes}, _temporary_list)) {
- LOG_INFO("try to do replica migration");
+ LOG_INFO_F("try to do replica migration");
_meta_svc->get_balancer()->apply_balancer({&_all_apps, &_nodes}, _temporary_list);
// update balancer action details
_meta_svc->get_balancer()->report(_temporary_list, false);
@@ -2607,9 +2593,9 @@ bool server_state::check_all_partitions()
return false;
}
- LOG_INFO("check if any replica migration left");
+ LOG_INFO_F("check if any replica migration left");
_meta_svc->get_balancer()->check({&_all_apps, &_nodes}, _temporary_list);
- LOG_INFO("balance checker operation count = %d", _temporary_list.size());
+ LOG_INFO_F("balance checker operation count = {}", _temporary_list.size());
// update balance checker operation count
_meta_svc->get_balancer()->report(_temporary_list, true);
@@ -2729,10 +2715,10 @@ void server_state::set_app_envs(const app_env_rpc &env_rpc)
os << keys[i] << "=" << values[i];
}
- LOG_INFO("set app envs for app(%s) from remote(%s): kvs = {%s}",
- app_name.c_str(),
- env_rpc.remote_address().to_string(),
- os.str().c_str());
+ LOG_INFO_F("set app envs for app({}) from remote({}): kvs = {}",
+ app_name,
+ env_rpc.remote_address(),
+ os.str());
app_info ainfo;
std::string app_path;
@@ -2762,9 +2748,7 @@ void server_state::set_app_envs(const app_env_rpc &env_rpc)
app->envs[keys[idx]] = values[idx];
}
std::string new_envs = dsn::utils::kv_map_to_string(app->envs, ',', '=');
- LOG_INFO("app envs changed: old_envs = {%s}, new_envs = {%s}",
- old_envs.c_str(),
- new_envs.c_str());
+ LOG_INFO_F("app envs changed: old_envs = {}, new_envs = {}", old_envs, new_envs);
});
}
@@ -2785,10 +2769,10 @@ void server_state::del_app_envs(const app_env_rpc &env_rpc)
os << ",";
os << keys[i];
}
- LOG_INFO("del app envs for app(%s) from remote(%s): keys = {%s}",
- app_name.c_str(),
- env_rpc.remote_address().to_string(),
- os.str().c_str());
+ LOG_INFO_F("del app envs for app({}) from remote({}): keys = {}",
+ app_name,
+ env_rpc.remote_address(),
+ os.str());
app_info ainfo;
std::string app_path;
@@ -2817,7 +2801,7 @@ void server_state::del_app_envs(const app_env_rpc &env_rpc)
}
if (deleted == 0) {
- LOG_INFO("no key need to delete");
+ LOG_INFO_F("no key need to delete");
env_rpc.response().hint_message = "no key need to delete";
return;
} else {
@@ -2834,9 +2818,7 @@ void server_state::del_app_envs(const app_env_rpc &env_rpc)
app->envs.erase(key);
}
std::string new_envs = dsn::utils::kv_map_to_string(app->envs, ',', '=');
- LOG_INFO("app envs changed: old_envs = {%s}, new_envs = {%s}",
- old_envs.c_str(),
- new_envs.c_str());
+ LOG_INFO_F("app envs changed: old_envs = {}, new_envs = {}", old_envs, new_envs);
});
}
@@ -2851,10 +2833,10 @@ void server_state::clear_app_envs(const app_env_rpc &env_rpc)
const std::string &prefix = request.clear_prefix;
const std::string &app_name = request.app_name;
- LOG_INFO("clear app envs for app(%s) from remote(%s): prefix = {%s}",
- app_name.c_str(),
- env_rpc.remote_address().to_string(),
- prefix.c_str());
+ LOG_INFO_F("clear app envs for app({}) from remote({}): prefix = {}",
+ app_name,
+ env_rpc.remote_address(),
+ prefix);
app_info ainfo;
std::string app_path;
@@ -2873,7 +2855,7 @@ void server_state::clear_app_envs(const app_env_rpc &env_rpc)
}
if (ainfo.envs.empty()) {
- LOG_INFO("no key need to delete");
+ LOG_INFO_F("no key need to delete");
env_rpc.response().hint_message = "no key need to delete";
return;
}
@@ -2908,7 +2890,7 @@ void server_state::clear_app_envs(const app_env_rpc &env_rpc)
if (!prefix.empty() && erase_keys.empty()) {
// no need update app_info
- LOG_INFO("no key need to delete");
+ LOG_INFO_F("no key need to delete");
env_rpc.response().hint_message = "no key need to delete";
return;
} else {
@@ -2930,9 +2912,7 @@ void server_state::clear_app_envs(const app_env_rpc &env_rpc)
}
}
std::string new_envs = dsn::utils::kv_map_to_string(app->envs, ',', '=');
- LOG_INFO("app envs changed: old_envs = {%s}, new_envs = {%s}",
- old_envs.c_str(),
- new_envs.c_str());
+ LOG_INFO_F("app envs changed: old_envs = {}, new_envs = {}", old_envs, new_envs);
});
}
diff --git a/src/perf_counter/test/perf_counter_test.cpp b/src/perf_counter/test/perf_counter_test.cpp
index 6944ad6b6..609317cf5 100644
--- a/src/perf_counter/test/perf_counter_test.cpp
+++ b/src/perf_counter/test/perf_counter_test.cpp
@@ -97,19 +97,19 @@ TEST(perf_counter, perf_counter_atomic)
"", "", "", dsn_perf_counter_type_t::COUNTER_TYPE_NUMBER, "");
perf_counter_inc_dec(counter);
perf_counter_add(counter, vec);
- LOG_INFO("%lf", counter->get_value());
+ LOG_INFO_F("{}", counter->get_value());
counter = new perf_counter_volatile_number_atomic(
"", "", "", dsn_perf_counter_type_t::COUNTER_TYPE_VOLATILE_NUMBER, "");
perf_counter_inc_dec(counter);
perf_counter_add(counter, vec);
- LOG_INFO("%lf", counter->get_value());
+ LOG_INFO_F("{}", counter->get_value());
counter =
new perf_counter_rate_atomic("", "", "", dsn_perf_counter_type_t::COUNTER_TYPE_RATE, "");
perf_counter_inc_dec(counter);
perf_counter_add(counter, vec);
- LOG_INFO("%lf", counter->get_value());
+ LOG_INFO_F("{}", counter->get_value());
counter = new perf_counter_number_percentile_atomic(
"", "", "", dsn_perf_counter_type_t::COUNTER_TYPE_NUMBER_PERCENTILES, "");
@@ -119,7 +119,7 @@ TEST(perf_counter, perf_counter_atomic)
counter->set(rand() % 10000);
// std::this_thread::sleep_for(std::chrono::seconds(sleep_interval));
for (int i = 0; i != COUNTER_PERCENTILE_COUNT; ++i)
- LOG_INFO("%lf", counter->get_percentile((dsn_perf_counter_percentile_type_t)i));
+ LOG_INFO_F("{}", counter->get_percentile((dsn_perf_counter_percentile_type_t)i));
}
}
diff --git a/src/redis_protocol/proxy_lib/proxy_layer.cpp b/src/redis_protocol/proxy_lib/proxy_layer.cpp
index d3af6009b..685860a85 100644
--- a/src/redis_protocol/proxy_lib/proxy_layer.cpp
+++ b/src/redis_protocol/proxy_lib/proxy_layer.cpp
@@ -96,7 +96,7 @@ void proxy_stub::remove_session(dsn::rpc_address remote_address)
LOG_WARNING("%s has been removed from proxy stub", remote_address.to_string());
return;
}
- LOG_INFO("remove %s from proxy stub", remote_address.to_string());
+ LOG_INFO_F("remove {} from proxy stub", remote_address);
session = std::move(iter->second);
_sessions.erase(iter);
}
@@ -116,7 +116,7 @@ proxy_session::proxy_session(proxy_stub *op, dsn::message_ex *first_msg)
proxy_session::~proxy_session()
{
_backup_one_request->release_ref();
- LOG_INFO("proxy session %s destroyed", _remote_address.to_string());
+ LOG_INFO_F("proxy session {} destroyed", _remote_address);
}
void proxy_session::on_recv_request(dsn::message_ex *msg)
diff --git a/src/redis_protocol/proxy_lib/redis_parser.cpp b/src/redis_protocol/proxy_lib/redis_parser.cpp
index e85fedb00..a81ae324f 100644
--- a/src/redis_protocol/proxy_lib/redis_parser.cpp
+++ b/src/redis_protocol/proxy_lib/redis_parser.cpp
@@ -97,7 +97,7 @@ redis_parser::~redis_parser()
{
clear_reply_queue();
reset_parser();
- LOG_INFO("%s: redis parser destroyed", _remote_address.to_string());
+ LOG_INFO_PREFIX("redis parser destroyed");
}
void redis_parser::prepare_current_buffer()
@@ -408,7 +408,7 @@ void redis_parser::default_handler(redis_parser::message_entry &entry)
{
::dsn::blob &cmd = entry.request.sub_requests[0].data;
std::string message = "unknown command '" + std::string(cmd.data(), cmd.length()) + "'";
- LOG_INFO_F("{}: {} with seqid {}", _remote_address.to_string(), message, entry.sequence_id);
+ LOG_INFO_PREFIX("{} with seqid {}", message, entry.sequence_id);
simple_error_reply(entry, message);
}
@@ -425,9 +425,7 @@ void redis_parser::set_internal(redis_parser::message_entry &entry)
{
redis_request &request = entry.request;
if (request.sub_requests.size() < 3) {
- LOG_INFO("%s: set command with invalid arguments, seqid(%" PRId64 ")",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SET command with invalid arguments, seqid({})", entry.sequence_id);
simple_error_reply(entry, "wrong number of arguments for 'set' command");
} else {
int ttl_seconds = 0;
@@ -435,15 +433,14 @@ void redis_parser::set_internal(redis_parser::message_entry &entry)
// with a reference to prevent the object from being destroyed
std::shared_ptr<proxy_session> ref_this = shared_from_this();
- LOG_DEBUG_PREFIX("send set command({})", entry.sequence_id);
+ LOG_DEBUG_PREFIX("send SET command({})", entry.sequence_id);
auto on_set_reply = [ref_this, this, &entry](
::dsn::error_code ec, dsn::message_ex *, dsn::message_ex *response) {
// when the "is_session_reset" flag is set, the socket may be broken.
// so continue to reply the message is not necessary
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: set command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SET command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -452,12 +449,10 @@ void redis_parser::set_internal(redis_parser::message_entry &entry)
//
// currently we only clear an entry when it is replied or
// in the redis_parser's destructor
- LOG_DEBUG_PREFIX("set command seqid({}) got reply", entry.sequence_id);
+ LOG_DEBUG_PREFIX("SET command seqid({}) got reply", entry.sequence_id);
if (::dsn::ERR_OK != ec) {
- LOG_INFO("%s: set command seqid(%" PRId64 ") got reply with error = %s",
- _remote_address.to_string(),
- entry.sequence_id,
- ec.to_string());
+ LOG_INFO_PREFIX(
+ "SET command seqid({}) got reply with error = {}", entry.sequence_id, ec);
simple_error_reply(entry, ec.to_string());
} else {
::dsn::apps::update_response rrdb_response;
@@ -504,9 +499,8 @@ void redis_parser::set_geo_internal(message_entry &entry)
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto set_callback = [ref_this, this, &entry](int ec, pegasus_client::internal_info &&) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SETEX command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -530,12 +524,10 @@ void redis_parser::setex(message_entry &entry)
redis_request &redis_req = entry.request;
// setex key ttl_SECONDS value
if (redis_req.sub_requests.size() != 4) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") with invalid arguments",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SETEX command seqid({}) with invalid arguments", entry.sequence_id);
simple_error_reply(entry, "wrong number of arguments for 'setex' command");
} else {
- LOG_DEBUG_PREFIX("send setex command seqid({})", entry.sequence_id);
+ LOG_DEBUG_PREFIX("send SETEX command seqid({})", entry.sequence_id);
::dsn::blob &ttl_blob = redis_req.sub_requests[2].data;
int ttl_seconds;
if (!dsn::buf2int32(ttl_blob, ttl_seconds)) {
@@ -551,17 +543,14 @@ void redis_parser::setex(message_entry &entry)
auto on_setex_reply = [ref_this, this, &entry](
::dsn::error_code ec, dsn::message_ex *, dsn::message_ex *response) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SETEX command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
if (::dsn::ERR_OK != ec) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") got reply with error = %s",
- _remote_address.to_string(),
- entry.sequence_id,
- ec.to_string());
+ LOG_INFO_PREFIX(
+ "SETEX command seqid({}) got reply with error = {}", entry.sequence_id, ec);
simple_error_reply(entry, ec.to_string());
return;
}
@@ -594,27 +583,22 @@ void redis_parser::get(message_entry &entry)
{
redis_request &redis_req = entry.request;
if (redis_req.sub_requests.size() != 2) {
- LOG_INFO("%s: get command seqid(%" PRId64 ") with invalid arguments",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("GET command seqid({}) with invalid arguments", entry.sequence_id);
simple_error_reply(entry, "wrong number of arguments for 'get' command");
} else {
- LOG_DEBUG_PREFIX("send get command seqid({})", entry.sequence_id);
+ LOG_DEBUG_PREFIX("send GET command seqid({})", entry.sequence_id);
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto on_get_reply = [ref_this, this, &entry](
::dsn::error_code ec, dsn::message_ex *, dsn::message_ex *response) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: get command(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("GET command({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
if (::dsn::ERR_OK != ec) {
- LOG_INFO("%s: get command seqid(%" PRId64 ") got reply with error = %s",
- _remote_address.to_string(),
- entry.sequence_id,
- ec.to_string());
+ LOG_INFO_PREFIX(
+ "GET command seqid({}) got reply with error = {}", entry.sequence_id, ec);
simple_error_reply(entry, ec.to_string());
} else {
::dsn::apps::read_response rrdb_response;
@@ -653,28 +637,23 @@ void redis_parser::del_internal(message_entry &entry)
{
redis_request &redis_req = entry.request;
if (redis_req.sub_requests.size() != 2) {
- LOG_INFO("%s: del command seqid(%" PRId64 ") with invalid arguments",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("DEL command seqid({}) with invalid arguments", entry.sequence_id);
simple_error_reply(entry, "wrong number of arguments for 'del' command");
} else {
- LOG_DEBUG_PREFIX("send del command seqid({})", entry.sequence_id);
+ LOG_DEBUG_PREFIX("send DEL command seqid({})", entry.sequence_id);
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto on_del_reply = [ref_this, this, &entry](
::dsn::error_code ec, dsn::message_ex *, dsn::message_ex *response) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: del command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("DEL command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
- LOG_DEBUG_PREFIX("del command seqid({}) got reply", entry.sequence_id);
+ LOG_DEBUG_PREFIX("DEL command seqid({}) got reply", entry.sequence_id);
if (::dsn::ERR_OK != ec) {
- LOG_INFO("%s: del command seqid(%" PRId64 ") got reply with error = %s",
- _remote_address.to_string(),
- entry.sequence_id,
- ec.to_string());
+ LOG_INFO_PREFIX(
+ "DEL command seqid({}) got reply with error = {}", entry.sequence_id, ec);
simple_error_reply(entry, ec.to_string());
} else {
::dsn::apps::read_response rrdb_response;
@@ -717,9 +696,8 @@ void redis_parser::del_geo_internal(message_entry &entry)
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto del_callback = [ref_this, this, &entry](int ec, pegasus_client::internal_info &&) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SETEX command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -743,29 +721,24 @@ void redis_parser::ttl(message_entry &entry)
redis_request &redis_req = entry.request;
bool is_ttl = (toupper(redis_req.sub_requests[0].data.data()[0]) == 'T');
if (redis_req.sub_requests.size() != 2) {
- LOG_INFO("%s: ttl/pttl command seqid(%" PRId64 ") with invalid arguments",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("TTL/PTTL command seqid({}) with invalid arguments", entry.sequence_id);
simple_error_reply(
entry, fmt::format("wrong number of arguments for '{}'", is_ttl ? "ttl" : "pttl"));
} else {
- LOG_DEBUG_PREFIX("send pttl/ttl command seqid({})", entry.sequence_id);
+ LOG_DEBUG_PREFIX("send PTTL/TTL command seqid({})", entry.sequence_id);
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto on_ttl_reply = [ref_this, this, &entry, is_ttl](
::dsn::error_code ec, dsn::message_ex *, dsn::message_ex *response) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: ttl/pttl command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("TTL/PTTL command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
- LOG_DEBUG_PREFIX("ttl/pttl command seqid({}) got reply", entry.sequence_id);
+ LOG_DEBUG_PREFIX("TTL/PTTL command seqid({}) got reply", entry.sequence_id);
if (::dsn::ERR_OK != ec) {
- LOG_INFO("%s: del command seqid(%" PRId64 ") got reply with error = %s",
- _remote_address.to_string(),
- entry.sequence_id,
- ec.to_string());
+ LOG_INFO_PREFIX(
+ "DEL command seqid({}) got reply with error = {}", entry.sequence_id, ec);
simple_error_reply(entry, ec.to_string());
} else {
::dsn::apps::ttl_response rrdb_response;
@@ -1080,9 +1053,8 @@ void redis_parser::process_geo_radius_result(message_entry &entry,
std::list<geo::SearchResult> &&results)
{
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: setex command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("SETEX command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -1166,9 +1138,8 @@ void redis_parser::geo_add(message_entry &entry)
auto set_latlng_callback = [ref_this, this, &entry, result, set_count](
int error_code, pegasus_client::internal_info &&info) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: GEOADD command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("GEOADD command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -1221,9 +1192,8 @@ void redis_parser::geo_dist(message_entry &entry)
std::shared_ptr<proxy_session> ref_this = shared_from_this();
auto get_callback = [ref_this, this, &entry, unit](int error_code, double &&distance) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: GEODIST command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("GEODIST command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
@@ -1269,9 +1239,8 @@ void redis_parser::geo_pos(message_entry &entry)
auto get_latlng_callback = [ref_this, this, &entry, result, get_count](
int error_code, int index, double lat_degrees, double lng_degrees) {
if (_is_session_reset.load(std::memory_order_acquire)) {
- LOG_INFO("%s: GEOPOS command seqid(%" PRId64 ") got reply, but session has reset",
- _remote_address.to_string(),
- entry.sequence_id);
+ LOG_INFO_PREFIX("GEOPOS command seqid({}) got reply, but session has reset",
+ entry.sequence_id);
return;
}
diff --git a/src/redis_protocol/proxy_ut/redis_proxy_test.cpp b/src/redis_protocol/proxy_ut/redis_proxy_test.cpp
index e2b312a27..40e6764f7 100644
--- a/src/redis_protocol/proxy_ut/redis_proxy_test.cpp
+++ b/src/redis_protocol/proxy_ut/redis_proxy_test.cpp
@@ -605,7 +605,7 @@ TEST(proxy, connection)
client_socket.shutdown(boost::asio::socket_base::shutdown_both);
client_socket.close();
} catch (...) {
- LOG_INFO("exception in shutdown");
+ LOG_INFO_F("exception in shutdown");
}
}
}
diff --git a/src/replica/backup/cold_backup_context.cpp b/src/replica/backup/cold_backup_context.cpp
index 6eeb7df7d..d66acd503 100644
--- a/src/replica/backup/cold_backup_context.cpp
+++ b/src/replica/backup/cold_backup_context.cpp
@@ -189,22 +189,23 @@ void cold_backup_context::check_backup_on_remote()
LPC_BACKGROUND_COLD_BACKUP,
[this, current_chkpt_file](const dist::block_service::create_file_response &resp) {
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else if (resp.err == ERR_OK) {
const dist::block_service::block_file_ptr &file_handle = resp.file_handle;
CHECK_NOTNULL(file_handle, "");
if (file_handle->get_md5sum().empty() && file_handle->get_size() <= 0) {
- LOG_INFO("%s: check backup on remote, current_checkpoint file %s is not exist",
- name,
- current_chkpt_file.c_str());
+ LOG_INFO_F(
+ "{}: check backup on remote, current_checkpoint file {} is not exist",
+ name,
+ current_chkpt_file);
complete_check(false);
} else {
- LOG_INFO("%s: check backup on remote, current_checkpoint file %s is exist",
- name,
- current_chkpt_file.c_str());
+ LOG_INFO_F("{}: check backup on remote, current_checkpoint file {} is exist",
+ name,
+ current_chkpt_file);
read_current_chkpt_file(file_handle);
}
} else if (resp.err == ERR_TIMEOUT) {
@@ -222,10 +223,10 @@ void cold_backup_context::check_backup_on_remote()
// before retry, should check whether the status is ready for
// check
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore "
- "checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore "
+ "checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else {
check_backup_on_remote();
@@ -259,19 +260,19 @@ void cold_backup_context::read_current_chkpt_file(
LPC_BACKGROUND_COLD_BACKUP,
[this, file_handle](const dist::block_service::read_response &resp) {
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else if (resp.err == ERR_OK) {
std::string chkpt_dirname(resp.buffer.data(), resp.buffer.length());
if (chkpt_dirname.empty()) {
complete_check(false);
} else {
- LOG_INFO("%s: after read current_checkpoint_file, check whether remote "
- "checkpoint dir = %s is exist",
- name,
- chkpt_dirname.c_str());
+ LOG_INFO_F("{}: after read current_checkpoint_file, check whether remote "
+ "checkpoint dir = {} is exist",
+ name,
+ chkpt_dirname);
remote_chkpt_dir_exist(chkpt_dirname);
}
} else if (resp.err == ERR_TIMEOUT) {
@@ -284,10 +285,10 @@ void cold_backup_context::read_current_chkpt_file(
nullptr,
[this, file_handle]() {
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore "
- "checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore "
+ "checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else {
read_current_chkpt_file(file_handle);
@@ -321,9 +322,9 @@ void cold_backup_context::remote_chkpt_dir_exist(const std::string &chkpt_dirnam
LPC_BACKGROUND_COLD_BACKUP,
[this, chkpt_dirname](const dist::block_service::ls_response &resp) {
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else if (resp.err == ERR_OK) {
bool found_chkpt_dir = false;
@@ -334,23 +335,25 @@ void cold_backup_context::remote_chkpt_dir_exist(const std::string &chkpt_dirnam
}
}
if (found_chkpt_dir) {
- LOG_INFO("%s: remote checkpoint dir is already exist, so upload have already "
- "complete, remote_checkpoint_dirname = %s",
- name,
- chkpt_dirname.c_str());
+ LOG_INFO_F("{}: remote checkpoint dir is already exist, so upload have already "
+ "complete, remote_checkpoint_dirname = {}",
+ name,
+ chkpt_dirname);
complete_check(true);
} else {
- LOG_INFO("%s: remote checkpoint dir is not exist, should re-upload checkpoint "
- "dir, remote_checkpoint_dirname = %s",
- name,
- chkpt_dirname.c_str());
+ LOG_INFO_F(
+ "{}: remote checkpoint dir is not exist, should re-upload checkpoint "
+ "dir, remote_checkpoint_dirname = {}",
+ name,
+ chkpt_dirname);
complete_check(false);
}
} else if (resp.err == ERR_OBJECT_NOT_FOUND) {
- LOG_INFO("%s: remote checkpoint dir is not exist, should re-upload checkpoint dir, "
- "remote_checkpoint_dirname = %s",
- name,
- chkpt_dirname.c_str());
+ LOG_INFO_F(
+ "{}: remote checkpoint dir is not exist, should re-upload checkpoint dir, "
+ "remote_checkpoint_dirname = {}",
+ name,
+ chkpt_dirname);
complete_check(false);
} else if (resp.err == ERR_TIMEOUT) {
LOG_ERROR(
@@ -363,10 +366,10 @@ void cold_backup_context::remote_chkpt_dir_exist(const std::string &chkpt_dirnam
nullptr,
[this, chkpt_dirname]() {
if (!is_ready_for_check()) {
- LOG_INFO("%s: backup status has changed to %s, ignore "
- "checking backup on remote",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore "
+ "checking backup on remote",
+ name,
+ cold_backup_status_to_string(status()));
ignore_check();
} else {
remote_chkpt_dir_exist(chkpt_dirname);
@@ -390,9 +393,9 @@ void cold_backup_context::remote_chkpt_dir_exist(const std::string &chkpt_dirnam
void cold_backup_context::upload_checkpoint_to_remote()
{
if (!is_ready_for_upload()) {
- LOG_INFO("%s: backup status has changed to %s, ignore upload checkpoint",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, ignore upload checkpoint",
+ name,
+ cold_backup_status_to_string(status()));
return;
}
@@ -401,8 +404,9 @@ void cold_backup_context::upload_checkpoint_to_remote()
// the result it has checked; But, because of upload_checkpoint_to_remote maybe call multi-times
// (for pause - uploading), so we use the atomic variant to implement
if (!_have_check_upload_status.compare_exchange_strong(old_status, true)) {
- LOG_INFO("%s: upload status has already been checked, start upload checkpoint dir directly",
- name);
+ LOG_INFO_F(
+ "{}: upload status has already been checked, start upload checkpoint dir directly",
+ name);
on_upload_chkpt_dir();
return;
}
@@ -424,12 +428,13 @@ void cold_backup_context::upload_checkpoint_to_remote()
CHECK_NOTNULL(resp.file_handle, "");
if (resp.file_handle->get_md5sum().empty() && resp.file_handle->get_size() <= 0) {
_upload_status.store(UploadUncomplete);
- LOG_INFO("%s: check upload_status complete, cold_backup_metadata isn't exist, "
- "start upload checkpoint dir",
- name);
+ LOG_INFO_F(
+ "{}: check upload_status complete, cold_backup_metadata isn't exist, "
+ "start upload checkpoint dir",
+ name);
on_upload_chkpt_dir();
} else {
- LOG_INFO("%s: cold_backup_metadata is exist, read it's context", name);
+ LOG_INFO_F("{}: cold_backup_metadata is exist, read it's context", name);
read_backup_metadata(resp.file_handle);
}
} else if (resp.err == ERR_TIMEOUT) {
@@ -446,8 +451,8 @@ void cold_backup_context::upload_checkpoint_to_remote()
nullptr,
[this]() {
if (!is_ready_for_upload()) {
- LOG_INFO(
- "%s: backup status has changed to %s, stop check upload status",
+ LOG_INFO_F(
+ "{}: backup status has changed to {}, stop check upload status",
name,
cold_backup_status_to_string(status()));
} else {
@@ -484,9 +489,9 @@ void cold_backup_context::read_backup_metadata(
LPC_BACKGROUND_COLD_BACKUP,
[this, file_handle](const dist::block_service::read_response &resp) {
if (resp.err == ERR_OK) {
- LOG_INFO("%s: read cold_backup_metadata succeed, verify it's context, file = %s",
- name,
- file_handle->file_name().c_str());
+ LOG_INFO_F("{}: read cold_backup_metadata succeed, verify it's context, file = {}",
+ name,
+ file_handle->file_name());
verify_backup_metadata(resp.buffer);
on_upload_chkpt_dir();
} else if (resp.err == ERR_TIMEOUT) {
@@ -500,8 +505,8 @@ void cold_backup_context::read_backup_metadata(
nullptr,
[this, file_handle] {
if (!is_ready_for_upload()) {
- LOG_INFO(
- "%s: backup status has changed to %s, stop check upload status",
+ LOG_INFO_F(
+ "{}: backup status has changed to {}, stop check upload status",
name,
cold_backup_status_to_string(status()));
_have_check_upload_status.store(false);
@@ -529,12 +534,13 @@ void cold_backup_context::verify_backup_metadata(const blob &value)
{
cold_backup_metadata tmp;
if (value.length() > 0 && json::json_forwarder<cold_backup_metadata>::decode(value, tmp)) {
- LOG_INFO("%s: check upload status complete, checkpoint dir uploading has already complete",
- name);
+ LOG_INFO_F(
+ "{}: check upload status complete, checkpoint dir uploading has already complete",
+ name);
_upload_status.store(UploadComplete);
} else {
- LOG_INFO("%s: check upload status complete, checkpoint dir uploading isn't complete yet",
- name);
+ LOG_INFO_F("{}: check upload status complete, checkpoint dir uploading isn't complete yet",
+ name);
_upload_status.store(UploadUncomplete);
}
}
@@ -542,9 +548,9 @@ void cold_backup_context::verify_backup_metadata(const blob &value)
void cold_backup_context::on_upload_chkpt_dir()
{
if (_upload_status.load() == UploadInvalid || !is_ready_for_upload()) {
- LOG_INFO("%s: replica is not ready for uploading, ignore upload, cold_backup_status(%s)",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: replica is not ready for uploading, ignore upload, cold_backup_status({})",
+ name,
+ cold_backup_status_to_string(status()));
return;
}
@@ -567,9 +573,9 @@ void cold_backup_context::on_upload_chkpt_dir()
}
if (checkpoint_files.size() <= 0) {
- LOG_INFO("%s: checkpoint dir is empty, so upload is complete and just start write "
- "backup_metadata",
- name);
+ LOG_INFO_F("{}: checkpoint dir is empty, so upload is complete and just start write "
+ "backup_metadata",
+ name);
bool old_status = false;
// using atomic variant _have_write_backup_metadata is to allow one task to
// write backup_metadata because on_upload_chkpt_dir maybe call multi-time
@@ -577,21 +583,21 @@ void cold_backup_context::on_upload_chkpt_dir()
write_backup_metadata();
}
} else {
- LOG_INFO("%s: start upload checkpoint dir, checkpoint dir = %s, total checkpoint file = %d",
- name,
- checkpoint_dir.c_str(),
- checkpoint_files.size());
+ LOG_INFO_F(
+ "{}: start upload checkpoint dir, checkpoint dir = {}, total checkpoint file = {}",
+ name,
+ checkpoint_dir,
+ checkpoint_files.size());
std::vector<std::string> files;
if (!upload_complete_or_fetch_uncomplete_files(files)) {
for (auto &file : files) {
- LOG_INFO(
- "%s: start upload checkpoint file to remote, file = %s", name, file.c_str());
+ LOG_INFO_F("{}: start upload checkpoint file to remote, file = {}", name, file);
upload_file(file);
}
} else {
- LOG_INFO("%s: upload checkpoint dir to remote complete, total_file_cnt = %d",
- name,
- checkpoint_files.size());
+ LOG_INFO_F("{}: upload checkpoint dir to remote complete, total_file_cnt = {}",
+ name,
+ checkpoint_files.size());
bool old_status = false;
if (_have_write_backup_metadata.compare_exchange_strong(old_status, true)) {
write_backup_metadata();
@@ -657,14 +663,14 @@ void cold_backup_context::upload_file(const std::string &local_filename)
::dsn::utils::filesystem::path_combine(checkpoint_dir, local_filename);
if (md5 == file_handle->get_md5sum() &&
local_file_size == file_handle->get_size()) {
- LOG_INFO("%s: checkpoint file already exist on remote, file = %s",
- name,
- full_path_local_file.c_str());
+ LOG_INFO_F("{}: checkpoint file already exist on remote, file = {}",
+ name,
+ full_path_local_file);
on_upload_file_complete(local_filename);
} else {
- LOG_INFO("%s: start upload checkpoint file to remote, file = %s",
- name,
- full_path_local_file.c_str());
+ LOG_INFO_F("{}: start upload checkpoint file to remote, file = {}",
+ name,
+ full_path_local_file);
on_upload(file_handle, full_path_local_file);
}
} else if (resp.err == ERR_TIMEOUT) {
@@ -689,12 +695,11 @@ void cold_backup_context::upload_file(const std::string &local_filename)
std::string full_path_local_file =
::dsn::utils::filesystem::path_combine(checkpoint_dir,
local_filename);
- LOG_INFO(
- "%s: backup status has changed to %s, stop upload "
- "checkpoint file to remote, file = %s",
- name,
- cold_backup_status_to_string(status()),
- full_path_local_file.c_str());
+ LOG_INFO_F("{}: backup status has changed to {}, stop "
+ "upload checkpoint file to remote, file = {}",
+ name,
+ cold_backup_status_to_string(status()),
+ full_path_local_file);
file_upload_uncomplete(local_filename);
} else {
upload_file(local_filename);
@@ -737,9 +742,8 @@ void cold_backup_context::on_upload(const dist::block_service::block_file_ptr &f
::dsn::utils::filesystem::get_file_name(full_path_local_file);
CHECK_EQ(_file_infos.at(local_filename).first,
static_cast<int64_t>(resp.uploaded_size));
- LOG_INFO("%s: upload checkpoint file complete, file = %s",
- name,
- full_path_local_file.c_str());
+ LOG_INFO_F(
+ "{}: upload checkpoint file complete, file = {}", name, full_path_local_file);
on_upload_file_complete(local_filename);
} else if (resp.err == ERR_TIMEOUT) {
LOG_ERROR("%s: upload checkpoint file timeout, retry after 10s, file = %s",
@@ -786,7 +790,7 @@ void cold_backup_context::on_upload(const dist::block_service::block_file_ptr &f
void cold_backup_context::write_backup_metadata()
{
if (_upload_status.load() == UploadComplete) {
- LOG_INFO("%s: upload have already done, no need write metadata again", name);
+ LOG_INFO_F("{}: upload have already done, no need write metadata again", name);
return;
}
std::string metadata = cold_backup::get_remote_chkpt_meta_file(
@@ -806,15 +810,16 @@ void cold_backup_context::write_backup_metadata()
blob buffer = json::json_forwarder<cold_backup_metadata>::encode(_metadata);
// hold itself until callback is executed
add_ref();
- LOG_INFO("%s: create backup metadata file succeed, start to write file, file = %s",
- name,
- metadata.c_str());
+ LOG_INFO_F(
+ "{}: create backup metadata file succeed, start to write file, file = {}",
+ name,
+ metadata);
this->on_write(resp.file_handle, buffer, [this](bool succeed) {
if (succeed) {
std::string chkpt_dirname = cold_backup::get_remote_chkpt_dirname();
_upload_status.store(UploadComplete);
- LOG_INFO(
- "%s: write backup metadata complete, write current checkpoint file",
+ LOG_INFO_F(
+ "{}: write backup metadata complete, write current checkpoint file",
name);
write_current_chkpt_file(chkpt_dirname);
}
@@ -867,9 +872,9 @@ void cold_backup_context::write_current_chkpt_file(const std::string &value)
_file_status.clear();
if (!is_ready_for_upload()) {
- LOG_INFO("%s: backup status has changed to %s, stop write current checkpoint file",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F("{}: backup status has changed to {}, stop write current checkpoint file",
+ name,
+ cold_backup_status_to_string(status()));
return;
}
@@ -891,9 +896,10 @@ void cold_backup_context::write_current_chkpt_file(const std::string &value)
std::shared_ptr<char> buf = utils::make_shared_array<char>(len);
::memcpy(buf.get(), value.c_str(), len);
blob write_buf(std::move(buf), static_cast<unsigned int>(len));
- LOG_INFO("%s: create current checkpoint file succeed, start write file ,file = %s",
- name,
- current_chkpt_file.c_str());
+ LOG_INFO_F(
+ "{}: create current checkpoint file succeed, start write file ,file = {}",
+ name,
+ current_chkpt_file);
add_ref();
this->on_write(resp.file_handle, write_buf, [this](bool succeed) {
if (succeed) {
@@ -911,10 +917,11 @@ void cold_backup_context::write_current_chkpt_file(const std::string &value)
nullptr,
[this, value]() {
if (!is_ready_for_upload()) {
- LOG_INFO("%s: backup status has changed to %s, stop write "
- "current checkpoint file",
- name,
- cold_backup_status_to_string(status()));
+ LOG_INFO_F(
+ "{}: backup status has changed to {}, stop write "
+ "current checkpoint file",
+ name,
+ cold_backup_status_to_string(status()));
} else {
write_current_chkpt_file(value);
}
@@ -950,25 +957,25 @@ void cold_backup_context::on_write(const dist::block_service::block_file_ptr &fi
LPC_BACKGROUND_COLD_BACKUP,
[this, value, file_handle, callback](const dist::block_service::write_response &resp) {
if (resp.err == ERR_OK) {
- LOG_INFO("%s: write remote file succeed, file = %s",
- name,
- file_handle->file_name().c_str());
+ LOG_INFO_F(
+ "{}: write remote file succeed, file = {}", name, file_handle->file_name());
callback(true);
} else if (resp.err == ERR_TIMEOUT) {
- LOG_INFO("%s: write remote file timeout, retry after 10s, file = %s",
- name,
- file_handle->file_name().c_str());
+ LOG_INFO_F("{}: write remote file timeout, retry after 10s, file = {}",
+ name,
+ file_handle->file_name());
add_ref();
tasking::enqueue(LPC_BACKGROUND_COLD_BACKUP,
nullptr,
[this, file_handle, value, callback]() {
if (!is_ready_for_upload()) {
- LOG_INFO("%s: backup status has changed to %s, stop write "
- "remote file, file = %s",
- name,
- cold_backup_status_to_string(status()),
- file_handle->file_name().c_str());
+ LOG_INFO_F(
+ "{}: backup status has changed to {}, stop write "
+ "remote file, file = {}",
+ name,
+ cold_backup_status_to_string(status()),
+ file_handle->file_name());
} else {
on_write(file_handle, value, callback);
}
@@ -1008,12 +1015,12 @@ void cold_backup_context::on_upload_file_complete(const std::string &local_filen
auto complete_size = static_cast<double>(_upload_file_size.load());
if (total <= complete_size) {
- LOG_INFO("%s: upload checkpoint to remote complete, checkpoint dir = %s, total file size = "
- "%" PRId64 ", file count = %d",
- name,
- checkpoint_dir.c_str(),
- static_cast<int64_t>(total),
- checkpoint_files.size());
+ LOG_INFO_F("{}: upload checkpoint to remote complete, checkpoint dir = {}, total file size "
+ "= {}, file count = {}",
+ name,
+ checkpoint_dir,
+ total,
+ checkpoint_files.size());
bool old_status = false;
if (_have_write_backup_metadata.compare_exchange_strong(old_status, true)) {
write_backup_metadata();
@@ -1022,13 +1029,13 @@ void cold_backup_context::on_upload_file_complete(const std::string &local_filen
} else {
CHECK_GT(total, 0.0);
update_progress(static_cast<int>(complete_size / total * 1000));
- LOG_INFO("%s: the progress of upload checkpoint is %d", name, _progress.load());
+ LOG_INFO_F("{}: the progress of upload checkpoint is {}", name, _progress);
}
if (is_ready_for_upload()) {
std::vector<std::string> upload_files;
upload_complete_or_fetch_uncomplete_files(upload_files);
for (auto &file : upload_files) {
- LOG_INFO("%s: start upload checkpoint file to remote, file = %s", name, file.c_str());
+ LOG_INFO_F("{}: start upload checkpoint file to remote, file = {}", name, file);
upload_file(file);
}
}
diff --git a/src/replica/duplication/duplication_sync_timer.cpp b/src/replica/duplication/duplication_sync_timer.cpp
index a3520403d..669b6221c 100644
--- a/src/replica/duplication/duplication_sync_timer.cpp
+++ b/src/replica/duplication/duplication_sync_timer.cpp
@@ -139,7 +139,7 @@ std::vector<replica_ptr> duplication_sync_timer::get_all_replicas()
void duplication_sync_timer::close()
{
- LOG_INFO("stop duplication sync");
+ LOG_INFO_F("stop duplication sync");
{
zauto_lock l(_lock);
diff --git a/src/replica/replica_stub.cpp b/src/replica/replica_stub.cpp
index 7d0bcf8b7..83fa5930f 100644
--- a/src/replica/replica_stub.cpp
+++ b/src/replica/replica_stub.cpp
@@ -480,7 +480,7 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
{
_primary_address = dsn_primary_address();
strcpy(_primary_address_str, _primary_address.to_string());
- LOG_INFO("primary_address = %s", _primary_address_str);
+ LOG_INFO_F("primary_address = {}", _primary_address_str);
set_options(opts);
std::ostringstream oss;
@@ -489,7 +489,7 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
oss << ",";
oss << _options.meta_servers[i].to_string();
}
- LOG_INFO("meta_servers = %s", oss.str().c_str());
+ LOG_INFO_F("meta_servers = {}", oss.str());
_deny_client = _options.deny_client_on_start;
_verbose_client_log = _options.verbose_client_log_on_start;
@@ -521,10 +521,10 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
_options.log_shared_file_size_mb,
_options.log_shared_force_flush,
&_counter_shared_log_recent_write_size);
- LOG_INFO("slog_dir = %s", _options.slog_dir.c_str());
+ LOG_INFO_F("slog_dir = {}", _options.slog_dir);
// init rps
- LOG_INFO("start to load replicas");
+ LOG_INFO_F("start to load replicas");
std::vector<std::string> dir_list;
for (auto &dir : _fs_manager.get_available_data_dirs()) {
@@ -545,33 +545,33 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
continue;
}
- load_tasks.push_back(tasking::create_task(
- LPC_REPLICATION_INIT_LOAD,
- &_tracker,
- [this, dir, &rps, &rps_lock] {
- LOG_INFO("process dir %s", dir.c_str());
-
- auto r = replica::load(this, dir.c_str());
- if (r != nullptr) {
- LOG_INFO("%s@%s: load replica '%s' success, <durable, commit> = <%" PRId64
- ", %" PRId64 ">, last_prepared_decree = %" PRId64,
- r->get_gpid().to_string(),
- dsn_primary_address().to_string(),
- dir.c_str(),
- r->last_durable_decree(),
- r->last_committed_decree(),
- r->last_prepared_decree());
-
- utils::auto_lock<utils::ex_lock> l(rps_lock);
- CHECK(rps.find(r->get_gpid()) == rps.end(),
- "conflict replica dir: {} <--> {}",
- r->dir(),
- rps[r->get_gpid()]->dir());
-
- rps[r->get_gpid()] = r;
- }
- },
- load_tasks.size()));
+ load_tasks.push_back(
+ tasking::create_task(LPC_REPLICATION_INIT_LOAD,
+ &_tracker,
+ [this, dir, &rps, &rps_lock] {
+ LOG_INFO_F("process dir {}", dir);
+
+ auto r = replica::load(this, dir.c_str());
+ if (r != nullptr) {
+ LOG_INFO_F("{}@{}: load replica '{}' success, <durable, "
+ "commit> = <{}, {}>, last_prepared_decree = {}",
+ r->get_gpid(),
+ dsn_primary_address(),
+ dir,
+ r->last_durable_decree(),
+ r->last_committed_decree(),
+ r->last_prepared_decree());
+
+ utils::auto_lock<utils::ex_lock> l(rps_lock);
+ CHECK(rps.find(r->get_gpid()) == rps.end(),
+ "conflict replica dir: {} <--> {}",
+ r->dir(),
+ rps[r->get_gpid()]->dir());
+
+ rps[r->get_gpid()] = r;
+ }
+ },
+ load_tasks.size()));
load_tasks.back()->enqueue();
}
for (auto &tsk : load_tasks) {
@@ -581,12 +581,12 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
dir_list.clear();
load_tasks.clear();
- LOG_INFO("load replicas succeed, replica_count = %d, time_used = %" PRIu64 " ms",
- static_cast<int>(rps.size()),
- finish_time - start_time);
+ LOG_INFO_F("load replicas succeed, replica_count = {}, time_used = {} ms",
+ rps.size(),
+ finish_time - start_time);
// init shared prepare log
- LOG_INFO("start to replay shared log");
+ LOG_INFO_F("start to replay shared log");
std::map<gpid, decree> replay_condition;
for (auto it = rps.begin(); it != rps.end(); ++it) {
@@ -608,7 +608,7 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
finish_time = dsn_now_ms();
if (err == ERR_OK) {
- LOG_INFO("replay shared log succeed, time_used = %" PRIu64 " ms", finish_time - start_time);
+ LOG_INFO_F("replay shared log succeed, time_used = {} ms", finish_time - start_time);
} else {
LOG_ERROR("replay shared log failed, err = %s, time_used = %" PRIu64
" ms, clear all logs ...",
@@ -734,7 +734,7 @@ void replica_stub::initialize(const replication_options &opts, bool clear /* = f
(_options.fd_grace_seconds + 3) * 1000; // for more 3 seconds than grace seconds
if (now_time_ms < dsn::utils::process_start_millis() + delay_time_ms) {
uint64_t delay = dsn::utils::process_start_millis() + delay_time_ms - now_time_ms;
- LOG_INFO("delay for %" PRIu64 "ms to make failure detector timeout", delay);
+ LOG_INFO_F("delay for {} ms to make failure detector timeout", delay);
tasking::enqueue(LPC_REPLICA_SERVER_DELAY_START,
&_tracker,
[this]() { this->initialize_start(); },
@@ -842,7 +842,7 @@ void replica_stub::initialize_start()
dsn::error_code replica_stub::on_kill_replica(gpid id)
{
- LOG_INFO("kill replica: gpid = %s", id.to_string());
+ LOG_INFO_F("kill replica: gpid = {}", id);
if (id.get_app_id() == -1 || id.get_partition_index() == -1) {
replicas rs;
{
@@ -899,12 +899,12 @@ void replica_stub::on_client_write(gpid id, dsn::message_ex *request)
return;
}
if (_verbose_client_log && request) {
- LOG_INFO("%s@%s: client = %s, code = %s, timeout = %d",
- id.to_string(),
- _primary_address_str,
- request->header->from_address.to_string(),
- request->header->rpc_name,
- request->header->client.timeout_ms);
+ LOG_INFO_F("{}@{}: client = {}, code = {}, timeout = {}",
+ id,
+ _primary_address_str,
+ request->header->from_address,
+ request->header->rpc_name,
+ request->header->client.timeout_ms);
}
replica_ptr rep = get_replica(id);
if (rep != nullptr) {
@@ -921,12 +921,12 @@ void replica_stub::on_client_read(gpid id, dsn::message_ex *request)
return;
}
if (_verbose_client_log && request) {
- LOG_INFO("%s@%s: client = %s, code = %s, timeout = %d",
- id.to_string(),
- _primary_address_str,
- request->header->from_address.to_string(),
- request->header->rpc_name,
- request->header->client.timeout_ms);
+ LOG_INFO_F("{}@{}: client = {}, code = {}, timeout = {}",
+ id,
+ _primary_address_str,
+ request->header->from_address,
+ request->header->rpc_name,
+ request->header->client.timeout_ms);
}
replica_ptr rep = get_replica(id);
if (rep != nullptr) {
@@ -947,11 +947,11 @@ void replica_stub::on_config_proposal(const configuration_update_request &propos
return;
}
- LOG_INFO("%s@%s: received config proposal %s for %s",
- proposal.config.pid.to_string(),
- _primary_address_str,
- enum_to_string(proposal.type),
- proposal.node.to_string());
+ LOG_INFO_F("{}@{}: received config proposal {} for {}",
+ proposal.config.pid,
+ _primary_address_str,
+ enum_to_string(proposal.type),
+ proposal.node);
replica_ptr rep = get_replica(proposal.config.pid);
if (rep == nullptr) {
@@ -1099,7 +1099,7 @@ void replica_stub::on_query_app_info(query_app_info_rpc rpc)
const query_app_info_request &req = rpc.request();
query_app_info_response &resp = rpc.response();
- LOG_INFO("got query app info request from (%s)", req.meta_server.to_string());
+ LOG_INFO_F("got query app info request from ({})", req.meta_server);
resp.err = dsn::ERR_OK;
std::set<app_id> visited_apps;
{
@@ -1202,14 +1202,14 @@ void replica_stub::on_group_check(group_check_rpc rpc)
return;
}
- LOG_INFO("%s@%s: received group check, primary = %s, ballot = %" PRId64
- ", status = %s, last_committed_decree = %" PRId64,
- request.config.pid.to_string(),
- _primary_address_str,
- request.config.primary.to_string(),
- request.config.ballot,
- enum_to_string(request.config.status),
- request.last_committed_decree);
+ LOG_INFO_F("{}@{}: received group check, primary = {}, ballot = {}, status = {}, "
+ "last_committed_decree = {}",
+ request.config.pid,
+ _primary_address_str,
+ request.config.primary,
+ request.config.ballot,
+ enum_to_string(request.config.status),
+ request.last_committed_decree);
replica_ptr rep = get_replica(request.config.pid);
if (rep != nullptr) {
@@ -1267,14 +1267,14 @@ void replica_stub::on_add_learner(const group_check_request &request)
return;
}
- LOG_INFO("%s@%s: received add learner, primary = %s, ballot = %" PRId64
- ", status = %s, last_committed_decree = %" PRId64,
- request.config.pid.to_string(),
- _primary_address_str,
- request.config.primary.to_string(),
- request.config.ballot,
- enum_to_string(request.config.status),
- request.last_committed_decree);
+ LOG_INFO_F("{}@{}: received add learner, primary = {}, ballot ={}, status = {}, "
+ "last_committed_decree = {}",
+ request.config.pid,
+ _primary_address_str,
+ request.config.primary,
+ request.config.ballot,
+ enum_to_string(request.config.status),
+ request.last_committed_decree);
replica_ptr rep = get_replica(request.config.pid);
if (rep != nullptr) {
@@ -1363,8 +1363,8 @@ void replica_stub::query_configuration_by_node()
::dsn::marshall(msg, req);
- LOG_INFO("send query node partitions request to meta server, stored_replicas_count = %d",
- (int)req.stored_replicas.size());
+ LOG_INFO_F("send query node partitions request to meta server, stored_replicas_count = {}",
+ req.stored_replicas.size());
rpc_address target(_failure_detector->get_servers());
_config_query_task =
@@ -1378,7 +1378,7 @@ void replica_stub::query_configuration_by_node()
void replica_stub::on_meta_server_connected()
{
- LOG_INFO("meta server connected");
+ LOG_INFO_F("meta server connected");
zauto_lock l(_state_lock);
if (_state == NS_Disconnected) {
@@ -1395,7 +1395,7 @@ void replica_stub::on_node_query_reply(error_code err,
dsn::message_ex *request,
dsn::message_ex *response)
{
- LOG_INFO("query node partitions replied, err = %s", err.to_string());
+ LOG_INFO_F("query node partitions replied, err = {}", err);
zauto_lock l(_state_lock);
_config_query_task = nullptr;
@@ -1417,8 +1417,8 @@ void replica_stub::on_node_query_reply(error_code err,
if (resp.err == ERR_BUSY) {
int delay_ms = 500;
- LOG_INFO("resend query node partitions request after %d ms for resp.err = ERR_BUSY",
- delay_ms);
+ LOG_INFO_F("resend query node partitions request after {} ms for resp.err = ERR_BUSY",
+ delay_ms);
_config_query_task = tasking::enqueue(LPC_QUERY_CONFIGURATION_ALL,
&_tracker,
[this]() {
@@ -1431,8 +1431,7 @@ void replica_stub::on_node_query_reply(error_code err,
return;
}
if (resp.err != ERR_OK) {
- LOG_INFO("ignore query node partitions response for resp.err = %s",
- resp.err.to_string());
+ LOG_INFO_F("ignore query node partitions response for resp.err = {}", resp.err);
return;
}
@@ -1515,15 +1514,15 @@ void replica_stub::on_node_query_reply_scatter(replica_stub_ptr this_,
: split_status::NOT_SPLIT);
} else {
if (req.config.primary == _primary_address) {
- LOG_INFO("%s@%s: replica not exists on replica server, which is primary, remove it "
- "from meta server",
- req.config.pid.to_string(),
- _primary_address_str);
+ LOG_INFO_F("{}@{}: replica not exists on replica server, which is primary, remove it "
+ "from meta server",
+ req.config.pid,
+ _primary_address_str);
remove_replica_on_meta_server(req.info, req.config);
} else {
- LOG_INFO(
- "%s@%s: replica not exists on replica server, which is not primary, just ignore",
- req.config.pid.to_string(),
+ LOG_INFO_F(
+ "{}@{}: replica not exists on replica server, which is not primary, just ignore",
+ req.config.pid,
_primary_address_str);
}
}
@@ -1538,11 +1537,11 @@ void replica_stub::on_node_query_reply_scatter2(replica_stub_ptr this_, gpid id)
if (replica->status() == partition_status::PS_INACTIVE &&
dsn_now_ms() - replica->create_time_milliseconds() <
_options.gc_memory_replica_interval_ms) {
- LOG_INFO("%s: replica not exists on meta server, wait to close", replica->name());
+ LOG_INFO_F("{}: replica not exists on meta server, wait to close", replica->name());
return;
}
- LOG_INFO("%s: replica not exists on meta server, remove", replica->name());
+ LOG_INFO_F("{}: replica not exists on meta server, remove", replica->name());
// TODO: set PS_INACTIVE instead for further state reuse
replica->update_local_configuration_with_no_ballot_change(partition_status::PS_ERROR);
@@ -1579,7 +1578,7 @@ void replica_stub::remove_replica_on_meta_server(const app_info &info,
void replica_stub::on_meta_server_disconnected()
{
- LOG_INFO("meta server disconnected");
+ LOG_INFO_F("meta server disconnected");
zauto_lock l(_state_lock);
if (NS_Disconnected == _state)
@@ -1684,8 +1683,7 @@ void replica_stub::on_gc_replica(replica_stub_ptr this_, gpid id)
return;
}
- LOG_INFO(
- "start to move replica(%s) as garbage, path: %s", id.to_string(), replica_path.c_str());
+ LOG_INFO_F("start to move replica({}) as garbage, path: {}", id, replica_path);
char rename_path[1024];
sprintf(rename_path, "%s.%" PRIu64 ".gar", replica_path.c_str(), dsn_now_us());
if (!dsn::utils::filesystem::rename_path(replica_path, rename_path)) {
@@ -1732,7 +1730,7 @@ void replica_stub::on_gc()
}
}
- LOG_INFO("start to garbage collection, replica_count = %d", (int)rs.size());
+ LOG_INFO_F("start to garbage collection, replica_count = {}", rs.size());
// gc shared prepare log
//
@@ -1766,23 +1764,21 @@ void replica_stub::on_gc()
decree plog_max_commit_on_disk = plog->max_commit_on_disk();
ri.max_decree = std::min(kv.second.last_durable_decree, plog_max_commit_on_disk);
- LOG_INFO(
- "gc_shared: gc condition for %s, status = %s, garbage_max_decree = %" PRId64
- ", last_durable_decree= %" PRId64 ", plog_max_commit_on_disk = %" PRId64 "",
- rep->name(),
- enum_to_string(kv.second.status),
- ri.max_decree,
- kv.second.last_durable_decree,
- plog_max_commit_on_disk);
+ LOG_INFO_F("gc_shared: gc condition for {}, status = {}, garbage_max_decree = {}, "
+ "last_durable_decree= {}, plog_max_commit_on_disk = {}",
+ rep->name(),
+ enum_to_string(kv.second.status),
+ ri.max_decree,
+ kv.second.last_durable_decree,
+ plog_max_commit_on_disk);
} else {
ri.max_decree = kv.second.last_durable_decree;
- LOG_INFO(
- "gc_shared: gc condition for %s, status = %s, garbage_max_decree = %" PRId64
- ", last_durable_decree = %" PRId64 "",
- rep->name(),
- enum_to_string(kv.second.status),
- ri.max_decree,
- kv.second.last_durable_decree);
+ LOG_INFO_F("gc_shared: gc condition for {}, status = {}, garbage_max_decree = {}, "
+ "last_durable_decree = {}",
+ rep->name(),
+ enum_to_string(kv.second.status),
+ ri.max_decree,
+ kv.second.last_durable_decree);
}
ri.valid_start_offset = kv.second.init_offset_in_shared_log;
gc_condition[kv.first] = ri;
@@ -1792,11 +1788,11 @@ void replica_stub::on_gc()
int reserved_log_count = _log->garbage_collection(
gc_condition, _options.log_shared_file_count_limit, prevent_gc_replicas);
if (reserved_log_count > _options.log_shared_file_count_limit * 2) {
- LOG_INFO("gc_shared: trigger emergency checkpoint by log_shared_file_count_limit, "
- "file_count_limit = %d, reserved_log_count = %d, trigger all replicas to do "
- "checkpoint",
- _options.log_shared_file_count_limit,
- reserved_log_count);
+ LOG_INFO_F("gc_shared: trigger emergency checkpoint by log_shared_file_count_limit, "
+ "file_count_limit = {}, reserved_log_count = {}, trigger all replicas to do "
+ "checkpoint",
+ _options.log_shared_file_count_limit,
+ reserved_log_count);
for (auto &kv : rs) {
tasking::enqueue(
LPC_PER_REPLICA_CHECKPOINT_TIMER,
@@ -1814,14 +1810,13 @@ void replica_stub::on_gc()
oss << i.to_string();
c++;
}
- LOG_INFO(
- "gc_shared: trigger emergency checkpoint by log_shared_file_count_limit, "
- "file_count_limit = %d, reserved_log_count = %d, prevent_gc_replica_count = %d, "
- "trigger them to do checkpoint: { %s }",
- _options.log_shared_file_count_limit,
- reserved_log_count,
- (int)prevent_gc_replicas.size(),
- oss.str().c_str());
+ LOG_INFO_F("gc_shared: trigger emergency checkpoint by log_shared_file_count_limit, "
+ "file_count_limit = {}, reserved_log_count = {}, prevent_gc_replica_count = "
+ "{}, trigger them to do checkpoint: {}",
+ _options.log_shared_file_count_limit,
+ reserved_log_count,
+ prevent_gc_replicas.size(),
+ oss.str());
for (auto &id : prevent_gc_replicas) {
auto find = rs.find(id);
if (find != rs.end()) {
@@ -1904,12 +1899,12 @@ void replica_stub::on_gc()
_counter_replicas_splitting_max_async_learn_time_ms->set(splitting_max_async_learn_time_ms);
_counter_replicas_splitting_max_copy_file_size->set(splitting_max_copy_file_size);
- LOG_INFO("finish to garbage collection, time_used_ns = %" PRIu64, dsn_now_ns() - start);
+ LOG_INFO_F("finish to garbage collection, time_used_ns = {}", dsn_now_ns() - start);
}
void replica_stub::on_disk_stat()
{
- LOG_INFO("start to update disk stat");
+ LOG_INFO_F("start to update disk stat");
uint64_t start = dsn_now_ns();
disk_cleaning_report report{};
@@ -1924,7 +1919,7 @@ void replica_stub::on_disk_stat()
_counter_replicas_origin_replica_dir_count->set(report.disk_migrate_origin_count);
_counter_replicas_recent_replica_remove_dir_count->add(report.remove_dir_count);
- LOG_INFO("finish to update disk stat, time_used_ns = %" PRIu64, dsn_now_ns() - start);
+ LOG_INFO_F("finish to update disk stat, time_used_ns = {}", dsn_now_ns() - start);
}
task_ptr replica_stub::begin_open_replica(
@@ -1937,17 +1932,13 @@ task_ptr replica_stub::begin_open_replica(
if (_replicas.find(id) != _replicas.end()) {
_replicas_lock.unlock_write();
- LOG_INFO("open replica '%s.%s' failed coz replica is already opened",
- app.app_type.c_str(),
- id.to_string());
+ LOG_INFO_F("open replica '{}.{}' failed coz replica is already opened", app.app_type, id);
return nullptr;
}
if (_opening_replicas.find(id) != _opening_replicas.end()) {
_replicas_lock.unlock_write();
- LOG_INFO("open replica '%s.%s' failed coz replica is under opening",
- app.app_type.c_str(),
- id.to_string());
+ LOG_INFO_F("open replica '{}.{}' failed coz replica is under opening", app.app_type, id);
return nullptr;
}
@@ -1968,9 +1959,7 @@ task_ptr replica_stub::begin_open_replica(
// unlock here to avoid dead lock
_replicas_lock.unlock_write();
- LOG_INFO("open replica '%s.%s' which is to be closed, reopen it",
- app.app_type.c_str(),
- id.to_string());
+ LOG_INFO_F("open replica '{}.{}' which is to be closed, reopen it", app.app_type, id);
// open by add learner
if (group_check != nullptr) {
@@ -1978,9 +1967,8 @@ task_ptr replica_stub::begin_open_replica(
}
} else {
_replicas_lock.unlock_write();
- LOG_INFO("open replica '%s.%s' failed coz replica is under closing",
- app.app_type.c_str(),
- id.to_string());
+ LOG_INFO_F(
+ "open replica '{}.{}' failed coz replica is under closing", app.app_type, id);
}
return nullptr;
}
@@ -2010,11 +1998,11 @@ void replica_stub::open_replica(
// NOTICE: if partition is DDD, and meta select one replica as primary, it will execute the
// load-process because of a.b.pegasus is exist, so it will never execute the restore
// process below
- LOG_INFO("%s@%s: start to load replica %s group check, dir = %s",
- id.to_string(),
- _primary_address_str,
- group_check ? "with" : "without",
- dir.c_str());
+ LOG_INFO_F("{}@{}: start to load replica {} group check, dir = {}",
+ id,
+ _primary_address_str,
+ group_check ? "with" : "without",
+ dir);
rep = replica::load(this, dir.c_str());
// if load data failed, re-open the `*.ori` folder which is the origin replica dir of disk
@@ -2093,9 +2081,8 @@ void replica_stub::open_replica(
}
if (rep == nullptr) {
- LOG_INFO("%s@%s: open replica failed, erase from opening replicas",
- id.to_string(),
- _primary_address_str);
+ LOG_INFO_F(
+ "{}@{}: open replica failed, erase from opening replicas", id, _primary_address_str);
zauto_write_lock l(_replicas_lock);
CHECK_GT_MSG(_opening_replicas.erase(id),
0,
@@ -2156,9 +2143,9 @@ task_ptr replica_stub::begin_close_replica(replica_ptr r)
int delay_ms = 0;
if (r->status() == partition_status::PS_INACTIVE) {
delay_ms = _options.gc_memory_replica_interval_ms;
- LOG_INFO("%s: delay %d milliseconds to close replica, status = PS_INACTIVE",
- r->name(),
- delay_ms);
+ LOG_INFO_F("{}: delay {} milliseconds to close replica, status = PS_INACTIVE",
+ r->name(),
+ delay_ms);
}
app_info a_info = *(r->get_app_info());
@@ -2179,7 +2166,7 @@ task_ptr replica_stub::begin_close_replica(replica_ptr r)
void replica_stub::close_replica(replica_ptr r)
{
- LOG_INFO("%s: start to close replica", r->name());
+ LOG_INFO_F("{}: start to close replica", r->name());
gpid id = r->get_gpid();
std::string name = r->name();
@@ -2196,7 +2183,7 @@ void replica_stub::close_replica(replica_ptr r)
_counter_replicas_closing_count->decrement();
}
- LOG_INFO("%s: finish to close replica", name.c_str());
+ LOG_INFO_F("{}: finish to close replica", name);
}
void replica_stub::notify_replica_state_update(const replica_configuration &config, bool is_closing)
diff --git a/src/replica/storage/simple_kv/simple_kv.server.impl.cpp b/src/replica/storage/simple_kv/simple_kv.server.impl.cpp
index 2be4e93c1..8915be47c 100644
--- a/src/replica/storage/simple_kv/simple_kv.server.impl.cpp
+++ b/src/replica/storage/simple_kv/simple_kv.server.impl.cpp
@@ -45,7 +45,7 @@ namespace application {
simple_kv_service_impl::simple_kv_service_impl(replica *r) : simple_kv_service(r), _lock(true)
{
reset_state();
- LOG_INFO("simple_kv_service_impl inited");
+ LOG_INFO_F("simple_kv_service_impl inited");
}
void simple_kv_service_impl::reset_state()
diff --git a/src/replica/storage/simple_kv/test/case.cpp b/src/replica/storage/simple_kv/test/case.cpp
index b78ac29e4..7e12d1788 100644
--- a/src/replica/storage/simple_kv/test/case.cpp
+++ b/src/replica/storage/simple_kv/test/case.cpp
@@ -1029,7 +1029,7 @@ bool test_case::init(const std::string &case_input)
forward();
- LOG_INFO("=== init %s succeed", _name.c_str());
+ LOG_INFO_F("=== init {} succeed", _name);
s_inited = true;
return true;
@@ -1046,11 +1046,11 @@ void test_case::forward()
output(cl->to_string());
print(cl, "");
}
- LOG_INFO("=== on_case_forward:[%d]%s", cl->line_no(), cl->to_string().c_str());
+ LOG_INFO_F("=== on_case_forward:[{}]{}", cl->line_no(), cl->to_string());
}
_next++;
if (_next >= _case_lines.size()) {
- LOG_INFO("=== on_case_done");
+ LOG_INFO_F("=== on_case_done");
g_done = true;
break;
}
@@ -1060,7 +1060,7 @@ void test_case::forward()
set_case_line *scl = static_cast<set_case_line *>(cl);
scl->apply_set();
} else if (cl->name() == exit_case_line::NAME()) {
- LOG_INFO("=== on_case_exit");
+ LOG_INFO_F("=== on_case_exit");
g_done = true;
break;
} else {
@@ -1128,7 +1128,7 @@ bool test_case::check_skip(bool consume_one)
skip_case_line *cl = static_cast<skip_case_line *>(c);
if (consume_one) {
cl->skip_one();
- LOG_INFO("=== on_skip_one:skipped=%d/%d", cl->skipped(), cl->count());
+ LOG_INFO_F("=== on_skip_one:skipped={}/{}", cl->skipped(), cl->count());
}
if (cl->is_skip_done()) {
forward();
@@ -1205,7 +1205,7 @@ void test_case::on_end_write(int id, ::dsn::error_code err, int32_t resp)
err.to_string(),
resp);
- LOG_INFO("=== on_end_write:id=%d,err=%s,resp=%d", id, err.to_string(), resp);
+ LOG_INFO_F("=== on_end_write:id={}, err={}, resp={}", id, err, resp);
if (check_skip(true)) {
output(buf);
@@ -1247,7 +1247,7 @@ void test_case::on_end_read(int id, ::dsn::error_code err, const std::string &re
err.to_string(),
resp.c_str());
- LOG_INFO("=== on_end_read:id=%d,err=%s,resp=%s", id, err.to_string(), resp.c_str());
+ LOG_INFO_F("=== on_end_read:id={}, err={}, resp={}", id, err, resp);
if (check_skip(true)) {
output(buf);
@@ -1280,7 +1280,7 @@ bool test_case::on_event(const event *ev)
if (g_done)
return true;
- LOG_INFO("=== %s", ev->to_string().c_str());
+ LOG_INFO_F("=== {}", *ev);
if (check_skip(false))
return true;
@@ -1328,7 +1328,7 @@ void test_case::on_config_change(const parti_config &last, const parti_config &c
_null_loop_count = 0; // reset null loop count
std::string buf = std::string(config_case_line::NAME()) + ":" + cur.to_string();
- LOG_INFO("=== on_config_change:%s", cur.to_string().c_str());
+ LOG_INFO_F("=== on_config_change: {}", cur);
if (check_skip(true)) {
output(buf);
@@ -1364,7 +1364,7 @@ void test_case::on_state_change(const state_snapshot &last, const state_snapshot
_null_loop_count = 0; // reset null loop count
std::string buf = std::string(state_case_line::NAME()) + ":" + cur.to_string();
- LOG_INFO("=== on_state_change:%s\n%s", cur.to_string().c_str(), cur.diff_string(last).c_str());
+ LOG_INFO_F("=== on_state_change: {}\n{}", cur, cur.diff_string(last));
if (check_skip(true)) {
output(buf);
diff --git a/src/replica/storage/simple_kv/test/case.h b/src/replica/storage/simple_kv/test/case.h
index 99b202a8c..a561777da 100644
--- a/src/replica/storage/simple_kv/test/case.h
+++ b/src/replica/storage/simple_kv/test/case.h
@@ -199,6 +199,11 @@ public:
virtual bool check_satisfied(const event *ev) const = 0;
std::string to_string() const;
+ friend std::ostream &operator<<(std::ostream &os, const event &evt)
+ {
+ return os << evt.to_string();
+ }
+
static event *parse(int line_no, const std::string ¶ms);
};
diff --git a/src/replica/storage/simple_kv/test/checker.cpp b/src/replica/storage/simple_kv/test/checker.cpp
index 79d445bbe..b3e7558cf 100644
--- a/src/replica/storage/simple_kv/test/checker.cpp
+++ b/src/replica/storage/simple_kv/test/checker.cpp
@@ -197,12 +197,12 @@ bool test_checker::init(const std::string &name, const std::vector<service_app *
rpc_address paddr = node.second->rpc()->primary_address();
int port = paddr.port();
_node_to_address[name] = paddr;
- LOG_INFO("=== node_to_address[%s]=%s", name.c_str(), paddr.to_string());
+ LOG_INFO_F("=== node_to_address[{}]={}", name, paddr);
_address_to_node[port] = name;
- LOG_INFO("=== address_to_node[%u]=%s", port, name.c_str());
+ LOG_INFO_F("=== address_to_node[{}]={}", port, name);
if (id != port) {
_address_to_node[id] = name;
- LOG_INFO("=== address_to_node[%u]=%s", id, name.c_str());
+ LOG_INFO_F("=== address_to_node[{}]={}", id, name);
}
}
diff --git a/src/replica/storage/simple_kv/test/client.cpp b/src/replica/storage/simple_kv/test/client.cpp
index f85e310ee..af4cf65ea 100644
--- a/src/replica/storage/simple_kv/test/client.cpp
+++ b/src/replica/storage/simple_kv/test/client.cpp
@@ -120,11 +120,7 @@ void simple_kv_client_app::begin_write(int id,
const std::string &value,
int timeout_ms)
{
- LOG_INFO("=== on_begin_write:id=%d,key=%s,value=%s,timeout=%d",
- id,
- key.c_str(),
- value.c_str(),
- timeout_ms);
+ LOG_INFO_F("=== on_begin_write:id={},key={},value={},timeout={}", id, key, value, timeout_ms);
std::shared_ptr<write_context> ctx(new write_context());
ctx->id = id;
ctx->req.key = key;
@@ -168,7 +164,7 @@ struct read_context
void simple_kv_client_app::begin_read(int id, const std::string &key, int timeout_ms)
{
- LOG_INFO("=== on_begin_read:id=%d,key=%s,timeout=%d", id, key.c_str(), timeout_ms);
+ LOG_INFO_F("=== on_begin_read:id={},key={},timeout={}", id, key, timeout_ms);
std::shared_ptr<read_context> ctx(new read_context());
ctx->id = id;
ctx->key = key;
diff --git a/src/replica/storage/simple_kv/test/common.h b/src/replica/storage/simple_kv/test/common.h
index 044fd9b52..44a2da4df 100644
--- a/src/replica/storage/simple_kv/test/common.h
+++ b/src/replica/storage/simple_kv/test/common.h
@@ -172,6 +172,11 @@ struct state_snapshot
std::string to_string() const;
bool from_string(const std::string &str);
std::string diff_string(const state_snapshot &other) const;
+
+ friend std::ostream &operator<<(std::ostream &os, const state_snapshot &ss)
+ {
+ return os << ss.to_string();
+ }
};
struct parti_config
@@ -201,6 +206,11 @@ struct parti_config
std::string to_string() const;
bool from_string(const std::string &str);
void convert_from(const partition_configuration &c);
+
+ friend std::ostream &operator<<(std::ostream &os, const parti_config &pc)
+ {
+ return os << pc.to_string();
+ }
};
}
}
diff --git a/src/replica/storage/simple_kv/test/injector.cpp b/src/replica/storage/simple_kv/test/injector.cpp
index fb8b0221a..dd619eadc 100644
--- a/src/replica/storage/simple_kv/test/injector.cpp
+++ b/src/replica/storage/simple_kv/test/injector.cpp
@@ -200,8 +200,6 @@ void test_injector::install(service_spec &svc_spec)
spec->on_rpc_reply.put_native(inject_on_rpc_reply);
spec->on_rpc_response_enqueue.put_native(inject_on_rpc_response_enqueue);
}
-
- // LOG_INFO("=== test_injector installed");
}
test_injector::test_injector(const char *name) : toollet(name) {}
diff --git a/src/replica/storage/simple_kv/test/simple_kv.main.cpp b/src/replica/storage/simple_kv/test/simple_kv.main.cpp
index 74199bc68..adb63d374 100644
--- a/src/replica/storage/simple_kv/test/simple_kv.main.cpp
+++ b/src/replica/storage/simple_kv/test/simple_kv.main.cpp
@@ -72,7 +72,7 @@ int main(int argc, char **argv)
std::this_thread::sleep_for(std::chrono::milliseconds(1));
}
- LOG_INFO("=== exiting ...");
+ LOG_INFO_F("=== exiting ...");
dsn::replication::test::test_checker::instance().exit();
diff --git a/src/replica/storage/simple_kv/test/simple_kv.server.impl.cpp b/src/replica/storage/simple_kv/test/simple_kv.server.impl.cpp
index 2e940dc44..913d91e3f 100644
--- a/src/replica/storage/simple_kv/test/simple_kv.server.impl.cpp
+++ b/src/replica/storage/simple_kv/test/simple_kv.server.impl.cpp
@@ -42,7 +42,7 @@ bool simple_kv_service_impl::s_simple_kv_apply_checkpoint_fail = false;
simple_kv_service_impl::simple_kv_service_impl(replica *r) : simple_kv_service(r), _lock(true)
{
reset_state();
- LOG_INFO("simple_kv_service_impl inited");
+ LOG_INFO_F("simple_kv_service_impl inited");
}
void simple_kv_service_impl::reset_state()
@@ -64,8 +64,6 @@ void simple_kv_service_impl::on_read(const std::string &key, ::dsn::rpc_replier<
value = it->second;
}
- // LOG_INFO("=== on_exec_read:int64_t=%" PRId64 ",key=%s,value=%s", last_committed_decree(),
- // key.c_str(), value.c_str());
reply(value);
}
@@ -75,8 +73,6 @@ void simple_kv_service_impl::on_write(const kv_pair &pr, ::dsn::rpc_replier<int3
dsn::zauto_lock l(_lock);
_store[pr.key] = pr.value;
- // LOG_INFO("=== on_exec_write:int64_t=%" PRId64 ",key=%s,value=%s", last_committed_decree(),
- // pr.key.c_str(), pr.value.c_str());
reply(0);
}
@@ -90,8 +86,6 @@ void simple_kv_service_impl::on_append(const kv_pair &pr, ::dsn::rpc_replier<int
else
_store[pr.key] = pr.value;
- // LOG_INFO("=== on_exec_append:int64_t=%" PRId64 ",key=%s,value=%s", last_committed_decree(),
- // pr.key.c_str(), pr.value.c_str());
reply(0);
}
@@ -103,7 +97,7 @@ void simple_kv_service_impl::on_append(const kv_pair &pr, ::dsn::rpc_replier<int
dsn::zauto_lock l(_lock);
recover();
- LOG_INFO("simple_kv_service_impl opened");
+ LOG_INFO_F("simple_kv_service_impl opened");
return ERR_OK;
}
@@ -121,7 +115,7 @@ void simple_kv_service_impl::on_append(const kv_pair &pr, ::dsn::rpc_replier<int
_store.clear();
reset_state();
}
- LOG_INFO("simple_kv_service_impl closed, clear_state = %s", clear_state ? "true" : "false");
+ LOG_INFO_F("simple_kv_service_impl closed, clear_state = {}", clear_state ? "true" : "false");
return ERR_OK;
}
@@ -157,8 +151,7 @@ void simple_kv_service_impl::recover()
recover(name, max_version);
set_last_durable_decree(max_version);
}
- LOG_INFO("simple_kv_service_impl recovered, last_durable_decree = %" PRId64 "",
- last_durable_decree());
+ LOG_INFO_F("simple_kv_service_impl recovered, last_durable_decree = {}", last_durable_decree());
}
void simple_kv_service_impl::recover(const std::string &name, int64_t version)
@@ -203,9 +196,9 @@ void simple_kv_service_impl::recover(const std::string &name, int64_t version)
int64_t last_commit = last_committed_decree();
if (last_commit == last_durable_decree()) {
- LOG_INFO("simple_kv_service_impl no need to create checkpoint, "
- "checkpoint already the latest, last_durable_decree = %" PRId64 "",
- last_durable_decree());
+ LOG_INFO_F("simple_kv_service_impl no need to create checkpoint, "
+ "checkpoint already the latest, last_durable_decree = {}",
+ last_durable_decree());
return ERR_OK;
}
@@ -235,9 +228,9 @@ void simple_kv_service_impl::recover(const std::string &name, int64_t version)
}
set_last_durable_decree(last_commit);
- LOG_INFO("simple_kv_service_impl create checkpoint succeed, "
- "last_durable_decree = %" PRId64 "",
- last_durable_decree());
+ LOG_INFO_F("simple_kv_service_impl create checkpoint succeed, "
+ "last_durable_decree = {}",
+ last_durable_decree());
return ERR_OK;
}
@@ -267,8 +260,8 @@ void simple_kv_service_impl::recover(const std::string &name, int64_t version)
state.to_decree_included = last_durable_decree();
state.files.push_back(std::string(name));
- LOG_INFO("simple_kv_service_impl get checkpoint succeed, last_durable_decree = %" PRId64 "",
- last_durable_decree());
+ LOG_INFO_F("simple_kv_service_impl get checkpoint succeed, last_durable_decree = {}",
+ last_durable_decree());
return ERR_OK;
} else {
state.from_decree_excluded = 0;
@@ -287,8 +280,6 @@ void simple_kv_service_impl::recover(const std::string &name, int64_t version)
if (mode == replication_app_base::chkpt_apply_mode::learn) {
recover(state.files[0], state.to_decree_included);
- // LOG_INFO("simple_kv_service_impl learn checkpoint succeed, last_committed_decree = %"
- // PRId64 "", last_committed_decree());
return ERR_OK;
} else {
CHECK_EQ_MSG(replication_app_base::chkpt_apply_mode::copy, mode, "invalid mode");
@@ -303,9 +294,8 @@ void simple_kv_service_impl::recover(const std::string &name, int64_t version)
return ERR_CHECKPOINT_FAILED;
} else {
set_last_durable_decree(state.to_decree_included);
- LOG_INFO(
- "simple_kv_service_impl copy checkpoint succeed, last_durable_decree = %" PRId64 "",
- last_durable_decree());
+ LOG_INFO_F("simple_kv_service_impl copy checkpoint succeed, last_durable_decree = {}",
+ last_durable_decree());
return ERR_OK;
}
}
diff --git a/src/reporter/pegasus_counter_reporter.cpp b/src/reporter/pegasus_counter_reporter.cpp
index e6ea04bf8..2ab57f8ee 100644
--- a/src/reporter/pegasus_counter_reporter.cpp
+++ b/src/reporter/pegasus_counter_reporter.cpp
@@ -119,9 +119,8 @@ void pegasus_counter_reporter::falcon_initialize()
_falcon_metric.tags = fmt::format(
"service=pegasus,cluster={},job={},port={}", _cluster_name, _app_name, _local_port);
- LOG_INFO("falcon initialize: endpoint(%s), tag(%s)",
- _falcon_metric.endpoint.c_str(),
- _falcon_metric.tags.c_str());
+ LOG_INFO_F(
+ "falcon initialize: endpoint({}), tag({})", _falcon_metric.endpoint, _falcon_metric.tags);
}
void pegasus_counter_reporter::start()
@@ -180,7 +179,7 @@ void pegasus_counter_reporter::stop()
void pegasus_counter_reporter::update_counters_to_falcon(const std::string &result,
int64_t timestamp)
{
- LOG_INFO("update counters to falcon with timestamp = %" PRId64, timestamp);
+ LOG_INFO_F("update counters to falcon with timestamp = {}", timestamp);
http_post_request(FLAGS_falcon_host,
FLAGS_falcon_port,
FLAGS_falcon_path,
@@ -204,7 +203,7 @@ void pegasus_counter_reporter::update()
oss << "[" << cs.name << ", " << dsn_counter_type_to_string(cs.type) << ", "
<< cs.value << "]" << std::endl;
});
- LOG_INFO("%s", oss.str().c_str());
+ LOG_INFO_F("{}", oss.str());
}
if (perf_counter_sink_t::FALCON == _perf_counter_sink) {
@@ -293,7 +292,7 @@ void pegasus_counter_reporter::update()
});
}
- LOG_INFO("update now_ms(%lld), last_report_time_ms(%lld)", now, _last_report_time_ms);
+ LOG_INFO_F("update now_ms({}), last_report_time_ms({})", now, _last_report_time_ms);
_last_report_time_ms = now;
}
diff --git a/src/runtime/fault_injector.cpp b/src/runtime/fault_injector.cpp
index 0dccbedca..e53da5980 100644
--- a/src/runtime/fault_injector.cpp
+++ b/src/runtime/fault_injector.cpp
@@ -146,8 +146,7 @@ static void fault_on_task_begin(task *this_)
fj_opt &opt = s_fj_opts[this_->spec().code];
if (opt.execution_extra_delay_us_max > 0) {
auto d = rand::next_u32(0, opt.execution_extra_delay_us_max);
- LOG_INFO(
- "fault inject %s at %s with delay %u us", this_->spec().name.c_str(), __FUNCTION__, d);
+ LOG_INFO_F("fault inject {} at {} with delay {} us", this_->spec().name, __FUNCTION__, d);
std::this_thread::sleep_for(std::chrono::microseconds(d));
}
}
@@ -168,14 +167,14 @@ static bool fault_on_aio_call(task *caller, aio_task *callee)
switch (callee->get_aio_context()->type) {
case AIO_Read:
if (rand::next_double01() < s_fj_opts[callee->spec().code].disk_read_fail_ratio) {
- LOG_INFO("fault inject %s at %s", callee->spec().name.c_str(), __FUNCTION__);
+ LOG_INFO_F("fault inject {} at {}", callee->spec().name, __FUNCTION__);
callee->set_error_code(ERR_FILE_OPERATION_FAILED);
return false;
}
break;
case AIO_Write:
if (rand::next_double01() < s_fj_opts[callee->spec().code].disk_write_fail_ratio) {
- LOG_INFO("fault inject %s at %s", callee->spec().name.c_str(), __FUNCTION__);
+ LOG_INFO_F("fault inject {} at {}", callee->spec().name, __FUNCTION__);
callee->set_error_code(ERR_FILE_OPERATION_FAILED);
return false;
}
@@ -192,10 +191,10 @@ static void fault_on_aio_enqueue(aio_task *this_)
fj_opt &opt = s_fj_opts[this_->spec().code];
if (this_->delay_milliseconds() == 0 && task_ext_for_fj::get(this_) == 0) {
this_->set_delay(rand::next_u32(opt.disk_io_delay_ms_min, opt.disk_io_delay_ms_max));
- LOG_INFO("fault inject %s at %s with delay %u ms",
- this_->spec().name.c_str(),
- __FUNCTION__,
- this_->delay_milliseconds());
+ LOG_INFO_F("fault inject {} at {} with delay {} ms",
+ this_->spec().name,
+ __FUNCTION__,
+ this_->delay_milliseconds());
task_ext_for_fj::get(this_) = 1; // ensure only fd once
}
}
@@ -231,17 +230,17 @@ static bool fault_on_rpc_call(task *caller, message_ex *req, rpc_response_task *
{
fj_opt &opt = s_fj_opts[req->local_rpc_code];
if (rand::next_double01() < opt.rpc_request_drop_ratio) {
- LOG_INFO("fault inject %s at %s: %s => %s",
- req->header->rpc_name,
- __FUNCTION__,
- req->header->from_address.to_string(),
- req->to_address.to_string());
+ LOG_INFO_F("fault inject {} at {}: {} => {}",
+ req->header->rpc_name,
+ __FUNCTION__,
+ req->header->from_address,
+ req->to_address);
return false;
} else {
if (rand::next_double01() < opt.rpc_request_data_corrupted_ratio) {
- LOG_INFO("corrupt the rpc call message from: %s, type: %s",
- req->header->from_address.to_string(),
- opt.rpc_message_data_corrupted_type.c_str());
+ LOG_INFO_F("corrupt the rpc call message from: {}, type: {}",
+ req->header->from_address,
+ opt.rpc_message_data_corrupted_type);
corrupt_data(req, opt.rpc_message_data_corrupted_type);
}
return true;
@@ -255,10 +254,10 @@ static void fault_on_rpc_request_enqueue(rpc_request_task *callee)
if (rand::next_double01() < opt.rpc_request_delay_ratio) {
callee->set_delay(
rand::next_u32(opt.rpc_message_delay_ms_min, opt.rpc_message_delay_ms_max));
- LOG_INFO("fault inject %s at %s with delay %u ms",
- callee->spec().name.c_str(),
- __FUNCTION__,
- callee->delay_milliseconds());
+ LOG_INFO_F("fault inject {} at {} with delay {} ms",
+ callee->spec().name,
+ __FUNCTION__,
+ callee->delay_milliseconds());
task_ext_for_fj::get(callee) = 1; // ensure only fd once
}
}
@@ -269,17 +268,17 @@ static bool fault_on_rpc_reply(task *caller, message_ex *msg)
{
fj_opt &opt = s_fj_opts[msg->local_rpc_code];
if (rand::next_double01() < opt.rpc_response_drop_ratio) {
- LOG_INFO("fault inject %s at %s: %s => %s",
- msg->header->rpc_name,
- __FUNCTION__,
- msg->header->from_address.to_string(),
- msg->to_address.to_string());
+ LOG_INFO_F("fault inject {} at {}: {} => {}",
+ msg->header->rpc_name,
+ __FUNCTION__,
+ msg->header->from_address,
+ msg->to_address);
return false;
} else {
if (rand::next_double01() < opt.rpc_response_data_corrupted_ratio) {
- LOG_INFO("fault injector corrupt the rpc reply message from: %s, type: %s",
- msg->header->from_address.to_string(),
- opt.rpc_message_data_corrupted_type.c_str());
+ LOG_INFO_F("fault injector corrupt the rpc reply message from: {}, type: {}",
+ msg->header->from_address,
+ opt.rpc_message_data_corrupted_type);
corrupt_data(msg, opt.rpc_message_data_corrupted_type);
}
return true;
@@ -293,10 +292,10 @@ static void fault_on_rpc_response_enqueue(rpc_response_task *resp)
if (rand::next_double01() < opt.rpc_response_delay_ratio) {
resp->set_delay(
rand::next_u32(opt.rpc_message_delay_ms_min, opt.rpc_message_delay_ms_max));
- LOG_INFO("fault inject %s at %s with delay %u ms",
- resp->spec().name.c_str(),
- __FUNCTION__,
- resp->delay_milliseconds());
+ LOG_INFO_F("fault inject {} at {} with delay {} ms",
+ resp->spec().name,
+ __FUNCTION__,
+ resp->delay_milliseconds());
task_ext_for_fj::get(resp) = 1; // ensure only fd once
}
}
diff --git a/src/runtime/rpc/asio_rpc_session.cpp b/src/runtime/rpc/asio_rpc_session.cpp
index 9018e2f6b..d2e4f8879 100644
--- a/src/runtime/rpc/asio_rpc_session.cpp
+++ b/src/runtime/rpc/asio_rpc_session.cpp
@@ -89,9 +89,7 @@ void asio_rpc_session::do_read(int read_next)
[this](boost::system::error_code ec, std::size_t length) {
if (!!ec) {
if (ec == boost::asio::error::make_error_code(boost::asio::error::eof)) {
- LOG_INFO("asio read from %s failed: %s",
- _remote_addr.to_string(),
- ec.message().c_str());
+ LOG_INFO_F("asio read from {} failed: {}", _remote_addr, ec.message());
} else {
LOG_ERROR("asio read from %s failed: %s",
_remote_addr.to_string(),
diff --git a/src/runtime/rpc/network.cpp b/src/runtime/rpc/network.cpp
index 41189fd20..1f231ef33 100644
--- a/src/runtime/rpc/network.cpp
+++ b/src/runtime/rpc/network.cpp
@@ -649,9 +649,9 @@ void connection_oriented_network::send_message(message_ex *request)
// init connection if necessary
if (new_client) {
- LOG_INFO("client session created, remote_server = %s, current_count = %d",
- client->remote_address().to_string(),
- ip_count);
+ LOG_INFO_F("client session created, remote_server = {}, current_count = {}",
+ client->remote_address(),
+ ip_count);
_client_session_count->set(ip_count);
client->connect();
}
@@ -691,14 +691,14 @@ void connection_oriented_network::on_server_session_accepted(rpc_session_ptr &s)
}
}
- LOG_INFO("server session accepted, remote_client = %s, current_count = %d",
- s->remote_address().to_string(),
- ip_count);
+ LOG_INFO_F("server session accepted, remote_client = {}, current_count = {}",
+ s->remote_address(),
+ ip_count);
- LOG_INFO("ip session %s, remote_client = %s, current_count = %d",
- ip_conn_count == 1 ? "inserted" : "increased",
- s->remote_address().to_string(),
- ip_conn_count);
+ LOG_INFO_F("ip session {}, remote_client = {}, current_count = {}",
+ ip_conn_count == 1 ? "inserted" : "increased",
+ s->remote_address(),
+ ip_conn_count);
_client_session_count->set(ip_count);
}
@@ -733,20 +733,19 @@ void connection_oriented_network::on_server_session_disconnected(rpc_session_ptr
}
if (session_removed) {
- LOG_INFO("session %s disconnected, the total client sessions count remains %d",
- s->remote_address().to_string(),
- ip_count);
+ LOG_INFO_F("session {} disconnected, the total client sessions count remains {}",
+ s->remote_address(),
+ ip_count);
_client_session_count->set(ip_count);
}
if (ip_conn_count == 0) {
// TODO(wutao1): print ip only
- LOG_INFO("client ip %s has no more session to this server",
- s->remote_address().to_string());
+ LOG_INFO_F("client ip {} has no more session to this server", s->remote_address());
} else {
- LOG_INFO("client ip %s has still %d of sessions to this server",
- s->remote_address().to_string(),
- ip_conn_count);
+ LOG_INFO_F("client ip {} has still {} of sessions to this server",
+ s->remote_address(),
+ ip_conn_count);
}
}
@@ -796,9 +795,9 @@ void connection_oriented_network::on_client_session_connected(rpc_session_ptr &s
}
if (r) {
- LOG_INFO("client session connected, remote_server = %s, current_count = %d",
- s->remote_address().to_string(),
- ip_count);
+ LOG_INFO_F("client session connected, remote_server = {}, current_count = {}",
+ s->remote_address(),
+ ip_count);
_client_session_count->set(ip_count);
}
}
@@ -818,9 +817,9 @@ void connection_oriented_network::on_client_session_disconnected(rpc_session_ptr
}
if (r) {
- LOG_INFO("client session disconnected, remote_server = %s, current_count = %d",
- s->remote_address().to_string(),
- ip_count);
+ LOG_INFO_F("client session disconnected, remote_server = {}, current_count = {}",
+ s->remote_address(),
+ ip_count);
_client_session_count->set(ip_count);
}
}
diff --git a/src/runtime/rpc/raw_message_parser.cpp b/src/runtime/rpc/raw_message_parser.cpp
index 8c7c1443a..6ad9a8d24 100644
--- a/src/runtime/rpc/raw_message_parser.cpp
+++ b/src/runtime/rpc/raw_message_parser.cpp
@@ -68,8 +68,8 @@ raw_message_parser::raw_message_parser()
bool hooked = false;
static std::atomic_bool s_handler_hooked(false);
if (s_handler_hooked.compare_exchange_strong(hooked, true)) {
- LOG_INFO("join point on_rpc_session_disconnected registered to notify disconnect with "
- "RPC_CALL_RAW_SESSION_DISCONNECT");
+ LOG_INFO_F("join point on_rpc_session_disconnected registered to notify disconnect with "
+ "RPC_CALL_RAW_SESSION_DISCONNECT");
rpc_session::on_rpc_session_disconnected.put_back(
raw_message_parser::notify_rpc_session_disconnected,
"notify disconnect with RPC_CALL_RAW_SESSION_DISCONNECT");
diff --git a/src/runtime/rpc/rpc_engine.cpp b/src/runtime/rpc/rpc_engine.cpp
index 17ebb24ca..d882d2a13 100644
--- a/src/runtime/rpc/rpc_engine.cpp
+++ b/src/runtime/rpc/rpc_engine.cpp
@@ -185,9 +185,9 @@ bool rpc_client_matcher::on_recv_reply(network *net, uint64_t key, message_ex *r
// failure injection applied
if (!call->enqueue(err, reply)) {
- LOG_INFO("rpc reply %s is dropped (fault inject), trace_id = %016" PRIx64,
- reply->header->rpc_name,
- reply->header->trace_id);
+ LOG_INFO_F("rpc reply {} is dropped (fault inject), trace_id = {:#018x}",
+ reply->header->rpc_name,
+ reply->header->trace_id);
// call network failure model
net->inject_drop_message(reply, false);
@@ -472,11 +472,11 @@ error_code rpc_engine::start(const service_app_spec &aspec)
return ERR_NETWORK_INIT_FAILED;
pnet[j].reset(net);
- LOG_INFO("[%s] network client started at port %u, channel = %s, fmt = %s ...",
- node()->full_name(),
- (uint32_t)(cs.port),
- cs.channel.to_string(),
- client_hdr_format.to_string());
+ LOG_INFO_F("[{}] network client started at port {}, channel = {}, fmt = {} ...",
+ node()->full_name(),
+ cs.port,
+ cs.channel,
+ client_hdr_format);
}
}
@@ -511,9 +511,9 @@ error_code rpc_engine::start(const service_app_spec &aspec)
_local_primary_address = _client_nets[NET_HDR_DSN][0]->address();
_local_primary_address.set_port(aspec.ports.size() > 0 ? *aspec.ports.begin() : aspec.id);
- LOG_INFO("=== service_node=[%s], primary_address=[%s] ===",
- _node->full_name(),
- _local_primary_address.to_string());
+ LOG_INFO_F("=== service_node=[{}], primary_address=[{}] ===",
+ _node->full_name(),
+ _local_primary_address);
_is_running = true;
return ERR_OK;
@@ -571,9 +571,9 @@ void rpc_engine::on_recv_request(network *net, message_ex *msg, int delay_ms)
// release the task when necessary
else {
- LOG_INFO("rpc request %s is dropped (fault inject), trace_id = %016" PRIx64,
- msg->header->rpc_name,
- msg->header->trace_id);
+ LOG_INFO_F("rpc request {} is dropped (fault inject), trace_id = {:#018x}",
+ msg->header->rpc_name,
+ msg->header->trace_id);
// call network failure model when network is present
net->inject_drop_message(msg, false);
@@ -693,9 +693,9 @@ void rpc_engine::call_ip(rpc_address addr,
// join point and possible fault injection
if (!sp->on_rpc_call.execute(task::get_current_task(), request, call, true)) {
- LOG_INFO("rpc request %s is dropped (fault inject), trace_id = %016" PRIx64,
- request->header->rpc_name,
- request->header->trace_id);
+ LOG_INFO_F("rpc request {} is dropped (fault inject), trace_id = {:#018x}",
+ request->header->rpc_name,
+ request->header->trace_id);
// call network failure model
net->inject_drop_message(request, true);
diff --git a/src/runtime/security/init.cpp b/src/runtime/security/init.cpp
index 982330cab..f76e6ff86 100644
--- a/src/runtime/security/init.cpp
+++ b/src/runtime/security/init.cpp
@@ -55,14 +55,14 @@ bool init(bool is_server)
LOG_ERROR_F("initialize kerberos failed, with err = {}", err.description());
return false;
}
- LOG_INFO("initialize kerberos succeed");
+ LOG_INFO_F("initialize kerberos succeed");
err = init_sasl(is_server);
if (!err.is_ok()) {
LOG_ERROR_F("initialize sasl failed, with err = {}", err.description());
return false;
}
- LOG_INFO("initialize sasl succeed");
+ LOG_INFO_F("initialize sasl succeed");
init_join_point();
return true;
@@ -75,14 +75,14 @@ bool init_for_zookeeper_client()
LOG_ERROR_F("initialize kerberos failed, with err = {}", err.description());
return false;
}
- LOG_INFO("initialize kerberos for zookeeper client succeed");
+ LOG_INFO_F("initialize kerberos for zookeeper client succeed");
err = init_sasl(false);
if (!err.is_ok()) {
LOG_ERROR_F("initialize sasl failed, with err = {}", err.description());
return false;
}
- LOG_INFO("initialize sasl for zookeeper client succeed");
+ LOG_INFO_F("initialize sasl for zookeeper client succeed");
return true;
}
} // namespace security
diff --git a/src/runtime/service_api_c.cpp b/src/runtime/service_api_c.cpp
index 6ecf14141..fe4a91d69 100644
--- a/src/runtime/service_api_c.cpp
+++ b/src/runtime/service_api_c.cpp
@@ -429,10 +429,10 @@ bool run(const char *config_file,
// prepare minimum necessary
::dsn::service_engine::instance().init_before_toollets(spec);
- LOG_INFO("process(%ld) start: %" PRIu64 ", date: %s",
- getpid(),
- dsn::utils::process_start_millis(),
- dsn::utils::process_start_date_time_mills());
+ LOG_INFO_F("process({}) start: {}, date: {}",
+ getpid(),
+ dsn::utils::process_start_millis(),
+ dsn::utils::process_start_date_time_mills());
// init toollets
for (auto it = spec.toollets.begin(); it != spec.toollets.end(); ++it) {
diff --git a/src/runtime/test/async_call.cpp b/src/runtime/test/async_call.cpp
index fd161911c..d98abc744 100644
--- a/src/runtime/test/async_call.cpp
+++ b/src/runtime/test/async_call.cpp
@@ -165,12 +165,12 @@ class simple_task : public dsn::raw_task
public:
simple_task(dsn::task_code code, const task_handler &h) : dsn::raw_task(code, h, 0, nullptr)
{
- LOG_INFO("simple task %p created", this);
+ LOG_INFO_F("simple task {} created", fmt::ptr(this));
allocate_count++;
}
virtual ~simple_task() override
{
- LOG_INFO("simple task %p is deallocated", this);
+ LOG_INFO_F("simple task {} is deallocated", fmt::ptr(this));
allocate_count--;
}
static std::atomic_int allocate_count;
@@ -188,12 +188,12 @@ public:
simple_rpc_response_task(dsn::message_ex *m, const rpc_response_handler &h)
: dsn::rpc_response_task(m, h)
{
- LOG_INFO("simple rpc response task(%p) created", this);
+ LOG_INFO_F("simple rpc response task({}) created", fmt::ptr(this));
allocate_count++;
}
virtual ~simple_rpc_response_task() override
{
- LOG_INFO("simple rpc repsonse task(%p) is dealloate", this);
+ LOG_INFO_F("simple rpc repsonse task({}) is dealloate", fmt::ptr(this));
allocate_count--;
}
static std::atomic_int allocate_count;
@@ -247,7 +247,7 @@ TEST(async_call, task_destructor)
{
dsn::ref_ptr<simple_task_container> c(new simple_task_container());
c->t =
- new simple_task(LPC_TEST_CLIENTLET, [c]() { LOG_INFO("cycle link reference test"); });
+ new simple_task(LPC_TEST_CLIENTLET, [c]() { LOG_INFO_F("cycle link reference test"); });
c->t->enqueue();
c->t->wait();
@@ -257,7 +257,7 @@ TEST(async_call, task_destructor)
{
dsn::ref_ptr<simple_task_container> c(new simple_task_container());
c->t =
- new simple_task(LPC_TEST_CLIENTLET, [c]() { LOG_INFO("cycle link reference test"); });
+ new simple_task(LPC_TEST_CLIENTLET, [c]() { LOG_INFO_F("cycle link reference test"); });
ASSERT_TRUE(c->t->cancel(false));
}
diff --git a/src/runtime/test/netprovider.cpp b/src/runtime/test/netprovider.cpp
index 8e91337ac..8b62372a6 100644
--- a/src/runtime/test/netprovider.cpp
+++ b/src/runtime/test/netprovider.cpp
@@ -75,8 +75,8 @@ public:
public:
void change_test_cfg_conn_threshold_per_ip(uint32_t n)
{
- LOG_INFO(
- "change _cfg_conn_threshold_per_ip %u -> %u for test", _cfg_conn_threshold_per_ip, n);
+ LOG_INFO_F(
+ "change _cfg_conn_threshold_per_ip {} -> {} for test", _cfg_conn_threshold_per_ip, n);
_cfg_conn_threshold_per_ip = n;
}
};
@@ -96,7 +96,7 @@ void response_handler(dsn::error_code ec,
::dsn::unmarshall(resp, response_string);
ASSERT_EQ(response_string, request_str);
} else {
- LOG_INFO("error msg: %s", ec.to_string());
+ LOG_INFO_F("error msg: {}", ec);
}
wait_flag = 1;
}
@@ -179,11 +179,11 @@ TEST(tools_common, asio_net_provider)
start_result = asio_network2->start(RPC_CHANNEL_TCP, TEST_PORT, false);
ASSERT_TRUE(start_result == ERR_OK);
- LOG_INFO("result: %s", start_result.to_string());
+ LOG_INFO_F("result: {}", start_result);
start_result = asio_network2->start(RPC_CHANNEL_TCP, TEST_PORT, false);
ASSERT_TRUE(start_result == ERR_SERVICE_ALREADY_RUNNING);
- LOG_INFO("result: %s", start_result.to_string());
+ LOG_INFO_F("result: {}", start_result);
rpc_session_ptr client_session =
asio_network->create_client_session(rpc_address("localhost", TEST_PORT));
@@ -290,7 +290,7 @@ TEST(tools_common, asio_network_provider_connection_threshold)
// not exceed threshold
for (int count = 0; count < CONN_THRESHOLD + 2; count++) {
- LOG_INFO("client # %d", count);
+ LOG_INFO_F("client # {}", count);
rpc_session_ptr client_session =
asio_network->create_client_session(rpc_address("localhost", TEST_PORT));
client_session->connect();
@@ -304,7 +304,7 @@ TEST(tools_common, asio_network_provider_connection_threshold)
// exceed threshold
bool reject = false;
for (int count = 0; count < CONN_THRESHOLD + 2; count++) {
- LOG_INFO("client # %d", count);
+ LOG_INFO_F("client # {}", count);
rpc_session_ptr client_session =
asio_network->create_client_session(rpc_address("localhost", TEST_PORT));
client_session->connect();
diff --git a/src/runtime/test/rpc.cpp b/src/runtime/test/rpc.cpp
index 7d52973c2..473fd84f1 100644
--- a/src/runtime/test/rpc.cpp
+++ b/src/runtime/test/rpc.cpp
@@ -99,7 +99,7 @@ TEST(core, group_address_talk_to_others)
auto typed_callback = [addr](error_code err_code, const std::string &result) {
EXPECT_EQ(ERR_OK, err_code);
dsn::rpc_address addr_got;
- LOG_INFO("talk to others callback, result: %s", result.c_str());
+ LOG_INFO_F("talk to others callback, result: {}", result);
EXPECT_TRUE(addr_got.from_string_ipv4(result.c_str()));
EXPECT_EQ(TEST_PORT_END, addr_got.port());
};
@@ -120,7 +120,7 @@ TEST(core, group_address_change_leader)
rpc_err = err_code;
if (ERR_OK == err_code) {
::dsn::rpc_address addr_got;
- LOG_INFO("talk to others callback, result: %s", result.c_str());
+ LOG_INFO_F("talk to others callback, result: {}", result);
EXPECT_TRUE(addr_got.from_string_ipv4(result.c_str()));
EXPECT_EQ(TEST_PORT_END, addr_got.port());
}
@@ -151,7 +151,7 @@ TEST(core, group_address_change_leader)
nullptr,
typed_callback);
resp_task->wait();
- LOG_INFO("addr.leader=%s", addr.group_address()->leader().to_string());
+ LOG_INFO_F("addr.leader={}", addr.group_address()->leader());
if (rpc_err == ERR_OK) {
EXPECT_EQ(TEST_PORT_END, addr.group_address()->leader().port());
}
diff --git a/src/runtime/test/test_utils.h b/src/runtime/test/test_utils.h
index 9bd90b625..84280b5d0 100644
--- a/src/runtime/test/test_utils.h
+++ b/src/runtime/test/test_utils.h
@@ -102,16 +102,16 @@ public:
dsn::rpc_address next_addr = dsn::service_app::primary_address();
if (next_addr.port() != TEST_PORT_END) {
next_addr.assign_ipv4(next_addr.ip(), next_addr.port() + 1);
- LOG_INFO("test_client_server, talk_to_others: %s", next_addr.to_string());
+ LOG_INFO_F("test_client_server, talk_to_others: {}", next_addr);
dsn_rpc_forward(message, next_addr);
} else {
- LOG_INFO("test_client_server, talk_to_me: %s", next_addr.to_string());
+ LOG_INFO_F("test_client_server, talk_to_me: {}", next_addr);
reply(message, next_addr.to_std_string());
}
} else if (command == "expect_no_reply") {
if (dsn::service_app::primary_address().port() == TEST_PORT_END) {
- LOG_INFO("test_client_server, talk_with_reply: %s",
- dsn::service_app::primary_address().to_std_string().c_str());
+ LOG_INFO_F("test_client_server, talk_with_reply: {}",
+ dsn::service_app::primary_address());
reply(message, dsn::service_app::primary_address().to_std_string());
}
} else if (command.substr(0, 5) == "echo ") {
diff --git a/src/runtime/tool_api.cpp b/src/runtime/tool_api.cpp
index 9d3d7e0d2..9509016d9 100644
--- a/src/runtime/tool_api.cpp
+++ b/src/runtime/tool_api.cpp
@@ -60,7 +60,7 @@ public:
err = _node->start_app();
CHECK_EQ_MSG(err, ERR_OK, "start app failed");
} else {
- LOG_INFO("stop app result(%s)", _node->stop_app(_cleanup).to_string());
+ LOG_INFO_F("stop app result({})", _node->stop_app(_cleanup));
}
}
diff --git a/src/runtime/tracer.cpp b/src/runtime/tracer.cpp
index ba142c1cb..eff2497c4 100644
--- a/src/runtime/tracer.cpp
+++ b/src/runtime/tracer.cpp
@@ -38,37 +38,35 @@ static void tracer_on_task_create(task *caller, task *callee)
dsn_task_type_t type = callee->spec().type;
if (TASK_TYPE_RPC_REQUEST == type) {
rpc_request_task *tsk = (rpc_request_task *)callee;
- LOG_INFO("%s CREATE, task_id = %016" PRIx64
- ", type = %s, rpc_name = %s, trace_id = %016" PRIx64 "",
- callee->spec().name.c_str(),
- callee->id(),
- enum_to_string(type),
- tsk->get_request()->header->rpc_name,
- tsk->get_request()->header->trace_id);
+ LOG_INFO_F("{} CREATE, task_id = {:#018x}, type = {}, rpc_name = {}, trace_id = {:#018x}",
+ callee->spec().name,
+ callee->id(),
+ enum_to_string(type),
+ tsk->get_request()->header->rpc_name,
+ tsk->get_request()->header->trace_id);
} else if (TASK_TYPE_RPC_RESPONSE == type) {
rpc_response_task *tsk = (rpc_response_task *)callee;
- LOG_INFO("%s CREATE, task_id = %016" PRIx64
- ", type = %s, rpc_name = %s, trace_id = %016" PRIx64 "",
- callee->spec().name.c_str(),
- callee->id(),
- enum_to_string(type),
- tsk->get_request()->header->rpc_name,
- tsk->get_request()->header->trace_id);
+ LOG_INFO_F("{} CREATE, task_id = {:#018x}, type = {}, rpc_name = {}, trace_id = {:#018x}",
+ callee->spec().name,
+ callee->id(),
+ enum_to_string(type),
+ tsk->get_request()->header->rpc_name,
+ tsk->get_request()->header->trace_id);
} else {
- LOG_INFO("%s CREATE, task_id = %016" PRIx64 ", type = %s",
- callee->spec().name.c_str(),
- callee->id(),
- enum_to_string(type));
+ LOG_INFO_F("{} CREATE, task_id = {:#018x}, type = {}",
+ callee->spec().name,
+ callee->id(),
+ enum_to_string(type));
}
}
static void tracer_on_task_enqueue(task *caller, task *callee)
{
- LOG_INFO("%s ENQUEUE, task_id = %016" PRIx64 ", delay = %d ms, queue size = %d",
- callee->spec().name.c_str(),
- callee->id(),
- callee->delay_milliseconds(),
- tls_dsn.last_worker_queue_size);
+ LOG_INFO_F("{} ENQUEUE, task_id = {:#018x}, delay = {} ms, queue size = {}",
+ callee->spec().name,
+ callee->id(),
+ callee->delay_milliseconds(),
+ tls_dsn.last_worker_queue_size);
}
static void tracer_on_task_begin(task *this_)
@@ -76,26 +74,25 @@ static void tracer_on_task_begin(task *this_)
switch (this_->spec().type) {
case dsn_task_type_t::TASK_TYPE_COMPUTE:
case dsn_task_type_t::TASK_TYPE_AIO:
- LOG_INFO(
- "%s EXEC BEGIN, task_id = %016" PRIx64 "", this_->spec().name.c_str(), this_->id());
+ LOG_INFO_F("{} EXEC BEGIN, task_id = {:#018x}", this_->spec().name, this_->id());
break;
case dsn_task_type_t::TASK_TYPE_RPC_REQUEST: {
rpc_request_task *tsk = (rpc_request_task *)this_;
- LOG_INFO("%s EXEC BEGIN, task_id = %016" PRIx64 ", %s => %s, trace_id = %016" PRIx64 "",
- this_->spec().name.c_str(),
- this_->id(),
- tsk->get_request()->header->from_address.to_string(),
- tsk->get_request()->to_address.to_string(),
- tsk->get_request()->header->trace_id);
+ LOG_INFO_F("{} EXEC BEGIN, task_id = {:#018x}, {} => {}, trace_id = {:#018x}",
+ this_->spec().name,
+ this_->id(),
+ tsk->get_request()->header->from_address,
+ tsk->get_request()->to_address,
+ tsk->get_request()->header->trace_id);
} break;
case dsn_task_type_t::TASK_TYPE_RPC_RESPONSE: {
rpc_response_task *tsk = (rpc_response_task *)this_;
- LOG_INFO("%s EXEC BEGIN, task_id = %016" PRIx64 ", %s => %s, trace_id = %016" PRIx64 "",
- this_->spec().name.c_str(),
- this_->id(),
- tsk->get_request()->to_address.to_string(),
- tsk->get_request()->header->from_address.to_string(),
- tsk->get_request()->header->trace_id);
+ LOG_INFO_F("{} EXEC BEGIN, task_id = {:#018x}, {} => {}, trace_id = {:#018x}",
+ this_->spec().name,
+ this_->id(),
+ tsk->get_request()->to_address,
+ tsk->get_request()->header->from_address,
+ tsk->get_request()->header->trace_id);
} break;
default:
break;
@@ -104,15 +101,15 @@ static void tracer_on_task_begin(task *this_)
static void tracer_on_task_end(task *this_)
{
- LOG_INFO("%s EXEC END, task_id = %016" PRIx64 ", err = %s",
- this_->spec().name.c_str(),
- this_->id(),
- this_->error().to_string());
+ LOG_INFO_F("{} EXEC END, task_id = {:#018x}, err = {}",
+ this_->spec().name,
+ this_->id(),
+ this_->error());
}
static void tracer_on_task_cancelled(task *this_)
{
- LOG_INFO("%s CANCELLED, task_id = %016" PRIx64 "", this_->spec().name.c_str(), this_->id());
+ LOG_INFO_F("{} CANCELLED, task_id = {:#018x}", this_->spec().name, this_->id());
}
static void tracer_on_task_wait_pre(task *caller, task *callee, uint32_t timeout_ms) {}
@@ -124,46 +121,46 @@ static void tracer_on_task_cancel_post(task *caller, task *callee, bool succ) {}
// return true means continue, otherwise early terminate with task::set_error_code
static void tracer_on_aio_call(task *caller, aio_task *callee)
{
- LOG_INFO("%s AIO.CALL, task_id = %016" PRIx64 ", offset = %" PRIu64 ", size = %d",
- callee->spec().name.c_str(),
- callee->id(),
- callee->get_aio_context()->file_offset,
- callee->get_aio_context()->buffer_size);
+ LOG_INFO_F("{} AIO.CALL, task_id = {:#018x}, offset = {}, size = {}",
+ callee->spec().name,
+ callee->id(),
+ callee->get_aio_context()->file_offset,
+ callee->get_aio_context()->buffer_size);
}
static void tracer_on_aio_enqueue(aio_task *this_)
{
- LOG_INFO("%s AIO.ENQUEUE, task_id = %016" PRIx64 ", queue size = %d",
- this_->spec().name.c_str(),
- this_->id(),
- tls_dsn.last_worker_queue_size);
+ LOG_INFO_F("{} AIO.ENQUEUE, task_id = {:#018x}, queue size = {}",
+ this_->spec().name,
+ this_->id(),
+ tls_dsn.last_worker_queue_size);
}
// return true means continue, otherwise early terminate with task::set_error_code
static void tracer_on_rpc_call(task *caller, message_ex *req, rpc_response_task *callee)
{
message_header &hdr = *req->header;
- LOG_INFO("%s RPC.CALL: %s => %s, trace_id = %016" PRIx64 ", callback_task = %016" PRIx64
- ", timeout = %d ms",
- hdr.rpc_name,
- req->header->from_address.to_string(),
- req->to_address.to_string(),
- hdr.trace_id,
- callee ? callee->id() : 0,
- hdr.client.timeout_ms);
+ LOG_INFO_F(
+ "{} RPC.CALL: {} => {}, trace_id = {:#018x}, callback_task = {:#018x}, timeout = {} ms",
+ hdr.rpc_name,
+ req->header->from_address,
+ req->to_address,
+ hdr.trace_id,
+ callee ? callee->id() : 0,
+ hdr.client.timeout_ms);
}
static void tracer_on_rpc_request_enqueue(rpc_request_task *callee)
{
- LOG_INFO("%s RPC.REQUEST.ENQUEUE (0x%p), task_id = %016" PRIx64
- ", %s => %s, trace_id = %016" PRIx64 ", queue size = %d",
- callee->spec().name.c_str(),
- callee,
- callee->id(),
- callee->get_request()->header->from_address.to_string(),
- callee->get_request()->to_address.to_string(),
- callee->get_request()->header->trace_id,
- tls_dsn.last_worker_queue_size);
+ LOG_INFO_F("{} RPC.REQUEST.ENQUEUE ({}), task_id = {:#018x}, {} => {}, trace_id = {:#018x}, "
+ "queue size = {}",
+ callee->spec().name,
+ fmt::ptr(callee),
+ callee->id(),
+ callee->get_request()->header->from_address,
+ callee->get_request()->to_address,
+ callee->get_request()->header->trace_id,
+ tls_dsn.last_worker_queue_size);
}
// return true means continue, otherwise early terminate with task::set_error_code
@@ -171,30 +168,30 @@ static void tracer_on_rpc_reply(task *caller, message_ex *msg)
{
message_header &hdr = *msg->header;
- LOG_INFO("%s RPC.REPLY: %s => %s, trace_id = %016" PRIx64 "",
- hdr.rpc_name,
- msg->header->from_address.to_string(),
- msg->to_address.to_string(),
- hdr.trace_id);
+ LOG_INFO_F("{} RPC.REPLY: {} => {}, trace_id = {:#018x}",
+ hdr.rpc_name,
+ msg->header->from_address,
+ msg->to_address,
+ hdr.trace_id);
}
static void tracer_on_rpc_response_enqueue(rpc_response_task *resp)
{
- LOG_INFO("%s RPC.RESPONSE.ENQUEUE, task_id = %016" PRIx64 ", %s => %s, trace_id = %016" PRIx64
- ", queue size = %d",
- resp->spec().name.c_str(),
- resp->id(),
- resp->get_request()->to_address.to_string(),
- resp->get_request()->header->from_address.to_string(),
- resp->get_request()->header->trace_id,
- tls_dsn.last_worker_queue_size);
+ LOG_INFO_F("{} RPC.RESPONSE.ENQUEUE, task_id = {:#018x}, {} => {}, trace_id = {:#018x}, queue "
+ "size = {}",
+ resp->spec().name,
+ resp->id(),
+ resp->get_request()->to_address,
+ resp->get_request()->header->from_address,
+ resp->get_request()->header->trace_id,
+ tls_dsn.last_worker_queue_size);
}
static void tracer_on_rpc_create_response(message_ex *req, message_ex *resp)
{
- LOG_INFO("%s RPC.CREATE.RESPONSE, trace_id = %016" PRIx64 "",
- resp->header->rpc_name,
- resp->header->trace_id);
+ LOG_INFO_F("{} RPC.CREATE.RESPONSE, trace_id = {:#018x}",
+ resp->header->rpc_name,
+ resp->header->trace_id);
}
enum logged_event_t
diff --git a/src/server/available_detector.cpp b/src/server/available_detector.cpp
index 6aeb68110..86bcea5f2 100644
--- a/src/server/available_detector.cpp
+++ b/src/server/available_detector.cpp
@@ -270,20 +270,20 @@ bool available_detector::generate_hash_keys()
void available_detector::on_detect(int32_t idx)
{
if (idx == 0) {
- LOG_INFO("detecting table[%s] with app_id[%d] and partition_count[%d] on cluster[%s], "
- "recent_day_detect_times(%" PRId64 "), recent_day_fail_times(%" PRId64 "), "
- "recent_hour_detect_times(%" PRId64 "), recent_hour_fail_times(%" PRId64 ") "
- "recent_minute_detect_times(%" PRId64 "), recent_minute_fail_times(%" PRId64 ")",
- _app_name.c_str(),
- _app_id,
- _partition_count,
- _cluster_name.c_str(),
- _recent_day_detect_times.load(),
- _recent_day_fail_times.load(),
- _recent_hour_detect_times.load(),
- _recent_hour_fail_times.load(),
- _recent_minute_detect_times.load(),
- _recent_minute_fail_times.load());
+ LOG_INFO_F("detecting table[{}] with app_id[{}] and partition_count[{}] on cluster[{}], "
+ "recent_day_detect_times({}), recent_day_fail_times({}), "
+ "recent_hour_detect_times({}), recent_hour_fail_times({}) "
+ "recent_minute_detect_times({}), recent_minute_fail_times({})",
+ _app_name,
+ _app_id,
+ _partition_count,
+ _cluster_name,
+ _recent_day_detect_times,
+ _recent_day_fail_times,
+ _recent_hour_detect_times,
+ _recent_hour_fail_times,
+ _recent_minute_detect_times,
+ _recent_minute_fail_times);
}
LOG_DEBUG_F("available_detector begin to detect partition[{}] of table[{}] with id[{}] on the "
"cluster[{}]",
@@ -362,15 +362,15 @@ void available_detector::check_and_send_email(std::atomic<int> *cnt, int32_t idx
}
}
if (send_email) {
- LOG_INFO("start to send alert email, partition_index = %d", idx);
+ LOG_INFO_F("start to send alert email, partition_index = {}", idx);
if (_send_alert_email_cmd.empty()) {
- LOG_INFO("ignore sending alert email because email address is not set, "
- "partition_index = %d",
- idx);
+ LOG_INFO_F("ignore sending alert email because email address is not set, "
+ "partition_index = {}",
+ idx);
} else {
int r = system((_send_alert_email_cmd + std::to_string(idx)).c_str());
if (r == 0) {
- LOG_INFO("send alert email done, partition_index = %d", idx);
+ LOG_INFO_F("send alert email done, partition_index = {}", idx);
} else {
LOG_ERROR("send alert email failed, partition_index = %d, "
"command_return = %d",
@@ -383,7 +383,7 @@ void available_detector::check_and_send_email(std::atomic<int> *cnt, int32_t idx
void available_detector::on_day_report()
{
- LOG_INFO("start to report on new day, last_day = %s", _old_day.c_str());
+ LOG_INFO_F("start to report on new day, last_day = {}", _old_day);
int64_t detect_times = _recent_day_detect_times.fetch_and(0);
int64_t fail_times = _recent_day_fail_times.fetch_and(0);
int64_t succ_times = std::max<int64_t>(0L, detect_times - fail_times);
@@ -402,23 +402,23 @@ void available_detector::on_day_report()
_pfc_fail_times_day->set(fail_times);
_pfc_available_day->set(available);
- LOG_INFO("start to send availability email, date = %s", _old_day.c_str());
+ LOG_INFO_F("start to send availability email, date = {}", _old_day);
if (_send_availability_info_email_cmd.empty()) {
- LOG_INFO("ignore sending availability email because email address is not set, "
- "date = %s, total_detect_times = %u, total_fail_times = %u",
- _old_day.c_str(),
- detect_times,
- fail_times);
+ LOG_INFO_F("ignore sending availability email because email address is not set, "
+ "date = {}, total_detect_times = {}, total_fail_times = {}",
+ _old_day,
+ detect_times,
+ fail_times);
} else {
int r = system((_send_availability_info_email_cmd + std::to_string(detect_times) + " " +
std::to_string(fail_times) + " " + _old_day)
.c_str());
if (r == 0) {
- LOG_INFO("send availability email done, date = %s, "
- "total_detect_times = %u, total_fail_times = %u",
- _old_day.c_str(),
- detect_times,
- fail_times);
+ LOG_INFO_F("send availability email done, date = {}, "
+ "total_detect_times = {}, total_fail_times = {}",
+ _old_day,
+ detect_times,
+ fail_times);
} else {
LOG_ERROR("send availability email fail, date = %s, "
"total_detect_times = %u, total_fail_times = %u, command_return = %d",
@@ -434,7 +434,7 @@ void available_detector::on_day_report()
void available_detector::on_hour_report()
{
- LOG_INFO("start to report on new hour, last_hour = %s", _old_hour.c_str());
+ LOG_INFO_F("start to report on new hour, last_hour = {}", _old_hour);
int64_t detect_times = _recent_hour_detect_times.fetch_and(0);
int64_t fail_times = _recent_hour_fail_times.fetch_and(0);
int64_t succ_times = std::max<int64_t>(0L, detect_times - fail_times);
@@ -458,7 +458,7 @@ void available_detector::on_hour_report()
void available_detector::on_minute_report()
{
- LOG_INFO("start to report on new minute, last_minute = %s", _old_minute.c_str());
+ LOG_INFO_F("start to report on new minute, last_minute = {}", _old_minute);
int64_t detect_times = _recent_minute_detect_times.fetch_and(0);
int64_t fail_times = _recent_minute_fail_times.fetch_and(0);
int64_t succ_times = std::max<int64_t>(0L, detect_times - fail_times);
diff --git a/src/server/compaction_operation.cpp b/src/server/compaction_operation.cpp
index 20b90df74..fbc947663 100644
--- a/src/server/compaction_operation.cpp
+++ b/src/server/compaction_operation.cpp
@@ -97,7 +97,7 @@ bool update_ttl::filter(dsn::string_view hash_key,
new_ts = value - pegasus::utils::epoch_begin;
break;
default:
- LOG_INFO("invalid update ttl operation type");
+ LOG_INFO_F("invalid update ttl operation type");
return false;
}
@@ -160,7 +160,7 @@ compaction_operations create_compaction_operations(const std::string &json, uint
internal::json_helper compaction;
if (!dsn::json::json_forwarder<internal::json_helper>::decode(
dsn::blob::create_from_bytes(json.data(), json.size()), compaction)) {
- LOG_INFO("invalid user specified compaction format");
+ LOG_INFO_F("invalid user specified compaction format");
return res;
}
diff --git a/src/server/hotspot_partition_calculator.cpp b/src/server/hotspot_partition_calculator.cpp
index 4f0584b10..15e838361 100644
--- a/src/server/hotspot_partition_calculator.cpp
+++ b/src/server/hotspot_partition_calculator.cpp
@@ -107,7 +107,7 @@ void hotspot_partition_calculator::stat_histories_analyse(uint32_t data_type,
}
}
if (sample_count <= 1) {
- LOG_INFO("_partitions_stat_histories size <= 1, not enough data for calculation");
+ LOG_INFO_F("_partitions_stat_histories size <= 1, not enough data for calculation");
return;
}
table_qps_avg = table_qps_sum / sample_count;
diff --git a/src/server/info_collector.cpp b/src/server/info_collector.cpp
index 3c5c6946f..7edfbfa79 100644
--- a/src/server/info_collector.cpp
+++ b/src/server/info_collector.cpp
@@ -140,7 +140,7 @@ void info_collector::stop() { _tracker.cancel_outstanding_tasks(); }
void info_collector::on_app_stat()
{
- LOG_INFO("start to stat apps");
+ LOG_INFO_F("start to stat apps");
std::map<std::string, std::vector<row_data>> all_rows;
if (!get_app_partition_stat(_shell_context.get(), all_rows)) {
LOG_ERROR("call get_app_stat() failed");
@@ -257,7 +257,7 @@ info_collector::app_stat_counters *info_collector::get_app_counters(const std::s
void info_collector::on_capacity_unit_stat(int remaining_retry_count)
{
- LOG_INFO("start to stat capacity unit, remaining_retry_count = %d", remaining_retry_count);
+ LOG_INFO_F("start to stat capacity unit, remaining_retry_count = {}", remaining_retry_count);
std::vector<node_capacity_unit_stat> nodes_stat;
if (!get_capacity_unit_stat(_shell_context.get(), nodes_stat)) {
if (remaining_retry_count > 0) {
@@ -304,7 +304,7 @@ bool info_collector::has_capacity_unit_updated(const std::string &node_address,
void info_collector::on_storage_size_stat(int remaining_retry_count)
{
- LOG_INFO("start to stat storage size, remaining_retry_count = %d", remaining_retry_count);
+ LOG_INFO_F("start to stat storage size, remaining_retry_count = {}", remaining_retry_count);
app_storage_size_stat st_stat;
if (!get_storage_size_stat(_shell_context.get(), st_stat)) {
if (remaining_retry_count > 0) {
diff --git a/src/server/main.cpp b/src/server/main.cpp
index f9ed0d81f..e145a5532 100644
--- a/src/server/main.cpp
+++ b/src/server/main.cpp
@@ -82,8 +82,7 @@ int main(int argc, char **argv)
dsn_exit(0);
}
}
- LOG_INFO(
- "pegasus server starting, pid(%d), version(%s)", (int)getpid(), pegasus_server_rcsid());
+ LOG_INFO_F("pegasus server starting, pid({}), version({})", getpid(), pegasus_server_rcsid());
dsn_app_registration_pegasus();
std::unique_ptr<command_deregister> server_info_cmd =
diff --git a/src/server/pegasus_server_impl.cpp b/src/server/pegasus_server_impl.cpp
index 3109e9b17..5d3c172be 100644
--- a/src/server/pegasus_server_impl.cpp
+++ b/src/server/pegasus_server_impl.cpp
@@ -96,7 +96,7 @@ void pegasus_server_impl::parse_checkpoints()
if (chkpt_init_from_dir(d1.c_str(), ci)) {
_checkpoints.push_back(ci);
} else if (d1.find("checkpoint") != std::string::npos) {
- LOG_INFO("%s: invalid checkpoint directory %s, remove it", replica_name(), d.c_str());
+ LOG_INFO_PREFIX("invalid checkpoint directory {}, remove it", d);
::dsn::utils::filesystem::remove_path(d);
if (!::dsn::utils::filesystem::remove_path(d)) {
LOG_ERROR(
@@ -165,9 +165,8 @@ void pegasus_server_impl::gc_checkpoints(bool force_reserve_one)
}
if (max_del_d == -1) {
// no checkpoint to delete
- LOG_INFO("%s: no checkpoint to garbage collection, checkpoints_count = %d",
- replica_name(),
- (int)temp_list.size());
+ LOG_INFO_PREFIX("no checkpoint to garbage collection, checkpoints_count = {}",
+ temp_list.size());
return;
}
std::list<int64_t> to_delete_list;
@@ -206,9 +205,7 @@ void pegasus_server_impl::gc_checkpoints(bool force_reserve_one)
::dsn::utils::filesystem::path_combine(data_dir(), chkpt_get_dir_name(del_d));
if (::dsn::utils::filesystem::directory_exists(cpt_dir)) {
if (::dsn::utils::filesystem::remove_path(cpt_dir)) {
- LOG_INFO("%s: checkpoint directory %s removed by garbage collection",
- replica_name(),
- cpt_dir.c_str());
+ LOG_INFO_PREFIX("checkpoint directory {} removed by garbage collection", cpt_dir);
} else {
LOG_ERROR("%s: checkpoint directory %s remove failed by garbage collection",
replica_name(),
@@ -216,9 +213,8 @@ void pegasus_server_impl::gc_checkpoints(bool force_reserve_one)
put_back_list.push_back(del_d);
}
} else {
- LOG_INFO("%s: checkpoint directory %s does not exist, ignored by garbage collection",
- replica_name(),
- cpt_dir.c_str());
+ LOG_INFO_PREFIX("checkpoint directory {} does not exist, ignored by garbage collection",
+ cpt_dir);
}
}
@@ -247,12 +243,11 @@ void pegasus_server_impl::gc_checkpoints(bool force_reserve_one)
}
}
- LOG_INFO("%s: after checkpoint garbage collection, checkpoints_count = %d, "
- "min_checkpoint = %" PRId64 ", max_checkpoint = %" PRId64,
- replica_name(),
- checkpoints_count,
- min_d,
- max_d);
+ LOG_INFO_PREFIX("after checkpoint garbage collection, checkpoints_count = {}, min_checkpoint = "
+ "{}, max_checkpoint = {}",
+ checkpoints_count,
+ min_d,
+ max_d);
}
int pegasus_server_impl::on_batched_write_requests(int64_t decree,
@@ -1828,8 +1823,7 @@ void pegasus_server_impl::cancel_background_work(bool wait)
_pfc_rdb_memtable_mem_usage->set(0);
}
- LOG_INFO(
- "%s: close app succeed, clear_state = %s", replica_name(), clear_state ? "true" : "false");
+ LOG_INFO_PREFIX("close app succeed, clear_state = {}", clear_state ? "true" : "false");
return ::dsn::ERR_OK;
}
@@ -2151,10 +2145,8 @@ private:
state.from_decree_excluded = 0;
state.to_decree_included = ci;
- LOG_INFO("%s: get checkpoint succeed, from_decree_excluded = 0, to_decree_included = %" PRId64
- "",
- replica_name(),
- state.to_decree_included);
+ LOG_INFO_PREFIX("get checkpoint succeed, from_decree_excluded = 0, to_decree_included = {}",
+ state.to_decree_included);
return ::dsn::ERR_OK;
}
@@ -2225,7 +2217,7 @@ pegasus_server_impl::storage_apply_checkpoint(chkpt_apply_mode mode,
err = start(0, nullptr);
} else {
- LOG_INFO("%s: apply empty checkpoint, create new rocksdb", replica_name());
+ LOG_INFO_PREFIX("apply empty checkpoint, create new rocksdb");
err = start(0, nullptr);
}
@@ -2237,9 +2229,7 @@ pegasus_server_impl::storage_apply_checkpoint(chkpt_apply_mode mode,
CHECK(_is_open, "");
CHECK_EQ(ci, last_durable_decree());
- LOG_INFO("%s: apply checkpoint succeed, last_durable_decree = %" PRId64,
- replica_name(),
- last_durable_decree());
+ LOG_INFO_PREFIX("apply checkpoint succeed, last_durable_decree = {}", last_durable_decree());
return ::dsn::ERR_OK;
}
@@ -2563,16 +2553,13 @@ pegasus_server_impl::get_restore_dir_from_env(const std::map<std::string, std::s
auto it = env_kvs.find(ROCKSDB_ENV_RESTORE_FORCE_RESTORE);
if (it != env_kvs.end()) {
- LOG_INFO("%s: found %s in envs", replica_name(), ROCKSDB_ENV_RESTORE_FORCE_RESTORE.c_str());
+ LOG_INFO_PREFIX("found {} in envs", ROCKSDB_ENV_RESTORE_FORCE_RESTORE);
res.second = true;
}
it = env_kvs.find(ROCKSDB_ENV_RESTORE_POLICY_NAME);
if (it != env_kvs.end()) {
- LOG_INFO("%s: found %s in envs: %s",
- replica_name(),
- ROCKSDB_ENV_RESTORE_POLICY_NAME.c_str(),
- it->second.c_str());
+ LOG_INFO_PREFIX("found {} in envs: {}", ROCKSDB_ENV_RESTORE_POLICY_NAME, it->second);
os << it->second << ".";
} else {
return res;
@@ -2580,10 +2567,7 @@ pegasus_server_impl::get_restore_dir_from_env(const std::map<std::string, std::s
it = env_kvs.find(ROCKSDB_ENV_RESTORE_BACKUP_ID);
if (it != env_kvs.end()) {
- LOG_INFO("%s: found %s in envs: %s",
- replica_name(),
- ROCKSDB_ENV_RESTORE_BACKUP_ID.c_str(),
- it->second.c_str());
+ LOG_INFO_PREFIX("found {} in envs: {}", ROCKSDB_ENV_RESTORE_BACKUP_ID, it->second);
os << it->second;
} else {
return res;
@@ -3109,10 +3093,8 @@ void pegasus_server_impl::recalculate_data_cf_options(
}
if (new_options.size() > 0) {
if (set_options(new_options)) {
- LOG_INFO_PREFIX(
- "{}: recalculate the value of the options related to usage scenario \"{}\"",
- replica_name(),
- _usage_scenario);
+ LOG_INFO_PREFIX("recalculate the value of the options related to usage scenario \"{}\"",
+ _usage_scenario);
}
}
_table_data_cf_opts_recalculated = true;
@@ -3139,10 +3121,7 @@ bool pegasus_server_impl::set_options(
}
rocksdb::Status status = _db->SetOptions(_data_cf, new_options);
if (status == rocksdb::Status::OK()) {
- LOG_INFO("%s: rocksdb set options returns %s: {%s}",
- replica_name(),
- status.ToString().c_str(),
- oss.str().c_str());
+ LOG_INFO_PREFIX("rocksdb set options returns {}: {}", status.ToString(), oss.str());
return true;
} else {
LOG_ERROR("%s: rocksdb set options returns %s: {%s}",
@@ -3242,9 +3221,8 @@ bool pegasus_server_impl::release_storage_after_manual_compact()
LOG_INFO_PREFIX("start async_checkpoint");
start_time = dsn_now_ms();
::dsn::error_code err = async_checkpoint(false);
- LOG_INFO_PREFIX("finish async_checkpoint, return = {}, time_used = {}ms",
- err.to_string(),
- dsn_now_ms() - start_time);
+ LOG_INFO_PREFIX(
+ "finish async_checkpoint, return = {}, time_used = {}ms", err, dsn_now_ms() - start_time);
// gc checkpoints
LOG_INFO_PREFIX("start gc_checkpoints");
diff --git a/src/test/kill_test/data_verifier.cpp b/src/test/kill_test/data_verifier.cpp
index 6a7ba2203..6099b0859 100644
--- a/src/test/kill_test/data_verifier.cpp
+++ b/src/test/kill_test/data_verifier.cpp
@@ -119,33 +119,33 @@ void do_set(int thread_id)
client->set(hash_key, sort_key, value, set_and_get_timeout_milliseconds, 0, &info);
if (ret == PERR_OK) {
long cur_time = get_time();
- LOG_INFO("SetThread[%d]: set succeed: id=%lld, try=%d, time=%ld (gpid=%d.%d, "
- "decree=%lld, server=%s)",
- thread_id,
- id,
- try_count,
- (cur_time - last_time),
- info.app_id,
- info.partition_index,
- info.decree,
- info.server.c_str());
+ LOG_INFO_F("SetThread[{}]: set succeed: id={}, try={}, time={} (gpid={}.{}, decree={}, "
+ "server={})",
+ thread_id,
+ id,
+ try_count,
+ cur_time - last_time,
+ info.app_id,
+ info.partition_index,
+ info.decree,
+ info.server);
stat_time[stat_count++] = cur_time - last_time;
if (stat_count == stat_batch) {
std::sort(stat_time.begin(), stat_time.end());
long total_time = 0;
for (auto t : stat_time)
total_time += t;
- LOG_INFO("SetThread[%d]: set statistics: count=%lld, min=%lld, P90=%lld, P99=%lld, "
- "P999=%lld, P9999=%lld, max=%lld, avg=%lld",
- thread_id,
- stat_count,
- stat_time[stat_min_pos],
- stat_time[stat_p90_pos],
- stat_time[stat_p99_pos],
- stat_time[stat_p999_pos],
- stat_time[stat_p9999_pos],
- stat_time[stat_max_pos],
- total_time / stat_batch);
+ LOG_INFO_F("SetThread[{}]: set statistics: count={}, min={}, P90={}, P99={}, "
+ "P999={}, P9999={}, max={}, avg={}",
+ thread_id,
+ stat_count,
+ stat_time[stat_min_pos],
+ stat_time[stat_p90_pos],
+ stat_time[stat_p99_pos],
+ stat_time[stat_p999_pos],
+ stat_time[stat_p9999_pos],
+ stat_time[stat_max_pos],
+ total_time / stat_batch);
stat_count = 0;
}
last_time = cur_time;
@@ -174,8 +174,8 @@ void do_set(int thread_id)
// - loop from range [start_id, end_id]
void do_get_range(int thread_id, int round_id, long long start_id, long long end_id)
{
- LOG_INFO(
- "GetThread[%d]: round(%d): start get range [%u,%u]", thread_id, round_id, start_id, end_id);
+ LOG_INFO_F(
+ "GetThread[{}]: round({}): start get range [{},{}]", thread_id, round_id, start_id, end_id);
char buf[1024];
std::string hash_key;
std::string sort_key;
@@ -244,17 +244,17 @@ void do_get_range(int thread_id, int round_id, long long start_id, long long end
long total_time = 0;
for (auto t : stat_time)
total_time += t;
- LOG_INFO("GetThread[%d]: get statistics: count=%lld, min=%lld, P90=%lld, "
- "P99=%lld, P999=%lld, P9999=%lld, max=%lld, avg=%lld",
- thread_id,
- stat_count,
- stat_time[stat_min_pos],
- stat_time[stat_p90_pos],
- stat_time[stat_p99_pos],
- stat_time[stat_p999_pos],
- stat_time[stat_p9999_pos],
- stat_time[stat_max_pos],
- total_time / stat_batch);
+ LOG_INFO_F("GetThread[{}]: get statistics: count={}, min={}, P90={}, "
+ "P99={}, P999={}, P9999={}, max={}, avg={}",
+ thread_id,
+ stat_count,
+ stat_time[stat_min_pos],
+ stat_time[stat_p90_pos],
+ stat_time[stat_p99_pos],
+ stat_time[stat_p999_pos],
+ stat_time[stat_p9999_pos],
+ stat_time[stat_max_pos],
+ total_time / stat_batch);
stat_count = 0;
}
}
@@ -279,11 +279,11 @@ void do_get_range(int thread_id, int round_id, long long start_id, long long end
}
}
}
- LOG_INFO("GetThread[%d]: round(%d): finish get range [%u,%u]",
- thread_id,
- round_id,
- start_id,
- end_id);
+ LOG_INFO_F("GetThread[{}]: round({}): finish get range [{},{}]",
+ thread_id,
+ round_id,
+ start_id,
+ end_id);
}
void do_check(int thread_count)
@@ -295,7 +295,7 @@ void do_check(int thread_count)
sleep(1);
continue;
}
- LOG_INFO("CheckThread: round(%d): start check round, range_end=%lld", round_id, range_end);
+ LOG_INFO_F("CheckThread: round({}): start check round, range_end={}", round_id, range_end);
long start_time = get_time();
std::vector<std::thread> worker_threads;
long long piece_count = range_end / thread_count;
@@ -308,8 +308,8 @@ void do_check(int thread_count)
t.join();
}
long finish_time = get_time();
- LOG_INFO(
- "CheckThread: round(%d): finish check round, range_end=%lld, total_time=%ld seconds",
+ LOG_INFO_F(
+ "CheckThread: round({}): finish check round, range_end={}, total_time={} seconds",
round_id,
range_end,
(finish_time - start_time) / 1000000);
@@ -320,10 +320,10 @@ void do_check(int thread_count)
sprintf(buf, "%lld", range_end);
int ret = client->set(check_max_key, "", buf, set_and_get_timeout_milliseconds);
if (ret == PERR_OK) {
- LOG_INFO("CheckThread: round(%d): update \"%s\" succeed: check_max=%lld",
- round_id,
- check_max_key,
- range_end);
+ LOG_INFO_F("CheckThread: round({}): update \"{}\" succeed: check_max={}",
+ round_id,
+ check_max_key,
+ range_end);
break;
} else {
LOG_ERROR("CheckThread: round(%d): update \"%s\" failed: check_max=%lld, ret=%d, "
@@ -358,10 +358,10 @@ void do_mark()
int ret = client->set(set_next_key, "", value, set_and_get_timeout_milliseconds);
if (ret == PERR_OK) {
long cur_time = get_time();
- LOG_INFO("MarkThread: update \"%s\" succeed: set_next=%lld, time=%ld",
- set_next_key,
- new_id,
- (cur_time - last_time));
+ LOG_INFO_F("MarkThread: update \"{}\" succeed: set_next={}, time={}",
+ set_next_key,
+ new_id,
+ cur_time - last_time);
old_id = new_id;
} else {
LOG_ERROR("MarkThread: update \"%s\" failed: set_next=%lld, ret=%d, error=%s",
@@ -416,11 +416,11 @@ void verifier_start()
set_next_value.c_str());
exit(-1);
}
- LOG_INFO("MainThread: read \"%s\" succeed: value=%lld", set_next_key, i);
+ LOG_INFO_F("MainThread: read \"{}\" succeed: value={}", set_next_key, i);
set_next.store(i);
break;
} else if (ret == PERR_NOT_FOUND) {
- LOG_INFO("MainThread: read \"%s\" not found, init set_next to 0", set_next_key);
+ LOG_INFO_F("MainThread: read \"{}\" not found, init set_next to 0", set_next_key);
set_next.store(0);
break;
} else {
diff --git a/src/test/kill_test/kill_testor.cpp b/src/test/kill_test/kill_testor.cpp
index 4eb2c22df..66c0400d6 100644
--- a/src/test/kill_test/kill_testor.cpp
+++ b/src/test/kill_test/kill_testor.cpp
@@ -145,7 +145,7 @@ dsn::error_code kill_testor::get_partition_info(bool debug_unhealthy,
info << "], ";
info << "last_committed_decree=" << p.last_committed_decree;
if (debug_unhealthy) {
- LOG_INFO("found unhealthy partition, %s", info.str().c_str());
+ LOG_INFO_F("found unhealthy partition, {}", info.str());
} else {
LOG_DEBUG_F("found unhealthy partition, {}", info.str());
}
@@ -180,7 +180,7 @@ bool kill_testor::check_cluster_status()
} else
return true;
} else {
- LOG_INFO("query partition status fail, try times = %d", try_count);
+ LOG_INFO_F("query partition status fail, try times = {}", try_count);
sleep(1);
}
try_count += 1;
diff --git a/src/test/kill_test/killer_handler_shell.cpp b/src/test/kill_test/killer_handler_shell.cpp
index 315ece9da..4adbf6b6b 100644
--- a/src/test/kill_test/killer_handler_shell.cpp
+++ b/src/test/kill_test/killer_handler_shell.cpp
@@ -28,6 +28,7 @@
#include "utils/api_utilities.h"
#include "utils/config_api.h"
#include "utils/fmt_logging.h"
+#include "utils/safe_strerror_posix.h"
namespace pegasus {
namespace test {
@@ -78,9 +79,9 @@ bool killer_handler_shell::kill_meta(int index)
{
std::string cmd = generate_cmd(index, "meta", "stop");
int res = system(cmd.c_str());
- LOG_INFO("kill meta command: %s", cmd.c_str());
+ LOG_INFO_F("kill meta command: {}", cmd);
if (res != 0) {
- LOG_INFO("kill meta encounter error(%s)", strerror(errno));
+ LOG_INFO_F("kill meta encounter error({})", dsn::utils::safe_strerror(errno));
return false;
}
return check("meta", index, "stop");
@@ -90,9 +91,9 @@ bool killer_handler_shell::kill_replica(int index)
{
std::string cmd = generate_cmd(index, "replica", "stop");
int res = system(cmd.c_str());
- LOG_INFO("kill replica command: %s", cmd.c_str());
+ LOG_INFO_F("kill replica command: {}", cmd);
if (res != 0) {
- LOG_INFO("kill meta encounter error(%s)", strerror(errno));
+ LOG_INFO_F("kill meta encounter error({})", dsn::utils::safe_strerror(errno));
return false;
}
return check("replica", index, "stop");
@@ -108,9 +109,9 @@ bool killer_handler_shell::start_meta(int index)
{
std::string cmd = generate_cmd(index, "meta", "start");
int res = system(cmd.c_str());
- LOG_INFO("start meta command: %s", cmd.c_str());
+ LOG_INFO_F("start meta command: {}", cmd);
if (res != 0) {
- LOG_INFO("kill meta encounter error(%s)", strerror(errno));
+ LOG_INFO_F("kill meta encounter error({})", dsn::utils::safe_strerror(errno));
return false;
}
return check("meta", index, "start");
@@ -121,9 +122,9 @@ bool killer_handler_shell::start_replica(int index)
std::string cmd = generate_cmd(index, "replica", "start");
int res = system(cmd.c_str());
- LOG_INFO("start replica command: %s", cmd.c_str());
+ LOG_INFO_F("start replica command: {}", cmd);
if (res != 0) {
- LOG_INFO("kill meta encounter error(%s)", strerror(errno));
+ LOG_INFO_F("kill meta encounter error({})", dsn::utils::safe_strerror(errno));
return false;
}
return check("meta", index, "start");
diff --git a/src/test/kill_test/partition_kill_testor.cpp b/src/test/kill_test/partition_kill_testor.cpp
index 6872531b1..99a53888b 100644
--- a/src/test/kill_test/partition_kill_testor.cpp
+++ b/src/test/kill_test/partition_kill_testor.cpp
@@ -38,14 +38,14 @@ partition_kill_testor::partition_kill_testor(const char *config_file) : kill_tes
void partition_kill_testor::Run()
{
- LOG_INFO("begin the kill-partition");
+ LOG_INFO_F("begin the kill-partition");
while (true) {
if (!check_cluster_status()) {
- LOG_INFO("check_cluster_status() failed");
+ LOG_INFO_F("check_cluster_status() failed");
} else {
run();
}
- LOG_INFO("sleep %d seconds before checking", kill_interval_seconds);
+ LOG_INFO_F("sleep {} seconds before checking", kill_interval_seconds);
sleep(kill_interval_seconds);
}
}
@@ -53,7 +53,7 @@ void partition_kill_testor::Run()
void partition_kill_testor::run()
{
if (partitions.size() == 0) {
- LOG_INFO("partitions empty");
+ LOG_INFO_F("partitions empty");
return;
}
diff --git a/src/test/kill_test/process_kill_testor.cpp b/src/test/kill_test/process_kill_testor.cpp
index 526fdbca7..11f004e5a 100644
--- a/src/test/kill_test/process_kill_testor.cpp
+++ b/src/test/kill_test/process_kill_testor.cpp
@@ -96,7 +96,7 @@ bool process_kill_testor::verifier_process_alive()
void process_kill_testor::Run()
{
- LOG_INFO("begin the kill-thread");
+ LOG_INFO_F("begin the kill-thread");
while (true) {
if (!check_cluster_status()) {
stop_verifier_and_exit("check_cluster_status() fail, and exit");
@@ -105,7 +105,7 @@ void process_kill_testor::Run()
stop_verifier_and_exit("the verifier process is dead");
}
run();
- LOG_INFO("sleep %d seconds before checking", kill_interval_seconds);
+ LOG_INFO_F("sleep {} seconds before checking", kill_interval_seconds);
sleep(kill_interval_seconds);
}
}
@@ -117,9 +117,9 @@ void process_kill_testor::run()
}
if (kill_round == 0) {
- LOG_INFO("Number of meta-server: %d", _total_meta_count);
- LOG_INFO("Number of replica-server: %d", _total_replica_count);
- LOG_INFO("Number of zookeeper: %d", _total_zookeeper_count);
+ LOG_INFO_F("Number of meta-server: {}", _total_meta_count);
+ LOG_INFO_F("Number of replica-server: {}", _total_replica_count);
+ LOG_INFO_F("Number of zookeeper: {}", _total_zookeeper_count);
}
kill_round += 1;
int meta_cnt = 0;
@@ -132,25 +132,26 @@ void process_kill_testor::run()
replica_cnt = generate_one_number(0, _kill_replica_max_count);
zk_cnt = generate_one_number(0, _kill_zk_max_count);
}
- LOG_INFO("************************");
- LOG_INFO("Round [%d]", kill_round);
- LOG_INFO("start kill...");
- LOG_INFO("kill meta number=%d, replica number=%d, zk number=%d", meta_cnt, replica_cnt, zk_cnt);
+ LOG_INFO_F("************************");
+ LOG_INFO_F("Round [{}]", kill_round);
+ LOG_INFO_F("start kill...");
+ LOG_INFO_F(
+ "kill meta number={}, replica number={}, zk number={}", meta_cnt, replica_cnt, zk_cnt);
if (!kill(meta_cnt, replica_cnt, zk_cnt)) {
stop_verifier_and_exit("kill jobs failed");
}
auto sleep_time_random_seconds = generate_one_number(1, _sleep_time_before_recover_seconds);
- LOG_INFO("sleep %d seconds before recovery", sleep_time_random_seconds);
+ LOG_INFO_F("sleep {} seconds before recovery", sleep_time_random_seconds);
sleep(sleep_time_random_seconds);
- LOG_INFO("start recover...");
+ LOG_INFO_F("start recover...");
if (!start()) {
stop_verifier_and_exit("recover jobs failed");
}
- LOG_INFO("after recover...");
- LOG_INFO("************************");
+ LOG_INFO_F("after recover...");
+ LOG_INFO_F("************************");
}
bool process_kill_testor::kill(int meta_cnt, int replica_cnt, int zookeeper_cnt)
@@ -165,12 +166,12 @@ bool process_kill_testor::kill(int meta_cnt, int replica_cnt, int zookeeper_cnt)
job_index_to_kill.clear();
generate_random(job_index_to_kill, kill_counts[id], 1, total_count[id]);
for (auto index : job_index_to_kill) {
- LOG_INFO("start to kill %s@%d", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("start to kill {}@{}", job_type_str(_job_types[id]), index);
if (!kill_job_by_index(_job_types[id], index)) {
- LOG_INFO("kill %s@%d failed", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("kill {}@{} failed", job_type_str(_job_types[id]), index);
return false;
}
- LOG_INFO("kill %s@%d succeed", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("kill {}@{} succeed", job_type_str(_job_types[id]), index);
}
}
return true;
@@ -183,12 +184,12 @@ bool process_kill_testor::start()
for (auto id : random_idxs) {
std::vector<int> &job_index_to_kill = _job_index_to_kill[_job_types[id]];
for (auto index : job_index_to_kill) {
- LOG_INFO("start to recover %s@%d", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("start to recover {}@{}", job_type_str(_job_types[id]), index);
if (!start_job_by_index(_job_types[id], index)) {
- LOG_INFO("recover %s@%d failed", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("recover {}@{} failed", job_type_str(_job_types[id]), index);
return false;
}
- LOG_INFO("recover %s@%d succeed", job_type_str(_job_types[id]), index);
+ LOG_INFO_F("recover {}@{} succeed", job_type_str(_job_types[id]), index);
}
}
return true;
diff --git a/src/test/pressure_test/main.cpp b/src/test/pressure_test/main.cpp
index d79df6317..48bcc4e5b 100644
--- a/src/test/pressure_test/main.cpp
+++ b/src/test/pressure_test/main.cpp
@@ -109,7 +109,7 @@ void test_set(int32_t qps)
atomic_int qps_quota(qps);
::dsn::task_ptr quota_task = ::dsn::tasking::enqueue_timer(
LPC_DEFAUT_TASK, nullptr, [&]() { qps_quota.store(qps); }, chrono::seconds(1));
- LOG_INFO("start to test set, with qps(%d)", qps);
+ LOG_INFO_F("start to test set, with qps({})", qps);
while (true) {
if (qps_quota.load() >= 10) {
qps_quota.fetch_sub(10);
@@ -132,7 +132,7 @@ void test_get(int32_t qps)
dsn::task_ptr quota_task = dsn::tasking::enqueue_timer(
LPC_DEFAUT_TASK, nullptr, [&]() { qps_quota.store(qps); }, chrono::seconds(1));
- LOG_INFO("start to test get, with qps(%d)", qps);
+ LOG_INFO_F("start to test get, with qps({})", qps);
while (true) {
if (qps_quota.load() >= 10) {
qps_quota.fetch_sub(10);
@@ -174,7 +174,7 @@ void test_del(int32_t qps)
dsn::task_ptr quota_task = dsn::tasking::enqueue_timer(
LPC_DEFAUT_TASK, nullptr, [&]() { qps_quota.store(qps); }, chrono::seconds(1));
- LOG_INFO("start to test get, with qps(%d)", qps);
+ LOG_INFO_F("start to test get, with qps({})", qps);
while (true) {
if (qps_quota.load() >= 10) {
qps_quota.fetch_sub(10);
@@ -223,7 +223,7 @@ int main(int argc, const char **argv)
return -1;
}
initialize();
- LOG_INFO("Initialize client and load config.ini succeed");
+ LOG_INFO_F("Initialize client and load config.ini succeed");
cluster_name =
dsn_config_get_value_string("pressureclient", "cluster_name", "onebox", "cluster name");
@@ -252,14 +252,14 @@ int main(int argc, const char **argv)
CHECK_GT(qps, 0);
CHECK(!op_name.empty(), "must assign operation name");
- LOG_INFO("pressureclient %s qps = %d", op_name.c_str(), qps);
+ LOG_INFO_F("pressureclient {} qps = {}", op_name, qps);
pg_client = pegasus_client_factory::get_client(cluster_name.c_str(), app_name.c_str());
CHECK_NOTNULL(pg_client, "initialize pg_client failed");
auto it = _all_funcs.find(op_name);
if (it != _all_funcs.end()) {
- LOG_INFO("start pressureclient with %s qps(%d)", op_name.c_str(), qps);
+ LOG_INFO_F("start pressureclient with {} qps({})", op_name, qps);
it->second(qps);
} else {
CHECK(false, "Unknown operation name({})", op_name);
diff --git a/src/utils/api_utilities.h b/src/utils/api_utilities.h
index e3c25d0a2..fc2de636a 100644
--- a/src/utils/api_utilities.h
+++ b/src/utils/api_utilities.h
@@ -87,7 +87,6 @@ extern void dsn_coredump();
dsn_logf(__FILENAME__, __FUNCTION__, __LINE__, level, __VA_ARGS__); \
} while (false)
-#define LOG_INFO(...) dlog(LOG_LEVEL_INFO, __VA_ARGS__)
#define LOG_WARNING(...) dlog(LOG_LEVEL_WARNING, __VA_ARGS__)
#define LOG_ERROR(...) dlog(LOG_LEVEL_ERROR, __VA_ARGS__)
#define LOG_FATAL(...) dlog(LOG_LEVEL_FATAL, __VA_ARGS__)
diff --git a/src/utils/command_manager.h b/src/utils/command_manager.h
index da60630fd..0e43ed3bf 100644
--- a/src/utils/command_manager.h
+++ b/src/utils/command_manager.h
@@ -30,6 +30,7 @@
#include "utils/api_utilities.h"
#include "utils/autoref_ptr.h"
+#include "utils/fmt_logging.h"
#include "utils/ports.h"
#include "utils/singleton.h"
#include "utils/synchronize.h"
@@ -107,10 +108,10 @@ inline std::string remote_command_set_bool_flag(bool &flag,
} else {
if (args[0] == "true") {
flag = true;
- LOG_INFO("set %s to true by remote command", flag_name);
+ LOG_INFO_F("set {} to true by remote command", flag_name);
} else if (args[0] == "false") {
flag = false;
- LOG_INFO("set %s to false by remote command", flag_name);
+ LOG_INFO_F("set {} to false by remote command", flag_name);
} else {
ret_msg = "ERR: invalid arguments";
}
diff --git a/src/utils/fail_point.cpp b/src/utils/fail_point.cpp
index b00811b50..54c372e45 100644
--- a/src/utils/fail_point.cpp
+++ b/src/utils/fail_point.cpp
@@ -71,12 +71,12 @@ inline const char *task_type_to_string(fail_point::task_type t)
{
fail_point &p = REGISTRY.create_if_not_exists(name);
p.set_action(action);
- LOG_INFO("add fail_point [name: %s, task: %s(%s), frequency: %d%, max_count: %d]",
- name.data(),
- task_type_to_string(p.get_task()),
- p.get_arg().data(),
- p.get_frequency(),
- p.get_max_count());
+ LOG_INFO_F("add fail_point [name: {}, task: {}({}), frequency: {}%, max_count: {}]",
+ name,
+ task_type_to_string(p.get_task()),
+ p.get_arg(),
+ p.get_frequency(),
+ p.get_max_count());
}
/*static*/ bool _S_FAIL_POINT_ENABLED = false;
@@ -152,7 +152,7 @@ const std::string *fail_point::eval()
return nullptr;
}
_max_cnt--;
- LOG_INFO("fail on %s", _name.data());
+ LOG_INFO_F("fail on {}", _name);
switch (_task) {
case Off:
@@ -161,7 +161,7 @@ const std::string *fail_point::eval()
case Return:
return &_arg;
case Print:
- LOG_INFO(_arg.data());
+ LOG_INFO_F(_arg);
break;
}
return nullptr;
diff --git a/src/zookeeper/distributed_lock_service_zookeeper.cpp b/src/zookeeper/distributed_lock_service_zookeeper.cpp
index 4937e34af..268aa9051 100644
--- a/src/zookeeper/distributed_lock_service_zookeeper.cpp
+++ b/src/zookeeper/distributed_lock_service_zookeeper.cpp
@@ -134,7 +134,7 @@ error_code distributed_lock_service_zookeeper::initialize(const std::vector<std:
}
_lock_root = current.empty() ? "/" : current;
- LOG_INFO("init distributed_lock_service_zookeeper succeed, lock_root = %s", _lock_root.c_str());
+ LOG_INFO_F("init distributed_lock_service_zookeeper succeed, lock_root = {}", _lock_root);
// Notice: this reference is released in the finalize
add_ref();
return ERR_OK;
diff --git a/src/zookeeper/lock_struct.cpp b/src/zookeeper/lock_struct.cpp
index 8ef4ad52c..bc05acf54 100644
--- a/src/zookeeper/lock_struct.cpp
+++ b/src/zookeeper/lock_struct.cpp
@@ -137,7 +137,7 @@ void lock_struct::remove_lock()
void lock_struct::on_operation_timeout()
{
- LOG_INFO("zookeeper operation times out, removing the current watching");
+ LOG_INFO_F("zookeeper operation times out, removing the current watching");
_state = lock_state::uninitialized;
_dist_lock_service->session()->detach(this);
_lock_callback->enqueue_with(ERR_TIMEOUT, _owner._node_value, _owner._sequence_id);
@@ -239,13 +239,13 @@ void lock_struct::after_remove_duplicated_locknode(lock_struct_ptr _this,
// 2. the node_delete_watcher is notified
// 3. check the children and found myself get the lock
// 4. requst in 1 resonsed
- LOG_INFO("the state is locked mainly because owner changed watcher is triggered first");
+ LOG_INFO_F("the state is locked mainly because owner changed watcher is triggered first");
}
if (ZOK == ec || ZNONODE == ec) {
- LOG_INFO("lock(%s) remove duplicated node(%s), rely on delete watcher to be actived",
- _this->_lock_id.c_str(),
- path->c_str());
+ LOG_INFO_F("lock({}) remove duplicated node({}), rely on delete watcher to be actived",
+ _this->_lock_id,
+ *path);
} else {
LOG_ERROR("lock struct(%s), myself(%s) got session expire",
_this->_lock_dir.c_str(),
@@ -302,13 +302,13 @@ void lock_struct::after_get_lock_owner(lock_struct_ptr _this,
}
if (ZNONODE == ec) {
// lock owner removed
- LOG_INFO("the lock(%s) old owner(%s:%s) has removed, myself(%s:%s) try to get the lock for "
- "another turn",
- _this->_lock_id.c_str(),
- _this->_owner._node_seq_name.c_str(),
- _this->_owner._node_value.c_str(),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("the lock({}) old owner({}:{}) has removed, myself({}:{}) try to get the lock "
+ "for another turn",
+ _this->_lock_id,
+ _this->_owner._node_seq_name,
+ _this->_owner._node_value,
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
_this->_owner._sequence_id = -1;
_this->_owner._node_seq_name.clear();
_this->get_lockdir_nodes();
@@ -322,12 +322,12 @@ void lock_struct::after_get_lock_owner(lock_struct_ptr _this,
else {
_this->_dist_lock_service->refresh_lock_cache(
_this->_lock_id, _this->_owner._node_value, _this->_owner._sequence_id);
- LOG_INFO("wait the lock(%s) owner(%s:%s) to remove, myself(%s:%s)",
- _this->_lock_id.c_str(),
- _this->_owner._node_seq_name.c_str(),
- _this->_owner._node_value.c_str(),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("wait the lock({}) owner({}:{}) to remove, myself({}:{})",
+ _this->_lock_id,
+ _this->_owner._node_seq_name,
+ _this->_owner._node_value,
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
}
} else {
LOG_ERROR("lock_dir(%s), myself(%s), sessin expired",
@@ -353,18 +353,18 @@ void lock_struct::after_self_check(lock_struct_ptr _this,
__check_code(_this->_state, allow_state, 3, string_state(_this->_state));
if (_this->_state == lock_state::unlocking || _this->_state == lock_state::expired) {
- LOG_INFO("skip lock(%s) owner self check, do nothing, myself(%s:%s)",
- _this->_lock_id.c_str(),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("skip lock({}) owner self check, do nothing, myself({}:{})",
+ _this->_lock_id,
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
return;
}
if (ZNONODE == ec || ZINVALIDSTATE == ec) {
- LOG_INFO("lock(%s) session expired, error reason(%s), myself(%s:%s)",
- _this->_lock_id.c_str(),
- zerror(ec),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("lock({}) session expired, error reason({}), myself({}:{})",
+ _this->_lock_id,
+ zerror(ec),
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
_this->on_expire();
return;
}
@@ -380,8 +380,8 @@ void lock_struct::get_lock_owner(bool watch_myself)
{
lock_struct_ptr _this = this;
auto watcher_callback_wrapper = [_this, watch_myself](int event) {
- LOG_INFO("get watcher callback, event type(%s)",
- zookeeper_session::string_zoo_event(event));
+ LOG_INFO_F("get watcher callback, event type({})",
+ zookeeper_session::string_zoo_event(event));
if (watch_myself)
__execute(std::bind(&lock_struct::my_lock_removed, _this, event), _this);
else
@@ -469,7 +469,7 @@ void lock_struct::after_get_lockdir_nodes(lock_struct_ptr _this,
my_pos = i;
}
- LOG_INFO("min sequece number(%lld) in lockdir(%s)", min_seq, _this->_lock_dir.c_str());
+ LOG_INFO_F("min sequece number({}) in lockdir({})", min_seq, _this->_lock_dir);
if (my_pos == -1) {
// znode removed on zookeeper, may timeout or removed by other procedure
LOG_WARNING(
@@ -498,10 +498,10 @@ void lock_struct::after_get_lockdir_nodes(lock_struct_ptr _this,
_this->_lock_id, _this->_owner._node_value, _this->_owner._sequence_id);
watch_myself = true;
- LOG_INFO("got the lock(%s), myself(%s:%s)",
- _this->_lock_id.c_str(),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("got the lock({}), myself({}:{})",
+ _this->_lock_id,
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
_this->_lock_callback->enqueue_with(
ERR_OK, _this->_myself._node_value, _this->_myself._sequence_id);
}
@@ -558,7 +558,9 @@ void lock_struct::after_create_locknode(lock_struct_ptr _this,
LOG_DEBUG_F("after create seq and ephe node, error({}), path({})", zerror(ec), *path);
if (_this->_state == lock_state::cancelled || _this->_state == lock_state::expired) {
- LOG_INFO("current state(%s), ignore event create lockdir(%s)", _this->_lock_dir.c_str());
+ LOG_INFO_F("current state({}), ignore event create lockdir({})",
+ string_state(_this->_state),
+ _this->_lock_dir);
if (ZOK == ec && _this->_state == lock_state::cancelled) {
_this->remove_my_locknode(std::move(*path), IGNORE_CALLBACK, REMOVE_FOR_CANCEL);
}
@@ -576,9 +578,9 @@ void lock_struct::after_create_locknode(lock_struct_ptr _this,
_this->_myself._node_seq_name = utils::get_last_component(*path, splitter);
_this->_myself._sequence_id = parse_seq_path(_this->_myself._node_seq_name);
CHECK_NE_MSG(_this->_myself._sequence_id, -1, "invalid seq path created");
- LOG_INFO("create seq/ephe node in dir(%s) ok, my_sequence_id(%d)",
- _this->_lock_dir.c_str(),
- _this->_myself._sequence_id);
+ LOG_INFO_F("create seq/ephe node in dir({}) ok, my_sequence_id({})",
+ _this->_lock_dir,
+ _this->_myself._sequence_id);
_this->get_lockdir_nodes();
}
@@ -624,9 +626,9 @@ void lock_struct::after_create_lockdir(lock_struct_ptr _this, int ec)
__check_code(_this->_state, allow_state, 3, string_state(_this->_state));
if (_this->_state == lock_state::cancelled || _this->_state == lock_state::expired) {
- LOG_INFO("current state(%s), ignore event create lockdir(%s)",
- string_state(_this->_state),
- _this->_lock_dir.c_str());
+ LOG_INFO_F("current state({}), ignore event create lockdir({})",
+ string_state(_this->_state),
+ _this->_lock_dir);
return;
}
if (ZINVALIDSTATE == ec) {
@@ -691,12 +693,12 @@ void lock_struct::after_remove_my_locknode(lock_struct_ptr _this, int ec, bool r
error_code dsn_ec;
if (lock_state::expired == _this->_state) {
- LOG_INFO("during unlock/cancel lock(%s), encountered expire, owner(%s:%s), myself(%s:%s)",
- _this->_lock_id.c_str(),
- _this->_owner._node_seq_name.c_str(),
- _this->_owner._node_value.c_str(),
- _this->_myself._node_seq_name.c_str(),
- _this->_myself._node_value.c_str());
+ LOG_INFO_F("during unlock/cancel lock({}), encountered expire, owner({}:{}), myself({}:{})",
+ _this->_lock_id,
+ _this->_owner._node_seq_name,
+ _this->_owner._node_value,
+ _this->_myself._node_seq_name,
+ _this->_myself._node_value);
dsn_ec = ERR_INVALID_STATE;
} else {
if (ZINVALIDSTATE == ec) {
@@ -727,22 +729,22 @@ void lock_struct::remove_my_locknode(std::string &&znode_path,
bool remove_for_unlock)
{
lock_struct_ptr _this = this;
- auto result_wrapper = [_this, ignore_callback, remove_for_unlock](
- zookeeper_session::zoo_opcontext *op) {
- LOG_INFO("delete node %s, result(%s)", op->_input._path.c_str(), zerror(op->_output.error));
- if (is_zookeeper_timeout(op->_output.error)) {
- __add_ref_and_delay_call(op, _this);
- return;
- }
+ auto result_wrapper =
+ [_this, ignore_callback, remove_for_unlock](zookeeper_session::zoo_opcontext *op) {
+ LOG_INFO_F("delete node {}, result({})", op->_input._path, zerror(op->_output.error));
+ if (is_zookeeper_timeout(op->_output.error)) {
+ __add_ref_and_delay_call(op, _this);
+ return;
+ }
- if (IGNORE_CALLBACK != ignore_callback) {
- __execute(std::bind(&lock_struct::after_remove_my_locknode,
- _this,
- op->_output.error,
- remove_for_unlock),
- _this);
- }
- };
+ if (IGNORE_CALLBACK != ignore_callback) {
+ __execute(std::bind(&lock_struct::after_remove_my_locknode,
+ _this,
+ op->_output.error,
+ remove_for_unlock),
+ _this);
+ }
+ };
zookeeper_session::zoo_opcontext *op = zookeeper_session::create_context();
op->_optype = zookeeper_session::ZOO_DELETE;
op->_input._path = std::move(znode_path);
@@ -779,11 +781,11 @@ void lock_struct::unlock(lock_struct_ptr _this, error_code_future_ptr unlock_cal
{
_this->_checker.only_one_thread_access();
if (_this->_state != lock_state::locked && _this->_state != lock_state::unlocking) {
- LOG_INFO("lock(%s) myself(%s) seqid(%lld) state(%s), just return",
- _this->_lock_id.c_str(),
- _this->_myself._node_value.c_str(),
- _this->_owner._sequence_id,
- string_state(_this->_state));
+ LOG_INFO_F("lock({}) myself({}) seqid({}) state({}), just return",
+ _this->_lock_id,
+ _this->_myself._node_value,
+ _this->_owner._sequence_id,
+ string_state(_this->_state));
unlock_callback->enqueue_with(ERR_INVALID_PARAMETERS);
return;
}
diff --git a/src/zookeeper/test/distributed_lock_zookeeper.cpp b/src/zookeeper/test/distributed_lock_zookeeper.cpp
index 338a9c4d7..1e85ee904 100644
--- a/src/zookeeper/test/distributed_lock_zookeeper.cpp
+++ b/src/zookeeper/test/distributed_lock_zookeeper.cpp
@@ -68,9 +68,9 @@ public:
error_code start(const std::vector<std::string> &args)
{
- LOG_INFO("name: %s, argc=%u", info().full_name.c_str(), args.size());
+ LOG_INFO_F("name: {}, argc={}", info().full_name, args.size());
for (const std::string &s : args)
- LOG_INFO("argv: %s", s.c_str());
+ LOG_INFO_F("argv: {}", s);
while (!ss_start)
std::this_thread::sleep_for(std::chrono::seconds(1));
@@ -87,10 +87,8 @@ public:
[this](error_code ec, const std::string &name, int version) {
EXPECT_TRUE(ERR_OK == ec);
EXPECT_TRUE(name == this->info().full_name);
- LOG_INFO("lock: error_code: %s, name: %s, lock version: %d",
- ec.to_string(),
- name.c_str(),
- version);
+ LOG_INFO_F(
+ "lock: error_code: {}, name: {}, lock version: {}", ec, name, version);
},
DLOCK_CALLBACK,
[](error_code, const std::string &, int) { CHECK(false, "session expired"); },
@@ -106,7 +104,7 @@ public:
task_ptr unlock_task = _dlock_service->unlock(
"test_lock", info().full_name, true, DLOCK_CALLBACK, [](error_code ec) {
EXPECT_TRUE(ERR_OK == ec);
- LOG_INFO("unlock, error code: %s", ec.to_string());
+ LOG_INFO_F("unlock, error code: {}", ec);
});
unlock_task->wait();
task_pair.second->cancel(false);
@@ -145,7 +143,7 @@ TEST(distributed_lock_service_zookeeper, simple_lock_unlock)
while (!ss_finish)
std::this_thread::sleep_for(std::chrono::seconds(1));
- LOG_INFO("actual result: %lld, expect_result:%lld", result, expect_reuslt);
+ LOG_INFO_F("actual result: {}, expect_result: {}", result, expect_reuslt);
EXPECT_TRUE(result == expect_reuslt);
}
diff --git a/src/zookeeper/zookeeper_session.cpp b/src/zookeeper/zookeeper_session.cpp
index a83d63998..2c856d868 100644
--- a/src/zookeeper/zookeeper_session.cpp
+++ b/src/zookeeper/zookeeper_session.cpp
@@ -317,10 +317,10 @@ void zookeeper_session::global_watcher(
{
zookeeper_session *zoo_session = (zookeeper_session *)ctx;
zoo_session->init_non_dsn_thread();
- LOG_INFO(
- "global watcher, type(%s), state(%s)", string_zoo_event(type), string_zoo_state(state));
+ LOG_INFO_F(
+ "global watcher, type({}), state({})", string_zoo_event(type), string_zoo_state(state));
if (type != ZOO_SESSION_EVENT && path != nullptr)
- LOG_INFO("watcher path: %s", path);
+ LOG_INFO_F("watcher path: {}", path);
CHECK(zoo_session->_handle == handle, "");
zoo_session->dispatch_event(type, state, type == ZOO_SESSION_EVENT ? "" : path);
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@pegasus.apache.org
For additional commands, e-mail: commits-help@pegasus.apache.org