From 65ce66c43141f7e5c8482a8f8e7e217a23791588 Mon Sep 17 00:00:00 2001 From: Petr Cech Date: Fri, 24 Jul 2015 10:56:49 -0400 Subject: HBAC: Better libhbac debugging MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Added support for logging via external log function. Log provides information about rules evaluating (HBAC_DBG_INFO level) and additionally can describe rules (HBAC_DBG_TRACE level). Resolves: https://fedorahosted.org/sssd/ticket/2703 Reviewed-by: Pavel Reichl Reviewed-by: Lukáš Slebodník Reviewed-by: Michal Židek --- Makefile.am | 2 +- src/providers/ipa/hbac_evaluator.c | 168 ++++++++++++++++++++++++++++++++++++- src/providers/ipa/ipa_access.c | 50 +++++++++++ src/providers/ipa/ipa_hbac.exports | 5 ++ src/providers/ipa/ipa_hbac.h | 22 +++++ 5 files changed, 244 insertions(+), 3 deletions(-) diff --git a/Makefile.am b/Makefile.am index aae123c18..ce3166716 100644 --- a/Makefile.am +++ b/Makefile.am @@ -933,7 +933,7 @@ libipa_hbac_la_LIBADD = \ $(UNICODE_LIBS) libipa_hbac_la_LDFLAGS = \ -Wl,--version-script,$(srcdir)/src/providers/ipa/ipa_hbac.exports \ - -version-info 0:1:0 + -version-info 1:0:1 dist_noinst_DATA += src/providers/ipa/ipa_hbac.exports diff --git a/src/providers/ipa/hbac_evaluator.c b/src/providers/ipa/hbac_evaluator.c index f40f9e0a7..28d802bc1 100644 --- a/src/providers/ipa/hbac_evaluator.c +++ b/src/providers/ipa/hbac_evaluator.c @@ -38,6 +38,39 @@ typedef int errno_t; #define EOK 0 #endif +/* HBAC logging system */ + +/* debug macro */ +#define HBAC_DEBUG(level, format, ...) do { \ + if (hbac_debug_fn != NULL) { \ + hbac_debug_fn(__FILE__, __LINE__, level, format, ##__VA_ARGS__); \ + } \ +} while (0) + +/* static pointer to external logging function */ +static hbac_debug_fn_t hbac_debug_fn = NULL; + +/* setup function for external logging function */ +void hbac_enable_debug(hbac_debug_fn_t external_debug_fn) +{ + hbac_debug_fn = external_debug_fn; +} + +/* auxiliary function for hbac_request_element logging */ +static void hbac_request_element_debug_print(struct hbac_request_element *el, + const char *label); + +/* auxiliary function for hbac_eval_req logging */ +static void hbac_req_debug_print(struct hbac_eval_req *req); + +/* auxiliary function for hbac_rule_element logging */ +static void hbac_rule_element_debug_print(struct hbac_rule_element *el, + const char *label); + +/* auxiliary function for hbac_rule logging */ +static void hbac_rule_debug_print(struct hbac_rule *rule); + + /* Placeholder structure for future HBAC time-based * evaluation rules */ @@ -114,31 +147,39 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, enum hbac_eval_result result = HBAC_EVAL_DENY; enum hbac_eval_result_int intermediate_result; + HBAC_DEBUG(HBAC_DBG_INFO, "[< hbac_evaluate()\n"); + hbac_req_debug_print(hbac_req); + if (info) { *info = malloc(sizeof(struct hbac_info)); if (!*info) { + HBAC_DEBUG(HBAC_DBG_ERROR, "Out of memory.\n"); return HBAC_EVAL_OOM; } (*info)->code = HBAC_ERROR_UNKNOWN; (*info)->rule_name = NULL; } - uint32_t i; - for (i = 0; rules[i]; i++) { + for (uint32_t i = 0; rules[i]; i++) { + hbac_rule_debug_print(rules[i]); intermediate_result = hbac_evaluate_rule(rules[i], hbac_req, &ret); if (intermediate_result == HBAC_EVAL_UNMATCHED) { /* This rule did not match at all. Skip it */ + HBAC_DEBUG(HBAC_DBG_INFO, "The rule [%s] did not match.\n", + rules[i]->name); continue; } else if (intermediate_result == HBAC_EVAL_MATCHED) { /* This request matched an ALLOW rule * Set the result to ALLOW but continue checking * the other rules in case a DENY rule trumps it. */ + HBAC_DEBUG(HBAC_DBG_INFO, "ALLOWED by rule [%s].\n", rules[i]->name); result = HBAC_EVAL_ALLOW; if (info) { (*info)->code = HBAC_SUCCESS; (*info)->rule_name = strdup(rules[i]->name); if (!(*info)->rule_name) { + HBAC_DEBUG(HBAC_DBG_ERROR, "Out of memory.\n"); result = HBAC_EVAL_ERROR; (*info)->code = HBAC_ERROR_OUT_OF_MEMORY; } @@ -146,6 +187,9 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, break; } else { /* An error occurred processing this rule */ + HBAC_DEBUG(HBAC_DBG_ERROR, + "Error occurred during evaluating of rule [%s].\n", + rules[i]->name); result = HBAC_EVAL_ERROR; if (info) { (*info)->code = ret; @@ -163,6 +207,7 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, */ done: + HBAC_DEBUG(HBAC_DBG_INFO, "hbac_evaluate() >]\n"); return result; } @@ -333,3 +378,122 @@ const char *hbac_error_string(enum hbac_error_code code) return "Unknown error code"; } } + +static void hbac_request_element_debug_print(struct hbac_request_element *el, + const char *label) +{ + if (el) { + if (el->name) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s [%s]\n", label, el->name); + } + + if (el->groups) { + if (el->groups[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_group:\n", label); + for (int i = 0; el->groups[i]; i++) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t\t[%s]\n", el->groups[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_group (none)\n", label); + } + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t%s (none)\n", label); + } +} + +static void hbac_req_debug_print(struct hbac_eval_req *req) +{ + HBAC_DEBUG(HBAC_DBG_TRACE, "\tREQUEST:\n"); + if (req) { + struct tm *local_time = NULL; + size_t ret; + const size_t buff_size = 100; + char time_buff[buff_size]; + + hbac_request_element_debug_print(req->service, "service"); + hbac_request_element_debug_print(req->user, "user"); + hbac_request_element_debug_print(req->targethost, "targethost"); + hbac_request_element_debug_print(req->srchost, "srchost"); + + local_time = localtime(&req->request_time); + if (local_time == NULL) { + return; + } + + ret = strftime(time_buff, buff_size, "%Y-%m-%d %H:%M:%S", local_time); + if (ret <= 0) { + return; + } + + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\trequest time %s\n", time_buff); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tRequest is EMPTY.\n"); + } +} + +static void hbac_rule_element_debug_print(struct hbac_rule_element *el, + const char *label) +{ + if (el) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\tcategory [%#x] [%s]\n", el->category, + (el->category == HBAC_CATEGORY_ALL) ? "ALL" : "NONE"); + + if (el->names) { + if (el->names[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_names:\n", label); + for (int i = 0; el->names[i]; i++) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t\t[%s]\n", el->names[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_names (none)\n", label); + } + } + + if (el->groups) { + if (el->groups[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_groups:\n", label); + for (int i = 0; el->groups[i]; i++) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t\t[%s]\n", el->groups[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\t\t%s_groups (none)\n", label); + } + } + } +} + +static void hbac_rule_debug_print(struct hbac_rule *rule) +{ + if (rule) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tRULE [%s] [%s]:\n", + rule->name, (rule->enabled) ? "ENABLED" : "DISABLED"); + if (rule->services) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tservices:\n"); + hbac_rule_element_debug_print(rule->services, "services"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tservices (none)\n"); + } + + if (rule->users) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tusers:\n"); + hbac_rule_element_debug_print(rule->users, "users"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tusers (none)\n"); + } + + if (rule->targethosts) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\ttargethosts:\n"); + hbac_rule_element_debug_print(rule->targethosts, "targethosts"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\ttargethosts (none)\n"); + } + + if (rule->srchosts) { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tsrchosts:\n"); + hbac_rule_element_debug_print(rule->srchosts, "srchosts"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, "\tsrchosts (none)\n"); + } + } +} diff --git a/src/providers/ipa/ipa_access.c b/src/providers/ipa/ipa_access.c index 3198e2bd2..65a791c3f 100644 --- a/src/providers/ipa/ipa_access.c +++ b/src/providers/ipa/ipa_access.c @@ -35,6 +35,54 @@ #include "providers/ipa/ipa_hbac_private.h" #include "providers/ipa/ipa_hbac_rules.h" +/* External logging function for HBAC. */ +void hbac_debug_messages(const char *file, int line, + enum hbac_debug_level level, + const char *fmt, ...) +{ + int loglevel; + + switch(level) { + case HBAC_DBG_FATAL: + loglevel = SSSDBG_FATAL_FAILURE; + break; + case HBAC_DBG_ERROR: + loglevel = SSSDBG_OP_FAILURE; + break; + case HBAC_DBG_WARNING: + loglevel = SSSDBG_MINOR_FAILURE; + break; + case HBAC_DBG_INFO: + loglevel = SSSDBG_CONF_SETTINGS; + break; + case HBAC_DBG_TRACE: + loglevel = SSSDBG_TRACE_INTERNAL; + break; + default: + loglevel = SSSDBG_UNRESOLVED; + break; + } + + if (DEBUG_IS_SET(loglevel)) { + va_list ap; + char *message = NULL; + int ret; + + va_start(ap, fmt); + ret = vasprintf(&message, fmt, ap); + va_end(ap); + if (ret < 0) { + /* ENOMEM */ + free(message); + return; + } + + debug_fn(__FILE__, __LINE__, "hbac", loglevel, "[%s:%i] %s", + file, line, message); + free(message); + } +} + static void ipa_access_reply(struct hbac_ctx *hbac_ctx, int pam_status) { struct be_req *be_req = hbac_ctx->be_req; @@ -635,6 +683,8 @@ void ipa_hbac_evaluate_rules(struct hbac_ctx *hbac_ctx) return; } + hbac_enable_debug(hbac_debug_messages); + result = hbac_evaluate(hbac_rules, eval_req, &info); if (result == HBAC_EVAL_ALLOW) { DEBUG(SSSDBG_MINOR_FAILURE, "Access granted by HBAC rule [%s]\n", diff --git a/src/providers/ipa/ipa_hbac.exports b/src/providers/ipa/ipa_hbac.exports index 0115084e2..abdcc5f5a 100644 --- a/src/providers/ipa/ipa_hbac.exports +++ b/src/providers/ipa/ipa_hbac.exports @@ -13,3 +13,8 @@ IPA_HBAC_0.0.1 { local: *; }; + +IPA_HBAC_0.1.0 { + global: + hbac_enable_debug; +} IPA_HBAC_0.0.1; diff --git a/src/providers/ipa/ipa_hbac.h b/src/providers/ipa/ipa_hbac.h index f43611351..9e85890e7 100644 --- a/src/providers/ipa/ipa_hbac.h +++ b/src/providers/ipa/ipa_hbac.h @@ -41,6 +41,28 @@ #include #include +/** Debug levels for HBAC. */ +enum hbac_debug_level { + HBAC_DBG_FATAL, /** Fatal failure (not used). */ + HBAC_DBG_ERROR, /** Serious failure (out of memory, for example). */ + HBAC_DBG_WARNING, /** Warnings (not used). */ + HBAC_DBG_INFO, /** HBAC allow/disallow info. */ + HBAC_DBG_TRACE /** Verbose description of rules. */ +}; + +/** + * Function pointer to HBAC external debugging function. + */ +typedef void (*hbac_debug_fn_t)(const char *file, int line, + enum hbac_debug_level, const char *format, + ...); + +/** + * HBAC uses external_debug_fn for logging messages. + * @param[in|out] external_debug_void Pointer to external logging function. + */ +void hbac_enable_debug(hbac_debug_fn_t external_debug_fn); + /** Result of HBAC evaluation */ enum hbac_eval_result { /** An error occurred -- cgit