Re: sound: WARNING in snd_rawmidi_transmit_ack
From: Dmitry Vyukov
Date: Mon Feb 01 2016 - 06:16:06 EST
On Sun, Jan 31, 2016 at 12:13 PM, Takashi Iwai <tiwai@xxxxxxx> wrote:
> On Wed, 27 Jan 2016 13:31:05 +0100,
> Dmitry Vyukov wrote:
>>
>> 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.
>
> This wasn't triggered on my machine. How did you start the test
> program?
I've attached my config.
Then I start qemu as:
$ qemu-system-x86_64 -hda
/usr/local/google/home/dvyukov/bin/wheezy.img -net
user,host=10.0.2.10,hostfwd=tcp::10022-:22 -net nic -nographic -kernel
arch/x86/boot/bzImage -append "console=ttyS0 root=/dev/sda debug
earlyprintk=serial slub_debug=UZ" -enable-kvm -pidfile vm_pid -m 2G
-numa node,nodeid=0,cpus=0-1 -numa node,nodeid=1,cpus=2-3 -smp
sockets=2,cores=2,threads=1 -usb -usbdevice mouse -usbdevice tablet
-soundhw all
Then I start programs using stress utility, if you have Go toolchain
installed you can get it with:
$ go get golang.org/x/tools/cmd/stress
$ ./stress -p 32 -failure=foobar ./a.out
This will run a.out constantly keeping 32 parallel processes and
ignoring any failures a.out itself.
> Meanwhile below is another patch to be applied in addition to the
> previous fix. There is a possible race in calling
> snd_rawmidi_transmit(), and this may result in such a warning.
>
>
> Takashi
>
> ---
> From: Takashi Iwai <tiwai@xxxxxxx>
> Subject: [PATCH] ALSA: rawmidi: Make snd_rawmidi_transmit() race-free
>
> Signed-off-by: Takashi Iwai <tiwai@xxxxxxx>
> ---
> sound/core/rawmidi.c | 95 ++++++++++++++++++++++++++++++++++------------------
> 1 file changed, 62 insertions(+), 33 deletions(-)
>
> diff --git a/sound/core/rawmidi.c b/sound/core/rawmidi.c
> index a7759846fbaa..3a27944c821c 100644
> --- a/sound/core/rawmidi.c
> +++ b/sound/core/rawmidi.c
> @@ -1054,24 +1054,9 @@ int snd_rawmidi_transmit_empty(struct snd_rawmidi_substream *substream)
> }
> EXPORT_SYMBOL(snd_rawmidi_transmit_empty);
>
> -/**
> - * snd_rawmidi_transmit_peek - copy data from the internal buffer
> - * @substream: the rawmidi substream
> - * @buffer: the buffer pointer
> - * @count: data size to transfer
> - *
> - * Copies data from the internal output buffer to the given buffer.
> - *
> - * Call this in the interrupt handler when the midi output is ready,
> - * and call snd_rawmidi_transmit_ack() after the transmission is
> - * finished.
> - *
> - * Return: The size of copied data, or a negative error code on failure.
> - */
> -int snd_rawmidi_transmit_peek(struct snd_rawmidi_substream *substream,
> +static int rawmidi_transmit_peek(struct snd_rawmidi_substream *substream,
> unsigned char *buffer, int count)
> {
> - unsigned long flags;
> int result, count1;
> struct snd_rawmidi_runtime *runtime = substream->runtime;
>
> @@ -1081,7 +1066,6 @@ int snd_rawmidi_transmit_peek(struct snd_rawmidi_substream *substream,
> return -EINVAL;
> }
> result = 0;
> - spin_lock_irqsave(&runtime->lock, flags);
> if (runtime->avail >= runtime->buffer_size) {
> /* warning: lowlevel layer MUST trigger down the hardware */
> goto __skip;
> @@ -1106,25 +1090,39 @@ int snd_rawmidi_transmit_peek(struct snd_rawmidi_substream *substream,
> }
> }
> __skip:
> - spin_unlock_irqrestore(&runtime->lock, flags);
> return result;
> }
> -EXPORT_SYMBOL(snd_rawmidi_transmit_peek);
>
> /**
> - * snd_rawmidi_transmit_ack - acknowledge the transmission
> + * snd_rawmidi_transmit_peek - copy data from the internal buffer
> * @substream: the rawmidi substream
> - * @count: the transferred count
> + * @buffer: the buffer pointer
> + * @count: data size to transfer
> *
> - * Advances the hardware pointer for the internal output buffer with
> - * the given size and updates the condition.
> - * Call after the transmission is finished.
> + * Copies data from the internal output buffer to the given buffer.
> *
> - * Return: The advanced size if successful, or a negative error code on failure.
> + * Call this in the interrupt handler when the midi output is ready,
> + * and call snd_rawmidi_transmit_ack() after the transmission is
> + * finished.
> + *
> + * Return: The size of copied data, or a negative error code on failure.
> */
> -int snd_rawmidi_transmit_ack(struct snd_rawmidi_substream *substream, int count)
> +int snd_rawmidi_transmit_peek(struct snd_rawmidi_substream *substream,
> + unsigned char *buffer, int count)
> {
> + struct snd_rawmidi_runtime *runtime = substream->runtime;
> + int result;
> unsigned long flags;
> +
> + spin_lock_irqsave(&runtime->lock, flags);
> + result = rawmidi_transmit_peek(substream, buffer, count);
> + spin_unlock_irqrestore(&runtime->lock, flags);
> + return result;
> +}
> +EXPORT_SYMBOL(snd_rawmidi_transmit_peek);
> +
> +static int rawmidi_transmit_ack(struct snd_rawmidi_substream *substream, int count)
> +{
> struct snd_rawmidi_runtime *runtime = substream->runtime;
>
> if (runtime->buffer == NULL) {
> @@ -1132,7 +1130,6 @@ int snd_rawmidi_transmit_ack(struct snd_rawmidi_substream *substream, int count)
> "snd_rawmidi_transmit_ack: output is not active!!!\n");
> return -EINVAL;
> }
> - spin_lock_irqsave(&runtime->lock, flags);
> snd_BUG_ON(runtime->avail + count > runtime->buffer_size);
> runtime->hw_ptr += count;
> runtime->hw_ptr %= runtime->buffer_size;
> @@ -1142,9 +1139,31 @@ int snd_rawmidi_transmit_ack(struct snd_rawmidi_substream *substream, int count)
> if (runtime->drain || snd_rawmidi_ready(substream))
> wake_up(&runtime->sleep);
> }
> - spin_unlock_irqrestore(&runtime->lock, flags);
> return count;
> }
> +
> +/**
> + * snd_rawmidi_transmit_ack - acknowledge the transmission
> + * @substream: the rawmidi substream
> + * @count: the transferred count
> + *
> + * Advances the hardware pointer for the internal output buffer with
> + * the given size and updates the condition.
> + * Call after the transmission is finished.
> + *
> + * Return: The advanced size if successful, or a negative error code on failure.
> + */
> +int snd_rawmidi_transmit_ack(struct snd_rawmidi_substream *substream, int count)
> +{
> + struct snd_rawmidi_runtime *runtime = substream->runtime;
> + int result;
> + unsigned long flags;
> +
> + spin_lock_irqsave(&runtime->lock, flags);
> + result = rawmidi_transmit_ack(substream, count);
> + spin_unlock_irqrestore(&runtime->lock, flags);
> + return result;
> +}
> EXPORT_SYMBOL(snd_rawmidi_transmit_ack);
>
> /**
> @@ -1160,12 +1179,22 @@ EXPORT_SYMBOL(snd_rawmidi_transmit_ack);
> int snd_rawmidi_transmit(struct snd_rawmidi_substream *substream,
> unsigned char *buffer, int count)
> {
> + struct snd_rawmidi_runtime *runtime = substream->runtime;
> + int result;
> + unsigned long flags;
> +
> + spin_lock_irqsave(&runtime->lock, flags);
> if (!substream->opened)
> - return -EBADFD;
> - count = snd_rawmidi_transmit_peek(substream, buffer, count);
> - if (count < 0)
> - return count;
> - return snd_rawmidi_transmit_ack(substream, count);
> + result = -EBADFD;
> + else {
> + count = rawmidi_transmit_peek(substream, buffer, count);
> + if (count <= 0)
> + result = count;
> + else
> + result = rawmidi_transmit_ack(substream, count);
> + }
> + spin_unlock_irqrestore(&runtime->lock, flags);
> + return result;
> }
> EXPORT_SYMBOL(snd_rawmidi_transmit);
>
> --
> 2.7.0
>
Attachment:
.config
Description: Binary data