From f960db4646a9535bcee6d53740811b84e0678c93 Mon Sep 17 00:00:00 2001 From: Haomai Wang Date: Thu, 7 Jul 2016 14:59:51 +0800 Subject: [PATCH] ceph_test_msgr: use ceph log infrastructure to output because we want to get the right log sequence which mixes ceph logginer and cerr. Otherwise, cerr output make the logs a little disordered. Signed-off-by: Haomai Wang (cherry picked from commit d1268a6aa895ee93cd9fee6fc6c759317e681a85) --- src/test/msgr/test_msgr.cc | 67 ++++++++++++++++++++------------------ 1 file changed, 36 insertions(+), 31 deletions(-) diff --git a/src/test/msgr/test_msgr.cc b/src/test/msgr/test_msgr.cc index 65a6a6fc49911..ecd33420a56a4 100644 --- a/src/test/msgr/test_msgr.cc +++ b/src/test/msgr/test_msgr.cc @@ -37,6 +37,14 @@ typedef boost::mt11213b gen_type; +#include "common/dout.h" +#include "include/assert.h" + +#define dout_subsys ceph_subsys_ms +#undef dout_prefix +#define dout_prefix *_dout << " ceph_test_msgr " + + #if GTEST_HAS_PARAM_TEST #define CHECK_AND_WAIT_TRUE(expr) do { \ @@ -55,7 +63,7 @@ class MessengerTest : public ::testing::TestWithParam { MessengerTest(): server_msgr(NULL), client_msgr(NULL) {} virtual void SetUp() { - cerr << __func__ << " start set up " << GetParam() << std::endl; + lderr(g_ceph_context) << __func__ << " start set up " << GetParam() << dendl; server_msgr = Messenger::create(g_ceph_context, string(GetParam()), entity_name_t::OSD(0), "server", getpid()); client_msgr = Messenger::create(g_ceph_context, string(GetParam()), entity_name_t::CLIENT(-1), "client", getpid()); server_msgr->set_default_policy(Messenger::Policy::stateless_server(0, 0)); @@ -104,12 +112,12 @@ class FakeDispatcher : public Dispatcher { void ms_handle_fast_connect(Connection *con) { lock.Lock(); - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; Session *s = static_cast(con->get_priv()); if (!s) { s = new Session(con); con->set_priv(s->get()); - cerr << __func__ << " con: " << con << " count: " << s->count << std::endl; + lderr(g_ceph_context) << __func__ << " con: " << con << " count: " << s->count << dendl; } s->put(); got_connect = true; @@ -135,7 +143,7 @@ class FakeDispatcher : public Dispatcher { s->put(); Mutex::Locker l1(s->lock); s->count++; - cerr << __func__ << " conn: " << m->get_connection() << " session " << s << " count: " << s->count << std::endl; + lderr(g_ceph_context) << __func__ << " conn: " << m->get_connection() << " session " << s << " count: " << s->count << dendl; if (is_server) { reply_message(m); } @@ -146,7 +154,7 @@ class FakeDispatcher : public Dispatcher { } bool ms_handle_reset(Connection *con) { Mutex::Locker l(lock); - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; Session *s = static_cast(con->get_priv()); if (s) { s->con.reset(NULL); // break con <-> session ref cycle @@ -157,7 +165,7 @@ class FakeDispatcher : public Dispatcher { } void ms_handle_remote_reset(Connection *con) { Mutex::Locker l(lock); - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; Session *s = static_cast(con->get_priv()); if (s) { s->con.reset(NULL); // break con <-> session ref cycle @@ -176,7 +184,7 @@ class FakeDispatcher : public Dispatcher { s->put(); Mutex::Locker l1(s->lock); s->count++; - cerr << __func__ << " conn: " << m->get_connection() << " session " << s << " count: " << s->count << std::endl; + lderr(g_ceph_context) << __func__ << " conn: " << m->get_connection() << " session " << s << " count: " << s->count << dendl; if (is_server) { if (loopback) assert(m->get_source().is_osd()); @@ -792,7 +800,7 @@ class SyntheticDispatcher : public Dispatcher { if (m->get_middle().length()) rm->set_middle(bl); m->get_connection()->send_message(rm); - //cerr << __func__ << " conn=" << m->get_connection() << " reply m=" << m << " i=" << i << std::endl; + lderr(g_ceph_context) << __func__ << " conn=" << m->get_connection() << " reply m=" << m << " i=" << i << dendl; } void send_message_wrap(ConnectionRef con, Message *m) { @@ -830,7 +838,7 @@ class SyntheticDispatcher : public Dispatcher { void print() { for (auto && p : conn_sent) { if (!p.second.empty()) { - cerr << __func__ << " " << p.first << " wait " << p.second.size() << std::endl; + lderr(g_ceph_context) << __func__ << " " << p.first << " wait " << p.second.size() << dendl; } } } @@ -1007,12 +1015,9 @@ class SyntheticWorkload { void print_internal_state(bool detail=false) { Mutex::Locker l(lock); - cerr << "available_connections: " << available_connections.size() - << " inflight messages: " << dispatcher.get_pending() << std::endl; + lderr(g_ceph_context) << "available_connections: " << available_connections.size() + << " inflight messages: " << dispatcher.get_pending() << dendl; if (detail && !available_connections.empty()) { - for (auto &&c : available_connections) - cerr << "available connection: " << c.first << " "; - cerr << std::endl; dispatcher.print(); } } @@ -1063,13 +1068,13 @@ TEST_P(MessengerTest, SyntheticStressTest) { Messenger::Policy::stateful_server(0, 0), Messenger::Policy::lossless_client(0, 0)); for (int i = 0; i < 100; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 5000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1092,13 +1097,13 @@ TEST_P(MessengerTest, SyntheticStressTest1) { Messenger::Policy::lossless_peer_reuse(0, 0), Messenger::Policy::lossless_peer_reuse(0, 0)); for (int i = 0; i < 10; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 10000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1124,13 +1129,13 @@ TEST_P(MessengerTest, SyntheticInjectTest) { Messenger::Policy::stateful_server(0, 0), Messenger::Policy::lossless_client(0, 0)); for (int i = 0; i < 100; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 1000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1157,13 +1162,13 @@ TEST_P(MessengerTest, SyntheticInjectTest2) { Messenger::Policy::lossless_peer_reuse(0, 0), Messenger::Policy::lossless_peer_reuse(0, 0)); for (int i = 0; i < 100; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 1000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1190,13 +1195,13 @@ TEST_P(MessengerTest, SyntheticInjectTest3) { Messenger::Policy::stateless_server(0, 0), Messenger::Policy::lossy_client(0, 0)); for (int i = 0; i < 100; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 1000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1227,13 +1232,13 @@ TEST_P(MessengerTest, SyntheticInjectTest4) { Messenger::Policy::lossless_peer(0, 0), Messenger::Policy::lossless_peer(0, 0)); for (int i = 0; i < 100; ++i) { - if (!(i % 10)) cerr << "seeding connection " << i << std::endl; + if (!(i % 10)) lderr(g_ceph_context) << "seeding connection " << i << dendl; test_msg.generate_connection(); } gen_type rng(time(NULL)); for (int i = 0; i < 1000; ++i) { if (!(i % 10)) { - cerr << "Op " << i << ": "; + lderr(g_ceph_context) << "Op " << i << ": " << dendl; test_msg.print_internal_state(); } boost::uniform_int<> true_false(0, 99); @@ -1276,7 +1281,7 @@ class MarkdownDispatcher : public Dispatcher { } void ms_handle_fast_connect(Connection *con) { - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; Mutex::Locker l(lock); conns.insert(con); } @@ -1285,7 +1290,7 @@ class MarkdownDispatcher : public Dispatcher { conns.insert(con); } bool ms_dispatch(Message *m) { - cerr << __func__ << " conn: " << m->get_connection() << std::endl; + lderr(g_ceph_context) << __func__ << " conn: " << m->get_connection() << dendl; Mutex::Locker l(lock); count.inc(); conns.insert(m->get_connection()); @@ -1307,7 +1312,7 @@ class MarkdownDispatcher : public Dispatcher { return true; } bool ms_handle_reset(Connection *con) { - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; Mutex::Locker l(lock); conns.erase(con); usleep(rand() % 500); @@ -1316,7 +1321,7 @@ class MarkdownDispatcher : public Dispatcher { void ms_handle_remote_reset(Connection *con) { Mutex::Locker l(lock); conns.erase(con); - cerr << __func__ << con << std::endl; + lderr(g_ceph_context) << __func__ << con << dendl; } void ms_fast_dispatch(Message *m) { assert(0); @@ -1360,7 +1365,7 @@ TEST_P(MessengerTest, MarkdownTest) { ASSERT_EQ(conn2->send_message(m), 0); CHECK_AND_WAIT_TRUE(srv_dispatcher.count.read() > last + 1); if (srv_dispatcher.count.read() == last) { - cerr << __func__ << " last is " << last << std::endl; + lderr(g_ceph_context) << __func__ << " last is " << last << dendl; equal = true; equal_count++; } else { -- 2.39.5