Re: How how latent should non-preemptive scheduling be?

[Sitsofe Wheeler]

Ingo Molnar wrote:
> * Sitsofe Wheeler <sitsofe@xxxxxxxxx> wrote:
>
> > Any ideas why the issue would go away with a debug kernel though?
>
> hm, that's weird indeed. You could try to trace the full battery readout 
> itself, via a script like this:
>
>   cat /debug/tracing/trace > /dev/null        # drain trace
>   cat /proc/acpi/whatever  
>   cat /debug/tracing/trace > trace.txt
>
> You can even turn on stack backtrace tracing feature, via:
>
>   echo stacktrace > /debug/tracing/iter_ctrl
>
> this adds extra trace entries that show the call path of every 
> reschedule. [this attribute is default-disabled.]

(Something bad seems to be happening with my kernels as I have been 
finding strange problems like network-manager detecting the wifi as a 
wired interface unless I did a make clean on my kernel sources before 
compiling). The stalling issue seems to keep coming and going and is 
currently showing up in both debug and non debug kernels.

There are traces when looking at battery information on both AC (where 
the problem is never there) and battery (where the problem always is 
there) here:
http://sucs.org/~sits/test/eeepc-debug/20080929/trace-on-ac.txt.bz2
http://sucs.org/~sits/test/eeepc-debug/20080929/trace-on-battery.txt.bz2 
(15Mbytes uncompressed)

I wasn't quite sure how to tell when a reschedule was done. I simply did 
a grep schedule on the file and most of it seemed reasonable. One part 
that caught my eye was the following:

    speaker-test-3891  [000]  1392.751699: __switch_to <-schedule
          <idle>-0     [000]  1392.752070: account_scheduler_latency 
<-enqueue_task_fair
          <idle>-0     [000]  1392.752091: __switch_to <-schedule
             cat-7717  [000]  1392.752092: del_timer <-schedule_timeout
             cat-7717  [000]  1392.772263: account_scheduler_latency 
<-enqueue_task_fair
             cat-7717  [000]  1392.773224: __tasklet_schedule <-kbd_event
             cat-7717  [000]  1392.773225: schedule_console_callback 
<-kbd_event
             cat-7717  [000]  1392.773225: schedule_work 
<-schedule_console_callback
             cat-7717  [000]  1392.773226: queue_work <-schedule_work
             cat-7717  [000]  1392.773232: account_scheduler_latency 
<-enqueue_task_fair
             cat-7717  [000]  1392.773240: account_scheduler_latency 
<-enqueue_task_fair
             cat-7717  [000]  1392.773251: schedule_delayed_work 
<-put_queue
             cat-7717  [000]  1392.773251: queue_delayed_work 
<-schedule_delayed_work
             cat-7717  [000]  1392.773258: schedule_console_callback 
<-kbd_event
             cat-7717  [000]  1392.773258: schedule_work 
<-schedule_console_callback
             cat-7717  [000]  1392.773259: queue_work <-schedule_work
             cat-7717  [000]  1392.773267: schedule_console_callback 
<-kbd_event
             cat-7717  [000]  1392.773268: schedule_work 
<-schedule_console_callback
             cat-7717  [000]  1392.773268: queue_work <-schedule_work
             cat-7717  [000]  1392.807931: account_scheduler_latency 
<-enqueue_task_fair
             cat-7717  [000]  1392.839464: __tasklet_schedule <-ath5k_intr
             cat-7717  [000]  1392.839506: account_scheduler_latency 
<-enqueue_task_fair
             cat-7717  [000]  1392.941867: __tasklet_schedule <-ath5k_intr
             cat-7717  [000]  1393.005963: __tasklet_schedule <-ath5k_intr
             cat-7717  [000]  1393.033222: __switch_to <-schedule

Here a schedule seemingly doesn't happen for a few hundredths of a second...

--
Sitsofe | http://sucs.org/~sits/
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/