directory-kerby mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Zheng, Kai" <kai.zh...@intel.com>
Subject RE: MIT Kerberos compatibility
Date Wed, 03 May 2017 11:28:59 GMT
Hi Marc,

In case you're not aware of this, please check out the latest fix made by Jiajia. We thought
your case may be different, but would be good to have a check before we can repeat/fix your
case. Thanks.
https://issues.apache.org/jira/browse/DIRKRB-625

Regards,
Kai

-----Original Message-----
From: Marc de Lignie [mailto:m.c.delignie@xs4all.nl] 
Sent: Sunday, April 30, 2017 7:45 PM
To: kerby@directory.apache.org
Subject: Re: MIT Kerberos compatibility

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