On Mon, 2014-04-28 at 21:35 +0200, Jakub Hrozek wrote:
> On Mon, Apr 28, 2014 at 01:55:00PM +0200, Pavel Reichl wrote:
> > On Thu, 2014-04-17 at 17:30 +0200, Jakub Hrozek wrote:
> > > On Tue, Apr 15, 2014 at 04:25:50PM +0200, Pavel Reichl wrote:
> > > > Hello,
> > > > 
> > > > some more generally useful logging messages are needed for that
> > > > bugzilla.
> > > > 
> > > > Patches for both master and 1.11 are attached.
> > > > 
> > > > Thanks for review!
> > > 
> > > It would be nice to explain in the commit message why you used TRACE_LIBS
> > > for the messages and not i.e OP_FAILURE.
> > > 
> > > > 
> > > > On Wed, 2014-04-09 at 14:29 +0200, Pavel Reichl wrote:
> > > > > Hello, 
> > > > > 
> > > > > please see attached patch. 
> > > > > 
> > > > > This patch was previously written for BZ 1059423. But it now seems 
> > > > > that
> > > > > more detailed logging information is generally useful for issues that
> > > > > are emerging from this area lately.
> > > > > 
> > > > > Pavel Reichl
> > > > 
> > > > 
> > > 
> > > > From e7e4a06098bce4df600370274babe470b0d71c47 Mon Sep 17 00:00:00 2001
> > > > From: Pavel Reichl <[email protected]>
> > > > Date: Mon, 14 Apr 2014 17:27:23 +0100
> > > > Subject: [PATCH] SDAP: augmented logging when adding new group
> > > > 
> > > > Resolves:
> > > >     https://fedorahosted.org/sssd/ticket/2239
> 
> ACK for master.
> 
> I would like a 1.11 version personally.
> _______________________________________________
> sssd-devel mailing list
> [email protected]
> https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
OK, patches attached.

>From 47c158c3dbd63d71a7372823b9d74da252478498 Mon Sep 17 00:00:00 2001
From: Pavel Reichl <[email protected]>
Date: Mon, 14 Apr 2014 17:27:23 +0100
Subject: [PATCH] SYSDB: augmented logging when adding new group

This patch adds some more log messages to functionality of storing groups into
sysdb. As these functions are low level and failures are often handled on
higher levels the commonly chosen level is SSSDBG_TRACE_LIBS.

Resolves:
    https://fedorahosted.org/sssd/ticket/2239
---
 src/db/sysdb_ops.c                     | 96 +++++++++++++++++++++++++++++-----
 src/providers/ldap/sdap_async_groups.c |  2 +-
 2 files changed, 83 insertions(+), 15 deletions(-)

diff --git a/src/db/sysdb_ops.c b/src/db/sysdb_ops.c
index 95354d98806a13cf142705dc304b7810b8ee82f4..f619aaee587b08548ea16359aaf37bb43dcf8ddb 100644
--- a/src/db/sysdb_ops.c
+++ b/src/db/sysdb_ops.c
@@ -1428,7 +1428,15 @@ int sysdb_add_group(struct sysdb_ctx *sysdb,
         ret = sysdb_search_user_by_name(tmp_ctx, sysdb, domain,
                                         name, NULL, &msg);
         if (ret != ENOENT) {
-            if (ret == EOK) ret = EEXIST;
+            if (ret == EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS, ("MPG domain contains a user "
+                                          "with the same name - %s.\n", name));
+                ret = EEXIST;
+            } else {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      ("sysdb_search_user_by_name failed for user %s.\n",
+                       name));
+            }
             goto done;
         }
     }
@@ -1438,18 +1446,33 @@ int sysdb_add_group(struct sysdb_ctx *sysdb,
         ret = sysdb_search_group_by_gid(tmp_ctx, sysdb, domain,
                                         gid, NULL, &msg);
         if (ret != ENOENT) {
-            if (ret == EOK) ret = EEXIST;
+            if (ret == EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      ("Group with the same gid exists: [%"SPRIgid"].\n",
+                       gid));
+                ret = EEXIST;
+            } else {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      ("sysdb_search_group_by_gid failed for gid: "
+                       "[%"SPRIgid"].\n", gid));
+            }
             goto done;
         }
     }
 
     /* try to add the group */
     ret = sysdb_add_basic_group(sysdb, domain, name, gid);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS,
+              ("sysdb_add_basic_group failed for: %s with gid: "
+               "[%"SPRIgid"].\n", name, gid));
+        goto done;
+    }
 
     if (!attrs) {
         attrs = sysdb_new_attrs(tmp_ctx);
         if (!attrs) {
+            DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_new_attrs failed.\n"));
             ret = ENOMEM;
             goto done;
         }
@@ -1459,17 +1482,27 @@ int sysdb_add_group(struct sysdb_ctx *sysdb,
     if (ret == ENOENT) {
         posix = true;
         ret = sysdb_attrs_add_bool(attrs, SYSDB_POSIX, true);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add posix attribute.\n"));
+            goto done;
+        }
     } else if (ret != EOK) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Failed to get posix attribute.\n"));
         goto done;
     }
 
     if (posix && gid == 0) {
         ret = sysdb_get_new_id(sysdb, domain, &id);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_get_new_id failed.\n"));
+            goto done;
+        }
 
         ret = sysdb_attrs_add_uint32(attrs, SYSDB_GIDNUM, id);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add new gid.\n"));
+            goto done;
+        }
     }
 
     if (!now) {
@@ -1477,14 +1510,24 @@ int sysdb_add_group(struct sysdb_ctx *sysdb,
     }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_LAST_UPDATE, now);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add sysdb-last-update.\n"));
+        goto done;
+    }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_CACHE_EXPIRE,
                                  ((cache_timeout) ?
                                   (now + cache_timeout) : 0));
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add sysdb-cache-expire.\n"));
+        goto done;
+    }
 
     ret = sysdb_set_group_attr(sysdb, domain, name, attrs, SYSDB_MOD_REP);
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_set_group_attr failed.\n"));
+        goto done;
+    }
 
 done:
     if (ret == EOK) {
@@ -1932,6 +1975,7 @@ int sysdb_store_group(struct sysdb_ctx *sysdb,
         goto done;
     }
     if (ret == ENOENT) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Group %s does not exist.\n", name));
         new_group = true;
     }
 
@@ -1959,20 +2003,31 @@ int sysdb_store_group(struct sysdb_ctx *sysdb,
             /* This may be a group rename. If there is a group with the
              * same GID, remove it and try to add the basic group again
              */
+            DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_add_group failed: [EEXIST].\n"));
             ret = sysdb_delete_group(sysdb, domain, NULL, gid);
             if (ret == ENOENT) {
                 /* Not found by GID, return the original EEXIST,
                  * this may be a conflict in MPG domain or something
                  * else */
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      ("sysdb_delete_group failed (while renaming group). Not "
+                       "found by gid: [%"SPRIgid"].\n", gid));
                 return EEXIST;
             } else if (ret != EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_add_group failed.\n"));
                 goto done;
             }
             DEBUG(SSSDBG_MINOR_FAILURE,
-                  ("A group with the same GID [%llu] was removed from the "
-                   "cache\n", (unsigned long long) gid));
+                  ("A group with the same GID [%"SPRIgid"] was removed from "
+                   "the cache\n", gid));
+
             ret = sysdb_add_group(sysdb, domain, name, gid,
                                   attrs, cache_timeout, now);
+            if (ret) {
+                DEBUG(SSSDBG_MINOR_FAILURE,
+                      ("sysdb_add_group failed (while renaming group) for: "
+                       "%s [%"SPRIgid"].\n", name, gid));
+            }
         }
         goto done;
     }
@@ -1980,18 +2035,31 @@ int sysdb_store_group(struct sysdb_ctx *sysdb,
     /* the group exists, let's just replace attributes when set */
     if (gid) {
         ret = sysdb_attrs_add_uint32(attrs, SYSDB_GIDNUM, gid);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add GID.\n"));
+            goto done;
+        }
     }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_LAST_UPDATE, now);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add sysdb-last-update.\n"));
+        goto done;
+    }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_CACHE_EXPIRE,
                                  ((cache_timeout) ?
                                   (now + cache_timeout) : 0));
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("Failed to add sysdb-cache-expire.\n"));
+        goto done;
+    }
 
     ret = sysdb_set_group_attr(sysdb, domain, name, attrs, SYSDB_MOD_REP);
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, ("sysdb_set_group_attr failed.\n"));
+        goto done;
+    }
 
 done:
     if (ret) {
@@ -3146,7 +3214,7 @@ int sysdb_cache_auth(struct sysdb_ctx *sysdb,
                                      SYSDB_LAST_FAILED_LOGIN,
                                      time(NULL));
         if (ret != EOK) {
-            DEBUG(3, ("sysdb_attrs_add_time_t failed\n."));
+            DEBUG(3, ("sysdb_attrs_add_time_t failed.\n"));
             goto done;
         }
 
diff --git a/src/providers/ldap/sdap_async_groups.c b/src/providers/ldap/sdap_async_groups.c
index 129fb3e6cfc31ea0b2b757e3378b1bbd37bbdba2..813d1944e7d28e932a05af55c4935fbd60f716e6 100644
--- a/src/providers/ldap/sdap_async_groups.c
+++ b/src/providers/ldap/sdap_async_groups.c
@@ -246,7 +246,7 @@ static int sdap_fill_memberships(struct sdap_options *opts,
             }
             if (ret != EOK) {
                 DEBUG(SSSDBG_MINOR_FAILURE,
-                      ("'sdap_find_entry_by_origDN' failed for member [%s] ",
+                      ("'sdap_find_entry_by_origDN' failed for member [%s].\n",
                       (char *)values[i].data));
                 goto done;
             }
-- 
1.8.4.2

>From 97b1deafd63c9ce54f55d4bba0e44d352fc938e0 Mon Sep 17 00:00:00 2001
From: Pavel Reichl <[email protected]>
Date: Mon, 14 Apr 2014 17:27:23 +0100
Subject: [PATCH] SYSDB: augmented logging when adding new group

This patch adds some more log messages to functionality of storing groups into
sysdb. As these functions are low level and failures are often handled on
higher levels the commonly chosen level is SSSDBG_TRACE_LIBS.

Resolves:
    https://fedorahosted.org/sssd/ticket/2239
---
 src/db/sysdb_ops.c                     | 93 +++++++++++++++++++++++++++++-----
 src/providers/ldap/sdap_async_groups.c |  4 +-
 2 files changed, 81 insertions(+), 16 deletions(-)

diff --git a/src/db/sysdb_ops.c b/src/db/sysdb_ops.c
index 1f51b9682f11b04f1e40677eb26982c300a1687f..3536d8724343012a5673c492ed3b33f159354321 100644
--- a/src/db/sysdb_ops.c
+++ b/src/db/sysdb_ops.c
@@ -1417,7 +1417,14 @@ int sysdb_add_group(struct sss_domain_info *domain,
 
         ret = sysdb_search_user_by_name(tmp_ctx, domain, name, NULL, &msg);
         if (ret != ENOENT) {
-            if (ret == EOK) ret = EEXIST;
+            if (ret == EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS, "MPG domain contains a user "
+                      "with the same name - %s.\n", name);
+                ret = EEXIST;
+            } else {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      "sysdb_search_user_by_name failed for user %s.\n", name);
+            }
             goto done;
         }
     }
@@ -1426,18 +1433,32 @@ int sysdb_add_group(struct sss_domain_info *domain,
     if (gid != 0) {
         ret = sysdb_search_group_by_gid(tmp_ctx, domain, gid, NULL, &msg);
         if (ret != ENOENT) {
-            if (ret == EOK) ret = EEXIST;
+            if (ret == EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      "Group with the same gid exists: [%"SPRIgid"].\n", gid);
+                ret = EEXIST;
+            } else {
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      "sysdb_search_group_by_gid failed for gid: "
+                      "[%"SPRIgid"].\n", gid);
+            }
             goto done;
         }
     }
 
     /* try to add the group */
     ret = sysdb_add_basic_group(domain, name, gid);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS,
+              "sysdb_add_basic_group failed for: %s with gid: "
+              "[%"SPRIgid"].\n", name, gid);
+        goto done;
+    }
 
     if (!attrs) {
         attrs = sysdb_new_attrs(tmp_ctx);
         if (!attrs) {
+            DEBUG(SSSDBG_TRACE_LIBS, "sysdb_new_attrs failed.\n");
             ret = ENOMEM;
             goto done;
         }
@@ -1447,17 +1468,27 @@ int sysdb_add_group(struct sss_domain_info *domain,
     if (ret == ENOENT) {
         posix = true;
         ret = sysdb_attrs_add_bool(attrs, SYSDB_POSIX, true);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, "Failed to add posix attribute.\n");
+            goto done;
+        }
     } else if (ret != EOK) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Failed to get posix attribute.\n");
         goto done;
     }
 
     if (posix && gid == 0) {
         ret = sysdb_get_new_id(domain, &id);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, "sysdb_get_new_id failed.\n");
+            goto done;
+        }
 
         ret = sysdb_attrs_add_uint32(attrs, SYSDB_GIDNUM, id);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, "Failed to add new gid.\n");
+            goto done;
+        }
     }
 
     if (!now) {
@@ -1465,14 +1496,24 @@ int sysdb_add_group(struct sss_domain_info *domain,
     }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_LAST_UPDATE, now);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Failed to add sysdb-last-update.\n");
+        goto done;
+    }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_CACHE_EXPIRE,
                                  ((cache_timeout) ?
                                   (now + cache_timeout) : 0));
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Failed to add sysdb-cache-expire.\n");
+        goto done;
+    }
 
     ret = sysdb_set_group_attr(domain, name, attrs, SYSDB_MOD_REP);
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "sysdb_set_group_attr failed.\n");
+        goto done;
+    }
 
 done:
     if (ret == EOK) {
@@ -1915,6 +1956,7 @@ int sysdb_store_group(struct sss_domain_info *domain,
         goto done;
     }
     if (ret == ENOENT) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Group %s does not exist.\n", name);
         new_group = true;
     }
 
@@ -1942,20 +1984,30 @@ int sysdb_store_group(struct sss_domain_info *domain,
             /* This may be a group rename. If there is a group with the
              * same GID, remove it and try to add the basic group again
              */
+            DEBUG(SSSDBG_TRACE_LIBS, "sysdb_add_group failed: [EEXIST].\n");
             ret = sysdb_delete_group(domain, NULL, gid);
             if (ret == ENOENT) {
                 /* Not found by GID, return the original EEXIST,
                  * this may be a conflict in MPG domain or something
                  * else */
+                DEBUG(SSSDBG_TRACE_LIBS,
+                      "sysdb_delete_group failed (while renaming group). Not "
+                      "found by gid: [%"SPRIgid"].\n", gid);
                 return EEXIST;
             } else if (ret != EOK) {
+                DEBUG(SSSDBG_TRACE_LIBS, "sysdb_add_group failed.\n");
                 goto done;
             }
             DEBUG(SSSDBG_MINOR_FAILURE,
-                  "A group with the same GID [%llu] was removed from the "
-                   "cache\n", (unsigned long long) gid);
+                  "A group with the same GID [%"SPRIgid"] was removed from "
+                  "the cache\n", gid);
             ret = sysdb_add_group(domain, name, gid, attrs, cache_timeout,
                                   now);
+            if (ret) {
+                DEBUG(SSSDBG_MINOR_FAILURE,
+                      "sysdb_add_group failed (while renaming group) for: "
+                      "%s [%"SPRIgid"].\n", name, gid);
+            }
         }
         goto done;
     }
@@ -1963,18 +2015,31 @@ int sysdb_store_group(struct sss_domain_info *domain,
     /* the group exists, let's just replace attributes when set */
     if (gid) {
         ret = sysdb_attrs_add_uint32(attrs, SYSDB_GIDNUM, gid);
-        if (ret) goto done;
+        if (ret) {
+            DEBUG(SSSDBG_TRACE_LIBS, "Failed to add GID.\n");
+            goto done;
+        }
     }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_LAST_UPDATE, now);
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Failed to add sysdb-last-update.\n");
+        goto done;
+    }
 
     ret = sysdb_attrs_add_time_t(attrs, SYSDB_CACHE_EXPIRE,
                                  ((cache_timeout) ?
                                   (now + cache_timeout) : 0));
-    if (ret) goto done;
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "Failed to add sysdb-cache-expire.\n");
+        goto done;
+    }
 
     ret = sysdb_set_group_attr(domain, name, attrs, SYSDB_MOD_REP);
+    if (ret) {
+        DEBUG(SSSDBG_TRACE_LIBS, "sysdb_set_group_attr failed.\n");
+        goto done;
+    }
 
 done:
     if (ret) {
@@ -3112,7 +3177,7 @@ int sysdb_cache_auth(struct sss_domain_info *domain,
                                      SYSDB_LAST_FAILED_LOGIN,
                                      time(NULL));
         if (ret != EOK) {
-            DEBUG(SSSDBG_MINOR_FAILURE, "sysdb_attrs_add_time_t failed\n.");
+            DEBUG(SSSDBG_MINOR_FAILURE, "sysdb_attrs_add_time_t failed.\n");
             goto done;
         }
 
diff --git a/src/providers/ldap/sdap_async_groups.c b/src/providers/ldap/sdap_async_groups.c
index 4240bb585d57a80199d040ac44891ee1b6429e05..cb70aa01e5e94f6af2898e85a1712b61a6f3e2ee 100644
--- a/src/providers/ldap/sdap_async_groups.c
+++ b/src/providers/ldap/sdap_async_groups.c
@@ -246,8 +246,8 @@ static int sdap_fill_memberships(struct sdap_options *opts,
             }
             if (ret != EOK) {
                 DEBUG(SSSDBG_MINOR_FAILURE,
-                      "'sdap_find_entry_by_origDN' failed for member [%s] ",
-                       (char *)values[i].data);
+                      "'sdap_find_entry_by_origDN' failed for member [%s].\n",
+                      (char *)values[i].data);
                 goto done;
             }
 
-- 
1.8.4.2

_______________________________________________
sssd-devel mailing list
[email protected]
https://lists.fedorahosted.org/mailman/listinfo/sssd-devel

Reply via email to