Message ID | s5hpotgqbs5.wl-tiwai@suse.de (mailing list archive) |
---|---|
State | New, archived |
Headers | show |
On Sat, Apr 23, 2016 at 11:02 PM, Takashi Iwai <tiwai@suse.de> wrote: > On Sat, 23 Apr 2016 15:40:21 +0200, > Dmitry Vyukov wrote: >> >> Hi Takashi, >> >> I've incorporated your hrtimer fixes (but also updated to >> ddce192106e4f984123884f8e878f66ace94b573) and now I am seeing lots of >> the following deadlock messages: >> >> >> [ INFO: possible circular locking dependency detected ] >> 4.6.0-rc4+ #351 Not tainted >> ------------------------------------------------------- >> swapper/0/0 is trying to acquire lock: >> (&(&timer->lock)->rlock){-.-...}, at: [<ffffffff8537a749>] >> snd_timer_interrupt+0xa9/0xd30 sound/core/timer.c:701 >> >> but task is already holding lock: >> (&(&stime->lock)->rlock){-.....}, at: [<ffffffff85383d3f>] >> snd_hrtimer_callback+0x4f/0x2b0 sound/core/hrtimer.c:54 >> >> which lock already depends on the new lock. > > Oh crap, my second patch is buggy, it leads to ABBA lock, indeed. > The first patch is still OK, as it just adds a new behavior mode. > > Could you replace the second patch with the below one? I've replaced the second path with this one. The deadlocks has gone, but I've hit these two hangs that look related: https://gist.githubusercontent.com/dvyukov/805718ea249c49d17ae759d1b0160684/raw/20891f7e87fe9af3967565559d465d296469244b/gistfile1.txt https://gist.githubusercontent.com/dvyukov/7f397ea4aeb9e35596e0c8053cf35a11/raw/3fc22f24f7bab5941e47bab604f96487b5f1944d/gistfile1.txt
On Sun, Apr 24, 2016 at 5:16 PM, Dmitry Vyukov <dvyukov@google.com> wrote: > On Sat, Apr 23, 2016 at 11:02 PM, Takashi Iwai <tiwai@suse.de> wrote: >> On Sat, 23 Apr 2016 15:40:21 +0200, >> Dmitry Vyukov wrote: >>> >>> Hi Takashi, >>> >>> I've incorporated your hrtimer fixes (but also updated to >>> ddce192106e4f984123884f8e878f66ace94b573) and now I am seeing lots of >>> the following deadlock messages: >>> >>> >>> [ INFO: possible circular locking dependency detected ] >>> 4.6.0-rc4+ #351 Not tainted >>> ------------------------------------------------------- >>> swapper/0/0 is trying to acquire lock: >>> (&(&timer->lock)->rlock){-.-...}, at: [<ffffffff8537a749>] >>> snd_timer_interrupt+0xa9/0xd30 sound/core/timer.c:701 >>> >>> but task is already holding lock: >>> (&(&stime->lock)->rlock){-.....}, at: [<ffffffff85383d3f>] >>> snd_hrtimer_callback+0x4f/0x2b0 sound/core/hrtimer.c:54 >>> >>> which lock already depends on the new lock. >> >> Oh crap, my second patch is buggy, it leads to ABBA lock, indeed. >> The first patch is still OK, as it just adds a new behavior mode. >> >> Could you replace the second patch with the below one? > > > I've replaced the second path with this one. The deadlocks has gone, > but I've hit these two hangs that look related: > > https://gist.githubusercontent.com/dvyukov/805718ea249c49d17ae759d1b0160684/raw/20891f7e87fe9af3967565559d465d296469244b/gistfile1.txt > https://gist.githubusercontent.com/dvyukov/7f397ea4aeb9e35596e0c8053cf35a11/raw/3fc22f24f7bab5941e47bab604f96487b5f1944d/gistfile1.txt Another one: [ 509.169244] BUG: spinlock lockup suspected on CPU#2, syz-executor/23652 [ 509.169244] lock: 0xffff880065662038, .magic: dead4ead, .owner: syz-executor/23642, .owner_cpu: 0 [ 509.169244] CPU: 2 PID: 23652 Comm: syz-executor Not tainted 4.6.0-rc4+ #352 [ 509.169244] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011 [ 509.169244] ffffffff87eb25c0 ffff88006d407c58 ffffffff82c8fe0f ffffffff5f369e98 [ 509.169244] fffffbfff0fd64b8 ffff880065662038 ffff88005f369840 ffff88005e806040 [ 509.169244] ffff880065662040 000000009a9d0630 ffff88006d407c90 ffffffff8147f75d [ 509.169244] Call Trace: [ 509.169244] <IRQ> [<ffffffff82c8fe0f>] dump_stack+0x12e/0x18f [ 509.169244] [<ffffffff8147f75d>] spin_dump+0x14d/0x280 [ 509.169244] [<ffffffff8537ad39>] ? snd_timer_interrupt+0xa9/0xd30 [ 509.169244] [<ffffffff8147fa7d>] do_raw_spin_lock+0x15d/0x2b0 [ 509.169244] [<ffffffff867c04e7>] _raw_spin_lock_irqsave+0xa7/0xd0 [ 509.169244] [<ffffffff8537ad39>] ? snd_timer_interrupt+0xa9/0xd30 [ 509.169244] [<ffffffff8537ad39>] snd_timer_interrupt+0xa9/0xd30 [ 509.169244] [<ffffffff8127c405>] ? kvm_clock_get_cycles+0x25/0x30 [ 509.169244] [<ffffffff814e53ba>] ? ktime_get+0x32a/0x550 [ 509.169244] [<ffffffff853842e7>] ? snd_hrtimer_callback+0xb7/0x180 [ 509.169244] [<ffffffff814cff2c>] ? hrtimer_forward+0x1cc/0x3e0 [ 509.169244] [<ffffffff85384338>] snd_hrtimer_callback+0x108/0x180 [ 509.169244] [<ffffffff814d1241>] __hrtimer_run_queues+0x331/0xe90 [ 509.169244] [<ffffffff85384230>] ? snd_hrtimer_close+0xa0/0xa0 [ 509.169244] [<ffffffff814d0f10>] ? enqueue_hrtimer+0x3d0/0x3d0 [ 509.169244] [<ffffffff814d3c12>] hrtimer_interrupt+0x182/0x430 [ 509.169244] [<ffffffff8125aa62>] local_apic_timer_interrupt+0x72/0xe0 [ 509.169244] [<ffffffff867c31d9>] smp_apic_timer_interrupt+0x79/0xa0 [ 509.169244] [<ffffffff867c152c>] apic_timer_interrupt+0x8c/0xa0 [ 509.169244] <EOI> [<ffffffff8171902e>] ? unmap_page_range+0x8be/0x19f0
On Sun, 24 Apr 2016 17:16:32 +0200, Dmitry Vyukov wrote: > > On Sat, Apr 23, 2016 at 11:02 PM, Takashi Iwai <tiwai@suse.de> wrote: > > On Sat, 23 Apr 2016 15:40:21 +0200, > > Dmitry Vyukov wrote: > >> > >> Hi Takashi, > >> > >> I've incorporated your hrtimer fixes (but also updated to > >> ddce192106e4f984123884f8e878f66ace94b573) and now I am seeing lots of > >> the following deadlock messages: > >> > >> > >> [ INFO: possible circular locking dependency detected ] > >> 4.6.0-rc4+ #351 Not tainted > >> ------------------------------------------------------- > >> swapper/0/0 is trying to acquire lock: > >> (&(&timer->lock)->rlock){-.-...}, at: [<ffffffff8537a749>] > >> snd_timer_interrupt+0xa9/0xd30 sound/core/timer.c:701 > >> > >> but task is already holding lock: > >> (&(&stime->lock)->rlock){-.....}, at: [<ffffffff85383d3f>] > >> snd_hrtimer_callback+0x4f/0x2b0 sound/core/hrtimer.c:54 > >> > >> which lock already depends on the new lock. > > > > Oh crap, my second patch is buggy, it leads to ABBA lock, indeed. > > The first patch is still OK, as it just adds a new behavior mode. > > > > Could you replace the second patch with the below one? > > > I've replaced the second path with this one. The deadlocks has gone, > but I've hit these two hangs that look related: > > https://gist.githubusercontent.com/dvyukov/805718ea249c49d17ae759d1b0160684/raw/20891f7e87fe9af3967565559d465d296469244b/gistfile1.txt > https://gist.githubusercontent.com/dvyukov/7f397ea4aeb9e35596e0c8053cf35a11/raw/3fc22f24f7bab5941e47bab604f96487b5f1944d/gistfile1.txt Hmm, so it wasn't a good idea to call hrtimer_cancel() in the spinlock, in anyway. Scratch the previous one. OK, below is the yet revised two patches. One is the simplified version of the patch, and another is to call hrtimer_cancel() in a new timer op without spinlock. Apply these after the first patch "ALSA: timer: Allow backend disabling start/stop from handler". thanks, Takashi
On Sun, Apr 24, 2016 at 6:16 PM, Takashi Iwai <tiwai@suse.de> wrote: > On Sun, 24 Apr 2016 17:16:32 +0200, > Dmitry Vyukov wrote: >> >> On Sat, Apr 23, 2016 at 11:02 PM, Takashi Iwai <tiwai@suse.de> wrote: >> > On Sat, 23 Apr 2016 15:40:21 +0200, >> > Dmitry Vyukov wrote: >> >> >> >> Hi Takashi, >> >> >> >> I've incorporated your hrtimer fixes (but also updated to >> >> ddce192106e4f984123884f8e878f66ace94b573) and now I am seeing lots of >> >> the following deadlock messages: >> >> >> >> >> >> [ INFO: possible circular locking dependency detected ] >> >> 4.6.0-rc4+ #351 Not tainted >> >> ------------------------------------------------------- >> >> swapper/0/0 is trying to acquire lock: >> >> (&(&timer->lock)->rlock){-.-...}, at: [<ffffffff8537a749>] >> >> snd_timer_interrupt+0xa9/0xd30 sound/core/timer.c:701 >> >> >> >> but task is already holding lock: >> >> (&(&stime->lock)->rlock){-.....}, at: [<ffffffff85383d3f>] >> >> snd_hrtimer_callback+0x4f/0x2b0 sound/core/hrtimer.c:54 >> >> >> >> which lock already depends on the new lock. >> > >> > Oh crap, my second patch is buggy, it leads to ABBA lock, indeed. >> > The first patch is still OK, as it just adds a new behavior mode. >> > >> > Could you replace the second patch with the below one? >> >> >> I've replaced the second path with this one. The deadlocks has gone, >> but I've hit these two hangs that look related: >> >> https://gist.githubusercontent.com/dvyukov/805718ea249c49d17ae759d1b0160684/raw/20891f7e87fe9af3967565559d465d296469244b/gistfile1.txt >> https://gist.githubusercontent.com/dvyukov/7f397ea4aeb9e35596e0c8053cf35a11/raw/3fc22f24f7bab5941e47bab604f96487b5f1944d/gistfile1.txt > > Hmm, so it wasn't a good idea to call hrtimer_cancel() in the > spinlock, in anyway. Scratch the previous one. > > OK, below is the yet revised two patches. One is the simplified > version of the patch, and another is to call hrtimer_cancel() in a new > timer op without spinlock. Apply these after the first patch > "ALSA: timer: Allow backend disabling start/stop from handler". Done. I will let you know if I see any failures.
diff --git a/sound/core/hrtimer.c b/sound/core/hrtimer.c index 656d9a9032dc..27e2493c94e4 100644 --- a/sound/core/hrtimer.c +++ b/sound/core/hrtimer.c @@ -38,7 +38,6 @@ static unsigned int resolution; struct snd_hrtimer { struct snd_timer *timer; struct hrtimer hrt; - atomic_t running; }; static enum hrtimer_restart snd_hrtimer_callback(struct hrtimer *hrt) @@ -46,14 +45,11 @@ static enum hrtimer_restart snd_hrtimer_callback(struct hrtimer *hrt) struct snd_hrtimer *stime = container_of(hrt, struct snd_hrtimer, hrt); struct snd_timer *t = stime->timer; unsigned long oruns; - - if (!atomic_read(&stime->running)) - return HRTIMER_NORESTART; + int ret; oruns = hrtimer_forward_now(hrt, ns_to_ktime(t->sticks * resolution)); - snd_timer_interrupt(stime->timer, t->sticks * oruns); - - if (!atomic_read(&stime->running)) + ret = snd_timer_interrupt(stime->timer, t->sticks * oruns); + if (ret == SNDRV_TIMER_RET_STOP) return HRTIMER_NORESTART; return HRTIMER_RESTART; } @@ -68,7 +64,6 @@ static int snd_hrtimer_open(struct snd_timer *t) hrtimer_init(&stime->hrt, CLOCK_MONOTONIC, HRTIMER_MODE_REL); stime->timer = t; stime->hrt.function = snd_hrtimer_callback; - atomic_set(&stime->running, 0); t->private_data = stime; return 0; } @@ -89,24 +84,22 @@ static int snd_hrtimer_start(struct snd_timer *t) { struct snd_hrtimer *stime = t->private_data; - atomic_set(&stime->running, 0); - hrtimer_try_to_cancel(&stime->hrt); hrtimer_start(&stime->hrt, ns_to_ktime(t->sticks * resolution), HRTIMER_MODE_REL); - atomic_set(&stime->running, 1); return 0; } static int snd_hrtimer_stop(struct snd_timer *t) { struct snd_hrtimer *stime = t->private_data; - atomic_set(&stime->running, 0); - hrtimer_try_to_cancel(&stime->hrt); + + hrtimer_cancel(&stime->hrt); return 0; } static struct snd_timer_hardware hrtimer_hw = { - .flags = SNDRV_TIMER_HW_AUTO | SNDRV_TIMER_HW_TASKLET, + .flags = SNDRV_TIMER_HW_AUTO | SNDRV_TIMER_HW_TASKLET | + SNDRV_TIMER_HW_RET_CTRL, .open = snd_hrtimer_open, .close = snd_hrtimer_close, .start = snd_hrtimer_start,