From 0117d5f8ff386075b0c4cbec0cbe460fe3cfa680 Mon Sep 17 00:00:00 2001
From: lichao <lichao@aiotlink.com>
Date: 星期四, 06 五月 2021 18:57:25 +0800
Subject: [PATCH] add logging, use boost.log.

---
 src/robust.h          |    3 
 src/shm.h             |    2 
 src/socket.h          |    2 
 box/center.cpp        |   17 +-
 .vscode/settings.json |    4 
 utest/utest.cpp       |   12 +
 src/topic_node.cpp    |   10 
 box/box.cc            |   30 +++-
 log/log.cpp           |  106 +++++++++++++++
 log/log.h             |  112 ++++++++++++++++
 box/center_main.cc    |   18 ++
 log/macro.h           |   15 ++
 utest/api_test.cpp    |    2 
 src/bh_util.h         |    9 -
 src/CMakeLists.txt    |    9 
 box/CMakeLists.txt    |    1 
 utest/CMakeLists.txt  |    1 
 src/bh_api.cpp        |   28 ++++
 18 files changed, 339 insertions(+), 42 deletions(-)

diff --git a/.vscode/settings.json b/.vscode/settings.json
index 4003476..c0b9587 100644
--- a/.vscode/settings.json
+++ b/.vscode/settings.json
@@ -77,7 +77,9 @@
     "cmake.configureOnOpen": false,
     "C_Cpp.default.includePath": [
         "build/proto",
+        "log",
         "src",
         "box"
-    ]
+    ],
+    "terminal.integrated.cwd": "utest"
 }
\ No newline at end of file
diff --git a/box/CMakeLists.txt b/box/CMakeLists.txt
index 9d9137d..a8aa868 100644
--- a/box/CMakeLists.txt
+++ b/box/CMakeLists.txt
@@ -6,6 +6,7 @@
 set(BinTarget ${Target}-bin)
 
 include_directories(../src)
+include_directories(../log)
 add_library(${Target} ${lib_sources})
 add_executable(${BinTarget} ${exe_sources})
 
diff --git a/box/box.cc b/box/box.cc
index dab1c42..f83f2fd 100644
--- a/box/box.cc
+++ b/box/box.cc
@@ -76,13 +76,24 @@
 }
 
 const std::string kOrigName("bhshmqbox");
+
+inline void PrintLn() { putchar('\n'); }
+
+template <class... Params>
+void PrintLn(const char *fmt, Params &&...t)
+{
+	printf(fmt, std::forward<decltype(t)>(t)...);
+	PrintLn();
+}
+
 void Help()
 {
-	printf("%s : bhome shared memory message queue box application.\n", kOrigName.c_str());
-	printf("usage:\n");
-	printf("\t1) %s [function [options]...]\n", kOrigName.c_str());
-	printf("\t2) rename or link %s to a function name then run it directly.\n", kOrigName.c_str());
-	printf("\nsupported functions:\n");
+	PrintLn("%s : bhome shared memory message queue box application.", kOrigName.c_str());
+	PrintLn("usage:");
+	PrintLn("\t1) %s [function [options]...]", kOrigName.c_str());
+	PrintLn("\t2) rename or link %s to a function name then run it directly.", kOrigName.c_str());
+	PrintLn();
+	PrintLn("supported functions:");
 	std::map<std::string, std::string> funcs;
 	auto getInfo = [&](const std::string &name, const std::string &desc) {
 		funcs[name] = desc;
@@ -92,9 +103,10 @@
 	int max_len = std::max_element(funcs.begin(), funcs.end(), cmp_name_len)->first.size();
 	for (auto &kv : funcs) {
 		int npad = max_len - kv.first.size();
-		printf("\n\t%s%s : %s\n", kv.first.c_str(), std::string(npad, ' ').c_str(), kv.second.c_str());
+		PrintLn();
+		PrintLn("\t%s%s : %s", kv.first.c_str(), std::string(npad, ' ').c_str(), kv.second.c_str());
 	}
-	printf("\n");
+	PrintLn();
 }
 
 int BoxMain(int argc, const char *argv[])
@@ -106,7 +118,7 @@
 	if (BoxFind(name, func)) {
 		return func(argc, argv);
 	} else {
-		printf("%s : function not found!\n", name.c_str());
+		PrintLn("%s : function not found!", name.c_str());
 		// Help();
 	}
 	return 0;
@@ -119,7 +131,7 @@
 
 	fs::path exe(argv[0]);
 	auto name = exe.filename().string();
-	// printf("name: %s\n", name.c_str());
+	// PrintLn("name: %s", name.c_str());
 
 	if (name == kOrigName) {
 		if (argc > 1) {
diff --git a/box/center.cpp b/box/center.cpp
index aa6f285..c57d34d 100644
--- a/box/center.cpp
+++ b/box/center.cpp
@@ -18,6 +18,7 @@
 #include "center.h"
 #include "bh_util.h"
 #include "defs.h"
+#include "log.h"
 #include "shm.h"
 #include <chrono>
 #include <set>
@@ -60,9 +61,7 @@
 		void UpdateState(const int64_t now, const int64_t offline_time, const int64_t kill_time)
 		{
 			auto diff = now - timestamp_;
-#ifndef NDEBUG
-			printf("state %p diff: %ld\n", this, diff);
-#endif
+			LOG_DEBUG() << "state " << this << " diff: " << diff;
 			if (diff < offline_time) {
 				flag_ = kStateNormal;
 			} else if (diff < kill_time) {
@@ -117,7 +116,7 @@
 		Node node(new NodeInfo);
 		UpdateRegInfo(node);
 		nodes_[ssn] = node;
-		printf("new node ssn (%ld) init\n", ssn);
+		LOG_INFO() << "new node ssn (" << ssn << ") init";
 	}
 	MsgCommonReply Register(const BHMsgHead &head, MsgRegister &msg)
 	{
@@ -148,14 +147,14 @@
 				UpdateRegInfo(node);
 				nodes_[ssn] = node;
 			}
-			printf("node (%s) ssn (%ld)\n", head.proc_id().c_str(), ssn);
+			LOG_DEBUG() << "node (" << head.proc_id() << ") ssn (" << ssn << ")";
 
 			auto old = online_node_addr_map_.find(head.proc_id());
 			if (old != online_node_addr_map_.end()) { // old session
 				auto &old_ssn = old->second;
 				if (old_ssn != ssn) {
 					nodes_[old_ssn]->state_.PutOffline(offline_time_);
-					printf("put node (%s) ssn (%ld) offline\n", nodes_[old_ssn]->proc_.proc_id().c_str(), old->second);
+					LOG_DEBUG() << "put node (" << nodes_[old_ssn]->proc_.proc_id() << ") ssn (" << old->second << ") offline";
 					old_ssn = ssn;
 				}
 			} else {
@@ -218,9 +217,9 @@
 			    for (auto &topic : topics) {
 				    service_map_[topic].insert(dest);
 			    }
-			    printf("node %s ssn %ld serve %d topics:\n", node->proc_.proc_id().c_str(), *node->addrs_.begin(), topics.size());
+			    LOG_DEBUG() << "node " << node->proc_.proc_id() << " ssn " << *node->addrs_.begin() << " serve " << topics.size() << " topics:\n";
 			    for (auto &topic : topics) {
-				    printf("\t %s\n", topic.c_str());
+				    LOG_DEBUG() << "\t" << topic;
 			    }
 			    return MakeReply(eSuccess);
 		    });
@@ -572,7 +571,7 @@
 	auto gc = [&](const MQId id) {
 		auto r = ShmSocket::Remove(shm, id);
 		if (r) {
-			printf("remove mq %ld ok\n", id);
+			LOG_DEBUG() << "remove mq " << id << " ok\n";
 		}
 	};
 
diff --git a/box/center_main.cc b/box/center_main.cc
index 79210fc..a8d5b75 100644
--- a/box/center_main.cc
+++ b/box/center_main.cc
@@ -19,6 +19,7 @@
 #include "box.h"
 #include "center.h"
 #include "defs.h"
+#include "log.h"
 #include "signalhandle.h"
 #include <boost/interprocess/sync/named_mutex.hpp>
 #include <chrono>
@@ -50,7 +51,7 @@
 		if (mtx && time_stamp) {
 			Guard lock(*mtx);
 			auto now = NowSec();
-			// printf("old: %ld, now: %ld\n", *time_stamp, now);
+			LOG_DEBUG() << "old: " << *time_stamp << ", now: " << now;
 			if (now > *time_stamp + 10) {
 				*time_stamp = now;
 				auto UpdateTime = [this, time_stamp]() {
@@ -91,12 +92,21 @@
 		return 0;
 	}
 
+	ns_log::AddLog("/tmp/bhshmq_center.log", true, true);
+	auto lvl = args.Get("log", "info");
+	if (strcasecmp(lvl.c_str(), "trace") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::trace); }
+	if (strcasecmp(lvl.c_str(), "debug") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::debug); }
+	if (strcasecmp(lvl.c_str(), "info") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::info); }
+	if (strcasecmp(lvl.c_str(), "warning") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::warning); }
+	if (strcasecmp(lvl.c_str(), "error") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::error); }
+	if (strcasecmp(lvl.c_str(), "fatal") == 0) { ns_log::ResetLogLevel(ns_log::LogLevel::fatal); }
+
 	auto &shm = BHomeShm();
 	GlobalInit(shm);
 
 	InstanceFlag inst(shm, kCenterRunningFlag);
 	if (!inst.TryStartAsFirstInstance()) {
-		printf("another instance is running, exit.\n");
+		LOG_INFO() << "another instance is running, exit.";
 		return 0;
 	}
 
@@ -107,8 +117,10 @@
 	BHCenter center(shm);
 	center.Start();
 
-	printf("center started ...\n");
+	LOG_INFO() << "center started ...";
 	WaitForSignals({SIGINT, SIGTERM});
+	center.Stop();
+	LOG_INFO() << "center stopped.";
 	return 0;
 }
 
diff --git a/log/log.cpp b/log/log.cpp
new file mode 100755
index 0000000..a08c468
--- /dev/null
+++ b/log/log.cpp
@@ -0,0 +1,106 @@
+#include "log.h"
+#include <atomic>
+#include <boost/log/core.hpp>
+#include <boost/log/expressions.hpp>
+#include <boost/log/sinks/text_file_backend.hpp>
+#include <boost/log/sources/record_ostream.hpp>
+#include <boost/log/sources/severity_logger.hpp>
+#include <boost/log/trivial.hpp>
+#include <boost/log/utility/setup/common_attributes.hpp>
+#include <boost/log/utility/setup/console.hpp>
+#include <boost/log/utility/setup/file.hpp>
+#include <execinfo.h>
+
+namespace ns_log
+{
+
+namespace logging = boost::log;
+namespace src = boost::log::sources;
+namespace sinks = boost::log::sinks;
+namespace keywords = boost::log::keywords;
+
+std::string TimeStamp()
+{
+	char buf[64] = {0};
+	timeval tv = {0};
+	gettimeofday(&tv, 0);
+	tm r = {0};
+	localtime_r(&tv.tv_sec, &r);
+	int n = snprintf(buf, sizeof(buf) - 1, "%04d-%02d-%02d %02d:%02d:%02d.%06ld",
+	                 r.tm_year + 1900, r.tm_mon + 1, r.tm_mday,
+	                 r.tm_hour, r.tm_min, r.tm_sec,
+	                 tv.tv_usec);
+	return std::string(buf, buf + n);
+}
+
+void GetTrace()
+{
+	const int ntrace = 256;
+	void *buffer[ntrace];
+	char **strings;
+	int nptrs = backtrace(buffer, ntrace);
+	strings = backtrace_symbols(buffer, nptrs);
+	if (strings) {
+		LOG_DEBUG() << "[[[ call trace begin:";
+		MsgIndent(2);
+		for (int i = 0; i < nptrs; ++i) {
+			LOG_DEBUG() << strings[i];
+		}
+		free(strings);
+		MsgIndent(-2);
+		LOG_DEBUG() << "]]] call trace end.";
+	}
+}
+
+std::string LogPrefix(logging::trivial::severity_level level)
+{
+	return "[" + TimeStamp() + "](" +
+	       //		logging::trivial::to_string(level) +
+	       std::to_string(level) +
+	       ") " + MsgPrefix();
+}
+
+void AddLogRaw(const std::string &file_ptn, bool flush, bool with_console)
+{
+	logging::add_file_log(
+	    keywords::file_name = file_ptn,
+	    keywords::open_mode = std::ios_base::app,
+	    keywords::rotation_size = 1024 * 1024 * 50,
+	    //			keywords::target = "/tmp/bhshmq_logs",
+	    //			keywords::format = "[%TimeStamp%] %Severity% %Message%",
+	    //			keywords::time_based_rotation = sinks::file::rotation_at_time_point(0, 0, 0)
+	    keywords::auto_flush = flush);
+	if (with_console) {
+		logging::add_console_log();
+	}
+	logging::add_common_attributes();
+	logging::core::get()->set_filter(logging::trivial::severity >= GetLogLevel());
+}
+void AddLog(const std::string &file_ptn, bool flush, bool with_console)
+{
+	AddLogRaw(file_ptn, flush, with_console);
+	std::string hint;
+	for (int i = 0; i < 6; ++i) {
+		hint += "(" + std::to_string(i) + ")=" + logging::trivial::to_string(logging::trivial::severity_level(i)) + ", ";
+	}
+	BOOST_LOG_TRIVIAL(fatal) << "[" + TimeStamp() + "]*info* log levels: " << hint;
+}
+
+std::atomic<LogLevel> &CurLogLevel()
+{
+	static std::atomic<LogLevel> cur(logging::trivial::info);
+	return cur;
+}
+
+LogLevel GetLogLevel() { return LogLevel(CurLogLevel().load()); }
+
+LogLevel ResetLogLevel(LogLevel level, bool log_this)
+{
+	if (log_this) {
+		BOOST_LOG_TRIVIAL(fatal) << "[" + TimeStamp() + "]*info* log level reset to " << level;
+	}
+	logging::core::get()->set_filter(logging::trivial::severity >= level);
+	return CurLogLevel().exchange(level);
+}
+
+} // namespace ns_log
diff --git a/log/log.h b/log/log.h
new file mode 100755
index 0000000..7afb208
--- /dev/null
+++ b/log/log.h
@@ -0,0 +1,112 @@
+#ifndef LOG_SPKA2JY7
+#define LOG_SPKA2JY7
+
+#include "macro.h"
+#include <boost/log/trivial.hpp>
+#include <string>
+
+namespace ns_log
+{
+
+void GetTrace();
+typedef boost::log::trivial::severity_level LogLevel;
+inline std::string &MsgPrefix()
+{
+	thread_local std::string prefix;
+	return prefix;
+}
+inline int MsgIndent(int offset)
+{
+	thread_local int indent = 0;
+	indent += offset;
+	if (indent > 0) {
+		MsgPrefix() = std::string(indent, ' ');
+	} else {
+		MsgPrefix().clear();
+	}
+	return indent;
+}
+std::string TimeStamp();
+std::string LogPrefix(LogLevel level);
+void AddLogRaw(const std::string &file_ptn, bool flush = true, bool with_console = false);
+void AddLog(const std::string &file_ptn, bool flush = true, bool with_console = false);
+LogLevel ResetLogLevel(LogLevel level, bool log_this = true);
+LogLevel GetLogLevel();
+
+} // namespace ns_log
+
+#define LOG_WITH_PREFIX(severity) BOOST_LOG_TRIVIAL(severity) << ns_log::LogPrefix(boost::log::trivial::severity)
+
+#define LOG__TRACE() LOG_WITH_PREFIX(trace)
+#define LOG__DEBUG() LOG_WITH_PREFIX(debug)
+#define LOG__INFO() LOG_WITH_PREFIX(info)
+#define LOG__WARNING() LOG_WITH_PREFIX(warning)
+#define LOG__ERROR() LOG_WITH_PREFIX(error)
+#define LOG__FATAL() LOG_WITH_PREFIX(fatal)
+
+#ifndef LOG_TRACE
+#define LOG_TRACE() LOG__TRACE()
+#endif
+
+#ifndef LOG_DEBUG
+#define LOG_DEBUG() LOG__DEBUG()
+#endif
+
+#ifndef LOG_INFO
+#define LOG_INFO() LOG__INFO()
+#endif
+
+#ifndef LOG_WARNING
+#define LOG_WARNING() LOG__WARNING()
+#endif
+
+#ifndef LOG_ERROR
+#define LOG_ERROR() LOG__ERROR()
+#endif
+
+#ifndef LOG_FATAL
+#define LOG_FATAL() LOG__FATAL()
+#endif
+
+#define LOG_POS() LOG__DEBUG() << __FILE__ << " +" << __LINE__ << ": "
+
+// usage:
+// LOG__WARNING() << "warning msg ...";
+// LOG__ERROR() << "error msg ...";
+
+namespace ns_log
+{
+namespace impl
+{
+using namespace boost::log::trivial;
+class FuncLog
+{
+	const char *name_;
+
+public:
+	FuncLog(const char *name) :
+	    name_(name)
+	{
+		LOG__DEBUG() << ">>> " << name_;
+		if (GetLogLevel() <= debug) {
+			MsgIndent(2);
+		}
+	}
+	~FuncLog()
+	{
+		if (GetLogLevel() <= debug) {
+			MsgIndent(-2);
+		}
+		LOG__DEBUG() << "<// " << name_;
+	}
+};
+} // namespace impl
+} // namespace ns_log
+
+#if defined(__GNUG__)
+#define LOG_FUNCTION ns_log::impl::FuncLog JOIN(log_func_, JOIN(__LINE__, _))(__PRETTY_FUNCTION__)
+#else
+#define LOG_FUNCTION ns_log::impl::FuncLog JOIN(log_func_, JOIN(__LINE__, _))(__FUNCTION__)
+#endif
+
+#endif // end of include guard: LOG_SPKA2JY7
diff --git a/log/macro.h b/log/macro.h
new file mode 100755
index 0000000..04fb693
--- /dev/null
+++ b/log/macro.h
@@ -0,0 +1,15 @@
+#ifndef MACRO_LMMKBZRX
+#define MACRO_LMMKBZRX
+
+#define EXPAND(x) x
+#define CALL(M, ...) EXPAND(M(__VA_ARGS__))
+
+// macro helper
+#define JOIN_IMPL(a, b) a##b
+#define JOIN(a, b) JOIN_IMPL(a, b)
+
+// defer function or lambda.
+#define DEFERF(func) ExitCall JOIN(defer_, __LINE__)(func)
+// defer simple expression
+#define DEFER1(expr) DEFERF([&]() { expr; })
+#endif // end of include guard: MACRO_LMMKBZRX
diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt
index eb6a848..3d74846 100644
--- a/src/CMakeLists.txt
+++ b/src/CMakeLists.txt
@@ -1,11 +1,14 @@
 
-file(GLOB sources "./*.cpp")
+file(GLOB sources "./*.cpp" "../log/*.cpp")
 
 set(Target bhome_shmq)
 set(TargetStatic bhome_shmq_static)
 
+include_directories(../log)
 add_library(${Target} SHARED ${sources})
 add_library(${TargetStatic} STATIC ${sources})
 
-target_link_libraries(${Target} bhome_msg pthread rt)
-target_link_libraries(${TargetStatic} bhome_msg_static pthread rt)
+set(LogLibs "boost_log;boost_log_setup;boost_thread;boost_filesystem")
+
+target_link_libraries(${Target} bhome_msg ${LogLibs} pthread rt)
+target_link_libraries(${TargetStatic} bhome_msg_static ${LogLibs} pthread rt)
diff --git a/src/bh_api.cpp b/src/bh_api.cpp
index c29afd9..c9ceb20 100644
--- a/src/bh_api.cpp
+++ b/src/bh_api.cpp
@@ -1,6 +1,7 @@
 #include "bh_api.h"
 #include "defs.h"
 #include "topic_node.h"
+#include <cstdio>
 #include <memory>
 
 using namespace bhome_shm;
@@ -8,9 +9,36 @@
 
 namespace
 {
+std::string GetProcExe()
+{
+	auto f = fopen("/proc/self/stat", "rb");
+	if (f) {
+		DEFER1(fclose(f));
+		char buf[100] = {0};
+		int n = fread(buf, 1, sizeof(buf), f);
+		if (n > 0) {
+			std::string s(buf, n);
+			auto start = s.find('(');
+			if (start != std::string::npos) {
+				++start;
+				auto end = s.find(')', start);
+				return s.substr(start, end - start);
+			}
+		}
+	}
+	return std::to_string(getpid());
+}
 std::unique_ptr<TopicNode> &ProcNodePtr()
 {
 	static bool init = GlobalInit(BHomeShm());
+	auto InitLog = []() {
+		auto id = GetProcExe();
+		char path[200] = {0};
+		sprintf(path, "/tmp/bhshmq_node_%s.log", id.c_str());
+		ns_log::AddLog(path);
+		return true;
+	};
+	static bool init_log = InitLog();
 	static std::unique_ptr<TopicNode> ptr(new TopicNode(BHomeShm()));
 	return ptr;
 }
diff --git a/src/bh_util.h b/src/bh_util.h
index c419a59..a1c0d84 100644
--- a/src/bh_util.h
+++ b/src/bh_util.h
@@ -18,6 +18,7 @@
 #ifndef BH_UTIL_SOXWOK67
 #define BH_UTIL_SOXWOK67
 
+#include "macro.h"
 #include <functional>
 #include <mutex>
 #include <stdint.h>
@@ -167,13 +168,5 @@
 		return ptr() ? false : Bind();
 	}
 };
-
-// macro helper
-#define JOIN_IMPL(a, b) a##b
-#define JOIN(a, b) JOIN_IMPL(a, b)
-// defer function / lambda.
-#define DEFERF(func) ExitCall JOIN(defer_, __LINE__)(func)
-// defer simple expression
-#define DEFER1(expr) DEFERF([&]() { expr; })
 
 #endif /* end of include guard: BH_UTIL_SOXWOK67 */
diff --git a/src/robust.h b/src/robust.h
index aa54c2f..b29fce5 100644
--- a/src/robust.h
+++ b/src/robust.h
@@ -19,6 +19,7 @@
 #ifndef ROBUST_Q31RCWYU
 #define ROBUST_Q31RCWYU
 
+#include "log.h"
 #include <atomic>
 #include <chrono>
 #include <memory>
@@ -171,7 +172,7 @@
 		} else if (!is_alive(Locker(old))) {
 			r = static_cast<int>(MetaCas(old, Meta(1, this_locker()))) << 1;
 			if (r) {
-				printf("captured locker %ld -> %ld, locker = %d\n", int64_t(Locker(old)), int64_t(this_locker()), r);
+				LOG_DEBUG() << "captured locker " << int64_t(Locker(old)) << " -> " << int64_t(this_locker()) << ", locker = " << r;
 			}
 		}
 		return r;
diff --git a/src/shm.h b/src/shm.h
index cb487df..b168413 100644
--- a/src/shm.h
+++ b/src/shm.h
@@ -68,7 +68,7 @@
 			if (Killed(old)) {
 				r = PidCas(old, pid());
 				if (r) {
-					printf("PidCheck captured pid %d -> %d\n", old, pid());
+					LOG_DEBUG() << "PidCheck captured pid " << old << " -> " << pid();
 				}
 			}
 		}
diff --git a/src/socket.h b/src/socket.h
index bd85fec..08a4b0a 100644
--- a/src/socket.h
+++ b/src/socket.h
@@ -114,7 +114,7 @@
 			std::unique_lock<std::mutex> lk(st->mutex);
 			bool sendok = Send(remote, head, body, std::move(OnRecv));
 			if (!sendok) {
-				printf("send timeout\n");
+				LOG_DEBUG() << "send timeout";
 			}
 			if (sendok && st->cv.wait_until(lk, endtime) == std::cv_status::no_timeout) {
 				return true;
diff --git a/src/topic_node.cpp b/src/topic_node.cpp
index f629597..c31cfc3 100644
--- a/src/topic_node.cpp
+++ b/src/topic_node.cpp
@@ -44,7 +44,7 @@
 
 TopicNode::~TopicNode()
 {
-	printf("~TopicNode()\n");
+	LOG_DEBUG() << "~TopicNode()";
 	Stop();
 }
 
@@ -59,7 +59,7 @@
 	if (ssn_id_ == 0) {
 		ssn_id_ = ShmMsgQueue::NewId();
 	}
-	printf("Node Init, id %ld \n", ssn_id_);
+	LOG_DEBUG() << "Node Init, id " << ssn_id_;
 	MsgI msg;
 	msg.OffsetRef() = ssn_id_;
 	if (ShmMsgQueue::TrySend(shm(), BHInitAddress(), msg)) {
@@ -95,9 +95,9 @@
 }
 void TopicNode::Stop()
 {
-	printf("Node Stopping\n");
+	LOG_DEBUG() << "Node Stopping";
 	for (auto &p : sockets_) { p->Stop(); }
-	printf("Node Stopped\n");
+	LOG_INFO() << "Node Stopped";
 }
 
 bool TopicNode::Register(ProcInfo &proc, MsgCommonReply &reply_body, const int timeout_ms)
@@ -423,7 +423,7 @@
 
 		BHAddress addr;
 		if (ClientQueryRPCTopic(request.topic(), addr, timeout_ms)) {
-			// printf("node: %ld, topic dest: %ld\n", SockNode().id(), addr.mq_id());
+			LOG_TRACE() << "node: " << SockNode().id() << ", topic dest: " << addr.mq_id();
 			BHMsgHead head(InitMsgHead(GetType(request), proc_id(), ssn()));
 			AddRoute(head, sock.id());
 			head.set_topic(request.topic());
diff --git a/utest/CMakeLists.txt b/utest/CMakeLists.txt
index 4992516..cbe5be7 100644
--- a/utest/CMakeLists.txt
+++ b/utest/CMakeLists.txt
@@ -1,6 +1,7 @@
 
 FILE(GLOB sources "./*.cpp")
 
+include_directories(../log)
 include_directories(../src)
 add_executable(utest ${sources})
 
diff --git a/utest/api_test.cpp b/utest/api_test.cpp
index 38483eb..bd59c7f 100644
--- a/utest/api_test.cpp
+++ b/utest/api_test.cpp
@@ -284,7 +284,7 @@
 	threads.Launch(hb, &run);
 	threads.Launch(showStatus, &run);
 	int ncli = 10;
-	const uint64_t nreq = 1000 * 100;
+	const int64_t nreq = 1000 * 100;
 	for (int i = 0; i < ncli; ++i) {
 		threads.Launch(asyncRequest, nreq);
 	}
diff --git a/utest/utest.cpp b/utest/utest.cpp
index d8dae45..7cb9587 100644
--- a/utest/utest.cpp
+++ b/utest/utest.cpp
@@ -1,5 +1,6 @@
 #include "center.h"
 #include "defs.h"
+#include "log.h"
 #include "util.h"
 #include <atomic>
 #include <condition_variable>
@@ -8,6 +9,17 @@
 #include <thread>
 #include <vector>
 
+namespace
+{
+bool InitLog()
+{
+	ns_log::AddLog("/tmp/bhshmq_test.log", true, true);
+	ns_log::ResetLogLevel(ns_log::LogLevel::debug);
+	return true;
+}
+static bool g_test_init_log = InitLog();
+} // namespace
+
 using namespace bhome_shm;
 using namespace bhome_msg;
 

--
Gitblit v1.8.0