* SSSDBG_TRACE_ALL produces:I think it could be useful to move user and might be user_group to less verbose level - I think it could be hard to navigate in less verbose logs otherwise, do you agree?
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:410] REQUEST:
...hbac_evaluator.c:391] service [sshd]
...hbac_evaluator.c:400] service_group (none)
...hbac_evaluator.c:391] user [csikos]
...hbac_evaluator.c:395] user_group:
...hbac_evaluator.c:397] [ipausers]
...hbac_evaluator.c:391] targethost [albireo.cygnus.dev]
...hbac_evaluator.c:400] targethost_group (none)
...hbac_evaluator.c:391] srchost [192.168.122.106]
...hbac_evaluator.c:400] srchost_group (none)
...hbac_evaluator.c:417] request time Fri Jul 24 14:29:36 2015
...hbac_evaluator.c:454] RULE [szabo_allowed] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] services_names (none)
...hbac_evaluator.c:440] services_groups:
...hbac_evaluator.c:442] [Sudo]
...hbac_evaluator.c:462] users:
Nice catch! Ci passed. ACK to this patch
From e83b609924ed2f6ff35b70355f3c330ec2586a15 Mon Sep 17 00:00:00 2001 From: Petr Cech <pcech@redhat.com> Date: Wed, 26 Aug 2015 02:50:26 -0400 Subject: [PATCH 1/2] TESTS: Fixing of uninitialized pointer. There was a bug with uninitialized pointer during solving ticket 2703. More details: rules[0]->services->names[1] is initialized on line 361, but initializing of rules[0]->srchosts->names[1] was missing. Resolves: https://fedorahosted.org/sssd/ticket/2703 --- src/tests/ipa_hbac-tests.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/tests/ipa_hbac-tests.c b/src/tests/ipa_hbac-tests.c index bd56c8f107b05f07b1ba8913fc14a03419d679f7..f2192a6fbc5188a7a7f6b204e03ca5961bb53f75 100644 --- a/src/tests/ipa_hbac-tests.c +++ b/src/tests/ipa_hbac-tests.c @@ -367,7 +367,7 @@ START_TEST(ipa_hbac_test_allow_utf8) fail_if(rules[0]->services->names == NULL); rules[0]->srchosts->names[0] = (const char *) &srchost_utf8_upcase; - rules[0]->services->names[1] = NULL; + rules[0]->srchosts->names[1] = NULL; rules[1] = NULL;-- 2.4.3
Are these header files really needed? What do we need from them? I'm just asking as code seems to compile fine even without them.
From 75d97a5336e2b66d4bb187ce024ad9be9b2702b9 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 | 149 +++++++++++++++++++++++++++++++++++++ src/providers/ipa/ipa_access.c | 45 +++++++++++ src/providers/ipa/ipa_hbac.exports | 3 +- src/providers/ipa/ipa_hbac.h | 22 ++++++ 4 files changed, 218 insertions(+), 1 deletion(-) diff --git a/src/providers/ipa/hbac_evaluator.c b/src/providers/ipa/hbac_evaluator.c index f40f9e0a7f16f5e012079c637b89c8e49ec5d15b..976d5887baeecbb45d660c0de5ca54c914fc6367 100644 --- a/src/providers/ipa/hbac_evaluator.c +++ b/src/providers/ipa/hbac_evaluator.c @@ -24,6 +24,8 @@ */ #include <stdlib.h> +#include <stdio.h> +#include <stdarg.h>
We do no like vars declared in 'for' , please move it to the beginning of the if block, thanks!#include <string.h> #include <errno.h> #include "providers/ipa/ipa_hbac.h" @@ -38,6 +40,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 +149,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()"); + hbac_req_debug_print(hbac_req); + if (info) { *info = malloc(sizeof(struct hbac_info)); if (!*info) { + HBAC_DEBUG(HBAC_DBG_ERROR, "Out of memory."); return HBAC_EVAL_OOM; } (*info)->code = HBAC_ERROR_UNKNOWN; @@ -125,20 +164,25 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, uint32_t i; 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].", + 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].", 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."); result = HBAC_EVAL_ERROR; (*info)->code = HBAC_ERROR_OUT_OF_MEMORY; } @@ -146,6 +190,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].", + rules[i]->name); result = HBAC_EVAL_ERROR; if (info) { (*info)->code = ret; @@ -163,6 +210,7 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules, */ done: + HBAC_DEBUG(HBAC_DBG_INFO, "hbac_evaluate() >]"); return result; } @@ -333,3 +381,104 @@ 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, " %s [%s]", label, el->name); + } + if (el->groups) { + if (el->groups[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_group:", label); + for (int i = 0; el->groups[i]; i++) {
Could we use directly ctime() here? Anyway please check that you don't pass NULL.+ HBAC_DEBUG(HBAC_DBG_TRACE, " [%s]", el->groups[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_group (none)", label); + } + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s (none)", label); + } +} + +static void hbac_req_debug_print(struct hbac_eval_req *req) +{ + HBAC_DEBUG(HBAC_DBG_TRACE, " REQUEST:"); + if (req) { + 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"); + HBAC_DEBUG(HBAC_DBG_TRACE, " request time %s", + asctime(gmtime(&req->request_time)));
indent the whole block please+ } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " Request is EMPTY."); + } +} + +static void hbac_rule_element_debug_print(struct hbac_rule_element *el, + const char *label) +{ + if (el) {
new line here+ HBAC_DEBUG(HBAC_DBG_TRACE, " category [%#x] [%s]", el->category, + (el->category == HBAC_CATEGORY_ALL) ? "ALL" : "NONE");
move the def. of i please+ if (el->names) { + if (el->names[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_names:", label); + for (int i = 0; el->names[i]; i++) {
new line here+ HBAC_DEBUG(HBAC_DBG_TRACE, " [%s]", el->names[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_names (none)", label); + } + }
defin. of i+ if (el->groups) { + if (el->groups[0]) { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_groups:", label); + for (int i = 0; el->groups[i]; i++) {
In https://fedorahosted.org/sssd/wiki/FAQ SSSDBG_FATAL_FAILURE is described as:+ HBAC_DEBUG(HBAC_DBG_TRACE, " [%s]", el->groups[i]); + } + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " %s_groups (none)", label); + } + } + } +} + +static void hbac_rule_debug_print(struct hbac_rule *rule) +{ + if (rule) { + HBAC_DEBUG(HBAC_DBG_TRACE, " RULE [%s] [%s]:", + rule->name, (rule->enabled) ? "ENABLED" : "DISABLED"); + if (rule->services) { + HBAC_DEBUG(HBAC_DBG_TRACE, " services:"); + hbac_rule_element_debug_print(rule->services, "services"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " services (none)"); + } + + if (rule->users) { + HBAC_DEBUG(HBAC_DBG_TRACE, " users:"); + hbac_rule_element_debug_print(rule->users, "users"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " users (none)"); + } + + if (rule->targethosts) { + HBAC_DEBUG(HBAC_DBG_TRACE, " targethosts:"); + hbac_rule_element_debug_print(rule->targethosts, "targethosts"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " targethosts (none)"); + } + + if (rule->srchosts) { + HBAC_DEBUG(HBAC_DBG_TRACE, " srchosts:"); + hbac_rule_element_debug_print(rule->srchosts, "srchosts"); + } else { + HBAC_DEBUG(HBAC_DBG_TRACE, " srchosts (none)"); + } + } +} diff --git a/src/providers/ipa/ipa_access.c b/src/providers/ipa/ipa_access.c index 3198e2bd2a4c8355eeccc129c85ae3d7d67f61b0..0e0716ad05a86a4acd57673c6944d5af9d22e71b 100644 --- a/src/providers/ipa/ipa_access.c +++ b/src/providers/ipa/ipa_access.c @@ -35,6 +35,49 @@ #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; + int ret; + char *message = NULL; + + switch(level) { + case HBAC_DBG_FATAL: + loglevel = SSSDBG_FATAL_FAILURE;
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?
I would lower this less severe level.+ break; + case HBAC_DBG_ERROR: + loglevel = SSSDBG_CRIT_FAILURE; + break; + case HBAC_DBG_WARNING: + loglevel = SSSDBG_OP_FAILURE;
Please rethink the log severity mapping, I think that generally you should lower the severity.+ break; + case HBAC_DBG_INFO: + loglevel = SSSDBG_MINOR_FAILURE; + break; + case HBAC_DBG_TRACE: + loglevel = SSSDBG_TRACE_ALL; + break; + }
Please move this test at the beginning of the function - so dynamic allocations can be skipped if possible.+ + va_list ap; + va_start(ap, fmt); + ret = vasprintf(&message, fmt, ap); + va_end(ap); + if (ret < 0) { + /* ENOMEM */ + return; + } + + if (DEBUG_IS_SET(loglevel)) {
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.+ debug_fn(__FILE__, __LINE__, "hbac", loglevel, "[%s:%i] %s\n",
+ 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 +678,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..f307778fa6d0b10364f4bc8f4151fda3f4a38dab 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, + HBAC_DBG_ERROR, + HBAC_DBG_WARNING, + HBAC_DBG_INFO, + HBAC_DBG_TRACE +}; + +/** + * 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