directory-kerby mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Li, Jiajia" <jiajia...@intel.com>
Subject RE: [Kerby] TGS req failing with "Unexpected item context"
Date Wed, 14 Jun 2017 02:41:34 GMT
Hi all,
I have some fix for this issue, could anyone help me to check it using your test env? 

Commit log is:
commit a6224d2cf60e8e18ba5e307f1a4a2bc4c01a55b4
Author: plusplusjiajia <jiajia.li@intel.com>
Date:   Wed Jun 14 10:43:46 2017 +0800

    Fix DIRKRB-614 and DIRKRB-631.

Thanks
Jiajia

-----Original Message-----
From: Marc de Lignie [mailto:m.c.delignie@xs4all.nl] 
Sent: Thursday, June 8, 2017 8:10 PM
To: kerby@directory.apache.org
Subject: Re: [Kerby] TGS req failing with "Unexpected item context"

Hi Kai,

See, my original logs from both the python client and the KDC at (this link is also present
in DIRKRB-631):

http://mail-archives.apache.org/mod_mbox/directory-kerby/201705.mbox/browser

Here, the logs of the python client coincide with Pratyush's report in the current thread.
The logs of the KDC coincide with the old
DIRKKRB-614 issue.

I would say all reports are related to the same error, Kerby not being able the decode the
FAST OTP requests of MIT Kerberos 1.11+. Also, all are related to a TGS request based on an
existing TGT.

Cheers,    Marc


Op 06-06-17 om 21:07 schreef Marc de Lignie:
> Dear all,
>
> My bad, it seems I made a separate issue for this, which might add 
> more details to DIRKRB-614 and might help you in finding the decode
> error:
>
> https://issues.apache.org/jira/browse/DIRKRB-631
>
> The workaround I mentioned is there, in the comments.
>
> Cheers,   Marc
>
>
> Op 06-06-17 om 21:02 schreef Marc de Lignie:
>> Pratjush,
>>
>> I just posted a temporary workaround as a comment below:
>>
>> https://issues.apache.org/jira/browse/DIRKRB-614
>>
>> Cheers,    Marc
>>
>>
>> Kai wrote:
>>
>> It seems so and we need to fix it. However, I don't see any obvious 
>> cause for it. Hope we can get to this sooner (should be next week) 
>> after some deadline is caught. Sorry for the late.
>>
>> Regards,
>> Kai
>>
>> -----Original Message-----
>> From: Colm O hEigeartaigh [mailto:coheigea@apache.org]
>> Sent: Monday, June 05, 2017 12:04 AM
>> To: kerby@directory.apache.org
>> Subject: Re: [Kerby] TGS req failing with "Unexpected item context"
>>
>> Looks like you're running into this known issue:
>>
>> https://issues.apache.org/jira/browse/DIRKRB-614
>>
>> Colm.
>>
>> On Sat, Jun 3, 2017 at 8:09 PM, pratyush parimal 
>> <pratyush.parimal@gmail.com
>>> wrote:
>>
>>> Hi everyone,
>>>
>>> I'm writing a simple Java program that stands up a KDC using the 
>>> SimpleKdcServer class, and I'm trying to use it for AS & TGS 
>>> operations. Relevant code is below:
>>>
>>>         kdc = new SimpleKdcServer(); 
>>> kdc.setKdcHost("kdc.example.com");
>>> kdc.setKdcPort(60088);
>>> kdc.setKdcRealm("EXAMPLE.COM");
>>>
>>> kdc.setAllowUdp(false);
>>> kdc.setWorkDir(keytabFile.getParentFile());
>>>
>>> kdc.init();
>>>
>>> kdc.createPrincipal("u1@EXAMPLE.COM", "u1pwd"); 
>>> kdc.createPrincipal("myservice/kdc.example.com@EXAMPLE.COM",
>>> "myservicepwd");
>>>
>>> kdc.start();
>>>
>>> I use kinit to fetch the TGT for my principal "u1" and that's 
>>> successful.
>>> However, the subsequent TGS req from my client program fails with 
>>> the
>>> error:
>>>
>>> GSSAPI continuation error: Unknown code krcM 137
>>>
>>> . I debugged through the source code for Kerby and saw that the full 
>>> exception was not getting thrown because of a (e instanceof
>>> KdcRecoverableException) check. When I print the stacktrace via a 
>>> debugger, I see the following (apologies for the huge stack trace):
>>>
>>> [pool-1-thread-1] INFO
>>> org.apache.kerby.kerberos.kerb.server.request.KdcRequest - Found 
>>> fast padata and starting to process it.
>>> 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:213)
>>> at
>>> org.apache.kerby.kerberos.kerb.server.request.
>>> KdcRequest.process(KdcRequest.java:170)
>>> at
>>> org.apache.kerby.kerberos.kerb.server.KdcHandler.
>>> handleMessage(KdcHandler.java:116)
>>> 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:1145)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(
>>> ThreadPoolExecutor.java:615)
>>> at java.lang.Thread.run(Thread.java:745)
>>> Caused by: java.io.IOException: Unexpected item context [0] 
>>> [tag=0xA0, off=0, len=3+198], expecting 0x30 at 
>>> org.apache.kerby.asn1.type.Asn1Encodeable.decode(
>>> Asn1Encodeable.java:219)
>>> at org.apache.kerby.asn1.type.Asn1Encodeable.decode(
>>> Asn1Encodeable.java:207)
>>> at org.apache.kerby.kerberos.kerb.KrbCodec.decode(KrbCodec.java:83)
>>> ... 9 more
>>> 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:213)
>>> at
>>> org.apache.kerby.kerberos.kerb.server.request.
>>> KdcRequest.process(KdcRequest.java:170)
>>> at
>>> org.apache.kerby.kerberos.kerb.server.KdcHandler.
>>> handleMessage(KdcHandler.java:116)
>>> 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:1145)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(
>>> ThreadPoolExecutor.java:615)
>>> at java.lang.Thread.run(Thread.java:745)
>>> Caused by: java.io.IOException: Unexpected item context [0] 
>>> [tag=0xA0, off=0, len=3+198], expecting 0x30 at 
>>> org.apache.kerby.asn1.type.Asn1Encodeable.decode(
>>> Asn1Encodeable.java:219)
>>> at org.apache.kerby.asn1.type.Asn1Encodeable.decode(
>>> Asn1Encodeable.java:207)
>>> at org.apache.kerby.kerberos.kerb.KrbCodec.decode(KrbCodec.java:83)
>>> ... 9 more
>>>
>>> The client program (and also kinit) were using the krb5.conf that 
>>> was auto-generated by the SimpleKdcServer in the workdir, and looked 
>>> like the following (I just replaced localhost with the FQDN of my
>>> machine):
>>>
>>> [libdefaults]
>>>     kdc_realm = EXAMPLE.COM
>>>     default_realm = EXAMPLE.COM
>>>     udp_preference_limit = 1
>>>     kdc_tcp_port = 60088
>>>     #_KDC_UDP_PORT_
>>>
>>> [realms]
>>>     EXAMPLE.COM = {
>>>         kdc = kdc.example.com:60088
>>>     }
>>>
>>> I had also enabled KRB5_TRACE on my client program that was making 
>>> the TGS req, and it shows the following:
>>>
>>>
>>> [1588796] 1496515969.488037: ccselect can't find appropriate cache 
>>> for server principal myservice/kdc.example.com@ [1588796]
>>> 1496515969.488112: Getting credentials u1@EXAMPLE.COM -> 
>>> myservice/kdc.example.com@ using ccache FILE:/tmp/krb5cc_20474 
>>> [1588796] 1496515969.488170: Retrieving u1@EXAMPLE.COM -> 
>>> myservice/kdc.example.com@ from FILE:/tmp/krb5cc_20474 with result:
>>> -1765328243/Matching credential not found (filename: 
>>> /tmp/krb5cc_20474) [1588796] 1496515969.488206: Retrying 
>>> u1@EXAMPLE.COM -> myservice/ kdc.example.com@EXAMPLE.COM with
>>> result: -1765328243/Matching credential not found (filename: 
>>> /tmp/krb5cc_20474) [1588796] 1496515969.488214: Server has referral 
>>> realm; starting with myservice/kdc.example.com@EXAMPLE.COM
>>> [1588796] 1496515969.488250: Retrieving u1@EXAMPLE.COM -> krbtgt/ 
>>> EXAMPLE.COM@EXAMPLE.COM from FILE:/tmp/krb5cc_20474 with result:
>>> 0/Success [1588796] 1496515969.488259: Starting with TGT for client
>>> realm:
>>> u1@EXAMPLE.COM -> krbtgt/EXAMPLE.COM@EXAMPLE.COM [1588796]
>>> 1496515969.488266: Requesting tickets for myservice/ 
>>> kdc.example.com@EXAMPLE.COM, referrals on [1588796]
>>> 1496515969.488298: Generated subkey for TGS request:
>>> aes128-cts/476E
>>> [1588796] 1496515969.488345: etypes requested in TGS request: 
>>> aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, 
>>> camellia256-cts [1588796] 1496515969.488460: Encoding request body 
>>> and padata into FAST request [1588796] 1496515969.488522: Sending 
>>> request (835 bytes) to EXAMPLE.COM [1588796] 1496515969.488553:
>>> Resolving hostname kdc.example.com [1588796] 1496515969.488621: 
>>> Initiating TCP connection to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.488682: Sending TCP request to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.492213: Received answer (134 bytes) from stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.492222: Terminating TCP connection to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.492292: Response was not from master KDC 
>>> [1588796] 1496515969.492309: TGS request result: -1765323383/Unknown 
>>> code krcM 137 [1588796] 1496515969.492332: Requesting tickets for 
>>> myservice/ kdc.example.com@EXAMPLE.COM, referrals off [1588796]
>>> 1496515969.492351: Generated subkey for TGS request:
>>> aes128-cts/AECC
>>> [1588796] 1496515969.492377: etypes requested in TGS request: 
>>> aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, 
>>> camellia256-cts [1588796] 1496515969.492430: Encoding request body 
>>> and padata into FAST request [1588796] 1496515969.492483: Sending 
>>> request (835 bytes) to EXAMPLE.COM [1588796] 1496515969.492493:
>>> Resolving hostname kdc.example.com [1588796] 1496515969.492543: 
>>> Initiating TCP connection to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.492586: Sending TCP request to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.496886: Received answer (134 bytes) from stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.496894: Terminating TCP connection to stream
>>> 172.17.0.53:60088
>>> [1588796] 1496515969.496948: Response was not from master KDC 
>>> [1588796] 1496515969.496963: TGS request result: -1765323383/Unknown 
>>> code krcM 137
>>>
>>>
>>> I've tried the same scenario with the MIT krb5kdc service with the 
>>> same principals, and the TGS req is successful, with the trace log:
>>>
>>> [1590761] 1496516355.23070: ccselect module realm chose cache
>>> FILE:/tmp/krb5cc_20474 with client principal u1@EXAMPLE.COM for 
>>> server principal myservice/kdc.example.com@EXAMPLE.COM
>>> [1590761] 1496516355.23150: Getting credentials u1@EXAMPLE.COM -> 
>>> myservice/ kdc.example.com@EXAMPLE.COM using ccache
>>> FILE:/tmp/krb5cc_20474 [1590761] 1496516355.23212: Retrieving 
>>> u1@EXAMPLE.COM -> myservice/ kdc.example.com@EXAMPLE.COM from
>>> FILE:/tmp/krb5cc_20474 with result:
>>> -1765328243/Matching credential not found (filename: 
>>> /tmp/krb5cc_20474) [1590761] 1496516355.23260: Retrieving 
>>> u1@EXAMPLE.COM -> krbtgt/ EXAMPLE.COM@EXAMPLE.COM from
>>> FILE:/tmp/krb5cc_20474 with result: 0/Success [1590761]
>>> 1496516355.23269: Starting with
>> TGT for client realm:
>>> u1@EXAMPLE.COM -> krbtgt/EXAMPLE.COM@EXAMPLE.COM [1590761]
>>> 1496516355.23277: Requesting tickets for myservice/ 
>>> kdc.example.com@EXAMPLE.COM, referrals on [1590761]
>>> 1496516355.23312: Generated subkey for TGS request:
>>> aes256-cts/3F0A
>>> [1590761] 1496516355.23368: etypes requested in TGS request: 
>>> aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, 
>>> camellia256-cts [1590761] 1496516355.23485: Encoding request body 
>>> and padata into FAST request [1590761] 1496516355.23552: Sending 
>>> request (933 bytes) to EXAMPLE.COM [1590761] 1496516355.23581:
>>> Resolving hostname kdc.example.com [1590761] 1496516355.23651: 
>>> Sending initial UDP request to dgram
>>> 172.17.0.53:88
>>> [1590761] 1496516355.24205: Received answer (912 bytes) from dgram
>>> 172.17.0.53:88
>>> [1590761] 1496516355.24223: Response was not from master KDC 
>>> [1590761] 1496516355.24240: Decoding FAST response [1590761]
>>> 1496516355.24334: FAST reply key: aes256-cts/8818 [1590761]
>>> 1496516355.24376: TGS reply is for u1@EXAMPLE.COM -> myservice/ 
>>> kdc.example.com@EXAMPLE.COM with session key aes256-cts/126E 
>>> [1590761] 1496516355.24390: TGS request result: 0/Success [1590761]
>>> 1496516355.24395: Received creds for desired service myservice/ 
>>> kdc.example.com@EXAMPLE.COM [1590761] 1496516355.24401: Storing 
>>> u1@EXAMPLE.COM -> myservice/ kdc.example.com@EXAMPLE.COM in
>>> FILE:/tmp/krb5cc_20474 [1590761] 1496516355.24517: Retrieving 
>>> u1@EXAMPLE.COM -> krbtgt/ EXAMPLE.COM@EXAMPLE.COM from
>>> FILE:/tmp/krb5cc_20474 with result: 0/Success [1590761]
>>> 1496516355.24528: Get cred via TGT krbtgt/ EXAMPLE.COM@EXAMPLE.COM 
>>> after requesting krbtgt/EXAMPLE.COM@EXAMPLE.COM (canonicalize off) 
>>> [1590761] 1496516355.24546: Generated subkey for TGS request:
>>> aes256-cts/0D91
>>> [1590761] 1496516355.24574: etypes requested in TGS request: 
>>> aes256-cts [1590761] 1496516355.24633: Encoding request body and 
>>> padata into FAST request [1590761] 1496516355.24689: Sending request
>>> (931 bytes) to EXAMPLE.COM [1590761] 1496516355.24699: Resolving 
>>> hostname kdc.example.com [1590761] 1496516355.24750: Sending initial 
>>> UDP request to dgram
>>> 172.17.0.53:88
>>> [1590761] 1496516355.25098: Received answer (900 bytes) from dgram
>>> 172.17.0.53:88
>>> [1590761] 1496516355.25115: Response was not from master KDC 
>>> [1590761] 1496516355.25127: Decoding FAST response [1590761]
>>> 1496516355.25198: FAST reply key: aes256-cts/03AB [1590761]
>>> 1496516355.25234: TGS reply is for u1@EXAMPLE.COM -> krbtgt/ 
>>> EXAMPLE.COM@EXAMPLE.COM with session key aes256-cts/A423 [1590761]
>>> 1496516355.25246: Got cred; 0/Success [1590761] 1496516355.25315: 
>>> Creating authenticator for u1@EXAMPLE.COM -> 
>>> myservice/kdc.example.com@EXAMPLE.COM, seqnum 751690771, subkey 
>>> aes256-cts/91D0, session key aes256-cts/126E
>>>
>>>
>>>
>>> My best guess is that maybe I'm missing some configuration steps in 
>>> my Java code and that's causing the FAST request to fail. I couldn't 
>>> find any code examples for kerby anywhere which can help me with my 
>>> use case. Does anyone have any ideas about the above?
>>>
>>> Apologies again for the long email, just wanted to share my trials 
>>> so far.
>>> Have a nice weekend.
>>>
>>> Cheers,
>>> Pratyush
>>>
>>
>>
>>
>> --
>> Colm O hEigeartaigh
>>
>> Talend Community Coder
>> http://coders.talend.com
>>
>

--
Marc de Lignie

Mime
View raw message