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:cohei...@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.pari...@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("u...@example.com", "u1pwd");
kdc.createPrincipal("myservice/kdc.example....@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 u...@example.com ->
myservice/kdc.example.com@ using ccache FILE:/tmp/krb5cc_20474
[1588796] 1496515969.488170: Retrieving u...@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
u...@example.com -> myservice/ kdc.example....@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....@example.com
[1588796] 1496515969.488250: Retrieving u...@example.com -> krbtgt/
example....@example.com from FILE:/tmp/krb5cc_20474 with result:
0/Success [1588796] 1496515969.488259: Starting with TGT for client
realm:
u...@example.com -> krbtgt/example....@example.com [1588796]
1496515969.488266: Requesting tickets for myservice/
kdc.example....@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....@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 u...@example.com for
server principal myservice/kdc.example....@example.com
[1590761] 1496516355.23150: Getting credentials u...@example.com ->
myservice/ kdc.example....@example.com using ccache
FILE:/tmp/krb5cc_20474 [1590761] 1496516355.23212: Retrieving
u...@example.com -> myservice/ kdc.example....@example.com from
FILE:/tmp/krb5cc_20474 with result:
-1765328243/Matching credential not found (filename:
/tmp/krb5cc_20474) [1590761] 1496516355.23260: Retrieving
u...@example.com -> krbtgt/ example....@example.com from
FILE:/tmp/krb5cc_20474 with result: 0/Success [1590761]
1496516355.23269: Starting with
TGT for client realm:
u...@example.com -> krbtgt/example....@example.com [1590761]
1496516355.23277: Requesting tickets for myservice/
kdc.example....@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 u...@example.com -> myservice/
kdc.example....@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....@example.com [1590761] 1496516355.24401: Storing
u...@example.com -> myservice/ kdc.example....@example.com in
FILE:/tmp/krb5cc_20474 [1590761] 1496516355.24517: Retrieving
u...@example.com -> krbtgt/ example....@example.com from
FILE:/tmp/krb5cc_20474 with result: 0/Success [1590761]
1496516355.24528: Get cred via TGT krbtgt/ example....@example.com
after requesting krbtgt/example....@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 u...@example.com -> krbtgt/
example....@example.com with session key aes256-cts/A423 [1590761]
1496516355.25246: Got cred; 0/Success [1590761] 1496516355.25315:
Creating authenticator for u...@example.com ->
myservice/kdc.example....@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
