* [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
* 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
* [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
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).