Possible Threading problem with -CURRENT / MySQL?

[Bruce Evans]

On Thu, 17 Jun 2004, Robert Watson wrote:

> On Thu, 17 Jun 2004, Jon Noack wrote:
>
> > > ... I know that Jeff's measurement work
> > > on ULE had a substantial focus on deadlines -- whether or not ULE was
> > > timely in scheduling tasks, etc, and that he demonstrated that it was
> > > much stronger than most other available schedulers in this area.
> >
> > Well, I switched to 4BSD and noticed this right away.  I occasionally
> > get sound hiccups under heavy i/o with ULE [1], but with 4BSD it's a bit
> > ridiculous.  There's a PR open about it (can't remember which off the
> > top of my head), but sound will skip and slow down (play at half speed
> > or slower).  I know the sound locking is not all it should be, so this
> > may not be a representative test.  Regardless, my workstations are back
> > on ULE...
>
> Hrm.  So, I'm not really a scheduler guy, but I have some ideas about how
> to investigate what's going on.  If you feel like playing with kernel
> tracing facilities, there are some really neat things you can do with
> ktr(4).  It allows you took hook context switch and interrupt delivery
> events and dump a trace to userspace.

Interrupt delivery if well known to be broken (interrupts that can't
switch to their ithread immediately, perhaps because they are scheduled
while in a critical region, just set a flag, and the flag is not checked
until return to user mode which may happen a long time later, so the
current current thread keeps running until it either gives up control
or another interrupt that can be switched to immediately is recieved
(then the flag becomes irrelevant and the highest priority ithread
is switched too; it may even be the one for the first interrupt).

The effects of this can be seen in ping latency.  For
"ping -fq -c1000000 besplex" over 100Mb/S ethernet using an old version
of ping that I keep for this benchmark:

Under -current on an unloaded  Celeron 366:
--- besplex.bde.org ping statistics ---
100002 packets transmitted, 100000 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.172/0.393/20.336/0.191 ms
       13.60 real         0.74 user         7.66 sys

The latency is sometimes 20ms (2 clock ticks).

Under my version of -current (which is missing the bug) on the same machine:
--- besplex.bde.org ping statistics ---
100001 packets transmitted, 100000 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.156/0.204/2.449/0.099 ms
       10.92 real         0.80 user         5.91 sys

The worst-case latency is still bad, but is much smaller, and the real
and system times are much smaller too (the latter may not be significant --
flood pings sometimes give strange behaviour (capture effect?) where
synchronization gives a larger latency but a smaller real time.  But here
the latency is smaller too.

> One possible cause of the symptoms you're seeing is poor interrupt
> handling response time -- possibly a failure to schedule the ithread in a
> timely manner.  It would be quite interesting to compare the latency in
> scheduling (and running) the ithread across ULE and 4BSD and see how well
> each is managing to do in getting it running quickly.  I'm not sure

The scheduler really shouldn't affect scheduling of ithreads.  The 4BSD
scheduler just picks the highest priority ithread (round robin among equal
priorities) and runs it, and doing much more than that would be wrong.
ULE may be reducing the effect of bugs by scheduling more often.  Or perhaps
it is better for sound because it handles competition between user threads
and ithreads better.  Ithreads are supposed to always have higher priority
than user threads; however, the 4BSD scheduler still has the bugfeature of
not enforcing this, so that when a user thread in kernel mode wakes up with
a high kernel priority, it essentially keeps the kernel priority when it
returns to user mode (until it gives up control or is interrupted).  This
bugfeature seems to be more responsible for the 4BSD scheduler's good
interactive behaviour than anything it does intentionally.  I believe the
ULE scheduler does similar things intentionally.

> there's a tutorial on how to get KTR(4) running -- I found the man page
> helpful, but a little confusing.  What you'll want to do, assuming you're
> willing to get into this, is turn on KTR tracing with KTR_INTR and
> KTR_PROC.  You'll need to set the flags in the kernel compile, and then
> set them using a sysctl.  You can use ktrdump to dump a record trace --
> I'd use a number of flags present to add timestamps, cpu numbers if SMP,
> etc.  With some post-processing, it should be possible to generate a
> distribution of "interrupt time" to "running interrupt handler".
>
> It would be useful to demonstrate to oneself that ithreads are running
> quickly, preempting things they need to, etc.

I think listening to the sound is the actually easiest way to see if
interrupt latency is not too large, at least if 100uS (corresponding
to 10kHz) is not too large :-).  Too bad I can't hear it well enough.
When I fixed interrupt problems for 386BSD-0.0, I set up a visual
indicator using about 10 words of VGA memory at the top of the screen.
It was updated on every change to the interrupt masks.  Latency bugs
in the 100uS range are far too short to see, but I could easily see
some larger bugs.

Bruce