From 49dbc9e1b4075575940fdecd8a403c9b75888c8c Mon Sep 17 00:00:00 2001 From: Joseph Sutton Date: Thu, 26 Aug 2021 21:18:26 +1200 Subject: [PATCH 1/7] CVE-2021-3670 tests/krb5/test_ldap.py: Add test for LDAP timeouts We allow a timeout of 2x over to avoid this being a flapping test. Samba is not very accurate on the timeout, which is not otherwise an issue but makes this test fail sometimes. BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Joseph Sutton Reviewed-by: Douglas Bagnall --- selftest/knownfail.d/ldap-timeout | 1 + source4/dsdb/tests/python/large_ldap.py | 63 +++++++++++++++++++++++++ 2 files changed, 64 insertions(+) create mode 100644 selftest/knownfail.d/ldap-timeout diff --git a/selftest/knownfail.d/ldap-timeout b/selftest/knownfail.d/ldap-timeout new file mode 100644 index 00000000000..378ca1f4821 --- /dev/null +++ b/selftest/knownfail.d/ldap-timeout @@ -0,0 +1 @@ +samba4.ldap.large_ldap\..*\.python\(.*\).__main__.LargeLDAPTest.test_timeout\(.*\) \ No newline at end of file diff --git a/source4/dsdb/tests/python/large_ldap.py b/source4/dsdb/tests/python/large_ldap.py index 0bf73f988d8..f1fc13939e5 100644 --- a/source4/dsdb/tests/python/large_ldap.py +++ b/source4/dsdb/tests/python/large_ldap.py @@ -23,6 +23,7 @@ import optparse import sys import os import random +import time sys.path.insert(0, "bin/python") import samba @@ -244,6 +245,68 @@ class LargeLDAPTest(samba.tests.TestCase): # Assert we don't get all the entries but still the error self.assertGreater(count, count_jpeg) + def test_timeout(self): + policy_dn = ldb.Dn(self.ldb, + 'CN=Default Query Policy,CN=Query-Policies,' + 'CN=Directory Service,CN=Windows NT,CN=Services,' + f'{self.ldb.get_config_basedn().get_linearized()}') + + # Get the current value of lDAPAdminLimits. + res = self.ldb.search(base=policy_dn, + scope=ldb.SCOPE_BASE, + attrs=['lDAPAdminLimits']) + msg = res[0] + admin_limits = msg['lDAPAdminLimits'] + + # Ensure we restore the previous value of the attribute. + admin_limits.set_flags(ldb.FLAG_MOD_REPLACE) + self.addCleanup(self.ldb.modify, msg) + + # Temporarily lower the value of MaxQueryDuration so we can test + # timeout behaviour. + timeout = 5 + query_duration = f'MaxQueryDuration={timeout}'.encode() + + admin_limits = [limit for limit in admin_limits + if not limit.lower().startswith(b'maxqueryduration=')] + admin_limits.append(query_duration) + + # Set the new attribute value. + msg = ldb.Message(policy_dn) + msg['lDAPAdminLimits'] = ldb.MessageElement(admin_limits, + ldb.FLAG_MOD_REPLACE, + 'lDAPAdminLimits') + self.ldb.modify(msg) + + # Use a new connection so that the limits are reloaded. + samdb = SamDB(url, credentials=creds, + session_info=system_session(lp), + lp=lp) + + # Create a large search expression that will take a long time to + # evaluate. + expression = '(anr=l)' * 10000 + expression = f'(|{expression})' + + # Perform the LDAP search. + prev = time.time() + with self.assertRaises(ldb.LdbError) as err: + samdb.search(base=self.ou_dn, + scope=ldb.SCOPE_SUBTREE, + expression=expression, + attrs=['objectGUID']) + now = time.time() + duration = now - prev + + # Ensure that we timed out. + enum, _ = err.exception.args + self.assertEqual(ldb.ERR_TIME_LIMIT_EXCEEDED, enum) + + # Ensure that the time spent searching is within the limit we + # set. We allow a margin of 100% over as the Samba timeout + # handling is not very accurate (and does not need to be) + self.assertLess(timeout - 1, duration) + self.assertLess(duration, timeout * 2) if "://" not in url: -- 2.25.1 From 9abc0802f80430da2f23bcd3763b09be3677339b Mon Sep 17 00:00:00 2001 From: Joseph Sutton Date: Thu, 26 Aug 2021 13:53:23 +1200 Subject: [PATCH 2/7] CVE-2021-3670 ldap_server: Set timeout on requests based on MaxQueryDuration BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Joseph Sutton Reviewed-by: Douglas Bagnall --- source4/ldap_server/ldap_backend.c | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/source4/ldap_server/ldap_backend.c b/source4/ldap_server/ldap_backend.c index e19f82cf5df..c7405f66643 100644 --- a/source4/ldap_server/ldap_backend.c +++ b/source4/ldap_server/ldap_backend.c @@ -869,7 +869,17 @@ static NTSTATUS ldapsrv_SearchRequest(struct ldapsrv_call *call) } } - ldb_set_timeout(samdb, lreq, req->timelimit); + { + time_t timeout = call->conn->limits.search_timeout; + + if (timeout == 0 + || (req->timelimit != 0 + && req->timelimit < timeout)) + { + timeout = req->timelimit; + } + ldb_set_timeout(samdb, lreq, timeout); + } if (!call->conn->is_privileged) { ldb_req_mark_untrusted(lreq); -- 2.25.1 From fb7dd6def431d711b2ec49273cc26fc43e4bca1f Mon Sep 17 00:00:00 2001 From: Joseph Sutton Date: Tue, 28 Sep 2021 17:20:43 +1300 Subject: [PATCH 3/7] CVE-2021-3670 ldap_server: Ensure value of MaxQueryDuration is greater than zero BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Joseph Sutton Reviewed-by: Douglas Bagnall --- source4/ldap_server/ldap_server.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/source4/ldap_server/ldap_server.c b/source4/ldap_server/ldap_server.c index ce4fd4f41d6..fbea5859756 100644 --- a/source4/ldap_server/ldap_server.c +++ b/source4/ldap_server/ldap_server.c @@ -255,7 +255,9 @@ static int ldapsrv_load_limits(struct ldapsrv_connection *conn) continue; } if (strcasecmp("MaxQueryDuration", policy_name) == 0) { - conn->limits.search_timeout = policy_value; + if (policy_value > 0) { + conn->limits.search_timeout = policy_value; + } continue; } } -- 2.25.1 From d2f8f005e85b2ccee6aaab4a44368a79176aae8e Mon Sep 17 00:00:00 2001 From: Andrew Bartlett Date: Mon, 27 Sep 2021 16:47:46 +1300 Subject: [PATCH 4/7] CVE-2021-3670 ldb: Confirm the request has not yet timed out in ldb filter processing The LDB filter processing is where the time is spent in the LDB stack but the timeout event will not get run while this is ongoing, so we must confirm we have not yet timed out manually. RN: Ensure that the LDB request has not timed out during filter processing as the LDAP server MaxQueryDuration is otherwise not honoured. BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Andrew Bartlett Reviewed-by: Douglas Bagnall --- lib/ldb/ldb_key_value/ldb_kv.c | 2 ++ lib/ldb/ldb_key_value/ldb_kv.h | 10 +++++++ lib/ldb/ldb_key_value/ldb_kv_index.c | 41 +++++++++++++++++++++++++++ lib/ldb/ldb_key_value/ldb_kv_search.c | 33 ++++++++++++++++++++- selftest/knownfail.d/ldap-timeout | 1 - 5 files changed, 85 insertions(+), 2 deletions(-) delete mode 100644 selftest/knownfail.d/ldap-timeout diff --git a/lib/ldb/ldb_key_value/ldb_kv.c b/lib/ldb/ldb_key_value/ldb_kv.c index ed0f760b5a2..aea6f0c1be0 100644 --- a/lib/ldb/ldb_key_value/ldb_kv.c +++ b/lib/ldb/ldb_key_value/ldb_kv.c @@ -2078,6 +2078,8 @@ static int ldb_kv_handle_request(struct ldb_module *module, } } + ac->timeout_timeval = tv; + /* set a spy so that we do not try to use the request context * if it is freed before ltdb_callback fires */ ac->spy = talloc(req, struct ldb_kv_req_spy); diff --git a/lib/ldb/ldb_key_value/ldb_kv.h b/lib/ldb/ldb_key_value/ldb_kv.h index f9dffae2dcf..ac474b04b4c 100644 --- a/lib/ldb/ldb_key_value/ldb_kv.h +++ b/lib/ldb/ldb_key_value/ldb_kv.h @@ -152,6 +152,16 @@ struct ldb_kv_context { struct ldb_module *module; struct ldb_request *req; + /* + * Required as we might not get to the event loop before the + * timeout, so we need some old-style cooperative multitasking + * here. + */ + struct timeval timeout_timeval; + + /* Used to throttle calls to gettimeofday() */ + size_t timeout_counter; + bool request_terminated; struct ldb_kv_req_spy *spy; diff --git a/lib/ldb/ldb_key_value/ldb_kv_index.c b/lib/ldb/ldb_key_value/ldb_kv_index.c index 1cc042aa84f..d70e5f619ef 100644 --- a/lib/ldb/ldb_key_value/ldb_kv_index.c +++ b/lib/ldb/ldb_key_value/ldb_kv_index.c @@ -2352,6 +2352,47 @@ static int ldb_kv_index_filter(struct ldb_kv_private *ldb_kv, for (i = 0; i < num_keys; i++) { int ret; bool matched; + + /* + * Check the time every 64 records, to reduce calls to + * gettimeofday(). This is a compromise, not all + * calls to ldb_match_message() will take the same + * time, most will run quickly but by luck it might be + * possible to have 64 records that are slow, doing a + * recursive search via LDAP_MATCHING_RULE_IN_CHAIN. + * + * Thankfully this is after index processing so only + * on the subset that matches some index (but still + * possibly a big one like objectclass=user) + */ + if (i % 64 == 0) { + struct timeval now = tevent_timeval_current(); + int timeval_cmp = tevent_timeval_compare(&ac->timeout_timeval, + &now); + + /* + * The search has taken too long. This is the + * most likely place for our time to expire, + * as we are checking the records after the + * index set intersection. This is now the + * slow process of checking if the records + * actually match. + * + * The tevent based timeout is not likely to + * be hit, sadly, as we don't run an event + * loop. + * + * While we are indexed and most of the work + * should have been done already, the + * ldb_match_* calls can be quite expensive if + * the caller uses LDAP_MATCHING_RULE_IN_CHAIN + */ + if (timeval_cmp <= 0) { + talloc_free(keys); + return LDB_ERR_TIME_LIMIT_EXCEEDED; + } + } + msg = ldb_msg_new(ac); if (!msg) { talloc_free(keys); diff --git a/lib/ldb/ldb_key_value/ldb_kv_search.c b/lib/ldb/ldb_key_value/ldb_kv_search.c index a0e1762bc90..46031b99c16 100644 --- a/lib/ldb/ldb_key_value/ldb_kv_search.c +++ b/lib/ldb/ldb_key_value/ldb_kv_search.c @@ -314,7 +314,8 @@ static int search_func(_UNUSED_ struct ldb_kv_private *ldb_kv, struct ldb_context *ldb; struct ldb_kv_context *ac; struct ldb_message *msg, *filtered_msg; - int ret; + struct timeval now; + int ret, timeval_cmp; bool matched; ac = talloc_get_type(state, struct ldb_kv_context); @@ -341,6 +342,36 @@ static int search_func(_UNUSED_ struct ldb_kv_private *ldb_kv, return 0; } + /* + * Check the time every 64 records, to reduce calls to + * gettimeofday(). This is a compromise, not all calls to + * ldb_match_message() will take the same time, most will fail + * quickly but by luck it might be possible to have 64 records + * that are slow, doing a recursive search via + * LDAP_MATCHING_RULE_IN_CHAIN. + */ + if (ac->timeout_counter++ % 64 == 0) { + now = tevent_timeval_current(); + timeval_cmp = tevent_timeval_compare(&ac->timeout_timeval, + &now); + + /* + * The search has taken too long. This is the most + * likely place for our time to expire, as we are in + * an un-indexed search and we return the data from + * within this loop. The tevent based timeout is not + * likely to be hit, sadly. + * + * ldb_match_msg_error() can be quite expensive if a + * LDAP_MATCHING_RULE_IN_CHAIN extended match was + * specified. + */ + if (timeval_cmp <= 0) { + ac->error = LDB_ERR_TIME_LIMIT_EXCEEDED; + return -1; + } + } + msg = ldb_msg_new(ac); if (!msg) { ac->error = LDB_ERR_OPERATIONS_ERROR; diff --git a/selftest/knownfail.d/ldap-timeout b/selftest/knownfail.d/ldap-timeout deleted file mode 100644 index 378ca1f4821..00000000000 --- a/selftest/knownfail.d/ldap-timeout +++ /dev/null @@ -1 +0,0 @@ -samba4.ldap.large_ldap\..*\.python\(.*\).__main__.LargeLDAPTest.test_timeout\(.*\) \ No newline at end of file -- 2.25.1 From 0f750e03aa4630b2a38afd4b1afdb695be918f2e Mon Sep 17 00:00:00 2001 From: Andrew Bartlett Date: Thu, 18 Nov 2021 15:27:08 +1300 Subject: [PATCH 5/7] CVE-2021-3670 ldap_server: Remove duplicate print of LDAP search details BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Andrew Bartlett Reviewed-by: Douglas Bagnall --- source4/ldap_server/ldap_backend.c | 3 --- 1 file changed, 3 deletions(-) diff --git a/source4/ldap_server/ldap_backend.c b/source4/ldap_server/ldap_backend.c index c7405f66643..78d0de951c5 100644 --- a/source4/ldap_server/ldap_backend.c +++ b/source4/ldap_server/ldap_backend.c @@ -729,9 +729,6 @@ static NTSTATUS ldapsrv_SearchRequest(struct ldapsrv_call *call) unsigned int i; int extended_type = 1; - DEBUG(10, ("SearchRequest")); - DEBUGADD(10, (" basedn: %s", req->basedn)); - DEBUGADD(10, (" filter: %s\n", ldb_filter_from_tree(call, req->tree))); local_ctx = talloc_new(call); NT_STATUS_HAVE_NO_MEMORY(local_ctx); -- 2.25.1 From 0562902f6300cd520b1556d9758049c7f5b28b69 Mon Sep 17 00:00:00 2001 From: Andrew Bartlett Date: Thu, 18 Nov 2021 15:57:34 +1300 Subject: [PATCH 6/7] CVE-2021-3670 dsdb/anr: Do a copy of the potentially anr query before starting to modify it RN: Do not modify the caller-supplied memory in the anr=* handling to allow clear logging of the actual caller request after it has been processed. BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Andrew Bartlett Reviewed-by: Douglas Bagnall --- source4/dsdb/samdb/ldb_modules/anr.c | 73 +++++++++++++++++++++++++--- 1 file changed, 65 insertions(+), 8 deletions(-) diff --git a/source4/dsdb/samdb/ldb_modules/anr.c b/source4/dsdb/samdb/ldb_modules/anr.c index 660ba271496..e083f5db17d 100644 --- a/source4/dsdb/samdb/ldb_modules/anr.c +++ b/source4/dsdb/samdb/ldb_modules/anr.c @@ -148,8 +148,6 @@ static int anr_replace_value(struct anr_context *ac, return LDB_ERR_OPERATIONS_ERROR; } - ac->found_anr = true; - if (match->length > 1 && match->data[0] == '=') { struct ldb_val *match2 = talloc(mem_ctx, struct ldb_val); if (match2 == NULL){ @@ -285,6 +283,49 @@ static int anr_replace_subtrees(struct anr_context *ac, return LDB_SUCCESS; } +struct anr_present_ctx { + bool found_anr; + const char *attr; +}; + +/* + callback to determine if ANR is in use at all + */ +static int parse_tree_anr_present(struct ldb_parse_tree *tree, void *private_context) +{ + struct anr_present_ctx *ctx = private_context; + switch (tree->operation) { + case LDB_OP_EQUALITY: + case LDB_OP_GREATER: + case LDB_OP_LESS: + case LDB_OP_APPROX: + if (ldb_attr_cmp(tree->u.equality.attr, ctx->attr) == 0) { + ctx->found_anr = true; + } + break; + case LDB_OP_SUBSTRING: + if (ldb_attr_cmp(tree->u.substring.attr, ctx->attr) == 0) { + ctx->found_anr = true; + } + break; + case LDB_OP_PRESENT: + if (ldb_attr_cmp(tree->u.present.attr, ctx->attr) == 0) { + ctx->found_anr = true; + } + break; + case LDB_OP_EXTENDED: + if (tree->u.extended.attr && + ldb_attr_cmp(tree->u.extended.attr, ctx->attr) == 0) { + ctx->found_anr = true; + } + break; + default: + break; + } + return LDB_SUCCESS; +} + + static int anr_search_callback(struct ldb_request *req, struct ldb_reply *ares) { struct anr_context *ac; @@ -322,8 +363,21 @@ static int anr_search(struct ldb_module *module, struct ldb_request *req) struct ldb_parse_tree *anr_tree; struct ldb_request *down_req; struct anr_context *ac; + struct anr_present_ctx ctx; + const char *attr = "anr"; int ret; + ctx.found_anr = false; + ctx.attr = attr; + + ldb_parse_tree_walk(req->op.search.tree, + parse_tree_anr_present, + &ctx); + + if (!ctx.found_anr) { + return ldb_next_request(module, req); + } + ldb = ldb_module_get_ctx(module); ac = talloc(req, struct anr_context); @@ -333,20 +387,23 @@ static int anr_search(struct ldb_module *module, struct ldb_request *req) ac->module = module; ac->req = req; - ac->found_anr = false; #if 0 printf("oldanr : %s\n", ldb_filter_from_tree (0, req->op.search.tree)); #endif - ret = anr_replace_subtrees(ac, req->op.search.tree, "anr", &anr_tree); - if (ret != LDB_SUCCESS) { + /* First make a copy, so we don't overwrite caller memory */ + + anr_tree = ldb_parse_tree_copy_shallow(ac, req->op.search.tree); + + if (anr_tree == NULL) { return ldb_operr(ldb); } - if (!ac->found_anr) { - talloc_free(ac); - return ldb_next_request(module, req); + /* Now expand 'anr' out */ + ret = anr_replace_subtrees(ac, anr_tree, attr, &anr_tree); + if (ret != LDB_SUCCESS) { + return ldb_operr(ldb); } ret = ldb_build_search_req_ex(&down_req, -- 2.25.1 From 3d0018f47d427fb078e884fd6166a76d3e0328d5 Mon Sep 17 00:00:00 2001 From: Andrew Bartlett Date: Thu, 18 Nov 2021 16:09:47 +1300 Subject: [PATCH 7/7] CVE-2021-3670 ldap_server: Clearly log LDAP queries and timeouts This puts all the detail on one line so it can be searched by IP address and connecting SID. This relies on the anr handling as otherwise this log becomes the expanded query, not the original one. RN: Provide clear logs of the LDAP search and who made it, including a warning (at log level 3) for queries that are 1/4 of the hard timeout. BUG: https://bugzilla.samba.org/show_bug.cgi?id=14694 Signed-off-by: Andrew Bartlett Reviewed-by: Douglas Bagnall Autobuild-User(master): Douglas Bagnall Autobuild-Date(master): Thu Nov 25 02:30:42 UTC 2021 on sn-devel-184 --- source4/ldap_server/ldap_backend.c | 121 +++++++++++++++++++++++------ 1 file changed, 99 insertions(+), 22 deletions(-) diff --git a/source4/ldap_server/ldap_backend.c b/source4/ldap_server/ldap_backend.c index 78d0de951c5..e37b87f62ee 100644 --- a/source4/ldap_server/ldap_backend.c +++ b/source4/ldap_server/ldap_backend.c @@ -729,6 +729,15 @@ static NTSTATUS ldapsrv_SearchRequest(struct ldapsrv_call *call) unsigned int i; int extended_type = 1; + /* + * Warn for searches that are longer than 1/4 of the + * search_timeout, being 30sec by default + */ + struct timeval start_time = timeval_current(); + struct timeval warning_time + = timeval_add(&start_time, + call->conn->limits.search_timeout / 4, + 0); local_ctx = talloc_new(call); NT_STATUS_HAVE_NO_MEMORY(local_ctx); @@ -736,29 +745,27 @@ static NTSTATUS ldapsrv_SearchRequest(struct ldapsrv_call *call) basedn = ldb_dn_new(local_ctx, samdb, req->basedn); NT_STATUS_HAVE_NO_MEMORY(basedn); - DEBUG(10, ("SearchRequest: basedn: [%s]\n", req->basedn)); - DEBUG(10, ("SearchRequest: filter: [%s]\n", ldb_filter_from_tree(call, req->tree))); - switch (req->scope) { - case LDAP_SEARCH_SCOPE_BASE: - scope_str = "BASE"; - scope = LDB_SCOPE_BASE; - break; - case LDAP_SEARCH_SCOPE_SINGLE: - scope_str = "ONE"; - scope = LDB_SCOPE_ONELEVEL; - break; - case LDAP_SEARCH_SCOPE_SUB: - scope_str = "SUB"; - scope = LDB_SCOPE_SUBTREE; - break; - default: - result = LDAP_PROTOCOL_ERROR; - map_ldb_error(local_ctx, LDB_ERR_PROTOCOL_ERROR, NULL, - &errstr); - errstr = talloc_asprintf(local_ctx, - "%s. Invalid scope", errstr); - goto reply; + case LDAP_SEARCH_SCOPE_BASE: + scope_str = "BASE"; + scope = LDB_SCOPE_BASE; + break; + case LDAP_SEARCH_SCOPE_SINGLE: + scope_str = "ONE"; + scope = LDB_SCOPE_ONELEVEL; + break; + case LDAP_SEARCH_SCOPE_SUB: + scope_str = "SUB"; + scope = LDB_SCOPE_SUBTREE; + break; + default: + result = LDAP_PROTOCOL_ERROR; + map_ldb_error(local_ctx, LDB_ERR_PROTOCOL_ERROR, NULL, + &errstr); + scope_str = ""; + errstr = talloc_asprintf(local_ctx, + "%s. Invalid scope", errstr); + goto reply; } DEBUG(10,("SearchRequest: scope: [%s]\n", scope_str)); @@ -911,6 +918,76 @@ static NTSTATUS ldapsrv_SearchRequest(struct ldapsrv_call *call) } reply: + + /* + * This looks like duplicated code - because it is - but + * otherwise the work in the parameters will be done + * regardless, this way the functions only execuate when the + * log level is set. + * + * The basedn is re-obtained as a string to escape it + */ + if ((req->timelimit == 0 || call->conn->limits.search_timeout < req->timelimit) + && ldb_ret == LDB_ERR_TIME_LIMIT_EXCEEDED) { + struct dom_sid_buf sid_buf; + DBG_WARNING("MaxQueryDuration(%d) timeout exceeded " + "in SearchRequest by %s from %s filter: [%s] " + "basedn: [%s] " + "scope: [%s]\n", + call->conn->limits.search_timeout, + dom_sid_str_buf(&call->conn->session_info->security_token->sids[0], + &sid_buf), + tsocket_address_string(call->conn->connection->remote_address, + call), + ldb_filter_from_tree(call, req->tree), + ldb_dn_get_extended_linearized(call, basedn, 1), + scope_str); + for (i=0; i < req->num_attributes; i++) { + DBG_WARNING("MaxQueryDuration timeout exceeded attrs: [%s]\n", + req->attributes[i]); + } + + } else if (timeval_expired(&warning_time)) { + struct dom_sid_buf sid_buf; + DBG_NOTICE("Long LDAP Query: Duration was %.2fs, " + "MaxQueryDuration(%d)/4 == %d " + "in SearchRequest by %s from %s filter: [%s] " + "basedn: [%s] " + "scope: [%s] " + "result: %s\n", + timeval_elapsed(&start_time), + call->conn->limits.search_timeout, + call->conn->limits.search_timeout / 4, + dom_sid_str_buf(&call->conn->session_info->security_token->sids[0], + &sid_buf), + tsocket_address_string(call->conn->connection->remote_address, + call), + ldb_filter_from_tree(call, req->tree), + ldb_dn_get_extended_linearized(call, basedn, 1), + scope_str, + ldb_strerror(ldb_ret)); + for (i=0; i < req->num_attributes; i++) { + DBG_NOTICE("Long LDAP Query attrs: [%s]\n", + req->attributes[i]); + } + } else { + struct dom_sid_buf sid_buf; + DBG_INFO("LDAP Query: Duration was %.2fs, " + "SearchRequest by %s from %s filter: [%s] " + "basedn: [%s] " + "scope: [%s] " + "result: %s\n", + timeval_elapsed(&start_time), + dom_sid_str_buf(&call->conn->session_info->security_token->sids[0], + &sid_buf), + tsocket_address_string(call->conn->connection->remote_address, + call), + ldb_filter_from_tree(call, req->tree), + ldb_dn_get_extended_linearized(call, basedn, 1), + scope_str, + ldb_strerror(ldb_ret)); + } + DLIST_REMOVE(call->conn->pending_calls, call); call->notification.busy = false; -- 2.25.1