diff --git a/tests/basic_tests.c b/tests/basic_tests.c index cb96a3c4..406e93b4 100644 --- a/tests/basic_tests.c +++ b/tests/basic_tests.c @@ -51,7 +51,9 @@ END_TEST START_TEST(test02_server_load_dump_random_string) { LassoServer *serverContext; + begin_check_do_log(G_LOG_LEVEL_CRITICAL, "libxml2: Start tag expected, '<' not found\\n", FALSE); serverContext = lasso_server_new_from_dump("foo"); + end_check_do_log(); fail_unless(serverContext == NULL, "serverContext was created from a fake dump"); } @@ -60,7 +62,9 @@ END_TEST START_TEST(test03_server_load_dump_random_xml) { LassoServer *serverContext; + begin_check_do_log(G_LOG_LEVEL_CRITICAL, "(xml.c/:2307) Unable to build a LassoNode from a xmlNode", TRUE); serverContext = lasso_server_new_from_dump(""); + end_check_do_log(); fail_unless(serverContext == NULL, "serverContext was created from fake (but valid XML) dump"); } @@ -156,7 +160,9 @@ START_TEST(test08_test_new_from_xmlNode) "LassoTest", &this_info, 0); r = lasso_registry_default_add_direct_mapping("http://example.com", "Test1", LASSO_LASSO_HREF, "LassoTest"); fail_unless(r == 0, "no mapping for http://example.com:Test1 should exist"); + begin_check_do_log(G_LOG_LEVEL_WARNING, " Class LassoTest has no node_data so no initialization is possible", TRUE); node = lasso_node_new_from_dump(""); + end_check_do_log(); fail_unless(node != NULL, "parsing should return an object"); fail_unless(strcmp(G_OBJECT_TYPE_NAME(node), "LassoTest") == 0, "node classname should be LassoTest"); g_object_unref(node); @@ -1960,11 +1966,13 @@ START_TEST(test13_test_lasso_server_load_metadata) TESTSDATADIR "/idp5-saml2/private-key.pem", NULL, /* Secret key to unlock private key */ NULL)); + block_lasso_logs; check_good_rc(lasso_server_load_metadata(server, LASSO_PROVIDER_ROLE_IDP, TESTSDATADIR "/metadata/renater-metadata.xml", TESTSDATADIR "/metadata/metadata-federation-renater.crt", &blacklisted_1, &loaded_entity_ids, LASSO_SERVER_LOAD_METADATA_FLAG_DEFAULT)); + unblock_lasso_logs; check_equals(g_hash_table_size(server->providers), 110); check_equals(g_list_length(loaded_entity_ids), 110); diff --git a/tests/login_tests.c b/tests/login_tests.c index 5589b8d0..90573afc 100644 --- a/tests/login_tests.c +++ b/tests/login_tests.c @@ -285,7 +285,10 @@ START_TEST(test02_serviceProviderLogin) fail_unless(found != NULL, "We must find an InResponseTo attribute"); found[sizeof("InResponseTo=\"")] = '?'; lasso_set_flag("no-verify-signature"); + begin_check_do_log(G_LOG_LEVEL_DEBUG, " If inResponseTo attribute is present, a matching " + "request must be present too in the LassoLogin object", TRUE); check_not_equals(lasso_login_process_response_msg(spLoginContext, soapResponseMsg), 0); + end_check_do_log(); lasso_set_flag("verify-signature"); check_good_rc(lasso_login_accept_sso(spLoginContext)); fail_unless(rc == 0, "lasso_login_accept_sso must fail"); diff --git a/tests/login_tests_saml2.c b/tests/login_tests_saml2.c index c17c7500..1052c61a 100644 --- a/tests/login_tests_saml2.c +++ b/tests/login_tests_saml2.c @@ -785,8 +785,10 @@ START_TEST(test05_sso_idp_with_key_rollover) check_good_rc(lasso_login_accept_sso(spLoginContext)); /* Process response 2 */ + block_lasso_logs; check_good_rc(lasso_login_process_authn_response_msg(spLoginContext, idpLoginContext2->parent.msg_body)); + unblock_lasso_logs; check_good_rc(lasso_login_accept_sso(spLoginContext)); /* Cleanup */ @@ -838,7 +840,9 @@ sso_sp_with_key_rollover(LassoServer *idp_context, LassoServer *sp_context) LASSO_SAML2_NAME_IDENTIFIER_FORMAT_PERSISTENT); LASSO_SAMLP2_AUTHN_REQUEST(idp_login_context->parent.request)->NameIDPolicy->AllowCreate = 1; + block_lasso_logs; check_good_rc(lasso_login_process_authn_request_msg(idp_login_context, NULL)); + unblock_lasso_logs; check_good_rc(lasso_login_validate_request_msg(idp_login_context, 1, /* authentication_result */ 0 /* is_consent_obtained */ @@ -855,8 +859,10 @@ sso_sp_with_key_rollover(LassoServer *idp_context, LassoServer *sp_context) check_not_null(idp_login_context->parent.msg_url); /* Process response */ + block_lasso_logs; check_good_rc(lasso_login_process_authn_response_msg(sp_login_context, idp_login_context->parent.msg_body)); + unblock_lasso_logs; check_good_rc(lasso_login_accept_sso(sp_login_context)); /* Cleanup */ @@ -986,7 +992,9 @@ START_TEST(test07_sso_sp_with_hmac_sha1_signatures) test07_make_context(idp_context, "idp6-saml2", LASSO_PROVIDER_ROLE_SP, "sp6-saml2", key) test07_make_context(sp_context, "sp6-saml2", LASSO_PROVIDER_ROLE_IDP, "idp6-saml2", key) + block_lasso_logs; sso_initiated_by_sp(idp_context, sp_context); + unblock_lasso_logs; /* Cleanup */ lasso_release_gobject(idp_context); diff --git a/tests/non_regression_tests.c b/tests/non_regression_tests.c index 03c11a35..64886e94 100644 --- a/tests/non_regression_tests.c +++ b/tests/non_regression_tests.c @@ -165,26 +165,17 @@ START_TEST(indexed_endpoints_20101008) } END_TEST -void error_log_func(G_GNUC_UNUSED const gchar *log_domain, G_GNUC_UNUSED GLogLevelFlags log_level, - const gchar *message, G_GNUC_UNUSED gpointer user_data) -{ - fail_unless(FALSE, "error_func called... %s", message); -} - START_TEST(remove_warning_when_parssing_unknown_SNIPPET_LIST_NODES_20111007) { LassoNode *node; xmlDoc *xmldoc; const char content[] = "C8NQsm1Y3Gas9m0AMDhxU7UxCSI="; - guint log_handler; xmldoc = xmlReadMemory(content, sizeof(content)-1, NULL, NULL, 0); check_not_null(xmldoc); - log_handler = g_log_set_handler("Lasso", G_LOG_LEVEL_MASK, error_log_func, NULL); node = lasso_node_new_from_xmlNode(xmlDocGetRootElement(xmldoc)); check_not_null(node); check_true(LASSO_IS_SAML2_ATTRIBUTE(node)); - g_log_remove_handler("Lasso", log_handler); check_true(LASSO_IS_NODE(node)); xmlFreeDoc(xmldoc); lasso_release_gobject(node); diff --git a/tests/tests.c b/tests/tests.c index a32d32e9..8ec4a40f 100644 --- a/tests/tests.c +++ b/tests/tests.c @@ -26,8 +26,9 @@ #include #include +#include #include "../lasso/lasso.h" -#include "lasso_config.h" +#include "../lasso/lasso_config.h" extern Suite* basic_suite(); extern Suite* login_suite(); @@ -55,6 +56,12 @@ SuiteFunction suites[] = { #endif NULL }; +void error_logger(const gchar *log_domain, GLogLevelFlags log_level, + const gchar *message, G_GNUC_UNUSED gpointer user_data) +{ + fail("No logging output expected: message «%s» was emitted for domain «%s» at the level" + " «%d»", message, log_domain, log_level); +} int main(int argc, char *argv[]) @@ -71,6 +78,7 @@ main(int argc, char *argv[]) } lasso_init(); + g_log_set_default_handler(error_logger, NULL); sr = srunner_create(suites[0]()); diff --git a/tests/tests.h b/tests/tests.h index ce89ac98..62f01719 100644 --- a/tests/tests.h +++ b/tests/tests.h @@ -23,6 +23,8 @@ #ifndef __TESTS_H__ #define __TESTS_H__ +#include "../lasso/lasso_config.h" + #define check_not_null(what) \ fail_unless((what) != NULL, "%s:%i: " #what " returned NULL", __func__, __LINE__); @@ -72,4 +74,72 @@ fail_unless(g_strcmp0(__tmp, to) != 0, "%s:%i: " #what " is equal to %s", __func__, __LINE__, to); \ } +static inline void mute_logger(G_GNUC_UNUSED const gchar *domain, + G_GNUC_UNUSED GLogLevelFlags log_level, G_GNUC_UNUSED const gchar *message, + G_GNUC_UNUSED gpointer user_data) { +} +G_GNUC_UNUSED static guint mute_log_handler = 0; + +#define block_lasso_logs mute_log_handler = g_log_set_handler(LASSO_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, \ + mute_logger, NULL) + +#define unblock_lasso_logs g_log_remove_handler(LASSO_LOG_DOMAIN, mute_log_handler) + +struct CheckingLogHandlerUserData { + GLogLevelFlags log_level; + const char *message; + gboolean endswith; + GLogLevelFlags log_level_found; + const char *message_found; +}; +G_GNUC_UNUSED static guint checking_log_handler = 0; +G_GNUC_UNUSED static guint checking_log_handler_flag = 0; +G_GNUC_UNUSED static struct CheckingLogHandlerUserData checking_logger_user_data; + +static inline gboolean check_message(const char *a, const char *b, gboolean endswith) { + if (endswith) { + return strlen(a) >= strlen(b) && + strcmp(a+(strlen(a)-strlen(b)), b) == 0; + } else { + return strcmp(a, b) == 0; + } +} + +static inline void checking_logger(G_GNUC_UNUSED const gchar *domain, + G_GNUC_UNUSED GLogLevelFlags log_level, G_GNUC_UNUSED const gchar *message, + G_GNUC_UNUSED gpointer user_data) { + struct CheckingLogHandlerUserData *ck_user_data = user_data; + if (log_level == ck_user_data->log_level && check_message(message, ck_user_data->message, + ck_user_data->endswith)) { + } else { + g_log_default_handler(domain, log_level, message, user_data); + checking_log_handler_flag = 0; + } + ck_user_data->log_level_found = log_level; + ck_user_data->message_found = g_strdup(message); +} +/* begin_check_do_log(level, message, endswith)/end_check_do_log() with check that the only + * message emitted between the two macros is one equals to message at the level level, + * or ending with message if endswith is True. + */ +static inline void begin_check_do_log(GLogLevelFlags level, const char *message, gboolean endswith) { + memset(&checking_logger_user_data, 0, sizeof(struct CheckingLogHandlerUserData)); + checking_logger_user_data.log_level = level; + checking_logger_user_data.message = message; + checking_logger_user_data.endswith = endswith; + checking_log_handler = g_log_set_handler(LASSO_LOG_DOMAIN, level, checking_logger, &checking_logger_user_data); + checking_log_handler_flag = 1; +} + +static inline void end_check_do_log() { + g_log_remove_handler(LASSO_LOG_DOMAIN, checking_log_handler); + checking_log_handler = 0; + fail_unless(checking_log_handler_flag, "Logging failure: expected log level %d and message «%s», got %d and «%s»", + checking_logger_user_data.log_level, + checking_logger_user_data.message, + checking_logger_user_data.log_level_found, + checking_logger_user_data.message_found); + checking_log_handler_flag = 0; +} + #endif /*__TESTS_H__ */