Bug 336 - Users extended groups aren't used when attempting write operation
Users extended groups aren't used when attempting write operation
Status: RESOLVED LATER
Product: Samba 3.0
Classification: Unclassified
Component: User/Group Accounts
3.0.0preX
All Solaris
: P1 major
: 3.0.1
Assigned To: Gerald (Jerry) Carter
:
: 444 (view as bug list)
Depends on:
Blocks: 807
  Show dependency treegraph
 
Reported: 2003-08-21 09:47 UTC by Brian King
Modified: 2005-11-14 09:30 UTC (History)
1 user (show)

See Also:


Attachments
Failed "put" debug level 10 (312 bytes, text/plain)
2003-08-21 09:55 UTC, Brian King
no flags Details
log.nmdb from comment 1 (36.94 KB, text/plain)
2003-08-21 09:56 UTC, Brian King
no flags Details
log.smbd from comment 1 (951 bytes, text/plain)
2003-08-21 09:56 UTC, Brian King
no flags Details
log.winbindd from comment 1 (1.65 KB, text/plain)
2003-08-21 09:57 UTC, Brian King
no flags Details
smbd -d10 (log.client) on a failed put (145.56 KB, text/plain)
2003-08-21 10:25 UTC, Brian King
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Brian King 2003-08-21 09:47:27 UTC
The user SNB\gwstairs can authenticate to a share (cetrmu), but can't write to 
it, even though the facl on the directory grants several of the groups he 
belongs to, write permissions. (using CVS version from 2003-08-18)

====
bash-2.05# for gid in `wbinfo -r SNB\\\\gwstairs` ; do wbinfo -s `wbinfo -G 
$gid` ; done
SNB\Domain Users 2
Could not lookup sid S-1-5-32-545
SNB\(SNB) Planet E-1 2
SNB\(SNB) Planet Email F 2
SNB\(SNB) RPIIS Team 2
SNB\(SNB) PLANET Communi 2
SNB\(SNB) R4 Test 2
SNB\(SNB) All Exchange U 2
SNB\Reports AT-A2G-OPS-M 2
SNB\SNB-QMVS_Purge-G 2
SNB\planet-map-admin-mt 2
SNB\SNB-DR_Exam-G 2
SNB\Reports DEV-M 2
SNB\SMSRemoteControlUsers 2
SNB\Reports AT-A2G-M 2
SNB\SNB-EDUC-STUDENTFS-DATA-G 2
SNB\SNB-Software-Install-G 2
SNB\SMS2-Include-G 2
SNB\SNB-EDUC-STUDENTFS-DATA-TEST-G 2
SNB\Reports-A2G-R 2
SNB\Reports-A2G-OPS-M 2

======
smb.conf excerpt:

[certmu]
        path = /oracle/app/oracle/admin/planet/P2900AT/files/mucki
        valid users = @SNB.CA\Reports-A2G-R
        read only = No
        preserve case = No
        browseable = No

=======
directory permissions:

bash-2.05# ls -ld /oracle/app/oracle/admin/planet/P2900AT/files/mucki
drwxrwsr-x+  4 oracle   dba        13824 Aug 21 
10:51 /oracle/app/oracle/admin/planet/P2900AT/files/mucki
bash-2.05# getfacl /oracle/app/oracle/admin/planet/P2900AT/files/mucki

# file: /oracle/app/oracle/admin/planet/P2900AT/files/mucki
# owner: oracle
# group: dba
user::rwx
group::rwx              #effective:rwx
group:SNB\(SNB) Planet E-1:rwx          #effective:rwx
group:SNB\Reports-A2G-R:rwx             #effective:rwx
group:SNB\planet-map-admin-mt:rwx               #effective:rwx
mask:rwx
other:r-x

====
So, 3 of that users groups are allowed to create files in that directory, yet 
the user can't create a file.
This "technique" of using the facl on the users group works for other users (at 
least one), and it work's for this user if I add "Domain Users" to the facl.

I _suspect_ that it doesn't look at any other groups once it runs into the ones 
with brackets in the names. Note though, that those extended groups _do_ work 
for authentication (on the "valid users" line), they just don't work for write 
permissions.

=====
Example of a user/group combination that does work:

bash-2.05# for gid in `wbinfo -r SNB\\\\xbking` ; do wbinfo -s `wbinfo -G 
$gid` ; done
SNB\Domain Users 2
Could not lookup sid S-1-5-32-545
SNB\planet-map-mt 2
SNB\MVIRP-G 2
SNB\SNB-Admin-G 2
SNB\planet-spad-mt 2
SNB\SNB-EDUC-STUDENTFS-DATA-G 2
SNB\planet-external-data-mt 2
SNB\SNB-EDUC-STUDENTFS-DATA-TEST-G 2

and I tested the facl with the groups "SNB\planet-map-mt", "SNB\planet-spad-
mt", "SNB\planet-external-data-mt" and they all work. Notice that all of 
xbking's groups contain only alpha numerics, spaces, and hyphens.

=====

I will be attaching debug output shortly.
Comment 1 Brian King 2003-08-21 09:55:37 UTC
Created attachment 94 [details]
Failed "put" debug level 10

Debug output contains the results of:
- start samba (default debug level)
- #smbclient -k \\\\snb-fton-dbs8\\certmu   #(with credentials for
SNB\gwstairs)
- > ls , put ps_data   # put fails
- #smbcontrol smbd debug 10
- #smbcontrol nmbd debug 10
- #smbcontrol winbindd debug 10
- > put ps_data    # put fails again but with greater debug
- #smbcontrol smbd debug 0
- #smbcontrol nmbd debug 0
- #smbcontrol winbindd debug 0
- > quit
Comment 2 Brian King 2003-08-21 09:56:13 UTC
Created attachment 95 [details]
log.nmdb from comment 1
Comment 3 Brian King 2003-08-21 09:56:42 UTC
Created attachment 96 [details]
log.smbd from comment 1
Comment 4 Brian King 2003-08-21 09:57:16 UTC
Created attachment 97 [details]
log.winbindd from comment 1
Comment 5 Brian King 2003-08-21 10:13:35 UTC
Just noticed 2 things from that last test.
1 - nmbd cored.
2 - the "smbcontrol smbd debug 10" only seems to have but the "main" smbd in 
debug level 10, not the one I was connected with.

Here is the backtrace from the nmbd core, and I'll be repeating the test from 
comment 1 with "debug 10" on from the start, and replacing the attachments.


==== Note, this backtrace was taken with the core from CVS 2003-08-18, but the 
debug binary from CVS 2003-08-20, I didn't have the old debug binary around. 
====

(gdb) bt
#0  0xfee9f930 in ?? ()
#1  0x00089730 in zero_ip (ip=0xc34a8) at lib/util.c:1180
#2  0x00074c00 in convert_string (from=4294967295, to=CH_DOS, src=0xffbef568,
    srclen=3, dest=0x0, destlen=1334112) at lib/charcnv.c:194
#3  0x0002e098 in refresh_my_names (t=-4262552) at nmbd/nmbd_mynames.c:225
#4  0x0002e1fc in update_name_in_namelist (subrec=0xffbef568, namerec=0x145b0c)
    at nmbd/nmbd_namelistdb.c:77
#5  0x0002ce54 in process_node_status_request (subrec=0x1451d0, p=0x145ab8)
    at nmbd/nmbd_incomingrequests.c:337
#6  0x00034440 in process_nmb_response (p=0x0) at nmbd/nmbd_packets.c:1611
#7  0x000260c0 in reload_nmbd_services (test=1) at nmbd/nmbd.c:282
#8  0x00026744 in main (argc=15, argv=0xffbefd1c) at nmbd/nmbd.c:721
Cannot access memory at address 0x10000
(gdb) bt full
#0  0xfee9f930 in ?? ()
No symbol table info available.
#1  0x00089730 in zero_ip (ip=0xc34a8) at lib/util.c:1180
        init = 0
        ipzero = {S_un = {S_un_b = {s_b1 = 0 '\0', s_b2 = 0 '\0',
      s_b3 = 0 '\0', s_b4 = 0 '\0'}, S_un_w = {s_w1 = 0, s_w2 = 0},
    S_addr = 0}}
#2  0x00074c00 in convert_string (from=4294967295, to=CH_DOS, src=0xffbef568,
    srclen=3, dest=0x0, destlen=1334112) at lib/charcnv.c:194
        i_len = 0
        o_len = 0
        retval = 799912
        inbuf = 0x0
        outbuf = 0x0
        descriptor = 0xffffffff
#3  0x0002e098 in refresh_my_names (t=-4262552) at nmbd/nmbd_mynames.c:225
        namerec = (struct name_record *) 0x0
#4  0x0002e1fc in update_name_in_namelist (subrec=0xffbef568, namerec=0x145b0c)
    at nmbd/nmbd_namelistdb.c:77
        oldrec = (struct name_record *) 0x0
#5  0x0002ce54 in process_node_status_request (subrec=0x1451d0, p=0x145ab8)
    at nmbd/nmbd_incomingrequests.c:337
        nmb = (struct nmb_packet *) 0x145ab8
        qname = 0xffbef638 ""
        ques_type = 0
        rdata = '\0' <repeats 16 times>, "ÿ¾õh", '\0' <repeats 28 
times>, "ÿÿÿÿ\0\0\0\003ÿ¾õh\0\0\0\003\0\0\0\0\0\024[`ÿ¾ô\230\0\002à\220", '\0' 
<repeats 88 times>, "ÿ¾õh\0\024[\f", '\0' <repeats 16 times>, "ÿ¾õ\b\0\002áô\0
\016è", '\0' <repeats 23 times>, "\004\0ÿ¾ö@\0\0\0\0\0\0\0\0ÿ¾ö8\0
\024ª\210ÿ¾õh", '\0' <repeats 29 times>, "\024QÐ\0\024[\f\0\0\0\0\0\0\002Ï\0\0\0
\0\0\a\211xÿ¾õÐ\0\002ÎL", '\0' <repeats 32 times>, "\237\177", '\0' <repeats 86 
times>, "ÿ¾õ¨\0\0"...
        countptr = 0x14aa88 ""
        buf = 0x145ad8 ""
        bufend = 0x145ad8 ""
        buf0 = 0x0
        names_added = 0
        i = 1333944
        namerec = (struct name_record *) 0x145b0c
#6  0x00034440 in process_nmb_response (p=0x0) at nmbd/nmbd_packets.c:1611
        nmb = (struct nmb_packet *) 0x145ab8
        subrec = (struct subnet_record *) 0x145ab8
        rrec = (struct response_record *) 0x0
#7  0x000260c0 in reload_nmbd_services (test=1) at nmbd/nmbd.c:282
        fname = "\0\0\0\0\0\0\0\0þëÀ\0\0\f4¨\0\fd\020\0\0\005¶ÿ¾ô\0\0\0ÿ\0ÿ¾ó°\0
\b\227(\0\0\0\001\0\f4¨\0\fd\020\0\0\005¶ÿ¾ï \0\017\020", '\0' <repeats 12 
times>, "Xÿ¾òØ", '\0' <repeats 34 times>, "\003\0\005@.\032\0\017\031h\0\016
\b", '\0' <repeats 26 times>, "\f4¨\0\0170ø\0\024bX\0\0\0\003ÿ¾ô\204\0\0ÿ\0ÿ¾ô 
\0\aKø\0\0\001\020ÿ¾ô\0\0\f4¨\0\fd\020\0\0\005¶ÿ¾ô\0\0\0ÿ\0ÿ¾õh", '\0' <repeats 
16 times>, "ÿ¾õh", '\0' <repeats 28 times>, "ÿÿ"...
        ret = 1061484462
#8  0x00026744 in main (argc=15, argv=0xffbefd1c) at nmbd/nmbd.c:721
        logfile = "/usr/local/samba/var/log.nmbd", '\0' <repeats 19 
times>, "þì5 \0\017\030(\0\0\0\001ÿ/ø\\ÿ1\205Ô\0\0\0\004ÿ¾ù\030ÿ/÷\200ÿ1
\205Ôÿ/ø\\", '\0' <repeats 16 times>, "ÿ¾ù\030ÿ/÷\200", '\0' <repeats 32 
times>, "ÿ1@", '\0' <repeats 21 times>, "ÿ¾ùxÿ0\0\034þëèxþëÀ\0\0\0\0\001\0\0\0\0
\0\0\0\001\0\0\0\0ÿ¾ùxþéù¸", '\0' <repeats 36 times>, "ÿ>\206°ÿ>\200Èÿ>\206°\0\0
\0\0\0\0\0\0ÿ¾ùØÿ;ËP\0\0"...
        opt_interactive = 0
        pc = 0xdcc00
        opt = 1
        long_options = {{longName = 0x0, shortName = 0 '\0', argInfo = 4,
    arg = 0xf0ed0, val = 0, descrip = 0xa35f0 "\001", argDescrip = 0x0}, {
    longName = 0xa3600 "\201è", shortName = 68 'D', argInfo = 7,
    arg = 0xe2168, val = 1, descrip = 0xa3608 "\177þ\006R\001",
    argDescrip = 0x0}, {longName = 0xa3628 "ncdns.c", shortName = 105 'i',
    argInfo = 7, arg = 0xe2164, val = 1, descrip = 0xa3638 "result",
    argDescrip = 0x0}, {longName = 0xa3658 " DNS answer for %s\n",
    shortName = 70 'F', argInfo = 7, arg = 0xdc5e0, val = 0,
    descrip = 0xa3668 "%s\n", argDescrip = 0x0}, {longName = 0xa36a0 "",
    shortName = 83 'S', argInfo = 7, arg = 0xe216c, val = 1,
    descrip = 0xa36b0 "ync_dns", argDescrip = 0x0}, {
    longName = 0xa36c0 "eate asyncdns pipes\n", shortName = 72 'H',
    argInfo = 1, arg = 0xdce80, val = 72, descrip = 0xa36c8 "ncdns pipes\n",
    argDescrip = 0x0}, {longName = 0xa36e8 " process %d\n",
    shortName = 112 'p', argInfo = 2, arg = 0xdc5dc, val = 137,
    descrip = 0xa36f0 " %d\n", argDescrip = 0x0}, {longName = 0x0,
    shortName = 0 '\0', argInfo = 4, arg = 0xe1f3c, val = 0,
    descrip = 0xa3710 "te DNS answer from child!\n", argDescrip = 0x0}, {
    longName = 0x0, shortName = 0 '\0', argInfo = 0, arg = 0x0, val = 0,
    descrip = 0x0, argDescrip = 0x0}}
#9  0x00024e88 in _START_ ()

Comment 6 Brian King 2003-08-21 10:25:37 UTC
Created attachment 98 [details]
smbd -d10 (log.client) on a failed put

Interesting portion of the new smdb debug 10:

...
[2003/08/21 14:18:57, 5] smbd/files.c:file_new(122)
  allocated file structure 4353, fnum = 8449 (1 used)
[2003/08/21 14:18:57, 10] smbd/open.c:open_file_shared1(846)
  open_file_shared: fname = ps_data, share_mode = 42, ofun = 12, mode = 744,
opl
ock request = 0
[2003/08/21 14:18:57, 8] lib/util.c:is_in_path(1535)
  is_in_path: ps_data
[2003/08/21 14:18:57, 8] lib/util.c:is_in_path(1539)
  is_in_path: no name list.
[2003/08/21 14:18:57, 3] lib/util.c:unix_clean_name(580)
  unix_clean_name [ps_data]
[2003/08/21 14:18:57, 4] smbd/open.c:open_file_shared1(1012)
  calling open_file with flags=0x2 flags2=0x300 mode=0744
[2003/08/21 14:18:57, 10] smbd/open.c:fd_open(51)
  fd_open: name ps_data, flags = 0402 mode = 0744, fd = -1. Permission denied
[2003/08/21 14:18:57, 3] smbd/open.c:open_file(182)
  Error opening file ps_data (Permission denied) (local_flags=258) (flags=770)
[2003/08/21 14:18:57, 5] smbd/files.c:file_free(369)
  freed files structure 8449 (0 used)
[2003/08/21 14:18:57, 10] smbd/trans2.c:set_bad_path_error(1719)
  set_bad_path_error: err = 13m bad_path = 0
[2003/08/21 14:18:57, 3] smbd/error.c:error_packet(94)
  error string = Permission denied
...
Comment 7 Brian King 2003-08-21 11:51:25 UTC
This could be related to bug 316 (if I am right in guessing it's the brackets). 
It may not be brackets though:

After talking to the Windows administrator, it turns out the problem "groups" 
are actually exchange distribution lists.
Also, wbinfo only returns 6 of the 14 distribution lists (as groups
 "wbinfo -r").

SNB\(SNB) Planet E-1 2
SNB\(SNB) Planet Email F 2
SNB\(SNB) RPIIS Team 2
SNB\(SNB) PLANET Communi 2
SNB\(SNB) R4 Test 2
SNB\(SNB) All Exchange U 2

Whereas "net ads user info" returns all 14:

(SNB) POS TEAM
(SNB) All Exchange Users
(SNB) HQ Electronic Services Staff
(SNB) HQ Electronic Services Branch
(SNB) HQ College Hill Road Staff
(SNB) A-cubed Team
(SNB) Planet Archive Errors
(SNB) Planet Archive Notices
(SNB) RPIIS Team
(SNB) Planet Email Fax Update
(SNB) PLANET Communication Operations
(SNB) Planet Email Fax Query
(SNB) R4 Test


So:
1 - should distribution lists be showing up as groups at all?
2 - if yes, where are the missing 8?
3 - if no, why are these 6 showing up?
4 - Is my problem caused by groups that aren't groups, or brackets?
Comment 8 Brian King 2003-08-22 09:50:30 UTC
Update: I downloaded today's (2003-08-22) CVS code and the problem is still 
present.
Comment 9 Gerald (Jerry) Carter 2003-08-22 10:10:22 UTC
distribution lists should not show up IMO.
I'll have to look into this.  

btw... are you using OU's other than cn=Users.
Comment 10 Brian King 2003-08-22 10:53:02 UTC
We are using non default containers:

---- Problem account (can't write to share) -----
bash-2.05# net ads search '(sAMAccountName=gwstairs)' distinguishedName 
objectCategory
Got 1 replies

distinguishedName: CN=Stairs\, George (SNB),OU=SNB UsersG,DC=snb,DC=ca
objectCategory: CN=Person,CN=Schema,CN=Configuration,DC=gnb,DC=ca


---- Working account (can write to share) -----

bash-2.05# net ads search '(sAMAccountName=xbking)' distinguishedName 
objectCategory
Got 1 replies

distinguishedName: CN=King\, Brian (SNB),OU=xwave,OU=IT Admin,OU=SNB 
UsersG,DC=snb,DC=ca
objectCategory: CN=Person,CN=Schema,CN=Configuration,DC=gnb,DC=ca


=====

Another update. We took the problem user out of the 6 exchange distribution 
lists that are showing up as groups, and now he can write, so we have confirmed 
that those "pseudo groups" are the problem. Either because of the brackets, or 
because of the fact that they aren't really groups. Unfortunately we have to 
add him back to those lists. We are adding him back now and expect it to break 
his write ability again. I'll post again once we've retested afterwards.
Comment 11 Brian King 2003-08-22 11:06:37 UTC
Confirmed, re-added the user to the distribution lists, and they reappeared as 
groups. His write access failed again.
Comment 12 Brian King 2003-08-22 12:16:20 UTC
Looked at the LDAP info for a distribution list that didn't show as a group, 
and one that did.

The differences were in:

Problem Dist List:
groupType: -2147483640
sAMAccountType: 268435456

Good Dist List:
groupType: 8
sAMAccountType: 268435457

When the windows admin looked more closely at it, he discovered that some of 
the distribution groups were assigned a type of "security group".
We changed one test distribution lists type to what it should be, and I 
confirmed that in LDAP, the values changed to match what the other distribution 
lists showed. Also, wbinfo no longer lists that test distribution list as 
a 'group'

We can't change the type of the rest of the distribution lists though. A 
windows "guru" here says that those particular distribution lists would be of 
that type because they have been used to grant permissions on exchange folders.

====
Other notes.
We added the xbking (working) account to one of the 6 distribution lists that 
are showing up as groups (R4 Test), and that accounts access did not break.

So, it still seems to be related to at least one of these groups, but it is not 
recreatable by just being a member of a "pseudo group"/distribution list with 
brackets. There is either something else at work here, or something else in 
combination with these things.
Comment 13 Gerald (Jerry) Carter 2003-08-25 21:48:22 UTC
This won't get fixed for RC2, but it is on my plate.
I've not been able to reproduce it yet.
Comment 14 Gerald (Jerry) Carter 2003-08-29 08:11:32 UTC
Will try again for RC3.
Comment 15 Gerald (Jerry) Carter 2003-08-29 08:11:55 UTC
Will try again for RC3.
Comment 16 Gerald (Jerry) Carter 2003-08-29 08:13:23 UTC
sorry.  didn't mean to close it.
Comment 17 Brian King 2003-09-08 08:08:12 UTC
We added the xbking account to all the same groups as the gwstairs account. 
gwstairs could still not write to the directory, but xbking could. So, it is 
not strictly a groups problem. It somehow related to the account as well!?!
Comment 18 Brian King 2003-09-09 07:39:21 UTC
Tried CVS code from 2003-09-08, and the problem seems to have gone away. Will 
be doing more testing to confirm.
Comment 19 Gerald (Jerry) Carter 2003-09-10 07:01:15 UTC
Let me know for sure and I'll close this one out.
Comment 20 Brian King 2003-09-12 06:05:31 UTC
Confirmed as working for 3 of our users (including one we know it didn't used 
to work for). Close it out.
Comment 21 Brian King 2003-09-12 06:38:12 UTC
This looks like bug 444. I might have been mistaken when I said the problem was 
resolved. I just realized I had added a "force group" option to each of the 
shares to work-around this issue while waiting for a fix, and forgot to remove 
it when I retested. Since mdawson (bug 444) is still having the issue, I 
suspect it's still there. I'll retest again.
Comment 22 Brian King 2003-09-12 07:18:08 UTC
Users to retest are not available today. I do have some other possibly 
interesting info though.

With winbindd at debug level 10. A "groups DOMAIN\\Username" command takes an 
extremely long time to return (>10 minutes) and only ever returns "Domain 
Users".

The winbindd log is filled with entries like

====
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 202, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5269]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5269 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5269 -> GID 10204
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5269 -> GID 10204
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10204
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10204 -> S-1-5-21-1416833156-
1238969774-10498456-5269
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10204]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10204 for group 1495
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5269
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5269 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5269 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5269 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5269 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 202
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 203, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5270]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5270 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5270 -> GID 10205
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5270 -> GID 10205
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10205
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10205 -> S-1-5-21-1416833156-
1238969774-10498456-5270
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10205]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10205 for group 1496
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5270
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5270 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5270 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5270 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5270 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 203
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 204, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5271]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5271 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5271 -> GID 10206
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5271 -> GID 10206
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10206
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10206 -> S-1-5-21-1416833156-
1238969774-10498456-5271
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10206]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10206 for group 1497
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5271
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5271 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5271 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5271 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5271 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 204
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 205, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5272]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5272 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5272 -> GID 10207
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5272 -> GID 10207
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10207
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10207 -> S-1-5-21-1416833156-
1238969774-10498456-5272
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10207]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10207 for group 1498
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5272
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5272 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5272 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5272 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5272 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 205
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 206, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5273]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5273 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5273 -> GID 10208
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5273 -> GID 10208
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10208
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10208 -> S-1-5-21-1416833156-
1238969774-10498456-5273
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10208]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10208 for group 1499
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5273
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5273 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5273 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5273 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5273 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 206
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 207, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5274]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5274 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5274 -> GID 10209
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5274 -> GID 10209
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10209
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10209 -> S-1-5-21-1416833156-
1238969774-10498456-5274
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10209]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10209 for group 149a
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5274
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5274 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5274 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5274 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5274 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 207
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 208, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5275]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5275 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5275 -> GID 10210
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5275 -> GID 10210
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10210
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10210 -> S-1-5-21-1416833156-
1238969774-10498456-5275
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10210]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10210 for group 149b
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5275
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5275 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5275 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5275 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5275 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 208
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 209, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5276]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5276 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5276 -> GID 10211
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5276 -> GID 10211
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10211
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10211 -> S-1-5-21-1416833156-
1238969774-10498456-5276
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10211]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10211 for group 149c
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5276
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5276 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5276 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5276 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5276 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 209
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 210, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5280]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5280 of type 0x2
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(228)
  internal_get_id_from_sid: record S-1-5-21-1416833156-1238969774-10498456-
5280 -> GID 10212
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(262)
  internal_get_id_from_sid: ID_GROUPID fetching record S-1-5-21-1416833156-
1238969774-10498456-5280 -> GID 10212
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(190)
  internal_get_sid_from_id: fetching record GID 10212
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_sid_from_id(196)
  internal_get_sid_from_id: fetching record GID 10212 -> S-1-5-21-1416833156-
1238969774-10498456-5280
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(187)
  idmap_sid_to_gid: gid = [10212]
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(695)
  got gid 10212 for group 14a0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(103)
  group SID S-1-5-21-1416833156-1238969774-10498456-5280
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(342)
  refresh_sequence_number: SNB time ok
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(367)
  refresh_sequence_number: SNB seq number is now 17722435
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:centry_expired(396)
  centry_expired: Key GM/S-1-5-21-1416833156-1238969774-10498456-5280 for 
domain SNB expired
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(455)
  wcache_fetch: entry GM/S-1-5-21-1416833156-1238969774-10498456-5280 expired 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(461)
  wcache_fetch: background processing expired entry GM/S-1-5-21-1416833156-
1238969774-10498456-5280 for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:wcache_fetch(470)
  wcache_fetch: returning entry GM/S-1-5-21-1416833156-1238969774-10498456-5280 
for domain SNB
[2003/09/12 10:59:05, 10] nsswitch/winbindd_cache.c:lookup_groupmem(1219)
  lookup_groupmem: [Cached] - cached info for domain SNB status Success
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(126)
  looked up 0 names
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(207)
  num_mem = 0, len = 0, mem = NULL
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:fill_grent_mem(214)
  fill_grent_mem returning 1
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(744)
  list_len = 632, mem_len = 0
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(766)
  adding group num_entries = 210
[2003/09/12 10:59:05, 10] nsswitch/winbindd_group.c:winbindd_getgrent(645)
  entry_index = 211, num_entries = 425
[2003/09/12 10:59:05, 10] sam/idmap_util.c:idmap_sid_to_gid(179)
  sid_to_gid: sid = [S-1-5-21-1416833156-1238969774-10498456-5281]
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:db_get_id_from_sid(315)
  db_get_id_from_sid
[2003/09/12 10:59:05, 10] sam/idmap_tdb.c:internal_get_id_from_sid(221)
  internal_get_id_from_sid: fetching record S-1-5-21-1416833156-1238969774-
10498456-5281 of type 0x2


=====
the ones I though were interesting are the:
"got gid 10### for group ####"

I am assuming the "group ####" should actually be a group name, not a number?
This debug output was a very small section from looking up the groups for 
gwstairs who should be in the following groups:

bash-2.05# net ads user INFO gwstairs
ESD Testing
(SNB) IT FW Notifications
planet-map-admin-mt
(SNB) Planet Acnt Chg Notice
Reports DEV-M
Reports AT-A2G-OPS-M
Reports AT-A2G-M
Reports-A2G-OPS-M
Reports-A2G-R
(SNB) POS TEAM
(SNB) All Exchange Users
(SNB) HQ Electronic Services Staff
(SNB) HQ Electronic Services Branch
(SNB) HQ College Hill Road Staff
(SNB) A-cubed Team
(SNB) Planet Archive Errors
(SNB) Planet Archive Notices
(SNB) RPIIS Team
(SNB) Planet Email Fax Update
(SNB) PLANET Communication Operations
(SNB) Planet Email Fax Query
(SNB) R4 Test
Software-Install
QMVS Purge
DR-Exam
EDUC-StudentsFS-Data
EDUC-StudentsFS-Test
SMS2 Include
SMSRemoteControlUsers


====
bash-2.05# for gid in `wbinfo -r SNB\\\\Gwstairs` ; do SID=`wbinfo -G 
$gid` ;echo "$gid $SID `wbinfo -s $SID`"; done
10000 S-1-5-21-1416833156-1238969774-10498456-513 SNB\Domain Users 2
10001 S-1-5-32-545 Could not lookup sid S-1-5-32-545
10034 S-1-5-21-1416833156-1238969774-10498456-5104 SNB\(SNB) Planet E-1 2
10224 S-1-5-21-1416833156-1238969774-10498456-5077 SNB\(SNB) Planet Email F 2
10038 S-1-5-21-1416833156-1238969774-10498456-5108 SNB\(SNB) RPIIS Team 2
10225 S-1-5-21-1416833156-1238969774-10498456-5078 SNB\(SNB) PLANET Communi 2
10197 S-1-5-21-1416833156-1238969774-10498456-5262 SNB\(SNB) All Exchange U 2
10368 S-1-5-21-1416833156-1238969774-10498456-5436 SNB\Reports AT-A2G-OPS-M 2
10329 S-1-5-21-1416833156-1238969774-10498456-4200 SNB\SNB-QMVS_Purge-G 2
10372 S-1-5-21-1416833156-1238969774-10498456-5591 SNB\planet-map-admin-mt 2
10328 S-1-5-21-1416833156-1238969774-10498456-4199 SNB\SNB-DR_Exam-G 2
10369 S-1-5-21-1416833156-1238969774-10498456-5438 SNB\Reports DEV-M 2
10259 S-1-5-21-1416833156-1238969774-10498456-1101 SNB\SMSRemoteControlUsers 2
10405 S-1-5-21-1416833156-1238969774-10498456-5967 SNB\ESD Testing 2
10361 S-1-5-21-1416833156-1238969774-10498456-5433 SNB\Reports AT-A2G-M 2
10004 S-1-5-21-1416833156-1238969774-10498456-3839 SNB\SNB-EDUC-STUDENTFS-DATA-
G 2
10263 S-1-5-21-1416833156-1238969774-10498456-4808 SNB\SNB-Software-Install-G 2
10248 S-1-5-21-1416833156-1238969774-10498456-3908 SNB\SMS2-Include-G 2
10005 S-1-5-21-1416833156-1238969774-10498456-3838 SNB\SNB-EDUC-STUDENTFS-DATA-
TEST-G 2
10351 S-1-5-21-1416833156-1238969774-10498456-5426 SNB\Reports-A2G-R 2
10356 S-1-5-21-1416833156-1238969774-10498456-5429 SNB\Reports-A2G-OPS-M 2
Comment 23 Brian King 2003-09-15 10:10:50 UTC
Users retested today, the bug is still there.
User cannot write to directory when one of his extended groups is allowed to 
write, but not his primary (Domain Users).
Comment 24 Gerald (Jerry) Carter 2003-09-24 15:14:33 UTC
*** Bug 444 has been marked as a duplicate of this bug. ***
Comment 25 Mike Dawson 2003-11-17 03:43:56 UTC
Is bug 395 (https://bugzilla.samba.org/show_bug.cgi?id=395) related to this?

I've found my access problems seem to go away if I set winbind use default
domain = no.
Comment 26 Gerald (Jerry) Carter 2003-11-17 08:30:51 UTC
Brian,  this might be a dpulicate of 406.
Canm you test 3.0.1pre3 and let me know if 
the problem is resolved?  Thanks.
Comment 27 Gerald (Jerry) Carter 2003-11-29 09:46:51 UTC
Closing this for a couple of reasons.

  1) We no longer have access to the test site.  
  2) I was never able to reproduce it locally
  3) I've been able to toexplain the question posted
     in the last comment (by teh reporter)
  4) This does not seem to be a generic problem since 
     we have had no other reports.

So we'll open a new bug if someone stumbles across this again.
Comment 28 Gerald (Jerry) Carter 2005-02-07 09:05:45 UTC
originally reported against one of the 3.0.0rc[1-4] releases.
Cleaning up non-production versions.
Comment 29 Gerald (Jerry) Carter 2005-11-14 09:30:29 UTC
database cleanup