directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Zheng, Kai" <kai.zh...@intel.com>
Subject RE: strange kerberos issue with apacheds
Date Tue, 09 Jun 2015 02:18:02 GMT
Thanks Sangjin for the good report. I thought you’re right in the analysis.

I’m not familiar with the part but it looks like not easy to have a work around. Maybe we
can force to use UDP transport thus bypass the problem?

Regards,
Kai

From: sjlee0@gmail.com [mailto:sjlee0@gmail.com] On Behalf Of Sangjin Lee
Sent: Tuesday, June 09, 2015 9:18 AM
To: dev@directory.apache.org
Subject: Re: strange kerberos issue with apacheds

Correction: hadoop is using Apache DS 2.0.0-M15 with Mina 2.0.0-M5. Sorry for the confusion.

On Mon, Jun 8, 2015 at 3:45 PM, Sangjin Lee <sjlee@apache.org<mailto:sjlee@apache.org>>
wrote:
Hi,

This might be a known issue, but I was not able to find discussions on this anywhere...

I stumbled on an interesting issue with kerberos authentication failure with an Apache DS
server while debugging a hadoop unit test failure. FYI, hadoop is using Apache DS 1.0.0-M20
with Mina 2.0.0-M15. This problem is happening on some machines but not on others.

Basically, a kerberos message to the Apache DS server is failing with the following exception:
2015-06-08 20:35:57,189 ERROR KerberosProtocolHandler - /127.0.0.1:54477<http://127.0.0.1:54477>
EXCEPTION
org.apache.mina.filter.codec.ProtocolDecoderException: java.lang.NullPointerException: message
(Hexdump: ...)
        at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:234)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:48)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:802)
        at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:120)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
        at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:604)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:564)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:553)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:57)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:892)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:65)
        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.lang.NullPointerException: message
        at org.apache.mina.filter.codec.AbstractProtocolDecoderOutput.write(AbstractProtocolDecoderOutput.java:44)
        at org.apache.directory.server.kerberos.protocol.codec.MinaKerberosDecoder.decode(MinaKerberosDecoder.java:65)
        at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:224)
        ... 15 more


I traced it down to a rather silent failure of Asn1Decoder. Basically the ASN.1 decoder thinks
the byte buffer it is passed does not have the promised size payload and aborts parsing:
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - >>>==========================================
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --> Decoding a PDU
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - >>>------------------------------------------
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --- State = TAG_STATE_START ---
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x6C
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - Tag 0x6C has been decoded
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --- State = LENGTH_STATE_START ---
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x82
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --- State = LENGTH_STATE_PENDING ---
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x02
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x02
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x41
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --- State = LENGTH_STATE_END ---
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x30
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - Parent length : TLV expected length stack :  -
null
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - Root TLV[577]
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - Length 577 has been decoded
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - --- State = VALUE_STATE_START ---
2015-06-08 20:35:57,187 DEBUG Asn1Decoder -   current byte : 0x30
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - <<<------------------------------------------
2015-06-08 20:35:57,187 DEBUG Asn1Decoder - <-- End decoding : TLV[ 0x6C, 577, DATA[...
]]


Here's an interesting thing however. The reason the buffer has fewer bytes than the length
value indicates is that the TCP message is split into 2 packets due to a small TCP window
size on this problematic machine. For the kerberos message of size 585 bytes, the first 570
bytes are sent in the first packet, and the remaining 15 bytes in another packet. The Asn1Decoder
thinks that it is missing the last 15 bytes and aborts decoding it.

Having small TCP window sizes aside, this strikes me as a code issue. Shouldn't the server
be able to handle the kerberos message even if it is split into multiple packets? Is this
a known issue with a workaround/solution?

I looked at MinaKerberosDecoder, and see it extend ProtocolDecoderAdapter. But shouldn't it
extend CumulativeProtocolDecoder to be able to handle situations like this?

Thanks in advance,
Sangjin

Mime
View raw message