Bug 3062 - uid and gid not being obtained from Windows 2003 ADS with idmap=ad, BUT shell and home dir are retrieved.
Summary: uid and gid not being obtained from Windows 2003 ADS with idmap=ad, BUT shell...
Status: RESOLVED WORKSFORME
Alias: None
Product: Samba 3.0
Classification: Unclassified
Component: winbind (show other bugs)
Version: 3.0.20
Hardware: All Linux
: P3 critical
Target Milestone: none
Assignee: Guenther Deschner
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2005-09-05 06:51 UTC by Mike Rose
Modified: 2005-10-14 08:21 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Mike Rose 2005-09-05 06:51:04 UTC
winbind is retrieving the "login shell" and "home directory" ADS information
(SFU 3.5 installed), but no the UID and GID information AFAIK. 

testparm 
Load smb config files from /usr/local/samba//lib/smb.conf
Loaded services file OK.
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
        password server = sd1.bss.phy.private.cam.ac.uk
        idmap backend = ad
        idmap uid = 100-20000
        idmap gid = 100-20000
        winbind separator = #
        winbind cache time = 600
        winbind nss info = sfu


getent gives:
BSS#bob:x:105:100:bob:/homely/bob:/bin/sh
BSS#mr:x:106:100:mr:/homes/mr:/bin/bash

bob UID should be 10002 and GID of 500.
the UID and GID appear to me to be assigned in numerical order starting from 100
as specified by the idmap_uid range.

entries in nsswitch.conf;
passwd:     files winbind nis
shadow:     files nis
group:      files winbind nis
hosts:      files dns

samba is build with:
./configure --prefix=/usr/local/samba/ --with-ldap --with-ads --with-krb5
--with-pam --with-winbind --with-shared-modules=idmap_ad --with-acl-support
--with-quotas

cp libnss_winbind.so /lib/
cp pam_winbind.so /lib/security/
cp ./source/bin/idmap_ad.so /usr/local/samba/lib/idmap/ad.so


I guess I have probably made a mistake in the configuration somewhere, but the
winbind lof file does suggest that the stardard method is being used to map SID
to uid (tdb??)...

When running getent passwd with winbindd -d 10 the log file says:
[2005/09/05 14:19:20, 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/09/05 14:19:20, 1] nsswitch/winbindd.c:main(935)
  winbindd version 3.0.20 started.
  Copyright The Samba Team 2000-2004
[2005/09/05 14:19:20, 3] param/loadparm.c:lp_load(4082)
  lp_load: refreshing parameters
[2005/09/05 14:19:20, 3] param/loadparm.c:init_globals(1366)
  Initialising global parameters
[2005/09/05 14:19:20, 3] param/params.c:pm_process(574)
  params.c:pm_process() - Processing configuration file
"/usr/local/samba//lib/smb.conf"
[2005/09/05 14:19:20, 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 cache time = 600
  doing parameter idmap backend = ad
  doing parameter winbind nss info = sfu
  doing parameter workgroup = BSS
  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/09/05 14:19:20, 4] param/loadparm.c:lp_load(4113)
  pm_process() returned Yes
[2005/09/05 14:19:20, 7] param/loadparm.c:lp_servicenumber(4226)
  lp_servicenumber: couldn't find homes
[2005/09/05 14:19:20, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 0 for IPC$
[2005/09/05 14:19:20, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/09/05 14:19:20, 8] param/loadparm.c:add_a_service(2393)
  add_a_service: Creating snum = 1 for ADMIN$
[2005/09/05 14:19:20, 3] param/loadparm.c:lp_add_ipc(2475)
  adding IPC service
[2005/09/05 14:19:20, 10] param/loadparm.c:set_server_role(4031)
  set_server_role: role = ROLE_DOMAIN_MEMBER
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2LE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2LE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16LE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16LE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS-2BE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS-2BE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-16BE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-16BE
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF8
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF8
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UTF-8
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UTF-8
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ASCII
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ASCII
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset 646
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset 646
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset ISO-8859-1
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset ISO-8859-1
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(103)
  Attempting to register new charset UCS2-HEX
[2005/09/05 14:19:20, 5] lib/iconv.c:smb_register_charset(111)
  Registered charset UCS2-HEX
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 5] lib/charcnv.c:charset_name(81)
  Substituting charset 'ANSI_X3.4-1968' for LOCALE
[2005/09/05 14:19:20, 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/09/05 14:19:20, 5] lib/util.c:init_names(260)
  Netbios name list:-
  my_netbios_names[0]="W1"
[2005/09/05 14:19:20, 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/09/05 14:19:20, 5] lib/gencache.c:gencache_init(59)
  Opening cache file at /usr/local/samba//var/locks/gencache.tdb
[2005/09/05 14:19:20, 5] libsmb/namecache.c:namecache_enable(58)
  namecache_enable: enabling netbios namecache, timeout 660 seconds
[2005/09/05 14:19:20, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ldap'
[2005/09/05 14:19:20, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'tdb'
[2005/09/05 14:19:20, 10] sam/idmap_tdb.c:db_idmap_init(500)
  db_idmap_init: Opening tdbfile /usr/local/samba//var/locks/winbindd_idmap.tdb
[2005/09/05 14:19:20, 3] sam/idmap.c:idmap_init(132)
  idmap_init: using 'ad' as remote backend
[2005/09/05 14:19:20, 5] lib/module.c:smb_probe_module(104)
  Probing module 'ad'
[2005/09/05 14:19:20, 5] lib/module.c:smb_probe_module(115)
  Probing module 'ad': Trying to load from /usr/local/samba//lib/idmap/ad.so
[2005/09/05 14:19:20, 5] sam/idmap.c:smb_register_idmap(91)
  smb_register_idmap: Successfully added idmap backend 'ad'
[2005/09/05 14:19:20, 2] lib/module.c:do_smb_load_module(66)
  Module '/usr/local/samba//lib/idmap/ad.so' loaded
[2005/09/05 14:19:20, 8] lib/util.c:fcntl_lock(1815)
  fcntl_lock 8 13 0 1 1
[2005/09/05 14:19:20, 8] lib/util.c:fcntl_lock(1850)
  fcntl_lock: Lock call successful
[2005/09/05 14:19:20, 2] lib/tallocmsg.c:register_msg_pool_usage(56)
  Registered MSG_REQ_POOL_USAGE
[2005/09/05 14:19:20, 2] lib/dmallocmsg.c:register_dmalloc_msgs(71)
  Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
[2005/09/05 14:19:20, 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/09/05 14:19:20, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain BUILTIN  S-1-5-32
[2005/09/05 14:19:20, 2] nsswitch/winbindd_util.c:add_trusted_domain(166)
  Added domain W1  S-1-5-21-2333854974-2933355403-3032310541
[2005/09/05 14:19:20, 10] nsswitch/winbindd_util.c:open_winbindd_socket(890)
  open_winbindd_socket: opened socket fd 11
[2005/09/05 14:19:20, 10] nsswitch/winbindd_util.c:open_winbindd_priv_socket(902)
  open_winbindd_priv_socket: opened socket fd 13
[2005/09/05 14:19:26, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1533)
  Retrieving response for pid 13282
[2005/09/05 14:19:26, 5] nsswitch/winbindd_util.c:init_child_recv(407)
  Received child initialization response for domain BSS
[2005/09/05 14:19:26, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1533)
  Retrieving response for pid 13282
[2005/09/05 14:19:26, 10] nsswitch/winbindd_cache.c:cache_retrieve_response(1555)
  Retrieving extra data length=71
[2005/09/05 14:19:28, 6] nsswitch/winbindd.c:new_connection(596)
  accepted socket 17
[2005/09/05 14:19:28, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn INTERFACE_VERSION
[2005/09/05 14:19:28, 3] nsswitch/winbindd_misc.c:winbindd_interface_version(460)
  [    0]: request interface version
[2005/09/05 14:19:28, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn WINBINDD_PRIV_PIPE_DIR
[2005/09/05 14:19:28, 3] nsswitch/winbindd_misc.c:winbindd_priv_pipe_dir(493)
  [    0]: request location of privileged pipe
[2005/09/05 14:19:28, 6] nsswitch/winbindd.c:new_connection(596)
  accepted socket 18
[2005/09/05 14:19:28, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn SETPWENT
[2005/09/05 14:19:28, 3] nsswitch/winbindd_user.c:winbindd_setpwent_internal(429)
  [    0]: setpwent
[2005/09/05 14:19:28, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn GETPWENT
[2005/09/05 14:19:28, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/09/05 14:19:28, 10] nsswitch/winbindd_cache.c:fetch_cache_seqnum(276)
  fetch_cache_seqnum: invalid data size key [SEQNUM/BSS]
[2005/09/05 14:19:28, 3] nsswitch/winbindd_ads.c:sequence_number(776)
  ads: fetch sequence_number for BSS
[2005/09/05 14:19:28, 6] libads/ldap.c:ads_find_dc(214)
  ads_find_dc: looking for realm 'bss.phy.private.cam.ac.uk'
[2005/09/05 14:19:28, 8] libsmb/namequery.c:get_sorted_dc_list(1433)
  get_sorted_dc_list: attempting lookup using [ads]
[2005/09/05 14:19:28, 10] libsmb/namequery.c:internal_resolve_name(1028)
  internal_resolve_name: looking up sd1.bss.phy.private.cam.ac.uk#20
[2005/09/05 14:19:28, 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, timeo
ut = Mon Sep  5 14:30:20 2005
  
[2005/09/05 14:19:28, 5] libsmb/namecache.c:namecache_fetch(201)
  name sd1.bss.phy.private.cam.ac.uk#20 found.
[2005/09/05 14:19:28, 10] libsmb/namequery.c:remove_duplicate_addrs2(320)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2005/09/05 14:19:28, 4] libsmb/namequery.c:get_dc_list(1406)
  get_dc_list: returning 1 ip addresses in an ordered list
[2005/09/05 14:19:28, 4] libsmb/namequery.c:get_dc_list(1407)
  get_dc_list: 172.24.125.5:389 
[2005/09/05 14:19:28, 5] libads/ldap.c:ads_try_connect(123)
  ads_try_connect: trying ldap server '172.24.125.5' port 389
[2005/09/05 14:19:28, 3] libads/ldap.c:ads_connect(285)
  Connected to LDAP server 172.24.125.5
[2005/09/05 14:19:28, 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,d
c=AC,dc=UK
[2005/09/05 14:19:28, 4] libads/ldap.c:ads_server_info(2520)
  time offset is 1 seconds
[2005/09/05 14:19:28, 4] libads/sasl.c:ads_sasl_bind(451)
  Found SASL mechanism GSS-SPNEGO
[2005/09/05 14:19:28, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2005/09/05 14:19:28, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2005/09/05 14:19:28, 3] libads/sasl.c:ads_sasl_spnego_bind(206)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2005/09/05 14:19:28, 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/09/05 14:19:28, 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/09/05 14:19:28, 3] libsmb/clikrb5.c:ads_krb5_mk_req(384)
  ads_krb5_mk_req: krb5_cc_get_principal failed (No such file or directory)
[2005/09/05 14:19:34, 4] libsmb/clikrb5.c:ads_krb5_mk_req(400)
  ads_krb5_mk_req: Advancing clock by 1 seconds to cope with clock skew
[2005/09/05 14:19:34, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(321)
  Ticket in ccache[MEMORY:winbind_ccache] expiration Tue, 06 Sep 2005 00:19:29 GMT
[2005/09/05 14:19:34, 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 un
til: (Tue, 06 Sep 2005 00:19:29 GMT - 1125962369)
[2005/09/05 14:19:34, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(512)
  Got KRB5 session key of length 16
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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/09/05 14:19:34, 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/09/05 14:19:34, 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/09/05 14:19:34, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectclass=*) gave 1 replies
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:store_cache_seqnum(329)
  store_cache_seqnum: success [BSS][79183 @ 1125926374]
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(387)
  refresh_sequence_number: BSS seq number is now 79183
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:query_user_list(723)
  query_user_list: [Cached] - doing backend query for list for domain BSS
[2005/09/05 14:19:34, 3] nsswitch/winbindd_ads.c:query_user_list(136)
  ads: query_user_list
[2005/09/05 14:19:34, 7] nsswitch/winbindd_ads.c:ads_cached_connection(48)
  Current tickets expire at 1125962369, time is now 1125926374
[2005/09/05 14:19:34, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for (objectClass=user) gave 9 replies
[2005/09/05 14:19:34, 3] nsswitch/winbindd_ads.c:query_user_list(206)
  ads query_user_list gave 9 entries
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(359)
  refresh_sequence_number: BSS time ok
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(387)
  refresh_sequence_number: BSS seq number is now 79183
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: ADMINISTRATOR ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-500 ->
Administrator
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-500 (acct_name
Administrator)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: GUEST -> S-1-5-21-571314010-3273254802-3516507047-501
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-501 -> Guest
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-501 (acct_name Guest)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: SUPPORT_388945A0 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1001 ->
SUPPORT_388945a0
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1001 (acct_name
SUPPORT_388945a0)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: SD1$ -> S-1-5-21-571314010-3273254802-3516507047-1004
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1004 -> SD1$
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1004 (acct_name SD1$)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: KRBTGT -> S-1-5-21-571314010-3273254802-3516507047-502
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-502 -> krbtgt
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-502 (acct_name krbtgt)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: BOB -> S-1-5-21-571314010-3273254802-3516507047-1108
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1108 -> bob
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1108 (acct_name bob)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: MR -> S-1-5-21-571314010-3273254802-3516507047-1118
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1118 -> mr
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1118 (acct_name mr)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: SD2$ -> S-1-5-21-571314010-3273254802-3516507047-1131
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1131 -> SD2$
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1131 (acct_name SD2$)
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(614)
  wcache_save_name_to_sid: W1$ -> S-1-5-21-571314010-3273254802-3516507047-1132
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_sid_to_name(633)
  wcache_save_sid_to_name: S-1-5-21-571314010-3273254802-3516507047-1132 -> w1$
[2005/09/05 14:19:34, 10] nsswitch/winbindd_cache.c:wcache_save_user(653)
  wcache_save_user: S-1-5-21-571314010-3273254802-3516507047-1132 (acct_name w1$)
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-500]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> UI
D 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 100 ->
S-1-5-21-571314010-3273254802-3516507047-500
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> G
ID 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 100 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-501]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 101
[2005/09/05 14:19:34, 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 -> UI
D 101 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 101
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 101 ->
S-1-5-21-571314010-3273254802-3516507047-501
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [101]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-514]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 101
[2005/09/05 14:19:34, 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 -> G
ID 101 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 101
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 101 ->
S-1-5-21-571314010-3273254802-3516507047-514
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [101]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1001]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 102
[2005/09/05 14:19:34, 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 -> U
ID 102 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 102
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 102 ->
S-1-5-21-571314010-3273254802-3516507047-1001
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [102]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> G
ID 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 100 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1004]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 103
[2005/09/05 14:19:34, 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 -> U
ID 103 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 103
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 103 ->
S-1-5-21-571314010-3273254802-3516507047-1004
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [103]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-516]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 102
[2005/09/05 14:19:34, 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 -> G
ID 102 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 102
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 102 ->
S-1-5-21-571314010-3273254802-3516507047-516
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [102]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-502]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 104
[2005/09/05 14:19:34, 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 -> UI
D 104 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 104
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 104 ->
S-1-5-21-571314010-3273254802-3516507047-502
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [104]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> G
ID 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 100 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1108]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 105
[2005/09/05 14:19:34, 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 -> U
ID 105 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 105
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 105 ->
S-1-5-21-571314010-3273254802-3516507047-1108
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [105]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> G
ID 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 100 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1118]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 106
[2005/09/05 14:19:34, 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 -> U
ID 106 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 106
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 106 ->
S-1-5-21-571314010-3273254802-3516507047-1118
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [106]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 100
[2005/09/05 14:19:34, 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 -> G
ID 100 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 100
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 100 ->
S-1-5-21-571314010-3273254802-3516507047-513
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [100]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1131]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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-1131 of type 0x1
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1131
-> UID 107
[2005/09/05 14:19:34, 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-1131 -> U
ID 107 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 107
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 107 ->
S-1-5-21-571314010-3273254802-3516507047-1131
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [107]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-516]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 102
[2005/09/05 14:19:34, 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 -> G
ID 102 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 102
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 102 ->
S-1-5-21-571314010-3273254802-3516507047-516
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [102]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1132]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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-1132 of type 0x1
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-1132
-> UID 108
[2005/09/05 14:19:34, 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-1132 -> U
ID 108 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 108
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 108 ->
S-1-5-21-571314010-3273254802-3516507047-1132
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [108]
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-515]
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/05 14:19:34, 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/09/05 14:19:34, 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 103
[2005/09/05 14:19:34, 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 -> G
ID 103 
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 103
[2005/09/05 14:19:34, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 103 ->
S-1-5-21-571314010-3273254802-3516507047-515
[2005/09/05 14:19:34, 10] sam/idmap_util.c:idmap_sid_to_gid(181)
  idmap_sid_to_gid: gid = [103]
[2005/09/05 14:19:34, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn GETPWENT
[2005/09/05 14:19:34, 3] nsswitch/winbindd_user.c:winbindd_getpwent(623)
  [    0]: getpwent
[2005/09/05 14:19:34, 10] nsswitch/winbindd.c:process_request(325)
  process_request: request fn ENDPWENT
[2005/09/05 14:19:34, 3] nsswitch/winbindd_user.c:winbindd_endpwent(505)
  [    0]: endpwent
Comment 1 Guenther Deschner 2005-09-05 14:37:27 UTC
This is a winbind design issue, whenever winbindd has mapped a SID to a UID or
GID it will store that value in the tdb. So, most probably, you have not deleted
an initial mapping created by not using the idmap ad module before.

Warning: You should never delete a winbindd_idmap.tdb on a production server
when you are currently using that mapping! If it is a test system. then just
delete that tdb and restart winbindd. It will then show the SFU uid and gid for
that user.

Please let us know if this fixes your problem.
Comment 2 Mike Rose 2005-09-06 01:43:42 UTC
Hi, thanks for the suggestion. I had wondered if it there was already a mapping
(I was slowly building the smb.conf so there had been). Maybe I'm mistaken, but
I seemed to have to delete these two files:
winbindd_cache.tdb
winbindd_idmap.tdb
to get rid of the previous mapping.

Unfortunately this appears to have caused another problem. I think the log file
(winbindd -d 10) shows the UID being found for the user "mr", but not the GID
and getent passwd now yields nothing from the Windows domain.
The ADS GUI certainly shows the UNIX GID attribute as set, but I admit I have
not, yet, directly queried the ADS LDAP for it.

[global]
        workgroup = BSS
        realm = BSS.PHY.PRIVATE.CAM.AC.UK
        security = ADS
        password server = sd1.bss.phy.private.cam.ac.uk
        idmap backend = ad
        idmap uid = 100-20000
        idmap gid = 100-20000
        winbind separator = #
        winbind cache time = 600
        winbind nss info = sfu


[2005/09/06 09:35:45, 1] nsswitch/winbindd_user.c:winbindd_getpwent(712)
  could not lookup domain user mr
[2005/09/06 09:35:45, 10] sam/idmap_util.c:idmap_sid_to_uid(144)
  idmap_sid_to_uid: sid = [S-1-5-21-571314010-3273254802-3516507047-1118]
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/06 09:35:45, 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/09/06 09:35:45, 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 500
[2005/09/06 09:35:45, 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 -> UI
D 500 
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record UID 500
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record UID 500 ->
S-1-5-21-571314010-3273254802-3516507047-1118
[2005/09/06 09:35:45, 10] sam/idmap_util.c:idmap_sid_to_uid(151)
  idmap_sid_to_uid: uid = [500]
[2005/09/06 09:35:45, 10] sam/idmap_util.c:idmap_sid_to_gid(173)
  sid_to_gid: sid = [S-1-5-21-571314010-3273254802-3516507047-513]
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/06 09:35:45, 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/09/06 09:35:45, 10] sam/idmap_tdb.c:internal_get_id_from_sid(225)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
not found
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2005/09/06 09:35:45, 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 0x1
[2005/09/06 09:35:45, 10] sam/idmap_tdb.c:internal_get_id_from_sid(225)
  internal_get_id_from_sid: record S-1-5-21-571314010-3273254802-3516507047-513
not found
[2005/09/06 09:35:45, 7] sam/idmap_ad.c:ad_idmap_cached_connection(91)
  Current tickets expire at 1126031740, time is now 1125995745
[2005/09/06 09:35:45, 5] libads/ldap_utils.c:ads_do_search_retry(56)
  Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\5A\8F\0D\22\92\E7\19\C3\A7\A3\99\D1\01\02\00
\00) gave 1 replies
[2005/09/06 09:35:45, 1] sam/idmap_ad.c:ad_idmap_get_id_from_sid(329)
  ad_idmap_get_id_from_sid: ads_pull_uint32: could not read attribute
'msSFU30GidNumber'
[2005/09/06 09:35:45, 1] nsswitch/winbindd_user.c:winbindd_fill_pwent(92)
  error getting group id for sid S-1-5-21-571314010-3273254802-3516507047-513
Comment 3 Guenther Deschner 2005-09-06 02:24:07 UTC
Apparently the user's primary group id has no SFU attributes.

Please verify with

net ads search objectSid=S-1-5-21-571314010-3273254802-3516507047-513
and the resulting entry won't have msSFU30GidNumber attribute, right?

Either change the user's primary group id to a group that has unix attributes or
add unix attributes to the "Domain Users"
(S-1-5-21-571314010-3273254802-3516507047-513).
Comment 4 Mike Rose 2005-09-06 03:09:31 UTC
Thank you for your patience. You are completely correct. I even read the answer
from the logs (duh).

Yes it is now fine. I must think about ADS as LDAP, I must not think about it as
NIS or passwd/group files. repeat...

Would you like a bit of documentation written about this? I am going to write
something anyway as people where I work are interested. I guess I should submit
it to the samba documentation project.

Comment 5 Guenther Deschner 2005-09-06 03:38:51 UTC
Oh yes, documentation is always welcome !

Just post your little Howto here or to the mailing-list.

Closing this bug know.
Comment 6 Mike Rose 2005-10-14 08:21:01 UTC
Hi,
All working, now.

I guess you might wish to put this wee "howto" here:
Examples of IDMAP Backend Usage
http://us2.samba.org/samba/docs/man/Samba-HOWTO-Collection/idmapper.html#id2586883

can call it:
IDMAP ADS Using ADS with SFU3.5

Info is posted here:
http://www.tcm.phy.cam.ac.uk/~mr349/samba.html#ads


"
Configure Windows 2003 Server
=============================
Install SFU3.5 - default is fine, to extend ADS
schema to include UNIX attributes - on a Windows 2003 Server
running as a Domain Controller.
Free download from Microsoft
Create a test user with UNIX attributes of:
uid
gid
home directory
default shell

Make sure that the Windows ADS group/s this user is a member of
also have UNIX attributes. In particular the gid of the test user
needs to correspond to an ADS group with a UNIX gid.

Linux Computer
===============
/etc/resolve.conf needs to point to the DNS server with all of the
ADS entries in it - so that samba can find AD.

Pre-requisites:
ldap + libraries + devel
kerberos + libraries + devel
openssl devel
pam libraries
cyrus-sasl libraries
acl libraries

For Suse9.1 these are the packages (rpm) that I needed:
openldap2
openldap2-devel
openldap2-client
heimdal
heimdal-lib
heimdal-tools
heimdal-devel
db-devel
e2fsprogs-devel
openssl-devel
cyrus-sasl-devel
pam-devel
libcap
libacl-devel
acl
libacl
quota

Compile samba
=============
as root:
mkdir /usr/local/samba/
chown mr /usr/local/samba/
as mr:
./configure --prefix=/usr/local/samba/ --with-ldap --with-ads --with-krb5
--with-pam --with-winbind --with-shared-modules=idmap_ad --with-acl-support
--with-quotas

Note: DO scan the config.log for errors. For example if you do not have libcap
installed samba will still build, but winbind will crash everytime you try
a "getent passwd". The errors are in config.log to see.

make
make install

Note: --with-shared-modules=idmap_ad is currently the only way to get the
idmap_ad module built

/usr/local/samba/lib/idmap$ ln -s ./idmap_ad.so ad.so

To pick up users and groups from ADS you'll need to:
cd samba-3.0.20/source/nsswitch
cp libnss_winbind.so /lib
cp libnss_wins.so /lib
ldconfig

Create your smb.conf. Best advice is to do this with a very simple
configuration to start with:
[global]
winbind separator = '\'
#idmap uid = 100-20000
#idmap gid = 100-20000
winbind enum users = yes
winbind enum groups = yes
winbind cache time = 600
winbind use default domain = yes
allow trusted domains = yes
idmap backend = ad
winbind nss info = sfu
workgroup = short_domain_name
realm = domain
security = ADS
encrypt passwords = yes
password server = winserver1.domain, winserver2.domain
obey pam restrictions = Yes

Use testparm to check it.

Note: if things do not work then you'll end up with default mappings to uid
and gid for users created on the fly by winbind. These go into a file in:
/usr/local/samba/var/locks.

Now to join the domain. Several ways you can do this, such as:
kinit Administrator@BSS.PHY.PRIVATE.CAM.AC.UK
net ads join "\unix_workstations"

edit /etc/nsswitch.conf:
passwd:     files winbind
shadow:     files
group:      files winbind

Some testing:
wbinfo -t
should give:
checking the trust secret via RPC calls succeeded

wbinfo -u
Administrator
Guest
SUPPORT_388945a0
SD1$
krbtgt
bob
SD2$
sf1$

wbinfo -g
Domain Computers
Domain Controllers
Schema Admins
Enterprise Admins
Domain Admins
Domain Users
Domain Guests
Group Policy Creator Owners
DnsUpdateProxy

Now a "getent passwd" should work...

Useful Links
============
http://lilly.csoft.net/~vdebaere/handleiding/samba-activedirectory/index_en.html

"