You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@brpc.apache.org by ja...@apache.org on 2020/11/27 07:34:05 UTC
[incubator-brpc] branch master updated: Replace previous hacky
impl. of appending postfix to ostream with a safer one and lose the
-log_as_json support for glog
This is an automated email from the ASF dual-hosted git repository.
jamesge pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-brpc.git
The following commit(s) were added to refs/heads/master by this push:
new 5f7e048 Replace previous hacky impl. of appending postfix to ostream with a safer one and lose the -log_as_json support for glog
5f7e048 is described below
commit 5f7e0480bae0c2b2c212803072eb330e0eaf9108
Author: jamesge <jg...@gmail.com>
AuthorDate: Fri Nov 27 15:33:45 2020 +0800
Replace previous hacky impl. of appending postfix to ostream with a safer one and lose the -log_as_json support for glog
---
src/brpc/controller.cpp | 45 +++++++---------------
src/brpc/controller.h | 28 ++++++++------
src/butil/logging.cc | 79 ++++++++++++++++-----------------------
test/brpc_controller_unittest.cpp | 26 ++++++++++---
4 files changed, 82 insertions(+), 96 deletions(-)
diff --git a/src/brpc/controller.cpp b/src/brpc/controller.cpp
index f343edb..e88e3e1 100644
--- a/src/brpc/controller.cpp
+++ b/src/brpc/controller.cpp
@@ -1507,7 +1507,7 @@ KVMap& Controller::SessionKV() {
return *_session_kv.get();
}
-#define BRPC_SESSION_END_MSG "Session ends"
+#define BRPC_SESSION_END_MSG "Session ends."
#define BRPC_REQ_ID "@rid"
#define BRPC_KV_SEP ":"
@@ -1522,62 +1522,43 @@ void Controller::FlushSessionKV(std::ostream& os) {
}
if (FLAGS_log_as_json) {
- os << "\"M\":\"" BRPC_SESSION_END_MSG "\"";
if (pRID) {
- os << ",\"" BRPC_REQ_ID "\":\"" << *pRID << '"';
+ os << "\"" BRPC_REQ_ID "\":\"" << *pRID << "\",";
}
+ os << "\"M\":\"" BRPC_SESSION_END_MSG "\"";
for (auto it = _session_kv->Begin(); it != _session_kv->End(); ++it) {
os << ",\"" << it->first << "\":\"" << it->second << '"';
}
} else {
- os << BRPC_SESSION_END_MSG;
if (pRID) {
- os << " " BRPC_REQ_ID BRPC_KV_SEP << *pRID;
+ os << BRPC_REQ_ID BRPC_KV_SEP << *pRID << " ";
}
+ os << BRPC_SESSION_END_MSG;
for (auto it = _session_kv->Begin(); it != _session_kv->End(); ++it) {
os << ' ' << it->first << BRPC_KV_SEP << it->second;
}
}
}
-Controller::LogPostfixDummy::~LogPostfixDummy() {
- if (osptr != nullptr) {
- *osptr << postfix;
- }
-}
-
-std::ostream& operator<<(std::ostream& os, const Controller::LogPostfixDummy& p) {
- const_cast<brpc::Controller::LogPostfixDummy&>(p).osptr = &os;
- if (FLAGS_log_as_json) {
- os << "\"M\":\"";
- }
+std::ostream& operator<<(std::ostream& os, const Controller::LogPrefixDummy& p) {
+ p.DoPrintLogPrefix(os);
return os;
}
-
-
-Controller::LogPostfixDummy Controller::LogPostfix() const {
- Controller::LogPostfixDummy result;
- std::string& p = result.postfix;
- if (FLAGS_log_as_json) {
- p.push_back('"');
- }
+void Controller::DoPrintLogPrefix(std::ostream& os) const {
const std::string* pRID = nullptr;
if (_http_request) {
pRID = _http_request->GetHeader(FLAGS_request_id_header);
if (pRID) {
if (FLAGS_log_as_json) {
- p.append(",\"" BRPC_REQ_ID "\":\"");
- p.append(*pRID);
- p.push_back('"');
+ os << BRPC_REQ_ID "\":\"" << *pRID << "\",";
} else {
- p.reserve(5 + pRID->size());
- p.append(" " BRPC_REQ_ID BRPC_KV_SEP);
- p.append(*pRID);
+ os << BRPC_REQ_ID BRPC_KV_SEP << *pRID << " ";
}
-
}
}
- return result;
+ if (FLAGS_log_as_json) {
+ os << "\"M\":\"";
+ }
}
} // namespace brpc
diff --git a/src/brpc/controller.h b/src/brpc/controller.h
index 8a75c54..b1689cf 100755
--- a/src/brpc/controller.h
+++ b/src/brpc/controller.h
@@ -491,13 +491,15 @@ public:
void FlushSessionKV(std::ostream& os);
// Contextual prefixes for LOGD/LOGI/LOGW/LOGE/LOGF macros
- struct LogPostfixDummy {
- LogPostfixDummy() : osptr(nullptr) {}
- ~LogPostfixDummy();
- std::string postfix;
- std::ostream* osptr;
+ class LogPrefixDummy {
+ public:
+ LogPrefixDummy(const Controller* cntl) : _cntl(cntl) {}
+ void DoPrintLogPrefix(std::ostream& os) const { _cntl->DoPrintLogPrefix(os); }
+ private:
+ const Controller* _cntl;
};
- LogPostfixDummy LogPostfix() const;
+ friend class LogPrefixDummy;
+ LogPrefixDummy LogPrefix() const { return LogPrefixDummy(this); }
// Return true if the remote side creates a stream.
bool has_remote_stream() { return _remote_stream_settings != NULL; }
@@ -677,6 +679,8 @@ private:
std::string& protocol_param() { return _thrift_method_name; }
const std::string& protocol_param() const { return _thrift_method_name; }
+ void DoPrintLogPrefix(std::ostream& os) const;
+
private:
// NOTE: align and group fields to make Controller as compact as possible.
@@ -806,16 +810,16 @@ bool IsAskedToQuit();
// Send Ctrl-C to current process.
void AskToQuit();
-std::ostream& operator<<(std::ostream& os, const Controller::LogPostfixDummy& p);
+std::ostream& operator<<(std::ostream& os, const Controller::LogPrefixDummy& p);
} // namespace brpc
// Print logs appended with @rid which is got from "x-request-id"(set
// -request_id_header to change) in http header by default
-#define LOGD(cntl) LOG(DEBUG) << (cntl)->LogPostfix()
-#define LOGI(cntl) LOG(INFO) << (cntl)->LogPostfix()
-#define LOGW(cntl) LOG(WARNING) << (cntl)->LogPostfix()
-#define LOGE(cntl) LOG(ERROR) << (cntl)->LogPostfix()
-#define LOGF(cntl) LOG(FATAL) << (cntl)->LogPostfix()
+#define LOGD(cntl) LOG(DEBUG) << (cntl)->LogPrefix()
+#define LOGI(cntl) LOG(INFO) << (cntl)->LogPrefix()
+#define LOGW(cntl) LOG(WARNING) << (cntl)->LogPrefix()
+#define LOGE(cntl) LOG(ERROR) << (cntl)->LogPrefix()
+#define LOGF(cntl) LOG(FATAL) << (cntl)->LogPrefix()
#endif // BRPC_CONTROLLER_H
diff --git a/src/butil/logging.cc b/src/butil/logging.cc
index c283ce1..6c04728 100644
--- a/src/butil/logging.cc
+++ b/src/butil/logging.cc
@@ -565,6 +565,33 @@ static void PrintLogPrefixAsJSON(
os << "\"C\":\"" << file << ':' << line << "\"";
}
+static void PrintLog(std::ostream& os,
+ int severity, const char* file, int line,
+ const butil::StringPiece& content) {
+ if (!FLAGS_log_as_json) {
+ PrintLogPrefix(os, severity, file, line);
+ os.write(content.data(), content.size());
+ } else {
+ os << '{';
+ PrintLogPrefixAsJSON(os, severity, file, line);
+ bool pair_quote = false;
+ if (content.empty() || content[0] != '"') {
+ // not a json, add a 'M' field
+ os << ",\"M\":\"";
+ pair_quote = true;
+ } else {
+ os << ',';
+ }
+ os.write(content.data(), content.size());
+ if (pair_quote) {
+ os << '"';
+ } else if (!content.empty() && content[content.size()-1] != '"') {
+ // Controller may write `"M":"...` which misses the last quote
+ os << '"';
+ }
+ os << '}';
+ }
+}
// A log message handler that gets notified of every log message we process.
class DoublyBufferedLogSink : public butil::DoublyBufferedData<LogSink*> {
@@ -669,33 +696,12 @@ void DisplayDebugMessageInDialog(const std::string& str) {
bool StringSink::OnLogMessage(int severity, const char* file, int line,
const butil::StringPiece& content) {
- std::ostringstream prefix_os;
- bool pair_quote = false;
- if (FLAGS_log_as_json) {
- prefix_os << '{';
- PrintLogPrefixAsJSON(prefix_os, severity, file, line);
- if (content.empty() || content[0] != '"') {
- // not a json, add 'M' field
- prefix_os << ",\"M\":\"";
- pair_quote = true;
- } else {
- prefix_os << ',';
- }
- } else {
- PrintLogPrefix(prefix_os, severity, file, line);
- }
- const std::string prefix = prefix_os.str();
+ std::ostringstream os;
+ PrintLog(os, severity, file, line, content);
+ const std::string msg = os.str();
{
butil::AutoLock lock_guard(_lock);
- reserve(size() + prefix.size() + content.size());
- append(prefix);
- append(content.data(), content.size());
- if (FLAGS_log_as_json) {
- if (pair_quote) {
- push_back('"');
- }
- push_back('}');
- }
+ append(msg);
}
return true;
}
@@ -849,27 +855,8 @@ public:
// A LogSink focused on performance should also be able to handle
// non-continuous inputs which is a must to maximize performance.
std::ostringstream os;
- if (!FLAGS_log_as_json) {
- PrintLogPrefix(os, severity, file, line);
- os.write(content.data(), content.size());
- os << '\n';
- } else {
- os << '{';
- PrintLogPrefixAsJSON(os, severity, file, line);
- bool pair_quote = false;
- if (content.empty() || content[0] != '"') {
- // not a json, add a 'M' field
- os << ",\"M\":\"";
- pair_quote = true;
- } else {
- os << ',';
- }
- os.write(content.data(), content.size());
- if (pair_quote) {
- os << '"';
- }
- os << "}\n";
- }
+ PrintLog(os, severity, file, line, content);
+ os << '\n';
std::string log = os.str();
if ((logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
diff --git a/test/brpc_controller_unittest.cpp b/test/brpc_controller_unittest.cpp
index 011928c..9b999b9 100644
--- a/test/brpc_controller_unittest.cpp
+++ b/test/brpc_controller_unittest.cpp
@@ -95,13 +95,27 @@ TEST_F(ControllerTest, SessionKV) {
FLAGS_log_as_json = false;
logging::StringSink sink1;
auto oldSink = logging::SetLogSink(&sink1);
- //brpc::SetGlobalSessionLogFormatter(new MyFormatter);
{
brpc::Controller cntl;
cntl.set_log_id(123); // not working now
- cntl.SessionKV().Set("Apple", 1);
- cntl.SessionKV().Set("Baidu", "22");
- cntl.SessionKV().Set("Cisco", 33.3);
+ // set
+ cntl.SessionKV().Set("Apple", 1234567);
+ cntl.SessionKV().Set("Baidu", "Building");
+ // get
+ auto v1 = cntl.SessionKV().Get("Apple");
+ ASSERT_TRUE(v1);
+ ASSERT_EQ("1234567", *v1);
+ auto v2 = cntl.SessionKV().Get("Baidu");
+ ASSERT_TRUE(v2);
+ ASSERT_EQ("Building", *v2);
+
+ // override
+ cntl.SessionKV().Set("Baidu", "NewStuff");
+ v2 = cntl.SessionKV().Get("Baidu");
+ ASSERT_TRUE(v2);
+ ASSERT_EQ("NewStuff", *v2);
+
+ cntl.SessionKV().Set("Cisco", 33.33);
LOGW(&cntl) << "My WARNING Log";
ASSERT_TRUE(endsWith(sink1, "] My WARNING Log")) << sink1;
@@ -110,13 +124,13 @@ TEST_F(ControllerTest, SessionKV) {
cntl.http_request().SetHeader("x-request-id", "abcdEFG-456");
LOGE(&cntl) << "My ERROR Log";
- ASSERT_TRUE(endsWith(sink1, "] My ERROR Log @rid:abcdEFG-456")) << sink1;
+ ASSERT_TRUE(endsWith(sink1, "] @rid:abcdEFG-456 My ERROR Log")) << sink1;
ASSERT_TRUE(startsWith(sink1, "E")) << sink1;
sink1.clear();
FLAGS_log_as_json = true;
}
- ASSERT_TRUE(endsWith(sink1, R"(,"M":"Session ends","@rid":"abcdEFG-456","Baidu":"22","Cisco":"33.300000","Apple":"1"})")) << sink1;
+ ASSERT_TRUE(endsWith(sink1, R"(,"@rid":"abcdEFG-456","M":"Session ends.","Baidu":"NewStuff","Cisco":"33.330000","Apple":"1234567"})")) << sink1;
ASSERT_TRUE(startsWith(sink1, R"({"L":"I",)")) << sink1;
logging::SetLogSink(oldSink);
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@brpc.apache.org
For additional commands, e-mail: dev-help@brpc.apache.org