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 Mon, 08 May 2017 19:01:05 GMT
Hi Chris, Jiajia, Kai,

Thanks for your additional suggestions. In the mean time I can confirm 
my test working on a Centos 6.x system, see logs below, that is with Mit 
Kerberos installed and the MitIssueTest.

So, there must be something strange on my Ubuntu Xenial + Mate system 
(maybe something silly as host resolution); that is for me to find out. 
At least I can compare a failing system with a working system now.

Cheers,    Marc

$ python 
kerby-kerb/kerb-kdc-test/src/test/java/org/apache/kerby/kerberos/kerb/server/MitIssueTest.py
[26558] 1494229795.344270: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.344941: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.345472: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.346300: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.346911: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.347490: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.348050: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
[26558] 1494229795.348559: Retrieving drankye@TEST.COM -> 
krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with result: 
-1765328243/Matching credential not found
kerberos.authGSSClientInit successful
[26558] 1494229795.350166: Getting credentials drankye@TEST.COM -> 
test-service/localhost@ using ccache 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
[26558] 1494229795.350278: 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
[26558] 1494229795.350332: Retrying drankye@TEST.COM -> 
test-service/localhost@TEST.COM with result: -1765328243/Matching 
credential not found
[26558] 1494229795.350349: Server has referral realm; starting with 
test-service/localhost@TEST.COM
[26558] 1494229795.350402: 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
[26558] 1494229795.350416: Found cached TGT for service realm: 
drankye@TEST.COM -> krbtgt/TEST.COM@TEST.COM
[26558] 1494229795.350431: Requesting tickets for 
test-service/localhost@TEST.COM, referrals on
[26558] 1494229795.350519: Generated subkey for TGS request: 
aes128-cts/F635
[26558] 1494229795.350541: etypes requested in TGS request: aes256-cts, 
aes128-cts, des3-cbc-sha1, rc4-hmac
[26558] 1494229795.350919: Sending request (599 bytes) to TEST.COM
[26558] 1494229795.352645: Resolving hostname localhost
[26558] 1494229795.352836: Initiating TCP connection to stream ::1:43227
[26558] 1494229795.353888: Terminating TCP connection to stream ::1:43227
[26558] 1494229795.353935: Initiating TCP connection to stream 
127.0.0.1:43227
[26558] 1494229795.356311: Sending TCP request to stream 127.0.0.1:43227
[26558] 1494229795.416195: Received answer from stream 127.0.0.1:43227
[26558] 1494229795.730533: Response was not from master KDC
[26558] 1494229795.730754: TGS reply didn't decode with subkey; trying 
session key (
[26558] 1494229795.730858: TGS reply is for drankye@TEST.COM -> 
test-service/localhost@TEST.COM with session key aes128-cts/B24D
[26558] 1494229795.730910: TGS request result: 0/Success
[26558] 1494229795.730919: Received creds for desired service 
test-service/localhost@TEST.COM
[26558] 1494229795.730935: Removing drankye@TEST.COM -> 
test-service/localhost@ from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
[26558] 1494229795.730947: Storing drankye@TEST.COM -> 
test-service/localhost@ in 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
[26558] 1494229795.731216: Also storing drankye@TEST.COM -> 
test-service/localhost@TEST.COM based on ticket
[26558] 1494229795.731231: Removing drankye@TEST.COM -> 
test-service/localhost@TEST.COM from 
FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
[26558] 1494229795.731541: Creating authenticator for drankye@TEST.COM 
-> test-service/localhost@, seqnum 682578751, subkey aes128-cts/6920, 
session key aes128-cts/B24D
[26558] 1494229795.731564: Negotiating for enctypes in authenticator: 
aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
First kerberos.authGSSClientStep successful

$ klist
Ticket cache: FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
Default principal: drankye@TEST.COM

Valid starting     Expires            Service principal
05/08/17 09:33:27  05/09/17 09:33:27 krbtgt/TEST.COM@TEST.COM
     renew until 05/09/17 09:33:27
05/08/17 09:49:55  05/09/17 09:33:27  test-service/localhost@
     renew until 05/09/17 09:33:27
05/08/17 09:49:55  05/09/17 09:33:27 test-service/localhost@TEST.COM
     renew until 05/09/17 09:33:27


Op 07-05-17 om 16:12 schreef Marc de Lignie:
> Hi Jiajia and Kai,
>
> Puzzled by the fact that the Mit Kerberos over python service ticket 
> request works on Jiajia's system but not on mine. I attempted to 
> request the service ticket with Mit Kerberos's kinit tool and .... it 
> worked.
>
> This means that my issue probably lies in the kerberos python wrapper 
> around the Mit Kerberos shared libs (or in the way how I use it). I 
> tried both with the Debian python-kerberos package, 
> https://pypi.python.org/pypi/kerberos and with 
> https://pypi.python.org/pypi/pykerberos/1.1.14, neither of which got 
> the ticket. This still makes me curious where Mac-OS gets its python 
> kerberos package from :-)
>
> Here, the kinit shell commands to reproduce my test.
>
> cd $PROJECTROOT
> WORKDIR=kerby-kerb/kerb-kdc-test/target/tmp
> export KRB5_CONFIG=$WORKDIR/krb5.conf
> export KRB5CCNAME=$WORKDIR/test-tkt.cc
> export KRB5_TRACE=/dev/stdout
>
> $ kinit -S test-service/localhost
> [3141] 1494161999.566468: Getting initial credentials for 
> drankye@TEST.COM
> [3141] 1494161999.566835: Setting initial creds service to 
> test-service/localhost
> [3141] 1494161999.566952: Sending request (168 bytes) to TEST.COM
> [3141] 1494161999.566997: Resolving hostname localhost
> [3141] 1494161999.567467: Sending initial UDP request to dgram 
> 127.0.0.1:45527
> [3141] 1494161999.573494: Received answer (555 bytes) from dgram 
> 127.0.0.1:45527
> [3141] 1494161999.576791: Response was not from master KDC
> [3141] 1494161999.576822: Salt derived from principal: TEST.COMdrankye
> [3141] 1494161999.576824: Getting AS key, salt "TEST.COMdrankye", 
> params ""
> Password for drankye@TEST.COM:
> [3141] 1494162015.450071: AS key obtained from gak_fct: aes128-cts/0548
> [3141] 1494162015.450101: Decrypted AS reply; session key is: 
> aes128-cts/4EFE
> [3141] 1494162015.450103: FAST negotiation: unavailable
> [3141] 1494162015.450112: Initializing 
> FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc with default 
> princ drankye@TEST.COM
> [3141] 1494162015.450305: Storing drankye@TEST.COM -> 
> test-service/localhost@TEST.COM in 
> FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
>
> $ klist
> Ticket cache: FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
> Default principal: drankye@TEST.COM
>
> Valid starting     Expires            Service principal
> 07-05-17 14:59:59  08-05-17 14:59:59 test-service/localhost@TEST.COM
>     renew until 08-05-17 14:59:59
>
> What is also notable here is that the TestKdc only produces one log 
> message:
>
> [nioEventLoopGroup-5-1] INFO 
> org.apache.kerby.kerberos.kerb.server.request.AsRequest - AS_REQ 
> ISSUE: authtime 1494164956766,drankye@TEST.COM for 
> test-service/localhost@TEST.COM
>
> while in the error situation from python it produces (and not the 
> AS_REQ line):
>
> [nioEventLoopGroup-5-1] INFO 
> org.apache.kerby.kerberos.kerb.server.request.KdcRequest - Found fast 
> padata and starting to process it.
> [nioEventLoopGroup-5-1] INFO 
> org.apache.kerby.kerberos.kerb.server.request.KdcRequest - Found fast 
> padata and starting to process it.
>
> Note also that kinit requires to give the password while in the python 
> testcase it is attempted to use the tgt from the credential cache.
>
> Maybe it also useful to restate my target: I want to authenticate a 
> python client towards a service using GSSAPI with SASL (the service 
> being gremlin-server from the Apache Tinkerpop project). So I want to 
> get the service ticket using GSSAPI and an existing tgt from the 
> credential cache.
>
> Any additional hints are welcome, good luck with the Kerby GA release.
>
> Marc
>
> Op 05-05-17 om 22:12 schreef Marc de Lignie:
>> 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/localhost@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\134@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/localhost@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\134@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.zheng@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.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
>>>
>>
>

-- 
Marc de Lignie


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message