Collect krb5 trace on high debug levels

If the debug level contains SSSDBG_TRACE_ALL, then the logs would also
include tracing information from libkrb5.

https://fedorahosted.org/sssd/ticket/1539

6 files changed, 69 insertions, 3 deletions

diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c
index 0116dbb70..cd826add0 100644
--- a/src/providers/krb5/krb5_child.c
+++ b/src/providers/krb5/krb5_child.c
@@ -1616,6 +1616,25 @@ done:
     return kerr;
 }
 
+static errno_t
+set_child_debugging(krb5_context ctx)
+{
+    krb5_error_code kerr;
+
+    /* Set the global error context */
+    krb5_error_ctx = ctx;
+
+    if (debug_level & SSSDBG_TRACE_ALL) {
+        kerr = krb5_set_trace_callback(ctx, sss_child_krb5_trace_cb, NULL);
+        if (kerr) {
+            KRB5_CHILD_DEBUG(SSSDBG_MINOR_FAILURE, kerr);
+            return EIO;
+        }
+    }
+
+    return EOK;
+}
+
 static int krb5_child_setup(struct krb5_req *kr, uint32_t offline)
 {
     krb5_error_code kerr = 0;
@@ -1682,7 +1701,11 @@ static int krb5_child_setup(struct krb5_req *kr, uint32_t offline)
         KRB5_CHILD_DEBUG(SSSDBG_CRIT_FAILURE, kerr);
         goto failed;
     }
-    krb5_error_ctx = kr->ctx;
+
+    kerr = set_child_debugging(kr->ctx);
+    if (kerr != EOK) {
+        DEBUG(SSSDBG_MINOR_FAILURE, ("Cannot set krb5_child debugging\n"));
+    }
 
     kerr = krb5_parse_name(kr->ctx, kr->upn, &kr->princ);
     if (kerr != 0) {
diff --git a/src/providers/krb5/krb5_init_shared.c b/src/providers/krb5/krb5_init_shared.c
index 7a0149184..312c695ea 100644
--- a/src/providers/krb5/krb5_init_shared.c
+++ b/src/providers/krb5/krb5_init_shared.c
@@ -71,7 +71,7 @@ errno_t krb5_child_init(struct krb5_ctx *krb5_auth_ctx,
     }
 
     if (debug_to_file != 0) {
-        ret = open_debug_file_ex("krb5_child", &debug_filep);
+        ret = open_debug_file_ex(KRB5_CHILD_LOG_FILE, &debug_filep);
         if (ret != EOK) {
             DEBUG(0, ("Error setting up logging (%d) [%s]\n",
                     ret, strerror(ret)));
diff --git a/src/providers/ldap/ldap_child.c b/src/providers/ldap/ldap_child.c
index 35e0c0f5b..de25fc073 100644
--- a/src/providers/ldap/ldap_child.c
+++ b/src/providers/ldap/ldap_child.c
@@ -141,6 +141,25 @@ static int pack_buffer(struct response *r, int result, krb5_error_code krberr,
     return EOK;
 }
 
+static errno_t
+set_child_debugging(krb5_context ctx)
+{
+    krb5_error_code kerr;
+
+    /* Set the global error context */
+    krb5_error_ctx = ctx;
+
+    if (debug_level & SSSDBG_TRACE_ALL) {
+        kerr = krb5_set_trace_callback(ctx, sss_child_krb5_trace_cb, NULL);
+        if (kerr) {
+            LDAP_CHILD_DEBUG(SSSDBG_MINOR_FAILURE, kerr);
+            return EIO;
+        }
+    }
+
+    return EOK;
+}
+
 static krb5_error_code ldap_child_get_tgt_sync(TALLOC_CTX *memctx,
                                                const char *realm_str,
                                                const char *princ_str,
@@ -173,6 +192,11 @@ static krb5_error_code ldap_child_get_tgt_sync(TALLOC_CTX *memctx,
     }
     DEBUG(SSSDBG_TRACE_INTERNAL, ("Kerberos context initialized\n"));
 
+    krberr = set_child_debugging(context);
+    if (krberr != EOK) {
+        DEBUG(SSSDBG_MINOR_FAILURE, ("Cannot set krb5_child debugging\n"));
+    }
+
     if (!realm_str) {
         krberr = krb5_get_default_realm(context, &default_realm);
         if (krberr) {
diff --git a/src/providers/ldap/sdap_child_helpers.c b/src/providers/ldap/sdap_child_helpers.c
index 5e86fce53..f2412f9e5 100644
--- a/src/providers/ldap/sdap_child_helpers.c
+++ b/src/providers/ldap/sdap_child_helpers.c
@@ -457,7 +457,7 @@ int setup_child(struct sdap_id_ctx *ctx)
     FILE *debug_filep;
 
     if (debug_to_file != 0 && ldap_child_debug_fd == -1) {
-        ret = open_debug_file_ex("ldap_child", &debug_filep);
+        ret = open_debug_file_ex(LDAP_CHILD_LOG_FILE, &debug_filep);
         if (ret != EOK) {
             DEBUG(0, ("Error setting up logging (%d) [%s]\n",
                         ret, strerror(ret)));
diff --git a/src/util/sss_krb5.c b/src/util/sss_krb5.c
index cce8d9021..0a80f23a8 100644
--- a/src/util/sss_krb5.c
+++ b/src/util/sss_krb5.c
@@ -963,3 +963,15 @@ sss_krb5_residual_check_type(const char *full_location,
 
     return sss_krb5_residual_by_type(full_location, type);
 }
+
+void
+sss_child_krb5_trace_cb(krb5_context context,
+                        const struct krb5_trace_info *info, void *data)
+{
+    if (info == NULL) {
+        /* Null info means destroy the callback data. */
+        return;
+    }
+
+    DEBUG(SSSDBG_TRACE_ALL, ("%s\n", info->message));
+}
diff --git a/src/util/sss_krb5.h b/src/util/sss_krb5.h
index 15dd1e6a6..708914c6c 100644
--- a/src/util/sss_krb5.h
+++ b/src/util/sss_krb5.h
@@ -34,6 +34,9 @@
 
 #include "util/util.h"
 
+#define KRB5_CHILD_LOG_FILE     "krb5_child"
+#define LDAP_CHILD_LOG_FILE     "ldap_child"
+
 /* MIT Kerberos has the same hardcoded warning interval of 7 days. Due to the
  * fact that using the expiration time of a Kerberos password with LDAP
  * authentication is presumably a rare case a separate config option is not
@@ -164,4 +167,8 @@ typedef krb5_ticket_times sss_krb5_ticket_times;
 typedef krb5_times sss_krb5_ticket_times;
 #endif
 
+void
+sss_child_krb5_trace_cb(krb5_context context,
+                        const struct krb5_trace_info *info, void *data);
+
 #endif /* __SSS_KRB5_H__ */