Re: sound: WARNING in snd_rawmidi_transmit_ack

From: Dmitry Vyukov
Date: Wed Jan 27 2016 - 07:31:36 EST

On Tue, Jan 26, 2016 at 3:51 PM, Takashi Iwai <tiwai@xxxxxxx> wrote:
> On Sun, 24 Jan 2016 17:29:12 +0100,
> Dmitry Vyukov wrote:
>>
>> Hello,
>>
>> The following program triggers WARNING in snd_rawmidi_transmit_ack:
>>
>> ------------[ cut here ]------------
>> WARNING: CPU: 1 PID: 20739 at sound/core/rawmidi.c:1136
>> snd_rawmidi_transmit_ack+0x275/0x400()
>> Modules linked in:
>> CPU: 1 PID: 20739 Comm: syz-executor Tainted: G W 4.4.0+ #276
>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
>> 00000000ffffffff ffff8800346af8d8 ffffffff82999e2d 0000000000000000
>> ffff88002fea97c0 ffffffff86d3f920 ffff8800346af918 ffffffff81352089
>> ffffffff84f80bd5 ffffffff86d3f920 0000000000000470 ffff8800600b9b68
>> Call Trace:
>> [< inline >] __dump_stack lib/dump_stack.c:15
>> [<ffffffff82999e2d>] dump_stack+0x6f/0xa2 lib/dump_stack.c:50
>> [<ffffffff81352089>] warn_slowpath_common+0xd9/0x140 kernel/panic.c:482
>> [<ffffffff813522b9>] warn_slowpath_null+0x29/0x30 kernel/panic.c:515
>> [<ffffffff84f80bd5>] snd_rawmidi_transmit_ack+0x275/0x400
>> sound/core/rawmidi.c:1136
>> [<ffffffff84fdb3c1>] snd_virmidi_output_trigger+0x4b1/0x5a0
>> sound/core/seq/seq_virmidi.c:163
>> [< inline >] snd_rawmidi_output_trigger sound/core/rawmidi.c:150
>> [<ffffffff84f87ed9>] snd_rawmidi_kernel_write1+0x549/0x780
>> sound/core/rawmidi.c:1223
>> [<ffffffff84f89fd3>] snd_rawmidi_write+0x543/0xb30 sound/core/rawmidi.c:1273
>> [<ffffffff817b0323>] __vfs_write+0x113/0x480 fs/read_write.c:528
>> [<ffffffff817b1db7>] vfs_write+0x167/0x4a0 fs/read_write.c:577
>> [< inline >] SYSC_write fs/read_write.c:624
>> [<ffffffff817b50a1>] SyS_write+0x111/0x220 fs/read_write.c:616
>> [<ffffffff86336c36>] entry_SYSCALL_64_fastpath+0x16/0x7a
>> arch/x86/entry/entry_64.S:185
>> ---[ end trace 93509ba74cc3e259 ]---
>>
>>
>> // autogenerated by syzkaller (http://github.com/google/syzkaller)
>> #include <pthread.h>
>> #include <stdint.h>
>> #include <string.h>
>> #include <sys/syscall.h>
>> #include <unistd.h>
>> #include <fcntl.h>
>>
>> long r[11];
>>
>> void* thr(void* arg)
>> {
>> switch ((long)arg) {
>> case 0:
>> r[0] = syscall(SYS_mmap, 0x20000000ul, 0x10000ul, 0x3ul, 0x32ul,
>> 0xfffffffffffffffful, 0x0ul);
>> break;
>> case 1:
>> r[1] = syscall(SYS_open, "/dev/dmmidi2", O_RDWR, 0);
>> break;
>> case 2:
>> *(uint32_t*)0x20006fda = (uint32_t)0x28;
>> *(uint32_t*)0x20006fde = (uint32_t)0x7;
>> *(uint64_t*)0x20006fe2 = (uint64_t)0x0;
>> *(uint64_t*)0x20006fea = (uint64_t)0x7;
>> *(uint64_t*)0x20006ff2 = (uint64_t)0x8;
>> *(uint16_t*)0x20006ffa = (uint16_t)0xfffffffffffffff8;
>> r[8] = syscall(SYS_write, r[1], 0x20006fdaul, 0x28ul, 0, 0, 0);
>> break;
>> case 3:
>> memcpy((void*)0x20007000,
>> "\x3c\x3f\xbc\xd7\x07\xee\x01\x21\x84\x26\x11\x6d\xc6\xc3"
>> "\xac\x7f\x14\xa3\x15\xda\xa1\x34\x67\xe9\xb6\xf8\xa8\xdd"
>> "\xb5\xe0\x2a\x64\x6e\x04\x7c\x40\xdb\x64\x4f\x53\x41\x90"
>> "\x02\x3b\x48\xba\xf6\xd7\x32\xe5\x11\x3f\xe5\xc5\xf2\x5f"
>> "\x4e\x6f\x5b\xe9\x0e\x76\x1a\x72\x77\x68\xad\xd3\x1b\x8d"
>> "\x8f\x71\x2f\x40\xde\xf4\xbf\x78\x48\xc2\xc3\xe5\xe9\x11"
>> "\x11\xd2\x9a\x91\x94\x81\x57\x22\xef\x2a\x5b\xe2\x9e\xce"
>> "\x3f\xa6\x07\x54\xd4\xb6\x1f\x30\xfd\x09\x35\x54\xcc\x78"
>> "\x12\x37\x59\xf7\x5c\x51\xd2\x47\xb8\x40\x98\x2b\xb4\x8d"
>> "\xbf\xd5\x34\x26\xcd\xb5\xe4\x98\x2d\x0e\xb1\x71\x0f\x12"
>> "\x06\xb0\x2c\x78\x74\xba\x3d\x32\x9c\x72\x96\x0d\x91\x50"
>> "\x9a\xe3\xbc\x4f\x1e\x26\xb2\xe3\xb2\xa2\x68\x6f\x10\xb5"
>> "\xc1\x7f\xfc\xfd\xf0\xe6\xd9\x0c\xa0\xa7\x54\x2c\x62\x0d"
>> "\xee\x04\x5b\x9d\x73\xf4\xcc\x29\x37\x01\xc2\x35\x8d\x3c"
>> "\x8a\x2f\xe3\xf5\x55\x42\x77\x55\x2d\x49\x6f\x46\xf7\x34"
>> "\xb1\x5f\xe7\x98\x55\xb5\x7c\x4e\xd7\x47\x18\xd1\xf9\xf2"
>> "\xd2\xfe\x47\xff\x22\x04\xa9\x32\xe9\xd6\x28\xda\xe1\x85"
>> "\xcb\xc5\xe6\xc1\xca\x9e\x3f\x1f\x80\xe6",
>> 248);
>> r[10] = syscall(SYS_write, r[1], 0x20007000ul, 0xf8ul, 0, 0, 0);
>> break;
>> }
>> return 0;
>> }
>>
>> int main()
>> {
>> long i;
>> pthread_t th[4];
>>
>> memset(r, -1, sizeof(r));
>> for (i = 0; i < 4; i++) {
>> pthread_create(&th[i], 0, thr, (void*)i);
>> usleep(10000);
>> }
>> for (i = 0; i < 4; i++) {
>> pthread_create(&th[i], 0, thr, (void*)i);
>> if (i % 2 == 0)
>> usleep(10000);
>> }
>> usleep(100000);
>> return 0;
>> }
>>
>> On commit 30f05309bde49295e02e45c7e615f73aa4e0ccc2.
>
> Could you check the patch below? It's untested yet in my side due to
> other bugs...

No, I still see the same warning.
Please try to reproduce it locally and test. I've attached my config.


[ 163.406601] ------------[ cut here ]------------
[ 163.407223] WARNING: CPU: 0 PID: 7812 at sound/core/rawmidi.c:1136
snd_rawmidi_transmit_ack+0x275/0x400()
[ 163.407552] Modules linked in:
[ 163.407552] CPU: 0 PID: 7812 Comm: a.out Not tainted 4.5.0-rc1+ #294
[ 163.407552] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS Bochs 01/01/2011
[ 163.407552] 00000000ffffffff ffff88005de5f8a8 ffffffff829e79ad
0000000000000000
[ 163.407552] ffff88005f848000 ffffffff86ef3060 ffff88005de5f8e8
ffffffff813536d9
[ 163.407552] ffffffff8507a085 ffffffff86ef3060 0000000000000470
ffff88005e9e8fa8
[ 163.407552] Call Trace:
[ 163.407552] [<ffffffff829e79ad>] dump_stack+0x6f/0xa2
[ 163.432954] [<ffffffff813536d9>] warn_slowpath_common+0xd9/0x140
[ 163.432954] [<ffffffff8507a085>] ? snd_rawmidi_transmit_ack+0x275/0x400
[ 163.432954] [<ffffffff81353909>] warn_slowpath_null+0x29/0x30
[ 163.432954] [<ffffffff8507a085>] snd_rawmidi_transmit_ack+0x275/0x400
[ 163.432954] [<ffffffff8507a5d0>] snd_rawmidi_transmit+0x70/0x90
[ 163.432954] [<ffffffff850d48a0>] snd_virmidi_output_trigger+0x480/0x570
[ 163.432954] [<ffffffff850d4420>] ? snd_virmidi_input_trigger+0x100/0x100
[ 163.432954] [<ffffffff85081389>] snd_rawmidi_kernel_write1+0x549/0x780
[ 163.432954] [<ffffffff85083483>] snd_rawmidi_write+0x543/0xb30
[ 163.432954] [<ffffffff85082f40>] ? snd_rawmidi_release+0xf0/0xf0
[ 163.432954] [<ffffffff81455c49>] ? __lock_acquire+0xea9/0x4700
[ 163.432954] [<ffffffff81453e78>] ? mark_held_locks+0xc8/0x120
[ 163.432954] [<ffffffff817a5e67>] ? mem_cgroup_commit_charge+0x187/0x2e0
[ 163.432954] [<ffffffff81454da0>] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 163.432954] [<ffffffff817b9013>] __vfs_write+0x113/0x480
[ 163.432954] [<ffffffff85082f40>] ? snd_rawmidi_release+0xf0/0xf0
[ 163.432954] [<ffffffff817b8f00>] ? vfs_iter_write+0x320/0x320
[ 163.432954] [<ffffffff814926e7>] ? debug_lockdep_rcu_enabled+0x77/0x90
[ 163.432954] [<ffffffff827eade5>] ? common_file_perm+0x155/0x3a0
[ 163.432954] [<ffffffff827eb242>] ? apparmor_file_permission+0x22/0x30
[ 163.432954] [<ffffffff82721a9c>] ? security_file_permission+0x8c/0x1f0
[ 163.432954] [<ffffffff817ba472>] ? rw_verify_area+0x102/0x2c0
[ 163.432954] [<ffffffff817baaa7>] vfs_write+0x167/0x4a0
[ 163.432954] [<ffffffff817bdd91>] SyS_write+0x111/0x220
[ 163.432954] [<ffffffff817bdc80>] ? SyS_read+0x220/0x220
[ 163.432954] [<ffffffff81005017>] ? trace_hardirqs_on_thunk+0x17/0x19
[ 163.432954] [<ffffffff864599b6>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 163.432954] ---[ end trace d6645f646c593dae ]---



> ---
> diff --git a/sound/core/seq/seq_virmidi.c b/sound/core/seq/seq_virmidi.c
> index 3da2d48610b3..1d13057c84cf 100644
> --- a/sound/core/seq/seq_virmidi.c
> +++ b/sound/core/seq/seq_virmidi.c
> @@ -160,8 +160,11 @@ static void snd_virmidi_output_trigger(struct snd_rawmidi_substream *substream,
> vmidi->trigger = 1;
> if (vmidi->seq_mode == SNDRV_VIRMIDI_SEQ_DISPATCH &&
> !(vmidi->rdev->flags & SNDRV_VIRMIDI_SUBSCRIBE)) {
> - snd_rawmidi_transmit_ack(substream, substream->runtime->buffer_size - substream->runtime->avail);
> - return; /* ignored */
> + while (snd_rawmidi_transmit(substream, buf,
> + sizeof(buf)) > 0) {
> + /* ignored */
> + }
> + return;
> }
> if (vmidi->event.type != SNDRV_SEQ_EVENT_NONE) {
> if (snd_seq_kernel_client_dispatch(vmidi->client, &vmidi->event, in_atomic(), 0) < 0)

Attachment: .config
Description: Binary data