Too Much Context Switching? - FIXED

[alex at schnarff.com]

Quoting Kris Kennaway <kris at FreeBSD.org>:

> alex at schnarff.com wrote:
>> Quoting Kris Kennaway <kris at FreeBSD.org>:
>>
>>> alex at schnarff.com wrote:
>>>> Quoting Kris Kennaway <kris at FreeBSD.org>:
>>>>
>>>>> Michel Talon wrote:
>>>>>> On Mon, Jun 30, 2008 at 07:53:00PM +0200, Kris Kennaway wrote:
>>>>>>> Yep, it could be that -- what confuses me though is that it is 
>>>>>>> claimed that performance suddenly regressed.  If so then this 
>>>>>>> cannot be the underlying cause.
>>>>>>
>>>>>> It may be that the load has augmented to the point that contention
>>>>>> imposes a rapid regression on throughput.
>>>>>
>>>>> Yes, it could be that.  I don't know off-hand whether multiple threads
>>>>> are counted separately by vmstat (at a guess I'd say no), but ps/top/etc
>>>>> should show how many are active in the python process.
>>>>
>>>> Just ran ktrace, and a bit of Googling seems to confirm my initial 
>>>> suspicion that the results I'm seeing are abnormal. The first 
>>>> several screenfulls of output look like this:
>>>>
>>>>  52929 python2.4 1214867016.469416 CALL  kse_wakeup(0x811740c)
>>>>  52929 python2.4 0.000060 RET   kse_wakeup 0
>>>>  52929 python2.4 0.000008 RET   kse_release 0
>>>>  52929 python2.4 0.000040 CALL  kse_release(0x811df4c)
>>>>  52929 python2.4 0.000515 CALL  kse_wakeup(0x811740c)
>>>>  52929 python2.4 0.000012 RET   kse_wakeup 0
>>>>  52929 python2.4 0.000004 RET   kse_release 0
>>>>  52929 python2.4 0.000012 CALL  kse_release(0x811df4c)
>>>>  52929 python2.4 0.000365 CALL  kse_wakeup(0x811740c)
>>>>  52929 python2.4 0.000012 RET   kse_wakeup 0
>>>>  52929 python2.4 0.000003 RET   kse_release 0
>>>>  52929 python2.4 0.000010 CALL  kse_release(0x811df4c)
>>>>  52929 python2.4 0.000413 CALL  kse_wakeup(0x811740c)
>>>>  52929 python2.4 0.000011 RET   kse_wakeup 0
>>>>  52929 python2.4 0.000004 RET   kse_release 0
>>>>  52929 python2.4 0.000009 CALL  kse_release(0x811df4c)
>>>>  52929 python2.4 0.000393 CALL  kse_wakeup(0x811740c)
>>>>  52929 python2.4 0.000012 RET   kse_wakeup 0
>>>>  52929 python2.4 0.000004 RET   kse_release 0
>>>>  52929 python2.4 0.000009 CALL  kse_release(0x811df4c)
>>>>
>>>> I may be mistaken, but it seems like that's a lot of unnecessary 
>>>> activity managing the threads; the confirmation I found came from 
>>>> http://arkiv.freebsd.se/?ml=freebsd-threads&a=2007-02&t=3178634.
>>>>
>>>> Am I correct that this is abnormal behavior? If so, any idea what 
>>>> I may need to do to fix the issue?
>>>
>>> Looks exactly like the python thread problem Michel described.
>>>
>>> You will get some improvement by switching to libthr and/or updating to
>>> 7.0 as I discussed, but ultimately you're hitting limits of python, not
>>> FreeBSD.
>>
>> WOW...it's *amazing* how much of a difference a single sysctl can make.
>>
>> I went ahead and set kern.threads.virtual_cpu=1, as suggested in the 
>> thread above, and the difference is ridiculous -- Zope is now faster 
>> than I've ever seen. More importantly, my ktracing shows that all of 
>> the kse_* garabage is now gone.
>>
>> I'll probably be upgrading to 7.0 in the next month or so, given 
>> that this is obviously a thread issue and that that release has much 
>> improved thread code. However, for the time being, the pressing 
>> issue is fixed, and for anyone in my position stuck on 6.2...this is 
>> night & day.
>
> Seriously, try libthr.  No matter what you do to libkse it is going to
> suck.  That's why we removed it.

I will, probably as part of upgrading to 7.0 (which I may accelerate, 
given this point). I'm just ecstatic at the difference I'm already 
seeing, and specifically wanted to make note of it in the archives. 
Point very much taken, though. :-)

Alex