Consumer 389 Error Log
consumer.log

Supplier 389 Error Log
supplier.log

Associated ticket: https://fedorahosted.org/freeipa/ticket/2118

Almost certainly this happens before we finished obtaining a keytab for ds and before we finished reconfiguring dirsrv to use the new keys in the right location.

So I consider this a red herring unless evidence of the contrary (full install log and errors log to compare times).

Corresponding Bugzilla for underlying 389 DS bug:

https://bugzilla.redhat.com/show_bug.cgi?id=755119

The corresponding DS ticket is fixed upstream in 1.2.10

Fixed in 1.2.10.a8.

We just need to bump the n-v-r of 389-ds-base.

Will test and see what other tickets need this version as well.

Oh, looking more closely the reported error messages (references to krb5.keytab rather than ds.keytab) are not what was fixed upstream. The referenced upstream bug has to do with DNA ranges, not keytab selection.

So either this ticket gets closed as invalid or we file a new upstream ticket.

JR can you evaluate and see if this is still an issue for you?

Please Unlink the 389 DS bug from this ticket. It would appear that whichever underlying bug was present in 389, is not at the root of the problem with these error messages.

Instead, It looks as though: ipa-replica-install is trying to perform the kinit, and gssapi bind via its own kdc, before the slapd process is fully started. See this in the order of the log:

[31/Jan/2012:12:00:48 -0800] - slapd stopped.

[31/Jan/2012:12:00:53 -0800] - 389-Directory/1.2.10.a8 B2012.024.2116 starting up

[31/Jan/2012:12:00:53 -0800] schema-compat-plugin - warning: no entries set up under cn=ng, cn=compat, dc=expertcity,dc=com

[31/Jan/2012:12:00:53 -0800] schema-compat-plugin - warning: no entries set up under ou=SUDOers, dc=expertcity,dc=com

[31/Jan/2012:12:00:53 -0800] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=expertcity,dc=com--no CoS Templates found, which should be added before the CoS Definition.

[31/Jan/2012:12:00:54 -0800] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=expertcity,dc=com--no CoS Templates found, which should be added before the CoS Definition.

[31/Jan/2012:12:00:54 -0800] set_krb5_creds - Could not get initial credentials for principal [ldap/authstage1.sjc.expertcity.com@EXPERTCITY.COM] in keytab [WRFILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))

[31/Jan/2012:12:00:54 -0800] - slapd started. Listening on All Interfaces port 389 for LDAP requests
[31/Jan/2012:12:00:54 -0800] - Listening on All Interfaces port 636 for LDAPS requests

[31/Jan/2012:12:00:54 -0800] - Listening on /var/run/slapd-EXPERTCITY-COM.socket for LDAPI requests

[31/Jan/2012:12:00:54 -0800] 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 (Credentials cache file '/tmp/krb5cc_496' not found)) errno 0 (Success)

[31/Jan/2012:12:00:54 -0800] slapi_ldap_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: error -2 (Local error)

[31/Jan/2012:12:00:54 -0800] NSMMReplicationPlugin - agmt="cn=meToauthstage1.ops.expertcity.com" (authstage1: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 (Credentials cache file '/tmp/krb5cc_496' not found))

Replying to [comment:12 jraquino]:
snip

[31/Jan/2012:12:00:54 -0800] NSMMReplicationPlugin - agmt="cn=meToauthstage1.ops.expertcity.com" (authstage1: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 (Credentials cache file '/tmp/krb5cc_496' not found))

Is this just a transient error? That is, once 389 and krb are up and running, do you see a message like "bind resumed"?

Moving to next month iteration.

Deon, we need to document this somewhere, not entirely sure where.

Rich, please correct me if I have this wrong.

When a replica starts you'll see severa; errors in 389-ds error logs:

slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credentials cache file '/tmp/krb5cc_496' not found))
slapi_ldap_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: error -2 (Local error)
NSMMReplicationPlugin - agmt="cn=meToipaserver.example.com" (replica1: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 (Credentials cache file '/tmp/krb5cc_496' not found))

389-ds supports multiple authentication mechanisms for replication, IPA uses GSSAPI (Kerberos). 389-ds uses a memory-based Kerberos credentials cache so when the process ends the credentials cache is destroy.

The first time 389-ds attempts to make a GSSAPI connection it has no credentials cache so these errors are thrown.

Additionally start up ordering of IPA has 389-ds starting before the KDC because 389-ds is the backend storage. This means that any Kerberos work 389-ds has to perform during startup will fail because the KDC is unavailable, not started yet. This may generate additional messages like:

set_krb5_creds - Could not get initial credentials for principal [ldap/ replica1.example.com@EXAMPLE.COM] in keytab [WRFILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))

Replying to [comment:15 rcritten]:

Deon, we need to document this somewhere, not entirely sure where.

Rich, please correct me if I have this wrong.

When a replica starts you'll see severa; errors in 389-ds error logs:

slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credentials cache file '/tmp/krb5cc_496' not found))
slapi_ldap_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: error -2 (Local error)
NSMMReplicationPlugin - agmt="cn=meToipaserver.example.com" (replica1: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 (Credentials cache file '/tmp/krb5cc_496' not found))

389-ds supports multiple authentication mechanisms for replication, IPA uses GSSAPI (Kerberos). 389-ds uses a memory-based Kerberos credentials cache so when the process ends the credentials cache is destroy.

The first time 389-ds attempts to make a GSSAPI connection it has no credentials cache so these errors are thrown.

Right. It also looks for /tmp/krb5cc_496 (496 == dirsrv user id) which is the file based tgt cache for the dirsrv user.

Additionally start up ordering of IPA has 389-ds starting before the KDC because 389-ds is the backend storage. This means that any Kerberos work 389-ds has to perform during startup will fail because the KDC is unavailable, not started yet. This may generate additional messages like:

set_krb5_creds - Could not get initial credentials for principal [ldap/ replica1.example.com@EXAMPLE.COM] in keytab [WRFILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))

Correct.

Moving to next month iteration.

Moving to next month iteration.

I added a small section on troubleshooting replica installs:
http://docs.fedoraproject.org/en-US/Fedora/16/html/FreeIPA_Guide/Setting_up_IPA_Replicas.html#troubleshooting-replica-install

And then general server/replica troubleshooting:
http://docs.fedoraproject.org/en-US/Fedora/16/html/FreeIPA_Guide/troubleshooting-servers-and-replicas.html#id822783

(Same text both places.)