Re: [patch] Real-Time Preemption, -RT-2.6.11-rc3-V0.7.38-01

From: William Weston (weston_at_sysex.net)
Date: 02/08/05

  • Next message: Marcelo Tosatti: "Re: [PATCH 2.4] SIOCSIFNAME wildcard support (resend)" 
    Date:	Tue, 8 Feb 2005 13:58:48 -0800 (PST)
To: Ingo Molnar <mingo@elte.hu>

    Hi Ingo,

    Great work on the -RT kernel! Here's a status report from my Athlon box
    w/ kernel -RT-2.6.11-rc3-V0.7.38-03, realtime-lsm-0.8.5, jack-0.99.48,
    alsa-1.0.8, and latencytest-0.5.5:

    Latencytest (measured with RTC instead of latencytest LKM, which appears
    to be somewhat broken under later kernels) is reporting consistent
    latencies down below 0.24ms and no xruns.

    Jack_test4.1 is giving me good results with the default settings. I tried
    increasing the number of clients, but ran into the same issues other have.

    Jackd (-R -P64 -dalsa -dhw:0 -r44100 -p64 -n3 -i2 -o2) w/ one soft-synth
    client (using 15% to 30% of the CPU) will run for over 12 hours without
    any xruns, even during kernel compiles and nightly updatedb runs.

    Running wmcube (an impractical, greedy, little CPU meter), even when
    niced, causes lots of xruns. It may be good for worst-case-scenario
    desktop load testing.

    A couple BUGs are being logged (see below), but without any ill effect
    other than taking up space on my /var.

    jack_test4.1 results (with default settings):

    ************* SUMMARY RESULT ****************
    Total seconds ran . . . . . . : 300
    Number of clients . . . . . . : 14
    Ports per client . . . . . . : 4
    Frames per buffer . . . . . . : 64
    Number of runs . . . . . . . :( 1)
    *********************************************
    Timeout Count . . . . . . . . :( 0)
    XRUN Count . . . . . . . . . : 0
    Delay Count (>spare time) . . : 0
    Delay Count (>1000 usecs) . . : 0
    Delay Maximum . . . . . . . . : 92 usecs
    Cycle Maximum . . . . . . . . : 1100 usecs
    Average DSP Load. . . . . . . : 60.2 %
    Average CPU System Load . . . : 24.3 %
    Average CPU User Load . . . . : 40.2 %
    Average CPU Nice Load . . . . : 0.3 %
    Average CPU I/O Wait Load . . : 0.6 %
    Average CPU IRQ Load . . . . : 0.0 %
    Average CPU Soft-IRQ Load . . : 0.0 %
    Average Interrupt Rate . . . : 1751.7 /sec
    Average Context-Switch Rate . : 18563.4 /sec
    *********************************************
    Delta Maximum . . . . . . . . : 0.00000
    *********************************************

    Network interface (via rhine) startup triggers these two BUGs:

    BUG: sleeping function called from invalid context ksoftirqd/0(2) at
    kernel/rt.c:1448
    in_atomic():1 [00000001], irqs_disabled():0
     [<c0103e77>] dump_stack+0x17/0x20 (12)
     [<c0119f89>] __might_sleep+0xd9/0xf0 (40)
     [<c0134816>] __spin_lock+0x36/0x50 (24)
     [<c0147914>] kmem_cache_alloc+0x34/0x120 (44)
     [<c01d3143>] sel_netif_lookup+0x63/0x150 (28)
     [<c01d32cd>] sel_netif_sids+0x2d/0xb0 (28)
     [<c01d01bc>] selinux_socket_sock_rcv_skb+0xac/0x230 (144)
     [<c02fd248>] udp_queue_rcv_skb+0xb8/0x280 (28)
     [<c02fd8e2>] udp_rcv+0x192/0x3e0 (100)
     [<c02dc224>] ip_local_deliver+0x64/0x1c0 (32)
     [<c02dc595>] ip_rcv+0x215/0x3f0 (56)
     [<c02c201c>] netif_receive_skb+0x12c/0x160 (40)
     [<c02c20ce>] process_backlog+0x7e/0x110 (32)
     [<c02c21d2>] net_rx_action+0x72/0x130 (24)
     [<c0122428>] ___do_softirq+0x48/0xd0 (40)
     [<c012254b>] _do_softirq+0x1b/0x30 (8)
     [<c0122920>] ksoftirqd+0xa0/0xf0 (28)
     [<c01312fb>] kthread+0x8b/0xc0 (36)
     [<c01012f5>] kernel_thread_helper+0x5/0x10 (537116692)
    ---------------------------
    | preempt count: 00000002 ]
    | 2-level deep critical section nesting:
    ----------------------------------------
    .. [<c013dd3f>] .... __do_IRQ+0xef/0x180
    .....[<c0105306>] .. ( <= do_IRQ+0x56/0xa0)
    .. [<c0135240>] .... print_traces+0x10/0x40
    .....[<c0103e77>] .. ( <= dump_stack+0x17/0x20)

    BUG: sleeping function called from invalid context ksoftirqd/0(2) at
    kernel/rt.c:1448
    in_atomic():1 [00000001], irqs_disabled():0
     [<c0103e77>] dump_stack+0x17/0x20 (12)
     [<c0119f89>] __might_sleep+0xd9/0xf0 (40)
     [<c0134816>] __spin_lock+0x36/0x50 (24)
     [<c0147914>] kmem_cache_alloc+0x34/0x120 (44)
     [<c01d3143>] sel_netif_lookup+0x63/0x150 (28)
     [<c01d32cd>] sel_netif_sids+0x2d/0xb0 (28)
     [<c01d01bc>] selinux_socket_sock_rcv_skb+0xac/0x230 (144)
     [<c02f6be6>] tcp_v4_rcv+0x4c6/0x8b0 (84)
     [<c02dc224>] ip_local_deliver+0x64/0x1c0 (32)
     [<c02dc595>] ip_rcv+0x215/0x3f0 (56)
     [<c02c201c>] netif_receive_skb+0x12c/0x160 (40)
     [<c02c20ce>] process_backlog+0x7e/0x110 (32)
     [<c02c21d2>] net_rx_action+0x72/0x130 (24)
     [<c0122428>] ___do_softirq+0x48/0xd0 (40)
     [<c012254b>] _do_softirq+0x1b/0x30 (8)
     [<c0122920>] ksoftirqd+0xa0/0xf0 (28)
     [<c01312fb>] kthread+0x8b/0xc0 (36)
     [<c01012f5>] kernel_thread_helper+0x5/0x10 (537116692)
    ---------------------------
    | preempt count: 00000002 ]
    | 2-level deep critical section nesting:
    ----------------------------------------
    .. [<c013dcc4>] .... __do_IRQ+0x74/0x180
    .....[<c0105306>] .. ( <= do_IRQ+0x56/0xa0)
    .. [<c0118922>] .... scheduler_tick+0x62/0x300
    .....[<c0107b2d>] .. ( <= timer_interrupt+0x4d/0x160)

    MIDI playback through any MPU-401 interface triggers the following BUG,
    reported once for each outgoing MIDI event (non MPU-401 hw interfaces and
    sw interfaces not affected):

    BUG: sleeping function called from invalid context ksoftirqd/0(2) at
    kernel/rt.c:1448
    in_atomic():0 [00000000], irqs_disabled():1
     [<c0103e77>] dump_stack+0x17/0x20 (12)
     [<c0119f89>] __might_sleep+0xd9/0xf0 (40)
     [<c0134816>] __spin_lock+0x36/0x50 (24)
     [<c013486b>] _spin_lock_irqsave+0xb/0x10 (8)
     [<e089674a>] snd_rawmidi_transmit_peek+0x3a/0xe0 [snd_rawmidi] (40)
     [<e088c700>] snd_mpu401_uart_output_write+0x20/0x90 [snd_mpu401_uart] (24)
     [<e088c7fc>] snd_mpu401_uart_output_trigger+0x8c/0xa0 [snd_mpu401_uart] (20)
     [<e0896a5c>] snd_rawmidi_kernel_write1+0x17c/0x190 [snd_rawmidi] (48)
     [<e0896a82>] snd_rawmidi_kernel_write+0x12/0x20 [snd_rawmidi] (12)
     [<e0c06117>] dump_midi+0x27/0x50 [snd_seq_midi] (16)
     [<e0c06192>] event_process_midi+0x52/0xb0 [snd_seq_midi] (40)
     [<e0a11acc>] snd_seq_deliver_single_event+0x12c/0x140 [snd_seq] (40)
     [<e0a11ca6>] snd_seq_deliver_event+0x36/0x50 [snd_seq] (24)
     [<e0a11cfb>] snd_seq_dispatch_event+0x3b/0x130 [snd_seq] (68)
     [<e0a14d4c>] snd_seq_check_queue+0xec/0x110 [snd_seq] (28)
     [<e0841067>] snd_timer_interrupt+0x2a7/0x2f0 [snd_timer] (56)
     [<c0126428>] run_timer_softirq+0x1c8/0x3c0 (52)
     [<c0122428>] ___do_softirq+0x48/0xd0 (40)
     [<c012254b>] _do_softirq+0x1b/0x30 (8)
     [<c0122920>] ksoftirqd+0xa0/0xf0 (28)
     [<c01312fb>] kthread+0x8b/0xc0 (36)
     [<c01012f5>] kernel_thread_helper+0x5/0x10 (537116692)
    ---------------------------
    | preempt count: 00000001 ]
    | 1-level deep critical section nesting:
    ----------------------------------------
    .. [<c0135240>] .... print_traces+0x10/0x40
    .....[<c0103e77>] .. ( <= dump_stack+0x17/0x20)

    Please let me know if there's anything else I can do to help debug this.

    Best Regards,
    --William Weston <weston at sysex.net>

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

  • Next message: Marcelo Tosatti: "Re: [PATCH 2.4] SIOCSIFNAME wildcard support (resend)"

    Relevant Pages

    • Re: Houston, we have a problem: big file copying, USB, external disks
      ... The bug you link to ... It is also unclear how the users determine that a given transfer rate is ... kernel) that works better it should be relatively easy to make some ... Leann Ogasawara actually already told people to report in separate ...
      (Linux-Kernel)
    • Re: [patch] scsi: revert "[SCSI] Get rid of scsi_cmnd->done"
      ... Noone knows how many thousand bug reports have never reached lkml ... filing or get back to terminate the report. ... But I would like kernel people to become less egocentric ... Send _one_ email to lkml and you'll get forever spam to this address. ...
      (Linux-Kernel)
    • Re: kernel BUG at lib/kernel_lock.c:83! - 2.6.19-1.2895.fc6
      ... kernel was tainted and just look at the "actual message", ... I had no reason to create a bugzilla report because, ... provided in my was interested because it appears to be the same bug ... kernels are completely useless around here along with that phony bug report ...
      (Fedora)
    • Backport hr-tick fix into .25/.26
      ... Since the introduction of 2.6.25-rc1 kernel I've been experiencing screen blanking during boot up. ... I've reported this issue before, and Rafael Wysocki opened a bug report. ... I know of one other person that ran into what seems to be the same bug. ... I did a git bisect and found both the commit that introduced the bug and also the one that fixed it. ...
      (Linux-Kernel)
    • Bug: Asus CUR-DLS and 2.6
      ... I'm writing to report and interesting occurance that I fully believe is a bug ... In March I purchased a used Asus CUR-DLS motherboard with two socket 370 PIII ... I believe my initial kernel was ... Well, I have more free time now, and I've narrowed down the bug I think. ...
      (Linux-Kernel)