Project

General

Profile

Actions

Bug #14306

closed

Can't get SID for ID=0 type=0, status=-9977

Added by Lee Damon over 2 years ago. Updated 11 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
cifs - CIFS server and client
Start date:
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:
External Bug:
racktop:BSR-11277

Description

My /var/adm/messages log is filling up with these messages from sbmd. This isn't the first time this has happened and I see we're not the only site seeing it (https://illumos.topicbox.com/groups/omnios-discuss/T4ef0de18d0619eef-M21952692b0a1c779d451300a/smbd572-cant-get-sid-for-id0-type0-status-9977).

I'd like to get this to shut up and stop filing my logs, ideally by fixing whatever the underlying problem is. However, if it's truly ignorable perhaps a bandage could be applied to at least amelorate filling my disk with the error messages.

I restarted smbd and the log entries stopped for a whole 58 minutes then resumed.

SunOS fs2 5.11 omnios-r151038-b3a82a213e i86pc i386 i86pc

Dec 16 11:46:04 fs2 smbd549: [ID 617204 daemon.error] Can't get SID for ID=0 type=0, status=-9977
Dec 16 11:52:37 fs2 last message repeated 40 times
Dec 16 11:52:47 fs2 smbd549: [ID 617204 daemon.error] Can't get SID for ID=0 type=0, status=-9977
Dec 16 11:59:09 fs2 last message repeated 40 times
Dec 16 11:59:19 fs2 smbd549: [ID 617204 daemon.error] Can't get SID for ID=0 type=0, status=-9977


Files

id_out (8.11 KB) id_out Lee Damon, 2021-12-22 11:54 PM
idmap-noise-k.d.txt (684 Bytes) idmap-noise-k.d.txt Gordon Ross, 2023-02-09 01:06 AM
idmap-noise-u.d.txt (746 Bytes) idmap-noise-u.d.txt Gordon Ross, 2023-02-09 01:06 AM
idmap-noise-sommerfeld (2.48 KB) idmap-noise-sommerfeld Bill Sommerfeld, 2023-02-09 04:51 PM
Actions #1

Updated by Lee Damon over 2 years ago

At andyf's suggestion I ran the following dtrace:

sudo dtrace -n 'pid$target::smb_idmap_bgm_report:entry{print(*args[1])}' -p `pgrep smbd`
dtrace: description 'pid$target::smb_idmap_bgm_report:entry' matched 1 probe
CPU     ID                    FUNCTION:NAME
  8  83851       smb_idmap_bgm_report:entry smb_idmap_t {
    int sim_idtype = 0
    uid_t *sim_id = 0
    char *sim_domsid = 0x87766d8
    uint32_t sim_rid = 0x80002911
    smb_sid_t *sim_sid = 0
    idmap_stat sim_stat = 0xffffd907
}
  2  83851       smb_idmap_bgm_report:entry smb_idmap_t {
    int sim_idtype = 0
    uid_t *sim_id = 0
    char *sim_domsid = 0x877e108
    uint32_t sim_rid = 0x80002911
    smb_sid_t *sim_sid = 0
    idmap_stat sim_stat = 0xffffd907
}
Actions #2

Updated by Lee Damon over 2 years ago

sudo  dtrace -n 'pid$target::smb_idmap_bgm_report:entry{@[ustack()] = count()}' -p `pgrep smbd`

dtrace: description 'pid$target::smb_idmap_bgm_report:entry' matched 1 probe
^C

              libsmb.so.1`smb_idmap_bgm_report
              libsmb.so.1`smb_idmap_batch_getmappings+0x6b
              libsmb.so.1`smb_idmap_getsid+0x77
              libmlsvc.so.1`smb_quota_sidstr+0x4a
              libmlsvc.so.1`smb_quota_zfs_callback+0x67
              libzfs.so.1`zfs_userspace+0x104
              libmlsvc.so.1`smb_quota_zfs_get_quotas+0x61
              libmlsvc.so.1`smb_quota_tree_populate+0x9d
              libmlsvc.so.1`smb_quota_query+0x69
              smbd`smbd_dop_quota_query+0x5e
              smbd`smbd_door_dispatch_op+0x76
              libc.so.1`_thrp_setup+0x81
              libc.so.1`_lwp_start
                3
Actions #3

Updated by Lee Damon over 2 years ago

For the record, this is what I have set for idmap.

 ; idmap list
add -d  winuser:*@*     unixuser:*
add -d  wingroup:*@*    unixgroup:*
Actions #4

Updated by Lee Damon over 2 years ago

 ; sudo dtrace -n 'pid$target::smb_quota_sidstr:entry{@[arg0, arg1] = count()}' -p `pgrep smbd` 
dtrace: description 'pid$target::smb_quota_sidstr:entry' matched 1 probe
^C

            10513                2                3
            10513                6                3
                0                0                6
                0                2                6
                0                4                6
                0                6                6
                0                8                6
                0               10                6
                3                2                6
                3                6                6
               14                2                6
               14                6                6
            12186                0                6
            12186                4                6
            19328                0                6
            19328                4                6
Actions #5

Updated by Andy Fiddaman over 2 years ago

Could you try running this d script?
Put it in a file such as idmap.d and run as:

./idmap.d -p `pgrep smbd`
#!/usr/sbin/dtrace -Cs

pid$target::smb_idmap_batch_getmappings:entry {
        self->sib = args[0];
}

pid$target::smb_idmap_batch_getmappings:return {
        mib = self->sib->sib_maps;
        printf("%d %s %d\n", mib->sim_stat,
            mib->sim_idtype == 0 ? "group" : "user",
            mib->sim_id == 0 ? 0 : *(uint_t *)mib->sim_id);
        printf("Domsid: %s\n",
            mib->sim_domsid ? copyinstr((uintptr_t)mib->sim_domsid) : "NULL");
}
Actions #6

Updated by Lee Damon over 2 years ago

 ; sudo /usr/sbin/dtrace /tmp/idmap.d
dtrace: no probes specified

Actions #7

Updated by Yuri Pankov over 2 years ago

Lee Damon wrote in #note-6:

[...]

Apparently you are missing the -p `pgrep smbd` part in command.

Actions #8

Updated by Lee Damon over 2 years ago

Yuri Pankov wrote in #note-7:

Apparently you are missing the -p `pgrep smbd` part in command.

Where would that go?

Actions #9

Updated by Andy Fiddaman over 2 years ago

Make the idmap.d file executable and run it with that as the argument.

chmod +x /tmp/idmap.d
/tmp/idmap.d -p `pgrep smbd`
Actions #10

Updated by Lee Damon over 2 years ago

Andy Fiddaman wrote in #note-9:

Make the idmap.d file executable and run it with that as the argument.

oh duh. Running it for 60 seconds gave the attached result.

Actions #11

Updated by Gordon Ross over 1 year ago

  • File idmap-noise-k.d.txt added
  • File idmap-noise-u.d.txt added

I've attached two new dtrace scripts, one for kernel, another for user-level.
Run them like this:

dtrace -s idmap-noise-k.d
dtrace -s idmap-noise-u.d -p $(pgrep smbd)

This message seems to happen if a user has a SID that we can't map to a user or group ID.
It would be great if anyone can help identify configurations where that happens.

Actions #12

Updated by Gordon Ross over 1 year ago

  • File deleted (idmap-noise-k.d.txt)
Actions #13

Updated by Gordon Ross over 1 year ago

  • File deleted (idmap-noise-u.d.txt)
Actions #14

Updated by Gordon Ross over 1 year ago

  • File idmap-noise-k.d.txt added
  • File idmap-noise-u.d.txt added
Actions #15

Updated by Electric Monk over 1 year ago

  • Gerrit CR set to 2630
Actions #16

Updated by Gordon Ross over 1 year ago

Actions #17

Updated by Gordon Ross over 1 year ago

This appears to happen when SMB (and/or idmap) encounters group IDs that don't have names.
For example, an /etc/passwd entry where the primary group is something not in /etc/group.
This is probably not the only case, and maybe not even an interesting case, but is a clue.

Actions #18

Updated by Bill Sommerfeld over 1 year ago

I've been seeing this for a while on one system; I ran the two idmap-noise scripts on it and got no output from idmap-noise-k.d and the attached idmap-noise-sommerfeld output from idmap-noise-u.d

The messages come in threes, one with idtype=1 and two with idtype=0.

The sim_rid value in the second one, 0x80019569, is equal to (0x80000000 + my uid).

Actions #19

Updated by Bill Sommerfeld over 1 year ago

Okay, after digging around I found files owned by two unnamed gids and one unnamed uid in a SMB-exported filesystem which is being actively used by several mac clients. Large chunks of that filesystem were copied from one or more macs, and it appears that this happened in a way that preserved their original numeric mac uid/gid values.

The unnamed gids and uids corresponded to the sim_rid values observed in dtrace. I've fixed the problem and the noise appears to have stopped.

Actions #20

Updated by Gordon Ross over 1 year ago

It turns out logging for smb_idmap_batch_getmappings has never worked correctly for the _ID2SID cases because the sim_id field is generally not filled in. I've taken a whack at providing that, and generally improving the logging for this.

While I was comparing files, I noticed that the two versions (kernel vs. user) of smb_acl.c were out of sync. w.r.t. smb_ace_isvalid and the functions that uses. I copied those over from the kernel version. (It's not really new code.)

Actions #21

Updated by Gordon Ross over 1 year ago

  • Status changed from New to In Progress
  • Assignee set to Gordon Ross
Actions #22

Updated by Bill Sommerfeld over 1 year ago

Here are a couple shell pipelines to screen a zfs pool for filesystems with files accounted to unnamed uids and gids.

Extending this to unnamed SIDs is left as an exercise for the reader.

zfs list -H -t filesystem -r -o name | 
while read fs; do 
    zfs userspace -H -o name,used,objused -p $fs | (grep '^[0-9]' && echo $fs)
done
zfs list -H -t filesystem -r -o name | 
while read fs; do 
    zfs groupspace -H -o name,used,objused -p $fs | (grep '^[0-9]' && echo $fs)
done

Once you identify the id and filesystem you can find the actual file with find ... -user $id or find ... -group $id

Actions #23

Updated by Gordon Ross 11 months ago

  • Assignee changed from Gordon Ross to Toomas Soome
  • External Bug set to racktop:BSR-11277
Actions #24

Updated by Gordon Ross 11 months ago

There a two small design changes in this fix:
1: Have places that call smb_idmap_batch_getmappings fill in the sim_id field (pointing at the ID it's trying to map to a SID) so error reports can correctly show what ID can't be mapped.
2: Pass an optional call-back function for actually printing the errors in smb_idmap_batch_getmappings, which some call sites can omit. Eg. cases where we're mapping only one ID generally do their own error handling.

Actions #25

Updated by Gordon Ross 11 months ago

Testing:

Set an ACL with a UID that's not in the passed file (and/or a GID that's not in /etc/groups) and do some SMB access to those files. See log noise before the fix and not after.

Actions #26

Updated by Toomas Soome 11 months ago

  • Status changed from In Progress to Pending RTI
Actions #27

Updated by Electric Monk 11 months ago

  • Status changed from Pending RTI to Closed
  • % Done changed from 0 to 100

git commit f920d1d14a9315d14ccff066570cb3a133b018f9

commit  f920d1d14a9315d14ccff066570cb3a133b018f9
Author: Gordon Ross <gwr@racktopsystems.com>
Date:   2023-07-12T13:33:43.000Z

    14306 Can't get SID for ID=0 type=0, status=-9977
    Reviewed by: Matt Barden <mbarden@racktopsystems.com>
    Reviewed by: Toomas Soome <tsoome@me.com>
    Approved by: Dan McDonald <danmcd@mnx.io>

Actions

Also available in: Atom PDF