[SSSD] [PATCH] [HBAC]: Better libhbac debuging
Petr Cech
pcech at redhat.com
Tue Sep 1 14:15:27 UTC 2015
On 09/01/2015 11:00 AM, Pavel Reichl wrote:
>> From 6b1c6cac7123e78a2c55c51019b66a6bcf97ec29 Mon Sep 17 00:00:00 2001
>> From: Petr Cech<pcech at 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 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?
Fixed.
>>
>> 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);
> 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?
Fixed.
>> 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 +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);
>> + }
> add empty line
Fixed.
>> + 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 const size_t size; or something like that here
Fixed.
>> +
>> + 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",
> IMO use 'size' here. Please check return value of both strftime() and
> localtime()
Fixed.
>> + 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;
> Would you move this assignment to the default clause in the switch
> statement?
Fixed.
>> +
>> + 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. */
> typo s/Vesrbose/Verbose/
> Generally - why 2 asterisks at the beginning of the comment? But as I
> see we use it at hundreds of other places, so no need to change it.
Fixed. 2 asterisks come from doxygen format.
>> +};
>> +
>> +/**
>> + * 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
Petr
PS: I attached both patches. The 0001-TESTS-Fixing... was ACK in past.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-TESTS-Fixing-of-uninitialized-pointer.patch
Type: text/x-patch
Size: 1085 bytes
Desc: not available
URL: <https://lists.fedorahosted.org/pipermail/sssd-devel/attachments/20150901/d9b4a567/attachment-0002.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0002-HBAC-Better-libhbac-debugging.patch
Type: text/x-patch
Size: 12674 bytes
Desc: not available
URL: <https://lists.fedorahosted.org/pipermail/sssd-devel/attachments/20150901/d9b4a567/attachment-0003.bin>
More information about the sssd-devel
mailing list