On 08/27/2015 10:42 AM, Pavel Reichl wrote:
* SSSDBG_TRACE_ALL produces:

...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:
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: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:
It was commented in previous mail. I agree.

On 08/26/2015 09:44 AM, Petr Cech wrote:

0001-TESTS-Fixing-of-uninitialized-pointer.patch
Nice catch! Ci passed. ACK to this patch
Thanks.

0002-HBAC-Better-libhbac-debugging.patch


 From 75d97a5336e2b66d4bb187ce024ad9be9b2702b9 Mon Sep 17 00:00:00 2001
From: Petr Cech<pc...@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>
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.
Amazingly, it works. The reason were things like ## __ VA_ARGS__ in new HBAC_DEBUG macro.
  #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++) {
We do no like vars declared in 'for' , please move it to the beginning
of the if block, thanks!
I asked community over mailing list for it. I think, we could try it.
+                    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)));
Could we use directly ctime() here? Anyway please check that you don't
pass NULL.
Fixed.
+    } 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) {
indent the whole block please
Fixed.
+    HBAC_DEBUG(HBAC_DBG_TRACE, "      category [%#x] [%s]", el->category,
+               (el->category == HBAC_CATEGORY_ALL) ? "ALL" : "NONE");
new line here
Added.
+    if (el->names) {
+        if (el->names[0]) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_names:", label);
+            for (int i = 0; el->names[i]; i++) {
move the def. of i please
It is new style.
+                HBAC_DEBUG(HBAC_DBG_TRACE, "        [%s]", el->names[i]);
+            }
+        } else {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_names (none)", label);
+        }
+    }
new line here
Fixed.
+    if (el->groups) {
+        if (el->groups[0]) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_groups:", label);
+            for (int i = 0; el->groups[i]; i++) {
defin. of i
New style.
+                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;
In https://fedorahosted.org/sssd/wiki/FAQ SSSDBG_FATAL_FAILURE is
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?
HBAC_DBG_FATAL isn't used in HBAC code. It is there for completeness of HBAC debug system.

+        break;
+    case HBAC_DBG_ERROR:
+        loglevel = SSSDBG_CRIT_FAILURE;
+        break;
+    case HBAC_DBG_WARNING:
+        loglevel = SSSDBG_OP_FAILURE;
I would lower this less severe level.
(I will write about it down at this mail.)
+        break;
+    case HBAC_DBG_INFO:
+        loglevel = SSSDBG_MINOR_FAILURE;
+        break;
+    case HBAC_DBG_TRACE:
+        loglevel = SSSDBG_TRACE_ALL;
+        break;
+    }
> Please add default here (http://www.freeipa.org/page/Coding_Style#Switch)
Fixed.
>
Please rethink the log severity mapping, I think that generally you
should lower the severity.
I did some changes:
HBAC_DBG_ERROR:
-        loglevel = SSSDBG_CRIT_FAILURE;
+        loglevel = SSSDBG_OP_FAILURE;
HBAC_DBG_WARNING:
-        loglevel = SSSDBG_OP_FAILURE;
+        loglevel = SSSDBG_MINOR_FAILURE;
HBAC_DBG_INFO:
-        loglevel = SSSDBG_MINOR_FAILURE;
+        loglevel = SSSDBG_CONF_SETTINGS;
HBAC_DBG_TRACE:
-        loglevel = SSSDBG_TRACE_ALL;
+        loglevel = SSSDBG_TRACE_INTERNAL;
Is it OK?
+
+    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)) {
Please move this test at the beginning of the function - so dynamic
allocations can be skipped if possible.
Fixed.
+        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.
I listened to the opinion of another engineer and I reworked it.
+                 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


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 rewrote it to '\t'.

Petr
>From 6b1c6cac7123e78a2c55c51019b66a6bcf97ec29 Mon Sep 17 00:00:00 2001
From: Petr Cech <pc...@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;
 
     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);
             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);
+        }
+        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];
+
+        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",
+                 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;
+
+    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

_______________________________________________
sssd-devel mailing list
sssd-devel@lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/sssd-devel

Reply via email to