[SSSD] [PATCH] Collect krb5 trace on high debug levels

Jakub Hrozek jhrozek at redhat.com
Tue Oct 9 17:15:00 UTC 2012


On Tue, Oct 02, 2012 at 10:53:54AM -0400, Stephen Gallagher wrote:
> On 10/02/2012 09:32 AM, Jakub Hrozek wrote:
> >https://fedorahosted.org/sssd/ticket/1539
> >
> >If the SSSD domain is running with SSSDBG_TRACE_ALL, then we also set
> >Kerberos tracing with krb5_set_trace_filename.
> >
> >There's one catch, though. The krb5_child and ldap_child logs are only
> >writable by root, but the krb5_child process drops privileges to the
> >user before priming his ccache. With this patch applied and debug_level
> >set to 10, the krb5_child process doesn't drop privileges..
> >
> >I personally think that's fine, because running with debug_level 10
> 
> SSSDBG_TRACE_ALL is actually level 9
> 
> >provides a LOT of debugging so it should only be configured for
> >debugging anyway. Also we don't drop privileges in other scenarios..
> >
> 
> Well, this really isn't acceptable. The reason we drop privileges is
> because that's the only way to create the credential cache with the
> proper ownership (and handle SELinux transitions).
> 
> 
> >I could maybe add a new param to the child or add heuristics to drop
> >privileges after the debugging is set but that seemed like an over
> >engineering when this feature is only useful for hardcode debugging.
> >
> >
> 
> I'd rather add a new debug level for this, if it's really the
> solution we're going to take, I want it to be called out in the
> manpage that if you set debug_level = 10 (or 0x8000) that you are
> accepting that the added debug information comes at a cost,
> specifically that it will result in unexpected behavior post-login
> (wrt access to the credential cache). Because this is now owned by
> root, it's nontrivial to restore access after this as well.
> 
> 
> I would much prefer finding a different way to do the logging;
> perhaps we could have the krb5_child log to krb5_child.$USER.log
> instead?

You're right, that wasn't my brightest patch.

I've checked the krb5 API again and used krb5_set_trace_callback() to
proxy krb5 tracing to our DEBUG macros.
-------------- next part --------------
>From 879ea2515047c53a49347cc402b4399aa82d9311 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhrozek at redhat.com>
Date: Tue, 9 Oct 2012 19:02:05 +0200
Subject: [PATCH 1/2] Two fixes to child processes

There was an unused structure member in the krb5_child.

Declaration of __krb5_error_msg was shadowing the same variable from
sss_krb5.h which is not nice. Also we might actually use the error
context directly instead of passing it as parameter.
---
 src/providers/krb5/krb5_child.c | 2 --
 src/providers/ldap/ldap_child.c | 9 +++++----
 2 files changed, 5 insertions(+), 6 deletions(-)

diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c
index b2d5bdaeb9d4b1ac8de12055a4d6bb5a7f48a7f1..a30636bc1bfc5d70728685778cf86b8dc348c88b 100644
--- a/src/providers/krb5/krb5_child.c
+++ b/src/providers/krb5/krb5_child.c
@@ -69,8 +69,6 @@ struct krb5_child_ctx {
     char *ccache_dir;
     char *ccname_template;
     int auth_timeout;
-
-    int child_debug_fd;
 };
 
 struct krb5_req {
diff --git a/src/providers/ldap/ldap_child.c b/src/providers/ldap/ldap_child.c
index 888a1249f2a12870e8f5d9fa6bc570d875b28cb8..35e0c0f5ba8ece4953f9c6047d9c1850eb01e8ba 100644
--- a/src/providers/ldap/ldap_child.c
+++ b/src/providers/ldap/ldap_child.c
@@ -35,12 +35,13 @@
 #include "providers/dp_backend.h"
 
 static krb5_context krb5_error_ctx;
+#define LDAP_CHILD_DEBUG(level, error) KRB5_DEBUG(level, krb5_error_ctx, error)
 
-static const char *__krb5_error_msg;
+static const char *__ldap_child_krb5_error_msg;
 #define KRB5_SYSLOG(krb5_error) do { \
-    __krb5_error_msg = sss_krb5_get_error_message(krb5_error_ctx, krb5_error); \
-    sss_log(SSS_LOG_ERR, "%s", __krb5_error_msg); \
-    sss_krb5_free_error_message(krb5_error_ctx, __krb5_error_msg); \
+    __ldap_child_krb5_error_msg = sss_krb5_get_error_message(krb5_error_ctx, krb5_error); \
+    sss_log(SSS_LOG_ERR, "%s", __ldap_child_krb5_error_msg); \
+    sss_krb5_free_error_message(krb5_error_ctx, __ldap_child_krb5_error_msg); \
 } while(0)
 
 struct input_buffer {
-- 
1.7.11.4

-------------- next part --------------
>From 6e0c2485de82fec0b1e6eff68eabb8c2d8a13d34 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhrozek at redhat.com>
Date: Tue, 9 Oct 2012 19:02:22 +0200
Subject: [PATCH 2/2] 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
---
 src/providers/krb5/krb5_child.c         | 25 ++++++++++++++++++++++++-
 src/providers/krb5/krb5_init_shared.c   |  2 +-
 src/providers/ldap/ldap_child.c         | 24 ++++++++++++++++++++++++
 src/providers/ldap/sdap_child_helpers.c |  2 +-
 src/util/sss_krb5.c                     | 12 ++++++++++++
 src/util/sss_krb5.h                     |  7 +++++++
 6 files changed, 69 insertions(+), 3 deletions(-)

diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c
index a30636bc1bfc5d70728685778cf86b8dc348c88b..23cad2192cfe93c781d35d17a02474b0fbb179bd 100644
--- a/src/providers/krb5/krb5_child.c
+++ b/src/providers/krb5/krb5_child.c
@@ -1608,6 +1608,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;
@@ -1674,7 +1693,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 7a014918462f7f25e1dc2644d3d9d24e208b7c37..312c695ea1c8b8e03701db4185ba6f168d80cc8b 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 35e0c0f5ba8ece4953f9c6047d9c1850eb01e8ba..de25fc073a674df02435987d50681b38db79ca20 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 5e86fce53bb823ead3ddd4fcbe0dbfe64fe87f8b..f2412f9e59a8ee3c6d1651b6b96ce2fd36c4fdd1 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 cce8d9021e9a3c7d8deb5328884b43bf38580721..0a80f23a8017a0aed245ca6a376a3d1fe6c8ca87 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 15dd1e6a6ac9ef826e2dde80fec76da7413cd7d7..708914c6c532ea9865b59e5eca1d224bc09d622e 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__ */
-- 
1.7.11.4



More information about the sssd-devel mailing list