directory-kerby mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Marc de Lignie <m.c.delig...@xs4all.nl>
Subject Re: MIT Kerberos compatibility
Date Sun, 30 Apr 2017 11:45:27 GMT
Hi Kai,

The terminal output below is for the latest MIT Kerberos 1.15.1 (locally 
built on Ubuntu Xenial). Before that, I also tested with the default 
Xenial MIT Kerberos packages (1.13.2), with the same result. I did not 
try earlier MIT Kerberos versions.

Marc

Op 29-04-17 om 21:42 schreef Marc de Lignie:
>
> 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: drankye@TEST.COM
>
> Valid starting     Expires            Service principal
> 29-04-17 21:07:39  30-04-17 05:07:39  krbtgt/TEST.COM@TEST.COM
>     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 drankye@TEST.COM 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 drankye@TEST.COM 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 drankye@TEST.COM -> 
> test-service/localhost@ using ccache 
> FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
> [15538] 1493491231.918210: Retrieving drankye@TEST.COM -> 
> 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 drankye@TEST.COM -> 
> test-service/localhost@TEST.COM 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/localhost@TEST.COM
> [15538] 1493491231.918278: Retrieving drankye@TEST.COM -> 
> krbtgt/TEST.COM@TEST.COM 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: 
> drankye@TEST.COM -> krbtgt/TEST.COM@TEST.COM
> [15538] 1493491231.918301: Requesting tickets for 
> test-service/localhost@TEST.COM, 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/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,195 DEBUG [main] backend.AbstractIdentityBackend: 
> getIdentity failed, principalName = krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: 
> addIdentity successful, principalName = krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: 
> getIdentity called, principalName = kadmin/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,212 DEBUG [main] backend.AbstractIdentityBackend: 
> getIdentity failed, principalName = kadmin/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,213 DEBUG [main] backend.AbstractIdentityBackend: 
> addIdentity successful, principalName = kadmin/TEST.COM@TEST.COM
> 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/localhost@TEST.COM
> 2017-04-29 21:07:39,425 DEBUG [main] backend.AbstractIdentityBackend: 
> addIdentity successful, principalName = drankye@TEST.COM
> 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity called, principalName = 
> krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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 = 
> drankye@TEST.COM
> 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = drankye@TEST.COM
> 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity called, principalName = 
> krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,465 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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/localhost@TEST.COM
> 2017-04-29 21:07:39,491 DEBUG [main] backend.AbstractIdentityBackend: 
> getIdentity successful, principalName = test-service/localhost@TEST.COM
> 2017-04-29 21:07:39,498 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity called, principalName = 
> krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,498 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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/localhost@TEST.COM
> 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = test-service/localhost@TEST.COM
> 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity called, principalName = 
> krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,499 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,505 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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/localhost@TEST.COM
> 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = test-service/localhost@TEST.COM
> 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity called, principalName = 
> krbtgt/TEST.COM@TEST.COM
> 2017-04-29 21:07:39,506 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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/TEST.COM@TEST.COM
> 2017-04-29 21:07:55,602 DEBUG [pool-1-thread-1] 
> backend.AbstractIdentityBackend: getIdentity successful, principalName 
> = krbtgt/TEST.COM@TEST.COM
> 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
>
>

-- 
Marc de Lignie


Mime
View raw message