Thanks Marc for the details. We need to solve this for the 1.0 GA release. I'll look into it when get back to office. The fix shouldn't be big if we figure it out why the provided ASN1 packet isn't as expected while decoding.
What's your version, the MIT Kerberos client binary installation? I wonder it's introduced by new versions since we did test the case of MIT Kerberos client + Kerby KDC about two years ago. Regards, Kai -----Original Message----- From: Marc de Lignie [mailto:[email protected]] Sent: Sunday, April 30, 2017 3:42 AM To: [email protected] Subject: RE: MIT Kerberos compatibility Hi Kai, Thanks for the response. I prepared a minimal config that reproduces my problem. You can fetch the branch/commit from: https://github.com/vtslab/directory-kerby/commits/MitIssue This is relative to RC2, but I also tried this on trunk for my actual project. This config produces the debug and error messages below. 1. For the terminal with the bash + python script $ klist Ticket cache: FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc Default principal: [email protected] Valid starting Expires Service principal 29-04-17 21:07:39 30-04-17 05:07:39 krbtgt/[email protected] renew until 29-04-17 21:07:39 $ . kerby-kerb/kerb-kdc-test/src/test/java/org/apache/kerby/kerberos/kerb/server/MitIssueTest.sh [15538] 1493491231.917606: Retrieving [email protected] from FILE:/etc/krb5/user/1000/client.keytab (vno 0, enctype 0) with result: 2/Key table file '/etc/krb5/user/1000/client.keytab' not found [15538] 1493491231.917827: Retrieving [email protected] from FILE:/etc/krb5/user/1000/client.keytab (vno 0, enctype 0) with result: 2/Key table file '/etc/krb5/user/1000/client.keytab' not found kerberos.authGSSClientInit successful [15538] 1493491231.918185: Getting credentials [email protected] -> test-service/localhost@ using ccache FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc [15538] 1493491231.918210: Retrieving [email protected] -> test-service/localhost@ from FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: -1765328243/Matching credential not found (filename: kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc) [15538] 1493491231.918226: Retrying [email protected] -> test-service/[email protected] with result: -1765328243/Matching credential not found (filename: kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc) [15538] 1493491231.918229: Server has referral realm; starting with test-service/[email protected] [15538] 1493491231.918278: Retrieving [email protected] -> krbtgt/[email protected] from FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 0/Success [15538] 1493491231.918281: Starting with TGT for client realm: [email protected] -> krbtgt/[email protected] [15538] 1493491231.918301: Requesting tickets for test-service/[email protected], referrals on [15538] 1493491231.918326: Generated subkey for TGS request: aes128-cts/FA30 [15538] 1493491231.918359: etypes requested in TGS request: aes256-cts, aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts [15538] 1493491231.918484: Encoding request body and padata into FAST request [15538] 1493491231.918541: Sending request (836 bytes) to TEST.COM [15538] 1493491231.918597: Resolving hostname localhost [15538] 1493491231.918703: Initiating TCP connection to stream 127.0.0.1:44292 [15538] 1493491231.918777: Sending TCP request to stream 127.0.0.1:44292 [15538] 1493491231.922803: TCP error receiving from stream 127.0.0.1:44292: 104/Connection reset by peer [15538] 1493491231.922812: Terminating TCP connection to stream 127.0.0.1:44292 [15538] 1493491231.922858: Sending initial UDP request to dgram 127.0.0.1:44292 ('First kerberos.authGSSClientStep not successful', GSSError(('Unspecified GSS failure. Minor code may provide more information', 851968), ("Cannot contact any KDC for realm 'TEST.COM'", -1765328228))) 2. For the terminal that runs mvn clean test -Dtest=MitIssueTest Running org.apache.kerby.kerberos.kerb.server.MitIssueTest 2017-04-29 21:07:39,182 DEBUG [main] backend.AbstractIdentityBackend: initialize called 2017-04-29 21:07:39,195 DEBUG [main] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,195 DEBUG [main] backend.AbstractIdentityBackend: getIdentity failed, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: addIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: getIdentity called, principalName = kadmin/[email protected] 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: getIdentity failed, principalName = kadmin/[email protected] 2017-04-29 21:07:39,213 DEBUG [main] backend.AbstractIdentityBackend: addIdentity successful, principalName = kadmin/[email protected] 2017-04-29 21:07:39,216 DEBUG [main] backend.AbstractIdentityBackend: start called 2017-04-29 21:07:39,232 DEBUG [main] backend.AbstractIdentityBackend: addIdentity successful, principalName = test-service/[email protected] 2017-04-29 21:07:39,425 DEBUG [main] backend.AbstractIdentityBackend: addIdentity successful, principalName = [email protected] 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,465 INFO [pool-1-thread-1] request.KdcRequest: Client entry is empty. 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = [email protected] 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = [email protected] 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,476 DEBUG [pool-1-thread-1] impl.DefaultKdcHandler: Transport or decoding error occurred, disconnecting abnormally java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.kerby.kerberos.kerb.transport.KrbTcpTransport.receiveMessage(KrbTcpTransport.java:54) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.run(DefaultKdcHandler.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2017-04-29 21:07:39,477 INFO [main] client.KrbClientBase: Storing the tgt to the credential cache file. 2017-04-29 21:07:39,491 DEBUG [main] backend.AbstractIdentityBackend: getIdentity called, principalName = test-service/[email protected] 2017-04-29 21:07:39,491 DEBUG [main] backend.AbstractIdentityBackend: getIdentity successful, principalName = test-service/[email protected] 2017-04-29 21:07:39,498 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,498 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,498 INFO [pool-1-thread-1] request.KdcRequest: Client entry is empty. 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = test-service/[email protected] 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = test-service/[email protected] 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,499 INFO [pool-1-thread-1] request.KdcRequest: The preauth data is empty. 2017-04-29 21:07:39,501 INFO [pool-1-thread-1] server.KdcHandler: KRB error occurred while processing request:Additional pre-authentication required 2017-04-29 21:07:39,502 DEBUG [pool-1-thread-1] impl.DefaultKdcHandler: Transport or decoding error occurred, disconnecting abnormally java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.kerby.kerberos.kerb.transport.KrbTcpTransport.receiveMessage(KrbTcpTransport.java:54) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.run(DefaultKdcHandler.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2017-04-29 21:07:39,505 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,505 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,505 INFO [pool-1-thread-1] request.KdcRequest: Client entry is empty. 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = test-service/[email protected] 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = test-service/[email protected] 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:39,510 DEBUG [pool-1-thread-1] impl.DefaultKdcHandler: Transport or decoding error occurred, disconnecting abnormally java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.kerby.kerberos.kerb.transport.KrbTcpTransport.receiveMessage(KrbTcpTransport.java:54) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.run(DefaultKdcHandler.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2017-04-29 21:07:55,602 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity called, principalName = krbtgt/[email protected] 2017-04-29 21:07:55,602 DEBUG [pool-1-thread-1] backend.AbstractIdentityBackend: getIdentity successful, principalName = krbtgt/[email protected] 2017-04-29 21:07:55,602 INFO [pool-1-thread-1] request.KdcRequest: Found fast padata and start to process it. 2017-04-29 21:07:55,603 ERROR [pool-1-thread-1] impl.DefaultKdcHandler: Error occured while processing request: org.apache.kerby.kerberos.kerb.KrbException: Decoding failed at org.apache.kerby.kerberos.kerb.KrbCodec.decode(KrbCodec.java:85) at org.apache.kerby.kerberos.kerb.KrbCodec.decode(KrbCodec.java:70) at org.apache.kerby.kerberos.kerb.server.request.KdcRequest.kdcFindFast(KdcRequest.java:208) at org.apache.kerby.kerberos.kerb.server.request.KdcRequest.process(KdcRequest.java:168) at org.apache.kerby.kerberos.kerb.server.KdcHandler.handleMessage(KdcHandler.java:115) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.handleMessage(DefaultKdcHandler.java:67) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.run(DefaultKdcHandler.java:52) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Caused by: java.io.IOException: Unexpected item context [0] [tag=0xA0, off=0, len=3+207], expecting 0x30 at org.apache.kerby.asn1.type.Asn1Encodeable.decode(Asn1Encodeable.java:210) at org.apache.kerby.asn1.type.Asn1Encodeable.decode(Asn1Encodeable.java:197) at org.apache.kerby.kerberos.kerb.KrbCodec.decode(KrbCodec.java:83) ... 9 more 2017-04-29 21:07:55,604 DEBUG [pool-1-thread-1] impl.DefaultKdcHandler: Transport or decoding error occurred, disconnecting abnormally java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.net.SocketInputStream.read(SocketInputStream.java:224) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.kerby.kerberos.kerb.transport.KrbTcpTransport.receiveMessage(KrbTcpTransport.java:54) at org.apache.kerby.kerberos.kerb.server.impl.DefaultKdcHandler.run(DefaultKdcHandler.java:46) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) In a FreeIPA environment these python lines "just" work. Any suggestions are welcome! Marc
