Sumit,
Apologize, forgot to include the additional check requested in gdb:
(gdb) print i
$1 = <value optimized out>
(gdb) print dom_sid
$2 = (struct sss_dom_sid *) 0x10b4300
(gdb) print dom_sid -> sub_auths
$3 = {2927152313, 560816471, 256, 0, 113, 0, 0, 0, 0, 0, 17404592, 0,
17409264, 0, 0}
As requested...
(gdb) print dom_sid -> num_auths
$4 = -78 '\262'
------ Original Message ------
From: "Sterling Sahaydak" <sterling.sahaydak(a)pi-coral.com>
To: "Sumit Bose" <sbose(a)redhat.com>; "Development of the System
Security
Services Daemon" <sssd-devel(a)lists.fedorahosted.org>
Sent: 4/23/2015 10:13:27 AM
Subject: Re[2]: [SSSD] Segmentation fault in 1.11.6 - error 6 in
libsss_idmap.so.0.4.0
Thanks Sumit!
Quick question, if I'm running sssd 1.11.6 can I use debug_level = 10?
Currently running at 9 and changed one of my sssd.conf to 10, but
didn't see any change in the log reporting?
As to the SID, a quick log snippet:
...
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]]
[sdap_ldap_connect_callback_del] (0x4000): Closing LDAP connection with
fd [20].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]]
[sdap_ldap_connect_callback_del] (0x4000): Closing LDAP connection with
fd [19].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_done]
(0x0400): Search result: Success(0), no errmsg set
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_search_user_process]
(0x0400): Search for users, returned 1 results.
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_search_user_process]
(0x4000): Retrieved total 1 users
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb
transaction (nesting: 0)
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Save user
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
SID S-1-5-21-2899899129-3095396270-1135405818-1638 does not belong to
any known domain
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_get_primary_name]
(0x0400): Processing object abrown
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Processing user abrown
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x2000):
Adding originalDN
[CN=abrown,OU=Users,OU=example,DC=ad,DC=example,DC=com] to attributes
of [abr
own].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Adding original memberOf attributes to [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original mod-Timestamp [20150422203946.0Z] to
attributes of [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Adding user principal [abrown(a)pcoral.net] to attributes of [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowLastChange is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMin is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMax is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowWarning is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowInactive is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowExpire is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowFlag is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): krbLastPwdChange is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): krbPasswordExpiration is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): pwdAttribute is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedService is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding adAccountExpires [9223372036854775807] to attributes
of [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding adUserAccountControl [512] to attributes of [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): nsAccountLock is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedHost is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginDisabled is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginExpirationTime is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginAllowedTimeMap is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr]
(0x2000): sshPublicKey is not available for [abrown].
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [sdap_save_user] (0x0400):
Storing info for user abrown
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb
transaction (nesting: 1)
(Thu Apr 23 09:51:02 2015) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed
event "ltdb_callback": 0x20c6180
...
*** The Line: "SID S-1-5-21-2899899129-3095396270-1135405818-1638 does
not belong to any known domain"
I'm seeing this on both server sssd log files. They have the same
value, but not sure why this is?
Wondering if it is the ldap server is in sub-domain "va.example.com"
and the Active Directory server is in sub-domain "ad.example.com" ?
I checked this value in Active Directory and did a quick ldapsearch
retrieving the Users info:
ldapsearch -D
"cn=adproxy,ou=serviceaccounts,ou=example,dc=ad,dc=example,dc=com" -W
-b "DC=ad,DC=example,DC=com" -h
ad-va.va.example.com
'(ObjectSid=S-1-5-21-2899899129-3095396270-1135405818-1638)'
# extended LDIF
#
# LDAPv3
# base <DC=ad,DC=example,DC=com> with scope subtree
# filter: (ObjectSid=S-1-5-21-2899899129-3095396270-1135405818-1638)
# requesting: ALL
#
# abrown, Users, example,
ad.example.com
dn: CN=abrown,OU=Users,OU=example,DC=ad,DC=example,DC=com
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: user
cn: abrown
sn: Brown
givenName: Angelica
distinguishedName:
CN=abrown,OU=Users,OU=example,DC=ad,DC=example,DC=com
instanceType: 4
whenCreated: 20150318214951.0Z
whenChanged: 20150422203946.0Z
displayName: Angelica Brown
uSNCreated: 29756
memberOf: CN=allowedusers,OU=Groups,OU=example,DC=ad,DC=example,DC=com
memberOf: CN=testgroup,OU=Groups,OU=example,DC=ad,DC=example,DC=com
uSNChanged: 109233
name: abrown
objectGUID:: +LIjLa23JkiBKdDaPQDctQ==
userAccountControl: 512
badPwdCount: 0
codePage: 0
countryCode: 0
homeDirectory: /home/users/abrown
badPasswordTime: 130736699841636452
lastLogoff: 0
lastLogon: 130736701714137408
pwdLastSet: 130742087861075675
primaryGroupID: 513
objectSid:: AQUAAAAAAAUVAAAA+fLYrK7/f7j66qxDZgYAAA==
accountExpires: 9223372036854775807
logonCount: 0
sAMAccountName: abrown
sAMAccountType: 805306368
userPrincipalName: abrown(a)example.net
objectCategory:
CN=Person,CN=Schema,CN=Configuration,DC=ad,DC=example,DC=com
dSCorePropagationData: 16010101000000.0Z
lastLogonTimestamp: 130741912484110710
uid: abrown
mail: abrown(a)pcoral.net
uidNumber: 2000
gidNumber: 1500
loginShell: /bin/bash
# search reference
ref:
ldap://DomainDnsZones.ad.example.com/DC=DomainDnsZones,DC=ad,DC=example
,DC=com
# search reference
ref:
ldap://ForestDnsZones.ad.example.com/DC=ForestDnsZones,DC=ad,DC=example
,DC=com
# search reference
ref:
ldap://ad.example.com/CN=Configuration,DC=ad,DC=example,DC=com
# search result
search: 2
result: 0 Success
# numResponses: 5
# numEntries: 1
# numReferences: 3
------ Original Message ------
From: "Sumit Bose" <sbose(a)redhat.com>
To: "Sterling Sahaydak" <sterling.sahaydak(a)example.com>; "Development
of the System Security Services Daemon"
<sssd-devel(a)lists.fedorahosted.org>
Sent: 4/23/2015 3:45:09 AM
Subject: Re: [SSSD] Segmentation fault in 1.11.6 - error 6 in
libsss_idmap.so.0.4.0
>On Wed, Apr 22, 2015 at 09:08:33PM +0000, Sterling Sahaydak wrote:
>> Consistently getting a segfault in libsss_idmap resulting in a core
>>dump in
>> sssd 1.11.6
>>
>>
>> :Apr 22 13:25:50 ldap kernel: sssd_be[9236]: segfault at 10da000 ip
>>000=
>> 07f785852b4f1 sp 00007fffbfbf6cf0 error 6 in
>>libsss_idmap.so.0.4.0[7f78=
>> 58528000+5000]
>> :Apr 22 13:25:50 ldap abrt[9244]: Saved core dump of pid 9236
>>(/usr/lib=
>> exec/sssd/sssd_be) to /var/spool/abrt/ccpp-2015-04-22-13:25:50-9236
>>(27=
>> 68896 bytes)
>>
>> Taking a look at it deeper in gdb revealing:
>>
>>
>> Loaded symbols for /lib64/libnss_dns-2.12.so
>> Core was generated by `/usr/libexec/sssd/sssd_be --domain LDAP'.
>> Program terminated with signal 11, Segmentation fault.
>> #0 sss_idmap_bin_sid_to_dom_sid (ctx=<value optimized out>,
>>bin_sid=<value
>> optimized out>, length=<value optimized out>,
>>_dom_sid=0x7fffbfbf6d38) at
>> src/lib/idmap/sss_id
>> map_conv.c:92
>> 92 dom_sid->sub_auths[i] = le32toh(val);
>> Missing separate debuginfos, use: debuginfo-install
>> dbus-libs-1.2.24-8.el6_6.x86_64 popt-1.13-7.el6.x86_64
>> sqlite-3.6.20-1.el6.x86_64
>> (gdb) where
>> #0 sss_idmap_bin_sid_to_dom_sid (ctx=<value optimized out>,
>>bin_sid=<value
>> optimized out>, length=<value optimized out>,
>>_dom_sid=0x7fffbfbf6d38) at
>> src/lib/idmap/sss_id
>> map_conv.c:92
>> #1 0x00007f785852b648 in sss_idmap_bin_sid_to_sid (ctx=0xf84520,
>> bin_sid=<value optimized out>, length=<value optimized out>,
>> _sid=0x7fffbfbf6d60) at src/lib/idmap/sss_i
>> dmap_conv.c:371
>> #2 0x00007f7858745ded in sdap_attrs_get_sid_str (mem_ctx=0x105fc10,
>> idmap_ctx=0xf811e0, sysdb_attrs=<value optimized out>,
>> sid_attr=0x7f7858783789 "objectSID", _sid_str=
>> 0x7fffbfbf6e28) at src/providers/ldap/ldap_common.c:1857
>> #3 0x00007f785875e509 in sdap_add_incomplete_groups
>>(sysdb=0xf63080,
>> domain=0xf63780, opts=0xf7eec0, groupnames=<value optimized out>,
>> ldap_groups=0x10b52b0, ldap_groups
>> _count=9) at src/providers/ldap/sdap_async_initgroups.c:131
>> #4 0x00007f785875ea1b in sdap_nested_groups_store (sysdb=0xf63080,
>> domain=0xf63780, opts=0xf7eec0, groups=0x10b52b0, count=9) at
>> src/providers/ldap/sdap_async_initgroups
>> .c:617
>> #5 0x00007f7858763095 in save_rfc2307bis_groups (subreq=0x0) at
>> src/providers/ldap/sdap_async_initgroups.c:1878
>> #6 sdap_initgr_rfc2307bis_done (subreq=0x0) at
>> src/providers/ldap/sdap_async_initgroups.c:1783
>> #7 0x00007f785876275a in rfc2307bis_nested_groups_process
>>(subreq=0x0) at
>> src/providers/ldap/sdap_async_initgroups.c:2554
>> #8 0x00007f785874f90f in sdap_get_generic_ext_done (op=<value
>>optimized
>> out>, reply=<value optimized out>, error=<value optimized out>,
>>pvt=<value
>> optimized out>) at src
>> /providers/ldap/sdap_async.c:1439
>> #9 0x00007f7858751e2a in sdap_process_message (ev=<value optimized
>>out>,
>> pvt=<value optimized out>) at src/providers/ldap/sdap_async.c:374
>> #10 sdap_process_result (ev=<value optimized out>, pvt=<value
>>optimized
>> out>) at src/providers/ldap/sdap_async.c:213
>> #11 0x00000039dda08ebe in epoll_event_loop (ev=<value optimized
>>out>,
>> location=<value optimized out>) at ../tevent_epoll.c:736
>> #12 epoll_event_loop_once (ev=<value optimized out>, location=<value
>> optimized out>) at ../tevent_epoll.c:931
>> #13 0x00000039dda072e6 in std_event_loop_once (ev=0xf5b580,
>> location=0x39dea3d4f5 "src/util/server.c:602") at
>>../tevent_standard.c:112
>> #14 0x00000039dda0349d in _tevent_loop_once (ev=0xf5b580,
>> location=0x39dea3d4f5 "src/util/server.c:602") at ../tevent.c:530
>> #15 0x00000039dda0351b in tevent_common_loop_wait (ev=0xf5b580,
>> location=0x39dea3d4f5 "src/util/server.c:602") at ../tevent.c:634
>> #16 0x00000039dda07256 in std_event_loop_wait (ev=0xf5b580,
>> location=0x39dea3d4f5 "src/util/server.c:602") at
>>../tevent_standard.c:138
>> #17 0x00000039dea2b963 in server_loop (main_ctx=0xf5c880) at
>> src/util/server.c:602
>> #18 0x000000000040a286 in main (argc=3, argv=<value optimized out>)
>>at
>> src/providers/data_provider_be.c:2856
>> (gdb) print i
>> $1 = <value optimized out>
>> (gdb) print val
>> $2 = 0
>> (gdb) print dom_sid
>> $3 = (struct sss_dom_sid *) 0x10b4300
>> (gdb) print dom_sid->sub_auths
>> $4 = {2927152313, 560816471, 256, 0, 113, 0, 0, 0, 0, 0, 17404592,
>>0,
>> 17409264, 0, 0}
>> (gdb) quit
>>
>> Above, you can see that "<value optimized out>" so not sure what
I
>>can
>> conclude from this futher.
>>
>> This is a mirrored site being replicated that I have the same
>>configuration
>> files setup on another sub domain.
>> I've recently run 'yum update' to verify and still end up with the
>>same
>> segmentation fault.
>>
>> I'm running the command 'getent passwd <username>' and
noticing this
>>is
>> occurring when running in "/usr/sbin/sssd -i" mode.
>>
>> Environment: CentOS => OpenLDAP 2.4.39 with OpenLDAP Proxy =>
>>Active
>> Directory 2012 containing Users
>>
>> Running the cmd: 'getent passwd <username>' is retrieving the
>>correct user
>> information along with groups, etc.
>>
>>
>> I presume it's this: dom_sid->sub_auths[i] = le32toh(val);
>>
>> Where "i" is out of bounds or "val" is not being checked
properly or
>>???
>
>yes, maybe i is out of bounds, but this most probably means that they
>given binary SID is invalid. Can you check the value of
>'dom_sid->num_auths'? Additionally it would be nice to see the binary
>SID. If gdb does not help you here please send logs with debug_level
>10
>which might help to identify the object using this SID.
>
>bye,
>Sumit
>
>>
>>
>>
>> Please let me know what other information is needed to assist,
>>before just
>> dumping sssd.conf, nsswitch.conf, etc.
>>
>>
>> Any help is greatly appreciated,
>>
>> Sterling
>
>> _______________________________________________
>> sssd-devel mailing list
>> sssd-devel(a)lists.fedorahosted.org
>>
https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
>