Hi Jakub.
> > > Note using this round-robin DNS name
"myadserver" works with the RHEL6 "stock" sssd we are running
(sssd-1.5.1-34.el6_1.3.x86_64).
> > >
> > > So this has been introduced somewhere between that version and v1.5.14.
> > >
> > > BTW I tried setting "ldap_sasl_canonicalize" to true and false
btw. It didn't make any difference.
> > >
> > > Can I no longer use a round-robin DNS name for my ldap server?
> > >
> >
> > Tim, what openldap and glibc versions are you running? I think getting the
> > "don't canonicalize" scenario to work involved fixes to several
components
> > including glibc and openldap.
>
> This is on RHEL6, so I think these are the current versions:
>
> # rpm -q glibc openldap
> glibc-2.12-1.25.el6_1.3.x86_64
> glibc-2.12-1.25.el6_1.3.i686
> openldap-2.4.23-15.el6_1.3.x86_64
>
> > Does merely swapping the sssd version with the same openldap and glibc versions
help?
>
> I'm not sure what I should swap. I'm running the latest openldap and glibc,
I could try the RHEL6 beta packages.
Sorry, I phrased that poorly. My original question was whether stock
RHEL6.1 SSSD worked with the same configuration and same version of
glibc and openldap where 1.5.14 failed.
To answer your question yes it does. It works, it's just slow hence why I'm
trying out 1.5.14 to see how much of an improvement the initgroups enhancement (trac
ticket #1006) has made.
<snip>
> 3) Now that I can login, I find the system can't resolves
uids and gids to usernames and groupnames. e.g.
>
> > ssh myhost999
> Password:
> Last login: Thu Oct 27 10:14:24 2011 from anotherhost.xxx.xxx.xxx
> id: cannot find name for user ID 9999999
> id: cannot find name for user ID 9999999
> $ id
2,9323,9324,9325,9326,9328,9329,9337,9338,9339,9340,9341
context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> $ groups
> localgroup1 groups: cannot find name for group ID 902
> 902 localgroup2 groups: cannot find name for group ID 2131
> 2131 groups: cannot find name for group ID 2132
> 2132 groups: cannot find name for group ID 2135
> 2135 groups: cannot find name for group ID 2202
> 2202 groups: cannot find name for group ID 2203
> ..etc
> ..etc
>
This is worrying. Can you paste more complete logs of the initgroups
operation? Are all the groups LDAP/AD groups or are some of them local
groups?
Certainly.
The ones you can see (localgroup1 localgroup2) are local groups (with sanitised names).
All the ones with just id's are from LDAP (active directory).
Logs below....
So when I try and log in, this is where it does an ldap search to see what groups I'm
in, this seems to work:
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_initgr_rfc2307bis_send] (6):
Looking up parent groups for user
[CN=U999999,OU=MyOU,OU=Users,OU=Accounts,DC=xxx,DC=xxx,DC=xxx]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (6): calling
ldap_search_ext with
[(&(msSFU30PosixMember=CN=U999999,OU=MyOU,OU=Users,OU=Accounts,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*))][ou=GroupOU,ou=Right
Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx].
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [objectClass]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [cn]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [userPassword]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [gidNumber]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [msSFU30PosixMember]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [nsUniqueId]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [modifyTimestamp]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [uSNChanged]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (8):
ldap_search_ext called, msgid = 7
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfd9e50], ldap[0xfac610]
(Thu Oct 27 10:17:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
ldap_result found nothing!
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfd9e50], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_parse_entry] (9): OriginalDN:
[CN=group1,OU=GroupOU,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfd9e50], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_parse_entry] (9): OriginalDN:
[CN=group2,OU=GroupOU,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfd9e50], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_parse_entry] (9): OriginalDN:
[CN=group3,OU=GroupOU,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfd9e50], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_parse_entry] (9): OriginalDN:
[CN=group4,OU=GroupOU,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx].
Then it looks up what groups my groups are members of, I assume this is to resolve
"groups within groups" which is cool but we purposely flattened all our groups
(in an attempt) to make unix -> LDAP authentication faster. So all these queries
return nothing.
On a side note: If there's a way to turn off this "Looking up parent groups for
group" processing I'd love to know how. :)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_step] (6):
Looking up parent groups for group [CN=group5,OU=GroupOU,OU=Right
Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (6): calling
ldap_search_ext with [(&(msSFU30PosixMember=CN=group5,OU=GroupOU,OU=Right
Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*))][ou=GroupOU,ou=Right
Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [objectClass]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [cn]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [userPassword]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [gidNumber]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [msSFU30PosixMember]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [nsUniqueId]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [modifyTimestamp]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [uSNChanged]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (8):
ldap_search_ext called, msgid = 106
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0x14fe6e0], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
ldap_result found nothing!
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0x14fe6e0], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (6): Search
result: Success(0), (null)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (7): Total
count [0]
Then it starts updating the cache I think (I'm winging it here):
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_get_direct_parents] (8):
searching sysdb with filter
[(&(objectClass=group)(member=name=idzrd,cn=groups,cn=XXX.XXX.XXX,cn=sysdb))]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x1586190
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x1588660
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x1588660 "ltdb_timeout"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x1586190 "ltdb_callback"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_get_direct_parents] (7): idzrd
is a member of 0 sysdb groups
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_get_direct_parents] (8):
searching sysdb with filter
[(&(objectClass=group)(member=name=pc4rd,cn=groups,cn=XXX.XXX.XXX,cn=sysdb))]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x1587dc0
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x1588660
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x1588660 "ltdb_timeout"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x1587dc0 "ltdb_callback"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_get_direct_parents] (7): pc4rd
is a member of 0 sysdb groups
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 1)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 2)
...now below here it says "initgroups done". But it then does more searches, I
assume it's enumerating the groups now:
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x157cee0 "ltdb_timeout"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x1501710 "ltdb_callback"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x1581f10 "ltdb_timeout"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x15b3780 "ltdb_callback"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 3)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 1)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 0)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_initgr_done] (9):
Initgroups done
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_id_op_connect_step] (9):
reusing cached connection
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_id_op_destroy] (9): releasing
operation connection
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_id_op_done] (9): releasing
operation connection
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [acctinfo_callback] (4): Request
processed. Returned 0,0,Success
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[(nil)], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
ldap_result found nothing!
(Thu Oct 27 10:17:14 2011) [sssd[nss]] [sss_dp_get_reply] (4): Got reply (0, 0, Success)
from Data Provider
(Thu Oct 27 10:17:14 2011) [sssd[nss]] [nss_cmd_initgroups_search] (4): Requesting info
for [user6(a)XXX.XXX.XXX]
(Thu Oct 27 10:17:14 2011) [sssd[nss]] [nss_cmd_initgroups_search] (6): Initgroups for
[user6(a)XXX.XXX.XXX] completed
(Thu Oct 27 10:17:14 2011) [sssd[nss]] [nss_cmd_getgrgid_search] (4): Requesting info
for [9008(a)XXX.XXX.XXX]
(Thu Oct 27 10:17:14 2011) [sssd[nss]] [sss_dp_send_acct_req_create] (4): Sending
request for [XXX.XXX.XXX][4098][1][idnumber=9008]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sbus_dispatch] (9): dbus conn:
FA6BA0
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sbus_dispatch] (9): Dispatching.
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sbus_message_handler] (9): Received
SBUS method [getAccountInfo]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [be_get_account_info] (4): Got
request for [4098][1][idnumber=9008]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_id_op_connect_step] (9):
reusing cached connection
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (6): calling
ldap_search_ext with
[(&(gidNumber=9008)(objectclass=group)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][ou=GroupOU,ou=Right
Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [objectClass]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [cn]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [userPassword]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [gidNumber]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [msSFU30PosixMember]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [nsUniqueId]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [modifyTimestamp]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (7):
Requesting attrs: [uSNChanged]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_step] (8):
ldap_search_ext called, msgid = 160
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfaa950], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_parse_entry] (9): OriginalDN:
[CN=group6,OU=GroupOU,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx].
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_process_result] (8): Trace:
sh[0xfabf20], connected[1], ops[0xfaa950], ldap[0xfac610]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (6): Search
result: Success(0), (null)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (7): Total
count [0]
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_groups_process] (6): Search
for groups, returned 1 results.
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Search
users with filter: (&(objectclass=user)(originalDN=CN=user1,OU=Admin
Accounts,OU=Accounts,DC=xxx,DC=xxx,DC=xxx))
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x14fe540
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x14ff240
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x14ff240 "ltdb_timeout"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x14fe540 "ltdb_callback"
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Search
groups with filter: (&(objectclass=group)(originalDN=CN=user1,OU=Admin
Accounts,OU=Accounts,DC=xxx,DC=xxx,DC=xxx))
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x14fe540
(Thu Oct 27 10:17:14 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0xfd9210
...and then the users:
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_users] (9): User 73
processed!
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (9): Save user
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (7): Adding original
DN [CN=user3,OU=Admin Accounts,OU=Accounts,DC=xxx,DC=xxx,DC=xxx] to attributes of
[a319064].
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (7): Adding original
memberOf attributes to [a319064].
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (7): User principal
is not available for [a319064].
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (9): Adding
[adAccountExpires]=[9223372036854775807] to user attributes.
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (9): Adding
[adUserAccountControl]=[512] to user attributes.
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (6): Storing info
for user a319064
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 1)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x16fc1f0
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x16fc2a0
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x16fc2a0 "ltdb_timeout"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x16fc1f0 "ltdb_callback"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x16fc1f0
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x16fc2a0
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x16fc2a0 "ltdb_timeout"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x16fc1f0 "ltdb_callback"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 3)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x1706170
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x1706290
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x1706290 "ltdb_timeout"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x1706170 "ltdb_callback"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 3)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): start ldb transaction
(nesting: 3)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_callback": 0x1708ad0
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Added timed event
"ltdb_timeout": 0x1708b80
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Destroying timer
event 0x1708b80 "ltdb_timeout"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): tevent: Ending timer event
0x1708ad0 "ltdb_callback"
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 3)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 2)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [ldb] (9): commit ldb transaction
(nesting: 1)
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_users] (9): User 74
processed!
(Thu Oct 27 10:17:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_user] (9): Save user
It does a lot of user processing here. Many many sdap_fill_memberships, so it's
definately accessing LDAP OK and populating the cache.
If there are more logs that would be of use please let me know.
One thing that's also concerning is I get "no such file or directory" errors
a lot in the debug output:
[root@jbsrd999586 ~]# grep 'such file or dir' /tmp/tim | tail -40
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:44 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_users] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Error: 2
(No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_name] (6):
Error: 2 (No such file or directory)
(Thu Oct 27 10:17:45 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_user_by_uid] (6):
Error: 2 (No such file or directory)
Not sure what this means though.
If I can provide any more logs (or more specific parts) please let me know.
Best regards,
Tim.
This e-mail is sent by Suncorp Group Limited ABN 66 145 290 124 or one of its related
entities "Suncorp".
Suncorp may be contacted at Level 18, 36 Wickham Terrace, Brisbane or on 13 11 55 or at
suncorp.com.au.
The content of this e-mail is the view of the sender or stated author and does not
necessarily reflect the view of Suncorp. The content, including attachments, is a
confidential communication between Suncorp and the intended recipient. If you are not the
intended recipient, any use, interference with, disclosure or copying of this e-mail,
including attachments, is unauthorised and expressly prohibited. If you have received this
e-mail in error please contact the sender immediately and delete the e-mail and any
attachments from your system.