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?
The backtrace show that the crash happens during group processing. You
should look in the logs for "Group #%d [%s][%s] is not cached, need to
add a fake entry" messages, or just send the complete logs.
bye,
Sumit
>
>...
>(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
>>