[Samba] Problems resolving most users with winbind and AD/SFU

[Steve B]

After some additional tests I gather more information which I hope
might help diagnose the problem.

Out of the 90 accounts on the AD server only 9 resolve through
winbind.  Administrator, Guest, and 7 misc user accounts.  There is no
pattern to which accounts resolve and which will not.  The RIDs and
SIDs for the accounts that resolve are not sequential, and both the
working and non-working accounts fall within the uid range defined in
smb.conf.  All user accounts have the SFU properties filled out, with
unique UIDs.

I had a 2nd fileserver which also is running CentOS 5.3.  I downloaded
and installed the rpm group for Samba 3.2.13 to see if I might have
better luck then I had with the standard rpms included with the
distro.  The following changes were made to my original smb.conf file.
 The first three to eliminate some errors I was seeing, the last to
gather as much information as possible:

   interfaces = bond0 127.0.0.1
   bind interfaces only = yes
   allow trusted domains = no
   log level = 10 all:10

No change was noticed.  The same exact accounts which resolved with
3.0.33 worked with 3.2.13.

'getent password'  displays all local accounts as well as the 9
accounts that winbind will resolve.  'getent group' shows local groups
and AD Global groups.  Samba 3.2.13 showed the AD Domain Local groups,
which did not appear with 3.0.33.  Neither showed BUILTIN groups, so
these were added through net sam createbuiltingroup.  When 'getent
group' lists the members of the AD groups, all valid members are
listed, including those that will not resolve through wbinfo -i.
Example: testgroup:x:2314:user1,user2,user3  where only user1 can
resolve with wbinfo -i.


... Part of successful account resolution in log.winbindd ...
[2009/06/26 14:33:24, 10]
winbindd/winbindd_cache.c:cache_retrieve_response(2468)
  Retrieving response for pid 6246
[2009/06/26 14:33:24,  7] winbindd/winbindd_idmap.c:winbindd_sid2gid_async(363)
  winbindd_sid2gid_async: Resolving
S-1-5-21-1060284298-861567501-682003330-513 to a gid
[2009/06/26 14:33:24, 10] winbindd/winbindd_dual.c:async_request(125)
  Sending request to child pid 6246 (domain='')
[2009/06/26 14:33:24, 10] lib/events.c:event_add_timed(130)
  Added timed event "async_request_timeout": 2ac6346a9c80
[2009/06/26 14:33:24, 10] lib/events.c:get_timed_events_timeout(304)
  timed_events_timeout: 299/999987
[2009/06/26 14:33:24, 10] lib/events.c:timed_event_destructor(65)
  Destroying timed event 2ac6346a9c80 "async_request_timeout"
[2009/06/26 14:33:24, 10]
winbindd/winbindd_cache.c:cache_retrieve_response(2468)
  Retrieving response for pid 6246
[2009/06/26 14:33:24,  2] winbindd/winbindd.c:remove_client(761)
  final write to client failed: Broken pipe
... end success...

...Part of failed account resolution in log.winbindd ...
[2009/06/26 14:33:24, 10]
winbindd/winbindd_cache.c:cache_retrieve_response(2468)
  Retrieving response for pid 6232
[2009/06/26 14:33:24, 10] winbindd/winbindd_dual.c:async_request(125)
  Sending request to child pid 6246 (domain='')
[2009/06/26 14:33:24, 10] lib/events.c:event_add_timed(130)
  Added timed event "async_request_timeout": 2ac6346a9c80
[2009/06/26 14:33:24, 10] lib/events.c:get_timed_events_timeout(304)
  timed_events_timeout: 299/999987
[2009/06/26 14:33:24, 10] lib/events.c:timed_event_destructor(65)
  Destroying timed event 2ac6346a9c80 "async_request_timeout"
[2009/06/26 14:33:24, 10]
winbindd/winbindd_cache.c:cache_retrieve_response(2468)
  Retrieving response for pid 6246
[2009/06/26 14:33:24,  5] winbindd/winbindd_idmap.c:winbindd_sid2uid_recv(289)
  sid2uid returned an error
[2009/06/26 14:33:24,  5] winbindd/winbindd_user.c:getpwsid_sid2uid_recv(293)
  Could not query uid for user SCOPELAB\harnilo1
[2009/06/26 14:33:24,  2] winbindd/winbindd.c:remove_client(761)
  final write to client failed: Broken pipe
... end failed...

... Part of successful account resolution in log.winbindd-idmap ...
[2009/06/26 14:33:24,  3] winbindd/winbindd_idmap.c:winbindd_dual_sid2uid(316)
  [ 6218]: sid to uid S-1-5-21-1060284298-861567501-682003330-1241
[2009/06/26 14:33:24, 10] winbindd/idmap_util.c:idmap_sid_to_uid(104)
  idmap_sid_to_uid: sid = [S-1-5-21-1060284298-861567501-682003330-1241]
[2009/06/26 14:33:24, 10] winbindd/idmap_cache.c:idmap_cache_map_sid(369)
  Returning valid cache entry: key =
IDMAP/SID/S-1-5-21-1060284298-861567501-682003330-1241,
value = IDMAP/UID/2241, timeout = Fri Jun 26 14:37:21 2009
[2009/06/26 14:33:24, 10] winbindd/winbindd_cache.c:cache_store_response(2428)
  Storing response for pid 6246, len 3496
[2009/06/26 14:33:24, 10] lib/events.c:get_timed_events_timeout(304)
  timed_events_timeout: 4/590284
[2009/06/26 14:33:24,  4] winbindd/winbindd_dual.c:fork_domain_child(1323)
  child daemon request 49
[2009/06/26 14:33:24, 10] winbindd/winbindd_dual.c:child_process_request(453)
  child_process_request: request fn DUAL_SID2GID
[2009/06/26 14:33:24,  3] winbindd/winbindd_idmap.c:winbindd_dual_sid2gid(376)
  [ 6218]: sid to gid S-1-5-21-1060284298-861567501-682003330-513
[2009/06/26 14:33:24, 10] winbindd/idmap_util.c:idmap_sid_to_gid(144)
  idmap_sid_to_gid: sid = [S-1-5-21-1060284298-861567501-682003330-513]
[2009/06/26 14:33:24, 10] winbindd/idmap_cache.c:idmap_cache_map_sid(369)
  Returning valid cache entry: key =
IDMAP/SID/S-1-5-21-1060284298-861567501-682003330-513, v
alue = IDMAP/GID/1513, timeout = Fri Jun 26 14:37:21 2009
[2009/06/26 14:33:24, 10] winbindd/winbindd_idmap.c:winbindd_dual_sid2gid(390)
  winbindd_dual_sid2gid: 0x00000000 -
S-1-5-21-1060284298-861567501-682003330-513 - 1513
[2009/06/26 14:33:24, 10] winbindd/winbindd_cache.c:cache_store_response(2428)
  Storing response for pid 6246, len 3496
... end success ...

...Part of failed account resolution in log.winbindd-idmap ...
[2009/06/26 14:33:24,  3] winbindd/winbindd_idmap.c:winbindd_dual_sid2uid(316)
  [ 6218]: sid to uid S-1-5-21-1060284298-861567501-682003330-1260
[2009/06/26 14:33:24, 10] winbindd/idmap_util.c:idmap_sid_to_uid(104)
  idmap_sid_to_uid: sid = [S-1-5-21-1060284298-861567501-682003330-1260]
[2009/06/26 14:33:24, 10] winbindd/idmap.c:idmap_backends_sids_to_unixids(1195)
  Query backends to map sids->ids
[2009/06/26 14:33:24, 10] winbindd/idmap.c:idmap_backends_sids_to_unixids(1220)
  SID S-1-5-21-1060284298-861567501-682003330-1260 is being handled by MYDOM
[2009/06/26 14:33:24, 10] winbindd/idmap.c:idmap_backends_sids_to_unixids(1241)
  Query ids from domain MYDOM
[2009/06/26 14:33:24,  7]
winbindd/idmap_ad.c:ad_idmap_cached_connection_internal(76)
  Current tickets expire in 36000 seconds (at 1246077204, time is now
1246041204)
[2009/06/26 14:33:24, 10] winbindd/idmap_ad.c:idmap_ad_sids_to_unixids(544)
  Filter: [(&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=805306370)
(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\15
\00\00\00\8A\A7\32\3F\0D\7A\5A\33\82\8B\A6\28\EC\04\00\00)))]
[2009/06/26 14:33:24,  5] libads/ldap_utils.c:ads_do_search_retry_internal(64)
  Search for (&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=80530637
0)(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\
15\00\00\00\8A\A7\32\3F\0D\7A\5A\33\82\8B\A6\28\EC\04\00\00))) in
<dc=MYDOM,dc=DOMAIN,dc=NET>
 gave 1 replies
[2009/06/26 14:33:24,  1] winbindd/idmap_ad.c:idmap_ad_sids_to_unixids(614)
  Could not get unix ID
[2009/06/26 14:33:24, 10] winbindd/idmap.c:idmap_can_map(998)
  idmap backend for SID S-1-5-21-1060284298-861567501-682003330-1260
is READONLY!
[2009/06/26 14:33:24, 10]
winbindd/idmap_cache.c:idmap_cache_set_negative_sid(210)
  Adding cache entry with key =
IDMAP/SID/S-1-5-21-1060284298-861567501-682003330-1260; value
 =   1246041324/IDMAP/NEGATIVE and timeout = Fri Jun 26 14:35:24 2009
   (120 seconds ahead)
[2009/06/26 14:33:24, 10] winbindd/idmap_util.c:idmap_sid_to_uid(124)
  sid [S-1-5-21-1060284298-861567501-682003330-1260] not mapped to an
uid [2,1,879607880]
[2009/06/26 14:33:24, 10] winbindd/winbindd_cache.c:cache_store_response(2428)
  Storing response for pid 6246, len 3496
... end failed ...

I've tried many things on the member fileservers, with no luck.  The
only thing I haven't been able to do is reboot the AD server due to it
being a production server with many accessing it.

Any tips? Thanks,
Steve


> Hello all,
>
> I'm having a problem with Winbind resolving some users from AD on a W2KSP4
> server running SFU 3.5 [8.0.1969.1].  All users and groups in the AD domain
> have been assigned UIDs and GIDs via SFU.  The Linux fileserver is running
> CentOS 5.3 with Samba 3.0.33-3.7.el5.  The fileserver has been joined to the
> domain using authconfig with proper modifications made to nsswitch and pam.
> My smb.conf is attached below.
>
> wbinfo -u will show all users.  What I'm seeing is that out of the 90 or so
> users, only 6 will respond to id or winbind -i requests.  The rest respond
> with "no such user" or similar.  The following error appears in
> my /var/log/samba/winbindd-idmap.log file when an attempt is made to resolve
> one of these users:
>
> [2009/06/23 13:59:13, 3] nsswitch/winbindd_async.c:winbindd_dual_sid2uid(374)
>  [11577]: sid to uid S-1-5-21-1060284298-861567501-682003330-1277
> [2009/06/23 13:59:13, 1] nsswitch/idmap_ad.c:idmap_ad_sids_to_unixids(613)
>  Could not get unix ID
>
> An additional symptom is as such, where wbinfo -n works for all users, but
> only a few can be resolved with wbinfo -S:
>
> # wbinfo -n user1
> S-1-5-21-1060284298-861567501-682003330-1241 User (1)
> # wbinfo -S S-1-5-21-1060284298-861567501-682003330-1241
> 2241
> # wbinfo -n user2
> S-1-5-21-1060284298-861567501-682003330-1260 User (1)
> # wbinfo -S S-1-5-21-1060284298-861567501-682003330-1260
> Could not convert sid S-1-5-21-1060284298-861567501-682003330-1260 to uid
>
> This problem directly affects attempts to 'xcopy /o' files from Windows to the
> Linux file server, or in the following example an attempt to use subinacl to
> set ownership of a file on the fileserver to one of the users who will not
> resolve:
>
> [2009/06/24 16:38:27, 3] smbd/posix_acls.c:unpack_nt_owners(966)
>  unpack_nt_owners: unable to validate owner sid for
> S-1-5-21-1060284298-861567501-682003330-1260
> [2009/06/24 16:38:27, 3] smbd/error.c:error_packet_set(106)
>  error packet at smbd/nttrans.c(2207) cmd=160 (SMBnttrans)
> NT_STATUS_ACCESS_DENIED
>
> This type of error also appears when I use subinacl to set group permissions
> on files owned by a user who does respond to id or wbinfo -i.  I've added the
> BUILTIN groups using net sam createbuiltingroup example_group -w MYDOM:
>
> [2009/06/24 16:51:22, 3] passdb/lookup_sid.c:fetch_gid_from_cache(1107)
>  fetch gid from cache 50000 -> S-1-5-32-544
> [2009/06/24 16:51:22, 3] smbd/posix_acls.c:unpack_nt_owners(966)
>  unpack_nt_owners: unable to validate owner sid for S-1-5-32-544
> [2009/06/24 16:51:22, 3] smbd/error.c:error_packet_set(106)
>  error packet at smbd/nttrans.c(2207) cmd=160 (SMBnttrans)
> NT_STATUS_ACCESS_DENIED
>
> I've searched high and low, and found several also complaining about winbind
> resolving only a subset of users.  None of the suggestions or fixes have
> affected my situation.  I'm not running nscd.  I've stopped winbind,
> deleted /etc/samba/secrets.tdb, deleted /var/cache/samba/*.tdb, rejoined the
> domain and restarted winbind.  I swapped schema_mode from sfu to rfc2307 and
> back.  Nothing helps.  The same 6 users resolve, but the others will not.
> Frankly I'm stumped, but feel I'm so close to the answer.  I'm hoping someone
> can suggest something that might work here.
>
> smb.conf
> --------
> [global]
>   security = ads
>   auth methods = winbind guest sam
>   realm = MYDOM.DOMAIN.NET
>   netbios name = FILESERVE1
>   workgroup = MYDOM
>   use kerberos keytab = true
>   password server = 192.168.1.23
>   encrypt passwords = yes
>   server string = Samba 3.0.33-3.7.el5
>
> # winbind configuration
>   winbind refresh tickets = true
>   winbind nested groups = yes
>   winbind enum groups = yes
>   winbind enum users = yes
>   winbind use default domain = yes
>   winbind nss info = sfu
>   winbind separator = +
>   winbind cache time = 0
>   idmap domains = MYDOM
>   idmap config MYDOM:backend = ad
>   idmap config MYDOM:default = yes
>   idmap config MYDOM:range = 200-49999
>   idmap config MYDOM:schema_mode = sfu
>   idmap alloc backend = tdb
>   idmap alloc config:range = 50000-99999
>
>   invalid users = root bin daemon lp sys tty
>
>   log file = /var/log/samba/log.%m
>   log level = 3 printdrivers: 0 lanman: 0 smb: 1 rpc_parse: 0 rpc_srv: 0
> rpc_cli: 0 passdb: 1 sam: 0 auth: 5 winbind: 5 vfs: 0 idmap: 0 quota: 0 acls:
> 0 locking: 0 msdfs: 0 dmapi: 0
>   max log size = 1024
>
>   wins server = 192.168.1.23
>   wins support = no
>
>   socket options = TCP_NODELAY
>
> [printers]
>   printable = no
>
> [Public]
>   path = /data/Public
>   comment = Public data
>   read only = no
>   browseable = yes
>   dos filemode = yes
>   inherit permissions = Yes
>   inherit acls = Yes
>   ea support = yes
>   map acl inherit = yes
>   store dos attributes = yes
>   nfs4: mode = simple
>   nfs4: acedup = merge
>
>
> Thanks for bearing with me,
> Steve
>
>
> --
> To unsubscribe from this list go to the following URL and read the
> instructions:  https://lists.samba.org/mailman/options/samba
>