[Freeipa-users] krb5kdc service not starting

Thu May 12 08:45:08 UTC 2016

Trying to provide some additional information if it helps. Here's the
timeline of events from logs:

Some logs from the failure:

May 11 17:34:03 localhost ns-slapd: [11/May/2016:17:34:03 -0400] dse - The
configuration file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif was not
restored from backup /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif.tmp, error -1
May 11 17:34:03 localhost ns-slapd: [11/May/2016:17:34:03 -0400] dse - The
configuration file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif was not
restored from backup /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif.bak, error 0
May 11 17:34:03 localhost ns-slapd: [11/May/2016:17:34:03 -0400] startup -
The default password storage scheme SSHA could not be read or was not found
in the file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif. It is mandatory.
May 11 17:34:03 localhost systemd: dirsrv at DOMAINNAME-EDU.service: control
process exited, code=exited status=1
May 11 17:34:03 localhost systemd: Failed to start 389 Directory Server
DOMAINNAME-EDU..
May 11 17:34:03 localhost systemd: Unit dirsrv at DOMAINNAME-EDU.service
entered failed state.
May 11 17:34:03 localhost systemd: dirsrv at DOMAINNAME-EDU.service failed.
May 11 17:34:03 localhost ipactl: Job for dirsrv at DOMAINNAME-EDU.service
failed because the control process exited with error code. See "systemctl
status dirsrv at DOMAINNAME-EDU.service" and "journalctl -xe" for details.
May 11 17:34:04 localhost ipactl: Failed to start Directory Service:
Command ''/bin/systemctl' 'start' 'dirsrv at DOMAINNAME-EDU.service'' returned
non-zero exit status 1
May 11 17:34:04 localhost ipactl: Starting Directory Service
May 11 17:34:04 localhost systemd: ipa.service: main process exited,
code=exited, status=1/FAILURE
May 11 17:34:04 localhost systemd: Failed to start Identity, Policy, Audit.
May 11 17:34:04 localhost systemd: Unit ipa.service entered failed state.
May 11 17:34:04 localhost systemd: ipa.service failed.

May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] dse - The
configuration file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif was not
restored from backup /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif.tmp, error -1
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] dse - The
configuration file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif was not
restored from backup /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif.bak, error -1
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] config -
The given config file /etc/dirsrv/slapd-DOMAINNAME-EDU/dse.ldif could not
be accessed, Netscape Portable Runtime error -5950 (File not found.)
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] schema -
Could not add attribute type "objectClass" to the schema: attribute type
objectClass: Unknown attribute syntax OID "1.3.6.1.4.1.1466.115.121.1.15"
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] -
valueset_value_syntax_cmp: slapi_attr_values2keys_sv failed for type
attributetypes
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] -
valueset_value_syntax_cmp: slapi_attr_values2keys_sv failed for type
attributetypes
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] -
valueset_value_syntax_cmp: slapi_attr_values2keys_sv failed for type
attributetypes
May 11 19:33:15 localhost ns-slapd: [11/May/2016:19:33:15 -0400] -
valueset_value_syntax_cmp: slapi_attr_values2keys_sv failed for type
attributetypes
... lots of similar messages

11/May/2016:17:19:34 -0400] slapd_ldap_sasl_interactive_bind - Error: could
not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1 (Can't
contact LDAP server) ((null)) errno 111 (Connection refused)
[11/May/2016:17:19:34 -0400] slapi_ldap_bind - Error: could not perform
interactive bind for id [] authentication mechanism [GSSAPI]: error -1
(Can't contact LDAP server)
[11/May/2016:17:24:34 -0400] slapd_ldap_sasl_interactive_bind - Error:
could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1
(Can't contact LDAP server) ((null)) errno 111 (Connection refused)
[11/May/2016:17:24:34 -0400] slapi_ldap_bind - Error: could not perform
interactive bind for id [] authentication mechanism [GSSAPI]: error -1
(Can't contact LDAP server)
[11/May/2016:17:29:34 -0400] slapd_ldap_sasl_interactive_bind - Error:
could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1
(Can't contact LDAP server) ((null)) errno 111 (Connection refused)
[11/May/2016:17:29:34 -0400] slapi_ldap_bind - Error: could not perform
interactive bind for id [] authentication mechanism [GSSAPI]: error -1
(Can't contact LDAP server)
[11/May/2016:17:32:21 -0400] - slapd shutting down - signaling operation
threads - op stack size 17 max work q size 14 max work q stack size 14
[11/May/2016:17:32:21 -0400] - slapd shutting down - waiting for 28 threads
to terminate
[11/May/2016:17:32:21 -0400] - slapd shutting down - closing down internal
subsystems and plugins
[11/May/2016:17:32:24 -0400] nis-plugin - error sending request to portmap
or rpcbind on 6: Broken pipe
[11/May/2016:17:32:24 -0400] nis-plugin - retried sending request to
portmap or rpcbind on 11, and succeeded
[11/May/2016:17:32:24 -0400] nis-plugin - error sending request to portmap
or rpcbind on 11: Broken pipe
[11/May/2016:17:32:24 -0400] nis-plugin - retried sending request to
portmap or rpcbind on 6, and succeeded
[11/May/2016:17:32:24 -0400] nis-plugin - error sending request to portmap
or rpcbind on 6: Broken pipe
[11/May/2016:17:32:24 -0400] nis-plugin - retried sending request to
portmap or rpcbind on 11, and succeeded
[11/May/2016:17:32:24 -0400] nis-plugin - error sending request to portmap
or rpcbind on 11: Broken pipe
... lots of similar messages

Logs after trying the fix:

[11/May/2016:23:19:49 -0400] SSL Initialization - Configured SSL version
range: min: TLS1.0, max: TLS1.2
[11/May/2016:23:19:49 -0400] - 389-Directory/1.3.4.0 B2016.070.190 starting
up
[11/May/2016:23:19:49 -0400] - WARNING: changelog: entry cache size
2097152B is less than db size 13729792B; We recommend to increase the entry
cache size nsslapd-cachememsize.
[11/May/2016:23:19:49 -0400] - Detected Disorderly Shutdown last time
Directory Server was running, recovering database.
[11/May/2016:23:19:50 -0400] nis-plugin - warning: no entries in domain=
domainname.edu,map=netgroup
[11/May/2016:23:19:50 -0400] schema-compat-plugin - warning: no entries set
up under cn=ng, cn=compat,dc=domainname,dc=edu
[11/May/2016:23:19:50 -0400] schema-compat-plugin - warning: no entries set
up under ou=sudoers,dc=domainname,dc=edu
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=dns,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=dns,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=keys,cn=sec,cn=dns,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=dns,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=dns,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=groups,cn=compat,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=computers,cn=compat,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=ng,cn=compat,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
ou=sudoers,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=users,cn=compat,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=vaults,cn=kra,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target
cn=ad,cn=etc,dc=domainname,dc=edu does not exist
[11/May/2016:23:19:51 -0400] NSACLPlugin - The ACL target cn=automember
rebuild membership,cn=tasks,cn=config does not exist
[11/May/2016:23:19:51 -0400] - Skipping CoS Definition cn=Password
Policy,cn=accounts,dc=domainname,dc=edu--no CoS Templates found, which
should be added before the CoS Definition.
[11/May/2016:23:19:52 -0400] NSMMReplicationPlugin -
replica_check_for_data_reload: Warning: disordely shutdown for replica
o=ipaca. Check if DB RUV needs to be updated
[11/May/2016:23:19:52 -0400] set_krb5_creds - Could not get initial
credentials for principal [ldap/idm_replica.com at DOMAINNAME.EDU] in keytab
[FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for
requested realm)
[11/May/2016:23:19:52 -0400] NSMMReplicationPlugin -
replica_check_for_data_reload: Warning: disordely shutdown for replica
dc=domainname,dc=edu. Check if DB RUV needs to be updated
[11/May/2016:23:19:52 -0400] slapd_ldap_sasl_interactive_bind - Error:
could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2
(Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS
failure.  Minor code may provide more information (No Kerberos credentials
available)) errno 0 (Success)
[11/May/2016:23:19:52 -0400] slapi_ldap_bind - Error: could not perform
interactive bind for id [] authentication mechanism [GSSAPI]: error -2
(Local error)
[11/May/2016:23:19:52 -0400] NSMMReplicationPlugin - agmt="cn=
meToidm_master.cc.gt.atl.ga.us" (idm_master:389): Replication bind with
GSSAPI auth failed: LDAP error -2 (Local error) (SASL(-1): generic failure:
GSSAPI Error: Unspecified GSS failure.  Minor code may provide more
information (No Kerberos credentials available))
[11/May/2016:23:19:52 -0400] NSMMReplicationPlugin -
agmt="cn=cloneAgreement1-idm_replica.com-pki-tomcat" (idm_master:389):
Unable to acquire replica: the replica instructed us to go into backoff
mode. Will retry later.
[11/May/2016:23:19:52 -0400] DSRetroclPlugin - delete_changerecord: could
not delete change record 404054 (rc: 32)
[11/May/2016:23:19:52 -0400] - slapd started.  Listening on All Interfaces
port 389 for LDAP requests
[11/May/2016:23:19:52 -0400] - Listening on All Interfaces port 636 for
LDAPS requests
[11/May/2016:23:19:52 -0400] - Listening on
/var/run/slapd-DOMAINNAME-EDU.socket for LDAPI requests
[11/May/2016:23:19:52 -0400] DSRetroclPlugin - delete_changerecord: could
not delete change record 404055 (rc: 32)
[11/May/2016:23:19:52 -0400] DSRetroclPlugin - delete_changerecord: could
not delete change record 404056 (rc: 32)
[11/May/2016:23:19:52 -0400] DSRetroclPlugin - delete_changerecord: could
not delete change record 404057 (rc: 32)
[11/May/2016:23:19:52 -0400] DSRetroclPlugin - delete_changerecord: could
not delete change record 404058 (rc: 32)
... lots of similar messages

On Thu, May 12, 2016 at 4:25 AM, Ludwig Krispenz <lkrispen at redhat.com>
wrote:

>
> On 05/12/2016 05:28 AM, Prasun Gera wrote:
>
> Hi everyone,
> I had a pretty similar failure on my replica yesterday. The replica was
> not reachable, and I asked someone to have a look at the system. They
> presumably rebooted it. When it came back up, ipactl wouldn't start, and
> the symptoms were pretty similar to those described in this thread. I
> followed the solution of copying dse.ldif.startOK to dse.ldif, and that
> started everything.
>
> This is very strange, it should not be possible to loose a dse.ldif,
> although you are now teh second person reporting this. I have seen 0 length
> dse.ldif.tmp if a VM was powerd off while ds was active, but from DS  point
> of view it is not possible to complete loos the dse.ldif.
> The dse.ldif stores the configuration information including replication
> agreements and and when ever this is updated the new state is written to
> disk. The procedure is like this:
> -create a dse.ldif.tmp (this is the only time a 0 byte dse.ldif* file
> exists
> -write the config to dse.ldif.tmp
> -rename dse.ldif to dse.ldif.bak
> -rename dse.ldif.tmp to dse.ldif
>
> So, if the machine or the server crashes during this process there should
> be always a dse.ldif.tmp or dse.ldif.bak containing the current or latest
> information. If anyone has an idea how on a VM when powering it off can
> completely loose these files I would like to know.
>
> However, I see some errors in dirsrv's logs. It is constantly printing
> lines like "DSRetroclPlugin - delete_changerecord: could not delete change
> record 418295". Is that normal ?
>
> Unfortunately it can be. If after a crash the beginning of the retro cl is
> incorrectly calculated, changelog trimming might try to remov no longer
> existing records, it is annoying but harmless, so far we have not further
> investigated how to prevent this.
>
> How do I confirm that the replica is back and fully functional ? Why did
> this happen in the first place ?
>
> On Wed, Apr 27, 2016 at 1:41 PM, Gady Notrica <gnotrica at candeal.com>
> wrote:
>
>> All good!!!
>>
>> Gady
>>
>> -----Original Message-----
>> From: Alexander Bokovoy [mailto:abokovoy at redhat.com]
>> Sent: April 27, 2016 1:19 PM
>> To: Gady Notrica
>> Cc: Ludwig Krispenz; freeipa-users at redhat.com
>> Subject: Re: [Freeipa-users] krb5kdc service not starting
>>
>> On Wed, 27 Apr 2016, Gady Notrica wrote:
>> >Hello Ludwig,
>> >
>> >Is there a reason why my AD show offline?
>> >
>> >[root at cd-p-ipa1 /]# wbinfo --online-status BUILTIN : online IPA :
>> >online CD-PRD : offline
>> wbinfo output is irrelevant for RHEL 7.2-based IPA trusts.
>>
>> You need to make sure that 'getent passwd CD-PRD\\Administrator'
>> resolves via SSSD.
>>
>> --
>> / Alexander Bokovoy
>>
>> --
>> Manage your subscription for the Freeipa-users mailing list:
>> https://www.redhat.com/mailman/listinfo/freeipa-users
>> Go to http://freeipa.org for more info on the project
>>
>
>
>
>
> --
> Red Hat GmbH, http://www.de.redhat.com/, Registered seat: Grasbrunn,
> Commercial register: Amtsgericht Muenchen, HRB 153243,
> Managing Directors: Paul Argiry, Charles Cachera, Michael Cunningham, Michael O'Neill
>
>
> --
> Manage your subscription for the Freeipa-users mailing list:
> https://www.redhat.com/mailman/listinfo/freeipa-users
> Go to http://freeipa.org for more info on the project
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20160512/ea89dcd8/attachment.htm>