From d1268a6aa895ee93cd9fee6fc6c759317e681a85 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 --- src/test/msgr/test_msgr.cc | 73 ++++++++++++++++++++------------------ 1 file changed, 39 insertions(+), 34 deletions(-) diff --git a/src/test/msgr/test_msgr.cc b/src/test/msgr/test_msgr.cc index f022130cbdd..df849665a78 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)); @@ -106,12 +114,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; @@ -137,7 +145,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); } @@ -148,7 +156,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 @@ -159,7 +167,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 @@ -178,7 +186,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()); @@ -803,10 +811,10 @@ class SyntheticDispatcher : public Dispatcher { ::decode(i, blp); ::decode(reply, blp); if (reply) { - //cerr << __func__ << " reply=" << reply << " i=" << i << std::endl; + lderr(g_ceph_context) << __func__ << " conn=" << m->get_connection() << " reply=" << reply << " i=" << i << dendl; reply_message(m, i); } else if (sent.count(i)) { - //cerr << __func__ << " reply=" << reply << " i=" << i << std::endl; + lderr(g_ceph_context) << __func__ << " conn=" << m->get_connection() << " reply=" << reply << " i=" << i << dendl; ASSERT_EQ(conn_sent[m->get_connection()].front(), i); ASSERT_TRUE(m->get_data().contents_equal(sent[i])); conn_sent[m->get_connection()].pop_front(); @@ -834,7 +842,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) { @@ -850,7 +858,7 @@ class SyntheticDispatcher : public Dispatcher { sent[i] = m->get_data(); conn_sent[con].push_back(i); } - //cerr << __func__ << " conn=" << con.get() << " send m=" << m << " i=" << i << std::endl; + lderr(g_ceph_context) << __func__ << " conn=" << con.get() << " send m=" << m << " i=" << i << dendl; } ASSERT_EQ(con->send_message(m), 0); } @@ -872,7 +880,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; } } } @@ -1049,12 +1057,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(); } } @@ -1107,13 +1112,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); @@ -1136,13 +1141,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); @@ -1170,13 +1175,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); @@ -1205,13 +1210,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); @@ -1238,13 +1243,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); @@ -1275,13 +1280,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); @@ -1324,7 +1329,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); } @@ -1333,7 +1338,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()); @@ -1355,7 +1360,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); @@ -1364,7 +1369,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); @@ -1408,7 +1413,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