* [PATCH v2 0/2] ALSA: Fix usb-audio races
@ 2017-01-02 15:50 Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu
` (2 more replies)
0 siblings, 3 replies; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-02 15:50 UTC (permalink / raw)
To: tiwai, perex, o-takashi; +Cc: linux-kernel, alsa-devel
Many thanks to Takashi Iwai & Sakamoto for their awesome feedback.
Changes since v1:
* Rebased my fix on top of tiwai's revert and integrated the changes
from the original fix into this.
* Dropped the stop_endpoints() call inside snd_usb_pcm_prepare() and
kept the previously existing snd_usb_endpoint_sync_pending_stop() call.
* Retained the deactivate_urbs() call in snd_usb_pcm_prepare(), I only
removed the can_sleep logic.
* Split the EP_FLAG_RUNNING check in a separate commit to keep the log
clean since this is not part of the race fix.
Ioan-Adrian Ratiu (2):
ALSA: usb-audio: Fix irq/process data synchronization
ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion
sound/usb/endpoint.c | 20 ++++++++++----------
sound/usb/endpoint.h | 2 +-
sound/usb/pcm.c | 10 +++++-----
3 files changed, 16 insertions(+), 16 deletions(-)
--
2.11.0
^ permalink raw reply [flat|nested] 8+ messages in thread
* [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization
2017-01-02 15:50 [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
@ 2017-01-02 15:50 ` Ioan-Adrian Ratiu
2017-01-04 6:28 ` Takashi Iwai
2017-01-02 15:50 ` [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion Ioan-Adrian Ratiu
2017-01-03 7:30 ` [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2 siblings, 1 reply; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-02 15:50 UTC (permalink / raw)
To: tiwai, perex, o-takashi; +Cc: linux-kernel, alsa-devel
Commit 16200948d83 ("ALSA: usb-audio: Fix race at stopping the stream") was
incomplete causing another more severe kernel panic, so it got reverted.
This fixes both the original problem and its fallout kernel race/crash.
The original fix is to move the endpoint member NULL clearing logic inside
wait_clear_urbs() so the irq triggering the urb completion doesn't call
retire_capture/playback_urb() after the NULL clearing and generate a panic.
However this creates a new race between snd_usb_endpoint_start()'s call
to wait_clear_urbs() and the irq urb completion handler which again calls
retire_capture/playback_urb() leading to a new NULL dereference.
We keep the EP deactivation code in snd_usb_endpoint_start() because
removing it will break the EP reference counting (see [1] [2] for info),
however we don't need the "can_sleep" mechanism anymore because a new
function was introduced (snd_usb_endpoint_sync_pending_stop()) which
synchronizes pending stops and gets called inside the pcm prepare callback.
It also makes sense to remove can_sleep because it was also removed from
deactivate_urbs() signature in [3] so we benefit from more simplification.
[1] commit 015618b90 ("ALSA: snd-usb: Fix URB cancellation at stream start")
[2] commit e9ba389c5 ("ALSA: usb-audio: Fix scheduling-while-atomic bug in PCM capture stream")
[3] commit ccc1696d5 ("ALSA: usb-audio: simplify endpoint deactivation code")
Fixes: f8114f8583bb ("Revert "ALSA: usb-audio: Fix race at stopping the stream"")
Signed-off-by: Ioan-Adrian Ratiu <adi@adirat.com>
---
sound/usb/endpoint.c | 17 +++++++----------
sound/usb/endpoint.h | 2 +-
sound/usb/pcm.c | 10 +++++-----
3 files changed, 13 insertions(+), 16 deletions(-)
diff --git a/sound/usb/endpoint.c b/sound/usb/endpoint.c
index 15d1d5c63c3c..2f0ea70a998c 100644
--- a/sound/usb/endpoint.c
+++ b/sound/usb/endpoint.c
@@ -534,6 +534,11 @@ static int wait_clear_urbs(struct snd_usb_endpoint *ep)
alive, ep->ep_num);
clear_bit(EP_FLAG_STOPPING, &ep->flags);
+ ep->data_subs = NULL;
+ ep->sync_slave = NULL;
+ ep->retire_data_urb = NULL;
+ ep->prepare_data_urb = NULL;
+
return 0;
}
@@ -912,9 +917,7 @@ int snd_usb_endpoint_set_params(struct snd_usb_endpoint *ep,
/**
* snd_usb_endpoint_start: start an snd_usb_endpoint
*
- * @ep: the endpoint to start
- * @can_sleep: flag indicating whether the operation is executed in
- * non-atomic context
+ * @ep: the endpoint to start
*
* A call to this function will increment the use count of the endpoint.
* In case it is not already running, the URBs for this endpoint will be
@@ -924,7 +927,7 @@ int snd_usb_endpoint_set_params(struct snd_usb_endpoint *ep,
*
* Returns an error if the URB submission failed, 0 in all other cases.
*/
-int snd_usb_endpoint_start(struct snd_usb_endpoint *ep, bool can_sleep)
+int snd_usb_endpoint_start(struct snd_usb_endpoint *ep)
{
int err;
unsigned int i;
@@ -938,8 +941,6 @@ int snd_usb_endpoint_start(struct snd_usb_endpoint *ep, bool can_sleep)
/* just to be sure */
deactivate_urbs(ep, false);
- if (can_sleep)
- wait_clear_urbs(ep);
ep->active_mask = 0;
ep->unlink_mask = 0;
@@ -1020,10 +1021,6 @@ void snd_usb_endpoint_stop(struct snd_usb_endpoint *ep)
if (--ep->use_count == 0) {
deactivate_urbs(ep, false);
- ep->data_subs = NULL;
- ep->sync_slave = NULL;
- ep->retire_data_urb = NULL;
- ep->prepare_data_urb = NULL;
set_bit(EP_FLAG_STOPPING, &ep->flags);
}
}
diff --git a/sound/usb/endpoint.h b/sound/usb/endpoint.h
index 6428392d8f62..584f295d7c77 100644
--- a/sound/usb/endpoint.h
+++ b/sound/usb/endpoint.h
@@ -18,7 +18,7 @@ int snd_usb_endpoint_set_params(struct snd_usb_endpoint *ep,
struct audioformat *fmt,
struct snd_usb_endpoint *sync_ep);
-int snd_usb_endpoint_start(struct snd_usb_endpoint *ep, bool can_sleep);
+int snd_usb_endpoint_start(struct snd_usb_endpoint *ep);
void snd_usb_endpoint_stop(struct snd_usb_endpoint *ep);
void snd_usb_endpoint_sync_pending_stop(struct snd_usb_endpoint *ep);
int snd_usb_endpoint_activate(struct snd_usb_endpoint *ep);
diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
index 34c6d4f2c0b6..657d54dffd2d 100644
--- a/sound/usb/pcm.c
+++ b/sound/usb/pcm.c
@@ -218,7 +218,7 @@ int snd_usb_init_pitch(struct snd_usb_audio *chip, int iface,
}
}
-static int start_endpoints(struct snd_usb_substream *subs, bool can_sleep)
+static int start_endpoints(struct snd_usb_substream *subs)
{
int err;
@@ -231,7 +231,7 @@ static int start_endpoints(struct snd_usb_substream *subs, bool can_sleep)
dev_dbg(&subs->dev->dev, "Starting data EP @%p\n", ep);
ep->data_subs = subs;
- err = snd_usb_endpoint_start(ep, can_sleep);
+ err = snd_usb_endpoint_start(ep);
if (err < 0) {
clear_bit(SUBSTREAM_FLAG_DATA_EP_STARTED, &subs->flags);
return err;
@@ -260,7 +260,7 @@ static int start_endpoints(struct snd_usb_substream *subs, bool can_sleep)
dev_dbg(&subs->dev->dev, "Starting sync EP @%p\n", ep);
ep->sync_slave = subs->data_endpoint;
- err = snd_usb_endpoint_start(ep, can_sleep);
+ err = snd_usb_endpoint_start(ep);
if (err < 0) {
clear_bit(SUBSTREAM_FLAG_SYNC_EP_STARTED, &subs->flags);
return err;
@@ -850,7 +850,7 @@ static int snd_usb_pcm_prepare(struct snd_pcm_substream *substream)
/* for playback, submit the URBs now; otherwise, the first hwptr_done
* updates for all URBs would happen at the same time when starting */
if (subs->direction == SNDRV_PCM_STREAM_PLAYBACK)
- ret = start_endpoints(subs, true);
+ return start_endpoints(subs);
unlock:
snd_usb_unlock_shutdown(subs->stream->chip);
@@ -1666,7 +1666,7 @@ static int snd_usb_substream_capture_trigger(struct snd_pcm_substream *substream
switch (cmd) {
case SNDRV_PCM_TRIGGER_START:
- err = start_endpoints(subs, false);
+ err = start_endpoints(subs);
if (err < 0)
return err;
--
2.11.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion
2017-01-02 15:50 [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu
@ 2017-01-02 15:50 ` Ioan-Adrian Ratiu
2017-01-03 7:30 ` [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2 siblings, 0 replies; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-02 15:50 UTC (permalink / raw)
To: tiwai, perex, o-takashi; +Cc: linux-kernel, alsa-devel
Testing EP_FLAG_RUNNING in snd_complete_urb() before running the completion
logic allows us to save a few cpu cycles by returning early, skipping the
pending urb in case the stream was stopped; the stop logic handles the urb
and sets the completion callbacks to NULL.
Signed-off-by: Ioan-Adrian Ratiu <adi@adirat.com>
---
sound/usb/endpoint.c | 3 +++
1 file changed, 3 insertions(+)
diff --git a/sound/usb/endpoint.c b/sound/usb/endpoint.c
index 2f0ea70a998c..c90607ebe155 100644
--- a/sound/usb/endpoint.c
+++ b/sound/usb/endpoint.c
@@ -384,6 +384,9 @@ static void snd_complete_urb(struct urb *urb)
if (unlikely(atomic_read(&ep->chip->shutdown)))
goto exit_clear;
+ if (unlikely(!test_bit(EP_FLAG_RUNNING, &ep->flags)))
+ goto exit_clear;
+
if (usb_pipeout(ep->pipe)) {
retire_outbound_urb(ep, ctx);
/* can be stopped during retire callback */
--
2.11.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH v2 0/2] ALSA: Fix usb-audio races
2017-01-02 15:50 [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion Ioan-Adrian Ratiu
@ 2017-01-03 7:30 ` Ioan-Adrian Ratiu
2017-01-03 8:47 ` Ioan-Adrian Ratiu
2 siblings, 1 reply; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-03 7:30 UTC (permalink / raw)
To: tiwai, perex, o-takashi; +Cc: linux-kernel, alsa-devel
On Mon, 02 Jan 2017, Ioan-Adrian Ratiu <adi@adirat.com> wrote:
> Many thanks to Takashi Iwai & Sakamoto for their awesome feedback.
>
> Changes since v1:
> * Rebased my fix on top of tiwai's revert and integrated the changes
> from the original fix into this.
> * Dropped the stop_endpoints() call inside snd_usb_pcm_prepare() and
> kept the previously existing snd_usb_endpoint_sync_pending_stop() call.
> * Retained the deactivate_urbs() call in snd_usb_pcm_prepare(), I only
> removed the can_sleep logic.
> * Split the EP_FLAG_RUNNING check in a separate commit to keep the log
> clean since this is not part of the race fix.
>
> Ioan-Adrian Ratiu (2):
> ALSA: usb-audio: Fix irq/process data synchronization
> ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion
>
> sound/usb/endpoint.c | 20 ++++++++++----------
> sound/usb/endpoint.h | 2 +-
> sound/usb/pcm.c | 10 +++++-----
> 3 files changed, 16 insertions(+), 16 deletions(-)
>
> --
> 2.11.0
@tiwai
You mentioned in a previous email to the first version I introduced a bug
by unballancing snd_usb_*lock_shutdown(), I think I managed to reproduce it
with v2. Is this trace a symptom of the bug you were refering to or is
this something newly introduced in v2?
I can't for the life of me figure out for sure how snd_usb_*lock_shutdown()
ballancing is affected by my patch. Any pointers how to fix this are
greatly appreciated.
[ 492.558350] INFO: task kworker/2:3:133 blocked for more than 120 seconds.
[ 492.558355] Not tainted 4.10.0-rc2-g0c771e68bbc8 #25
[ 492.558356] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 492.558359] kworker/2:3 D 0 133 2 0x00000000
[ 492.558368] Workqueue: usb_hub_wq hub_event
[ 492.558370] Call Trace:
[ 492.558377] ? __schedule+0x1dd/0x7f0
[ 492.558380] ? trace_hardirqs_on+0xd/0x10
[ 492.558384] schedule+0x3b/0x90
[ 492.558392] usb_audio_disconnect+0x1bf/0x220 [snd_usb_audio]
[ 492.558394] ? wake_atomic_t_function+0x50/0x50
[ 492.558397] usb_unbind_interface+0x7a/0x260
[ 492.558399] device_release_driver_internal+0x158/0x210
[ 492.558400] device_release_driver+0xd/0x10
[ 492.558401] bus_remove_device+0x10f/0x190
[ 492.558411] device_del+0x208/0x330
[ 492.558413] ? usb_remove_ep_devs+0x1a/0x30
[ 492.558414] usb_disable_device+0x99/0x270
[ 492.558416] usb_disconnect+0x87/0x2a0
[ 492.558417] hub_event+0x962/0x1530
[ 492.558419] process_one_work+0x221/0x4b0
[ 492.558420] ? process_one_work+0x1bb/0x4b0
[ 492.558421] worker_thread+0x46/0x4f0
[ 492.558423] kthread+0x102/0x140
[ 492.558424] ? process_one_work+0x4b0/0x4b0
[ 492.558425] ? kthread_create_on_node+0x40/0x40
[ 492.558427] ret_from_fork+0x27/0x40
[ 492.558428]
Showing all locks held in the system:
[ 492.558433] 2 locks held by khungtaskd/34:
[ 492.558434] #0: (rcu_read_lock){......}, at: [<ffffffff810da44f>] watchdog+0x9f/0x4a0
[ 492.558438] #1: (tasklist_lock){.+.+..}, at: [<ffffffff81094ffd>] debug_show_all_locks+0x3d/0x1a0
[ 492.558449] 6 locks held by kworker/2:3/133:
[ 492.558449] #0: ("usb_hub_wq"){.+.+.+}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
[ 492.558452] #1: ((&hub->events)){+.+.+.}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
[ 492.558455] #2: (&dev->mutex){......}, at: [<ffffffff814a4e3c>] hub_event+0x5c/0x1530
[ 492.558459] #3: (&dev->mutex){......}, at: [<ffffffff814a1abe>] usb_disconnect+0x4e/0x2a0
[ 492.558461] #4: (&dev->mutex){......}, at: [<ffffffff8142dd84>] device_release_driver_internal+0x34/0x210
[ 492.558464] #5: (register_mutex#3){+.+.+.}, at: [<ffffffffa07de27e>] usb_audio_disconnect+0x2e/0x220 [snd_usb_audio]
[ 492.558485] 2 locks held by idn/975:
[ 492.558485] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
[ 492.558489] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
[ 492.558494] 2 locks held by idn/1311:
[ 492.558494] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
[ 492.558497] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
[ 492.558500] =============================================
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2 0/2] ALSA: Fix usb-audio races
2017-01-03 7:30 ` [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
@ 2017-01-03 8:47 ` Ioan-Adrian Ratiu
2017-01-03 9:15 ` Takashi Iwai
0 siblings, 1 reply; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-03 8:47 UTC (permalink / raw)
To: tiwai, perex, o-takashi; +Cc: linux-kernel, alsa-devel
On Tue, 03 Jan 2017, Ioan-Adrian Ratiu <adi@adirat.com> wrote:
> On Mon, 02 Jan 2017, Ioan-Adrian Ratiu <adi@adirat.com> wrote:
>> Many thanks to Takashi Iwai & Sakamoto for their awesome feedback.
>>
>> Changes since v1:
>> * Rebased my fix on top of tiwai's revert and integrated the changes
>> from the original fix into this.
>> * Dropped the stop_endpoints() call inside snd_usb_pcm_prepare() and
>> kept the previously existing snd_usb_endpoint_sync_pending_stop() call.
>> * Retained the deactivate_urbs() call in snd_usb_pcm_prepare(), I only
>> removed the can_sleep logic.
>> * Split the EP_FLAG_RUNNING check in a separate commit to keep the log
>> clean since this is not part of the race fix.
>>
>> Ioan-Adrian Ratiu (2):
>> ALSA: usb-audio: Fix irq/process data synchronization
>> ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion
>>
>> sound/usb/endpoint.c | 20 ++++++++++----------
>> sound/usb/endpoint.h | 2 +-
>> sound/usb/pcm.c | 10 +++++-----
>> 3 files changed, 16 insertions(+), 16 deletions(-)
>>
>> --
>> 2.11.0
>
> @tiwai
>
> You mentioned in a previous email to the first version I introduced a bug
> by unballancing snd_usb_*lock_shutdown(), I think I managed to reproduce it
> with v2. Is this trace a symptom of the bug you were refering to or is
> this something newly introduced in v2?
>
> I can't for the life of me figure out for sure how snd_usb_*lock_shutdown()
> ballancing is affected by my patch. Any pointers how to fix this are
> greatly appreciated.
A bit more context on the trace: usb_audio_disconnect hangs while
waiting for all pending tasks to finish while the implicit feedback
endpoint sending errors at usb_submit_urb (err -19).
I could figure these out on my own but at the moment my time is very
limited and I don't want to keep you guys waiting after me so maybe
asking about it will be faster.
Thanks,
Ionel
>
> [ 492.558350] INFO: task kworker/2:3:133 blocked for more than 120 seconds.
> [ 492.558355] Not tainted 4.10.0-rc2-g0c771e68bbc8 #25
> [ 492.558356] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 492.558359] kworker/2:3 D 0 133 2 0x00000000
> [ 492.558368] Workqueue: usb_hub_wq hub_event
> [ 492.558370] Call Trace:
> [ 492.558377] ? __schedule+0x1dd/0x7f0
> [ 492.558380] ? trace_hardirqs_on+0xd/0x10
> [ 492.558384] schedule+0x3b/0x90
> [ 492.558392] usb_audio_disconnect+0x1bf/0x220 [snd_usb_audio]
> [ 492.558394] ? wake_atomic_t_function+0x50/0x50
> [ 492.558397] usb_unbind_interface+0x7a/0x260
> [ 492.558399] device_release_driver_internal+0x158/0x210
> [ 492.558400] device_release_driver+0xd/0x10
> [ 492.558401] bus_remove_device+0x10f/0x190
> [ 492.558411] device_del+0x208/0x330
> [ 492.558413] ? usb_remove_ep_devs+0x1a/0x30
> [ 492.558414] usb_disable_device+0x99/0x270
> [ 492.558416] usb_disconnect+0x87/0x2a0
> [ 492.558417] hub_event+0x962/0x1530
> [ 492.558419] process_one_work+0x221/0x4b0
> [ 492.558420] ? process_one_work+0x1bb/0x4b0
> [ 492.558421] worker_thread+0x46/0x4f0
> [ 492.558423] kthread+0x102/0x140
> [ 492.558424] ? process_one_work+0x4b0/0x4b0
> [ 492.558425] ? kthread_create_on_node+0x40/0x40
> [ 492.558427] ret_from_fork+0x27/0x40
> [ 492.558428]
> Showing all locks held in the system:
> [ 492.558433] 2 locks held by khungtaskd/34:
> [ 492.558434] #0: (rcu_read_lock){......}, at: [<ffffffff810da44f>] watchdog+0x9f/0x4a0
> [ 492.558438] #1: (tasklist_lock){.+.+..}, at: [<ffffffff81094ffd>] debug_show_all_locks+0x3d/0x1a0
> [ 492.558449] 6 locks held by kworker/2:3/133:
> [ 492.558449] #0: ("usb_hub_wq"){.+.+.+}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
> [ 492.558452] #1: ((&hub->events)){+.+.+.}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
> [ 492.558455] #2: (&dev->mutex){......}, at: [<ffffffff814a4e3c>] hub_event+0x5c/0x1530
> [ 492.558459] #3: (&dev->mutex){......}, at: [<ffffffff814a1abe>] usb_disconnect+0x4e/0x2a0
> [ 492.558461] #4: (&dev->mutex){......}, at: [<ffffffff8142dd84>] device_release_driver_internal+0x34/0x210
> [ 492.558464] #5: (register_mutex#3){+.+.+.}, at: [<ffffffffa07de27e>] usb_audio_disconnect+0x2e/0x220 [snd_usb_audio]
> [ 492.558485] 2 locks held by idn/975:
> [ 492.558485] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
> [ 492.558489] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
> [ 492.558494] 2 locks held by idn/1311:
> [ 492.558494] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
> [ 492.558497] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
>
> [ 492.558500] =============================================
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2 0/2] ALSA: Fix usb-audio races
2017-01-03 8:47 ` Ioan-Adrian Ratiu
@ 2017-01-03 9:15 ` Takashi Iwai
0 siblings, 0 replies; 8+ messages in thread
From: Takashi Iwai @ 2017-01-03 9:15 UTC (permalink / raw)
To: Ioan-Adrian Ratiu; +Cc: perex, o-takashi, alsa-devel, linux-kernel
On Tue, 03 Jan 2017 09:47:06 +0100,
Ioan-Adrian Ratiu wrote:
>
> On Tue, 03 Jan 2017, Ioan-Adrian Ratiu <adi@adirat.com> wrote:
> > On Mon, 02 Jan 2017, Ioan-Adrian Ratiu <adi@adirat.com> wrote:
> >> Many thanks to Takashi Iwai & Sakamoto for their awesome feedback.
> >>
> >> Changes since v1:
> >> * Rebased my fix on top of tiwai's revert and integrated the changes
> >> from the original fix into this.
> >> * Dropped the stop_endpoints() call inside snd_usb_pcm_prepare() and
> >> kept the previously existing snd_usb_endpoint_sync_pending_stop() call.
> >> * Retained the deactivate_urbs() call in snd_usb_pcm_prepare(), I only
> >> removed the can_sleep logic.
> >> * Split the EP_FLAG_RUNNING check in a separate commit to keep the log
> >> clean since this is not part of the race fix.
> >>
> >> Ioan-Adrian Ratiu (2):
> >> ALSA: usb-audio: Fix irq/process data synchronization
> >> ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion
> >>
> >> sound/usb/endpoint.c | 20 ++++++++++----------
> >> sound/usb/endpoint.h | 2 +-
> >> sound/usb/pcm.c | 10 +++++-----
> >> 3 files changed, 16 insertions(+), 16 deletions(-)
> >>
> >> --
> >> 2.11.0
> >
> > @tiwai
> >
> > You mentioned in a previous email to the first version I introduced a bug
> > by unballancing snd_usb_*lock_shutdown(), I think I managed to reproduce it
> > with v2. Is this trace a symptom of the bug you were refering to or is
> > this something newly introduced in v2?
> >
> > I can't for the life of me figure out for sure how snd_usb_*lock_shutdown()
> > ballancing is affected by my patch. Any pointers how to fix this are
> > greatly appreciated.
>
> A bit more context on the trace: usb_audio_disconnect hangs while
> waiting for all pending tasks to finish while the implicit feedback
> endpoint sending errors at usb_submit_urb (err -19).
>
> I could figure these out on my own but at the moment my time is very
> limited and I don't want to keep you guys waiting after me so maybe
> asking about it will be faster.
Yes, this looks like so. snd_usb_lock_shutdown() manages the autopm
with a refcount, and in usb_audio_disconnect(), the driver waits until
the refcount is cleared. The unbalanced call would result in an
endless wait there.
Takashi
>
> Thanks,
> Ionel
>
> >
> > [ 492.558350] INFO: task kworker/2:3:133 blocked for more than 120 seconds.
> > [ 492.558355] Not tainted 4.10.0-rc2-g0c771e68bbc8 #25
> > [ 492.558356] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [ 492.558359] kworker/2:3 D 0 133 2 0x00000000
> > [ 492.558368] Workqueue: usb_hub_wq hub_event
> > [ 492.558370] Call Trace:
> > [ 492.558377] ? __schedule+0x1dd/0x7f0
> > [ 492.558380] ? trace_hardirqs_on+0xd/0x10
> > [ 492.558384] schedule+0x3b/0x90
> > [ 492.558392] usb_audio_disconnect+0x1bf/0x220 [snd_usb_audio]
> > [ 492.558394] ? wake_atomic_t_function+0x50/0x50
> > [ 492.558397] usb_unbind_interface+0x7a/0x260
> > [ 492.558399] device_release_driver_internal+0x158/0x210
> > [ 492.558400] device_release_driver+0xd/0x10
> > [ 492.558401] bus_remove_device+0x10f/0x190
> > [ 492.558411] device_del+0x208/0x330
> > [ 492.558413] ? usb_remove_ep_devs+0x1a/0x30
> > [ 492.558414] usb_disable_device+0x99/0x270
> > [ 492.558416] usb_disconnect+0x87/0x2a0
> > [ 492.558417] hub_event+0x962/0x1530
> > [ 492.558419] process_one_work+0x221/0x4b0
> > [ 492.558420] ? process_one_work+0x1bb/0x4b0
> > [ 492.558421] worker_thread+0x46/0x4f0
> > [ 492.558423] kthread+0x102/0x140
> > [ 492.558424] ? process_one_work+0x4b0/0x4b0
> > [ 492.558425] ? kthread_create_on_node+0x40/0x40
> > [ 492.558427] ret_from_fork+0x27/0x40
> > [ 492.558428]
> > Showing all locks held in the system:
> > [ 492.558433] 2 locks held by khungtaskd/34:
> > [ 492.558434] #0: (rcu_read_lock){......}, at: [<ffffffff810da44f>] watchdog+0x9f/0x4a0
> > [ 492.558438] #1: (tasklist_lock){.+.+..}, at: [<ffffffff81094ffd>] debug_show_all_locks+0x3d/0x1a0
> > [ 492.558449] 6 locks held by kworker/2:3/133:
> > [ 492.558449] #0: ("usb_hub_wq"){.+.+.+}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
> > [ 492.558452] #1: ((&hub->events)){+.+.+.}, at: [<ffffffff8106705b>] process_one_work+0x1bb/0x4b0
> > [ 492.558455] #2: (&dev->mutex){......}, at: [<ffffffff814a4e3c>] hub_event+0x5c/0x1530
> > [ 492.558459] #3: (&dev->mutex){......}, at: [<ffffffff814a1abe>] usb_disconnect+0x4e/0x2a0
> > [ 492.558461] #4: (&dev->mutex){......}, at: [<ffffffff8142dd84>] device_release_driver_internal+0x34/0x210
> > [ 492.558464] #5: (register_mutex#3){+.+.+.}, at: [<ffffffffa07de27e>] usb_audio_disconnect+0x2e/0x220 [snd_usb_audio]
> > [ 492.558485] 2 locks held by idn/975:
> > [ 492.558485] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
> > [ 492.558489] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
> > [ 492.558494] 2 locks held by idn/1311:
> > [ 492.558494] #0: (&tty->ldisc_sem){++++++}, at: [<ffffffff815fd25d>] ldsem_down_read+0x2d/0x40
> > [ 492.558497] #1: (&ldata->atomic_read_lock){+.+.+.}, at: [<ffffffff81312160>] n_tty_read+0xb0/0x890
> >
> > [ 492.558500] =============================================
>
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization
2017-01-02 15:50 ` [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu
@ 2017-01-04 6:28 ` Takashi Iwai
2017-01-04 9:15 ` Ioan-Adrian Ratiu
0 siblings, 1 reply; 8+ messages in thread
From: Takashi Iwai @ 2017-01-04 6:28 UTC (permalink / raw)
To: Ioan-Adrian Ratiu; +Cc: perex, o-takashi, alsa-devel, linux-kernel
On Mon, 02 Jan 2017 16:50:30 +0100,
Ioan-Adrian Ratiu wrote:
>
> --- a/sound/usb/pcm.c
> +++ b/sound/usb/pcm.c
(snip)
> @@ -850,7 +850,7 @@ static int snd_usb_pcm_prepare(struct snd_pcm_substream *substream)
> /* for playback, submit the URBs now; otherwise, the first hwptr_done
> * updates for all URBs would happen at the same time when starting */
> if (subs->direction == SNDRV_PCM_STREAM_PLAYBACK)
> - ret = start_endpoints(subs, true);
> + return start_endpoints(subs);
Here you miss the unlock below.
>
> unlock:
> snd_usb_unlock_shutdown(subs->stream->chip);
... and this must be the reason of the hang up at disconnection, where
the driver ways forever at wait_event() in usb_audio_disconnect().
Could you fix this and resubmit v3? Other than that, it looks OK.
thanks,
Takashi
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization
2017-01-04 6:28 ` Takashi Iwai
@ 2017-01-04 9:15 ` Ioan-Adrian Ratiu
0 siblings, 0 replies; 8+ messages in thread
From: Ioan-Adrian Ratiu @ 2017-01-04 9:15 UTC (permalink / raw)
To: Takashi Iwai; +Cc: perex, o-takashi, alsa-devel, linux-kernel
On Wed, 04 Jan 2017, Takashi Iwai <tiwai@suse.de> wrote:
> On Mon, 02 Jan 2017 16:50:30 +0100,
> Ioan-Adrian Ratiu wrote:
>>
>> --- a/sound/usb/pcm.c
>> +++ b/sound/usb/pcm.c
> (snip)
>> @@ -850,7 +850,7 @@ static int snd_usb_pcm_prepare(struct snd_pcm_substream *substream)
>> /* for playback, submit the URBs now; otherwise, the first hwptr_done
>> * updates for all URBs would happen at the same time when starting */
>> if (subs->direction == SNDRV_PCM_STREAM_PLAYBACK)
>> - ret = start_endpoints(subs, true);
>> + return start_endpoints(subs);
>
> Here you miss the unlock below.
>
>>
>> unlock:
>> snd_usb_unlock_shutdown(subs->stream->chip);
>
> ... and this must be the reason of the hang up at disconnection, where
> the driver ways forever at wait_event() in usb_audio_disconnect().
>
> Could you fix this and resubmit v3? Other than that, it looks OK.
Sure, I'll resubmit v3 by tonight hopefully.
Thank you for taking a look at this, I didn't have a chance to look it
again since I posted v2.
Ionel
>
>
> thanks,
>
> Takashi
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2017-01-04 9:16 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-01-02 15:50 [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu
2017-01-04 6:28 ` Takashi Iwai
2017-01-04 9:15 ` Ioan-Adrian Ratiu
2017-01-02 15:50 ` [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion Ioan-Adrian Ratiu
2017-01-03 7:30 ` [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu
2017-01-03 8:47 ` Ioan-Adrian Ratiu
2017-01-03 9:15 ` Takashi Iwai
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).