with winbindd running at debug level 10, I see the following ldap search errors when doing "wbinfo -u" or "wbinfo -g". It also shows up when I connect to a share. ... [2003/08/18 14:33:39, 3] libads/ldap.c:ads_do_paged_search(451) ldap_search_ext_s((distinguishedName=CN=Thompson\, Pamela (SNB),OU=Tele Servic esG,OU=SNB UsersG,DC=snb,DC=ca)) -> Bad search filter [2003/08/18 14:33:39, 3] libads/ldap_utils.c:ads_do_search_retry(60) Reopening ads connection to realm 'SNB.CA' after error Bad search filter [2003/08/18 14:33:39, 6] libads/ldap.c:ads_find_dc(147) ads_find_dc: looking for domain 'MYGROUP' [2003/08/18 14:33:39, 8] libsmb/namequery.c:get_sorted_dc_list(1215) get_sorted_dc_list: attempting lookup using [lmhosts wins host bcast] [2003/08/18 14:33:39, 10] libsmb/namequery.c:internal_resolve_name(989) internal_resolve_name: looking up snb-fton-ad1.snb.ca#20 [2003/08/18 14:33:39, 10] lib/gencache.c:gencache_get(263) Returning valid cache entry: key = NBT/SNB-FTON-AD1.SNB.CA#20, value = 142.139 .93.41:0, timeout = Mon Aug 18 14:40:21 2003 ... The "cause" appears to be the brackets in our usernames: bash-2.05# net ads search '(distinguishedName=CN=Fortune\, Jim (SNB/xwave),OU=xwave,OU=IT Admin,OU=SNB UsersG,DC=snb,DC=ca)' search failed: Bad search filter bash-2.05# net ads search '(distinguishedName=CN=Fortune\\, Jim \(SNB/xwave\),OU=xwave,OU=IT Admin,OU=SNB UsersG,DC=snb,DC=ca)' Got 1 replies ... Once I excape the brackets (and double escape the comma because I'm working in a shell), it seems to return all the correct info. I have not noticed what the functional effect of this error is.
I downloaded new CVS code today (2003-09-08) and noticed this error _seems_ to be worse. I now see every user repeated 3 times in a row, and eventually the user repeats again 3 times in a row (the users "triplet" repeats multiple (more than 5) times each). It is not stuck in a loop because it does eventually stop (about 15 minutes later with 1017 users), but it seems that an excessive amount of work is being done for ldap searches that should not fail. I did a single 'getent group', and it took about 2 minutes, but it eventually returned, but the ldap errors were written to log.winbindd for approximately 15 minutes afterward. I'm attaching a 100K section of the log.winbindd
Created attachment 127 [details] log.winbind (-d10, 1000K extract) Shows repeated ldap failures, looking like they are due to non-escaped brackets.
This may also be of interest. While waiting for "getent group" to return I tried to switch to debug level 10 (was at 1) for winbindd by using "smbcontrol winbindd debug 10". winbindd dumped core with the following backtrace and full backtrace. (also note, within the "smbcontrol --help", winbindd is not mentioned as a "destination" but does work (most of the time)) (gdb) bt #0 0xfef1eda0 in _libc_kill () from /usr/lib/libc.so.1 #1 0xfeeb5c68 in abort () from /usr/lib/libc.so.1 #2 0x00087984 in smb_panic (why=0x13f080 "internal error") at lib/util.c:1421 #3 0x00074a5c in fault_report (sig=11) at lib/fault.c:41 #4 <signal handler called> #5 0xfeeb3464 in strlen () from /usr/lib/libc.so.1 #6 0xfeed0578 in strdup () from /usr/lib/libc.so.1 #7 0x00123340 in ads_do_search_retry (ads=0x1ed5d0, bind_path=0x0, scope=2, expr=0x20129d8 "(distinguishedName=CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca)", attrs=0xffbfecf0, res=0xffbfecd8) at libads/ldap_utils.c:43 #8 0x00123660 in ads_search_retry (ads=0x1ed5d0, res=0xffbfecd8, expr=0x20129d8 "(distinguishedName=CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca)", attrs=0xffbfecf0) at libads/ldap_utils.c:88 #9 0x00047a0c in dn_lookup (ads=0x1ed5d0, mem_ctx=0x1d59b30, dn=0x1d87aa8 "CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca", name=0xffbfed7c, name_type=0xffbfed78, sid=0xffbfed88) at nsswitch/winbindd_ads.c:368 #10 0x00048ed4 in lookup_groupmem (domain=0x1d0, mem_ctx=0x1d59b30, group_sid=0xffbff390, num_names=0xffbff100, sid_mem=0xffbff0fc, names=0xffbff0f8, name_types=0xffbff104) at nsswitch/winbindd_ads.c:749 #11 0x0003ef30 in lookup_groupmem (domain=0x1eb740, mem_ctx=0x1d59b30, group_sid=0xffbff390, num_names=0xffbff100, sid_mem=0xffbff0fc, names=0xffbff0f8, name_types=0xffbff104) at nsswitch/winbindd_cache.c:1238 #12 0x00036bf4 in fill_grent_mem (domain=0x1eb740, group_sid=0xffbff390, group_name_type=SID_NAME_DOM_GRP, num_gr_mem=0x2305e4, gr_mem=0xffbff388, gr_mem_len=0xffbff384) at nsswitch/winbindd_group.c:117 #13 0x00038870 in winbindd_getgrent (state=0x1fa740) at nsswitch/winbindd_group.c:721 #14 0x00033b94 in process_request (state=0x1fa740) at nsswitch/winbindd.c:306 #15 0x00033e9c in winbind_process_packet (state=0x620) at nsswitch/winbindd.c:430 #16 0x000347b0 in process_loop () at nsswitch/winbindd.c:727 #17 0x00034df8 in main (argc=0, argv=0xffbff700) at nsswitch/winbindd.c:929 (gdb) bt full #0 0xfef1eda0 in _libc_kill () from /usr/lib/libc.so.1 No symbol table info available. #1 0xfeeb5c68 in abort () from /usr/lib/libc.so.1 No symbol table info available. #2 0x00087984 in smb_panic (why=0x13f080 "internal error") at lib/util.c:1421 cmd = 0x2013d40 "" result = 33635648 #3 0x00074a5c in fault_report (sig=11) at lib/fault.c:41 counter = 1 #4 <signal handler called> No symbol table info available. #5 0xfeeb3464 in strlen () from /usr/lib/libc.so.1 No symbol table info available. #6 0xfeed0578 in strdup () from /usr/lib/libc.so.1 No symbol table info available. #7 0x00123340 in ads_do_search_retry (ads=0x1ed5d0, bind_path=0x0, scope=2, expr=0x20129d8 "(distinguishedName=CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca)", attrs=0xffbfecf0, res=0xffbfecd8) at libads/ldap_utils.c:43 status = {error_type = ADS_ERROR_LDAP, err = {rc = 73, nt_status = {v = 73}}, minor_status = 0} count = 0 bp = 0x7 <Address 0x7 out of bounds> #8 0x00123660 in ads_search_retry (ads=0x1ed5d0, res=0xffbfecd8, expr=0x20129d8 "(distinguishedName=CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca)", attrs=0xffbfecf0) at libads/ldap_utils.c:88 No locals. #9 0x00047a0c in dn_lookup (ads=0x1ed5d0, mem_ctx=0x1d59b30, dn=0x1d87aa8 "CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca", name=0xffbfed7c, name_type=0xffbfed78, sid=0xffbfed88) at nsswitch/winbindd_ads.c:368 ldap_exp = 0x20129d8 "(distinguishedName=CN=Schurman\\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca)" res = (void *) 0x0 attrs = {0x132610 "userPrincipalName", 0x132600 "sAMAccountName", 0x132630 "objectSid", 0x132650 "sAMAccountType", 0x0} rc = {error_type = ADS_ERROR_LDAP, err = {rc = 81, nt_status = {v = 81}}, minor_status = 0} atype = 805306368 escaped_dn = 0x1fac338 "CN=Schurman\\5c, George \\28SNB\\29,OU=SNB UsersG,DC=snb,DC=ca" #10 0x00048ed4 in lookup_groupmem (domain=0x1d0, mem_ctx=0x1d59b30, group_sid=0xffbff390, num_names=0xffbff100, sid_mem=0xffbff0fc, names=0xffbff0f8, name_types=0xffbff104) at nsswitch/winbindd_ads.c:749 name_type = 1 name = 0x1ff2208 "AMMACDOU" sid = {sid_rev_num = 1 '\001', num_auths = 5 '\005', id_auth = "\0\0\0\0 \0\005", sub_auths = {21, 1416833156, 1238969774, 10498456, 1816, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}} rc = {error_type = ADS_ERROR_LDAP, err = {rc = 0, nt_status = {v = 0}}, minor_status = 0} count = 0 res = (void *) 0x1d64738 ads = (ADS_STRUCT *) 0x1ed5d0 ldap_exp = 0x1c5c0b8 "`Z\006\006+\006\001\005\005\002 P0N 00.\006 \t*\206H\202÷\022\001\002\002\006\t*\206H\206÷\022\001\002\002\006 \n*\206H\206÷\022\001\002\002\003\006\n+\006\001\004\001\2027\002\002\n£\0320 \030 \026\e\024snb-fton-ad1$@SNB.CA" status = {v = 30836552} sidstr = 0x64 <Address 0x64 out of bounds> attrs = {0x132c58 "member", 0x0} members = (char **) 0x1d7b750 i = 464 num_members = 688 sid_string = "ÿ¿îð?\\È:", '\0' <repeats 25 times>, "\036Ö¨ÿ¿îà\001Õ\\\230\0\0\0/\0\036\200\020\0\0ÿ\0ÿ¿îx\0\003Î|969774- 10498456-3908\0\0ö¼\001ÖRP\0\0\0/\001Õ\\\230\0\0\0/\0\0ç\204\0\0\0@\0\0\0\0\0\0 \0@\0\0\0/\0\0\0\f±Tx\e&\001\031\231ÿ¿íh\0\0\0\vÿ¿ó¬\0\0\0\005ÿ¿ó¬\0\0\0 \005ÿ¿îè\0\024\f\0\0\024\020\0\001Ñ\207pÿ¿ñ\004ÿ¿í\210\0\036\200\020\0\036·@\0 \023\vàÿ¿ï\200\0\0\0\001\0#\004àÿ¿ï\b\0\003ð"... #11 0x0003ef30 in lookup_groupmem (domain=0x1eb740, mem_ctx=0x1d59b30, group_sid=0xffbff390, num_names=0xffbff100, sid_mem=0xffbff0fc, names=0xffbff0f8, name_types=0xffbff104) at nsswitch/winbindd_cache.c:1238 cache = (struct winbind_cache *) 0x48c40 centry = (struct cache_entry *) 0x0 status = {v = 30776112} i = 4290769424 sid_string = "S-1-5-21-1416833156-1238969774-10498456-3908\0\0\0¤\001 \022\"Ø\0\0\0\005ÿ¿îè\0\024\f\0\0\024\020\0\0\0\0\vÿ¿ñ\004ÿ¿í\210\001\022F \0 \023\vàÿ¿ï\200ÿ¿ñ\0ÿ¿ðüÿ¿ðøÿ¿ð \0\bÆ\234\0\0\0\003\0\0\0\003\0\0\0 \0þÚO\024ÿ¿ðp\0\0\0\023\0\0\0\0\0\0\0\004\0\0\0\0\0\0\0\001ÿ¿ðP\0\t¨8\0\004 \214@\0\0\0\0\001\rJèÿ¿ò\fÿ¿ñ\004ÿ¿ô(\0\0\002iþô\005\230\001\022F \0\036^("... #12 0x00036bf4 in fill_grent_mem (domain=0x1eb740, group_sid=0xffbff390, group_name_type=SID_NAME_DOM_GRP, num_gr_mem=0x2305e4, gr_mem=0xffbff388, gr_mem_len=0xffbff384) at nsswitch/winbindd_group.c:117 sid_mem = (DOM_SID **) 0x1d68748 num_names = 26 name_types = (unsigned int *) 0x1d69218 buf_len = 0 buf_ndx = 0 i = 2 names = (char **) 0x1d73850 buf = 0x12e800 "error getting user info for user '[%s]\\[%s]'\n" result = 0 mem_ctx = (TALLOC_CTX *) 0x1d59b30 status = {v = 1239040} sid_string = "SNB\\SMS2-Include-G\0\b\0\031,\0\0\031,\0 \001Ñ\003`ÿ¿ñ\004ÿ¿ô(\0\0\002\201þô\005\230ÿ¿ó\fÿ¿ólÿ¿óà\0\036^È\0\0\0\004ÿ¿ô- ÿ¿ò¨\0\022\207Hÿ¿ò\224\0\aØ`\0\0\0H\0'÷Ðÿ¿ò\230\0\003\200\\", '\0' <repeats 15 times>, "\016\0\0\0\0þóÀ\0\0\0\0\0\0\0\0\022\0\0\0\0\0\037\233Ð\0'÷Ð\0\031G \0 \036·@\0\0\0\0\0\0\0\001\0\0\0\0\001Ñ\225È\0\036·@\0\0\0\0\0 \037¶hÿ¿óÜÿ¿ó\214ÿ¿óà\0\0\0\005\0\0\017D\001"... #13 0x00038870 in winbindd_getgrent (state=0x1fa740) at nsswitch/winbindd_group.c:721 member_sid = {sid_rev_num = 1 '\001', num_auths = 5 '\005', id_auth = "\0\0\0\0\0\005", sub_auths = {21, 1416833156, 1238969774, 10498456, 3908, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}} new_gr_mem_list = 0x1eb740 "SNB" domain = (struct winbindd_domain *) 0x1eb740 name_list = (struct acct_info *) 0x27f7d0 domain_group_name = "SNB\\SMS2-Include-G\0L-M\0TO-M\0\0\0\0\0ÿ¿õ \0 \bóèÿ¿õ \0\bóè\0\030Ð\0\0\024\024", '\0' <repeats 20 times>, "\r\0@\0\0\0\0\0 \020\0@\0\0\0\0\0\021\0@\0\0\0\0\0\023\0@\0@\0\0\0\023\0@", '\0' <repeats 15 times>, "\002£A\0\0Aè\0\0\0\002\0\0\0\0\0\0\0\001", '\0' <repeats 17 times>, "\037\233Ð", '\0' <repeats 33 times>, "\036^(\0\0\0\0\0\004\036,\0 \036^È\0\037§5ÿ¿õ8\0\003;\214", '\0' <repeats 12 times>, "þóò¨\177ÿÿÿ\0\0\0"... result = 1 group_gid = 10248 gr_mem_len = 0 gr_mem = 0x0 group_sid = {sid_rev_num = 1 '\001', num_auths = 5 '\005', id_auth = "\0 \0\0\0\0\005", sub_auths = {21, 1416833156, 1238969774, 10498456, 3908, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}} ent = (struct getent_state *) 0x1f9bd0 num_groups = 250 group_list_ndx = 245 i = 245 gr_mem_list_len = 639 new_extra_data = 0x2 <Address 0x2 out of bounds> gr_mem_list = 0x1d10360 "SNB\\SNBBRBTOC02,SNB\\SNBCCMTNC01,SNB\\SNBCMMCHV02,SNB\\SNBCMMCHV01,S NB\\SNBBMCTNC01,SNB\\SNBCMMCHC01,SNB\\SNBFHMPNC02,SNB\\SNBFHMPNC01,SNB\\SNBFSSTN C02,SNB\\SNBFSSTNC01,SNB\\SNBFSTJHC03,SNB\\SNBFSTJHC02,SNB\\SNBF"... #14 0x00033b94 in process_request (state=0x1fa740) at nsswitch/winbindd.c:306 table = (struct dispatch_table *) 0x17e5b0 #15 0x00033e9c in winbind_process_packet (state=0x620) at nsswitch/winbindd.c:430 No locals. #16 0x000347b0 in process_loop () at nsswitch/winbindd.c:727 state = (struct winbindd_cli_state *) 0x1fa740 r_fds = {fds_bits = {524288, 0 <repeats 31 times>}} w_fds = {fds_bits = {0 <repeats 32 times>}} maxfd = 1583104 listen_sock = 16 listen_priv_sock = 17 selret = 1568 timeout = {tv_sec = 30, tv_usec = 0} r_fds = {fds_bits = {524288, 0 <repeats 31 times>}} w_fds = {fds_bits = {0 <repeats 32 times>}} timeout = {tv_sec = 30, tv_usec = 0} #17 0x00034df8 in main (argc=0, argv=0xffbff700) at nsswitch/winbindd.c:929 logfile = "/usr/local/samba/var/log.winbindd\0\211\204ÿ1ú", '\0' <repeats 17 times>, "ÿ¿ù0ÿ1ù$", '\0' <repeats 32 times>, "ÿ3@", '\0' <repeats 29 times>, "ÿ3ZÌ", '\0' <repeats 20 times>, "ÿ¿ù\220ÿ2\001¬", '\0' <repeats 19 times>, "\002\0\200\0\0\177ÿÿÿ", '\0' <repeats 44 times>, "ÿ?\201ä\0 \002í\0ÿ<Ê\020ÿ?\206Ìÿ¿ùðÿ<Ê\030ÿ;\002,ÿ;\002,ÿ>@\nÿ;\002,ÿ;\002,\0\0\0 \0ÿ<b\214ÿ?\200Èÿ\n÷\0\0\0\0\030þõ\b0ÿ"... interactive = 0 Fork = 1 log_stdout = 0 long_options = {{longName = 0x0, shortName = 0 '\0', argInfo = 4, arg = 0x193a18, val = 0, descrip = 0x12e348 "Help options:", argDescrip = 0x0}, {longName = 0x12e358 "stdout", shortName = 83 'S', argInfo = 7, arg = 0x17e738, val = 1, descrip = 0x12e360 "Log to stdout", argDescrip = 0x0}, {longName = 0x12e370 "foreground", shortName = 70 'F', argInfo = 7, arg = 0x17e734, val = 0, descrip = 0x12e380 "Daemon in foreground mode", argDescrip = 0x0}, {longName = 0x12e3a0 "interactive", shortName = 105 'i', argInfo = 0, arg = 0x0, val = 105, descrip = 0x12e3b0 "Interactive mode", argDescrip = 0x0}, {longName = 0x12e3c8 "single-daemon", shortName = 89 'Y', argInfo = 7, arg = 0x17e534, val = 0, descrip = 0x12e3d8 "Single daemon mode", argDescrip = 0x0}, {longName = 0x12e3f0 "no-caching", shortName = 110 'n', argInfo = 7, arg = 0x17e530, val = 0, descrip = 0x12e400 "Disable caching", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\0', argInfo = 4, arg = 0x184440, val = 0, descrip = 0x12e410 "Common samba options:", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\0', argInfo = 0, arg = 0x0, val = 0, descrip = 0x0, argDescrip = 0x0}} pc = 0x1e5c00 opt = 16
Brian, is this head or the 3.0 cvs tree? I'ma assuming its 3.0. Would you mind updating the versio? Thanks.
changing to 3.0 so I don't loose this one.
You were correct, it was CVS 3.0. I've seen it with rc1-rc3 so I just updated the version to rc3.
brian, most probably the fix for bug #592 resolves the bad search filters you were seeing.
marking as fixed based on Guenther's comments. Reopen if you find differently.
originally reported against one of the 3.0.0rc[1-4] releases. Cleaning up non-production versions.
sorry for the same, cleaning up the database to prevent unecessary reopens of bugs.
database cleanup