[alsa-devel] 2.6.26.[6|7]-rt11, alsa rawmidi, seq hang
(starting a new thread with the hope of being more precise after a lot of testing and rebooting)
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Just tested this on 2.6.26.7 + rt11, Gina3G soundcard with an external MIDI keyboard sending messages. This is not specific to the Gina card, I have tested also USB midi interfaces and an RME hdsp card with a Multiface interface.
2.6.24.7 + rt21 works fine on the same hardware combinations. The standard Fedora 9 2.6.26.x kernel works fine as well.
I'm attaching the kernel configuration for the kernel I'm currently testing plus a dmesg dump of the whole boot process (rt kernel hackers can find there some additional sleeping in wrong context warning messages there), including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
Hopefully this will narrow the area affected enough so that a solution can be found or more debugging info can be requested. Currently 2.6.26.x-rtx is unusable for musical purposes (at least when you have to interact with external midi controllers).
Thanks for any help... -- Fernando
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
I vaguely remember that we had exactly the same problem (hangs when using sequencer on RT kernel) some time ago, and that it was somehow related to tasklets.
Regards, Clemens
I wrote:
I vaguely remember that we had exactly the same problem (hangs when using sequencer on RT kernel) some time ago, and that it was somehow related to tasklets.
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
I added a printk before and after the call, it looks like it gets called and it returns (but only _once_... aseqdump hangs in an unkillable state as before).
But the hang is different, I'll reboot and retry to see if it is repeatable:
-------- Nov 7 10:05:36 host kernel: ======================= Nov 7 10:05:36 host kernel: aseqdump S [f2e5c330] f78df0f0 0 5256 5185 Nov 7 10:05:36 host kernel: f2cffbd4 00000086 f2cffb88 f78df0f0 00000003 f2e5c330 f2e5c5c4 c4847700 Nov 7 10:05:36 host kernel: 00000001 c4847700 ef1ba352 0000002c c4844054 00000000 fffe5e91 00000246 Nov 7 10:05:36 host kernel: f57fc274 00000000 00000000 00000000 ffffffff 00000000 7fffffff f2cffe98 Nov 7 10:05:36 host kernel: Call Trace: Nov 7 10:05:36 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 7 10:05:36 host kernel: [<c0643c72>] schedule_timeout+0x17/0xbc Nov 7 10:05:36 host kernel: [<c0496c8f>] ? __pollwait+0xad/0xb6 Nov 7 10:05:36 host kernel: [<f8971b34>] ? snd_seq_fifo_poll_wait +0x18/0x25 [snd_seq] Nov 7 10:05:36 host kernel: [<f896efad>] ? snd_seq_poll+0x4d/0x9f [snd_seq] Nov 7 10:05:36 host kernel: [<c0495d92>] do_sys_poll+0x292/0x348 Nov 7 10:05:36 host kernel: [<c0496be2>] ? __pollwait+0x0/0xb6 Nov 7 10:05:36 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 7 10:05:36 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:05:36 host kernel: [<c04752f7>] ? page_address+0x88/0xaa Nov 7 10:05:36 host kernel: [<c047596d>] ? kmap_high+0x421/0x42a Nov 7 10:05:36 host kernel: [<c04ff574>] ? radix_valid_always+0x0/0xa Nov 7 10:05:36 host kernel: [<c046430b>] ? __rcu_read_unlock+0x6d/0x72 Nov 7 10:05:36 host kernel: [<c04699ec>] ? find_get_page+0xfa/0x120 Nov 7 10:05:36 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 7 10:05:36 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:05:36 host kernel: [<c0420afc>] ? __enqueue_entity+0xe3/0xeb Nov 7 10:05:36 host kernel: [<c041f87b>] ? task_rq_lock+0x44/0x6e Nov 7 10:05:36 host kernel: [<c0425c76>] ? try_to_wake_up+0x212/0x21d Nov 7 10:05:36 host kernel: [<c0425c91>] ? default_wake_function +0x10/0x12 Nov 7 10:05:36 host kernel: [<c041ddd8>] ? __wake_up_common+0x35/0x5b Nov 7 10:05:36 host kernel: [<c0423172>] ? __wake_up+0x28/0x32 Nov 7 10:05:36 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 7 10:05:36 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 7 10:05:36 host kernel: [<c0447cef>] ? rt_mutex_up_read+0x1b7/0x25d Nov 7 10:05:36 host kernel: [<c0448f40>] ? rt_up_read+0x8/0xa Nov 7 10:05:36 host kernel: [<c0647c26>] ? do_page_fault+0x45f/0x7d8 Nov 7 10:05:36 host kernel: [<c0502f6c>] ? copy_to_user+0x36/0x106 Nov 7 10:05:36 host kernel: [<c0644770>] ? rt_spin_lock_slowlock +0x1bd/0x1d8 Nov 7 10:05:36 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 7 10:05:36 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:05:36 host kernel: [<f8971c46>] ? snd_seq_fifo_cell_out +0x47/0xee [snd_seq] Nov 7 10:05:36 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 7 10:05:36 host kernel: [<f896f041>] ? snd_seq_read+0x0/0x1d8 [snd_seq] Nov 7 10:05:36 host kernel: [<f896f11e>] ? snd_seq_read+0xdd/0x1d8 [snd_seq] Nov 7 10:05:36 host kernel: [<c04d73d3>] ? security_file_permission +0xf/0x11 Nov 7 10:05:36 host kernel: [<c045e231>] ? audit_syscall_entry +0xf9/0x123 Nov 7 10:05:36 host kernel: [<c049606a>] sys_poll+0x3a/0x6a Nov 7 10:05:36 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 7 10:05:36 host kernel: ======================= --------
# cat /proc/5256/status Name: aseqdump State: D (disk sleep) Tgid: 5256 Pid: 5256 PPid: 5185 TracerPid: 0 Uid: 743 743 743 743 Gid: 10 10 10 10 FDSize: 32 Groups: 10 11 30 31 400 VmPeak: 3104 kB VmSize: 3048 kB VmLck: 0 kB VmHWM: 884 kB VmRSS: 884 kB VmData: 172 kB VmStk: 84 kB VmExe: 12 kB VmLib: 2700 kB VmPTE: 20 kB Threads: 1 SigQ: 1/32768 SigPnd: 0000000000000000 ShdPnd: 0000000000004000 SigBlk: 0000000000000000 SigIgn: 0000000000000000 SigCgt: 0000000180004002 CapInh: 0000000000000000 CapPrm: 0000000000000000 CapEff: 0000000000000000 CapBnd: ffffffffffffffff Cpus_allowed: 0000000f Cpus_allowed_list: 0-3 Mems_allowed: 1 Mems_allowed_list: 0 voluntary_ctxt_switches: 66283 nonvoluntary_ctxt_switches: 4
# cat /proc/5256/wchan msleep
-- Fernando
On Fri, 2008-11-07 at 10:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be
Nope, different this time. Maybe this one points closer to the culprit? (BTW, snd_midi_input_event only gets called _once_, I added a few more printk's there):
-------- Nov 7 10:34:51 host kernel: aseqdump S [f15ce070] f7910d70 0 5341 5247 Nov 7 10:34:51 host kernel: f3691bd4 00000086 f3691b88 f7910d70 00000001 f15ce070 f15ce304 c4852700 Nov 7 10:34:51 host kernel: 00000002 c4852700 9a9894aa 0000002c c484f054 00000000 fffeb4bf 00000246 Nov 7 10:34:51 host kernel: f35cf274 00000000 00000000 00000000 ffffffff 00000000 7fffffff f3691e98 Nov 7 10:34:51 host kernel: Call Trace: Nov 7 10:34:51 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 7 10:34:51 host kernel: [<c0643c72>] schedule_timeout+0x17/0xbc Nov 7 10:34:51 host kernel: [<c0496c8f>] ? __pollwait+0xad/0xb6 Nov 7 10:34:51 host kernel: [<f893cb34>] ? snd_seq_fifo_poll_wait +0x18/0x25 [snd_seq] Nov 7 10:34:51 host kernel: [<f8939fad>] ? snd_seq_poll+0x4d/0x9f [snd_seq] Nov 7 10:34:51 host kernel: [<c0495d92>] do_sys_poll+0x292/0x348 Nov 7 10:34:51 host kernel: [<c0496be2>] ? __pollwait+0x0/0xb6 Nov 7 10:34:51 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 7 10:34:51 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:34:51 host kernel: [<c04752f7>] ? page_address+0x88/0xaa Nov 7 10:34:51 host kernel: [<c047596d>] ? kmap_high+0x421/0x42a Nov 7 10:34:51 host kernel: [<c04ff574>] ? radix_valid_always+0x0/0xa Nov 7 10:34:51 host kernel: [<c046430b>] ? __rcu_read_unlock+0x6d/0x72 Nov 7 10:34:51 host kernel: [<c04699ec>] ? find_get_page+0xfa/0x120 Nov 7 10:34:51 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 7 10:34:51 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:34:51 host kernel: [<c0420afc>] ? __enqueue_entity+0xe3/0xeb Nov 7 10:34:51 host kernel: [<c041f87b>] ? task_rq_lock+0x44/0x6e Nov 7 10:34:51 host kernel: [<c0425c76>] ? try_to_wake_up+0x212/0x21d Nov 7 10:34:51 host kernel: [<c0425c91>] ? default_wake_function +0x10/0x12 Nov 7 10:34:51 host kernel: [<c041ddd8>] ? __wake_up_common+0x35/0x5b Nov 7 10:34:51 host kernel: [<c0423172>] ? __wake_up+0x28/0x32 Nov 7 10:34:51 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 7 10:34:51 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 7 10:34:51 host kernel: [<c0447cef>] ? rt_mutex_up_read+0x1b7/0x25d Nov 7 10:34:51 host kernel: [<c0448f40>] ? rt_up_read+0x8/0xa Nov 7 10:34:51 host kernel: [<c0647c26>] ? do_page_fault+0x45f/0x7d8 Nov 7 10:34:51 host kernel: [<c043e441>] ? hrtimer_start+0x133/0x162 Nov 7 10:34:51 host kernel: [<c04249d0>] ? hrtick_set+0x97/0xe5 Nov 7 10:34:51 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 7 10:34:51 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 7 10:34:51 host kernel: [<f893cc46>] ? snd_seq_fifo_cell_out +0x47/0xee [snd_seq] Nov 7 10:34:51 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 7 10:34:51 host kernel: [<f893a041>] ? snd_seq_read+0x0/0x1d8 [snd_seq] Nov 7 10:34:51 host kernel: [<f893a11e>] ? snd_seq_read+0xdd/0x1d8 [snd_seq] Nov 7 10:34:51 host kernel: [<c04d73d3>] ? security_file_permission +0xf/0x11 Nov 7 10:34:51 host kernel: [<c045e231>] ? audit_syscall_entry +0xf9/0x123 Nov 7 10:34:51 host kernel: [<c049606a>] sys_poll+0x3a/0x6a Nov 7 10:34:51 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 7 10:34:51 host kernel: ======================= --------
-- Fernando
On Fri, 2008-11-07 at 10:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
I added a printk before and after the call, it looks like it gets called and it returns (but only _once_... aseqdump hangs in an unkillable state as before).
Just in case, the tasklet keeps getting called as long as midi bytes are received. So the tasklet runs once, snd_midi_input_event gets called once and the tasklet keeps running again and again, but nobody runs snd_midi_input_event. Who should?
-- Fernando
On Fri, 2008-11-07 at 15:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
I added a printk before and after the call, it looks like it gets called and it returns (but only _once_... aseqdump hangs in an unkillable state as before).
Just in case, the tasklet keeps getting called as long as midi bytes are received. So the tasklet runs once, snd_midi_input_event gets called once and the tasklet keeps running again and again, but nobody runs snd_midi_input_event. Who should?
I normally use rtirq to tune realtime priorities for realtime kernel processes, as I looked around and noticed tasklets seem to be related to (or are) software interrupts and those have priorities, so I disabled rtirq and rebooted (which leaves the default priority of 50 for all realtime kernel processes).
Now I get __two__ midi bytes instead of one (active sensing messages from the keyboard) and the whole thing stalls as before. ?? So is this a priority inversion problem? -- Fernando
On Fri, 2008-11-07 at 16:48 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 15:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
Please try the snd-virmidi driver, then we'd have a test case that does not require MIDI hardware.
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
I added a printk before and after the call, it looks like it gets called and it returns (but only _once_... aseqdump hangs in an unkillable state as before).
Just in case, the tasklet keeps getting called as long as midi bytes are received. So the tasklet runs once, snd_midi_input_event gets called once and the tasklet keeps running again and again, but nobody runs snd_midi_input_event. Who should?
I normally use rtirq to tune realtime priorities for realtime kernel processes, as I looked around and noticed tasklets seem to be related to (or are) software interrupts and those have priorities, so I disabled rtirq and rebooted (which leaves the default priority of 50 for all realtime kernel processes).
Now I get __two__ midi bytes instead of one (active sensing messages from the keyboard) and the whole thing stalls as before.
This is repeatable.
?? So is this a priority inversion problem?
And for that matter, what _should_ be the priority order of all the realtime little tasks of rt kernels?? Names have changed and there's a lot more of those...
(I can readily hang the whole machine if I change the wrong one to a higher priority!)
Any help appreciated... -- Fernando
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
Going back to this in the hope of a bit more data helping solve the problem...
I don't understand what is going on (of course! :-)
Cards look like this:
$ cat /proc/asound/cards 0 [Gina3G ]: Echo_Echo3G - Gina3G Gina3G rev.0 (DSP56361) at 0xfeb00000 irq 18 1 [Intel ]: HDA-Intel - HDA Intel HDA Intel at 0xfe7f8000 irq 22 2 [PCR ]: USB-Audio - PCR EDIROL PCR at usb-0000:00:1d.0-1, full speed
Here's what I do: - start aseqdump - aconnect 16:0 128:0 - aseqdump receives one midi message (one byte active sensing msg) - aseqdump hangs forever (reboot needed)
This is what dmesg prints (patch attached which shows where the printk's are located in the source for rawmidi.c and seq_midi.c):
== this starts happening as soon as I run aconnect: rawmidi: before input ops trigger rawmidi: after input ops trigger rawmidi: before input ops trigger rawmidi: after input ops trigger == hmmm, after it is actually subscribed? rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: about to run input tasklet seq: snd_midi_input_event called seq: seq_midi_input_event loop begin rawmidi: before input ops trigger rawmidi: after input ops trigger seq: snd_seq_kernel_client_dispatch called seq: snd_seq_kernel_client_dispatch returned seq: snd_midi_input_event exiting rawmidi: after running input tasklet rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock
So, snd_midi_input_event runs once but never gets called back.
Something else is deadlocking, what can it be? (ie: where can I put more printk's to try to see what is going on??)
This is where I think aseqdujmp hangs:
Nov 13 11:36:53 host kernel: ======================= Nov 13 11:36:53 host kernel: aseqdump S [f3505170] f7960f30 0 5580 5515 Nov 13 11:36:53 host kernel: f567bbd4 00200082 00000001 f7960f30 00200246 f3505170 f3505404 c485d700 Nov 13 11:36:53 host kernel: 00000003 c485d700 9a5d89b4 000000bc f567bba4 f567bba4 0007c8c8 00200246 Nov 13 11:36:53 host kernel: f35a7af4 00000000 00000000 00000000 ffffffff 00000000 7fffffff f567be98 Nov 13 11:36:53 host kernel: Call Trace: Nov 13 11:36:53 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 13 11:36:53 host kernel: [<c0643c72>] schedule_timeout+0x17/0xbc Nov 13 11:36:53 host kernel: [<c0496c8f>] ? __pollwait+0xad/0xb6 Nov 13 11:36:53 host kernel: [<f8968b34>] ? snd_seq_fifo_poll_wait +0x18/0x25 [snd_seq] Nov 13 11:36:53 host kernel: [<f8965fad>] ? snd_seq_poll+0x4d/0x9f [snd_seq] Nov 13 11:36:53 host kernel: [<c0495d92>] do_sys_poll+0x292/0x348 Nov 13 11:36:53 host kernel: [<c0496be2>] ? __pollwait+0x0/0xb6 Nov 13 11:36:53 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 11:36:53 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 11:36:53 host kernel: [<c04752f7>] ? page_address+0x88/0xaa Nov 13 11:36:53 host kernel: [<c047596d>] ? kmap_high+0x421/0x42a Nov 13 11:36:53 host kernel: [<c04ff574>] ? radix_valid_always+0x0/0xa Nov 13 11:36:53 host kernel: [<c046430b>] ? __rcu_read_unlock+0x6d/0x72 Nov 13 11:36:53 host kernel: [<c04699ec>] ? find_get_page+0xfa/0x120 Nov 13 11:36:53 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 11:36:53 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 11:36:53 host kernel: [<c0420afc>] ? __enqueue_entity+0xe3/0xeb Nov 13 11:36:53 host kernel: [<c041f87b>] ? task_rq_lock+0x44/0x6e Nov 13 11:36:53 host kernel: [<c0425c76>] ? try_to_wake_up+0x212/0x21d Nov 13 11:36:53 host kernel: [<c0425c91>] ? default_wake_function +0x10/0x12 Nov 13 11:36:53 host kernel: [<c041ddd8>] ? __wake_up_common+0x35/0x5b Nov 13 11:36:53 host kernel: [<c0423172>] ? __wake_up+0x28/0x32 Nov 13 11:36:53 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 11:36:53 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 11:36:53 host kernel: [<c0447cef>] ? rt_mutex_up_read+0x1b7/0x25d Nov 13 11:36:53 host kernel: [<c0448f40>] ? rt_up_read+0x8/0xa Nov 13 11:36:53 host kernel: [<c0647c26>] ? do_page_fault+0x45f/0x7d8 Nov 13 11:36:53 host kernel: [<c0502f6c>] ? copy_to_user+0x36/0x106 Nov 13 11:36:53 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 11:36:53 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 11:36:53 host kernel: [<f8968c46>] ? snd_seq_fifo_cell_out +0x47/0xee [snd_seq] Nov 13 11:36:53 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 11:36:53 host kernel: [<f8966041>] ? snd_seq_read+0x0/0x1d8 [snd_seq] Nov 13 11:36:53 host kernel: [<f896611e>] ? snd_seq_read+0xdd/0x1d8 [snd_seq] Nov 13 11:36:53 host kernel: [<c04d73d3>] ? security_file_permission +0xf/0x11 Nov 13 11:36:53 host kernel: [<c045e231>] ? audit_syscall_entry +0xf9/0x123 Nov 13 11:36:53 host kernel: [<c049606a>] sys_poll+0x3a/0x6a Nov 13 11:36:53 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 13 11:36:53 host kernel: =======================
Looks like it is a poll...
Then, when I try to actually kill aseqdump I get this in the log:
Nov 13 11:39:02 host kernel: rawmidi: about to kill input tasklet
And the trace:
Nov 13 11:39:13 host kernel: aseqdump D [f3505170] f786c0b0 0 5580 5515 Nov 13 11:39:13 host kernel: f567be0c 00200082 00000000 f786c0b0 00200246 f3505170 f3505404 c483c700 Nov 13 11:39:13 host kernel: 00000000 c483c700 5618b41d 00000121 f567bdf4 000e6262 f567bdf4 c04320f3 Nov 13 11:39:13 host kernel: f567be1c f567be1c f567be14 c0432918 000e6263 000e6263 f567be1c f567be48 Nov 13 11:39:13 host kernel: Call Trace: Nov 13 11:39:13 host kernel: [<c04320f3>] ? internal_add_timer+0x88/0x8c Nov 13 11:39:13 host kernel: [<c0432918>] ? __mod_timer+0xc8/0xd3 Nov 13 11:39:13 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 13 11:39:13 host kernel: [<c0643cf8>] schedule_timeout+0x9d/0xbc Nov 13 11:39:13 host kernel: [<c0431da2>] ? process_timeout+0x0/0xa Nov 13 11:39:13 host kernel: [<c0643cf3>] ? schedule_timeout+0x98/0xbc Nov 13 11:39:13 host kernel: [<c0643d2c>] schedule_timeout_uninterruptible+0x15/0x17 Nov 13 11:39:13 host kernel: [<c0432a1b>] msleep+0x10/0x16 Nov 13 11:39:13 host kernel: [<c042eaef>] tasklet_kill+0x2e/0x58 Nov 13 11:39:13 host kernel: [<f89bb755>] snd_rawmidi_input_trigger +0x31/0x44 [snd_rawmidi] Nov 13 11:39:13 host kernel: [<f89bceeb>] snd_rawmidi_kernel_release +0x37/0x105 [snd_rawmidi] Nov 13 11:39:13 host kernel: [<f8f28633>] midisynth_unsubscribe+0xb/0xd [snd_seq_midi] Nov 13 11:39:13 host kernel: [<f8969cb9>] unsubscribe_port+0x3c/0x71 [snd_seq] Nov 13 11:39:13 host kernel: [<f896a510>] clear_subscriber_list +0xae/0xdb [snd_seq] Nov 13 11:39:13 host kernel: [<f896a57e>] port_delete+0x41/0x65 [snd_seq] Nov 13 11:39:13 host kernel: [<f896a63c>] snd_seq_delete_all_ports +0x9a/0xba [snd_seq] Nov 13 11:39:13 host kernel: [<f8965175>] seq_free_client1+0xb/0x90 [snd_seq] Nov 13 11:39:13 host kernel: [<f8965232>] seq_free_client+0x38/0x6f [snd_seq] Nov 13 11:39:13 host kernel: [<f896527e>] snd_seq_release+0x15/0x35 [snd_seq] Nov 13 11:39:13 host kernel: [<c048b5a2>] __fput+0xae/0x158 Nov 13 11:39:13 host kernel: [<c048b663>] fput+0x17/0x19 Nov 13 11:39:13 host kernel: [<c0488b95>] filp_close+0x50/0x5a Nov 13 11:39:13 host kernel: [<c0488c12>] sys_close+0x73/0xad Nov 13 11:39:13 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 13 11:39:13 host kernel: =======================
-- Fernando
On Thu, 2008-11-13 at 13:01 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
Going back to this in the hope of a bit more data helping solve the problem...
I don't understand what is going on (of course! :-)
Cards look like this:
$ cat /proc/asound/cards 0 [Gina3G ]: Echo_Echo3G - Gina3G Gina3G rev.0 (DSP56361) at 0xfeb00000 irq 18 1 [Intel ]: HDA-Intel - HDA Intel HDA Intel at 0xfe7f8000 irq 22 2 [PCR ]: USB-Audio - PCR EDIROL PCR at usb-0000:00:1d.0-1, full speed
Here's what I do:
- start aseqdump
- aconnect 16:0 128:0
- aseqdump receives one midi message (one byte active sensing msg)
- aseqdump hangs forever (reboot needed)
This is what dmesg prints (patch attached which shows where the printk's are located in the source for rawmidi.c and seq_midi.c):
More info with some more printk's (see attached patch for location):
after aseqdump startup:
snd_seq_fifo: before init snd_seq_fifo: after init snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait
after aconnect:
snd_seq_fifo: before init snd_seq_fifo: after init rawmidi: before input ops trigger rawmidi: after input ops trigger rawmidi: before input ops trigger rawmidi: after input ops trigger snd_seq_fifo_event_in: before wake_up snd_seq_fifo_event_in: after wake_up snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait snd_seq_fifo_cell_out: before spin_unlock snd_seq_fifo_cell_out: after spin_unlock snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: about to run input tasklet seq: snd_midi_input_event called seq: seq_midi_input_event loop begin rawmidi: before input ops trigger rawmidi: after input ops trigger seq: snd_seq_kernel_client_dispatch called snd_seq_fifo_event_in: before wake_up snd_seq_fifo_event_in: after wake_up seq: snd_seq_kernel_client_dispatch returned snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait seq: snd_midi_input_event exiting rawmidi: after running input tasklet snd_seq_fifo_cell_out: before spin_unlock snd_seq_fifo_cell_out: after spin_unlock snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet
Hangs here:
Nov 13 14:39:57 host kernel: aseqdump S [f55762f0] f714dbe0 0 5360 5318 Nov 13 14:39:57 host kernel: f714dbd4 00200082 f628edc0 f714dbe0 c042ab6d f55762f0 f5576584 c4847700 Nov 13 14:39:57 host kernel: 00000001 c4847700 098b418d 0000003d 00000000 00000000 00200246 f63980f4 Nov 13 14:39:57 host kernel: f714dbc0 c06456c1 f63980f4 f714dc5c f714dbcc 00000000 7fffffff f714de98 Nov 13 14:39:57 host kernel: Call Trace: Nov 13 14:39:57 host kernel: [<c042ab6d>] ? vprintk+0x30e/0x331 Nov 13 14:39:57 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 14:39:57 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 13 14:39:57 host kernel: [<c0643c72>] schedule_timeout+0x17/0xbc Nov 13 14:39:57 host kernel: [<c0642de5>] ? printk+0xf/0x12 Nov 13 14:39:57 host kernel: [<f8967c0c>] ? snd_seq_fifo_poll_wait +0x32/0x44 [snd_seq] Nov 13 14:39:57 host kernel: [<f8964fad>] ? snd_seq_poll+0x4d/0x9f [snd_seq] Nov 13 14:39:57 host kernel: [<c0495d92>] do_sys_poll+0x292/0x348 Nov 13 14:39:57 host kernel: [<c0496be2>] ? __pollwait+0x0/0xb6 Nov 13 14:39:57 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 14:39:57 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 14:39:57 host kernel: [<c04752f7>] ? page_address+0x88/0xaa Nov 13 14:39:57 host kernel: [<c047596d>] ? kmap_high+0x421/0x42a Nov 13 14:39:57 host kernel: [<c04ff574>] ? radix_valid_always+0x0/0xa Nov 13 14:39:57 host kernel: [<c046430b>] ? __rcu_read_unlock+0x6d/0x72 Nov 13 14:39:57 host kernel: [<c04699ec>] ? find_get_page+0xfa/0x120 Nov 13 14:39:57 host kernel: [<c0440314>] ? getnstimeofday+0x3c/0xd6 Nov 13 14:39:57 host kernel: [<c043e653>] ? ktime_get_ts+0x4a/0x4e Nov 13 14:39:57 host kernel: [<c043e66a>] ? ktime_get+0x13/0x2f Nov 13 14:39:57 host kernel: [<c0424060>] ? hrtick_start_fair +0x140/0x148 Nov 13 14:39:57 host kernel: [<c041f87b>] ? task_rq_lock+0x44/0x6e Nov 13 14:39:57 host kernel: [<c0425c76>] ? try_to_wake_up+0x212/0x21d Nov 13 14:39:57 host kernel: [<c0425c91>] ? default_wake_function +0x10/0x12 Nov 13 14:39:57 host kernel: [<c041ddd8>] ? __wake_up_common+0x35/0x5b Nov 13 14:39:57 host kernel: [<c0423172>] ? __wake_up+0x28/0x32 Nov 13 14:39:57 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 14:39:57 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 14:39:57 host kernel: [<c05009a6>] ? rb_insert_color+0x56/0xc0 Nov 13 14:39:57 host kernel: [<c043dbab>] ? enqueue_hrtimer+0x112/0x11e Nov 13 14:39:57 host kernel: [<c043e441>] ? hrtimer_start+0x133/0x162 Nov 13 14:39:57 host kernel: [<c04249d0>] ? hrtick_set+0x97/0xe5 Nov 13 14:39:57 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 14:39:57 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 14:39:57 host kernel: [<f8967c68>] ? snd_seq_fifo_cell_out +0x4a/0x146 [snd_seq] Nov 13 14:39:57 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 14:39:57 host kernel: [<f8965041>] ? snd_seq_read+0x0/0x1d8 [snd_seq] Nov 13 14:39:57 host kernel: [<f896511e>] ? snd_seq_read+0xdd/0x1d8 [snd_seq] Nov 13 14:39:57 host kernel: [<c04d73d3>] ? security_file_permission +0xf/0x11 Nov 13 14:39:57 host kernel: [<c045e231>] ? audit_syscall_entry +0xf9/0x123 Nov 13 14:39:57 host kernel: [<c049606a>] sys_poll+0x3a/0x6a Nov 13 14:39:57 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 13 14:39:57 host kernel: =======================
After I try to kill aseqdump:
snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before input ops trigger rawmidi: after input ops trigger rawmidi: about to kill input tasklet (definitely hangs there as well, never kills tasklet)
Help! What can I try next?? -- Fernando
On Thu, 2008-11-13 at 14:56 -0800, Fernando Lopez-Lezcano wrote:
On Thu, 2008-11-13 at 13:01 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-07 at 10:12 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I'm seeing a realtime patch related hard hang in the kernel alsa subsystem (MIDI input/output). In a nutshell:
- alsa rawmidi works (ie: "rawmidi -v -i hw:0" outputs a stream of
messages when pointed to a midi capable card that has an external keyboard connected).
- the alsa sequencer interface works (ie: aplaymidi connected to
aseqdump transfers data just fine).
- BOTH combined do NOT work (ie: use aconnect to connect the port that
corresponds to the external midi interface to aseqdump: aseqdump hangs forever after transferring the first message and the only way out is a reboot).
... including the output of a "echo t >/proc/sysrq-trigger" that should show where aseqdump currently hangs (or so I think).
It hangs in tasklet_kill(), which gets called while it tries to close the rawmidi port.
The rawmidi framework uses this tasklet to notify the sequencer that new MIDI data is available. The handler function is snd_rawmidi_input_event_tasklet() in sound/core/rawmidi.c; the sequencer callback that gets called from there is snd_midi_input_event() in core/seq/seq_midi.c.
You say that the first event gets delivered, so it might be possible that the tasklet never finishes executing. Please check whether the call to snd_seq_kernel_client_dispatch() in snd_midi_input_event() ever returns.
Going back to this in the hope of a bit more data helping solve the problem...
I don't understand what is going on (of course! :-)
Cards look like this:
$ cat /proc/asound/cards 0 [Gina3G ]: Echo_Echo3G - Gina3G Gina3G rev.0 (DSP56361) at 0xfeb00000 irq 18 1 [Intel ]: HDA-Intel - HDA Intel HDA Intel at 0xfe7f8000 irq 22 2 [PCR ]: USB-Audio - PCR EDIROL PCR at usb-0000:00:1d.0-1, full speed
Here's what I do:
- start aseqdump
- aconnect 16:0 128:0
- aseqdump receives one midi message (one byte active sensing msg)
- aseqdump hangs forever (reboot needed)
This is what dmesg prints (patch attached which shows where the printk's are located in the source for rawmidi.c and seq_midi.c):
More info with some more printk's (see attached patch for location):
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ... the handling code is being scheduled but never executes, right? (well, it executes _once_ and then never again). And that leads to tasklet_common_schedule - as Clemens pointed at the beginning of the thread this is eerily similar to what happened before in 2006:
http://lkml.org/lkml/2006/3/7/256
So, is tasklet_common_schedule just going through the "goto again;" loop forever?:
tasklet_trylock(t) is true again: -> test_bit(TASKLET_STATE_SCHED, &t->state) is false -> !tasklet_tryunlock(t) is true -> goto again
I don't know what it all _means_, I'm just trying to point a finger to something in the hope that somebody will understand and say "aha!" (and email a nice patch! :-)
As the code says, "this is subtle"...
-- Fernando
after aseqdump startup:
snd_seq_fifo: before init snd_seq_fifo: after init snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait
after aconnect:
snd_seq_fifo: before init snd_seq_fifo: after init rawmidi: before input ops trigger rawmidi: after input ops trigger rawmidi: before input ops trigger rawmidi: after input ops trigger snd_seq_fifo_event_in: before wake_up snd_seq_fifo_event_in: after wake_up snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait snd_seq_fifo_cell_out: before spin_unlock snd_seq_fifo_cell_out: after spin_unlock snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: about to run input tasklet seq: snd_midi_input_event called seq: seq_midi_input_event loop begin rawmidi: before input ops trigger rawmidi: after input ops trigger seq: snd_seq_kernel_client_dispatch called snd_seq_fifo_event_in: before wake_up snd_seq_fifo_event_in: after wake_up seq: snd_seq_kernel_client_dispatch returned snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait seq: snd_midi_input_event exiting rawmidi: after running input tasklet snd_seq_fifo_cell_out: before spin_unlock snd_seq_fifo_cell_out: after spin_unlock snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet rawmidi: run receive tasklet rawmidi: before receive spin unlock rawmidi: after receive spin unlock rawmidi: before receive spinlock rawmidi: after receive spinlock rawmidi: about to run receive tasklet
Hangs here:
Nov 13 14:39:57 host kernel: aseqdump S [f55762f0] f714dbe0 0 5360 5318 Nov 13 14:39:57 host kernel: f714dbd4 00200082 f628edc0 f714dbe0 c042ab6d f55762f0 f5576584 c4847700 Nov 13 14:39:57 host kernel: 00000001 c4847700 098b418d 0000003d 00000000 00000000 00200246 f63980f4 Nov 13 14:39:57 host kernel: f714dbc0 c06456c1 f63980f4 f714dc5c f714dbcc 00000000 7fffffff f714de98 Nov 13 14:39:57 host kernel: Call Trace: Nov 13 14:39:57 host kernel: [<c042ab6d>] ? vprintk+0x30e/0x331 Nov 13 14:39:57 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 14:39:57 host kernel: [<c0643ba5>] schedule+0xbf/0xd8 Nov 13 14:39:57 host kernel: [<c0643c72>] schedule_timeout+0x17/0xbc Nov 13 14:39:57 host kernel: [<c0642de5>] ? printk+0xf/0x12 Nov 13 14:39:57 host kernel: [<f8967c0c>] ? snd_seq_fifo_poll_wait +0x32/0x44 [snd_seq] Nov 13 14:39:57 host kernel: [<f8964fad>] ? snd_seq_poll+0x4d/0x9f [snd_seq] Nov 13 14:39:57 host kernel: [<c0495d92>] do_sys_poll+0x292/0x348 Nov 13 14:39:57 host kernel: [<c0496be2>] ? __pollwait+0x0/0xb6 Nov 13 14:39:57 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 14:39:57 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 14:39:57 host kernel: [<c04752f7>] ? page_address+0x88/0xaa Nov 13 14:39:57 host kernel: [<c047596d>] ? kmap_high+0x421/0x42a Nov 13 14:39:57 host kernel: [<c04ff574>] ? radix_valid_always+0x0/0xa Nov 13 14:39:57 host kernel: [<c046430b>] ? __rcu_read_unlock+0x6d/0x72 Nov 13 14:39:57 host kernel: [<c04699ec>] ? find_get_page+0xfa/0x120 Nov 13 14:39:57 host kernel: [<c0440314>] ? getnstimeofday+0x3c/0xd6 Nov 13 14:39:57 host kernel: [<c043e653>] ? ktime_get_ts+0x4a/0x4e Nov 13 14:39:57 host kernel: [<c043e66a>] ? ktime_get+0x13/0x2f Nov 13 14:39:57 host kernel: [<c0424060>] ? hrtick_start_fair +0x140/0x148 Nov 13 14:39:57 host kernel: [<c041f87b>] ? task_rq_lock+0x44/0x6e Nov 13 14:39:57 host kernel: [<c0425c76>] ? try_to_wake_up+0x212/0x21d Nov 13 14:39:57 host kernel: [<c0425c91>] ? default_wake_function +0x10/0x12 Nov 13 14:39:57 host kernel: [<c041ddd8>] ? __wake_up_common+0x35/0x5b Nov 13 14:39:57 host kernel: [<c0423172>] ? __wake_up+0x28/0x32 Nov 13 14:39:57 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 14:39:57 host kernel: [<c0554f2e>] ? n_tty_receive_buf +0xfa9/0xff7 Nov 13 14:39:57 host kernel: [<c05009a6>] ? rb_insert_color+0x56/0xc0 Nov 13 14:39:57 host kernel: [<c043dbab>] ? enqueue_hrtimer+0x112/0x11e Nov 13 14:39:57 host kernel: [<c043e441>] ? hrtimer_start+0x133/0x162 Nov 13 14:39:57 host kernel: [<c04249d0>] ? hrtick_set+0x97/0xe5 Nov 13 14:39:57 host kernel: [<c06456c1>] ? __rt_spin_lock+0x24/0x61 Nov 13 14:39:57 host kernel: [<c0645736>] ? rt_spin_lock+0x38/0x3b Nov 13 14:39:57 host kernel: [<f8967c68>] ? snd_seq_fifo_cell_out +0x4a/0x146 [snd_seq] Nov 13 14:39:57 host kernel: [<c0425c81>] ? default_wake_function +0x0/0x12 Nov 13 14:39:57 host kernel: [<f8965041>] ? snd_seq_read+0x0/0x1d8 [snd_seq] Nov 13 14:39:57 host kernel: [<f896511e>] ? snd_seq_read+0xdd/0x1d8 [snd_seq] Nov 13 14:39:57 host kernel: [<c04d73d3>] ? security_file_permission +0xf/0x11 Nov 13 14:39:57 host kernel: [<c045e231>] ? audit_syscall_entry +0xf9/0x123 Nov 13 14:39:57 host kernel: [<c049606a>] sys_poll+0x3a/0x6a Nov 13 14:39:57 host kernel: [<c0404be6>] syscall_call+0x7/0xb Nov 13 14:39:57 host kernel: =======================
After I try to kill aseqdump:
snd_seq_fifo_poll_wait: before poll_wait snd_seq_fifo_poll_wait: after poll_wait rawmidi: before input ops trigger rawmidi: after input ops trigger rawmidi: about to kill input tasklet (definitely hangs there as well, never kills tasklet)
Help! What can I try next?? -- Fernando
Alsa-devel mailing list Alsa-devel@alsa-project.org http://mailman.alsa-project.org/mailman/listinfo/alsa-devel
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
HTH Clemens
At Fri, 14 Nov 2008 09:15:53 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
Hmm, I don't remember why we still keep tasklet_hi version...
Takashi
On Fri, 2008-11-14 at 09:15 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
YES YES!! __Thanks__ for the suggestion, it WORKED!!
Maybe the kernel rt gurus should look around and see _why_ the problem was happening in the first place. There are not that many uses of tasklet_hi_schedule in the kernel tree I'm working with:
./drivers/char/drm/drm_irq.c ./drivers/infiniband/hw/ehca/ehca_irq.c ./drivers/infiniband/hw/ipath/ipath_cq.c ./drivers/infiniband/hw/ipath/ipath_driver.c ./drivers/infiniband/hw/ipath/ipath_intr.c ./drivers/infiniband/hw/ipath/ipath_sdma.c ./drivers/media/video/vino.c ./drivers/mmc/host/omap.c ./drivers/mmc/host/wbsd.c ./drivers/net/chelsio/sge.c ./drivers/net/ehea/ehea_main.c ./drivers/net/smc91x.c ./drivers/s390/block/dasd.c ./drivers/s390/cio/qdio.c ./drivers/s390/net/ctcm_fsms.c ./drivers/s390/net/ctcm_mpc.c ./drivers/usb/c67x00/c67x00-sched.c ./drivers/usb/gadget/gmidi.c ./kernel/softirq.c ./sound/core/rtctimer.c ./sound/core/timer.c ./sound/drivers/vx/vx_core.c ./sound/drivers/vx/vx_pcm.c ./sound/pci/es1968.c ./sound/pci/maestro3.c ./sound/pci/mixart/mixart_core.c ./sound/pci/pcxhr/pcxhr.c ./sound/pci/pcxhr/pcxhr_core.c ./sound/pci/riptide/riptide.c ./sound/pci/rme9652/hdsp.c ./sound/pci/rme9652/hdspm.c ./sound/pcmcia/pdaudiocf/pdaudiocf_irq.c ./sound/usb/usbmidi.c
Maybe other drivers are affected as well by the rt patch. What is the difference between tasklet_hi_schedule and tasklet_schedule?
Thanks again... -- Fernando
At Fri, 14 Nov 2008 10:57:10 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-14 at 09:15 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
YES YES!! __Thanks__ for the suggestion, it WORKED!!
Maybe the kernel rt gurus should look around and see _why_ the problem was happening in the first place. There are not that many uses of tasklet_hi_schedule in the kernel tree I'm working with:
(snip)
Maybe other drivers are affected as well by the rt patch. What is the difference between tasklet_hi_schedule and tasklet_schedule?
AFAIK, tasklet_hi_schedule() uses another softirq vector with the highest priority (the first item to be scanned).
Regarding the ALSA codes, there is no big reason to use hi_* version. Could you check the patch below and see whether you get any regressions?
thanks,
Takashi
--- diff --git a/sound/core/rawmidi.c b/sound/core/rawmidi.c index 39672f6..002777b 100644 --- a/sound/core/rawmidi.c +++ b/sound/core/rawmidi.c @@ -151,7 +151,7 @@ static inline void snd_rawmidi_output_trigger(struct snd_rawmidi_substream *subs if (!substream->opened) return; if (up) { - tasklet_hi_schedule(&substream->runtime->tasklet); + tasklet_schedule(&substream->runtime->tasklet); } else { tasklet_kill(&substream->runtime->tasklet); substream->ops->trigger(substream, 0); @@ -908,7 +908,7 @@ int snd_rawmidi_receive(struct snd_rawmidi_substream *substream, } if (result > 0) { if (runtime->event) - tasklet_hi_schedule(&runtime->tasklet); + tasklet_schedule(&runtime->tasklet); else if (snd_rawmidi_ready(substream)) wake_up(&runtime->sleep); } diff --git a/sound/core/rtctimer.c b/sound/core/rtctimer.c index 51e64e3..0851cd1 100644 --- a/sound/core/rtctimer.c +++ b/sound/core/rtctimer.c @@ -118,7 +118,7 @@ static void rtctimer_tasklet(unsigned long data) */ static void rtctimer_interrupt(void *private_data) { - tasklet_hi_schedule(private_data); + tasklet_schedule(private_data); }
diff --git a/sound/core/timer.c b/sound/core/timer.c index c584408..7965320 100644 --- a/sound/core/timer.c +++ b/sound/core/timer.c @@ -743,7 +743,7 @@ void snd_timer_interrupt(struct snd_timer * timer, unsigned long ticks_left) spin_unlock_irqrestore(&timer->lock, flags);
if (use_tasklet) - tasklet_hi_schedule(&timer->task_queue); + tasklet_schedule(&timer->task_queue); }
/* diff --git a/sound/drivers/vx/vx_core.c b/sound/drivers/vx/vx_core.c index 473b07f..14e3354 100644 --- a/sound/drivers/vx/vx_core.c +++ b/sound/drivers/vx/vx_core.c @@ -548,7 +548,7 @@ irqreturn_t snd_vx_irq_handler(int irq, void *dev) (chip->chip_status & VX_STAT_IS_STALE)) return IRQ_NONE; if (! vx_test_and_ack(chip)) - tasklet_hi_schedule(&chip->tq); + tasklet_schedule(&chip->tq); return IRQ_HANDLED; }
diff --git a/sound/drivers/vx/vx_pcm.c b/sound/drivers/vx/vx_pcm.c index 27de574..6644d00 100644 --- a/sound/drivers/vx/vx_pcm.c +++ b/sound/drivers/vx/vx_pcm.c @@ -823,7 +823,7 @@ static int vx_pcm_trigger(struct snd_pcm_substream *subs, int cmd) * we trigger the pipe using tasklet, so that the interrupts are * issued surely after the trigger is completed. */ - tasklet_hi_schedule(&pipe->start_tq); + tasklet_schedule(&pipe->start_tq); chip->pcm_running++; pipe->running = 1; break; diff --git a/sound/pci/es1968.c b/sound/pci/es1968.c index 20ee759..e9c3794 100644 --- a/sound/pci/es1968.c +++ b/sound/pci/es1968.c @@ -1953,7 +1953,7 @@ static irqreturn_t snd_es1968_interrupt(int irq, void *dev_id) outw(inw(chip->io_port + 4) & 1, chip->io_port + 4);
if (event & ESM_HWVOL_IRQ) - tasklet_hi_schedule(&chip->hwvol_tq); /* we'll do this later */ + tasklet_schedule(&chip->hwvol_tq); /* we'll do this later */
/* else ack 'em all, i imagine */ outb(0xFF, chip->io_port + 0x1A); diff --git a/sound/pci/maestro3.c b/sound/pci/maestro3.c index 9ff3f9e..59bbaf8 100644 --- a/sound/pci/maestro3.c +++ b/sound/pci/maestro3.c @@ -1670,7 +1670,7 @@ static irqreturn_t snd_m3_interrupt(int irq, void *dev_id) return IRQ_NONE;
if (status & HV_INT_PENDING) - tasklet_hi_schedule(&chip->hwvol_tq); + tasklet_schedule(&chip->hwvol_tq);
/* * ack an assp int if its running diff --git a/sound/pci/mixart/mixart_core.c b/sound/pci/mixart/mixart_core.c index b9a06c2..d3350f3 100644 --- a/sound/pci/mixart/mixart_core.c +++ b/sound/pci/mixart/mixart_core.c @@ -550,7 +550,7 @@ irqreturn_t snd_mixart_interrupt(int irq, void *dev_id) mgr->msg_fifo[mgr->msg_fifo_writeptr] = msg; mgr->msg_fifo_writeptr++; mgr->msg_fifo_writeptr %= MSG_FIFO_SIZE; - tasklet_hi_schedule(&mgr->msg_taskq); + tasklet_schedule(&mgr->msg_taskq); } spin_unlock(&mgr->msg_lock); break; diff --git a/sound/pci/pcxhr/pcxhr.c b/sound/pci/pcxhr/pcxhr.c index 73de6e9..8309d44 100644 --- a/sound/pci/pcxhr/pcxhr.c +++ b/sound/pci/pcxhr/pcxhr.c @@ -653,7 +653,7 @@ static int pcxhr_trigger(struct snd_pcm_substream *subs, int cmd) PCXHR_STREAM_STATUS_SCHEDULE_RUN; snd_pcm_trigger_done(s, subs); } - tasklet_hi_schedule(&chip->mgr->trigger_taskq); + tasklet_schedule(&chip->mgr->trigger_taskq); } else { stream = subs->runtime->private_data; snd_printdd("Only one Substream %c %d\n", diff --git a/sound/pci/pcxhr/pcxhr_core.c b/sound/pci/pcxhr/pcxhr_core.c index 7143259..4a5481f 100644 --- a/sound/pci/pcxhr/pcxhr_core.c +++ b/sound/pci/pcxhr/pcxhr_core.c @@ -1213,7 +1213,7 @@ irqreturn_t pcxhr_interrupt(int irq, void *dev_id) mgr->dsp_time_last = PCXHR_DSP_TIME_INVALID; mgr->src_it_dsp = reg; - tasklet_hi_schedule(&mgr->msg_taskq); + tasklet_schedule(&mgr->msg_taskq); } #ifdef CONFIG_SND_DEBUG_VERBOSE if (reg & PCXHR_FATAL_DSP_ERR) diff --git a/sound/pci/riptide/riptide.c b/sound/pci/riptide/riptide.c index e9f0706..1d0eeb1 100644 --- a/sound/pci/riptide/riptide.c +++ b/sound/pci/riptide/riptide.c @@ -1754,7 +1754,7 @@ snd_riptide_interrupt(int irq, void *dev_id) if (IS_EOBIRQ(cif->hwport) || IS_EOSIRQ(cif->hwport) || IS_EOCIRQ(cif->hwport)) { chip->handled_irqs++; - tasklet_hi_schedule(&chip->riptide_tq); + tasklet_schedule(&chip->riptide_tq); } if (chip->rmidi && IS_MPUIRQ(cif->hwport)) { chip->handled_irqs++; diff --git a/sound/pci/rme9652/hdsp.c b/sound/pci/rme9652/hdsp.c index fdd3be5..44d0c15 100644 --- a/sound/pci/rme9652/hdsp.c +++ b/sound/pci/rme9652/hdsp.c @@ -3750,7 +3750,7 @@ static irqreturn_t snd_hdsp_interrupt(int irq, void *dev_id) } } if (hdsp->use_midi_tasklet && schedule) - tasklet_hi_schedule(&hdsp->midi_tasklet); + tasklet_schedule(&hdsp->midi_tasklet); return IRQ_HANDLED; }
diff --git a/sound/pci/rme9652/hdspm.c b/sound/pci/rme9652/hdspm.c index dc5c4ba..71231cf 100644 --- a/sound/pci/rme9652/hdspm.c +++ b/sound/pci/rme9652/hdspm.c @@ -3476,7 +3476,7 @@ static irqreturn_t snd_hdspm_interrupt(int irq, void *dev_id) schedule = 1; } if (schedule) - tasklet_hi_schedule(&hdspm->midi_tasklet); + tasklet_schedule(&hdspm->midi_tasklet); return IRQ_HANDLED; }
diff --git a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c index fa4b113..ea903c8 100644 --- a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c +++ b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c @@ -41,7 +41,7 @@ irqreturn_t pdacf_interrupt(int irq, void *dev) if (stat & PDAUDIOCF_IRQOVR) /* should never happen */ snd_printk(KERN_ERR "PDAUDIOCF SRAM buffer overrun detected!\n"); if (chip->pcm_substream) - tasklet_hi_schedule(&chip->tq); + tasklet_schedule(&chip->tq); if (!(stat & PDAUDIOCF_IRQAKM)) stat |= PDAUDIOCF_IRQAKM; /* check rate */ } diff --git a/sound/usb/usbmidi.c b/sound/usb/usbmidi.c index 5962e4b..6d9f9b1 100644 --- a/sound/usb/usbmidi.c +++ b/sound/usb/usbmidi.c @@ -880,7 +880,7 @@ static void snd_usbmidi_output_trigger(struct snd_rawmidi_substream *substream, snd_rawmidi_transmit_ack(substream, 1); return; } - tasklet_hi_schedule(&port->ep->tasklet); + tasklet_schedule(&port->ep->tasklet); } }
At Wed, 19 Nov 2008 12:44:23 +0100, I wrote:
At Fri, 14 Nov 2008 10:57:10 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-14 at 09:15 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
YES YES!! __Thanks__ for the suggestion, it WORKED!!
Maybe the kernel rt gurus should look around and see _why_ the problem was happening in the first place. There are not that many uses of tasklet_hi_schedule in the kernel tree I'm working with:
(snip)
Maybe other drivers are affected as well by the rt patch. What is the difference between tasklet_hi_schedule and tasklet_schedule?
AFAIK, tasklet_hi_schedule() uses another softirq vector with the highest priority (the first item to be scanned).
Regarding the ALSA codes, there is no big reason to use hi_* version. Could you check the patch below and see whether you get any regressions?
Nando, any chance to test on your machines?
thanks,
Takashi
thanks,
Takashi
diff --git a/sound/core/rawmidi.c b/sound/core/rawmidi.c index 39672f6..002777b 100644 --- a/sound/core/rawmidi.c +++ b/sound/core/rawmidi.c @@ -151,7 +151,7 @@ static inline void snd_rawmidi_output_trigger(struct snd_rawmidi_substream *subs if (!substream->opened) return; if (up) {
tasklet_hi_schedule(&substream->runtime->tasklet);
tasklet_schedule(&substream->runtime->tasklet);@@ -908,7 +908,7 @@ int snd_rawmidi_receive(struct snd_rawmidi_substream *substream, } if (result > 0) { if (runtime->event)
tasklet_hi_schedule(&runtime->tasklet);
tasklet_schedule(&runtime->tasklet);diff --git a/sound/core/rtctimer.c b/sound/core/rtctimer.c index 51e64e3..0851cd1 100644 --- a/sound/core/rtctimer.c +++ b/sound/core/rtctimer.c @@ -118,7 +118,7 @@ static void rtctimer_tasklet(unsigned long data) */ static void rtctimer_interrupt(void *private_data) {
- tasklet_hi_schedule(private_data);
- tasklet_schedule(private_data);
}
diff --git a/sound/core/timer.c b/sound/core/timer.c index c584408..7965320 100644 --- a/sound/core/timer.c +++ b/sound/core/timer.c @@ -743,7 +743,7 @@ void snd_timer_interrupt(struct snd_timer * timer, unsigned long ticks_left) spin_unlock_irqrestore(&timer->lock, flags);
if (use_tasklet)
tasklet_hi_schedule(&timer->task_queue);
tasklet_schedule(&timer->task_queue);}
/* diff --git a/sound/drivers/vx/vx_core.c b/sound/drivers/vx/vx_core.c index 473b07f..14e3354 100644 --- a/sound/drivers/vx/vx_core.c +++ b/sound/drivers/vx/vx_core.c @@ -548,7 +548,7 @@ irqreturn_t snd_vx_irq_handler(int irq, void *dev) (chip->chip_status & VX_STAT_IS_STALE)) return IRQ_NONE; if (! vx_test_and_ack(chip))
tasklet_hi_schedule(&chip->tq);
tasklet_schedule(&chip->tq);}
diff --git a/sound/drivers/vx/vx_pcm.c b/sound/drivers/vx/vx_pcm.c index 27de574..6644d00 100644 --- a/sound/drivers/vx/vx_pcm.c +++ b/sound/drivers/vx/vx_pcm.c @@ -823,7 +823,7 @@ static int vx_pcm_trigger(struct snd_pcm_substream *subs, int cmd) * we trigger the pipe using tasklet, so that the interrupts are * issued surely after the trigger is completed. */
tasklet_hi_schedule(&pipe->start_tq);
tasklet_schedule(&pipe->start_tq);diff --git a/sound/pci/es1968.c b/sound/pci/es1968.c index 20ee759..e9c3794 100644 --- a/sound/pci/es1968.c +++ b/sound/pci/es1968.c @@ -1953,7 +1953,7 @@ static irqreturn_t snd_es1968_interrupt(int irq, void *dev_id) outw(inw(chip->io_port + 4) & 1, chip->io_port + 4);
if (event & ESM_HWVOL_IRQ)
tasklet_hi_schedule(&chip->hwvol_tq); /* we'll do this later */
tasklet_schedule(&chip->hwvol_tq); /* we'll do this later *//* else ack 'em all, i imagine */ outb(0xFF, chip->io_port + 0x1A);
diff --git a/sound/pci/maestro3.c b/sound/pci/maestro3.c index 9ff3f9e..59bbaf8 100644 --- a/sound/pci/maestro3.c +++ b/sound/pci/maestro3.c @@ -1670,7 +1670,7 @@ static irqreturn_t snd_m3_interrupt(int irq, void *dev_id) return IRQ_NONE;
if (status & HV_INT_PENDING)
tasklet_hi_schedule(&chip->hwvol_tq);
tasklet_schedule(&chip->hwvol_tq);/*
- ack an assp int if its running
diff --git a/sound/pci/mixart/mixart_core.c b/sound/pci/mixart/mixart_core.c index b9a06c2..d3350f3 100644 --- a/sound/pci/mixart/mixart_core.c +++ b/sound/pci/mixart/mixart_core.c @@ -550,7 +550,7 @@ irqreturn_t snd_mixart_interrupt(int irq, void *dev_id) mgr->msg_fifo[mgr->msg_fifo_writeptr] = msg; mgr->msg_fifo_writeptr++; mgr->msg_fifo_writeptr %= MSG_FIFO_SIZE;
tasklet_hi_schedule(&mgr->msg_taskq);
tasklet_schedule(&mgr->msg_taskq); } spin_unlock(&mgr->msg_lock); break;diff --git a/sound/pci/pcxhr/pcxhr.c b/sound/pci/pcxhr/pcxhr.c index 73de6e9..8309d44 100644 --- a/sound/pci/pcxhr/pcxhr.c +++ b/sound/pci/pcxhr/pcxhr.c @@ -653,7 +653,7 @@ static int pcxhr_trigger(struct snd_pcm_substream *subs, int cmd) PCXHR_STREAM_STATUS_SCHEDULE_RUN; snd_pcm_trigger_done(s, subs); }
tasklet_hi_schedule(&chip->mgr->trigger_taskq);
tasklet_schedule(&chip->mgr->trigger_taskq);diff --git a/sound/pci/pcxhr/pcxhr_core.c b/sound/pci/pcxhr/pcxhr_core.c index 7143259..4a5481f 100644 --- a/sound/pci/pcxhr/pcxhr_core.c +++ b/sound/pci/pcxhr/pcxhr_core.c @@ -1213,7 +1213,7 @@ irqreturn_t pcxhr_interrupt(int irq, void *dev_id) mgr->dsp_time_last = PCXHR_DSP_TIME_INVALID; mgr->src_it_dsp = reg;
tasklet_hi_schedule(&mgr->msg_taskq);
tasklet_schedule(&mgr->msg_taskq);#ifdef CONFIG_SND_DEBUG_VERBOSE if (reg & PCXHR_FATAL_DSP_ERR) diff --git a/sound/pci/riptide/riptide.c b/sound/pci/riptide/riptide.c index e9f0706..1d0eeb1 100644 --- a/sound/pci/riptide/riptide.c +++ b/sound/pci/riptide/riptide.c @@ -1754,7 +1754,7 @@ snd_riptide_interrupt(int irq, void *dev_id) if (IS_EOBIRQ(cif->hwport) || IS_EOSIRQ(cif->hwport) || IS_EOCIRQ(cif->hwport)) { chip->handled_irqs++;
tasklet_hi_schedule(&chip->riptide_tq);
tasklet_schedule(&chip->riptide_tq);diff --git a/sound/pci/rme9652/hdsp.c b/sound/pci/rme9652/hdsp.c index fdd3be5..44d0c15 100644 --- a/sound/pci/rme9652/hdsp.c +++ b/sound/pci/rme9652/hdsp.c @@ -3750,7 +3750,7 @@ static irqreturn_t snd_hdsp_interrupt(int irq, void *dev_id) } } if (hdsp->use_midi_tasklet && schedule)
tasklet_hi_schedule(&hdsp->midi_tasklet);
tasklet_schedule(&hdsp->midi_tasklet);}
diff --git a/sound/pci/rme9652/hdspm.c b/sound/pci/rme9652/hdspm.c index dc5c4ba..71231cf 100644 --- a/sound/pci/rme9652/hdspm.c +++ b/sound/pci/rme9652/hdspm.c @@ -3476,7 +3476,7 @@ static irqreturn_t snd_hdspm_interrupt(int irq, void *dev_id) schedule = 1; } if (schedule)
tasklet_hi_schedule(&hdspm->midi_tasklet);
tasklet_schedule(&hdspm->midi_tasklet);}
diff --git a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c index fa4b113..ea903c8 100644 --- a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c +++ b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c @@ -41,7 +41,7 @@ irqreturn_t pdacf_interrupt(int irq, void *dev) if (stat & PDAUDIOCF_IRQOVR) /* should never happen */ snd_printk(KERN_ERR "PDAUDIOCF SRAM buffer overrun detected!\n"); if (chip->pcm_substream)
tasklet_hi_schedule(&chip->tq);
tasklet_schedule(&chip->tq);diff --git a/sound/usb/usbmidi.c b/sound/usb/usbmidi.c index 5962e4b..6d9f9b1 100644 --- a/sound/usb/usbmidi.c +++ b/sound/usb/usbmidi.c @@ -880,7 +880,7 @@ static void snd_usbmidi_output_trigger(struct snd_rawmidi_substream *substream, snd_rawmidi_transmit_ack(substream, 1); return; }
tasklet_hi_schedule(&port->ep->tasklet);
tasklet_schedule(&port->ep->tasklet);}
At Thu, 27 Nov 2008 17:50:52 +0100, I wrote:
At Wed, 19 Nov 2008 12:44:23 +0100, I wrote:
At Fri, 14 Nov 2008 10:57:10 -0800, Fernando Lopez-Lezcano wrote:
On Fri, 2008-11-14 at 09:15 +0100, Clemens Ladisch wrote:
Fernando Lopez-Lezcano wrote:
I've been trying to follow the printk crumbs without much success. AFAICT it all points to tasklet_hi_schedule ...
I don't have -rt, but if the error is similar to the old one you might try replacing tasklet_hi_schedule with tasklet_schedule.
YES YES!! __Thanks__ for the suggestion, it WORKED!!
Maybe the kernel rt gurus should look around and see _why_ the problem was happening in the first place. There are not that many uses of tasklet_hi_schedule in the kernel tree I'm working with:
(snip)
Maybe other drivers are affected as well by the rt patch. What is the difference between tasklet_hi_schedule and tasklet_schedule?
AFAIK, tasklet_hi_schedule() uses another softirq vector with the highest priority (the first item to be scanned).
Regarding the ALSA codes, there is no big reason to use hi_* version. Could you check the patch below and see whether you get any regressions?
Nando, any chance to test on your machines?
Ping.
Takashi
thanks,
Takashi
diff --git a/sound/core/rawmidi.c b/sound/core/rawmidi.c index 39672f6..002777b 100644 --- a/sound/core/rawmidi.c +++ b/sound/core/rawmidi.c @@ -151,7 +151,7 @@ static inline void snd_rawmidi_output_trigger(struct snd_rawmidi_substream *subs if (!substream->opened) return; if (up) {
tasklet_hi_schedule(&substream->runtime->tasklet);
tasklet_schedule(&substream->runtime->tasklet);@@ -908,7 +908,7 @@ int snd_rawmidi_receive(struct snd_rawmidi_substream *substream, } if (result > 0) { if (runtime->event)
tasklet_hi_schedule(&runtime->tasklet);
tasklet_schedule(&runtime->tasklet);diff --git a/sound/core/rtctimer.c b/sound/core/rtctimer.c index 51e64e3..0851cd1 100644 --- a/sound/core/rtctimer.c +++ b/sound/core/rtctimer.c @@ -118,7 +118,7 @@ static void rtctimer_tasklet(unsigned long data) */ static void rtctimer_interrupt(void *private_data) {
- tasklet_hi_schedule(private_data);
- tasklet_schedule(private_data);
}
diff --git a/sound/core/timer.c b/sound/core/timer.c index c584408..7965320 100644 --- a/sound/core/timer.c +++ b/sound/core/timer.c @@ -743,7 +743,7 @@ void snd_timer_interrupt(struct snd_timer * timer, unsigned long ticks_left) spin_unlock_irqrestore(&timer->lock, flags);
if (use_tasklet)
tasklet_hi_schedule(&timer->task_queue);
tasklet_schedule(&timer->task_queue);}
/* diff --git a/sound/drivers/vx/vx_core.c b/sound/drivers/vx/vx_core.c index 473b07f..14e3354 100644 --- a/sound/drivers/vx/vx_core.c +++ b/sound/drivers/vx/vx_core.c @@ -548,7 +548,7 @@ irqreturn_t snd_vx_irq_handler(int irq, void *dev) (chip->chip_status & VX_STAT_IS_STALE)) return IRQ_NONE; if (! vx_test_and_ack(chip))
tasklet_hi_schedule(&chip->tq);
tasklet_schedule(&chip->tq);}
diff --git a/sound/drivers/vx/vx_pcm.c b/sound/drivers/vx/vx_pcm.c index 27de574..6644d00 100644 --- a/sound/drivers/vx/vx_pcm.c +++ b/sound/drivers/vx/vx_pcm.c @@ -823,7 +823,7 @@ static int vx_pcm_trigger(struct snd_pcm_substream *subs, int cmd) * we trigger the pipe using tasklet, so that the interrupts are * issued surely after the trigger is completed. */
tasklet_hi_schedule(&pipe->start_tq);
tasklet_schedule(&pipe->start_tq);diff --git a/sound/pci/es1968.c b/sound/pci/es1968.c index 20ee759..e9c3794 100644 --- a/sound/pci/es1968.c +++ b/sound/pci/es1968.c @@ -1953,7 +1953,7 @@ static irqreturn_t snd_es1968_interrupt(int irq, void *dev_id) outw(inw(chip->io_port + 4) & 1, chip->io_port + 4);
if (event & ESM_HWVOL_IRQ)
tasklet_hi_schedule(&chip->hwvol_tq); /* we'll do this later */
tasklet_schedule(&chip->hwvol_tq); /* we'll do this later *//* else ack 'em all, i imagine */ outb(0xFF, chip->io_port + 0x1A);
diff --git a/sound/pci/maestro3.c b/sound/pci/maestro3.c index 9ff3f9e..59bbaf8 100644 --- a/sound/pci/maestro3.c +++ b/sound/pci/maestro3.c @@ -1670,7 +1670,7 @@ static irqreturn_t snd_m3_interrupt(int irq, void *dev_id) return IRQ_NONE;
if (status & HV_INT_PENDING)
tasklet_hi_schedule(&chip->hwvol_tq);
tasklet_schedule(&chip->hwvol_tq);/*
- ack an assp int if its running
diff --git a/sound/pci/mixart/mixart_core.c b/sound/pci/mixart/mixart_core.c index b9a06c2..d3350f3 100644 --- a/sound/pci/mixart/mixart_core.c +++ b/sound/pci/mixart/mixart_core.c @@ -550,7 +550,7 @@ irqreturn_t snd_mixart_interrupt(int irq, void *dev_id) mgr->msg_fifo[mgr->msg_fifo_writeptr] = msg; mgr->msg_fifo_writeptr++; mgr->msg_fifo_writeptr %= MSG_FIFO_SIZE;
tasklet_hi_schedule(&mgr->msg_taskq);
tasklet_schedule(&mgr->msg_taskq); } spin_unlock(&mgr->msg_lock); break;diff --git a/sound/pci/pcxhr/pcxhr.c b/sound/pci/pcxhr/pcxhr.c index 73de6e9..8309d44 100644 --- a/sound/pci/pcxhr/pcxhr.c +++ b/sound/pci/pcxhr/pcxhr.c @@ -653,7 +653,7 @@ static int pcxhr_trigger(struct snd_pcm_substream *subs, int cmd) PCXHR_STREAM_STATUS_SCHEDULE_RUN; snd_pcm_trigger_done(s, subs); }
tasklet_hi_schedule(&chip->mgr->trigger_taskq);
tasklet_schedule(&chip->mgr->trigger_taskq);diff --git a/sound/pci/pcxhr/pcxhr_core.c b/sound/pci/pcxhr/pcxhr_core.c index 7143259..4a5481f 100644 --- a/sound/pci/pcxhr/pcxhr_core.c +++ b/sound/pci/pcxhr/pcxhr_core.c @@ -1213,7 +1213,7 @@ irqreturn_t pcxhr_interrupt(int irq, void *dev_id) mgr->dsp_time_last = PCXHR_DSP_TIME_INVALID; mgr->src_it_dsp = reg;
tasklet_hi_schedule(&mgr->msg_taskq);
tasklet_schedule(&mgr->msg_taskq);#ifdef CONFIG_SND_DEBUG_VERBOSE if (reg & PCXHR_FATAL_DSP_ERR) diff --git a/sound/pci/riptide/riptide.c b/sound/pci/riptide/riptide.c index e9f0706..1d0eeb1 100644 --- a/sound/pci/riptide/riptide.c +++ b/sound/pci/riptide/riptide.c @@ -1754,7 +1754,7 @@ snd_riptide_interrupt(int irq, void *dev_id) if (IS_EOBIRQ(cif->hwport) || IS_EOSIRQ(cif->hwport) || IS_EOCIRQ(cif->hwport)) { chip->handled_irqs++;
tasklet_hi_schedule(&chip->riptide_tq);
tasklet_schedule(&chip->riptide_tq);diff --git a/sound/pci/rme9652/hdsp.c b/sound/pci/rme9652/hdsp.c index fdd3be5..44d0c15 100644 --- a/sound/pci/rme9652/hdsp.c +++ b/sound/pci/rme9652/hdsp.c @@ -3750,7 +3750,7 @@ static irqreturn_t snd_hdsp_interrupt(int irq, void *dev_id) } } if (hdsp->use_midi_tasklet && schedule)
tasklet_hi_schedule(&hdsp->midi_tasklet);
tasklet_schedule(&hdsp->midi_tasklet);}
diff --git a/sound/pci/rme9652/hdspm.c b/sound/pci/rme9652/hdspm.c index dc5c4ba..71231cf 100644 --- a/sound/pci/rme9652/hdspm.c +++ b/sound/pci/rme9652/hdspm.c @@ -3476,7 +3476,7 @@ static irqreturn_t snd_hdspm_interrupt(int irq, void *dev_id) schedule = 1; } if (schedule)
tasklet_hi_schedule(&hdspm->midi_tasklet);
tasklet_schedule(&hdspm->midi_tasklet);}
diff --git a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c index fa4b113..ea903c8 100644 --- a/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c +++ b/sound/pcmcia/pdaudiocf/pdaudiocf_irq.c @@ -41,7 +41,7 @@ irqreturn_t pdacf_interrupt(int irq, void *dev) if (stat & PDAUDIOCF_IRQOVR) /* should never happen */ snd_printk(KERN_ERR "PDAUDIOCF SRAM buffer overrun detected!\n"); if (chip->pcm_substream)
tasklet_hi_schedule(&chip->tq);
tasklet_schedule(&chip->tq);diff --git a/sound/usb/usbmidi.c b/sound/usb/usbmidi.c index 5962e4b..6d9f9b1 100644 --- a/sound/usb/usbmidi.c +++ b/sound/usb/usbmidi.c @@ -880,7 +880,7 @@ static void snd_usbmidi_output_trigger(struct snd_rawmidi_substream *substream, snd_rawmidi_transmit_ack(substream, 1); return; }
tasklet_hi_schedule(&port->ep->tasklet);
tasklet_schedule(&port->ep->tasklet);}
participants (3)
-
Clemens Ladisch -
Fernando Lopez-Lezcano -
Takashi Iwai