kinit apacheds kerberos

I've installed ApacheDS and am trying to configure it to run as a kerberos server on my localhost.  When I run kinit (the one from the installed jre7) to get a ticket granting ticket (TGT), I get the following error:

C:\Users\wnpr>kinit.exe hnelson@EXAMPLE.COM
Password for hnelson@EXAMPLE.COM:secret
Exception: krb_error 6 Client not found in Kerberos database (6) - Client not found in Kerberos database Client not found in Kerberos database
KrbException: Client not found in Kerberos database (6) - Client not found in Kerberos 

The configuration, which is being used by kinit, is in the %JRE_HOME%/lib/security/krb5.conf
file.

The LDAP/Kerberos configuration is in the "instances\default\conf" of my ApachDS installation and is called config.ldif. If one opens the configuration file with Apache Directory Studio,  one should see the following:

Notice that the Kerberos Server has been activated on the default port, which agrees with the one configured in the krb5.conf. 

Below one can see the DIT structure, which is the default one plus a new partition called sevenSeas and a new user.

The problem is why cannot Kerberos find the hnelson user. Notice that the search basis is set to "ou=users,ou=system".

To further investigate the issue, I increased the servers log level to debug by changing the log4j.properties file found in the $APACHEDS_HOME directory as shown here:

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=${apacheds.log.dir}/apacheds.log

log4j.appender.R.MaxFileSize=10240KB
# Keep some backup files
log4j.appender.R.MaxBackupIndex=5

log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=[%d{HH:mm:ss}] %p [%c] - %m%n

log4j.appender.stdout.layout.ConversionPattern=[%d{HH:mm:ss}] %p [%c] - %m%n

# with these we'll not get innundated when switching to DEBUG
log4j.logger.jdbm.recman.BaseRecordManager=DEBUG
log4j.logger.org.apache.directory.server.OPERATION_LOG=DEBUG
log4j.logger.org.apache.directory.server.OPERATION_TIME=FATAL
log4j.logger.org.apache.directory.api.CODEC_LOG=DEBUG
log4j.logger.org.apache.directory.server.ACI_LOG=DEBUG
log4j.logger.org.apache.directory.server.PROVIDER_LOG=DEBUG
log4j.logger.org.apache.directory.server.CONSUMER_LOG=DEBUG
log4j.logger.org.apache.directory.CURSOR_LOG=DEBUG
log4j.logger.org.apache.directory.api=DEBUG
log4j.logger.org.apache.directory.server=DEBUG
log4j.logger.net.sf.ehcache=FATAL

log4j.logger.org.apache.mina=FATAL

The output looked like this:

[14:46:57] DEBUG [org.apache.directory.server.PROVIDER_LOG] - syncrepl provider initialized successfully
[14:46:57] INFO [org.apache.directory.server.ldap.LdapServer] - Successful bind of an LDAP Service (10636) is completed.
[14:46:57] INFO [org.apache.directory.server.ldap.LdapServer] - Successful bind of an LDAP Service (10389) is completed.
[14:46:57] INFO [org.apache.directory.server.ldap.LdapServer] - Ldap service started.
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - LDAP server: started in 481 milliseconds
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Starting the NTP server
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Cannot find any reference to the NTP Server in the configuration : the server won't be started
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Starting the Kerberos server
[14:46:57] DEBUG [org.apache.directory.server.protocol.shared.transport.UdpTransport] - UDP Transport created : <0.0.0.0:60088,>
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Starting the Kerberos server
[14:46:57] DEBUG [org.apache.directory.server.kerberos.kdc.KdcServer] - initializing the kerberos replay cache
[14:46:57] INFO [org.apache.directory.server.core.api.CacheService] - fetching the cache named kdcReplayCache
[14:46:57] INFO [org.apache.directory.server.kerberos.kdc.KdcServer] - Kerberos service started.

[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Kerberos server: started in 39 milliseconds

The following entries were written to the log upon executing kinit hnelson@EXAMPLE.COM 

[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Kerberos server: started in 39 milliseconds
[14:46:57] INFO [org.apache.directory.server.ApacheDsService] - Cannot find any reference to the HTTP Server in the configuration : the server won't be started
[14:51:10] DEBUG [org.apache.directory.server.kerberos.protocol.KerberosProtocolHandler] - /127.0.0.1:55596 CREATED:  datagram
[14:51:10] DEBUG [org.apache.directory.server.KERBEROS_LOG] - /127.0.0.1:55596 CREATED:  datagram

[14:51:10] DEBUG [org.apache.directory.server.kerberos.protocol.KerberosProtocolHandler] - /127.0.0.1:55596 OPENED

I re-executed kinit.

[14:51:11] DEBUG [org.apache.directory.server.kerberos.protocol.codec.KerberosDecoder] - Decoded KerberosMessage : 
>-------------------------------------------------------------------------------
AS-REQ
pvno : 5
msg-type : AS_REQ
kdc-req-body : 
    KDCOptions : 
    cname : { name-type: KRB_NT_UNKNOWN, name-string : <'hnelson'> }
    realm : EXAMPLE.COM
    sname : { name-type: KRB_NT_SRV_INST, name-string : <'krbtgt', 'EXAMPLE.COM'> }
    till : 19700101000000Z
    nonce : 508742362
    etype : des-cbc-md5 (3) des3-cbc-sha1-kd (16)
    addresses : 192.168.178.42 fe80:0:0:0:45a9:39dc:cf90:bdc2 fe80:0:0:0:287f:3fbf:3f57:4dd5 2001:0:5ef5:79fd:287f:3fbf:3f57:4dd5

-------------------------------------------------------------------------------<



[14:51:11] DEBUG [org.apache.directory.api.ldap.model.schema.syntaxCheckers.Ia5StringSyntaxChecker] - Syntax valid for 'hnelson@EXAMPLE.COM'
[14:51:11] DEBUG [org.apache.directory.server.OPERATION_LOG] - >> SearchOperation : SearchContext for Dn 'ou=users,ou=system', filter :'(krb5PrincipalName=hnelson@EXAMPLE.COM)'

.
.
[14:51:11] DEBUG [org.apache.directory.api.ldap.model.schema.syntaxCheckers.DnSyntaxChecker] - Syntax valid for 'cn=hnelson,ou=users,ou=system'


I then added some kerberos related elements to the user's entry.

The log file now showed something else.

[15:42:24] DEBUG [org.apache.directory.server.core.authn.AuthenticationInterceptor] - Operation Context: SearchContext for Dn 'ou=users,ou=system', filter :'(krb5PrincipalName=hnelson@EXAMPLE.COM)'
[15:42:24] DEBUG [org.apache.directory.server.xdbm.search.impl.DefaultSearchEngine] - Nb results : 2 for filter : (&:[2](krb5PrincipalName=hnelson@EXAMPLE.COM:[?])(#{SUBTREE_SCOPE (Estimated), 'ou=users,ou=system', DEREF_ALWAYS}:[2]))
[15:42:24] DEBUG [org.apache.directory.server.protocol.shared.kerberos.StoreUtils] - Found entry cn=hnelson,ou=users,ou=system for kerberos principal name hnelson@EXAMPLE.COM
[15:42:24] DEBUG [org.apache.directory.server.KERBEROS_LOG] - Found entry cn=hnelson,ou=users,ou=system for kerberos principal name hnelson@EXAMPLE.COM
[15:42:24] ERROR [org.apache.directory.server.KERBEROS_LOG] - Error while searching for client hnelson@EXAMPLE.COM : Client not found in Kerberos database


Which didn't quiet make sense because I still got the "Client not found" error message.

I've added a kbrtgt and a ldap to the users node and placed the user node with in the dc=example,dc=com partition and am now getting a password decryption error.

INFO   | jvm 1    | 2014/05/25 00:15:55 | [00:15:55] DEBUG [org.apache.directory.server.KERBEROS_LOG] - --> Verifying the policy
INFO   | jvm 1    | 2014/05/25 00:15:55 | [00:15:55] DEBUG [org.apache.directory.server.KERBEROS_LOG] - --> Verifying using SAM subsystem.
INFO   | jvm 1    | 2014/05/25 00:15:55 | [00:15:55] DEBUG [org.apache.directory.server.KERBEROS_LOG] - --> Verifying using encrypted timestamp.
INFO   | jvm 1    | 2014/05/25 00:15:55 | [00:15:55] DEBUG [org.apache.directory.server.KERBEROS_LOG] - Entry for client principal hnelson@EXAMPLE.COM has no SAM type.  Proceeding with standard pre-authentication.
INFO   | jvm 1    | 2014/05/25 00:15:55 | [00:15:55] DEBUG [org.apache.directory.server.KERBEROS_LOG] - Decrypting data using key des3-cbc-sha1-kd (16) and usage ERR_603 AS-REQ PA-ENC-TIMESTAMP padata timestamp, encrypted with the client key (1)
INFO   | jvm 1    | 2014/05/25 00:15:55 | javax.crypto.IllegalBlockSizeException: Input length not multiple of 8 bytes

INFO   | jvm 1    | 2014/05/25 00:15:55 | at com.sun.crypto.provider.CipherCore.finalNoPadding(CipherCore.java:854)

My LDAP configuration now looks like this:

At first I  thought it must having something to do with the user password but then I remembered that the special thing about kerberos is that the user never sends his or her password accross the network so the error must be referring to the krb5key.

Time to dig a little deeper into the DIT (Data Information Tree) and the Object Tree Structure.

From zytrax:

"LDAP Data Interchange Files (LDIF) which are fully described in a later chapter. LDIFs are textual files that describe the tree hierarchy - the Directory Information Tree (DIT)"

 Important Note: The lines in the above LDIF file beginning with 'dn:' essentially tell the LDAP server how to structure or place the entry within the DIT. In general, it does not matter what attribute value is used for this purpose as long as the 'dn:' is unique. ..........However, if the entry is going to be used for user authentication, say, a logon or Single Sign-On type use, the 'dn:' value becomes extremely important and defines the logon (or Bind DN in the jargon) identifier. It is sometimes (especially in the context of LDAP used within Microsoft's AD) referred to as a Principal DN though this term is not used within the LDAP standards definitions. For more on this topic.

More about DN and binding.

LDAP: DNs for Authentication

the Bind DN CAN ONLY be the DN used when the entry was added or created.

References:

http://www.zytrax.com/books/ldap/ch2/index.html#basic

http://www.zytrax.com/books/ldap/apa/binddn.html


I restructured the DIT so that it looked like this:

and added example.com to the host file in C:\Windows\System32\drivers\etc

# localhost name resolution is handled within DNS itself.
# 127.0.0.1       localhost
# ::1             localhost
127.0.0.1 EXAMPLE.COM

Now, kinit gives:

kinit.exe hnelson@EXAMPLE.COM

Password for hnelson@EXAMPLE.COM:

Exception: krb_error 6 Client not found in Kerberos database (6) - Client not found in Kerberos database Client not found in Kerberos database

KrbException: Client not found in Kerberos database (6) - Client not found in Kerberos database

The IllegalBlockSizeException disappeared because the search basis, due to the changes in the DIT structure, was wrong. Once corrected so that the target DN was found, the error reoccurred again.

I found some useful information about the krb5.conf file and the TGT Request here:
http://docs.oracle.com/cd/E19253-01/816-4557/egric/index.html. Here I read that it is recommendable not to set default_tkt_enctypes (See below).

Note, that the encryption types specified in default_tkt_enctypes must match at least one of the principal key encryption types in the principal database stored on the KDC. Otherwise, the TGT request will fail. In most situations, it is best not to set default_tkt_enctypes because this parameter can be a source of interoperability problems.

I commented out the setting in my krb5.conf, which now looks like this:

[libdefaults]
default_realm = EXAMPLE.COM
# default_tgs_enctypes = des-cbc-md5,des3-cbc-sha1-kd
# default_tkt_enctypes = des-cbc-md5,des3-cbc-sha1-kd
kdc_timeout = 5000
dns_lookup_realm = false
dns_lookup_kdc = false
allow_weak_crypto = yes
forwardable = true

[realms]
EXAMPLE.COM = {
kdc = example.com:60088
}

[login]
krb4_convert = true
krb4_get_tickets = false



This solved the issue with the illegal block side and produced a new error.

kinit.exe  wmmnpr@EXAMPLE.COM
Password for wmmnpr@EXAMPLE.COM:
Exception: krb_error 7 Server not found in Kerberos database (7) - Server not found in Kerberos database Server not found in Kerberos database

KrbException: Server not found in Kerberos database (7) - Server not found in Kerberos database

I put the IP Address (127.0.0.1) back in place of the hostname (example.com) but that still didn't help. 

During testing, I typed in the wrong password, which produce a new error:

kinit.exe hnelson@EXAMPLE.COM
Password for hnelson@EXAMPLE.COM:
Exception: krb_error 31 Integrity check on decrypted field failed (31) - Integrity check on decrypted field failed Integrity check on decrypted field failed



I could see in the log, that ApacheDS was looking for the krbtgt service in the same sub-tree as the user.

[org.apache.directory.server.KERBEROS_LOG] - --> Getting the server entry for {}{ name-type: KRB_NT_SRV_INST, name-string : <'krbtgt', 'EXAMPLE.COM'> }

 [org.apache.directory.server.core.authn.AuthenticationInterceptor] - Operation Context: SearchContext for Dn 'ou=users,dc=security,dc=example,dc=com', filter :'(krb5PrincipalName=krbtgt/EXAMPLE.COM@EXAMPLE.COM)'

So I copied the krbtgt entry back to the users entry.

And now bingo!

kinit.exe wmmnpr@EXAMPLE.COM
Password for wmmnpr@EXAMPLE.COM:
New ticket is stored in cache file C:\Users\wnpr\krb5cc_wnpr


What confuses me is that I seem to be getting a service ticket and not a ticket granting ticket. See log entries:

INFO   | jvm 1    | 2014/05/26 09:39:27 | [09:39:27] DEBUG [org.apache.directory.server.KERBEROS_LOG] - --> Generating ticket for { name-type: KRB_NT_SRV_INST, name-string : <'krbtgt', 'EXAMPLE.COM'> }

INFO   | jvm 1    | 2014/05/26 09:39:27 | [09:39:27] DEBUG [org.apache.directory.server.KERBEROS_LOG] - Ticket will be issued for access to { name-type: KRB_NT_SRV_INST, name-string : <'krbtgt', 'EXAMPLE.COM'> }.