Bug 1498773

Part of ipa

2017-10-04T20:45:31Z DEBUG   [40/45]: configuring Posix uid/gid generation
2017-10-04T20:45:31Z DEBUG Starting external process
2017-10-04T20:45:31Z DEBUG args=/usr/bin/ldapmodify -v -f /tmp/tmpSzZXI_ -H ldapi://%2fvar%2frun%2fslapd-TESTRELM-TEST.socket -Y EXTERNAL
2017-10-04T20:45:31Z DEBUG Process finished, return code=255
2017-10-04T20:45:31Z DEBUG stdout=add objectclass:
        top
        extensibleObject
add cn:
        Posix IDs
add dnaType:
        uidNumber
        gidNumber
add dnaNextValue:
        1861400000
add dnaMaxValue:
        1861599999
add dnaMagicRegen:
        -1
add dnaFilter:
        (|(objectClass=posixAccount)(objectClass=posixGroup)(objectClass=ipaIDobject))
add dnaScope:
        dc=testrelm,dc=test
add dnaThreshold:
        500
add dnaSharedCfgDN:
        cn=posix-ids,cn=dna,cn=ipa,cn=etc,dc=testrelm,dc=test
add dnaExcludeScope:
        cn=provisioning,dc=testrelm,dc=test
adding new entry "cn=Posix IDs,cn=Distributed Numeric Assignment Plugin,cn=plugins,cn=config"
modify complete

replace nsslapd-pluginEnabled:
        on
modifying entry "cn=Distributed Numeric Assignment Plugin,cn=plugins,cn=config"


2017-10-04T20:45:31Z DEBUG stderr=ldap_initialize( ldapi://%2Fvar%2Frun%2Fslapd-TESTRELM-TEST.socket/??base )
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
ldap_result: Can't contact LDAP server (-1)
2017-10-04T20:45:31Z CRITICAL Failed to load dna.ldif: Command '/usr/bin/ldapmodify -v -f /tmp/tmpSzZXI_ -H ldapi://%2fvar%2frun%2fslapd-TESTRELM-TEST.socket -Y EXTERNAL' returned non-zero exit status 255
2017-10-04T20:45:31Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 504, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 494, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 704, in __config_uidgid_gen
    self._ldap_mod("dna.ldif", self.sub_dict)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 308, in _ldap_mod
    ipautil.run(args, nolog=nologlist)
  File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 511, in run
    raise CalledProcessError(p.returncode, arg_string, str(output))
CalledProcessError: Command '/usr/bin/ldapmodify -v -f /tmp/tmpSzZXI_ -H ldapi://%2fvar%2frun%2fslapd-TESTRELM-TEST.socket -Y EXTERNAL' returned non-zero exit status 255

2017-10-04T20:45:31Z DEBUG   [error] CalledProcessError: Command '/usr/bin/ldapmodify -v -f /tmp/tmpSzZXI_ -H ldapi://%2fvar%2frun%2fslapd-TESTRELM-TEST.socket -Y EXTERNAL' returned non-zero exit status 255

Debug details:


#
# the crash occurs while enabling DNA plugin, topology plugin catches the update
#
(gdb) where
#0  0x00007f411e5ee939 in __strcasecmp_l_sse2 () at ../sysdeps/x86_64/strcmp.S:212
#1  0x00007f41151e5761 in ipa_topo_check_segment_updates (pb=pb@entry=0x556e1722e0a0) at topology_pre.c:393
#2  0x00007f41151e5c78 in ipa_topo_pre_mod (pb=0x556e1722e0a0) at topology_pre.c:573
#3  0x00007f41216c1f74 in plugin_call_func (list=0x556e171ee100, operation=operation@entry=451, pb=pb@entry=0x556e1722e0a0, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
#4  0x00007f41216c2203 in plugin_call_list (pb=0x556e1722e0a0, operation=451, list=<optimized out>)
    at ldap/servers/slapd/plugin.c:1972
#5  0x00007f41216c2203 in plugin_call_plugins (pb=pb@entry=0x556e1722e0a0, whichfunction=whichfunction@entry=451)
    at ldap/servers/slapd/plugin.c:442
#6  0x00007f412167c00a in dse_modify (pb=0x556e1722e0a0) at ldap/servers/slapd/dse.c:1751
#7  0x00007f41216ae456 in op_shared_modify (pb=pb@entry=0x556e1722e0a0, pw_change=pw_change@entry=0, old_pw=0x0)
    at ldap/servers/slapd/modify.c:1013
#8  0x00007f41216af8eb in do_modify (pb=pb@entry=0x556e1722e0a0) at ldap/servers/slapd/modify.c:383
#9  0x0000556e159e32b7 in connection_dispatch_operation (pb=0x556e1722e0a0, op=0x556e1732e000, conn=0x556e17d66050)
    at ldap/servers/slapd/connection.c:624
#10 0x0000556e159e32b7 in connection_threadmain () at ldap/servers/slapd/connection.c:1761
#11 0x00007f411f60dc1b in _pt_root (arg=0x556e17d22900) at ../../../nspr/pr/src/pthreads/ptthread.c:216
#12 0x00007f411efade25 in start_thread (arg=0x7f40f7a4e700) at pthread_create.c:308
#13 0x00007f411e65c1ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113


#
# Topology plugin retrieves the SLAPI_PLUGIN_IDENTITY to be sure not
# process its own updates
#
# it uses 'pi' that is not initialized to retrieve SLAPI_PLUGIN_IDENTITY value
#
(gdb) frame 1
#1  0x00007f41151e5761 in ipa_topo_check_segment_updates (pb=pb@entry=0x556e1722e0a0) at topology_pre.c:393
393	    if (pi && 0 == strcasecmp(pi, ipa_topo_get_plugin_id())) {
(gdb) list 382,393
382	int
383	ipa_topo_check_segment_updates(Slapi_PBlock *pb)
384	{
385	    int rc = 0;
386	    Slapi_Entry *mod_entry;
387	    char *pi;
388	
389	    /* we have to check if the operation is triggered by the
390	     * topology plugin itself - allow it
391	     */
392	    slapi_pblock_get(pb, SLAPI_PLUGIN_IDENTITY,&pi);
393	    if (pi && 0 == strcasecmp(pi, ipa_topo_get_plugin_id())) {

#
# https://pagure.io/389-ds-base/issue/49097 split pblocks into
# several sub-structs
#
#  pb_intplugin that contains SLAPI_PLUGIN_IDENTITY is allocated
# on demand only if one of its fields is set.
#
# Here the field was not slapi-pblock-set before slapi-pblock-get
#
(gdb) print *pb
$25 = {pb_backend = 0x556e16fd7dc0, pb_conn = 0x556e17d66050, pb_op = 0x556e1732e000, pb_plugin = 0x556e171ee100, pb_dse = 0x0, 
  pb_task = 0x0, pb_mr = 0x0, pb_misc = 0x556e1801bf00, pb_intop = 0x556e16fd4ea0, pb_intplugin = 0x0, pb_deprecated = 0x0}


#
# slapi_pblock_get leaves the variable unchanged if the
# sub-struct that contains the requested field is not allocate
#
# the consequence is that 'pi' is keeping the value it got from the stack
(gdb) list slapi_pblock_get
353	#define SLAPI_PBLOCK_GET_PLUGIN_RELATED_POINTER(pb, element) \
354	    ((pb)->pb_plugin == NULL ? NULL : (pb)->pb_plugin->element)
355	
356	int
357	slapi_pblock_get(Slapi_PBlock *pblock, int arg, void *value)
358	{
359	
360	#ifdef PBLOCK_ANALYTICS
361	    pblock_analytics_record(pblock, arg);
362	#endif

(gdb) list 703
698	        }
699	        break;
700	    case SLAPI_PLUGIN_DESCRIPTION:
701	        (*(Slapi_PluginDesc *)value) = pblock->pb_plugin->plg_desc;
702	        break;
703	    case SLAPI_PLUGIN_IDENTITY:
704	        if (pblock->pb_intplugin != NULL) {
705	            (*(void **)value) = pblock->pb_intplugin->pb_plugin_identity;
706	        }
707	        break;


Before, pblock was a calloc struct. Get of a unset field always set the variable &pi.
So the API behavior changed.

Others plugins may hit that issue (accessing a field that has not been previously set). This is a 389-ds bug. slapi-pblock-get should always set the variable, even if the sub-struct is not allocated.

Upstream ticket https://pagure.io/389-ds-base/issue/49394

*** Bug 1499179 has been marked as a duplicate of this bug. ***

Upstream ticket is pushed -> POST

Build tested:
389-ds-base-1.3.7.5-10.el7.x86_64
ipa-server-4.5.4-4.el7.x86_64

I did ipa-server-install several times and didn't observe a crash.

Marking as VERIFIED, SanityOnly.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:0811