directory-kerby mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Colm O hEigeartaigh <cohei...@apache.org>
Subject Re: MIT Kerberos compatibility
Date Fri, 05 May 2017 15:33:39 GMT
Hi Jiajia,

If UDP is disabled and we don't use Netty, I can get a token successfully
via kinit. However I then see an error message in the Kerby console:

Exception in thread "Thread-1" java.lang.RuntimeException: Error occured
while checking udp connections
    at
org.apache.kerby.kerberos.kerb.transport.KdcNetwork.run(KdcNetwork.java:105)
    at
org.apache.kerby.kerberos.kerb.transport.KdcNetwork.access$000(KdcNetwork.java:39)
    at
org.apache.kerby.kerberos.kerb.transport.KdcNetwork$1.run(KdcNetwork.java:75)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.nio.channels.ClosedChannelException
    at
sun.nio.ch.DatagramChannelImpl.ensureOpen(DatagramChannelImpl.java:320)
    at sun.nio.ch.DatagramChannelImpl.receive(DatagramChannelImpl.java:331)
    at
org.apache.kerby.kerberos.kerb.transport.KdcNetwork.checkUdpMessage(KdcNetwork.java:132)
    at
org.apache.kerby.kerberos.kerb.transport.KdcNetwork.run(KdcNetwork.java:101)

I'm not sure why we are seeing UDP errors when it's disabled?

Colm.

On Fri, May 5, 2017 at 3:57 PM, Li, Jiajia <jiajia.li@intel.com> wrote:

> Hi Colm,
> The shell client can't connect to kdc if the UDP is disabled.
> We don't use Netty in default.
> What's your test-cases? The same as the Marc's?
>
> Thanks
> Jiajia
>
> -----Original Message-----
> From: Colm O hEigeartaigh [mailto:coheigea@apache.org]
> Sent: Friday, May 5, 2017 10:09 PM
> To: kerby@directory.apache.org
> Cc: Zheng, Kai <kai.zheng@intel.com>; mailto:m.c.delignie@xs4all.nl <
> m.c.delignie@xs4all.nl>
> Subject: Re: MIT Kerberos compatibility
>
> Hi Jiajia,
>
> What are the issues if UDP is disabled and we don't use Netty? I tried
> doing this with my own test-cases and it didn't work, so it would be good
> to get this fixed soon.
>
> Colm.
>
> On Fri, May 5, 2017 at 2:46 PM, Li, Jiajia <jiajia.li@intel.com> wrote:
>
> > Hi Marc,
> > >>> - your KRB5 tracing looks quite different. What OS and
> > >>> mit-kerberos
> > version did you use?
> > I use mac os and the python version is 2.7.10
> >
> > >>>- your KRB5 tracing shows UDP comms between kerberos client and
> > >>>KDC,
> > despite the allowUDP = false setting
> > >>> in my test. I did this setting because I get different problems
> > without it, see the additional logs below. So,
> > >>>we must also be aware of networking problems at my side.
> > I enable the UDP and use netty network, there are some issues if UDP
> > disabled, you can create a JIRA for this and we can fix this issue in
> > the next release version.
> >
> > The changes in my side as following:
> >
> > protected boolean allowUdp() {
> >     return true;
> > }
> > @Override
> > protected void prepareKdc() throws KrbException {
> >     getKdcServer().setInnerKdcImpl(
> >             new NettyKdcServerImpl(getKdcServer().getKdcSetting()));
> >     super.prepareKdc();
> > }
> >
> > Here is log of MitIssueTest:
> > [INFO] Running org.apache.kerby.kerberos.kerb.server.MitIssueTest
> > [nioEventLoopGroup-2-1] INFO io.netty.handler.logging.LoggingHandler -
> > [id: 0x2634fe6b] REGISTERED
> > [nioEventLoopGroup-2-1] INFO io.netty.handler.logging.LoggingHandler -
> > [id: 0x2634fe6b] BIND(0.0.0.0/0.0.0.0:53957) [nioEventLoopGroup-2-1]
> > INFO io.netty.handler.logging.LoggingHandler -
> > [id: 0x2634fe6b, /0:0:0:0:0:0:0:0:53957] ACTIVE [main] INFO
> > org.apache.kerby.kerberos.kdc.impl.NettyKdcServerImpl - Netty kdc
> > server started.
> > [nioEventLoopGroup-2-1] INFO io.netty.handler.logging.LoggingHandler -
> > [id: 0x2634fe6b, /0:0:0:0:0:0:0:0:53957] RECEIVED: [id: 0xdac7228b, /
> > 127.0.0.1:53961 => /127.0.0.1:53957]
> > [defaultEventExecutorGroup-4-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest
> > - AS_REQ ISSUE: authtime 1493991123792,drankye@TEST.COM for krbtgt/
> > TEST.COM@TEST.COM [main] INFO
> > org.apache.kerby.kerberos.kerb.client.impl.DefaultInternalKrbClient
> > - Send to kdc success.
> > [main] INFO org.apache.kerby.kerberos.kerb.client.KrbClientBase -
> > Storing the tgt to the credential cache file.
> > [nioEventLoopGroup-5-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.KdcRequest
> > - The preauth data is empty.
> > [nioEventLoopGroup-5-1] INFO
> > org.apache.kerby.kerberos.kerb.server.KdcHandler
> > - KRB error occurred while processing request:Additional
> > pre-authentication required [nioEventLoopGroup-5-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest
> > - AS_REQ ISSUE: authtime 1493991123859,test-service/localhost@TEST.COM
> > for krbtgt/TEST.COM@TEST.COM
> > [nioEventLoopGroup-5-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.TgsRequest
> > - TGS_REQ ISSUE: authtime 1493991142850,drankye for test-service/
> > localhost@TEST.COM
> >
> > Thanks
> > Jiajia
> >
> > -----Original Message-----
> > From: Zheng, Kai
> > Sent: Friday, May 5, 2017 7:46 PM
> > To: kerby@directory.apache.org; Li, Jiajia <jiajia.li@intel.com>
> > Subject: RE: MIT Kerberos compatibility
> >
> > Hi Marc,
> >
> > Looks like this is quite environment related, could you fire an issue
> > for this? I would suggest we target it to 1.1.0, which can be done in
> June.
> >
> > Regards,
> > Kai
> >
> > -----Original Message-----
> > From: Marc de Lignie [mailto:m.c.delignie@xs4all.nl]
> > Sent: Friday, May 05, 2017 4:44 PM
> > To: Li, Jiajia <jiajia.li@intel.com>
> > Cc: kerby@directory.apache.org
> > Subject: Re: MIT Kerberos compatibility
> >
> > Hi Jiajia,
> >
> > Great to read that you made progress on this issue and to see a
> > working config at your side. Below, I list my progress below (with
> > trunk merged into my MitIssue branch), but I am afraid we are not done
> yet.
> >
> > Things that stand out:
> >
> > - the kdc decoding error is solved, relative to the logs without your
> > patch
> >
> > - your KRB5 tracing looks quite different. What OS and mit-kerberos
> > version did you use?
> >
> > - your KRB5 tracing shows UDP comms between kerberos client and KDC,
> > despite the allowUDP = false setting in my test. I did this setting
> > because I get different problems without it, see the additional logs
> > below. So, we must also be aware of networking problems at my side.
> >
> > - the "Response was not from master KDC" msg is not relevant; it
> > disappears if you manually add master_kdc to the realms section of the
> > krb5.conf
> >
> > I have no idea how to proceed from here, so that is why I just
> > document the status at my side and ask about your - apparently working -
> config.
> >
> > Cheers,   Marc
> >
> >
> > KDC logging with allowUDP = false:
> >
> > [INFO] Running org.apache.kerby.kerberos.kerb.server.MitIssueTest
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest - AS_REQ ISSUE:
> > authtime 1493970789075,drankye@TEST.COM for krbtgt/TEST.COM@TEST.COM
> > [main] INFO
> > org.apache.kerby.kerberos.kerb.client.impl.DefaultInternalKrbClient
> > - Send to kdc success.
> > [main] INFO org.apache.kerby.kerberos.kerb.client.KrbClientBase -
> > Storing the tgt to the credential cache file.
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.KdcRequest - The preauth
> > data is empty.
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.KdcHandler
> > - KRB error occurred while processing request:Additional
> > pre-authentication required [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest - AS_REQ ISSUE:
> > authtime 1493970789108,test-service/localhost@TEST.COM for krbtgt/
> > TEST.COM@TEST.COM [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.KdcRequest
> > - Found fast padata and starting to process it.
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.KdcRequest - Found fast
> > padata and starting to process it.
> >
> > Python script KRB5 tracing (MIT Kerberos 1.13.2 of Ubuntu Xenial) with
> > allowUDP = false:
> >
> > $ .
> > kerby-kerb/kerb-kdc-test/src/test/java/org/apache/kerby/
> > kerberos/kerb/server/MitIssueTest.sh
> > [25281] 1493970797.298753: 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 [25281]
> > 1493970797.298952: 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 [25281]
> > 1493970797.299106: 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 [25281]
> > 1493970797.299213: 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 [25281]
> > 1493970797.299323: 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 [25281]
> > 1493970797.299436: 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 [25281]
> > 1493970797.299545: 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 [25281]
> > 1493970797.299654: 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 [25281] 1493970797.299922:
> > Getting credentials drankye@TEST.COM -> test-service/localhost@ using
> > ccache FILE:kerby-kerb/kerb-kdc-test/target/tmp/test-tkt.cc
> > [25281] 1493970797.299945: 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 [25281] 1493970797.299959:
> > Retrying drankye@TEST.COM -> test-service/localhost@TEST.COM with
> result:
> > -1765328243/Matching credential not found [25281] 1493970797.299962:
> > Server has referral realm; starting with
> > test-service/localhost@TEST.COM [25281]
> > 1493970797.299975: 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 [25281] 1493970797.299979: Starting with TGT for client realm:
> > drankye@TEST.COM -> krbtgt/TEST.COM@TEST.COM [25281] 1493970797.299981:
> > Requesting tickets for test-service/localhost@TEST.COM, referrals on
> > [25281] 1493970797.299994: Generated subkey for TGS request:
> > aes128-cts/1B9B [25281] 1493970797.300009: etypes requested in TGS
> request:
> > aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts,
> > camellia256-cts [25281] 1493970797.300054: Encoding request body and
> > padata into FAST request [25281] 1493970797.300080: Sending request
> > (823 bytes) to TEST.COM [25281] 1493970797.300091: Resolving hostname
> > localhost [25281]
> > 1493970797.300136: Initiating TCP connection to stream
> > 127.0.0.1:34319
> > [25281] 1493970797.300191: Sending TCP request to stream
> > 127.0.0.1:34319 [25281] 1493970797.303610: Received answer (125 bytes)
> > from stream
> > 127.0.0.1:34319
> > [25281] 1493970797.303618: Terminating TCP connection to stream
> > 127.0.0.1:34319
> > [25281] 1493970797.553126: Response was not from master KDC [25281]
> > 1493970797.553198: TGS request result: -1765323383/Unknown code krcM
> > 137 [25281] 1493970797.553234: Requesting tickets for test-service/
> > localhost@TEST.COM, referrals off [25281] 1493970797.553273: Generated
> > subkey for TGS request: aes128-cts/94C6 [25281] 1493970797.553323:
> > etypes requested in TGS request: aes256-cts, aes128-cts,
> > des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts [25281]
> > 1493970797.553436: Encoding request body and padata into FAST request
> [25281] 1493970797.553532:
> > Sending request (823 bytes) to TEST.COM [25281] 1493970797.553567:
> > Resolving hostname localhost [25281] 1493970797.553745: Initiating TCP
> > connection to stream
> > 127.0.0.1:34319
> > [25281] 1493970797.553889: Sending TCP request to stream
> > 127.0.0.1:34319 [25281] 1493970797.558297: Received answer (125 bytes)
> > from stream
> > 127.0.0.1:34319
> > [25281] 1493970797.558318: Terminating TCP connection to stream
> > 127.0.0.1:34319
> > [25281] 1493970797.561189: Response was not from master KDC [25281]
> > 1493970797.561258: TGS request result: -1765323383/Unknown code krcM
> > 137 ('First kerberos.authGSSClientStep not successful',
> > GSSError(('Unspecified GSS failure.  Minor code may provide more
> > information', 851968), ('Unknown code krcM 137', -1765323383)))
> >
> >
> > KDC logging with allowUDP = true:
> >
> > [INFO] Running org.apache.kerby.kerberos.kerb.server.MitIssueTest
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest - AS_REQ ISSUE:
> > authtime 1493972505784,drankye@TEST.COM for krbtgt/TEST.COM@TEST.COM
> > [main] INFO
> > org.apache.kerby.kerberos.kerb.client.impl.DefaultInternalKrbClient
> > - Send to kdc success.
> > [main] INFO org.apache.kerby.kerberos.kerb.client.KrbClientBase -
> > Storing the tgt to the credential cache file.
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.request.KdcRequest - The preauth
> > data is empty.
> > [pool-1-thread-1] INFO
> > org.apache.kerby.kerberos.kerb.server.KdcHandler
> > - KRB error occurred while processing request:Additional
> > pre-authentication required [pool-1-thread-2] INFO
> > org.apache.kerby.kerberos.kerb.server.request.AsRequest - AS_REQ ISSUE:
> > authtime 1493972505948,test-service/localhost@TEST.COM for krbtgt/
> > TEST.COM@TEST.COM Exception in thread "Thread-0"
> > java.lang.RuntimeException: Error occured while checking udp connections
> >      at
> > org.apache.kerby.kerberos.kerb.transport.KdcNetwork.run(
> > KdcNetwork.java:105)
> >      at
> > org.apache.kerby.kerberos.kerb.transport.KdcNetwork.
> > access$000(KdcNetwork.java:39)
> >      at
> > org.apache.kerby.kerberos.kerb.transport.KdcNetwork$1.
> > run(KdcNetwork.java:75)
> >      at java.lang.Thread.run(Thread.java:748)
> > Caused by: java.nio.channels.ClosedChannelException
> >      at
> > sun.nio.ch.DatagramChannelImpl.ensureOpen(DatagramChannelImpl.java:320)
> >      at sun.nio.ch.DatagramChannelImpl.receive(
> > DatagramChannelImpl.java:331)
> >      at
> > org.apache.kerby.kerberos.kerb.transport.KdcNetwork.
> > checkUdpMessage(KdcNetwork.java:132)
> >      at
> > org.apache.kerby.kerberos.kerb.transport.KdcNetwork.run(
> > KdcNetwork.java:101)
> >      ... 3 more
> >
> >
> > krb5.conf:
> >
> > [libdefaults]
> >      kdc_realm = TEST.COM
> >      default_realm = TEST.COM
> >      udp_preference_limit = 4096
> >      kdc_tcp_port = 37080
> >      kdc_udp_port = 36525
> >
> > [realms]
> >      TEST.COM = {
> >          kdc = localhost:36525
> >      }
> >
> > And port 36525 does not show up in `netstat -l` (while 37080 does)
> >
> >
> > 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/ker
> > > b/
> > > 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@
> > > TE
> > > ST.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/ke
> > >> rb / 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.kdcFindFas
> > >> t(
> > 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
> >
> >
>
>
> --
> Colm O hEigeartaigh
>
> Talend Community Coder
> http://coders.talend.com
>



-- 
Colm O hEigeartaigh

Talend Community Coder
http://coders.talend.com

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