OKIn https://fedorahosted.org/sssd/wiki/FAQ SSSDBG_FATAL_FAILURE isHBAC_DBG_FATAL isn't used in HBAC code. It is there for completeness of HBAC debug system.
described as:
0x0010: Fatal failures. Anything that would prevent SSSD from
starting up or causes it to cease running.
Are you sure that such errors can happen in HBAC?
Thanks.
I listened to the opinion of another engineer and I reworked it.+ debug_fn(__FILE__, __LINE__, "hbac", loglevel, "[%s:%i] %s\n",I noticed that you add '\n' here. DEBUG macro doesn't explicitly add
'\n'. I don't say it's bad, it's just different. I would like if some
other developer agreed to this.
IMO it's better, thanks!I rewrote it to '\t'.
Petr I noticed that you use spaces in debug messages to make logs
readable which I like, I'm just thing whether '\t' would be better than
just for spaces " ", or you could #define INDENT " "
What do you think?
I know that you haven't changed this code, but could you move the definition of i into for cycle or to he beginning of the block?
From 6b1c6cac7123e78a2c55c51019b66a6bcf97ec29 Mon Sep 17 00:00:00 2001 From: Petr Cech <pcech@redhat.com> Date: Fri, 24 Jul 2015 10:56:49 -0400 Subject: [PATCH 2/2] HBAC: Better libhbac debugging 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 --- src/providers/ipa/hbac_evaluator.c | 152 +++++++++++++++++++++++++++++++++++++ src/providers/ipa/ipa_access.c | 49 ++++++++++++ src/providers/ipa/ipa_hbac.exports | 3 +- src/providers/ipa/ipa_hbac.h | 22 ++++++ 4 files changed, 225 insertions(+), 1 deletion(-) diff --git a/src/providers/ipa/hbac_evaluator.c b/src/providers/ipa/hbac_evaluator.c index f40f9e0a7f16f5e012079c637b89c8e49ec5d15b..6f236058a4a9711cf9bfba1db1447789bbb2d4b5 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,9 +147,13 @@ 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; @@ -125,20 +162,25 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, uint32_t i;
I think this log message is wrong. Rule did not match - it was not relevant for this user, host or service. There are no deny rules. "The rule [%s] did not match" is fine by me, do you agree?for (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, "DISALLOWED by rule [%s].\n", + rules[i]->name);
add empty linecontinue; } 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 +188,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 +208,7 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, */ done: + HBAC_DEBUG(HBAC_DBG_INFO, "hbac_evaluate() >]\n"); return result; } @@ -333,3 +379,109 @@ 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); + }
IMO use const size_t size; or something like that here+ 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) { + char time_buff[100];
IMO use 'size' here. Please check return value of both strftime() and localtime()+ + 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"); + strftime(time_buff, sizeof time_buff, "%Y-%m-%d %H:%M:%S",
Would you move this assignment to the default clause in the switch statement?+ localtime(&req->request_time)); + 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 3198e2bd2a4c8355eeccc129c85ae3d7d67f61b0..77b5ffcb8e4f7ac15ab9aa1cbc503594a7ee760b 100644 --- a/src/providers/ipa/ipa_access.c +++ b/src/providers/ipa/ipa_access.c @@ -35,6 +35,53 @@ #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 = SSSDBG_UNRESOLVED;
typo s/Vesrbose/Verbose/+ + 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: + 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 +682,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 0115084e2b3a66569f97c4e7c035dffdb6450b43..63b6a5cd673d7b7f3096794648483d280a6bb47f 100644 --- a/src/providers/ipa/ipa_hbac.exports +++ b/src/providers/ipa/ipa_hbac.exports @@ -1,4 +1,4 @@ -IPA_HBAC_0.0.1 { +IPA_HBAC_0.0.2 { # public functions global: @@ -8,6 +8,7 @@ IPA_HBAC_0.0.1 { hbac_error_string; hbac_free_info; hbac_rule_is_complete; + hbac_enable_debug; # everything else is local local: diff --git a/src/providers/ipa/ipa_hbac.h b/src/providers/ipa/ipa_hbac.h index f43611351c8a5dfb20ca3d075f0bcd7bb71798c9..57947e7bb8509a8280e43259bbaf1b75599e0484 100644 --- a/src/providers/ipa/ipa_hbac.h +++ b/src/providers/ipa/ipa_hbac.h @@ -41,6 +41,28 @@ #include <stdbool.h> #include <time.h> +/** 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 /** Vesrbose 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-- 2.4.3