On Thu, Apr 23, 2015 at 02:40:38PM +0000, Sterling Sahaydak wrote:
> 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.sahay...@pi-coral.com>
> To: "Sumit Bose" <sb...@redhat.com>; "Development of the System Security
> Services Daemon" <sssd-devel@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?
level 9 is ok (it is actually the highest I just find it easier to say
10 :-)
> >
> >As to the SID, a quick log snippet:
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 [abr...@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: abr...@example.net
> >objectCategory:
> >CN=Person,CN=Schema,CN=Configuration,DC=ad,DC=example,DC=com
> >dSCorePropagationData: 16010101000000.0Z
> >lastLogonTimestamp: 130741912484110710
> >uid: abrown
> >mail: abr...@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" <sb...@redhat.com>
> >To: "Sterling Sahaydak" <sterling.sahay...@example.com>; "Development of
> >the System Security Services Daemon" <sssd-devel@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@lists.fedorahosted.org
> >>> https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
> >>
>
_______________________________________________
sssd-devel mailing list
sssd-devel@lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
