Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1549258 > unrolled thread

[PATCH v2 0/2] ALSA: Fix usb-audio races

Back to article view | Back to linux.kernel

Contents

  [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-02 16:50 +0100
    [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-02 16:50 +0100
    [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-02 17:00 +0100
      Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Takashi Iwai <tiwai@suse.de> - 2017-01-04 07:30 +0100
        Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-04 10:20 +0100
    Re: [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-03 08:30 +0100
      Re: [PATCH v2 0/2] ALSA: Fix usb-audio races Ioan-Adrian Ratiu <adi@adirat.com> - 2017-01-03 09:50 +0100
        Re: [PATCH v2 0/2] ALSA: Fix usb-audio races Takashi Iwai <tiwai@suse.de> - 2017-01-03 10:20 +0100

#1549258 — [PATCH v2 0/2] ALSA: Fix usb-audio races

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

[toc] | [next] | [standalone]

#1549264 — [PATCH v2 2/2] ALSA: usb-audio: test EP_FLAG_RUNNING at urb completion

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

[toc] | [prev] | [next] | [standalone]

#1549267 — [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization

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

[toc] | [prev] | [next] | [standalone]

#1550456 — Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization

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

[toc] | [prev] | [next] | [standalone]

#1550551 — Re: [PATCH v2 1/2] ALSA: usb-audio: Fix irq/process data synchronization

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

[toc] | [prev] | [next] | [standalone]

#1549577

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] =============================================

[toc] | [prev] | [next] | [standalone]

#1549613

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] =============================================

[toc] | [prev] | [next] | [standalone]

#1549636

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] =============================================
> 

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web