<html>
  <head>
    <meta content="text/html; charset=utf-8" http-equiv="Content-Type">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    On 07/24/2015 06:20 PM, Petr Cech wrote:<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">From 2fcf13ef59f00b460afa77b27ef6cc2789b06393 Mon Sep 17 00:00:00 2001
From: Petr Cech <a moz-do-not-send="true" class="moz-txt-link-rfc2396E" href="mailto:pcech@redhat.com">&lt;pcech@redhat.com&gt;</a>
Date: Fri, 24 Jul 2015 10:56:49 -0400
Subject: [PATCH] [HBAC]: Better libhbac debuging</pre>
      </div>
    </blockquote>
    s/debuging/debugging<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">

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:
<a moz-do-not-send="true" class="moz-txt-link-freetext" href="https://fedorahosted.org/sssd/ticket/2703">https://fedorahosted.org/sssd/ticket/2703</a>
---
 src/providers/ipa/hbac_evaluator.c | 146 +++++++++++++++++++++++++++++++++++++
 src/providers/ipa/ipa_access.c     |  45 ++++++++++++
 src/providers/ipa/ipa_hbac.exports |   3 +-
 src/providers/ipa/ipa_hbac.h       |  23 ++++++
 4 files changed, 216 insertions(+), 1 deletion(-)

diff --git a/src/providers/ipa/hbac_evaluator.c b/src/providers/ipa/hbac_evaluator.c
index f40f9e0a7f16f5e012079c637b89c8e49ec5d15b..66d3512937702b5955f333c0c837807ee9e13deb 100644
--- a/src/providers/ipa/hbac_evaluator.c
+++ b/src/providers/ipa/hbac_evaluator.c
@@ -24,6 +24,8 @@
 */
 
 #include &lt;stdlib.h&gt;
+#include &lt;stdio.h&gt;
+#include &lt;stdarg.h&gt;
 #include &lt;string.h&gt;
 #include &lt;errno.h&gt;
 #include "providers/ipa/ipa_hbac.h"
@@ -38,6 +40,41 @@ typedef int errno_t;
 #define EOK 0
 #endif
 
+/* HBAC logging system */
+
+/* static pointer to external logging function */
+static void (*hbac_debug_fn)(const char *file, int line, enum hbac_debug_level,
+                             const char *format, ...) = NULL;</pre>
      </div>
    </blockquote>
    Do you think that introducing a new type using typedef for this type
    of callback would be more readable?<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+
+/* setup function for external logging function */
+void hbac_enable_debug(void (*external_debug_fn)(const char *file, int line,
+                       enum hbac_debug_level, const char *format, ...))
+{
+    hbac_debug_fn = external_debug_fn;
+}
+
+/* debug macro */
+#define HBAC_DEBUG(level, format, ...) do { \
+    if (hbac_debug_fn != NULL) { \
+        hbac_debug_fn(__FILE__, __LINE__, level, format, ##__VA_ARGS__); \
+    } \
+} while (0)</pre>
      </div>
    </blockquote>
    IMO macro should be defined after includes and before function
    definitions, but I haven't check if we are 100 % consistent about
    this in SSSD.<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+
+/* auxiliary function for hbac_request_element logging */
+static void hbac_request_element_debug_print(struct hbac_request_element *el,
+        const char *label);</pre>
      </div>
    </blockquote>
    bad indentation<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+
+/* 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
  */
@@ -110,6 +147,9 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules,
                                     struct hbac_eval_req *hbac_req,
                                     struct hbac_info **info)
 {
+    HBAC_DEBUG(HBAC_DBG_INFO, "[&lt; hbac_evaluate()");
+    hbac_req_debug_print(hbac_req);
+</pre>
      </div>
    </blockquote>
    We generally do not add any code before variable definitions, I
    understand that logging is kinda special, but I would prefer to add
    it after the definitions, do you agree?<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
     enum hbac_error_code ret;
     enum hbac_eval_result result = HBAC_EVAL_DENY;
     enum hbac_eval_result_int intermediate_result;
@@ -117,6 +157,7 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules,
     if (info) {
         *info = malloc(sizeof(struct hbac_info));
         if (!*info) {
+            HBAC_DEBUG(HBAC_DBG_ERROR, "Out of memory.");
             return HBAC_EVAL_OOM;
         }
         (*info)-&gt;code = HBAC_ERROR_UNKNOWN;
@@ -125,20 +166,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, &amp;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]-&gt;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]-&gt;name);
             result = HBAC_EVAL_ALLOW;
             if (info) {
                 (*info)-&gt;code = HBAC_SUCCESS;
                 (*info)-&gt;rule_name = strdup(rules[i]-&gt;name);
                 if (!(*info)-&gt;rule_name) {
+                    HBAC_DEBUG(HBAC_DBG_ERROR, "Out of memory.");
                     result = HBAC_EVAL_ERROR;
                     (*info)-&gt;code = HBAC_ERROR_OUT_OF_MEMORY;
                 }
@@ -146,6 +192,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 occured during evaluating of rule [%s].",</pre>
      </div>
    </blockquote>
    s/occured/occurred/<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+                       rules[i]-&gt;name);
             result = HBAC_EVAL_ERROR;
             if (info) {
                 (*info)-&gt;code = ret;
@@ -163,6 +212,7 @@ enum hbac_eval_result hbac_evaluate(struct hbac_rule **rules,
      */
 done:
 
+    HBAC_DEBUG(HBAC_DBG_INFO, "hbac_evaluate() &gt;] ");</pre>
      </div>
    </blockquote>
    trialing ' ' in string?<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
     return result;
 }
 
@@ -333,3 +383,99 @@ 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)</pre>
      </div>
    </blockquote>
    indentation<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+{
+    if (el) {
+        if (el-&gt;name) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    %s [%s]", label, el-&gt;name);
+        }
+        if (el-&gt;groups) {
+            if (el-&gt;groups[0]) {
+                HBAC_DEBUG(HBAC_DBG_TRACE, "    %s_group:", label);
+                for (int i = 0; el-&gt;groups[i]; i++) {
+                    HBAC_DEBUG(HBAC_DBG_TRACE, "      [%s]", el-&gt;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-&gt;service, "service");
+        hbac_request_element_debug_print(req-&gt;user, "user");
+        hbac_request_element_debug_print(req-&gt;targethost, "targethost");
+        hbac_request_element_debug_print(req-&gt;srchost, "srchost");
+        HBAC_DEBUG(HBAC_DBG_TRACE, "    request time %s",
+                   asctime(gmtime(&amp;req-&gt;request_time)));
+    } else {
+        HBAC_DEBUG(HBAC_DBG_TRACE, "  Request is EMPTY.");
+    }
+}
+
+static void hbac_rule_element_debug_print(struct hbac_rule_element *el,
+                                          const char *label)
+{
+    HBAC_DEBUG(HBAC_DBG_TRACE, "      category [%#x] [%s]", el-&gt;category,
+               (el-&gt;category == HBAC_CATEGORY_ALL) ? "ALL" : "NONE");
+    if (el-&gt;names) {
+        if (el-&gt;names[0]) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_names:", label);
+            for (int i = 0; el-&gt;names[i]; i++) {
+                HBAC_DEBUG(HBAC_DBG_TRACE, "        [%s]", el-&gt;names[i]);
+            }
+        } else {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_names (none)", label);
+        }
+    }
+    if (el-&gt;groups) {
+        if (el-&gt;groups[0]) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "      %s_groups:", label);
+            for (int i = 0; el-&gt;groups[i]; i++) {
+                HBAC_DEBUG(HBAC_DBG_TRACE, "        [%s]", el-&gt;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-&gt;name, (rule-&gt;enabled) ? "ENABLED" : "DISABLED");
+        if (rule-&gt;services) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    services:");
+            hbac_rule_element_debug_print(rule-&gt;services, "services");
+        } else {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    services (none)");
+        }</pre>
      </div>
    </blockquote>
    could you add empty line here?<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+        if (rule-&gt;users) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    users:");
+            hbac_rule_element_debug_print(rule-&gt;users, "users");
+        } else {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    users (none)");
+        }</pre>
      </div>
    </blockquote>
    same here<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+        if (rule-&gt;targethosts) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    targethosts:");
+            hbac_rule_element_debug_print(rule-&gt;targethosts, "targethosts");
+        } else {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    targethosts (none)");
+        }</pre>
      </div>
    </blockquote>
    same here<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+        if (rule-&gt;srchosts) {
+            HBAC_DEBUG(HBAC_DBG_TRACE, "    srchosts:");
+            hbac_rule_element_debug_print(rule-&gt;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..55c79744a430969a84bafc4ae1ff46780b9701dc 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;</pre>
      </div>
    </blockquote>
    space after *<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
+
+    switch(level) {
+    case HBAC_DBG_FATAL:
+        loglevel = SSSDBG_FATAL_FAILURE;
+        break;
+    case HBAC_DBG_ERROR:
+        loglevel = SSSDBG_CRIT_FAILURE;
+        break;
+    case HBAC_DBG_WARNING:
+        loglevel = SSSDBG_OP_FAILURE;
+        break;
+    case HBAC_DBG_INFO:
+        loglevel = SSSDBG_MINOR_FAILURE;
+        break;
+    case HBAC_DBG_TRACE:
+        loglevel = SSSDBG_TRACE_ALL;
+        break;
+    }
+
+    va_list ap;
+    va_start(ap, fmt);
+    ret = vasprintf(&amp;message, fmt, ap);
+    va_end(ap);
+    if (ret &lt; 0) {
+        /* ENOMEM */
+        return;
+    }
+
+    if (DEBUG_IS_SET(loglevel)) {
+        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-&gt;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, &amp;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..f82f8dbb55c72bc1b011a87759c1bdb932cc2672 100644
--- a/src/providers/ipa/ipa_hbac.h
+++ b/src/providers/ipa/ipa_hbac.h
@@ -37,10 +37,33 @@
  * @{
  */
 
+#include &lt;stdio.h&gt;
+#include &lt;stdarg.h&gt;</pre>
      </div>
    </blockquote>
    are you sure that both headers have to be included here?<br>
    <blockquote cite="mid:55B265EA.5030107@redhat.com" type="cite">
      <div class="moz-text-plain" wrap="true" graphical-quote="true"
        style="font-family: -moz-fixed; font-size: 12px;"
        lang="x-western">
        <pre wrap="">
 #include &lt;stdint.h&gt;
 #include &lt;stdbool.h&gt;
 #include &lt;time.h&gt;
 
+/** Debug levels for HBAC. */
+enum hbac_debug_level {
+    HBAC_DBG_FATAL,
+    HBAC_DBG_ERROR,
+    HBAC_DBG_WARNING,
+    HBAC_DBG_INFO,
+    HBAC_DBG_TRACE
+};
+
+/**
+ *  HBAC uses external_debug_fn for logging messages.
+ *  @param[in|out] external_debug_void Pointer to external logging function.
+ *  Note: Internal HBAC logging function provides:
+ *        __FILE__ as file
+ *        __LINE__ as line
+ *        hbac_debug_level as level
+ *        format and ellipsis
+ */
+void hbac_enable_debug(void (<b class="moz-txt-star"><span class="moz-txt-tag">*</span>external_debug_fn)(const char<span class="moz-txt-tag">*</span></b> file, int line,
+                       enum hbac_debug_level level, const char* format, ...));
+
 /** Result of HBAC evaluation */
 enum hbac_eval_result {
     /** An error occurred
<div class="moz-txt-sig">-- 
2.4.3

</div></pre>
      </div>
    </blockquote>
    Petr I just quickly scrolled through the code and added some
    comments. I haven't tested the code yet, but  ci fails.<br>
    <br>
    ===================================<br>
       sssd 1.13.1: ./test-suite.log<br>
    ===================================<br>
    <br>
    # TOTAL: 72<br>
    # PASS:  71<br>
    # SKIP:  0<br>
    # XFAIL: 0<br>
    # FAIL:  0<br>
    # XPASS: 0<br>
    # ERROR: 1<br>
    <br>
    .. contents:: :depth: 2<br>
    <br>
    ERROR: ipa_hbac-tests<br>
    =====================<br>
    <br>
    Running suite(s): HBAC<br>
    100%: Checks: 9, Failures: 0, Errors: 0<br>
    ERROR ipa_hbac-tests (exit status: 99)<br>
    <br>
  </body>
</html>