[Freeipa-devel] slow response

[Stephen Ingram]

On Thu, Aug 2, 2012 at 10:33 AM, Rich Megginson <rmeggins at redhat.com> wrote:
> On 08/02/2012 11:29 AM, Stephen Ingram wrote:
>>
>> On Thu, Aug 2, 2012 at 10:23 AM, Simo Sorce<simo at redhat.com>  wrote:
>>>
>>> On Thu, 2012-08-02 at 10:17 -0700, Stephen Ingram wrote:
>>>>
>>>> On Wed, Aug 1, 2012 at 7:35 AM, Simo Sorce<simo at redhat.com>  wrote:
>>>>>
>>>>> On Tue, 2012-07-31 at 08:49 -0700, Stephen Ingram wrote:
>>>>>>
>>>>>> On Tue, Jul 31, 2012 at 1:39 AM, Petr Spacek<pspacek at redhat.com>
>>>>>> wrote:
>>>>>>>
>>>>>>> On 07/31/2012 12:27 AM, John Dennis wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>> What is taking so long with session bookkeeping? I don't know yet. I
>>>>>>>> would
>>>>>>>> need more timing instrumentation. I will say when I looked at the
>>>>>>>> python-krb5
>>>>>>>> code (which we use to populate the ccache from the session and read
>>>>>>>> back
>>>>>>>> to
>>>>>>>> store in the session) seemed to be remarkably inefficient. We also
>>>>>>>> elected
>>>>>>>> to
>>>>>>>> use file based ccache rather than in-memory ccache (that means there
>>>>>>>> is a
>>>>>>>> bit
>>>>>>>> of file-IO occurring).
>>>>>>>
>>>>>>>
>>>>>>> A note regarding python-krbV:
>>>>>>> I used python-krbV extensively in my thesis for KDC stress test.
>>>>>>> Python-krbV
>>>>>>> can obtain several thousands of TGTs per second (even with ccache in
>>>>>>> a
>>>>>>> file). AFAIK VFS calls are not done synchronously. But others parts
>>>>>>> of
>>>>>>> python-krbV were left uncovered, so it can contain some surprises.
>>>>>>>
>>>>>>> === Wild speculation follows ===
>>>>>>> 1.5 second is incredibly long time, it sounds like some kind of
>>>>>>> timeout.
>>>>>>> Krb5 libs have usual timeout = 1 second per request.
>>>>>>>
>>>>>>> Are all KDCs in /etc/krb5.conf alive and reachable?
>>>>>>
>>>>>> In this case, as I'm referring to the extreme slowness of the Web UI,
>>>>>> the KDC is on the same system (the ipa server) that is making the
>>>>>> request, correct?
>>>>>>
>>>>>>> Is SSSD running on problematic server?
>>>>>>
>>>>>> Yes. Again, I'm guessing the problematic server is the IPA server
>>>>>> itself.
>>>>>>
>>>>>>> Is proper KDC selected by SSSD KDC auto-locator plugin?
>>>>>>> (See /var/lib/sss/pubconf/)
>>>>>>
>>>>>> Yes, I checked that file and it is the IP address of the IPA server on
>>>>>> the same server. Perhaps should this be 127.0.0.1 instead?
>>>>>>
>>>>>> I also have checked the resolv.conf file, and indeed the IP points to
>>>>>> the IPA server itself (same machine) as expected. Both forward and
>>>>>> reverse DNS work. I'm not really sure what else could be setup
>>>>>> incorrectly to cause any KDC slowness.
>>>>>>
>>>>>> Due to the extreme UI slowness issue, I have not created any replicas
>>>>>> so this system is it. I'm not so sure I would be able to see the 1.5 s
>>>>>> delay if it weren't compounded by the overall slowness of the Web UI,
>>>>>> however, the KDC seems to perform well for other systems in the realm.
>>>>>> I'm certainly not taxing it with a huge load, but tickets seem to be
>>>>>> issued without delay.
>>>>>
>>>>> Stephen,
>>>>> another user sent me a wireshark trace for a similar performance issue.
>>>>> So far I see a pause when doing the first leg of a SASL authentication.
>>>>> This may well explain also your issue.
>>>>>
>>>>> Can you test connecting to the ldap server using ldapsearch -Y GSSAPI
>>>>> (you need a kerberos ticket) and telling me if you experience any
>>>>> delay ?
>>>>> If you could run a bunch of searches in a loop and take a wireshark
>>>>> trace that may help analyzing the timings and seeing if there is a
>>>>> correlation.
>>>>
>>>> I've done this. It looks like this delay has been uncovered already
>>>> though? I can still send you the dump privately if you think it would
>>>> help.
>>>
>>> I think we reproduced it, can you confirm you are also running on RHEL ?
>>> So far it seem the only platfrom we can reproduce is RHEL 6.3
>>
>>
>> Yes, I'm running RHEL 6.3. I just ran the command in the BZ and it
>> takes 1.542s for me. What are Z-stream packages?
>
>
> They are packages delivered between minor RHEL releases e.g. between RHEL
> 6.3 and RHEL 6.4 - the 389-ds-base package released with RHEL 6.3 was
> 389-ds-base-1.2.10.2-15.el6 - since RHEL 6.3, we released some bugfix
> packages, and the latest is now 389-ds-base-1.2.10.2-20.el6_3 - note the
> "_3" at the end - this means it is a bugfix release for RHEL 6.3 -
> "Z-stream" is just Red Hat terminology for a package released between minor
> RHEL releases - the "Z" stands for the "Z" in the versioning scheme "X.Y.Z"

Got it. We are using those packages now. Although this might or might
not be the cause of the slow Web UI, the Web UI has been slow since
the initial 6.3 release. If this 389 slowness was only introduced in
the Z-stream 389ds, then it is likely not, or not the only, cause of
the Web UI slowness.

Steve