Hi Jiajia,

Thanks for the netty config option. This indeed helped to get rid of the udp errors, but did not help in getting the service ticket (final error message remains the same).


I also noticed that I get the same error from the python console whether I specify the right service name or some service name for which no service principal exists in the TestKdc.

I did not succeed in getting mvn tst to print the debug logging of the various kdc classes involved.

Did you check with klist whether drankye's credential cache contains the service ticket for test-service?

Cheers,    Marc


Op 04-05-17 om 14:55 schreef Li, Jiajia:
Hi Marc,
I try to run your test(through applying your patch in the trunk) , I think it's 
success now.  Could you take some time to check about it?
Here is the log:

directory-kerby git:(trunk) ✗ . 
kerby-kerb/kerb-kdc-test/src/test/java/org/apache/kerby/kerberos/kerb/server/MitIssueTest.sh
kerberos.authGSSClientInit successful
2017-05-04T20:44:06 set-error: -1765328234: entypes not supported
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/realm-config@X-CACHECONF: in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
test-service/localh...@test.com in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/negative-cache/test-service\134/localhost\1...@test.com@X-CACHECONF:
 in cache FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/lkdc-hostname@X-CACHECONF: in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/sitename@X-CACHECONF: in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
test-service/localh...@test.com in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-md5-deprecated not supported
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-md4-deprecated not supported
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-crc-deprecated not supported
2017-05-04T20:44:06 Trying to find service kdc for realm TEST.COM flags 0
2017-05-04T20:44:06 configuration file for realm TEST.COM found
2017-05-04T20:44:06 submissing new requests to new host
2017-05-04T20:44:06 host_create: setting hostname localhost
2017-05-04T20:44:06 connecting to host: udp ::1:52534 (localhost) tid: 00000001
2017-05-04T20:44:06 host_create: setting hostname localhost
2017-05-04T20:44:06 Queuing host in future (in 3s), its the 2 address on the 
same name: udp 127.0.0.1:52534 (localhost) tid: 00000002
2017-05-04T20:44:06 writing packet: udp ::1:52534 (localhost) tid: 00000001
2017-05-04T20:44:06 reading packet: udp ::1:52534 (localhost) tid: 00000001
2017-05-04T20:44:06 host completed: udp ::1:52534 (localhost) tid: 00000001
2017-05-04T20:44:06 krb5_sendto_context TEST.COM done: 0 hosts 1 packets 1 wc: 
0.048927 nr: 0.000932 kh: 0.000814 tid: 00000002
2017-05-04T20:44:06 tkt: extract key 17/763641F3
2017-05-04T20:44:06 set-error: -1765328353: Decrypt integrity check failed for 
checksum type hmac-sha1-96-aes128, key type aes128-cts-hmac-sha1-96
2017-05-04T20:44:06 tkt: extract key 17/3084A95C
2017-05-04T20:44:06 krb5_get_credentials_with_flags: TEST.COM wc: 0.050317
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/realm-config@X-CACHECONF: in cache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 set-error: -1765328243: Did not find credential for 
krb5_ccache_conf_data/time-offset/test-service\134/localhost\1...@test.com@X-CACHECONF:
 in cache FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
2017-05-04T20:44:06 Setting up PFS for auth context
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-md5-deprecated not supported
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-md4-deprecated not supported
2017-05-04T20:44:06 set-error: -1765328234: Encryption type 
des-cbc-crc-deprecated not supported
First kerberos.authGSSClientStep successful

Thanks
Jiajia

-----Original Message-----
From: Zheng, Kai [mailto:kai.zh...@intel.com]
Sent: Wednesday, May 3, 2017 7:29 PM
To: kerby@directory.apache.org
Subject: RE: MIT Kerberos compatibility

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.delig...@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: dran...@test.com

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


--
Marc de Lignie

Reply via email to