Univention Bugzilla – Bug 34829
msgpo.schema registration failed during install
Last modified: 2014-06-02 08:45:31 CEST
During the installation tests for UCS-3.2-2 it happened once (of 1297+ installations) that the schema registration of "msgpo.schema" failed: $ less /var/log/univention/join.log Configure 97univention-s4-connector.inst Create connector/s4/ldap/host Create connector/s4/ldap/base Not updating connector/s4/ldap/ssl Create connector/s4/mapping/group/language Create connector/s4/ldap/protocol Create connector/s4/ldap/socket Object created: cn=gPLink,cn=custom attributes,cn=univention,dc=phahn,dc=qa Object exists: cn=Builtin,dc=phahn,dc=qa Object created: cn=System,dc=phahn,dc=qa Object created: cn=Policies,cn=System,dc=phahn,dc=qa Object created: ou=Domain Controllers,dc=phahn,dc=qa Object created: cn=WMIPolicy,cn=System,dc=phahn,dc=qa Object created: cn=SOM,cn=WMIPolicy,cn=System,dc=phahn,dc=qa Object exists: cn=ldapschema,cn=univention,dc=phahn,dc=qa Object exists: cn=udm_module,cn=univention,dc=phahn,dc=qa Object created: cn=msgpo,cn=ldapschema,cn=univention,dc=phahn,dc=qa Object created: cn=mswmi,cn=ldapschema,cn=univention,dc=phahn,dc=qa Object created: cn=container/msgpo,cn=udm_module,cn=univention,dc=phahn,dc=qa Waiting for activation of the extension object msgpo:............ERROR: Master did not mark the extension object act ERROR ucs_registerLDAPExtension: registraton of /usr/share/univention-s4-connector/ldap/msgpo.schema failed. This VM was deliberately configured with a broken network configuration (gateway pointed to a not existing host).
Looking at "slapcat" the schema is marked as active: $ slapcat | less dn: cn=msgpo,cn=ldapschema,cn=univention,dc=phahn,dc=qa univentionLDAPSchemaActive: TRUE entryCSN: 20140513204711.957853Z#000000#000#000000 modifyTimestamp: 20140513204711Z $ less /var/log/univention/listener.log 13.05.14 16:39:31.748 LISTENER ( PROCESS ) : ldap_extension: Reloading LDAP server. Initiating graceful reload of ldap server(s). ... 13.05.14 16:44:28.785 LISTENER ( PROCESS ) : ldap_extension: Reloading LDAP server. Initiating graceful reload of ldap server(s). # grep slapd /var/log/syslog | cut -c 8-13,20-$COLUMNS 20:14:32 slapd[8732]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/temp 20:14:32 slapd[8733]: slapd starting 20:20:32 slapd[8733]: daemon: shutdown requested and initiated. 20:20:32 slapd[8733]: slapd shutdown: waiting for 0 operations/tasks to finish 20:20:32 slapd[8733]: slapd stopped. 20:20:32 slapd[13335]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/tem 20:20:32 slapd[13336]: slapd starting 20:20:32 logger: /etc/init.d/slapd stop (pid: 13544, ppid:13346 univention-ldap) 20:20:32 slapd[13336]: daemon: shutdown requested and initiated. 20:20:32 slapd[13336]: slapd shutdown: waiting for 0 operations/tasks to finish 20:20:32 slapd[13336]: slapd stopped. 20:20:32 logger: /etc/init.d/slapd start (pid: 13568, ppid:13346 univention-ldap) 20:20:32 slapd db4.8_stat: command failed (1): 20:20:32 slapd db4.8_stat: db4.8_stat: DB_ENV->open: /var/lib/univention-ldap/ldap: No such file or dir 20:20:32 slapd[13591]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/tem 20:20:32 slapd[13592]: slapd starting 20:24:32 logger: /etc/init.d/slapd crestart (pid: 20888, ppid:20872 invoke-rc.d) 20:24:32 logger: /etc/init.d/slapd restart (pid: 20895, ppid:20888 slapd) 20:24:32 logger: /etc/init.d/slapd stop (pid: 20901, ppid:20895 slapd) 20:24:32 slapd[13592]: daemon: shutdown requested and initiated. 20:24:32 slapd[13592]: slapd shutdown: waiting for 0 operations/tasks to finish 20:24:32 slapd[13592]: slapd stopped. 20:24:32 logger: /etc/init.d/slapd start (pid: 20911, ppid:20895 slapd) 20:24:32 slapd db4.8_stat: command failed (1): 20:24:32 slapd db4.8_stat: db4.8_stat: DB_ENV->open: /var/lib/univention-ldap/ldap: No such file or dir 20:24:32 slapd[20934]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/tem 20:24:32 slapd[20935]: slapd starting 20:37:32 logger: /etc/init.d/slapd start (pid: 6927, ppid: 6911 invoke-rc.d) 20:37:32 slapd[6955]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/temp 20:39:32 logger: /etc/init.d/slapd graceful-restart (pid: 8562, ppid: 7501 univention-dire) 20:39:32 logger: /etc/init.d/slapd graceful-stop (pid: 8569, ppid: 8562 slapd) 20:39:32 logger: /etc/init.d/slapd start (pid: 8579, ppid: 8562 slapd) 20:39:32 slapd[8607]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/temp 20:42:32 logger: /etc/init.d/slapd restart (pid: 10799, ppid:10475 setup-s4.sh) 20:42:32 logger: /etc/init.d/slapd stop (pid: 10806, ppid:10799 slapd) 20:42:32 logger: /etc/init.d/slapd start (pid: 10816, ppid:10799 slapd) 20:42:32 slapd[10844]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/tem 20:44:32 logger: /etc/init.d/slapd graceful-restart (pid: 11743, ppid:10865 univention-dire) 20:44:32 logger: /etc/init.d/slapd graceful-stop (pid: 11752, ppid:11743 slapd) 20:44:32 logger: /etc/init.d/slapd start (pid: 11779, ppid:11743 slapd) 20:44:32 slapd[11807]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladda:/var/build/tem 20:50:32 logger: /etc/init.d/slapd stop (pid: 19029, ppid:19013 invoke-rc.d)
Happened again during installation of a UCS-3.2-*1* system; probably caused by the init scripts of OpenLDPAP failing to kill the previous slapd process (see Bug #34440 which already improved this for UCS-3.2-*2*) $ less /var/log/univention/listener.log Traceback (most recent call last): File "/usr/lib/univention-directory-listener/system/ldap_extension.py", line 94, in postrun handler_object.mark_active() File "/usr/lib/pymodules/python2.6/univention/lib/ldap_extension.py", line 303, in mark_active lo, ldap_position = udm_uldap.getAdminConnection() File "/usr/lib/pymodules/python2.6/univention/admin/uldap.py", line 70, in getAdminConnection lo=univention.uldap.getAdminConnection(start_tls, decode_ignorelist=decode_ignorelist) File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 73, in getAdminConnection lo=access(host=ucr['ldap/master'], port=port, base=ucr['ldap/base'], binddn='cn=admin,'+ucr['lda p/base'], bindpw=bindpw, start_tls=start_tls, decode_ignorelist=decode_ignorelist) File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 182, in __init__ self.__open(ca_certfile) File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 227, in __open self.lo.simple_bind_s(self.binddn, self.__encode_pwd(self.bindpw)) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 781, in simple_bind_s return SimpleLDAPObject.simple_bind_s(self,*args,**kwargs) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 207, in simple_bind_s return self.result(msgid,all=1,timeout=self.timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 422, in result res_type,res_data,res_msgid = self.result2(msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 426, in result2 res_type, res_data, res_msgid, srv_ctrls = self.result3(msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 432, in result3 ldap_result = self._ldap_call(self._l.result3,msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 96, in _ldap_call result = func(*args,**kwargs) ldap.OTHER: {'info': 'internal error', 'desc': 'Other (e.g., implementation specific) error'} $ less /var/log/univention/join.log Waiting for activation of the extension object msgpo:............................................... ERROR ucs_registerLDAPExtension: registraton of /usr/share/univention-s4-connector/ldap/msgpo.schema faile Configure 98univention-pkgdb-tools.inst Cannot find service-record of _pkgdb._tcp. No DB-Server-Name found. Configure 98univention-samba4-dns.inst Waiting for RID Pool replication: done. User 'dns-master' created successfully Expiry for user 'dns-master' disabled. Modified 1 records successfully Added 1 records successfully Traceback (most recent call last): File "/usr/lib/univention-pam/ldap-group-to-file.py", line 109, in <module> lo = univention.uldap.getMachineConnection( ldap_master=False ) File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 109, in getMachineConnection lo=access(host=ucr['ldap/server/name'], port=port, base=ucr['ldap/base'], binddn=ucr['ldap/hostd File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 182, in __init__ self.__open(ca_certfile) File "/usr/lib/pymodules/python2.6/univention/uldap.py", line 227, in __open self.lo.simple_bind_s(self.binddn, self.__encode_pwd(self.bindpw)) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 781, in simple_bind_s return SimpleLDAPObject.simple_bind_s(self,*args,**kwargs) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 207, in simple_bind_s return self.result(msgid,all=1,timeout=self.timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 422, in result res_type,res_data,res_msgid = self.result2(msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 426, in result2 res_type, res_data, res_msgid, srv_ctrls = self.result3(msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 432, in result3 ldap_result = self._ldap_call(self._l.result3,msgid,all,timeout) File "/usr/lib/python2.6/dist-packages/ldap/ldapobject.py", line 96, in _ldap_call result = func(*args,**kwargs) ldap.OTHER: {'info': 'internal error', 'desc': 'Other (e.g., implementation specific) error'} # grep slapd /var/log/syslog | cut -c 8-16,24-$COLUMNS 12:50:35 slapd[7507]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladd 12:50:35 slapd[7508]: slapd starting 12:51:08 slapd[7508]: daemon: shutdown requested and initiated. 12:51:08 slapd[7508]: slapd shutdown: waiting for 0 operations/tasks to finish 12:51:08 slapd[7508]: slapd stopped. 12:51:08 slapd[11913]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@lad 12:51:08 slapd[11914]: slapd starting 12:52:14 slapd[11914]: daemon: shutdown requested and initiated. 12:52:14 slapd[11914]: slapd shutdown: waiting for 0 operations/tasks to finish 12:52:14 slapd[11914]: slapd stopped. 12:52:15 slapd[23746]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@lad 12:52:15 slapd[23747]: slapd starting 12:54:55 slapd[23747]: daemon: shutdown requested and initiated. 12:54:55 slapd[23747]: slapd shutdown: waiting for 0 operations/tasks to finish 12:54:55 slapd[23747]: slapd stopped. 12:54:56 slapd[6796]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladd 12:56:24 slapd[8423]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@ladd 12:57:49 slapd[11012]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@lad 12:57:49 slapd[11024]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@lad 12:59:01 slapd[12217]: @(#) $OpenLDAP: slapd (Oct 2 2013 17:48:42) $#012#011root@lad 12:59:01 slapd[12217]: daemon: bind(8) failed errno=98 (Address already in use) 12:59:01 slapd[12217]: daemon: bind(8) failed errno=98 (Address already in use) 12:59:01 slapd[12217]: slapd stopped. 12:59:01 slapd[12217]: connections_destroy: nothing to destroy. # univention-ldapsearch "internal error" # slapcat | grep msgpo | less univentionLDAPSchemaActive: FALSE # /etc/init.d/slapd stop "failed; slapd was still running" # pkill slapd ; /etc/init.d/slapd start ; univention-ldapsearch "works again"
I think it does not happen with the 3.2-2 release dvd. If it does, please re-open with logfiles.