Commit 6b53cac1 authored by gejun's avatar gejun

Make printing socket in logs more readable

parent 8ce32797
...@@ -202,8 +202,7 @@ void InputMessenger::OnNewMessages(Socket* m) { ...@@ -202,8 +202,7 @@ void InputMessenger::OnNewMessages(Socket* m) {
// Set `read_eof' flag and proceed to feed EOF into `Protocol' // Set `read_eof' flag and proceed to feed EOF into `Protocol'
// (implied by m->_read_buf.empty), which may produce a new // (implied by m->_read_buf.empty), which may produce a new
// `InputMessageBase' under some protocols such as HTTP // `InputMessageBase' under some protocols such as HTTP
LOG_IF(WARNING, FLAGS_log_connection_close) LOG_IF(WARNING, FLAGS_log_connection_close) << *m << " was closed by remote side";
<< "Remote side of " << *m << " was closed";
read_eof = true; read_eof = true;
} else if (errno != EAGAIN) { } else if (errno != EAGAIN) {
if (errno == EINTR) { if (errno == EINTR) {
......
...@@ -98,7 +98,7 @@ ParseResult ParseStreamingMessage(butil::IOBuf* source, ...@@ -98,7 +98,7 @@ ParseResult ParseStreamingMessage(butil::IOBuf* source,
do { do {
StreamFrameMeta fm; StreamFrameMeta fm;
if (!ParsePbFromIOBuf(&fm, meta_buf)) { if (!ParsePbFromIOBuf(&fm, meta_buf)) {
LOG(WARNING) << "Fail to Parse StreamFrameMeta, socket=" << *socket; LOG(WARNING) << "Fail to Parse StreamFrameMeta from " << *socket;
break; break;
} }
SocketUniquePtr ptr; SocketUniquePtr ptr;
......
...@@ -774,7 +774,7 @@ void Socket::Revive() { ...@@ -774,7 +774,7 @@ void Socket::Revive() {
if (_user) { if (_user) {
_user->AfterRevived(this); _user->AfterRevived(this);
} else { } else {
LOG(INFO) << "Revived socket=" << *this; LOG(INFO) << "Revived " << *this;
} }
return; return;
} }
...@@ -979,7 +979,7 @@ bool HealthCheckTask::OnTriggeringTask(timespec* next_abstime) { ...@@ -979,7 +979,7 @@ bool HealthCheckTask::OnTriggeringTask(timespec* next_abstime) {
if (_first_time) { // Only check at first time. if (_first_time) { // Only check at first time.
_first_time = false; _first_time = false;
if (ptr->WaitAndReset(2/*note*/) != 0) { if (ptr->WaitAndReset(2/*note*/) != 0) {
LOG(INFO) << "Cancel checking socket=" << *ptr; LOG(INFO) << "Cancel checking " << *ptr;
return false; return false;
} }
} }
...@@ -999,7 +999,7 @@ bool HealthCheckTask::OnTriggeringTask(timespec* next_abstime) { ...@@ -999,7 +999,7 @@ bool HealthCheckTask::OnTriggeringTask(timespec* next_abstime) {
ptr->_hc_count = 0; ptr->_hc_count = 0;
return false; return false;
} else if (hc == ESTOP) { } else if (hc == ESTOP) {
LOG(INFO) << "Cancel checking socket=" << *ptr; LOG(INFO) << "Cancel checking " << *ptr;
return false; return false;
} }
++ ptr->_hc_count; ++ ptr->_hc_count;
...@@ -1396,7 +1396,7 @@ void Socket::AfterAppConnected(int err, void* data) { ...@@ -1396,7 +1396,7 @@ void Socket::AfterAppConnected(int err, void* data) {
} }
} }
s->SetFailed(err, "Fail to connect socket=%s: %s", s->SetFailed(err, "Fail to connect %s: %s",
s->description().c_str(), berror(err)); s->description().c_str(), berror(err));
s->ReleaseAllFailedWriteRequests(req); s->ReleaseAllFailedWriteRequests(req);
} }
...@@ -1589,7 +1589,7 @@ int Socket::StartWrite(WriteRequest* req, const WriteOptions& opt) { ...@@ -1589,7 +1589,7 @@ int Socket::StartWrite(WriteRequest* req, const WriteOptions& opt) {
int ret = ConnectIfNot(opt.abstime, req); int ret = ConnectIfNot(opt.abstime, req);
if (ret < 0) { if (ret < 0) {
saved_errno = errno; saved_errno = errno;
SetFailed(errno, "Fail to connect socket=%s directly: %m", description().c_str()); SetFailed(errno, "Fail to connect %s directly: %m", description().c_str());
goto FAIL_TO_WRITE; goto FAIL_TO_WRITE;
} else if (ret == 1) { } else if (ret == 1) {
// We are doing connection. Callback `KeepWriteIfConnected' // We are doing connection. Callback `KeepWriteIfConnected'
...@@ -1621,8 +1621,8 @@ int Socket::StartWrite(WriteRequest* req, const WriteOptions& opt) { ...@@ -1621,8 +1621,8 @@ int Socket::StartWrite(WriteRequest* req, const WriteOptions& opt) {
if (errno != EAGAIN && errno != EOVERCROWDED) { if (errno != EAGAIN && errno != EOVERCROWDED) {
saved_errno = errno; saved_errno = errno;
// EPIPE is common in pooled connections + backup requests. // EPIPE is common in pooled connections + backup requests.
PLOG_IF(WARNING, errno != EPIPE) << "Fail to write into socket=" << *this; PLOG_IF(WARNING, errno != EPIPE) << "Fail to write into " << *this;
SetFailed(saved_errno, "Fail to write into socket=%s: %s", SetFailed(saved_errno, "Fail to write into %s: %s",
description().c_str(), berror(saved_errno)); description().c_str(), berror(saved_errno));
goto FAIL_TO_WRITE; goto FAIL_TO_WRITE;
} }
...@@ -1675,8 +1675,8 @@ void* Socket::KeepWrite(void* void_arg) { ...@@ -1675,8 +1675,8 @@ void* Socket::KeepWrite(void* void_arg) {
if (nw < 0) { if (nw < 0) {
if (errno != EAGAIN && errno != EOVERCROWDED) { if (errno != EAGAIN && errno != EOVERCROWDED) {
const int saved_errno = errno; const int saved_errno = errno;
PLOG(WARNING) << "Fail to keep-write into socket=" << *s; PLOG(WARNING) << "Fail to keep-write into " << *s;
s->SetFailed(saved_errno, "Fail to keep-write into socket=%s: %s", s->SetFailed(saved_errno, "Fail to keep-write into %s: %s",
s->description().c_str(), berror(saved_errno)); s->description().c_str(), berror(saved_errno));
break; break;
} }
...@@ -1707,8 +1707,8 @@ void* Socket::KeepWrite(void* void_arg) { ...@@ -1707,8 +1707,8 @@ void* Socket::KeepWrite(void* void_arg) {
const int rc = s->WaitEpollOut(s->fd(), pollin, &duetime); const int rc = s->WaitEpollOut(s->fd(), pollin, &duetime);
if (rc < 0 && errno != ETIMEDOUT) { if (rc < 0 && errno != ETIMEDOUT) {
const int saved_errno = errno; const int saved_errno = errno;
PLOG(WARNING) << "Fail to wait epollout of socket=" << *s; PLOG(WARNING) << "Fail to wait epollout of " << *s;
s->SetFailed(saved_errno, "Fail to wait epollout of socket=%s: %s", s->SetFailed(saved_errno, "Fail to wait epollout of %s: %s",
s->description().c_str(), berror(saved_errno)); s->description().c_str(), berror(saved_errno));
break; break;
} }
...@@ -1967,7 +1967,7 @@ void Socket::SetAuthentication(int error_code) { ...@@ -1967,7 +1967,7 @@ void Socket::SetAuthentication(int error_code) {
butil::memory_order_relaxed)) { butil::memory_order_relaxed)) {
// As expected // As expected
if (error_code != 0) { if (error_code != 0) {
SetFailed(error_code, "Fail to authenticate socket=%s", description().c_str()); SetFailed(error_code, "Fail to authenticate %s", description().c_str());
} }
CHECK_EQ(0, bthread_id_unlock_and_destroy(_auth_id)); CHECK_EQ(0, bthread_id_unlock_and_destroy(_auth_id));
} }
...@@ -2262,7 +2262,7 @@ void Socket::DebugSocket(std::ostream& os, SocketId id) { ...@@ -2262,7 +2262,7 @@ void Socket::DebugSocket(std::ostream& os, SocketId id) {
int Socket::CheckHealth() { int Socket::CheckHealth() {
if (_hc_count == 0) { if (_hc_count == 0) {
LOG(INFO) << "Checking socket=" << *this; LOG(INFO) << "Checking " << *this;
} }
// Note: No timeout. Timeout setting is given to Write() which // Note: No timeout. Timeout setting is given to Write() which
// we don't know. A drawback is that if a connection takes long // we don't know. A drawback is that if a connection takes long
...@@ -2324,7 +2324,7 @@ int SocketUser::CheckHealth(Socket* ptr) { ...@@ -2324,7 +2324,7 @@ int SocketUser::CheckHealth(Socket* ptr) {
} }
void SocketUser::AfterRevived(Socket* ptr) { void SocketUser::AfterRevived(Socket* ptr) {
LOG(INFO) << "Revived socket=" << *ptr; LOG(INFO) << "Revived " << *ptr;
} }
////////// SocketPool ////////////// ////////// SocketPool //////////////
...@@ -2498,7 +2498,7 @@ int Socket::GetPooledSocket(SocketUniquePtr* pooled_socket) { ...@@ -2498,7 +2498,7 @@ int Socket::GetPooledSocket(SocketUniquePtr* pooled_socket) {
(*pooled_socket)->ShareStats(this); (*pooled_socket)->ShareStats(this);
CHECK((*pooled_socket)->parsing_context() == NULL) CHECK((*pooled_socket)->parsing_context() == NULL)
<< "context=" << (*pooled_socket)->parsing_context() << "context=" << (*pooled_socket)->parsing_context()
<< " is not NULL when socket={" << *(*pooled_socket) << "} is got from" << " is not NULL when " << *(*pooled_socket) << " is got from"
" SocketPool, the protocol implementation is buggy"; " SocketPool, the protocol implementation is buggy";
return 0; return 0;
} }
...@@ -2518,7 +2518,7 @@ int Socket::ReturnToPool() { ...@@ -2518,7 +2518,7 @@ int Socket::ReturnToPool() {
return -1; return -1;
} }
CHECK(parsing_context() == NULL) CHECK(parsing_context() == NULL)
<< "context=" << parsing_context() << " is not released when socket=" << "context=" << parsing_context() << " is not released when "
<< *this << " is returned to SocketPool, the protocol " << *this << " is returned to SocketPool, the protocol "
"implementation is buggy"; "implementation is buggy";
// NOTE: be careful with the sequence. // NOTE: be careful with the sequence.
...@@ -2687,7 +2687,7 @@ std::string Socket::description() const { ...@@ -2687,7 +2687,7 @@ std::string Socket::description() const {
// NOTE: The output should be consistent with operator<<() // NOTE: The output should be consistent with operator<<()
std::string result; std::string result;
result.reserve(64); result.reserve(64);
butil::string_appendf(&result, "{id=%" PRIu64, id()); butil::string_appendf(&result, "Socket{id=%" PRIu64, id());
const int saved_fd = fd(); const int saved_fd = fd();
if (saved_fd >= 0) { if (saved_fd >= 0) {
butil::string_appendf(&result, " fd=%d", saved_fd); butil::string_appendf(&result, " fd=%d", saved_fd);
...@@ -2718,7 +2718,7 @@ SocketSSLContext::~SocketSSLContext() { ...@@ -2718,7 +2718,7 @@ SocketSSLContext::~SocketSSLContext() {
namespace std { namespace std {
ostream& operator<<(ostream& os, const brpc::Socket& sock) { ostream& operator<<(ostream& os, const brpc::Socket& sock) {
// NOTE: The output should be consistent with Socket::description() // NOTE: The output should be consistent with Socket::description()
os << "{id=" << sock.id(); os << "Socket{id=" << sock.id();
const int fd = sock.fd(); const int fd = sock.fd();
if (fd >= 0) { if (fd >= 0) {
os << " fd=" << fd; os << " fd=" << fd;
......
...@@ -358,7 +358,7 @@ TEST_F(ServerTest, only_allow_protocols_in_enabled_protocols) { ...@@ -358,7 +358,7 @@ TEST_F(ServerTest, only_allow_protocols_in_enabled_protocols) {
test::EchoService_Stub stub(&chan); test::EchoService_Stub stub(&chan);
stub.Echo(&cntl, &req, &res, NULL); stub.Echo(&cntl, &req, &res, NULL);
ASSERT_TRUE(cntl.Failed()); ASSERT_TRUE(cntl.Failed());
ASSERT_TRUE(cntl.ErrorText().find("Got EOF of {id=") != std::string::npos); ASSERT_TRUE(cntl.ErrorText().find("Got EOF of ") != std::string::npos);
ASSERT_EQ(0, server.Stop(0)); ASSERT_EQ(0, server.Stop(0));
ASSERT_EQ(0, server.Join()); ASSERT_EQ(0, server.Join());
......
...@@ -502,7 +502,7 @@ TEST_F(SocketTest, not_health_check_when_nref_hits_0) { ...@@ -502,7 +502,7 @@ TEST_F(SocketTest, not_health_check_when_nref_hits_0) {
ASSERT_EQ(wait_id.value, data.id.value); ASSERT_EQ(wait_id.value, data.id.value);
ASSERT_EQ(ECONNREFUSED, data.error_code); ASSERT_EQ(ECONNREFUSED, data.error_code);
ASSERT_TRUE(butil::StringPiece(data.error_text).starts_with( ASSERT_TRUE(butil::StringPiece(data.error_text).starts_with(
"Fail to connect socket=")); "Fail to connect "));
#else #else
ASSERT_EQ(-1, s->Write(&src)); ASSERT_EQ(-1, s->Write(&src));
ASSERT_EQ(ECONNREFUSED, errno); ASSERT_EQ(ECONNREFUSED, errno);
...@@ -582,7 +582,7 @@ TEST_F(SocketTest, health_check) { ...@@ -582,7 +582,7 @@ TEST_F(SocketTest, health_check) {
ASSERT_EQ(wait_id.value, data.id.value); ASSERT_EQ(wait_id.value, data.id.value);
ASSERT_EQ(ECONNREFUSED, data.error_code); ASSERT_EQ(ECONNREFUSED, data.error_code);
ASSERT_TRUE(butil::StringPiece(data.error_text).starts_with( ASSERT_TRUE(butil::StringPiece(data.error_text).starts_with(
"Fail to connect socket=")); "Fail to connect "));
if (use_my_message) { if (use_my_message) {
ASSERT_TRUE(appended_msg); ASSERT_TRUE(appended_msg);
} }
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment