directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Kiran Ayyagari <kayyag...@apache.org>
Subject Re: strange kerberos issue with apacheds
Date Tue, 09 Jun 2015 08:20:39 GMT
On Tue, Jun 9, 2015 at 12:28 PM, Sangjin Lee <sjlee@apache.org> wrote:

> Thanks folks. I filed DIRSERVER-2071:
> https://issues.apache.org/jira/browse/DIRSERVER-2071
>
thanks for the bug report, I have committed the fix in trunk, would it be
possible for you to give a try?

>
> Sangjin
>
> On Mon, Jun 8, 2015 at 8:16 PM, Kiran Ayyagari <kayyagari@apache.org>
> wrote:
>
>> Hi Sangjin,
>>
>> On Tue, Jun 9, 2015 at 6:45 AM, Sangjin Lee <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
>>> 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?
>>>
>> the current ASN.1 decoder is supposed to handle this case, can you file a
>> bug, I will take a look
>>
>>>
>>> Thanks in advance,
>>> Sangjin
>>>
>>
>>
>>
>> --
>> Kiran Ayyagari
>> http://keydap.com
>>
>
>


-- 
Kiran Ayyagari
http://keydap.com

Mime
View raw message