8:24 a.m.
Hi guys,
Weird problem here. Running Ubuntu with SSSD 1.9.5.
Upon login after a long period between consecutive logins by the same user,
I receive the following error message:
groups: cannot find name for group ID 1596003661
`id` yields this:
USER@smarty:~$ id
uid=1596001141(USER) gid=1596000513(domain users) groups=1596000513(domain
users),1596001142(radioworksusers),1596001642(nixdesktopusers),1596001643(nixserverusers),1596003180(puppetmakers),1596003206(drupal_admin),1596003661
An immediate subsequent login on the same system by the same user fails to
produce the error message and the phantom group disappears from `id` output:
USER@smarty:~$ id
uid=1596001141(USER) gid=1596000513(domain users) groups=1596000513(domain
users),1596001142(radioworksusers),1596001642(nixdesktopusers),1596001643(nixserverusers),1596003180(puppetmakers),1596003206(drupal_admin)
I've also just noticed that the group ID reported is not consistent but can
vary. I've searched my AD server for a group objectSID in question but have
not found one; the group does not exist.
There seem to be no negative side effects aside from the error message and
unmapped GID in the output of the `id` command.
My config:
[sssd]
config_file_version = 2
debug_level = 0
reconnection_retries = 3
sbus_timeout = 30
services = nss, pam
domains = DOMAIN
[pam]
debug_level = 0
[nss]
debug_level = 0
filter_users =
root,ldap,named,avahi,haldaemon,dbus,radvd,tomcat,radiusd,news,mailman,nscd,gdm
filter_groups =
root,ldap,named,avahi,haldaemon,dbus,radvd,tomcat,radiusd,news,mailman,nscd,gdm
reconnection_retries = 3
default_shell = /bin/bash
shell_fallback = /bin/bash
[domain/DOMAIN]
debug_level = 0
ad_domain = DOMAIN.local
id_provider = ad
auth_provider = ad
chpass_provider = ad
access_provider = ad
enumerate = true
cache_credentials = true
# Will check unixHomeDirectory LDAP attribute for a value first
fallback_homedir = /home/%u
dyndns_update = true
dyndns_update_ptr = true
ldap_schema = ad
ldap_id_mapping = true
default_shell = /bin/bash
Thanks!
-Chris
8:42 a.m.
On (09/08/13 09:24), Chris Hartman wrote:
Hi guys,
Weird problem here. Running Ubuntu with SSSD 1.9.5.
Upon login after a long period between consecutive logins by the same user,
I receive the following error message:
groups: cannot find name for group ID 1596003661
`id` yields this:
> USER@smarty:~$ id
uid=1596001141(USER) gid=1596000513(domain users) groups=1596000513(domain
>
users),1596001142(radioworksusers),1596001642(nixdesktopusers),1596001643(nixserverusers),1596003180(puppetmakers),1596003206(drupal_admin),1596003661
An immediate subsequent login on the same system by the same user fails to
produce the error message and the phantom group disappears from `id` output:
> USER@smarty:~$ id
uid=1596001141(USER) gid=1596000513(domain users) groups=1596000513(domain
>
users),1596001142(radioworksusers),1596001642(nixdesktopusers),1596001643(nixserverusers),1596003180(puppetmakers),1596003206(drupal_admin)
I've also just noticed that the group ID reported is not consistent but can
vary. I've searched my AD server for a group objectSID in question but have
not found one; the group does not exist.
There seem to be no negative side effects aside from the error message and
unmapped GID in the output of the `id` command.
My config:
> [sssd]
> config_file_version = 2
> debug_level = 0
> reconnection_retries = 3
> sbus_timeout = 30
> services = nss, pam
> domains = DOMAIN
>
> [pam]
> debug_level = 0
>
[nss]
> debug_level = 0
> filter_users =
> root,ldap,named,avahi,haldaemon,dbus,radvd,tomcat,radiusd,news,mailman,nscd,gdm
> filter_groups =
> root,ldap,named,avahi,haldaemon,dbus,radvd,tomcat,radiusd,news,mailman,nscd,gdm
> reconnection_retries = 3
> default_shell = /bin/bash
> shell_fallback = /bin/bash
>
[domain/DOMAIN]
> debug_level = 0
> ad_domain = DOMAIN.local
> id_provider = ad
> auth_provider = ad
> chpass_provider = ad
> access_provider = ad
> enumerate = true
> cache_credentials = true
> # Will check unixHomeDirectory LDAP attribute for a value first
> fallback_homedir = /home/%u
> dyndns_update = true
> dyndns_update_ptr = true
> ldap_schema = ad
> ldap_id_mapping = true
> default_shell = /bin/bash
Thanks!
-Chris
Please enable verbose logging in sssd.
add debug_level = 10 into domain and nss section.
Restart sssd.
And then try to get some information about problematic group.
getent group -s sss 1596003661
I hope that something useful will be in sssd log files,
if the same error message will be shown.
>groups: cannot find name for group ID 1596003661
LS
9:57 a.m.
On Fri, Aug 9, 2013 at 9:42 AM, Lukas Slebodnik <lslebodn(a)redhat.com> wrote:
And then try to get some information about problematic group.
getent group -s sss 1596003661
Output from that command:
USER@smarty:~$ getent group -s sss 1596003661
certificate service dcom access:*:1596003661:
Performed again with another phantom group:
USER@smarty:/etc/puppet/modules/sssd$ getent group -s sss 1596003662
users:*:1596003662:aspnet
I've got debug output but it contains some relatively private information
(first and last names, usernames, possibly other directory information).
It's also rather large (11K lines). Could I share this offlist if necessary?
As it is, here are some relevant lines. In this case, the reported bad
group was 1596003663.
==> sssd_nss.log <==
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_remove_timeout] (0x2000):
0x9656278
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_dispatch] (0x4000): dbus
conn: 964B150
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_dispatch] (0x4000):
Dispatching.
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got
reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100):
Requesting info for [1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_callback": 0x9655fe0
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_timeout": 0x9648240
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying
timer event 0x9648240 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending
timer event 0x9655fe0 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0400):
Returning info for gid [1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000):
Checking negative cache for [NCE/GROUP/TESTDOMAIN/drupal_admin]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000):
Checking negative cache for [NCE/USER/TESTDOMAIN/testuser]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_req_destructor] (0x0400):
Deleting request: [0x807bb20:2:1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000):
Checking negative cache for [NCE/GID/1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100):
Requesting info for [1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_callback": 0x9648298
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_timeout": 0x9656a70
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying
timer event 0x9656a70 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending
timer event 0x9648298 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_issue_request] (0x0400):
Issuing request for [0x807bb20:2:1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_get_account_msg] (0x0400):
Creating request for [TESTDOMAIN][4098][1][idnumber=1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_add_timeout] (0x2000):
0x96579e8
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_internal_get_send]
(0x0400): Entering request [0x807bb20:2:1596003663@TESTDOMAIN]
==> sssd_TESTDOMAIN.log <==
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [acctinfo_callback]
(0x0100): Request processed. Returned 0,0,Success
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[(nil)], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_dispatch]
(0x4000): dbus conn: 95379C0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_dispatch]
(0x4000): Dispatching.
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_message_handler]
(0x4000): Received SBUS method [getAccountInfo]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [be_get_account_info]
(0x0100): Got request for [4098][1][idnumber=1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_groups_next_base] (0x0400): Searching for groups with base
[DC=TESTDOMAIN,DC=local]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))][DC=TESTDOMAIN,DC=local].
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 104
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg
set
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_get_groups_process] (0x0400): Search for groups, returned 0 results.
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_id_op_done]
(0x4000): releasing operation connection
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_callback": 0x9550388
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_timeout": 0x9658190
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Destroying timer event 0x9658190 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Ending timer event 0x9550388 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): start
ldb transaction (nesting: 0)
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_callback": 0x95562b0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_timeout": 0x9556310
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_callback": 0x95f5ac8
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_timeout": 0x95507e0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Destroying timer event 0x9556310 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Ending timer event 0x95562b0 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_callback": 0x95ea5e8
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_timeout": 0x95c6c58
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Destroying timer event 0x95507e0 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Ending timer event 0x95f5ac8 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_callback": 0x95c6d60
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent:
Added timed event "ltdb_timeout": 0x95e9b20
etc...
<output ommitted>
==> sssd_nss.log <==
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_remove_timeout] (0x2000):
0x96579e8
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000): dbus
conn: 964B150
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000):
Dispatching.
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got
reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100):
Requesting info for [1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_callback": 0x965a8f0
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
event "ltdb_timeout": 0x96575c0
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying
timer event 0x96575c0 "ltdb_timeout"
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending
timer event 0x965a8f0 "ltdb_callback"
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0040):
No matching domain found for [1596003663], fail!
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sss_dp_req_destructor] (0x0400):
Deleting request: [0x807bb20:2:1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle
timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [client_recv] (0x0200): Client
disconnected!
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [client_destructor] (0x2000):
Terminated client [0x9658678][23]
==> sssd_TESTDOMAIN.log <==
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [acctinfo_callback]
(0x0100): Request processed. Returned 0,0,Success
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: sh[0x9543678], connected[1], ops[(nil)], ldap[0x9537030]
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
Thanks.
-Chris
10:47 a.m.
On (09/08/13 10:57), Chris Hartman wrote:
On Fri, Aug 9, 2013 at 9:42 AM, Lukas Slebodnik
<lslebodn(a)redhat.com> wrote:
> And then try to get some information about problematic group.
> getent group -s sss 1596003661
>
Output from that command:
> USER@smarty:~$ getent group -s sss 1596003661
> certificate service dcom access:*:1596003661:
Performed again with another phantom group:
> USER@smarty:/etc/puppet/modules/sssd$ getent group -s sss 1596003662
> users:*:1596003662:aspnet
I've got debug output but it contains some relatively private information
(first and last names, usernames, possibly other directory information).
It's also rather large (11K lines). Could I share this offlist if necessary?
As it is, here are some relevant lines. In this case, the reported bad
group was 1596003663.
... snip ...
> (0x4000): Received SBUS method [getAccountInfo]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [be_get_account_info]
> (0x0100): Got request for [4098][1][idnumber=1596003663]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_id_op_connect_step] (0x4000): reusing cached connection
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_groups_next_base] (0x0400): Searching for groups with base
> [DC=TESTDOMAIN,DC=local]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
>
[(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))][DC=TESTDOMAIN,DC=local].
^^^^^^^
This is the 1st interesting part.
Could you try to do same query with ldapsearch? (the first part is filster and
the second one is search base.
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 104
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
> (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
> ldap[0x9537030]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
> (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
> (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
> ldap[0x9537030]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
> (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
> (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
> ldap[0x9537030]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
> (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result]
> (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300],
> ldap[0x9537030]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message]
> (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg
> set
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
> [sdap_get_groups_process] (0x0400): Search for groups, returned 0 results.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Group was not found.
> (Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]]
[sdap_id_op_done]
> (0x4000): releasing operation connection
> <output ommitted>
> ==> sssd_nss.log <==
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_remove_timeout] (0x2000):
> 0x96579e8
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000): dbus
> conn: 964B150
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got
> reply from Data Provider - DP error code: 0 errno: 0 error message: Success
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100):
> Requesting info for [1596003663@TESTDOMAIN]
^^^^^^^^
Here is begin of request in sssd_nss
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent:
Added timed
> event "ltdb_callback": 0x965a8f0
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed
> event "ltdb_timeout": 0x96575c0
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying
> timer event 0x96575c0 "ltdb_timeout"
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending
> timer event 0x965a8f0 "ltdb_callback"
> (Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0040):
> No matching domain found for [1596003663], fail!
^^^^^^^^^^^^^^^^^^^^^^^^^^^
I don't know why this message is here. I would expect:
a) No results for getgrgid call
b) Returning info for gid .....
Maybe someone else will help you.
LS
11:31 a.m.
On Fri, Aug 9, 2013 at 11:47 AM, Lukas Slebodnik <lslebodn(a)redhat.com>wrote:
Could you try to do same query with ldapsearch? (the first part is
filster
and
the second one is search base.
Sure can:
root@smarty:/etc/puppet/modules/sssd/files# kinit -k -t
/etc/krb5.keytab
host/$(hostname -f)
root@smarty:/etc/puppet/modules/sssd/files# ldapsearch -H
ldap://milkdud.TESTDOMAIN.local/ -Y GSSAPI -N -b "dc=testdomain,dc=local"
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
SASL/GSSAPI authentication started
SASL username: host/smarty.testdomain.local(a)TESTDOMAIN.LOCAL
SASL SSF: 56
SASL data security layer installed.
# extended LDIF
#
# LDAPv3
# base <dc=testdomain,dc=local> with scope subtree
# filter:
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
# requesting: ALL
#
# search reference
ref:
ldap://ForestDnsZones.testdomain.local/DC=ForestDnsZones,DC=testdomain,DC=local
# search reference
ref:
ldap://DomainDnsZones.testdomain.local/DC=DomainDnsZones,DC=testdomain,DC=local
# search reference
ref: ldap://testdomain.local/CN=Configuration,DC=testdomain,DC=local
# search result
search: 4
result: 0 Success
# numResponses: 4
# numReferences: 3
It's also interesting that some of the GIDs that are returned are not
actually groups but user objects in AD.
-Chris
5:08 p.m.
On 08/09/2013 12:31 PM, Chris Hartman wrote:
On Fri, Aug 9, 2013 at 11:47 AM, Lukas Slebodnik <lslebodn(a)redhat.com
<mailto:lslebodn@redhat.com>> wrote:
Could you try to do same query with ldapsearch? (the first part is
filster and
the second one is search base.
Sure can:
root@smarty:/etc/puppet/modules/sssd/files# kinit -k -t
/etc/krb5.keytab host/$(hostname -f)
root@smarty:/etc/puppet/modules/sssd/files# ldapsearch -H
ldap://milkdud.TESTDOMAIN.local/ -Y GSSAPI -N -b
"dc=testdomain,dc=local"
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
SASL/GSSAPI authentication started
SASL username: host/smarty.testdomain.local(a)TESTDOMAIN.LOCAL
SASL SSF: 56
SASL data security layer installed.
# extended LDIF
#
# LDAPv3
# base <dc=testdomain,dc=local> with scope subtree
# filter:
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
# requesting: ALL
#
# search reference
ref:
ldap://ForestDnsZones.testdomain.local/DC=ForestDnsZones,DC=testdomain,DC=local
# search reference
ref:
ldap://DomainDnsZones.testdomain.local/DC=DomainDnsZones,DC=testdomain,DC=local
# search reference
ref: ldap://testdomain.local/CN=Configuration,DC=testdomain,DC=local
# search result
search: 4
result: 0 Success
# numResponses: 4
# numReferences: 3
It's also interesting that some of the GIDs that are returned are not
actually groups but user objects in AD.
-Chris
_______________________________________________
sssd-users mailing list
sssd-users(a)lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/sssd-users
Was there any resolution to this issue?
--
Thank you,
Dmitri Pal
Sr. Engineering Manager for IdM portfolio
Red Hat Inc.
-------------------------------
Looking to carve out IT costs?
www.redhat.com/carveoutcosts/
7:29 a.m.
On Fri, Aug 09, 2013 at 12:31:01PM -0400, Chris Hartman wrote:
On Fri, Aug 9, 2013 at 11:47 AM, Lukas Slebodnik
<lslebodn(a)redhat.com>wrote:
> Could you try to do same query with ldapsearch? (the first part is filster
> and
> the second one is search base.
>
Sure can:
> root@smarty:/etc/puppet/modules/sssd/files# kinit -k -t /etc/krb5.keytab
> host/$(hostname -f)
> root@smarty:/etc/puppet/modules/sssd/files# ldapsearch -H
> ldap://milkdud.TESTDOMAIN.local/ -Y GSSAPI -N -b "dc=testdomain,dc=local"
>
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
> SASL/GSSAPI authentication started
> SASL username: host/smarty.testdomain.local(a)TESTDOMAIN.LOCAL
> SASL SSF: 56
> SASL data security layer installed.
> # extended LDIF
> #
> # LDAPv3
> # base <dc=testdomain,dc=local> with scope subtree
> # filter:
>
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
> # requesting: ALL
> #
> # search reference
> ref:
> ldap://ForestDnsZones.testdomain.local/DC=ForestDnsZones,DC=testdomain,DC=local
> # search reference
> ref:
> ldap://DomainDnsZones.testdomain.local/DC=DomainDnsZones,DC=testdomain,DC=local
> # search reference
> ref: ldap://testdomain.local/CN=Configuration,DC=testdomain,DC=local
> # search result
> search: 4
> result: 0 Success
> # numResponses: 4
> # numReferences: 3
It's also interesting that some of the GIDs that are returned are not
actually groups but user objects in AD.
-Chris
Do you run AD server in a trusted setup? Is it possible this group comes
from another AD domain?
Can you check if searching the SID in the Global Catalog works (just
search port 3268)?
# ldapsearch -H ldap://milkdud.TESTDOMAIN.local:3268 -Y GSSAPI -N -b
"dc=testdomain,dc=local" \
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
10:09 a.m.
On Fri, Aug 23, 2013 at 8:29 AM, Jakub Hrozek <jhrozek(a)redhat.com> wrote:
Do you run AD server in a trusted setup? Is it possible this group
comes
from another AD domain?
No. We have a single domain. No trusts or subdomains.
Can you check if searching the SID in the Global Catalog works (just
search port 3268)?
# ldapsearch -H ldap://milkdud.TESTDOMAIN.local:3268 -Y GSSAPI -N -b
"dc=testdomain,dc=local" \
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
Here are the results of that query:
USER@HOST:~$ ldapsearch -H ldap://milkdud.TESTDOMAIN.local:3268 -Y
GSSAPI
-N -b "dc=testdomain,dc=local"
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"SASL/GSSAPI
authentication started
SASL username: USER(a)TESTDOMAIN.LOCAL
SASL SSF: 56
SASL data security layer installed.
# extended LDIF
#
# LDAPv3
# base <dc=wysu,dc=local> with scope subtree
# filter:
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
# requesting: ALL
#
# search result
search: 4
result: 0 Success
# numResponses: 1
Also, I've actually not seen the original error in a few days and have
failed to reproduce it the few times I tried just now, so perhaps this was
a fluke? The only thing that has happened since then has been a reboot or
two of each domain controller. No changes to AD or any of the SIDs in
question. I'd be okay with shelving this issue until it rears its head
again. If any curious party wants me to experiment some more, I'd be happy
to oblige, I'll just need some direction because I'm stumped. Otherwise,
I'll monitor the issue for a few more days and post back with one more
follow up if I can't reproduce it.
Thanks.
-Chris
10:20 a.m.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On 08/23/2013 11:09 AM, Chris Hartman wrote:
On Fri, Aug 23, 2013 at 8:29 AM, Jakub Hrozek <jhrozek(a)redhat.com
<mailto:jhrozek@redhat.com>> wrote:
Do you run AD server in a trusted setup? Is it possible this group
comes from another AD domain?
No. We have a single domain. No trusts or subdomains.
Can you check if searching the SID in the Global Catalog works
(just search port 3268)? # ldapsearch -H
ldap://milkdud.TESTDOMAIN.local:3268 -Y GSSAPI -N -b
"dc=testdomain,dc=local" \
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
Here are the results of that query:
USER@HOST:~$ ldapsearch -H ldap://milkdud.TESTDOMAIN.local:3268 -Y
GSSAPI -N -b "dc=testdomain,dc=local"
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"SASL/GSSAPI
authentication started
SASL username: USER(a)TESTDOMAIN.LOCAL SASL SSF: 56 SASL data
security layer installed. # extended LDIF # # LDAPv3 # base
<dc=wysu,dc=local> with scope subtree # filter:
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
# requesting: ALL
# # search result search: 4 result: 0 Success # numResponses: 1
Also, I've actually not seen the original error in a few days and
have failed to reproduce it the few times I tried just now, so
perhaps this was a fluke? The only thing that has happened since
then has been a reboot or two of each domain controller. No changes
to AD or any of the SIDs in question. I'd be okay with shelving
this issue until it rears its head again. If any curious party
wants me to experiment some more, I'd be happy to oblige, I'll just
need some direction because I'm stumped. Otherwise, I'll monitor
the issue for a few more days and post back with one more follow up
if I can't reproduce it.
My best guess here is that you might have had an entry with that SID
on one replica that wasn't syncing properly. Every once in a while,
SSSD would end up connected to that replica at login.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.14 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iEYEARECAAYFAlIXfbEACgkQeiVVYja6o6PtiQCeOWxrq3Dmbbuo7hT7YHNrUjNr
NaMAn3AVnDB0qaI5iFUbZN+Qg6JDlwdf
=0K5v
-----END PGP SIGNATURE-----
10 a.m.
Well, I've gotten the phantom group error message again.
groups: cannot find name for group ID 1596003650
So, I tried to get some info:
root@snickers:~# getent group -s sss 1596003650
root@snickers:~#
As you can see, no output from getent.
So, I did an AD query as outlined here:
http://blog.schertz.name/2008/03/searching-ad-for-a-user-account-with-a-sid/
This
is the query I performed:
(&(objectCategory=*)(objectSID=\01\05\00\00\00\00\00\05\15\00\00\00\D9\4D\0B\6A\B4\D6\05\0E\16\51\0D\E2\42\0E\00\00))
No results found. So, the group reported REALLY doesn't exist, contrary to
what we found earlier. I've got sanitized, detailed logs:
- SSSD NSS log: http://pastebin.com/CQS4rYUe (I removed most timer event
messages as they took up ~2300 lines)
- SSSD domain log: http://tny.cz/41eec8a3
Bear in mind, I had to do some regex to remove sensitive information like
usernames and full names.
-Chris
On Fri, Aug 23, 2013 at 11:20 AM, Stephen Gallagher <sgallagh(a)redhat.com>wrote:
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On 08/23/2013 11:09 AM, Chris Hartman wrote:
>
> On Fri, Aug 23, 2013 at 8:29 AM, Jakub Hrozek <jhrozek(a)redhat.com
> <mailto:jhrozek@redhat.com>> wrote:
>
> Do you run AD server in a trusted setup? Is it possible this group
> comes from another AD domain?
>
> No. We have a single domain. No trusts or subdomains.
>
> Can you check if searching the SID in the Global Catalog works
> (just search port 3268)? # ldapsearch -H
> ldap://milkdud.TESTDOMAIN.local:3268 -Y GSSAPI -N -b
> "dc=testdomain,dc=local" \
>
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"
>
> Here are the results of that query:
>
> USER@HOST:~$ ldapsearch -H ldap://milkdud.TESTDOMAIN.local:3268 -Y
> GSSAPI -N -b "dc=testdomain,dc=local"
>
"(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))"SASL/GSSAPI
>
>
authentication started
> SASL username: USER(a)TESTDOMAIN.LOCAL SASL SSF: 56 SASL data
> security layer installed. # extended LDIF # # LDAPv3 # base
> <dc=wysu,dc=local> with scope subtree # filter:
>
(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))
>
>
# requesting: ALL
> # # search result search: 4 result: 0 Success # numResponses: 1
>
>
> Also, I've actually not seen the original error in a few days and
> have failed to reproduce it the few times I tried just now, so
> perhaps this was a fluke? The only thing that has happened since
> then has been a reboot or two of each domain controller. No changes
> to AD or any of the SIDs in question. I'd be okay with shelving
> this issue until it rears its head again. If any curious party
> wants me to experiment some more, I'd be happy to oblige, I'll just
> need some direction because I'm stumped. Otherwise, I'll monitor
> the issue for a few more days and post back with one more follow up
> if I can't reproduce it.
>
My best guess here is that you might have had an entry with that SID
on one replica that wasn't syncing properly. Every once in a while,
SSSD would end up connected to that replica at login.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.14 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iEYEARECAAYFAlIXfbEACgkQeiVVYja6o6PtiQCeOWxrq3Dmbbuo7hT7YHNrUjNr
NaMAn3AVnDB0qaI5iFUbZN+Qg6JDlwdf
=0K5v
-----END PGP SIGNATURE-----
_______________________________________________
sssd-users mailing list
sssd-users(a)lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/sssd-users
3886
days inactive
3906
days old
sssd-users@lists.fedorahosted.org
9 comments
5 participants
participants (5)
-
Chris Hartman -
Dmitri Pal -
Jakub Hrozek -
Lukas Slebodnik -
Stephen Gallagher