Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

GTEST: refactor log handlers using RAII idiom #2958

Merged
merged 3 commits into from
Oct 16, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions src/ucs/debug/log.c
Original file line number Diff line number Diff line change
Expand Up @@ -153,6 +153,11 @@ void ucs_log_pop_handler()
}
}

unsigned ucs_log_handlers_num()
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe ucs_log_num_handlers()?

{
return ucs_log_num_handlers;
}

void ucs_log_dispatch(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *format, ...)
{
Expand Down
1 change: 1 addition & 0 deletions src/ucs/debug/log.h
Original file line number Diff line number Diff line change
Expand Up @@ -148,6 +148,7 @@ const char *ucs_log_dump_hex(const void* data, size_t length, char *buf,
*/
void ucs_log_push_handler(ucs_log_func_t handler);
void ucs_log_pop_handler();
unsigned ucs_log_handlers_num();

END_C_DECLS

Expand Down
32 changes: 10 additions & 22 deletions test/gtest/common/test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,8 @@ test_base::test_base() :
m_num_threads(1),
m_num_valgrind_errors_before(0),
m_num_errors_before(0),
m_num_warnings_before(0)
m_num_warnings_before(0),
m_num_log_handlers_before(0)
{
push_config();
}
Expand Down Expand Up @@ -123,26 +124,6 @@ void test_base::pop_config()
m_config_stack.pop_back();
}

void test_base::hide_errors()
{
ucs_log_push_handler(hide_errors_logger);
}

void test_base::hide_warnings()
{
ucs_log_push_handler(hide_warns_logger);
}

void test_base::wrap_errors()
{
ucs_log_push_handler(wrap_errors_logger);
}

void test_base::restore_errors()
{
ucs_log_pop_handler();
}

ucs_log_func_rc_t
test_base::count_warns_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap)
Expand Down Expand Up @@ -224,6 +205,7 @@ void test_base::SetUpProxy() {
m_num_errors_before = m_total_errors;

m_errors.clear();
m_num_log_handlers_before = ucs_log_handlers_num();
ucs_log_push_handler(count_warns_logger);

try {
Expand All @@ -248,9 +230,15 @@ void test_base::TearDownProxy() {
cleanup();
}

ucs_log_pop_handler();
m_errors.clear();

ucs_log_pop_handler();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should we use RAII here too?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think that calling destructor implicitly is a RAII... more classes in inheritance to define ordering of destructors will only complicate the code. Do you know how to use it other way?

if (m_num_log_handlers_before != ucs_log_handlers_num()) {
ADD_FAILURE() << "Missed log handler cleanup, "
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

unsigned num_not_removed = ucs_log_handlers_num() - m_num_log_handlers_before;
if (num_not_removed != 0) {
     ADD_FAILURE() << num_not_removed << " log handlers were not removed";
 }

<< m_num_log_handlers_before << " != "
<< ucs_log_handlers_num();
}

int num_valgrind_errors = VALGRIND_COUNT_ERRORS - m_num_valgrind_errors_before;
if (num_valgrind_errors > 0) {
ADD_FAILURE() << "Got " << num_valgrind_errors << " valgrind errors during the test";
Expand Down
47 changes: 26 additions & 21 deletions test/gtest/common/test.h
Original file line number Diff line number Diff line change
Expand Up @@ -38,12 +38,16 @@ class test_base {
virtual void push_config();
virtual void pop_config();

static void hide_errors();
static void hide_warnings();
static void wrap_errors();
static void restore_errors();

protected:
class scoped_log_handler {
public:
scoped_log_handler(ucs_log_func_t handler) {
ucs_log_push_handler(handler);
}
~scoped_log_handler() {
ucs_log_pop_handler();
}
};

typedef enum {
NEW, RUNNING, SKIPPED, ABORTED, FINISHED
Expand All @@ -62,6 +66,22 @@ class test_base {

virtual void test_body() = 0;

static ucs_log_func_rc_t
count_warns_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
hide_errors_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
hide_warns_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
wrap_errors_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

state_t m_state;
bool m_initialized;
unsigned m_num_threads;
Expand All @@ -70,6 +90,7 @@ class test_base {
int m_num_valgrind_errors_before;
unsigned m_num_errors_before;
unsigned m_num_warnings_before;
unsigned m_num_log_handlers_before;

static pthread_mutex_t m_logger_mutex;
static unsigned m_total_errors;
Expand All @@ -82,22 +103,6 @@ class test_base {
void run();
static void *thread_func(void *arg);

static ucs_log_func_rc_t
count_warns_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
hide_errors_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
hide_warns_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

static ucs_log_func_rc_t
wrap_errors_logger(const char *file, unsigned line, const char *function,
ucs_log_level_t level, const char *message, va_list ap);

pthread_barrier_t m_barrier;
};

Expand Down
29 changes: 14 additions & 15 deletions test/gtest/ucp/test_ucp_atomic.cc
Original file line number Diff line number Diff line change
Expand Up @@ -63,12 +63,13 @@ void test_ucp_atomic::unaligned_blocking_add64(entity *e, size_t max_size,
void *memheap_addr, ucp_rkey_h rkey,
std::string& expected_data)
{
/* Test that unaligned addresses generate error */
ucs_status_t status;
hide_errors();
status = ucp_atomic_add64(e->ep(), 0, (uintptr_t)memheap_addr + 1, rkey);
restore_errors();
EXPECT_EQ(UCS_ERR_INVALID_PARAM, status);
{
/* Test that unaligned addresses generate error */
scoped_log_handler slh(hide_errors_logger);
ucs_status_t status = ucp_atomic_add64(e->ep(), 0,
(uintptr_t)memheap_addr + 1, rkey);
EXPECT_EQ(UCS_ERR_INVALID_PARAM, status);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

looks like EXPECT_EQ should be outside the scope?

}
expected_data.clear();
}

Expand Down Expand Up @@ -106,15 +107,13 @@ void test_ucp_atomic::unaligned_nb_post(entity *e, size_t max_size,
void *memheap_addr, ucp_rkey_h rkey,
std::string& expected_data)
{
/* Test that unaligned addresses generate error */
ucs_status_t status;

hide_errors();
status = test_ucp_atomic::ucp_atomic_post_nbi<uint64_t>(e->ep(), OP, 0,
(void *)((uintptr_t)memheap_addr + 1),
rkey);
restore_errors();
EXPECT_EQ(UCS_ERR_INVALID_PARAM, status);
{
/* Test that unaligned addresses generate error */
scoped_log_handler slh(hide_errors_logger);
ucs_status_t status = test_ucp_atomic::ucp_atomic_post_nbi<uint64_t>
(e->ep(), OP, 0, (void *)((uintptr_t)memheap_addr + 1), rkey);
EXPECT_EQ(UCS_ERR_INVALID_PARAM, status);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same here, EXPECT_EQ outside the scope

}
expected_data.clear();
}

Expand Down
3 changes: 1 addition & 2 deletions test/gtest/ucp/test_ucp_context.cc
Original file line number Diff line number Diff line change
Expand Up @@ -80,10 +80,9 @@ UCS_TEST_P(test_ucp_version, wrong_api_version) {
ucs_status_t status;
size_t warn_count;
{
hide_warnings();
scoped_log_handler slh(hide_warns_logger);
warn_count = m_warnings.size();
status = ucp_init_version(99, 99, &params, config.get(), &ucph);
restore_errors();
}
if (status != UCS_OK) {
ADD_FAILURE() << "Failed to create UCP with wrong version";
Expand Down
20 changes: 14 additions & 6 deletions test/gtest/ucp/test_ucp_mmap.cc
Original file line number Diff line number Diff line change
Expand Up @@ -36,9 +36,13 @@ class test_ucp_mmap : public test_ucp_memheap {

bool test_ucp_mmap::resolve_rma(entity *e, ucp_rkey_h rkey)
{
hide_errors();
ucs_status_t status = UCP_RKEY_RESOLVE(rkey, e->ep(), rma);
restore_errors();
ucs_status_t status;

{
scoped_log_handler slh(hide_errors_logger);
status = UCP_RKEY_RESOLVE(rkey, e->ep(), rma);
}

if (status == UCS_OK) {
EXPECT_NE(UCP_NULL_LANE, rkey->cache.rma_lane);
return true;
Expand All @@ -52,9 +56,13 @@ bool test_ucp_mmap::resolve_rma(entity *e, ucp_rkey_h rkey)

bool test_ucp_mmap::resolve_amo(entity *e, ucp_rkey_h rkey)
{
hide_errors();
ucs_status_t status = UCP_RKEY_RESOLVE(rkey, e->ep(), amo);
restore_errors();
ucs_status_t status;

{
scoped_log_handler slh(hide_errors_logger);
status = UCP_RKEY_RESOLVE(rkey, e->ep(), amo);
}

if (status == UCS_OK) {
EXPECT_NE(UCP_NULL_LANE, rkey->cache.amo_lane);
return true;
Expand Down
90 changes: 45 additions & 45 deletions test/gtest/ucp/test_ucp_peer_failure.cc
Original file line number Diff line number Diff line change
Expand Up @@ -287,65 +287,65 @@ void test_ucp_peer_failure::do_test(size_t msg_size, int pre_msg_count,

EXPECT_EQ(UCS_OK, m_err_status);

wrap_errors();
{
scoped_log_handler slh(wrap_errors_logger);

fail_receiver();
fail_receiver();

void *sreq = send_nb(failing_sender(), m_failing_rkey);
void *sreq = send_nb(failing_sender(), m_failing_rkey);

while (!m_err_count) {
progress();
}
EXPECT_NE(UCS_OK, m_err_status);

if (UCS_PTR_IS_PTR(sreq)) {
/* The request may either succeed or fail, even though the data is not
* delivered - depends on when the error is detected on sender side and
* if zcopy/bcopy protocol is used. In any case, the request must
* complete, and all resources have to be released.
*/
ucs_status_t status = ucp_request_check_status(sreq);
EXPECT_NE(UCS_INPROGRESS, status);
if (request_must_fail) {
EXPECT_EQ(m_err_status, status);
} else {
EXPECT_TRUE((m_err_status == status) || (UCS_OK == status));
while (!m_err_count) {
progress();
}
EXPECT_NE(UCS_OK, m_err_status);

if (UCS_PTR_IS_PTR(sreq)) {
/* The request may either succeed or fail, even though the data is
* not * delivered - depends on when the error is detected on sender
* side and if zcopy/bcopy protocol is used. In any case, the
* request must complete, and all resources have to be released.
*/
ucs_status_t status = ucp_request_check_status(sreq);
EXPECT_NE(UCS_INPROGRESS, status);
if (request_must_fail) {
EXPECT_EQ(m_err_status, status);
} else {
EXPECT_TRUE((m_err_status == status) || (UCS_OK == status));
}
ucp_request_release(sreq);
}
ucp_request_release(sreq);
}

/* Additional sends must fail */
void *sreq2 = send_nb(failing_sender(), m_failing_rkey);
EXPECT_FALSE(UCS_PTR_IS_PTR(sreq2));
EXPECT_EQ(m_err_status, UCS_PTR_STATUS(sreq2));
/* Additional sends must fail */
void *sreq2 = send_nb(failing_sender(), m_failing_rkey);
EXPECT_FALSE(UCS_PTR_IS_PTR(sreq2));
EXPECT_EQ(m_err_status, UCS_PTR_STATUS(sreq2));

if (force_close) {
unsigned allocd_eps_before =
ucs_strided_alloc_inuse_count(&sender().worker()->ep_alloc);
if (force_close) {
unsigned allocd_eps_before =
ucs_strided_alloc_inuse_count(&sender().worker()->ep_alloc);

ucp_ep_h ep = sender().revoke_ep(0, FAILING_EP_INDEX);
ucp_ep_h ep = sender().revoke_ep(0, FAILING_EP_INDEX);

void *creq = ucp_ep_close_nb(ep, UCP_EP_CLOSE_MODE_FORCE);
wait(creq);
void *creq = ucp_ep_close_nb(ep, UCP_EP_CLOSE_MODE_FORCE);
wait(creq);

unsigned allocd_eps_after =
ucs_strided_alloc_inuse_count(&sender().worker()->ep_alloc);
unsigned allocd_eps_after =
ucs_strided_alloc_inuse_count(&sender().worker()->ep_alloc);

if (!(GetParam().variant & FAIL_IMM)) {
EXPECT_LT(allocd_eps_after, allocd_eps_before);
if (!(GetParam().variant & FAIL_IMM)) {
EXPECT_LT(allocd_eps_after, allocd_eps_before);
}
}
}

/* release requests */
while (!sreqs_pre.empty()) {
void *req = sreqs_pre.back();
sreqs_pre.pop_back();
EXPECT_NE(UCS_INPROGRESS, ucp_request_test(req, NULL));
ucp_request_release(req);
/* release requests */
while (!sreqs_pre.empty()) {
void *req = sreqs_pre.back();
sreqs_pre.pop_back();
EXPECT_NE(UCS_INPROGRESS, ucp_request_test(req, NULL));
ucp_request_release(req);
}
}

restore_errors();

/* Check workability of stable pair */
smoke_test(true);

Expand Down
Loading