s4:ldb Add additional tracing of the ldb API

This helps pin down where errors occour, by printing a call stack and
setting error strings and trace messages in the transaction case.

Andrew Bartlett

2 files changed, 80 insertions, 4 deletions

diff --git a/source4/lib/ldb/common/ldb.c b/source4/lib/ldb/common/ldb.c
index 59727d75d0..9be3aa13e4 100644
--- a/source4/lib/ldb/common/ldb.c
+++ b/source4/lib/ldb/common/ldb.c
@@ -288,6 +288,10 @@ void ldb_reset_err_string(struct ldb_context *ldb)
 #define FIRST_OP_NOERR(ldb, op) do { \
 	module = ldb->modules;					\
 	while (module && module->ops->op == NULL) module = module->next; \
+	if ((ldb->flags & LDB_FLG_ENABLE_TRACING) && module) { \
+		ldb_debug(ldb, LDB_DEBUG_TRACE, "ldb_trace_request: (%s)->" #op, \
+			  module->ops->name);				\
+	}								\
 } while (0)
 
 #define FIRST_OP(ldb, op) do { \
@@ -335,6 +339,10 @@ int ldb_transaction_start(struct ldb_context *ldb)
 				status);
 		}
 	}
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "start ldb transaction error: %s", 
+			  ldb_errstring(module->ldb));				
+	}
 	return status;
 }
 
@@ -383,6 +391,10 @@ int ldb_transaction_prepare_commit(struct ldb_context *ldb)
 					       ldb_strerror(status),
 					       status);
 		}
+		if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+			ldb_debug(module->ldb, LDB_DEBUG_TRACE, "prepare commit transaction error: %s", 
+				  ldb_errstring(module->ldb));				
+		}
 	}
 
 	return status;
@@ -432,6 +444,10 @@ int ldb_transaction_commit(struct ldb_context *ldb)
 				ldb_strerror(status),
 				status);
 		}
+		if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+			ldb_debug(module->ldb, LDB_DEBUG_TRACE, "commit ldb transaction error: %s", 
+				  ldb_errstring(module->ldb));				
+		}
 		/* cancel the transaction */
 		FIRST_OP(ldb, del_transaction);
 		module->ops->del_transaction(module);
@@ -477,6 +493,10 @@ int ldb_transaction_cancel(struct ldb_context *ldb)
 				ldb_strerror(status),
 				status);
 		}
+		if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+			ldb_debug(module->ldb, LDB_DEBUG_TRACE, "cancel ldb transaction error: %s", 
+				  ldb_errstring(module->ldb));				
+		}
 	}
 	return status;
 }
diff --git a/source4/lib/ldb/common/ldb_modules.c b/source4/lib/ldb/common/ldb_modules.c
index 69b8ed0bf4..e79f072d50 100644
--- a/source4/lib/ldb/common/ldb_modules.c
+++ b/source4/lib/ldb/common/ldb_modules.c
@@ -481,6 +481,10 @@ int ldb_load_modules(struct ldb_context *ldb, const char *options[])
 #define FIND_OP_NOERR(module, op) do { \
 	module = module->next; \
 	while (module && module->ops->op == NULL) module = module->next; \
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { \
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "ldb_trace_next_request: (%s)->" #op, \
+			  module->ops->name);				\
+	}								\
 } while (0)
 
 #define FIND_OP(module, op) do { \
@@ -611,31 +615,83 @@ int ldb_next_init(struct ldb_module *module)
 
 int ldb_next_start_trans(struct ldb_module *module)
 {
+	int ret;
 	FIND_OP(module, start_transaction);
-	return module->ops->start_transaction(module);
+	ret = module->ops->start_transaction(module);
+	if (ret == LDB_SUCCESS) {
+		return ret;
+	}
+	if (!ldb_errstring(module->ldb)) {
+		/* Set a default error string, to place the blame somewhere */
+		ldb_asprintf_errstring(module->ldb, "start_trans error in module %s: %s (%d)", module->ops->name, ldb_strerror(ret), ret);
+	}
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "ldb_next_start_trans error: %s", 
+			  ldb_errstring(module->ldb));				
+	}
+	return ret;
 }
 
 int ldb_next_end_trans(struct ldb_module *module)
 {
+	int ret;
 	FIND_OP(module, end_transaction);
-	return module->ops->end_transaction(module);
+	ret = module->ops->end_transaction(module);
+	if (ret == LDB_SUCCESS) {
+		return ret;
+	}
+	if (!ldb_errstring(module->ldb)) {
+		/* Set a default error string, to place the blame somewhere */
+		ldb_asprintf_errstring(module->ldb, "end_trans error in module %s: %s (%d)", module->ops->name, ldb_strerror(ret), ret);
+	}
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "ldb_next_end_trans error: %s", 
+			  ldb_errstring(module->ldb));				
+	}
+	return ret;
 }
 
 int ldb_next_prepare_commit(struct ldb_module *module)
 {
+	int ret;
 	FIND_OP_NOERR(module, prepare_commit);
 	if (module == NULL) {
 		/* we are allowed to have no prepare commit in
 		   backends */
 		return LDB_SUCCESS;
 	}
-	return module->ops->prepare_commit(module);
+	ret = module->ops->prepare_commit(module);
+	if (ret == LDB_SUCCESS) {
+		return ret;
+	}
+	if (!ldb_errstring(module->ldb)) {
+		/* Set a default error string, to place the blame somewhere */
+		ldb_asprintf_errstring(module->ldb, "prepare_commit error in module %s: %s (%d)", module->ops->name, ldb_strerror(ret), ret);
+	}
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "ldb_next_prepare_commit error: %s", 
+			  ldb_errstring(module->ldb));				
+	}
+	return ret;
 }
 
 int ldb_next_del_trans(struct ldb_module *module)
 {
+	int ret;
 	FIND_OP(module, del_transaction);
-	return module->ops->del_transaction(module);
+	ret = module->ops->del_transaction(module);
+	if (ret == LDB_SUCCESS) {
+		return ret;
+	}
+	if (!ldb_errstring(module->ldb)) {
+		/* Set a default error string, to place the blame somewhere */
+		ldb_asprintf_errstring(module->ldb, "del_trans error in module %s: %s (%d)", module->ops->name, ldb_strerror(ret), ret);
+	}
+	if ((module && module->ldb->flags & LDB_FLG_ENABLE_TRACING)) { 
+		ldb_debug(module->ldb, LDB_DEBUG_TRACE, "ldb_next_del_trans error: %s", 
+			  ldb_errstring(module->ldb));				
+	}
+	return ret;
 }
 
 struct ldb_handle *ldb_handle_new(TALLOC_CTX *mem_ctx, struct ldb_context *ldb)