Bug 2952 - winbind not getting Windows 2003 ADS users with sfu settings for samba 3.0.20rc1
Summary: winbind not getting Windows 2003 ADS users with sfu settings for samba 3.0.20rc1
Status: RESOLVED WORKSFORME
Alias: None
Product: Samba 3.0
Classification: Unclassified
Component: winbind (show other bugs)
Version: 3.0.20
Hardware: x86 Linux
: P3 major
Target Milestone: none
Assignee: Guenther Deschner
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2005-08-03 03:11 UTC by Mike Rose
Modified: 2005-09-06 03:11 UTC (History)
0 users

See Also:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Mike Rose 2005-08-03 03:11:10 UTC 
From a previous bug report:

"
Maybe your problem has to do with misspelling

"winbind nss support = sfu"

It is actually "winbind nss info = sfu".

Please reopen a new bug, as jerry said, if you are seeing problems with either
the SFU-support or the idmap_ad-module.
"

Here is the new bug.

smb.conf is:
"
[global]
# separate domain and username with '\', like DOMAIN\username
winbind separator = +
# use uids from 10000 to 20000 for domain users
 idmap uid = 100-20000
# use gids from 10000 to 20000 for domain groups
idmap gid = 100-20000
# allow enumeration of winbind users and groups
winbind enum users = yes
winbind enum groups = yes
# give winbind users a real shell (only needed if they have telnet access)
template homedir = /home/%U
template shell = /bin/bash
winbind cache time = 600
# winbind trusted domains only = yes
winbind use default domain = yes

idmap backend = ad
#winbind nss support = sfu
winbind nss info = sfu

workgroup = BSS

obey pam restrictions = Yes

realm = bss.phy.private.cam.ac.uk
security = ADS
encrypt passwords = yes
password server = sd1.bss.phy.private.cam.ac.uk
"

wbinfo -t, wbinfo -u, wbinfo -g all work:
"
# wbinfo -u
Administrator
Guest
SUPPORT_388945a0
SD1$
krbtgt
bob
mr
w1$
ldap
"

With winbind logging on there is this:
"
[2005/08/03 11:09:59, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1108]
[2005/08/03 11:09:59, 1] nsswitch/winbindd_user.c:winbindd_fill_pwent(85)
  error getting user id for sid S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/03 11:09:59, 1] nsswitch/winbindd_user.c:winbindd_getpwent(712)
  could not lookup domain user mr
"

If I comment out the sfu and idmap lines in smb.conf:
"
# idmap backend = ad
#winbind nss support = sfu
# winbind nss info = sfu
"

Then getent passwd is fine and dandy:
"
getent passwd
root:x:0:0:root:/root:/bin/bash
bin:x:1:1:bin:/bin:/bin/bash
daemon:x:2:2:Daemon:/sbin:/bin/bash
lp:x:4:7:Printing daemon:/var/spool/lpd:/bin/bash
mail:x:8:12:Mailer daemon:/var/spool/clientmqueue:/bin/false
news:x:9:13:News system:/etc/news:/bin/bash
uucp:x:10:14:Unix-to-Unix CoPy system:/etc/uucp:/bin/bash
man:x:13:62:Manual pages viewer:/var/cache/man:/bin/bash
at:x:25:25:Batch jobs daemon:/var/spool/atjobs:/bin/bash
sshd:x:71:65:SSH daemon:/var/lib/sshd:/bin/false
nobody:x:65534:65533:nobody:/var/lib/nobody:/bin/bash
exim:x:51:51:Exim MTA:/:/bin/sh
ldap:x:76:70:User for OpenLDAP:/var/lib/ldap:/bin/bash
administrator:x:10000:10009:Administrator:/home/administrator:/bin/bash
guest:x:10001:10010:Guest:/home/guest:/bin/bash
support_388945a0:x:10002:10009:SUPPORT_388945a0:/home/support_388945a0:/bin/bash
sd1$:x:10003:10011:SD1:/home/sd1_:/bin/bash
krbtgt:x:10004:10009:krbtgt:/home/krbtgt:/bin/bash
bob:x:10005:10009:bob:/home/bob:/bin/bash
mr:x:10006:10009:mr:/home/mr:/bin/bash
w1$:x:10007:10012:w1:/home/w1_:/bin/bash
ldap:x:10008:10009:ldap:/home/ldap:/bin/bash
"

There are UNIX type entries in AD for the user mr.
Comment 1 Guenther Deschner 2005-08-03 13:22:05 UTC 
Please post your full log.winbindd (log level 10) right from starting the
daemon, then call "getent user BSS\\mr".

Please also make sure to verify the following:
Have you made sure the ad.so module is installed in the correct location, does
winbindd find and load it? 
You have the correct libnss_winbind.so installed?
Comment 2 Mike Rose 2005-08-04 09:33:06 UTC 
I do not seem to have any file with the name of ad.so

Samba was configured and built like so:
./configure --prefix=/usr/local/samba/ --with-ldap --with-ads --with-krb5
--with-pam --with-winbind; make
make install

OK, here's the winbind log from (log level 10 and rather a lot):
nmbd; winbindd -d 10
getent passwd
killproc winbindd; killproc nmbd

"
[2005/08/04 17:32:05, 5] lib/debug.c:debug_dump_status(368)
  INFO: Current debug levels:
    all: True/10
    tdb: False/0
    printdrivers: False/0
    lanman: False/0
    smb: False/0
    rpc_parse: False/0
    rpc_srv: False/0
    rpc_cli: False/0
    passdb: False/0
    sam: False/0
    auth: False/0
    winbind: False/0
    vfs: False/0
    idmap: False/0
    quota: False/0
    acls: False/0
    locking: False/0
    msdfs: False/0
[2005/08/04 17:32:05, 1] nsswitch/winbindd.c:main(977)
  winbindd version 3.0.20rc1 started.
  Copyright The Samba Team 2000-2004
[2005/08/04 17:32:05, 3] param/loadparm.c:lp_load(4082)
  lp_load: refreshing parameters
[2005/08/04 17:32:05, 3] param/loadparm.c:init_globals(1366)
  Initialising global parameters
[2005/08/04 17:32:05, 3] param/params.c:pm_process(574)
  params.c:pm_process() - Processing configuration file
"/usr/local/samba//lib/smb.conf"
[2005/08/04 17:32:05, 3] param/loadparm.c:do_section(3542)
  Processing section "[global]"
  doing parameter winbind separator = +
  doing parameter idmap uid = 100-20000
  doing parameter idmap gid = 100-20000
  doing parameter winbind enum users = yes
  doing parameter winbind enum groups = yes
  doing parameter template homedir = /home/%U
  doing parameter template shell = /bin/bash
  doing parameter winbind cache time = 600
  doing parameter winbind use default domain = yes
  doing parameter workgroup = BSS
  doing parameter obey pam restrictions = Yes
  doing parameter realm = bss.phy.private.cam.ac.uk
  doing parameter security = ADS
  doing parameter encrypt passwords = yes
  doing parameter password server = sd1.bss.phy.private.cam.ac.uk
[2005/08/04 17:32:05, 4] param/loadparm.c:lp_load(4113)
  pm_process() returned Yes
[2005/08/04 17:32:05, 7] param/loadparm.c:lp_servicenumber(4226)
  lp_servicenumber: couldn't find homes
[2005/08/04 17:32:05, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 0 for IPC$
[2005/08/04 17:32:05, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/04 17:32:05, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 1 for ADMIN$
[2005/08/04 17:32:05, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/04 17:32:05, 10] param/loadparm.c:set_server_role(4031)
  set_server_role: role = ROLE_DOMAIN_MEMBER
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2LE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2LE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16LE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16LE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2BE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2BE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16BE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16BE
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF8
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF8
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-8
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-8
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ASCII
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ASCII
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset 646
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset 646
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ISO-8859-1
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ISO-8859-1
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS2-HEX
[2005/08/04 17:32:05, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS2-HEX
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/04 17:32:05, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/04 17:32:05, 5] lib/util.c:init_names(260)
  Netbios name list:-
  my_netbios_names[0]="W1"
[2005/08/04 17:32:05, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/04 17:32:05, 5] lib/gencache.c:gencache_init(59)
  Opening cache file at /usr/local/samba//var/locks/gencache.tdb
[2005/08/04 17:32:05, 5] libsmb/namecache.c:namecache_enable(58)
  namecache_enable: enabling netbios namecache, timeout 660 seconds
[2005/08/04 17:32:05, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ldap'
[2005/08/04 17:32:05, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'tdb'
[2005/08/04 17:32:05, 10] sam/idmap_tdb.c:db_idmap_init(500)
  db_idmap_init: Opening tdbfile /usr/local/samba//var/locks/winbindd_idmap.tdb
[2005/08/04 17:32:05, 8] lib/util.c:fcntl_lock(1815)
  fcntl_lock 8 13 0 1 1
[2005/08/04 17:32:05, 8] lib/util.c:fcntl_lock(1850)
  fcntl_lock: Lock call successful
[2005/08/04 17:32:05, 2] lib/tallocmsg.c:register_msg_pool_usage(56)
  Registered MSG_REQ_POOL_USAGE
[2005/08/04 17:32:05, 2] lib/dmallocmsg.c:register_dmalloc_msgs(71)
  Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
[2005/08/04 17:32:05, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BSS BSS.PHY.PRIVATE.CAM.AC.UK
S-1-5-21-571314010-3273254802-3516507047
[2005/08/04 17:32:05, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BUILTIN  S-1-5-32
[2005/08/04 17:32:05, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain W1  S-1-5-21-1038852147-1775589294-3259616702
[2005/08/04 17:32:05, 10] nsswitch/winbindd_util.c:open_winbindd_socket(890)
  open_winbindd_socket: opened socket fd 12
[2005/08/04 17:32:05, 10] nsswitch/winbindd_util.c:open_winbindd_priv_socket(902)
  open_winbindd_priv_socket: opened socket fd 14
[2005/08/04 17:32:05, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 18839
[2005/08/04 17:32:05, 5] nsswitch/winbindd_util.c:init_child_recv(407)
  Received child initialization response for domain BSS
[2005/08/04 17:32:05, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 18839
[2005/08/04 17:32:05, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1562)
  Retrieving extra data length=71
[2005/08/04 17:32:08, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 18
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn INTERFACE_VERSION
[2005/08/04 17:32:08, 3] nsswitch/winbindd_misc.c:winbindd_interface_version(460)
  [    0]: request interface version
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn WINBINDD_PRIV_PIPE_DIR
[2005/08/04 17:32:08, 3] nsswitch/winbindd_misc.c:winbindd_priv_pipe_dir(493)
  [    0]: request location of privileged pipe
[2005/08/04 17:32:08, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 19
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn SETPWENT
[2005/08/04 17:32:08, 3] nsswitch/winbindd_user.c:winbindd_setpwent_internal(429)
  [    0]: setpwent
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/04 17:32:08, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:fetch_cache_seqnum(271)
  fetch_cache_seqnum: invalid data size key [SEQNUM/BSS]
[2005/08/04 17:32:08, 3] nsswitch/winbindd_ads.c:sequence_number(776)
  ads: fetch sequence_number for BSS
[2005/08/04 17:32:08, 6] libads/ldap.c:ads_find_dc(214)
  ads_find_dc: looking for realm 'bss.phy.private.cam.ac.uk'
[2005/08/04 17:32:08, 8] libsmb/namequery.c:get_sorted_dc_list(1433)
  get_sorted_dc_list: attempting lookup using [ads]
[2005/08/04 17:32:08, 10] libsmb/namequery.c:internal_resolve_name(1028)
  internal_resolve_name: looking up sd1.bss.phy.private.cam.ac.uk#20
[2005/08/04 17:32:08, 10] lib/gencache.c:gencache_get(263)
  Returning valid cache entry: key = NBT/SD1.BSS.PHY.PRIVATE.CAM.AC.UK#20, value
= 172.24.125.5:0, timeout = Thu Aug  4 17:43:05 2005
  
[2005/08/04 17:32:08, 5] libsmb/namecache.c:namecache_fetch(201)
  name sd1.bss.phy.private.cam.ac.uk#20 found.
[2005/08/04 17:32:08, 10] libsmb/namequery.c:remove_duplicate_addrs2(320)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2005/08/04 17:32:08, 4] libsmb/namequery.c:get_dc_list(1406)
  get_dc_list: returning 1 ip addresses in an ordered list
[2005/08/04 17:32:08, 4] libsmb/namequery.c:get_dc_list(1407)
  get_dc_list: 172.24.125.5:389 
[2005/08/04 17:32:08, 5] libads/ldap.c:ads_try_connect(123)
  ads_try_connect: trying ldap server '172.24.125.5' port 389
[2005/08/04 17:32:08, 3] libads/ldap.c:ads_connect(285)
  Connected to LDAP server 172.24.125.5
[2005/08/04 17:32:08, 3] libads/ldap.c:ads_server_info(2514)
  got ldap server name sd1@BSS.PHY.PRIVATE.CAM.AC.UK, using bind path:
dc=BSS,dc=PHY,dc=PRIVATE,dc=CAM,dc=AC,dc=UK
[2005/08/04 17:32:08, 4] libads/ldap.c:ads_server_info(2520)
  time offset is -1 seconds
[2005/08/04 17:32:08, 4] libads/sasl.c:ads_sasl_bind(451)
  Found SASL mechanism GSS-SPNEGO
[2005/08/04 17:32:08, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2005/08/04 17:32:08, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2005/08/04 17:32:08, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2005/08/04 17:32:08, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2005/08/04 17:32:08, 3] libads/sasl.c:ads_sasl_spnego_bind(215)
  ads_sasl_spnego_bind: got server principal name =sd1$@BSS.PHY.PRIVATE.CAM.AC.UK
[2005/08/04 17:32:08, 3] libsmb/clikrb5.c:ads_krb5_mk_req(384)
  ads_krb5_mk_req: krb5_cc_get_principal failed (No such file or directory)
[2005/08/04 17:32:08, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(321)
  Ticket in ccache[MEMORY:winbind_ccache] expiration Fri, 05 Aug 2005 03:32:06 GMT
[2005/08/04 17:32:08, 10] libsmb/clikrb5.c:ads_krb5_mk_req(411)
  ads_krb5_mk_req: Ticket (sd1$@BSS.PHY.PRIVATE.CAM.AC.UK) in ccache
(MEMORY:winbind_ccache) is valid until: (Fri, 05 Aug 2005 03:32:06 GMT - 1123209126)
[2005/08/04 17:32:08, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(512)
  Got KRB5 session key of length 16
[2005/08/04 17:32:08, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectclass=*) gave 1 replies
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:store_cache_seqnum(324)
  store_cache_seqnum: success [BSS][59239 @ 1123173128]
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 59239
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:query_user_list(730)
  query_user_list: [Cached] - doing backend query for list for domain BSS
[2005/08/04 17:32:08, 3] nsswitch/winbindd_ads.c:query_user_list(136)
  ads: query_user_list
[2005/08/04 17:32:08, 7] nsswitch/winbindd_ads.c:ads_cached_connection(48)
  Current tickets expire at 1123209126, time is now 1123173128
[2005/08/04 17:32:08, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectClass=user) gave 9 replies
[2005/08/04 17:32:08, 3] nsswitch/winbindd_ads.c:query_user_list(206)
  ads query_user_list gave 9 entries
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(354)
  refresh_sequence_number: BSS time ok
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 59239
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: ADMINISTRATOR ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-500 ->
Administrator
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-500 (acct_name
Administrator)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: GUEST -> S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-501 -> Guest
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-501 (acct_name Guest)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SUPPORT_388945A0 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1001 ->
SUPPORT_388945a0
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1001 (acct_name
SUPPORT_388945a0)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SD1$ -> S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1004 -> SD1$
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1004 (acct_name SD1$)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: KRBTGT -> S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-502 -> krbtgt
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-502 (acct_name krbtgt)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: BOB -> S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1108 -> bob
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1108 (acct_name bob)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: MR -> S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1118 -> mr
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1118 (acct_name mr)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: W1$ -> S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1129 -> w1$
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1129 (acct_name w1$)
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: LDAP -> S-1-5-21-571314010-3273254802-3516507047-1130
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1130 -> ldap
[2005/08/04 17:32:08, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1130 (acct_name ldap)
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-500]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-500 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-500
-> UID 10000
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-500 -> UID 10000 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10000
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10000 ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10000]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-501]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-501 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-501
-> UID 10001
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-501 -> UID 10001 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10001
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10001 ->
S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10001]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-514]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-514 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-514
-> GID 10010
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-514 -> GID 10010 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10010
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10010 ->
S-1-5-21-571314010-3273254802-3516507047-514
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10010]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1001]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1001
-> UID 10002
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 -> UID 10002 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10002
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10002 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10002]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1004]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1004
-> UID 10003
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 -> UID 10003 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10003
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10003 ->
S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10003]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-516]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-516 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-516
-> GID 10011
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-516 -> GID 10011 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10011
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10011 ->
S-1-5-21-571314010-3273254802-3516507047-516
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10011]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-502]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-502 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-502
-> UID 10004
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-502 -> UID 10004 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10004
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10004 ->
S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10004]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1108]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1108
-> UID 10005
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 -> UID 10005 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10005
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10005 ->
S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10005]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1118]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1118
-> UID 10006
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 -> UID 10006 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10006
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10006 ->
S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10006]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1129]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1129
-> UID 10007
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 -> UID 10007 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10007
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10007 ->
S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10007]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-515]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-515 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-515
-> GID 10012
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-515 -> GID 10012 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10012
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10012 ->
S-1-5-21-571314010-3273254802-3516507047-515
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10012]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1130]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1130 of type 0x1
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1130
-> UID 10008
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1130 -> UID 10008 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10008
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10008 ->
S-1-5-21-571314010-3273254802-3516507047-1130
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10008]
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/04 17:32:08, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/04 17:32:08, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/04 17:32:08, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/04 17:32:08, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn ENDPWENT
[2005/08/04 17:32:08, 3] nsswitch/winbindd_user.c:winbindd_endpwent(505)
  [    0]: endpwent
[2005/08/04 17:32:10, 10] nsswitch/winbindd_dual.c:dual_client_read(69)
  client_read: read 0 bytes. Need 1828 more for a full request.
[2005/08/04 17:32:10, 5] nsswitch/winbindd_dual.c:dual_client_read(76)
  read failed on sock 9, pid 18837: EOF
"
Comment 3 Mike Rose 2005-08-10 08:46:41 UTC 
Just tried this with Version 3.0.20rc2, no luck either. 
getent passwd and getent group work with:

# idmap backend = ad
# winbind nss info = sfu

, but not with:
idmap backend = ad
winbind nss info = sfu

I can provide an ssh login to a test machine if it would help.
Comment 4 Guenther Deschner 2005-08-11 04:43:01 UTC 
First of all, you did not enable the build of the ad-module. Do so with
./configure --with-shared-modules=idmap_ad --prefix=/usr/local/samba (...your
other opts). (We might change this default-behaviour for the final 3.0.20-release).

Then, after the build, manually copy the module bin/idmap_ad.so to
/usr/local/samba/lib/idmap/ad.so

Then you send the wrong logfile (obviously without the two parameters set), so
there are nor errors w.r.t the non-existing ad-module.

Please set 
"winbind nss info = sfu" only. And report back if none of your sfu-attributes
are reflected (incl. winbindd-logfile) in NSS.

Then set both parameters and report back if there any further problems (incl.
winbindd-logfile).
Comment 5 Mike Rose 2005-08-11 07:19:30 UTC 
Data requested below, but first:

apologies for sending wrong logfile.

using winbind nss info = sfu getent passwd worked (no sfu data).
setting idmap backend = ad produced errors in the winbindd log because
ad.so could not be found. idmap_ad.so existed in the same directory
ln -s /usr/local/samba//lib/idmap/idmap_ad.so /usr/local/samba//lib/idmap/ad.so
errors gone, but still no sfu UNIX attribs being pulled from ADS for user "mr".
removed (expecting uid of 500 and gid of 100):
        idmap uid = 100-20000
        idmap gid = 100-20000
from smb.conf as I was wondering if SFU data is used for UID maybe these are not
neeeded, gives:
[2005/08/11 15:12:53, 1] nsswitch/winbindd_user.c:winbindd_getpwent(712)
  could not lookup domain user mr



Data:

testparm
Load smb config files from /usr/local/samba//lib/smb.conf
Loaded services file OK.
'winbind separator = +' might cause problems with group membership.
Server role: ROLE_DOMAIN_MEMBER
Press enter to see a dump of your service definitions

[global]
        workgroup = BSS
        realm = BSS.PHY.PRIVATE.CAM.AC.UK
        security = ADS
        obey pam restrictions = Yes
        password server = sd1.bss.phy.private.cam.ac.uk
        idmap uid = 100-20000
        idmap gid = 100-20000
        template homedir = /home/%U
        template shell = /bin/bash
        winbind separator = +
        winbind cache time = 600
        winbind use default domain = Yes
        winbind nss info = sfu

ls -l /usr/local/samba/lib/idmap/idmap_ad.so
-rwxr-xr-x  1 root root 15428 Aug 11 14:11 /usr/local/samba/lib/idmap/idmap_ad.so

w1:/scratch/samba-3.0.20rc2/source# nmbd -V
Version 3.0.20rc2

getent passwd
root:x:0:0:root:/root:/bin/bash
bin:x:1:1:bin:/bin:/bin/bash
daemon:x:2:2:Daemon:/sbin:/bin/bash
lp:x:4:7:Printing daemon:/var/spool/lpd:/bin/bash
mail:x:8:12:Mailer daemon:/var/spool/clientmqueue:/bin/false
news:x:9:13:News system:/etc/news:/bin/bash
uucp:x:10:14:Unix-to-Unix CoPy system:/etc/uucp:/bin/bash
man:x:13:62:Manual pages viewer:/var/cache/man:/bin/bash
at:x:25:25:Batch jobs daemon:/var/spool/atjobs:/bin/bash
sshd:x:71:65:SSH daemon:/var/lib/sshd:/bin/false
nobody:x:65534:65533:nobody:/var/lib/nobody:/bin/bash
exim:x:51:51:Exim MTA:/:/bin/sh
ldap:x:76:70:User for OpenLDAP:/var/lib/ldap:/bin/bash
administrator:x:10000:10009:Administrator:/home/administrator:/bin/bash
guest:x:10001:10010:Guest:/home/guest:/bin/bash
support_388945a0:x:10002:10009:SUPPORT_388945a0:/home/support_388945a0:/bin/bash
sd1$:x:10003:10011:SD1:/home/sd1_:/bin/bash
krbtgt:x:10004:10009:krbtgt:/home/krbtgt:/bin/bash
bob:x:10005:10009:bob:/home/bob:/bin/bash
mr:x:10006:10009:mr:/home/mr:/bin/bash
w1$:x:10007:10012:w1:/home/w1_:/bin/bash

[2005/08/11 14:58:35, 5] lib/debug.c:debug_dump_status(368)
  INFO: Current debug levels:
    all: True/10
    tdb: False/0
    printdrivers: False/0
    lanman: False/0
    smb: False/0
    rpc_parse: False/0
    rpc_srv: False/0
    rpc_cli: False/0
    passdb: False/0
    sam: False/0
    auth: False/0
    winbind: False/0
    vfs: False/0
    idmap: False/0
    quota: False/0
    acls: False/0
    locking: False/0
    msdfs: False/0
[2005/08/11 14:58:35, 1] nsswitch/winbindd.c:main(977)
  winbindd version 3.0.20rc2 started.
  Copyright The Samba Team 2000-2004
[2005/08/11 14:58:35, 3] param/loadparm.c:lp_load(4082)
  lp_load: refreshing parameters
[2005/08/11 14:58:35, 3] param/loadparm.c:init_globals(1366)
  Initialising global parameters
[2005/08/11 14:58:35, 3] param/params.c:pm_process(574)
  params.c:pm_process() - Processing configuration file
"/usr/local/samba//lib/smb.conf"
[2005/08/11 14:58:35, 3] param/loadparm.c:do_section(3542)
  Processing section "[global]"
  doing parameter winbind separator = +
  doing parameter idmap uid = 100-20000
  doing parameter idmap gid = 100-20000
  doing parameter winbind enum users = yes
  doing parameter winbind enum groups = yes
  doing parameter template homedir = /home/%U
  doing parameter template shell = /bin/bash
  doing parameter winbind cache time = 600
  doing parameter winbind use default domain = yes
  doing parameter winbind nss info = sfu
  doing parameter workgroup = BSS
  doing parameter obey pam restrictions = Yes
  doing parameter realm = bss.phy.private.cam.ac.uk
  doing parameter security = ADS
  doing parameter encrypt passwords = yes
  doing parameter password server = sd1.bss.phy.private.cam.ac.uk
[2005/08/11 14:58:35, 4] param/loadparm.c:lp_load(4113)
  pm_process() returned Yes
[2005/08/11 14:58:35, 7] param/loadparm.c:lp_servicenumber(4226)
  lp_servicenumber: couldn't find homes
[2005/08/11 14:58:35, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 0 for IPC$
[2005/08/11 14:58:35, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/11 14:58:35, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 1 for ADMIN$
[2005/08/11 14:58:35, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/11 14:58:35, 10] param/loadparm.c:set_server_role(4031)
  set_server_role: role = ROLE_DOMAIN_MEMBER
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2LE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2LE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16LE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16LE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2BE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2BE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16BE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16BE
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF8
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF8
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-8
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-8
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ASCII
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ASCII
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset 646
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset 646
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ISO-8859-1
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ISO-8859-1
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS2-HEX
[2005/08/11 14:58:35, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS2-HEX
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 14:58:35, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/11 14:58:35, 5] lib/util.c:init_names(260)
  Netbios name list:-
  my_netbios_names[0]="W1"
[2005/08/11 14:58:35, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/11 14:58:35, 5] lib/gencache.c:gencache_init(59)
  Opening cache file at /usr/local/samba//var/locks/gencache.tdb
[2005/08/11 14:58:35, 5] libsmb/namecache.c:namecache_enable(58)
  namecache_enable: enabling netbios namecache, timeout 660 seconds
[2005/08/11 14:58:35, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ldap'
[2005/08/11 14:58:35, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'tdb'
[2005/08/11 14:58:35, 10] sam/idmap_tdb.c:db_idmap_init(500)
  db_idmap_init: Opening tdbfile /usr/local/samba//var/locks/winbindd_idmap.tdb
[2005/08/11 14:58:35, 8] lib/util.c:fcntl_lock(1815)
  fcntl_lock 8 13 0 1 1
[2005/08/11 14:58:35, 8] lib/util.c:fcntl_lock(1850)
  fcntl_lock: Lock call successful
[2005/08/11 14:58:35, 2] lib/tallocmsg.c:register_msg_pool_usage(56)
  Registered MSG_REQ_POOL_USAGE
[2005/08/11 14:58:35, 2] lib/dmallocmsg.c:register_dmalloc_msgs(71)
  Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
[2005/08/11 14:58:35, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BSS BSS.PHY.PRIVATE.CAM.AC.UK
S-1-5-21-571314010-3273254802-3516507047
[2005/08/11 14:58:35, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BUILTIN  S-1-5-32
[2005/08/11 14:58:35, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain W1  S-1-5-21-1038852147-1775589294-3259616702
[2005/08/11 14:58:35, 10] nsswitch/winbindd_util.c:open_winbindd_socket(890)
  open_winbindd_socket: opened socket fd 12
[2005/08/11 14:58:35, 10] nsswitch/winbindd_util.c:open_winbindd_priv_socket(902)
  open_winbindd_priv_socket: opened socket fd 14
[2005/08/11 14:58:35, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 7421
[2005/08/11 14:58:35, 5] nsswitch/winbindd_util.c:init_child_recv(407)
  Received child initialization response for domain BSS
[2005/08/11 14:58:35, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 7421
[2005/08/11 14:58:35, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1562)
  Retrieving extra data length=71
[2005/08/11 14:58:41, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 18
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn INTERFACE_VERSION
[2005/08/11 14:58:41, 3] nsswitch/winbindd_misc.c:winbindd_interface_version(460)
  [    0]: request interface version
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn WINBINDD_PRIV_PIPE_DIR
[2005/08/11 14:58:41, 3] nsswitch/winbindd_misc.c:winbindd_priv_pipe_dir(493)
  [    0]: request location of privileged pipe
[2005/08/11 14:58:41, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 19
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn SETPWENT
[2005/08/11 14:58:41, 3] nsswitch/winbindd_user.c:winbindd_setpwent_internal(429)
  [    0]: setpwent
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/11 14:58:41, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:fetch_cache_seqnum(271)
  fetch_cache_seqnum: invalid data size key [SEQNUM/BSS]
[2005/08/11 14:58:41, 3] nsswitch/winbindd_ads.c:sequence_number(776)
  ads: fetch sequence_number for BSS
[2005/08/11 14:58:41, 6] libads/ldap.c:ads_find_dc(214)
  ads_find_dc: looking for realm 'bss.phy.private.cam.ac.uk'
[2005/08/11 14:58:41, 8] libsmb/namequery.c:get_sorted_dc_list(1433)
  get_sorted_dc_list: attempting lookup using [ads]
[2005/08/11 14:58:41, 10] libsmb/namequery.c:internal_resolve_name(1028)
  internal_resolve_name: looking up sd1.bss.phy.private.cam.ac.uk#20
[2005/08/11 14:58:41, 10] lib/gencache.c:gencache_get(263)
  Returning valid cache entry: key = NBT/SD1.BSS.PHY.PRIVATE.CAM.AC.UK#20, value
= 172.24.125.5:0, timeout = Thu Aug 1
1 15:07:01 2005
  
[2005/08/11 14:58:41, 5] libsmb/namecache.c:namecache_fetch(201)
  name sd1.bss.phy.private.cam.ac.uk#20 found.
[2005/08/11 14:58:41, 10] libsmb/namequery.c:remove_duplicate_addrs2(320)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2005/08/11 14:58:41, 4] libsmb/namequery.c:get_dc_list(1406)
  get_dc_list: returning 1 ip addresses in an ordered list
[2005/08/11 14:58:41, 4] libsmb/namequery.c:get_dc_list(1407)
  get_dc_list: 172.24.125.5:389 
[2005/08/11 14:58:41, 5] libads/ldap.c:ads_try_connect(123)
  ads_try_connect: trying ldap server '172.24.125.5' port 389
[2005/08/11 14:58:41, 3] libads/ldap.c:ads_connect(285)
  Connected to LDAP server 172.24.125.5
[2005/08/11 14:58:41, 3] libads/ldap.c:ads_server_info(2514)
  got ldap server name sd1@BSS.PHY.PRIVATE.CAM.AC.UK, using bind path:
dc=BSS,dc=PHY,dc=PRIVATE,dc=CAM,dc=AC,dc=UK
[2005/08/11 14:58:41, 4] libads/ldap.c:ads_server_info(2520)
  time offset is 0 seconds
[2005/08/11 14:58:41, 4] libads/sasl.c:ads_sasl_bind(451)
  Found SASL mechanism GSS-SPNEGO
[2005/08/11 14:58:41, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2005/08/11 14:58:41, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2005/08/11 14:58:41, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2005/08/11 14:58:41, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2005/08/11 14:58:41, 3] libads/sasl.c:ads_sasl_spnego_bind(215)
  ads_sasl_spnego_bind: got server principal name =sd1$@BSS.PHY.PRIVATE.CAM.AC.UK
[2005/08/11 14:58:41, 3] libsmb/clikrb5.c:ads_krb5_mk_req(384)
  ads_krb5_mk_req: krb5_cc_get_principal failed (No such file or directory)
[2005/08/11 14:58:41, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(321)
  Ticket in ccache[MEMORY:winbind_ccache] expiration Fri, 12 Aug 2005 00:58:41 GMT
[2005/08/11 14:58:41, 10] libsmb/clikrb5.c:ads_krb5_mk_req(411)
  ads_krb5_mk_req: Ticket (sd1$@BSS.PHY.PRIVATE.CAM.AC.UK) in ccache
(MEMORY:winbind_ccache) is valid until: (Fri, 12 
Aug 2005 00:58:41 GMT - 1123804721)
[2005/08/11 14:58:41, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(512)
  Got KRB5 session key of length 16
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.311) gave 1 replies
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.310) gave 1 replies
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.344) gave 1 replies
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.312) gave 1 replies
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectclass=*) gave 1 replies
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:store_cache_seqnum(324)
  store_cache_seqnum: success [BSS][61516 @ 1123768721]
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 61516
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:query_user_list(730)
  query_user_list: [Cached] - doing backend query for list for domain BSS
[2005/08/11 14:58:41, 3] nsswitch/winbindd_ads.c:query_user_list(136)
  ads: query_user_list
[2005/08/11 14:58:41, 7] nsswitch/winbindd_ads.c:ads_cached_connection(48)
  Current tickets expire at 1123804721, time is now 1123768721
[2005/08/11 14:58:41, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectClass=user) gave 8 replies
[2005/08/11 14:58:41, 3] nsswitch/winbindd_ads.c:query_user_list(206)
  ads query_user_list gave 8 entries
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(354)
  refresh_sequence_number: BSS time ok
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 61516
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: ADMINISTRATOR ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-500 ->
Administrator
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-500 (acct_name
Administrator)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: GUEST -> S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-501 -> Guest
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-501 (acct_name Guest)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SUPPORT_388945A0 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1001 ->
SUPPORT_388945a0
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1001 (acct_name
SUPPORT_388945a0)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SD1$ -> S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1004 -> SD1$
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1004 (acct_name SD1$)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: KRBTGT -> S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-502 -> krbtgt
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-502 (acct_name krbtgt)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: BOB -> S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1108 -> bob
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1108 (acct_name bob)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: MR -> S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1118 -> mr
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1118 (acct_name mr)
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: W1$ -> S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1129 -> w1$
[2005/08/11 14:58:41, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1129 (acct_name w1$)
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-500]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-500 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-500
-> UID 10000
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-500 -> UID 10000 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10000
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10000 ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10000]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-501]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-501 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-501
-> UID 10001
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-501 -> UID 10001 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10001
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10001 ->
S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10001]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-514]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-514 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-514
-> GID 10010
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-514 -> GID 10010 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10010
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10010 ->
S-1-5-21-571314010-3273254802-3516507047-514
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10010]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1001]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1001
-> UID 10002
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 -> UID 10002 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10002
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10002 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10002]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1004]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1004
-> UID 10003
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 -> UID 10003 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10003
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10003 ->
S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10003]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-516]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-516 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-516
-> GID 10011
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-516 -> GID 10011 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10011
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10011 ->
S-1-5-21-571314010-3273254802-3516507047-516
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10011]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-502]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-502 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-502
-> UID 10004
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-502 -> UID 10004 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10004
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10004 ->
S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10004]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1108]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1108
-> UID 10005
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 -> UID 10005 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10005
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10005 ->
S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10005]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1118]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1118
-> UID 10006
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 -> UID 10006 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10006
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10006 ->
S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10006]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1129]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 of type 0x1
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1129
-> UID 10007
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 -> UID 10007 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10007
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10007 ->
S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10007]
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-515]
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-515 of type 0x2
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-515
-> GID 10012
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-515 -> GID 10012 
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10012
[2005/08/11 14:58:41, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10012 ->
S-1-5-21-571314010-3273254802-3516507047-515
[2005/08/11 14:58:41, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10012]
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/11 14:58:41, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/11 14:58:41, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn ENDPWENT
[2005/08/11 14:58:41, 3] nsswitch/winbindd_user.c:winbindd_endpwent(505)
  [    0]: endpwent


===========================================================================
Comment 6 Mike Rose 2005-08-11 07:19:46 UTC 
w1:/scratch/samba-3.0.20rc2/source# testparm
Load smb config files from /usr/local/samba//lib/smb.conf
Loaded services file OK.
'winbind separator = +' might cause problems with group membership.
Server role: ROLE_DOMAIN_MEMBER
Press enter to see a dump of your service definitions

[global]
        workgroup = BSS
        realm = BSS.PHY.PRIVATE.CAM.AC.UK
        security = ADS
        obey pam restrictions = Yes
        password server = sd1.bss.phy.private.cam.ac.uk
        idmap backend = ad
        idmap uid = 100-20000
        idmap gid = 100-20000
        template homedir = /home/%U
        template shell = /bin/bash
        winbind separator = +
        winbind cache time = 600
        winbind use default domain = Yes
        winbind nss info = sfu

w1:/scratch/samba-3.0.20rc2/source# !get 
getent passwd
root:x:0:0:root:/root:/bin/bash
bin:x:1:1:bin:/bin:/bin/bash
daemon:x:2:2:Daemon:/sbin:/bin/bash
lp:x:4:7:Printing daemon:/var/spool/lpd:/bin/bash
mail:x:8:12:Mailer daemon:/var/spool/clientmqueue:/bin/false
news:x:9:13:News system:/etc/news:/bin/bash
uucp:x:10:14:Unix-to-Unix CoPy system:/etc/uucp:/bin/bash
man:x:13:62:Manual pages viewer:/var/cache/man:/bin/bash
at:x:25:25:Batch jobs daemon:/var/spool/atjobs:/bin/bash
sshd:x:71:65:SSH daemon:/var/lib/sshd:/bin/false
nobody:x:65534:65533:nobody:/var/lib/nobody:/bin/bash
exim:x:51:51:Exim MTA:/:/bin/sh
ldap:x:76:70:User for OpenLDAP:/var/lib/ldap:/bin/bash

[2005/08/11 15:17:17, 5] lib/debug.c:debug_dump_status(368)
  INFO: Current debug levels:
    all: True/10
    tdb: False/0
    printdrivers: False/0
    lanman: False/0
    smb: False/0
    rpc_parse: False/0
    rpc_srv: False/0
    rpc_cli: False/0
    passdb: False/0
    sam: False/0
    auth: False/0
    winbind: False/0
    vfs: False/0
    idmap: False/0
    quota: False/0
    acls: False/0
    locking: False/0
    msdfs: False/0
[2005/08/11 15:17:17, 1] nsswitch/winbindd.c:main(977)
  winbindd version 3.0.20rc2 started.
  Copyright The Samba Team 2000-2004
[2005/08/11 15:17:17, 3] param/loadparm.c:lp_load(4082)
  lp_load: refreshing parameters
[2005/08/11 15:17:17, 3] param/loadparm.c:init_globals(1366)
  Initialising global parameters
[2005/08/11 15:17:17, 3] param/params.c:pm_process(574)
  params.c:pm_process() - Processing configuration file
"/usr/local/samba//lib/smb.conf"
[2005/08/11 15:17:17, 3] param/loadparm.c:do_section(3542)
  Processing section "[global]"
  doing parameter winbind separator = +
  doing parameter idmap uid = 100-20000
  doing parameter idmap gid = 100-20000
  doing parameter winbind enum users = yes
  doing parameter winbind enum groups = yes
  doing parameter template homedir = /home/%U
  doing parameter template shell = /bin/bash
  doing parameter winbind cache time = 600
  doing parameter winbind use default domain = yes
  doing parameter idmap backend = ad
  doing parameter winbind nss info = sfu
  doing parameter workgroup = BSS
  doing parameter obey pam restrictions = Yes
  doing parameter realm = bss.phy.private.cam.ac.uk
  doing parameter security = ADS
  doing parameter encrypt passwords = yes
  doing parameter password server = sd1.bss.phy.private.cam.ac.uk
[2005/08/11 15:17:17, 4] param/loadparm.c:lp_load(4113)
  pm_process() returned Yes
[2005/08/11 15:17:17, 7] param/loadparm.c:lp_servicenumber(4226)
  lp_servicenumber: couldn't find homes
[2005/08/11 15:17:17, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 0 for IPC$
[2005/08/11 15:17:17, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/11 15:17:17, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 1 for ADMIN$
[2005/08/11 15:17:17, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/08/11 15:17:17, 10] param/loadparm.c:set_server_role(4031)
  set_server_role: role = ROLE_DOMAIN_MEMBER
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2LE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2LE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16LE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16LE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2BE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2BE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16BE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16BE
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF8
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF8
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-8
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-8
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ASCII
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ASCII
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset 646
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset 646
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ISO-8859-1
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ISO-8859-1
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS2-HEX
[2005/08/11 15:17:17, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS2-HEX
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/08/11 15:17:17, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/11 15:17:17, 5] lib/util.c:init_names(260)
  Netbios name list:-
  my_netbios_names[0]="W1"
[2005/08/11 15:17:17, 2] lib/interface.c:add_interface(81)
  added interface ip=131.111.75.196 bcast=131.111.75.255 nmask=255.255.255.0
[2005/08/11 15:17:17, 5] lib/gencache.c:gencache_init(59)
  Opening cache file at /usr/local/samba//var/locks/gencache.tdb
[2005/08/11 15:17:17, 5] libsmb/namecache.c:namecache_enable(58)
  namecache_enable: enabling netbios namecache, timeout 660 seconds
[2005/08/11 15:17:17, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ldap'
[2005/08/11 15:17:17, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'tdb'
[2005/08/11 15:17:17, 10] sam/idmap_tdb.c:db_idmap_init(500)
  db_idmap_init: Opening tdbfile /usr/local/samba//var/locks/winbindd_idmap.tdb
[2005/08/11 15:17:17, 3] sam/idmap.c:idmap_init(132)
  idmap_init: using 'ad' as remote backend
[2005/08/11 15:17:17, 5] lib/module.c:smb_probe_module(104)
  Probing module 'ad'
[2005/08/11 15:17:17, 5] lib/module.c:smb_probe_module(115)
  Probing module 'ad': Trying to load from /usr/local/samba//lib/idmap/ad.so
[2005/08/11 15:17:17, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ad'
[2005/08/11 15:17:17, 2] lib/module.c:do_smb_load_module(66)
  Module '/usr/local/samba//lib/idmap/ad.so' loaded
[2005/08/11 15:17:17, 8] lib/util.c:fcntl_lock(1815)
  fcntl_lock 8 13 0 1 1
[2005/08/11 15:17:17, 8] lib/util.c:fcntl_lock(1850)
  fcntl_lock: Lock call successful
[2005/08/11 15:17:17, 2] lib/tallocmsg.c:register_msg_pool_usage(56)
  Registered MSG_REQ_POOL_USAGE
[2005/08/11 15:17:17, 2] lib/dmallocmsg.c:register_dmalloc_msgs(71)
  Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
[2005/08/11 15:17:17, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BSS BSS.PHY.PRIVATE.CAM.AC.UK
S-1-5-21-571314010-3273254802-3516507047
[2005/08/11 15:17:17, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BUILTIN  S-1-5-32
[2005/08/11 15:17:17, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain W1  S-1-5-21-1038852147-1775589294-3259616702
[2005/08/11 15:17:17, 10] nsswitch/winbindd_util.c:open_winbindd_socket(890)
  open_winbindd_socket: opened socket fd 12
[2005/08/11 15:17:17, 10] nsswitch/winbindd_util.c:open_winbindd_priv_socket(902)
  open_winbindd_priv_socket: opened socket fd 14
[2005/08/11 15:17:18, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 7509
[2005/08/11 15:17:18, 5] nsswitch/winbindd_util.c:init_child_recv(407)
  Received child initialization response for domain BSS
[2005/08/11 15:17:18, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1540)
  Retrieving response for pid 7509
[2005/08/11 15:17:18, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1562)
  Retrieving extra data length=71
[2005/08/11 15:17:25, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 18
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn INTERFACE_VERSION
[2005/08/11 15:17:25, 3] nsswitch/winbindd_misc.c:winbindd_interface_version(460)
  [    0]: request interface version
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn WINBINDD_PRIV_PIPE_DIR
[2005/08/11 15:17:25, 3] nsswitch/winbindd_misc.c:winbindd_priv_pipe_dir(493)
  [    0]: request location of privileged pipe
[2005/08/11 15:17:25, 6] nsswitch/winbindd.c:new_connection(603)
  accepted socket 19
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn SETPWENT
[2005/08/11 15:17:25, 3] nsswitch/winbindd_user.c:winbindd_setpwent_internal(429)
  [    0]: setpwent
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/11 15:17:25, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:fetch_cache_seqnum(271)
  fetch_cache_seqnum: invalid data size key [SEQNUM/BSS]
[2005/08/11 15:17:25, 3] nsswitch/winbindd_ads.c:sequence_number(776)
  ads: fetch sequence_number for BSS
[2005/08/11 15:17:25, 6] libads/ldap.c:ads_find_dc(214)
  ads_find_dc: looking for realm 'bss.phy.private.cam.ac.uk'
[2005/08/11 15:17:25, 8] libsmb/namequery.c:get_sorted_dc_list(1433)
  get_sorted_dc_list: attempting lookup using [ads]
[2005/08/11 15:17:25, 10] libsmb/namequery.c:internal_resolve_name(1028)
  internal_resolve_name: looking up sd1.bss.phy.private.cam.ac.uk#20
[2005/08/11 15:17:25, 10] lib/gencache.c:gencache_get(263)
  Returning valid cache entry: key = NBT/SD1.BSS.PHY.PRIVATE.CAM.AC.UK#20, value
= 172.24.125.5:0, timeout = Thu Aug 1
1 15:19:48 2005
  
[2005/08/11 15:17:25, 5] libsmb/namecache.c:namecache_fetch(201)
  name sd1.bss.phy.private.cam.ac.uk#20 found.
[2005/08/11 15:17:25, 10] libsmb/namequery.c:remove_duplicate_addrs2(320)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2005/08/11 15:17:25, 4] libsmb/namequery.c:get_dc_list(1406)
  get_dc_list: returning 1 ip addresses in an ordered list
[2005/08/11 15:17:25, 4] libsmb/namequery.c:get_dc_list(1407)
  get_dc_list: 172.24.125.5:389 
[2005/08/11 15:17:25, 5] libads/ldap.c:ads_try_connect(123)
  ads_try_connect: trying ldap server '172.24.125.5' port 389
[2005/08/11 15:17:25, 3] libads/ldap.c:ads_connect(285)
  Connected to LDAP server 172.24.125.5
[2005/08/11 15:17:25, 3] libads/ldap.c:ads_server_info(2514)
  got ldap server name sd1@BSS.PHY.PRIVATE.CAM.AC.UK, using bind path:
dc=BSS,dc=PHY,dc=PRIVATE,dc=CAM,dc=AC,dc=UK
[2005/08/11 15:17:25, 4] libads/ldap.c:ads_server_info(2520)
  time offset is 0 seconds
[2005/08/11 15:17:25, 4] libads/sasl.c:ads_sasl_bind(451)
  Found SASL mechanism GSS-SPNEGO
[2005/08/11 15:17:25, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2005/08/11 15:17:25, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2005/08/11 15:17:25, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2005/08/11 15:17:25, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2005/08/11 15:17:25, 3] libads/sasl.c:ads_sasl_spnego_bind(215)
  ads_sasl_spnego_bind: got server principal name =sd1$@BSS.PHY.PRIVATE.CAM.AC.UK
[2005/08/11 15:17:25, 3] libsmb/clikrb5.c:ads_krb5_mk_req(384)
  ads_krb5_mk_req: krb5_cc_get_principal failed (No such file or directory)
[2005/08/11 15:17:25, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(321)
  Ticket in ccache[MEMORY:winbind_ccache] expiration Fri, 12 Aug 2005 01:17:25 GMT
[2005/08/11 15:17:25, 10] libsmb/clikrb5.c:ads_krb5_mk_req(411)
  ads_krb5_mk_req: Ticket (sd1$@BSS.PHY.PRIVATE.CAM.AC.UK) in ccache
(MEMORY:winbind_ccache) is valid until: (Fri, 12 
Aug 2005 01:17:25 GMT - 1123805845)
[2005/08/11 15:17:25, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(512)
  Got KRB5 session key of length 16
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.311) gave 1 replies
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.310) gave 1 replies
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.344) gave 1 replies
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (attributeId=1.2.840.113556.1.6.18.1.312) gave 1 replies
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectclass=*) gave 1 replies
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:store_cache_seqnum(324)
  store_cache_seqnum: success [BSS][61531 @ 1123769845]
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 61531
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:query_user_list(730)
  query_user_list: [Cached] - doing backend query for list for domain BSS
[2005/08/11 15:17:25, 3] nsswitch/winbindd_ads.c:query_user_list(136)
  ads: query_user_list
[2005/08/11 15:17:25, 7] nsswitch/winbindd_ads.c:ads_cached_connection(48)
  Current tickets expire at 1123805845, time is now 1123769845
[2005/08/11 15:17:25, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectClass=user) gave 8 replies
[2005/08/11 15:17:25, 3] nsswitch/winbindd_ads.c:query_user_list(206)
  ads query_user_list gave 8 entries
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(354)
  refresh_sequence_number: BSS time ok
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(385)
  refresh_sequence_number: BSS seq number is now 61531
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: ADMINISTRATOR ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-500 ->
Administrator
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-500 (acct_name
Administrator)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: GUEST -> S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-501 -> Guest
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-501 (acct_name Guest)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SUPPORT_388945A0 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1001 ->
SUPPORT_388945a0
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1001 (acct_name
SUPPORT_388945a0)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: SD1$ -> S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1004 -> SD1$
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1004 (acct_name SD1$)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: KRBTGT -> S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-502 -> krbtgt
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-502 (acct_name krbtgt)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: BOB -> S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1108 -> bob
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1108 (acct_name bob)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: MR -> S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1118 -> mr
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1118 (acct_name mr)
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(621)
  wcache_save_name_to_sid: W1$ -> S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(640)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1129 -> w1$
[2005/08/11 15:17:25, 10] nsswitch/winbindd_cache.c:wcache_save_user(660)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1129 (acct_name w1$)
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-500]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-500 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-500
-> UID 10000
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-500 -> UID 10000 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10000
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10000 ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10000]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-501]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-501 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-501
-> UID 10001
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-501 -> UID 10001 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10001
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10001 ->
S-1-5-21-571314010-3273254802-3516507047-501
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10001]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-514]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-514 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-514
-> GID 10010
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-514 -> GID 10010 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10010
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10010 ->
S-1-5-21-571314010-3273254802-3516507047-514
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10010]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1001]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1001
-> UID 10002
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1001 -> UID 10002 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10002
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10002 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10002]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1004]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1004
-> UID 10003
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1004 -> UID 10003 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10003
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10003 ->
S-1-5-21-571314010-3273254802-3516507047-1004
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10003]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-516]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-516 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-516
-> GID 10011
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-516 -> GID 10011 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10011
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10011 ->
S-1-5-21-571314010-3273254802-3516507047-516
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10011]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-502]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-502 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-502
-> UID 10004
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-502 -> UID 10004 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10004
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10004 ->
S-1-5-21-571314010-3273254802-3516507047-502
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10004]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1108]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1108
-> UID 10005
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1108 -> UID 10005 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10005
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10005 ->
S-1-5-21-571314010-3273254802-3516507047-1108
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10005]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1118]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1118
-> UID 10006
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1118 -> UID 10006 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10006
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10006 ->
S-1-5-21-571314010-3273254802-3516507047-1118
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10006]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-513 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
-> GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-513 -> GID 10009 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10009
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10009 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10009]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1129]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 of type 0x1
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1129
-> UID 10007
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(243)
  internal_get_id_from_sid: ID_USERID fetching record
S-1-5-21-571314010-3273254802-3516507047-1129 -> UID 10007 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 10007
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 10007 ->
S-1-5-21-571314010-3273254802-3516507047-1129
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [10007]
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-515]
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record
S-1-5-21-571314010-3273254802-3516507047-515 of type 0x2
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-515
-> GID 10012
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-571314010-3273254802-3516507047-515 -> GID 10012 
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10012
[2005/08/11 15:17:25, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10012 ->
S-1-5-21-571314010-3273254802-3516507047-515
[2005/08/11 15:17:25, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [10012]
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn GETPWENT
[2005/08/11 15:17:25, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/08/11 15:17:25, 10] nsswitch/winbindd.c:process_request(332)
  process_request: request fn ENDPWENT
[2005/08/11 15:17:25, 3] nsswitch/winbindd_user.c:winbindd_endpwent(505)
  [    0]: endpwent
Comment 7 Mike Rose 2005-09-06 03:11:22 UTC 
Now got this working. Took a while as working in the dark a little.