All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-19  2:50 Shuah Khan
  2016-03-19  2:57 ` Mauro Carvalho Chehab
  2016-03-19 12:10   ` Mauro Carvalho Chehab
  0 siblings, 2 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-19  2:50 UTC (permalink / raw)
  To: mchehab, tiwai, perex; +Cc: Shuah Khan, linux-media, alsa-devel, linux-kernel

Fix to release stream resources from media_snd_device_delete() before
media device is unregistered. Without this change, stream resource free
is attempted after the media device is unregistered which would result
in use-after-free errors.

Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
---

- Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
  while running mc_nextgen_test loop (1000 iterations) in parallel.
- Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
  generated graphs when after bind/unbind, rmmod/modprobe. Graphs
  look good.
- Note: Please apply the following patch to fix memory leak:
  sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
  https://lkml.org/lkml/2016/3/16/1050

 sound/usb/media.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/sound/usb/media.c b/sound/usb/media.c
index de4a815..e35af88 100644
--- a/sound/usb/media.c
+++ b/sound/usb/media.c
@@ -301,6 +301,13 @@ int media_snd_device_create(struct snd_usb_audio *chip,
 void media_snd_device_delete(struct snd_usb_audio *chip)
 {
 	struct media_device *mdev = chip->media_dev;
+	struct snd_usb_stream *stream;
+
+	/* release resources */
+	list_for_each_entry(stream, &chip->pcm_list, list) {
+		media_snd_stream_delete(&stream->substream[0]);
+		media_snd_stream_delete(&stream->substream[1]);
+	}
 
 	media_snd_mixer_delete(chip);
 
-- 
2.5.0

^ permalink raw reply related	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19  2:50 [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete() Shuah Khan
@ 2016-03-19  2:57 ` Mauro Carvalho Chehab
  2016-03-19 10:39   ` Mauro Carvalho Chehab
  2016-03-19 12:10   ` Mauro Carvalho Chehab
  1 sibling, 1 reply; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-19  2:57 UTC (permalink / raw)
  To: Shuah Khan; +Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel

Em Fri, 18 Mar 2016 20:50:31 -0600
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> Fix to release stream resources from media_snd_device_delete() before
> media device is unregistered. Without this change, stream resource free
> is attempted after the media device is unregistered which would result
> in use-after-free errors.
> 
> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> ---
> 
> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>   while running mc_nextgen_test loop (1000 iterations) in parallel.
> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>   look good.
> - Note: Please apply the following patch to fix memory leak:
>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>   https://lkml.org/lkml/2016/3/16/1050
> 
>  sound/usb/media.c | 7 +++++++
>  1 file changed, 7 insertions(+)
> 
> diff --git a/sound/usb/media.c b/sound/usb/media.c
> index de4a815..e35af88 100644
> --- a/sound/usb/media.c
> +++ b/sound/usb/media.c
> @@ -301,6 +301,13 @@ int media_snd_device_create(struct snd_usb_audio *chip,
>  void media_snd_device_delete(struct snd_usb_audio *chip)
>  {
>  	struct media_device *mdev = chip->media_dev;
> +	struct snd_usb_stream *stream;
> +
> +	/* release resources */
> +	list_for_each_entry(stream, &chip->pcm_list, list) {
> +		media_snd_stream_delete(&stream->substream[0]);
> +		media_snd_stream_delete(&stream->substream[1]);

I'll look on it better tomorrow, but it sounds weird to hardcode
substream[0] and [1] here... are you sure that this is valid for
*all* devices supported by snd-usb-audio?

Regards,
Mauro

> +	}
>  
>  	media_snd_mixer_delete(chip);
>  


-- 
Thanks,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19  2:57 ` Mauro Carvalho Chehab
@ 2016-03-19 10:39   ` Mauro Carvalho Chehab
  2016-03-19 13:25       ` Shuah Khan
  0 siblings, 1 reply; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-19 10:39 UTC (permalink / raw)
  To: Shuah Khan; +Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel

Em Fri, 18 Mar 2016 23:57:08 -0300
Mauro Carvalho Chehab <mchehab@osg.samsung.com> escreveu:

> Em Fri, 18 Mar 2016 20:50:31 -0600
> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
> 
> > Fix to release stream resources from media_snd_device_delete() before
> > media device is unregistered. Without this change, stream resource free
> > is attempted after the media device is unregistered which would result
> > in use-after-free errors.
> > 
> > Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> > ---
> > 
> > - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
> >   while running mc_nextgen_test loop (1000 iterations) in parallel.
> > - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
> >   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
> >   look good.
> > - Note: Please apply the following patch to fix memory leak:
> >   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
> >   https://lkml.org/lkml/2016/3/16/1050
> > 
> >  sound/usb/media.c | 7 +++++++
> >  1 file changed, 7 insertions(+)
> > 
> > diff --git a/sound/usb/media.c b/sound/usb/media.c
> > index de4a815..e35af88 100644
> > --- a/sound/usb/media.c
> > +++ b/sound/usb/media.c
> > @@ -301,6 +301,13 @@ int media_snd_device_create(struct snd_usb_audio *chip,
> >  void media_snd_device_delete(struct snd_usb_audio *chip)
> >  {
> >  	struct media_device *mdev = chip->media_dev;
> > +	struct snd_usb_stream *stream;
> > +
> > +	/* release resources */
> > +	list_for_each_entry(stream, &chip->pcm_list, list) {
> > +		media_snd_stream_delete(&stream->substream[0]);
> > +		media_snd_stream_delete(&stream->substream[1]);  
> 
> I'll look on it better tomorrow, but it sounds weird to hardcode
> substream[0] and [1] here... are you sure that this is valid for
> *all* devices supported by snd-usb-audio?

After looking at pcm.c and finding this:

static void snd_usb_audio_stream_free(struct snd_usb_stream *stream)
{
	free_substream(&stream->substream[0]);
	free_substream(&stream->substream[1]);
	list_del(&stream->list);
	kfree(stream);
}

It seems that assuming that substream is always an array with size 2
is right.

I'll do some tests with it today with your patch.

Regards,
Mauro

> 
> Regards,
> Mauro
> 
> > +	}
> >  
> >  	media_snd_mixer_delete(chip);
> >    
> 
> 


-- 
Thanks,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19  2:50 [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete() Shuah Khan
@ 2016-03-19 12:10   ` Mauro Carvalho Chehab
  2016-03-19 12:10   ` Mauro Carvalho Chehab
  1 sibling, 0 replies; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-19 12:10 UTC (permalink / raw)
  To: Shuah Khan; +Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel

Em Fri, 18 Mar 2016 20:50:31 -0600
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> Fix to release stream resources from media_snd_device_delete() before
> media device is unregistered. Without this change, stream resource free
> is attempted after the media device is unregistered which would result
> in use-after-free errors.
> 
> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> ---
> 
> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>   while running mc_nextgen_test loop (1000 iterations) in parallel.
> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>   look good.
> - Note: Please apply the following patch to fix memory leak:
>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>   https://lkml.org/lkml/2016/3/16/1050

Yeah, a way better!

For normal bind/unbind, it seems to be working fine. Also
for driver's rmmod, so:

Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>

PS.:
===

There are still some troubles if we run an infinite loop
binding/unbinding au0828 and another one binding/unbinding
snd-usb-audio, like this one:


[   91.556188] ------------[ cut here ]------------
[   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
[   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
[   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
[   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
[   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
[   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
[   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
[   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
[   91.556768] Call Trace:
[   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
[   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
[   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
[   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
[   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
[   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
[   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
[   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
[   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
[   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
[   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
[   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
[   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
[   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
[   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
[   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
[   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
[   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
[   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
[   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
[   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
[   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
[   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
[   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
[   91.556872] ---[ end trace 3e95e11ff0b9efad ]---

I suspect that something is not properly protected by the graph mutex at
either ALSA or au0828 driver.

I also got a GPF:

[   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
[   95.398936] au0828: Deactivate link Error 0
[   95.398943] tuner 6-0061: Putting tuner to sleep
[   95.398960] kasan: CONFIG_KASAN_INLINE enabled
[   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
[   95.398967] general protection fault: 0000 [#2] SMP KASAN
[   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
[   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
[   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
[   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
[   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
[   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
[   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
[   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
[   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
[   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
[   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
[   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
[   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
[   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
[   95.401255] Stack:
[   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
[   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
[   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
[   95.401518] Call Trace:
[   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
[   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
[   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
[   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
[   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
[   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
[   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
[   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
[   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
[   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
[   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
[   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
[   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
[   95.430358]  RSP <ffff8803a45a7d18>
[   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---

As nobody expects someone to do infinite loops binding/unbinding
both drivers, I guess it is ok to keep it for Kernel 4.6, but
we need to find a way fix those locking issues for dynamic graph
changes.

Regards,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-19 12:10   ` Mauro Carvalho Chehab
  0 siblings, 0 replies; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-19 12:10 UTC (permalink / raw)
  To: Shuah Khan; +Cc: linux-kernel, alsa-devel, linux-media, tiwai

Em Fri, 18 Mar 2016 20:50:31 -0600
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> Fix to release stream resources from media_snd_device_delete() before
> media device is unregistered. Without this change, stream resource free
> is attempted after the media device is unregistered which would result
> in use-after-free errors.
> 
> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> ---
> 
> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>   while running mc_nextgen_test loop (1000 iterations) in parallel.
> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>   look good.
> - Note: Please apply the following patch to fix memory leak:
>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>   https://lkml.org/lkml/2016/3/16/1050

Yeah, a way better!

For normal bind/unbind, it seems to be working fine. Also
for driver's rmmod, so:

Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>

PS.:
===

There are still some troubles if we run an infinite loop
binding/unbinding au0828 and another one binding/unbinding
snd-usb-audio, like this one:


[   91.556188] ------------[ cut here ]------------
[   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
[   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec 
 bluetooth
[   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
[   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
[   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
[   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
[   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
[   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
[   91.556768] Call Trace:
[   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
[   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
[   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
[   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
[   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
[   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
[   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
[   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
[   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
[   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
[   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
[   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
[   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
[   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
[   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
[   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
[   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
[   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
[   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
[   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
[   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
[   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
[   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
[   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
[   91.556872] ---[ end trace 3e95e11ff0b9efad ]---

I suspect that something is not properly protected by the graph mutex at
either ALSA or au0828 driver.

I also got a GPF:

[   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
[   95.398936] au0828: Deactivate link Error 0
[   95.398943] tuner 6-0061: Putting tuner to sleep
[   95.398960] kasan: CONFIG_KASAN_INLINE enabled
[   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
[   95.398967] general protection fault: 0000 [#2] SMP KASAN
[   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec 
 bluetooth
[   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
[   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
[   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
[   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
[   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
[   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
[   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
[   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
[   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
[   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
[   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
[   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
[   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
[   95.401255] Stack:
[   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
[   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
[   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
[   95.401518] Call Trace:
[   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
[   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
[   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
[   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
[   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
[   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
[   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
[   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
[   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
[   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
[   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
[   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
[   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
[   95.430358]  RSP <ffff8803a45a7d18>
[   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---

As nobody expects someone to do infinite loops binding/unbinding
both drivers, I guess it is ok to keep it for Kernel 4.6, but
we need to find a way fix those locking issues for dynamic graph
changes.

Regards,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19 10:39   ` Mauro Carvalho Chehab
@ 2016-03-19 13:25       ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-19 13:25 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/19/2016 04:39 AM, Mauro Carvalho Chehab wrote:
> Em Fri, 18 Mar 2016 23:57:08 -0300
> Mauro Carvalho Chehab <mchehab@osg.samsung.com> escreveu:
> 
>> Em Fri, 18 Mar 2016 20:50:31 -0600
>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>
>>> Fix to release stream resources from media_snd_device_delete() before
>>> media device is unregistered. Without this change, stream resource free
>>> is attempted after the media device is unregistered which would result
>>> in use-after-free errors.
>>>
>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>> ---
>>>
>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>   look good.
>>> - Note: Please apply the following patch to fix memory leak:
>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>   https://lkml.org/lkml/2016/3/16/1050
>>>
>>>  sound/usb/media.c | 7 +++++++
>>>  1 file changed, 7 insertions(+)
>>>
>>> diff --git a/sound/usb/media.c b/sound/usb/media.c
>>> index de4a815..e35af88 100644
>>> --- a/sound/usb/media.c
>>> +++ b/sound/usb/media.c
>>> @@ -301,6 +301,13 @@ int media_snd_device_create(struct snd_usb_audio *chip,
>>>  void media_snd_device_delete(struct snd_usb_audio *chip)
>>>  {
>>>  	struct media_device *mdev = chip->media_dev;
>>> +	struct snd_usb_stream *stream;
>>> +
>>> +	/* release resources */
>>> +	list_for_each_entry(stream, &chip->pcm_list, list) {
>>> +		media_snd_stream_delete(&stream->substream[0]);
>>> +		media_snd_stream_delete(&stream->substream[1]);  
>>
>> I'll look on it better tomorrow, but it sounds weird to hardcode
>> substream[0] and [1] here... are you sure that this is valid for
>> *all* devices supported by snd-usb-audio?
> 
> After looking at pcm.c and finding this:
> 
> static void snd_usb_audio_stream_free(struct snd_usb_stream *stream)
> {
> 	free_substream(&stream->substream[0]);
> 	free_substream(&stream->substream[1]);
> 	list_del(&stream->list);
> 	kfree(stream);
> }
> 
> It seems that assuming that substream is always an array with size 2
> is right.
> 
> I'll do some tests with it today with your patch.
> 

Right. snd-usb-audio uses this in several places like the one above you found.

thanks,
-- Shuah


-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-19 13:25       ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-19 13:25 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: alsa-devel, tiwai, Shuah Khan, linux-kernel, linux-media

On 03/19/2016 04:39 AM, Mauro Carvalho Chehab wrote:
> Em Fri, 18 Mar 2016 23:57:08 -0300
> Mauro Carvalho Chehab <mchehab@osg.samsung.com> escreveu:
> 
>> Em Fri, 18 Mar 2016 20:50:31 -0600
>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>
>>> Fix to release stream resources from media_snd_device_delete() before
>>> media device is unregistered. Without this change, stream resource free
>>> is attempted after the media device is unregistered which would result
>>> in use-after-free errors.
>>>
>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>> ---
>>>
>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>   look good.
>>> - Note: Please apply the following patch to fix memory leak:
>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>   https://lkml.org/lkml/2016/3/16/1050
>>>
>>>  sound/usb/media.c | 7 +++++++
>>>  1 file changed, 7 insertions(+)
>>>
>>> diff --git a/sound/usb/media.c b/sound/usb/media.c
>>> index de4a815..e35af88 100644
>>> --- a/sound/usb/media.c
>>> +++ b/sound/usb/media.c
>>> @@ -301,6 +301,13 @@ int media_snd_device_create(struct snd_usb_audio *chip,
>>>  void media_snd_device_delete(struct snd_usb_audio *chip)
>>>  {
>>>  	struct media_device *mdev = chip->media_dev;
>>> +	struct snd_usb_stream *stream;
>>> +
>>> +	/* release resources */
>>> +	list_for_each_entry(stream, &chip->pcm_list, list) {
>>> +		media_snd_stream_delete(&stream->substream[0]);
>>> +		media_snd_stream_delete(&stream->substream[1]);  
>>
>> I'll look on it better tomorrow, but it sounds weird to hardcode
>> substream[0] and [1] here... are you sure that this is valid for
>> *all* devices supported by snd-usb-audio?
> 
> After looking at pcm.c and finding this:
> 
> static void snd_usb_audio_stream_free(struct snd_usb_stream *stream)
> {
> 	free_substream(&stream->substream[0]);
> 	free_substream(&stream->substream[1]);
> 	list_del(&stream->list);
> 	kfree(stream);
> }
> 
> It seems that assuming that substream is always an array with size 2
> is right.
> 
> I'll do some tests with it today with your patch.
> 

Right. snd-usb-audio uses this in several places like the one above you found.

thanks,
-- Shuah


-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19 12:10   ` Mauro Carvalho Chehab
@ 2016-03-19 13:31     ` Shuah Khan
  -1 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-19 13:31 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
> Em Fri, 18 Mar 2016 20:50:31 -0600
> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
> 
>> Fix to release stream resources from media_snd_device_delete() before
>> media device is unregistered. Without this change, stream resource free
>> is attempted after the media device is unregistered which would result
>> in use-after-free errors.
>>
>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>> ---
>>
>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>   look good.
>> - Note: Please apply the following patch to fix memory leak:
>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>   https://lkml.org/lkml/2016/3/16/1050
> 
> Yeah, a way better!
> 
> For normal bind/unbind, it seems to be working fine. Also
> for driver's rmmod, so:
> 
> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
> 
> PS.:
> ===
> 
> There are still some troubles if we run an infinite loop
> binding/unbinding au0828 and another one binding/unbinding
> snd-usb-audio, like this one:

Yes. I noticed this one when I was running a loop of 1000 on au0828.
I couldn't reproduce this when I tested this patch.

P.S: au08282 loops takes longer btw since au0828 initialization is lot more
complex. We have to look at this one.

> 
> 
> [   91.556188] ------------[ cut here ]------------
> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
> [   91.556768] Call Trace:
> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
> 
> I suspect that something is not properly protected by the graph mutex at
> either ALSA or au0828 driver.
> 
> I also got a GPF:
> 
> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
> [   95.398936] au0828: Deactivate link Error 0
> [   95.398943] tuner 6-0061: Putting tuner to sleep
> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
> [   95.401255] Stack:
> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
> [   95.401518] Call Trace:
> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
> [   95.430358]  RSP <ffff8803a45a7d18>
> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
> 
> As nobody expects someone to do infinite loops binding/unbinding
> both drivers, I guess it is ok to keep it for Kernel 4.6, but
> we need to find a way fix those locking issues for dynamic graph
> changes.
> 

Yes. Right. We have to look at these closely. I agree nobody runs a stress
bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
and race type issue in au0828 v4l2 release path. I have had to fix some issues
there in the past. I agree with you that we are good for 4.6-rc1 and I can 
continue to look at this. We can get this fixed for rc2 or rc3.

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-19 13:31     ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-19 13:31 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: alsa-devel, tiwai, Shuah Khan, linux-kernel, linux-media

On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
> Em Fri, 18 Mar 2016 20:50:31 -0600
> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
> 
>> Fix to release stream resources from media_snd_device_delete() before
>> media device is unregistered. Without this change, stream resource free
>> is attempted after the media device is unregistered which would result
>> in use-after-free errors.
>>
>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>> ---
>>
>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>   look good.
>> - Note: Please apply the following patch to fix memory leak:
>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>   https://lkml.org/lkml/2016/3/16/1050
> 
> Yeah, a way better!
> 
> For normal bind/unbind, it seems to be working fine. Also
> for driver's rmmod, so:
> 
> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
> 
> PS.:
> ===
> 
> There are still some troubles if we run an infinite loop
> binding/unbinding au0828 and another one binding/unbinding
> snd-usb-audio, like this one:

Yes. I noticed this one when I was running a loop of 1000 on au0828.
I couldn't reproduce this when I tested this patch.

P.S: au08282 loops takes longer btw since au0828 initialization is lot more
complex. We have to look at this one.

> 
> 
> [   91.556188] ------------[ cut here ]------------
> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_code
 c bluetooth
> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
> [   91.556768] Call Trace:
> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
> 
> I suspect that something is not properly protected by the graph mutex at
> either ALSA or au0828 driver.
> 
> I also got a GPF:
> 
> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
> [   95.398936] au0828: Deactivate link Error 0
> [   95.398943] tuner 6-0061: Putting tuner to sleep
> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_code
 c bluetooth
> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
> [   95.401255] Stack:
> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
> [   95.401518] Call Trace:
> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
> [   95.430358]  RSP <ffff8803a45a7d18>
> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
> 
> As nobody expects someone to do infinite loops binding/unbinding
> both drivers, I guess it is ok to keep it for Kernel 4.6, but
> we need to find a way fix those locking issues for dynamic graph
> changes.
> 

Yes. Right. We have to look at these closely. I agree nobody runs a stress
bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
and race type issue in au0828 v4l2 release path. I have had to fix some issues
there in the past. I agree with you that we are good for 4.6-rc1 and I can 
continue to look at this. We can get this fixed for rc2 or rc3.

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-19 13:31     ` Shuah Khan
@ 2016-03-22  4:01       ` Shuah Khan
  -1 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22  4:01 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/19/2016 07:31 AM, Shuah Khan wrote:
> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>> Em Fri, 18 Mar 2016 20:50:31 -0600
>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>
>>> Fix to release stream resources from media_snd_device_delete() before
>>> media device is unregistered. Without this change, stream resource free
>>> is attempted after the media device is unregistered which would result
>>> in use-after-free errors.
>>>
>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>> ---
>>>
>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>   look good.
>>> - Note: Please apply the following patch to fix memory leak:
>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>   https://lkml.org/lkml/2016/3/16/1050
>>
>> Yeah, a way better!
>>
>> For normal bind/unbind, it seems to be working fine. Also
>> for driver's rmmod, so:
>>
>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
>>
>> PS.:
>> ===
>>
>> There are still some troubles if we run an infinite loop
>> binding/unbinding au0828 and another one binding/unbinding
>> snd-usb-audio, like this one:
> 
> Yes. I noticed this one when I was running a loop of 1000 on au0828.
> I couldn't reproduce this when I tested this patch.
> 
> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
> complex. We have to look at this one.
> 
>>
>>
>> [   91.556188] ------------[ cut here ]------------
>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>> [   91.556768] Call Trace:
>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>
>> I suspect that something is not properly protected by the graph mutex at
>> either ALSA or au0828 driver.
>>
>> I also got a GPF:
>>
>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>> [   95.398936] au0828: Deactivate link Error 0
>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>> [   95.401255] Stack:
>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>> [   95.401518] Call Trace:
>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>> [   95.430358]  RSP <ffff8803a45a7d18>
>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>
>> As nobody expects someone to do infinite loops binding/unbinding
>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>> we need to find a way fix those locking issues for dynamic graph
>> changes.
>>
> 
> Yes. Right. We have to look at these closely. I agree nobody runs a stress
> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
> and race type issue in au0828 v4l2 release path. I have had to fix some issues
> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
> continue to look at this. We can get this fixed for rc2 or rc3.
> 

I isolated this problem to an existing race condition between au0828_v4l2_open()
and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
loop test triggers it.

au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
detect the device disconnected state correctly, if au0828_v4l2_open() runs
to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
by increasing the likelihood of au0828_v4l2_open() occurring while unbind
is in progress. When au0828_v4l2_close() fails to detect that the device
is in disconnect state, it attempts to power down the device and fails with
the both of the above problems.

The second one from xc5000_sleep() would trigger without any of the new
patches. I am building Linux 4.5 to verify that.

I am sending one line fix patch. I ran the loop test 1000 times and didn't
see the above two issues.

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-22  4:01       ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22  4:01 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/19/2016 07:31 AM, Shuah Khan wrote:
> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>> Em Fri, 18 Mar 2016 20:50:31 -0600
>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>
>>> Fix to release stream resources from media_snd_device_delete() before
>>> media device is unregistered. Without this change, stream resource free
>>> is attempted after the media device is unregistered which would result
>>> in use-after-free errors.
>>>
>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>> ---
>>>
>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>   look good.
>>> - Note: Please apply the following patch to fix memory leak:
>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>   https://lkml.org/lkml/2016/3/16/1050
>>
>> Yeah, a way better!
>>
>> For normal bind/unbind, it seems to be working fine. Also
>> for driver's rmmod, so:
>>
>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
>>
>> PS.:
>> ===
>>
>> There are still some troubles if we run an infinite loop
>> binding/unbinding au0828 and another one binding/unbinding
>> snd-usb-audio, like this one:
> 
> Yes. I noticed this one when I was running a loop of 1000 on au0828.
> I couldn't reproduce this when I tested this patch.
> 
> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
> complex. We have to look at this one.
> 
>>
>>
>> [   91.556188] ------------[ cut here ]------------
>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_cod
 ec bluetooth
>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>> [   91.556768] Call Trace:
>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>
>> I suspect that something is not properly protected by the graph mutex at
>> either ALSA or au0828 driver.
>>
>> I also got a GPF:
>>
>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>> [   95.398936] au0828: Deactivate link Error 0
>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_cod
 ec bluetooth
>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>> [   95.401255] Stack:
>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>> [   95.401518] Call Trace:
>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>> [   95.430358]  RSP <ffff8803a45a7d18>
>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>
>> As nobody expects someone to do infinite loops binding/unbinding
>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>> we need to find a way fix those locking issues for dynamic graph
>> changes.
>>
> 
> Yes. Right. We have to look at these closely. I agree nobody runs a stress
> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
> and race type issue in au0828 v4l2 release path. I have had to fix some issues
> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
> continue to look at this. We can get this fixed for rc2 or rc3.
> 

I isolated this problem to an existing race condition between au0828_v4l2_open()
and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
loop test triggers it.

au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
detect the device disconnected state correctly, if au0828_v4l2_open() runs
to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
by increasing the likelihood of au0828_v4l2_open() occurring while unbind
is in progress. When au0828_v4l2_close() fails to detect that the device
is in disconnect state, it attempts to power down the device and fails with
the both of the above problems.

The second one from xc5000_sleep() would trigger without any of the new
patches. I am building Linux 4.5 to verify that.

I am sending one line fix patch. I ran the loop test 1000 times and didn't
see the above two issues.

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-22  4:01       ` Shuah Khan
@ 2016-03-22 13:03         ` Shuah Khan
  -1 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22 13:03 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/21/2016 10:01 PM, Shuah Khan wrote:
> On 03/19/2016 07:31 AM, Shuah Khan wrote:
>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>>> Em Fri, 18 Mar 2016 20:50:31 -0600
>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>>
>>>> Fix to release stream resources from media_snd_device_delete() before
>>>> media device is unregistered. Without this change, stream resource free
>>>> is attempted after the media device is unregistered which would result
>>>> in use-after-free errors.
>>>>
>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>>> ---
>>>>
>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>>   look good.
>>>> - Note: Please apply the following patch to fix memory leak:
>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>>   https://lkml.org/lkml/2016/3/16/1050
>>>
>>> Yeah, a way better!
>>>
>>> For normal bind/unbind, it seems to be working fine. Also
>>> for driver's rmmod, so:
>>>
>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
>>>
>>> PS.:
>>> ===
>>>
>>> There are still some troubles if we run an infinite loop
>>> binding/unbinding au0828 and another one binding/unbinding
>>> snd-usb-audio, like this one:
>>
>> Yes. I noticed this one when I was running a loop of 1000 on au0828.
>> I couldn't reproduce this when I tested this patch.
>>
>> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
>> complex. We have to look at this one.
>>
>>>
>>>
>>> [   91.556188] ------------[ cut here ]------------
>>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>>> [   91.556768] Call Trace:
>>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>>
>>> I suspect that something is not properly protected by the graph mutex at
>>> either ALSA or au0828 driver.
>>>
>>> I also got a GPF:
>>>
>>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>>> [   95.398936] au0828: Deactivate link Error 0
>>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>>> [   95.401255] Stack:
>>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>>> [   95.401518] Call Trace:
>>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>> [   95.430358]  RSP <ffff8803a45a7d18>
>>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>>
>>> As nobody expects someone to do infinite loops binding/unbinding
>>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>>> we need to find a way fix those locking issues for dynamic graph
>>> changes.
>>>
>>
>> Yes. Right. We have to look at these closely. I agree nobody runs a stress
>> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
>> and race type issue in au0828 v4l2 release path. I have had to fix some issues
>> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
>> continue to look at this. We can get this fixed for rc2 or rc3.
>>
> 
> I isolated this problem to an existing race condition between au0828_v4l2_open()
> and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
> loop test triggers it.
> 
> au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
> detect the device disconnected state correctly, if au0828_v4l2_open() runs
> to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
> by increasing the likelihood of au0828_v4l2_open() occurring while unbind
> is in progress. When au0828_v4l2_close() fails to detect that the device
> is in disconnect state, it attempts to power down the device and fails with
> the both of the above problems.
> 
> The second one from xc5000_sleep() would trigger without any of the new
> patches. I am building Linux 4.5 to verify that.
> 

Hi Mauro,

Reproduced the problem on Linux 4.5 release. Here is the log. The patch
I sent https://lkml.org/lkml/2016/3/22/3 should go into stable releases
as well.

Mar 22 06:55:16 anduin kernel: [  883.235413] PM: Removing info for No Bus:video1
Mar 22 06:55:16 anduin kernel: [  883.236165] device: 'vbi0': device_unregister
Mar 22 06:55:16 anduin kernel: [  883.237883] kasan: CONFIG_KASAN_INLINE enabled
Mar 22 06:55:16 anduin kernel: [  883.237893] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN
Mar 22 06:55:16 anduin kernel: [  883.237988] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi ir_lirc_codec snd_seq_device lirc_dev binfmt_misc rc_hauppauge au8522_dig nls_iso8859_1 xc5000 tuner au8522_decoder au8522_common hp_wmi sparse_keymap au0828 ghash_clmulni_intel aesni_intel tveeprom aes_x86_64 ablk_helper dvb_core cryptd lrw gf128mul uvcvideo glue_helper rc_core v4l2_common joydev videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core serio_raw videodev media k10temp i2c_piix4 snd_hda_codec_idt snd_hda_codec_generic snd_hda_codec_hdmi snd_hda_intel snd_hda_codec tpm_infineon snd_hda_core snd_hwdep snd_pcm hp_accel lis3lv02d input_polldev mac_hid snd_timer kvm_amd tpm_tis kvm irqbypass parport_pc ppdev lp parport autofs4 p
 l
2303 usbserial hid_generic psmouse usbhid hid radeon i2c_algo_bit ttm drm_kms_helper syscopyarea sysfillrect sysimgblt firewire_ohci fb_sys_fops sdhci_pci firewire_core sdhci crc_itu_t r8169 drm mii wmi video
Mar 22 06:55:16 anduin kernel: [  883.239547] CPU: 1 PID: 2793 Comm: v4l_id Not tainted 4.5.0 #16
Mar 22 06:55:16 anduin kernel: [  883.239613] Hardware name: Hewlett-Packard HP ProBook 6475b/180F, BIOS 68TTU Ver. F.04 08/03/2012
Mar 22 06:55:16 anduin kernel: [  883.239709] task: ffff88009a0fcd80 ti: ffff8800942f0000 task.ti: ffff8800942f0000
Mar 22 06:55:16 anduin kernel: [  883.239790] RIP: 0010:[<ffffffff82102264>]  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
Mar 22 06:55:16 anduin kernel: [  883.239896] PM: Removing info for No Bus:vbi0
Mar 22 06:55:16 anduin kernel: [  883.239947] RSP: 0018:ffff8800942f7d10  EFLAGS: 00010212
Mar 22 06:55:16 anduin kernel: [  883.240007] RAX: dffffc0000000000 RBX: ffff8801eef75338 RCX: ffff88009a0fd5b8
Mar 22 06:55:16 anduin kernel: [  883.240093] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
Mar 22 06:55:16 anduin kernel: [  883.240189] RBP: ffff8800942f7d88 R08: 0000000000000006 R09: 0000000000000000
Mar 22 06:55:16 anduin kernel: [  883.240284] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801eef76874
Mar 22 06:55:16 anduin kernel: [  883.240381] R13: 0000000000000000 R14: dffffc0000000000 R15: ffff8801eef74000
Mar 22 06:55:16 anduin kernel: [  883.240478] FS:  00007f83985c4700(0000) GS:ffff8801fa880000(0000) knlGS:0000000000000000
Mar 22 06:55:16 anduin kernel: [  883.240586] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar 22 06:55:16 anduin kernel: [  883.240664] CR2: 000055fd2e0ec000 CR3: 000000009426d000 CR4: 00000000000406e0
Mar 22 06:55:16 anduin kernel: [  883.240754] Stack:
Mar 22 06:55:16 anduin kernel: [  883.240779]  dffffc0000000000 ffff8801eef74000 ffff8800942f7d40 ffffffffa0f58f0f
Mar 22 06:55:16 anduin kernel: [  883.240873]  ffff88009a0fd5d8 ffff8801eeee4050 ffff8800942f7d58 ffffffffa0e3803c
Mar 22 06:55:16 anduin kernel: [  883.240966]  ffff880100000000 ffff880000000000 ffff8801eef75338 ffff8801eef76874
Mar 22 06:55:16 anduin kernel: [  883.241058] Call Trace:
Mar 22 06:55:16 anduin kernel: [  883.241095]  [<ffffffffa0f58f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
Mar 22 06:55:16 anduin kernel: [  883.241166]  [<ffffffffa0e3803c>] ? fe_standby+0x3c/0x50 [tuner]
Mar 22 06:55:16 anduin kernel: [  883.241242]  [<ffffffffa0e8bade>] au0828_v4l2_close+0x36e/0x570 [au0828]
Mar 22 06:55:16 anduin kernel: [  883.241348]  [<ffffffffa0c70ec0>] v4l2_release+0xf0/0x210 [videodev]
Mar 22 06:55:16 anduin kernel: [  883.241438]  [<ffffffff815662fc>] __fput+0x1fc/0x6c0
Mar 22 06:55:16 anduin kernel: [  883.241508]  [<ffffffff8156682e>] ____fput+0xe/0x10
Mar 22 06:55:16 anduin kernel: [  883.241583]  [<ffffffff8116a813>] task_work_run+0x133/0x1f0
Mar 22 06:55:16 anduin kernel: [  883.241664]  [<ffffffff810035d0>] exit_to_usermode_loop+0x140/0x170
Mar 22 06:55:16 anduin kernel: [  883.241747]  [<ffffffff810061b6>] syscall_return_slowpath+0x156/0x1b0
Mar 22 06:55:16 anduin kernel: [  883.241838]  [<ffffffff82829db1>] int_ret_from_sys_call+0x25/0x9f
Mar 22 06:55:16 anduin kernel: [  883.241921] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 fd 53 48 83 c7 40 48 83 ec 50 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 7b 07 00 00 49 8d 7d 18 48 b8 00 00 00 00 00
Mar 22 06:55:16 anduin kernel: [  883.242471] RIP  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
Mar 22 06:55:16 anduin kernel: [  883.242612]  RSP <ffff8800942f7d10>

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-22 13:03         ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22 13:03 UTC (permalink / raw)
  To: Mauro Carvalho Chehab
  Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel, Shuah Khan

On 03/21/2016 10:01 PM, Shuah Khan wrote:
> On 03/19/2016 07:31 AM, Shuah Khan wrote:
>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>>> Em Fri, 18 Mar 2016 20:50:31 -0600
>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>>
>>>> Fix to release stream resources from media_snd_device_delete() before
>>>> media device is unregistered. Without this change, stream resource free
>>>> is attempted after the media device is unregistered which would result
>>>> in use-after-free errors.
>>>>
>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>>> ---
>>>>
>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>>   look good.
>>>> - Note: Please apply the following patch to fix memory leak:
>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>>   https://lkml.org/lkml/2016/3/16/1050
>>>
>>> Yeah, a way better!
>>>
>>> For normal bind/unbind, it seems to be working fine. Also
>>> for driver's rmmod, so:
>>>
>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>
>>>
>>> PS.:
>>> ===
>>>
>>> There are still some troubles if we run an infinite loop
>>> binding/unbinding au0828 and another one binding/unbinding
>>> snd-usb-audio, like this one:
>>
>> Yes. I noticed this one when I was running a loop of 1000 on au0828.
>> I couldn't reproduce this when I tested this patch.
>>
>> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
>> complex. We have to look at this one.
>>
>>>
>>>
>>> [   91.556188] ------------[ cut here ]------------
>>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_co
 dec bluetooth
>>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>>> [   91.556768] Call Trace:
>>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>>
>>> I suspect that something is not properly protected by the graph mutex at
>>> either ALSA or au0828 driver.
>>>
>>> I also got a GPF:
>>>
>>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>>> [   95.398936] au0828: Deactivate link Error 0
>>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_co
 dec bluetooth
>>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>>> [   95.401255] Stack:
>>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>>> [   95.401518] Call Trace:
>>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>> [   95.430358]  RSP <ffff8803a45a7d18>
>>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>>
>>> As nobody expects someone to do infinite loops binding/unbinding
>>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>>> we need to find a way fix those locking issues for dynamic graph
>>> changes.
>>>
>>
>> Yes. Right. We have to look at these closely. I agree nobody runs a stress
>> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
>> and race type issue in au0828 v4l2 release path. I have had to fix some issues
>> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
>> continue to look at this. We can get this fixed for rc2 or rc3.
>>
> 
> I isolated this problem to an existing race condition between au0828_v4l2_open()
> and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
> loop test triggers it.
> 
> au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
> detect the device disconnected state correctly, if au0828_v4l2_open() runs
> to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
> by increasing the likelihood of au0828_v4l2_open() occurring while unbind
> is in progress. When au0828_v4l2_close() fails to detect that the device
> is in disconnect state, it attempts to power down the device and fails with
> the both of the above problems.
> 
> The second one from xc5000_sleep() would trigger without any of the new
> patches. I am building Linux 4.5 to verify that.
> 

Hi Mauro,

Reproduced the problem on Linux 4.5 release. Here is the log. The patch
I sent https://lkml.org/lkml/2016/3/22/3 should go into stable releases
as well.

Mar 22 06:55:16 anduin kernel: [  883.235413] PM: Removing info for No Bus:video1
Mar 22 06:55:16 anduin kernel: [  883.236165] device: 'vbi0': device_unregister
Mar 22 06:55:16 anduin kernel: [  883.237883] kasan: CONFIG_KASAN_INLINE enabled
Mar 22 06:55:16 anduin kernel: [  883.237893] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN
Mar 22 06:55:16 anduin kernel: [  883.237988] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi ir_lirc_codec snd_seq_device lirc_dev binfmt_misc rc_hauppauge au8522_dig nls_iso8859_1 xc5000 tuner au8522_decoder au8522_common hp_wmi sparse_keymap au0828 ghash_clmulni_intel aesni_intel tveeprom aes_x86_64 ablk_helper dvb_core cryptd lrw gf128mul uvcvideo glue_helper rc_core v4l2_common joydev videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core serio_raw videodev media k10temp i2c_piix4 snd_hda_codec_idt snd_hda_codec_generic snd_hda_cod
 ec_hdmi snd_hda_intel snd_hda_codec tpm_infineon snd_hda_core snd_hwdep snd_pcm hp_accel lis3lv02d input_polldev mac_hid snd_timer kvm_amd tpm_tis kvm irqbypass parport_pc ppdev lp parport autofs4 p
 l
2303 usbserial hid_generic psmouse usbhid hid radeon i2c_algo_bit ttm drm_kms_helper syscopyarea sysfillrect sysimgblt firewire_ohci fb_sys_fops sdhci_pci firewire_core sdhci crc_itu_t r8169 drm mii wmi video
Mar 22 06:55:16 anduin kernel: [  883.239547] CPU: 1 PID: 2793 Comm: v4l_id Not tainted 4.5.0 #16
Mar 22 06:55:16 anduin kernel: [  883.239613] Hardware name: Hewlett-Packard HP ProBook 6475b/180F, BIOS 68TTU Ver. F.04 08/03/2012
Mar 22 06:55:16 anduin kernel: [  883.239709] task: ffff88009a0fcd80 ti: ffff8800942f0000 task.ti: ffff8800942f0000
Mar 22 06:55:16 anduin kernel: [  883.239790] RIP: 0010:[<ffffffff82102264>]  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
Mar 22 06:55:16 anduin kernel: [  883.239896] PM: Removing info for No Bus:vbi0
Mar 22 06:55:16 anduin kernel: [  883.239947] RSP: 0018:ffff8800942f7d10  EFLAGS: 00010212
Mar 22 06:55:16 anduin kernel: [  883.240007] RAX: dffffc0000000000 RBX: ffff8801eef75338 RCX: ffff88009a0fd5b8
Mar 22 06:55:16 anduin kernel: [  883.240093] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
Mar 22 06:55:16 anduin kernel: [  883.240189] RBP: ffff8800942f7d88 R08: 0000000000000006 R09: 0000000000000000
Mar 22 06:55:16 anduin kernel: [  883.240284] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801eef76874
Mar 22 06:55:16 anduin kernel: [  883.240381] R13: 0000000000000000 R14: dffffc0000000000 R15: ffff8801eef74000
Mar 22 06:55:16 anduin kernel: [  883.240478] FS:  00007f83985c4700(0000) GS:ffff8801fa880000(0000) knlGS:0000000000000000
Mar 22 06:55:16 anduin kernel: [  883.240586] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar 22 06:55:16 anduin kernel: [  883.240664] CR2: 000055fd2e0ec000 CR3: 000000009426d000 CR4: 00000000000406e0
Mar 22 06:55:16 anduin kernel: [  883.240754] Stack:
Mar 22 06:55:16 anduin kernel: [  883.240779]  dffffc0000000000 ffff8801eef74000 ffff8800942f7d40 ffffffffa0f58f0f
Mar 22 06:55:16 anduin kernel: [  883.240873]  ffff88009a0fd5d8 ffff8801eeee4050 ffff8800942f7d58 ffffffffa0e3803c
Mar 22 06:55:16 anduin kernel: [  883.240966]  ffff880100000000 ffff880000000000 ffff8801eef75338 ffff8801eef76874
Mar 22 06:55:16 anduin kernel: [  883.241058] Call Trace:
Mar 22 06:55:16 anduin kernel: [  883.241095]  [<ffffffffa0f58f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
Mar 22 06:55:16 anduin kernel: [  883.241166]  [<ffffffffa0e3803c>] ? fe_standby+0x3c/0x50 [tuner]
Mar 22 06:55:16 anduin kernel: [  883.241242]  [<ffffffffa0e8bade>] au0828_v4l2_close+0x36e/0x570 [au0828]
Mar 22 06:55:16 anduin kernel: [  883.241348]  [<ffffffffa0c70ec0>] v4l2_release+0xf0/0x210 [videodev]
Mar 22 06:55:16 anduin kernel: [  883.241438]  [<ffffffff815662fc>] __fput+0x1fc/0x6c0
Mar 22 06:55:16 anduin kernel: [  883.241508]  [<ffffffff8156682e>] ____fput+0xe/0x10
Mar 22 06:55:16 anduin kernel: [  883.241583]  [<ffffffff8116a813>] task_work_run+0x133/0x1f0
Mar 22 06:55:16 anduin kernel: [  883.241664]  [<ffffffff810035d0>] exit_to_usermode_loop+0x140/0x170
Mar 22 06:55:16 anduin kernel: [  883.241747]  [<ffffffff810061b6>] syscall_return_slowpath+0x156/0x1b0
Mar 22 06:55:16 anduin kernel: [  883.241838]  [<ffffffff82829db1>] int_ret_from_sys_call+0x25/0x9f
Mar 22 06:55:16 anduin kernel: [  883.241921] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 fd 53 48 83 c7 40 48 83 ec 50 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 7b 07 00 00 49 8d 7d 18 48 b8 00 00 00 00 00
Mar 22 06:55:16 anduin kernel: [  883.242471] RIP  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
Mar 22 06:55:16 anduin kernel: [  883.242612]  RSP <ffff8800942f7d10>

thanks,
-- Shuah

-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-22 13:03         ` Shuah Khan
@ 2016-03-22 17:29           ` Shuah Khan
  -1 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22 17:29 UTC (permalink / raw)
  To: Mauro Carvalho Chehab, tiwai; +Cc: perex, linux-media, alsa-devel, linux-kernel

On 03/22/2016 07:03 AM, Shuah Khan wrote:
> On 03/21/2016 10:01 PM, Shuah Khan wrote:
>> On 03/19/2016 07:31 AM, Shuah Khan wrote:
>>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>>>> Em Fri, 18 Mar 2016 20:50:31 -0600
>>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>>>
>>>>> Fix to release stream resources from media_snd_device_delete() before
>>>>> media device is unregistered. Without this change, stream resource free
>>>>> is attempted after the media device is unregistered which would result
>>>>> in use-after-free errors.
>>>>>
>>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>>>> ---
>>>>>
>>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>>>   look good.
>>>>> - Note: Please apply the following patch to fix memory leak:
>>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>>>   https://lkml.org/lkml/2016/3/16/1050
>>>>
>>>> Yeah, a way better!
>>>>
>>>> For normal bind/unbind, it seems to be working fine. Also
>>>> for driver's rmmod, so:
>>>>
>>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>

Takashi,

Could please ack this patch - please see below that the problem
Mauro and I both saw ended up to a latent bug in au0828 that is
in Linux 4.5 as well. It is now fixed.

thanks,
-- Shuah

>>>>
>>>> PS.:
>>>> ===
>>>>
>>>> There are still some troubles if we run an infinite loop
>>>> binding/unbinding au0828 and another one binding/unbinding
>>>> snd-usb-audio, like this one:
>>>
>>> Yes. I noticed this one when I was running a loop of 1000 on au0828.
>>> I couldn't reproduce this when I tested this patch.
>>>
>>> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
>>> complex. We have to look at this one.
>>>
>>>>
>>>>
>>>> [   91.556188] ------------[ cut here ]------------
>>>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>>>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>>>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>>>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>>>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>>>> [   91.556768] Call Trace:
>>>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>>>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>>>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>>>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>>>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>>>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>>>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>>>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>>>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>>>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>>>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>>>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>>>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>>>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>>>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>>>
>>>> I suspect that something is not properly protected by the graph mutex at
>>>> either ALSA or au0828 driver.
>>>>
>>>> I also got a GPF:
>>>>
>>>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>>>> [   95.398936] au0828: Deactivate link Error 0
>>>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>>>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>>>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>>>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>>>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_codec bluetooth
>>>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>>>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>>>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>>>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>>>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>>>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>>>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>>>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>>>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>>>> [   95.401255] Stack:
>>>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>>>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>>>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>>>> [   95.401518] Call Trace:
>>>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>>>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>>>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>>>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>>>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>>> [   95.430358]  RSP <ffff8803a45a7d18>
>>>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>>>
>>>> As nobody expects someone to do infinite loops binding/unbinding
>>>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>>>> we need to find a way fix those locking issues for dynamic graph
>>>> changes.
>>>>
>>>
>>> Yes. Right. We have to look at these closely. I agree nobody runs a stress
>>> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
>>> and race type issue in au0828 v4l2 release path. I have had to fix some issues
>>> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
>>> continue to look at this. We can get this fixed for rc2 or rc3.
>>>
>>
>> I isolated this problem to an existing race condition between au0828_v4l2_open()
>> and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
>> loop test triggers it.
>>
>> au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
>> detect the device disconnected state correctly, if au0828_v4l2_open() runs
>> to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
>> by increasing the likelihood of au0828_v4l2_open() occurring while unbind
>> is in progress. When au0828_v4l2_close() fails to detect that the device
>> is in disconnect state, it attempts to power down the device and fails with
>> the both of the above problems.
>>
>> The second one from xc5000_sleep() would trigger without any of the new
>> patches. I am building Linux 4.5 to verify that.
>>
> 
> Hi Mauro,
> 
> Reproduced the problem on Linux 4.5 release. Here is the log. The patch
> I sent https://lkml.org/lkml/2016/3/22/3 should go into stable releases
> as well.
> 
> Mar 22 06:55:16 anduin kernel: [  883.235413] PM: Removing info for No Bus:video1
> Mar 22 06:55:16 anduin kernel: [  883.236165] device: 'vbi0': device_unregister
> Mar 22 06:55:16 anduin kernel: [  883.237883] kasan: CONFIG_KASAN_INLINE enabled
> Mar 22 06:55:16 anduin kernel: [  883.237893] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN
> Mar 22 06:55:16 anduin kernel: [  883.237988] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi ir_lirc_codec snd_seq_device lirc_dev binfmt_misc rc_hauppauge au8522_dig nls_iso8859_1 xc5000 tuner au8522_decoder au8522_common hp_wmi sparse_keymap au0828 ghash_clmulni_intel aesni_intel tveeprom aes_x86_64 ablk_helper dvb_core cryptd lrw gf128mul uvcvideo glue_helper rc_core v4l2_common joydev videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core serio_raw videodev media k10temp i2c_piix4 snd_hda_codec_idt snd_hda_codec_generic snd_hda_codec_hdmi snd_hda_intel snd_hda_codec tpm_infineon snd_hda_core snd_hwdep snd_pcm hp_accel lis3lv02d input_polldev mac_hid snd_timer kvm_amd tpm_tis kvm irqbypass parport_pc ppdev lp parport a
>  utofs4 p
>  l
> 2303 usbserial hid_generic psmouse usbhid hid radeon i2c_algo_bit ttm drm_kms_helper syscopyarea sysfillrect sysimgblt firewire_ohci fb_sys_fops sdhci_pci firewire_core sdhci crc_itu_t r8169 drm mii wmi video
> Mar 22 06:55:16 anduin kernel: [  883.239547] CPU: 1 PID: 2793 Comm: v4l_id Not tainted 4.5.0 #16
> Mar 22 06:55:16 anduin kernel: [  883.239613] Hardware name: Hewlett-Packard HP ProBook 6475b/180F, BIOS 68TTU Ver. F.04 08/03/2012
> Mar 22 06:55:16 anduin kernel: [  883.239709] task: ffff88009a0fcd80 ti: ffff8800942f0000 task.ti: ffff8800942f0000
> Mar 22 06:55:16 anduin kernel: [  883.239790] RIP: 0010:[<ffffffff82102264>]  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
> Mar 22 06:55:16 anduin kernel: [  883.239896] PM: Removing info for No Bus:vbi0
> Mar 22 06:55:16 anduin kernel: [  883.239947] RSP: 0018:ffff8800942f7d10  EFLAGS: 00010212
> Mar 22 06:55:16 anduin kernel: [  883.240007] RAX: dffffc0000000000 RBX: ffff8801eef75338 RCX: ffff88009a0fd5b8
> Mar 22 06:55:16 anduin kernel: [  883.240093] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
> Mar 22 06:55:16 anduin kernel: [  883.240189] RBP: ffff8800942f7d88 R08: 0000000000000006 R09: 0000000000000000
> Mar 22 06:55:16 anduin kernel: [  883.240284] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801eef76874
> Mar 22 06:55:16 anduin kernel: [  883.240381] R13: 0000000000000000 R14: dffffc0000000000 R15: ffff8801eef74000
> Mar 22 06:55:16 anduin kernel: [  883.240478] FS:  00007f83985c4700(0000) GS:ffff8801fa880000(0000) knlGS:0000000000000000
> Mar 22 06:55:16 anduin kernel: [  883.240586] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> Mar 22 06:55:16 anduin kernel: [  883.240664] CR2: 000055fd2e0ec000 CR3: 000000009426d000 CR4: 00000000000406e0
> Mar 22 06:55:16 anduin kernel: [  883.240754] Stack:
> Mar 22 06:55:16 anduin kernel: [  883.240779]  dffffc0000000000 ffff8801eef74000 ffff8800942f7d40 ffffffffa0f58f0f
> Mar 22 06:55:16 anduin kernel: [  883.240873]  ffff88009a0fd5d8 ffff8801eeee4050 ffff8800942f7d58 ffffffffa0e3803c
> Mar 22 06:55:16 anduin kernel: [  883.240966]  ffff880100000000 ffff880000000000 ffff8801eef75338 ffff8801eef76874
> Mar 22 06:55:16 anduin kernel: [  883.241058] Call Trace:
> Mar 22 06:55:16 anduin kernel: [  883.241095]  [<ffffffffa0f58f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
> Mar 22 06:55:16 anduin kernel: [  883.241166]  [<ffffffffa0e3803c>] ? fe_standby+0x3c/0x50 [tuner]
> Mar 22 06:55:16 anduin kernel: [  883.241242]  [<ffffffffa0e8bade>] au0828_v4l2_close+0x36e/0x570 [au0828]
> Mar 22 06:55:16 anduin kernel: [  883.241348]  [<ffffffffa0c70ec0>] v4l2_release+0xf0/0x210 [videodev]
> Mar 22 06:55:16 anduin kernel: [  883.241438]  [<ffffffff815662fc>] __fput+0x1fc/0x6c0
> Mar 22 06:55:16 anduin kernel: [  883.241508]  [<ffffffff8156682e>] ____fput+0xe/0x10
> Mar 22 06:55:16 anduin kernel: [  883.241583]  [<ffffffff8116a813>] task_work_run+0x133/0x1f0
> Mar 22 06:55:16 anduin kernel: [  883.241664]  [<ffffffff810035d0>] exit_to_usermode_loop+0x140/0x170
> Mar 22 06:55:16 anduin kernel: [  883.241747]  [<ffffffff810061b6>] syscall_return_slowpath+0x156/0x1b0
> Mar 22 06:55:16 anduin kernel: [  883.241838]  [<ffffffff82829db1>] int_ret_from_sys_call+0x25/0x9f
> Mar 22 06:55:16 anduin kernel: [  883.241921] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 fd 53 48 83 c7 40 48 83 ec 50 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 7b 07 00 00 49 8d 7d 18 48 b8 00 00 00 00 00
> Mar 22 06:55:16 anduin kernel: [  883.242471] RIP  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
> Mar 22 06:55:16 anduin kernel: [  883.242612]  RSP <ffff8800942f7d10>
> 
> thanks,
> -- Shuah
> 


-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-22 17:29           ` Shuah Khan
  0 siblings, 0 replies; 17+ messages in thread
From: Shuah Khan @ 2016-03-22 17:29 UTC (permalink / raw)
  To: Mauro Carvalho Chehab, tiwai; +Cc: perex, linux-media, alsa-devel, linux-kernel

On 03/22/2016 07:03 AM, Shuah Khan wrote:
> On 03/21/2016 10:01 PM, Shuah Khan wrote:
>> On 03/19/2016 07:31 AM, Shuah Khan wrote:
>>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:
>>>> Em Fri, 18 Mar 2016 20:50:31 -0600
>>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
>>>>
>>>>> Fix to release stream resources from media_snd_device_delete() before
>>>>> media device is unregistered. Without this change, stream resource free
>>>>> is attempted after the media device is unregistered which would result
>>>>> in use-after-free errors.
>>>>>
>>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
>>>>> ---
>>>>>
>>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
>>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
>>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
>>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
>>>>>   look good.
>>>>> - Note: Please apply the following patch to fix memory leak:
>>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
>>>>>   https://lkml.org/lkml/2016/3/16/1050
>>>>
>>>> Yeah, a way better!
>>>>
>>>> For normal bind/unbind, it seems to be working fine. Also
>>>> for driver's rmmod, so:
>>>>
>>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>

Takashi,

Could please ack this patch - please see below that the problem
Mauro and I both saw ended up to a latent bug in au0828 that is
in Linux 4.5 as well. It is now fixed.

thanks,
-- Shuah

>>>>
>>>> PS.:
>>>> ===
>>>>
>>>> There are still some troubles if we run an infinite loop
>>>> binding/unbinding au0828 and another one binding/unbinding
>>>> snd-usb-audio, like this one:
>>>
>>> Yes. I noticed this one when I was running a loop of 1000 on au0828.
>>> I couldn't reproduce this when I tested this patch.
>>>
>>> P.S: au08282 loops takes longer btw since au0828 initialization is lot more
>>> complex. We have to look at this one.
>>>
>>>>
>>>>
>>>> [   91.556188] ------------[ cut here ]------------
>>>> [   91.556500] WARNING: CPU: 1 PID: 2920 at drivers/media/media-entity.c:392 __media_entity_pipeline_start+0x271/0xce0 [media]()
>>>> [   91.556626] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_c
 odec bluetooth
>>>> [   91.556693]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>>> [   91.556748] CPU: 1 PID: 2920 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>>> [   91.556751] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>>> [   91.556754]  ffffffffa0e247a0 ffff8803a3d17b08 ffffffff819447c1 0000000000000000
>>>> [   91.556759]  ffff88009bbe17c0 ffff8803a3d17b48 ffffffff8114fd16 ffffffffa0e20651
>>>> [   91.556763]  ffff8803a47c9c58 ffff8803a477d2c8 ffff8803a5ac96f8 dffffc0000000000
>>>> [   91.556768] Call Trace:
>>>> [   91.556774]  [<ffffffff819447c1>] dump_stack+0x85/0xc4
>>>> [   91.556778]  [<ffffffff8114fd16>] warn_slowpath_common+0xc6/0x120
>>>> [   91.556783]  [<ffffffffa0e20651>] ? __media_entity_pipeline_start+0x271/0xce0 [media]
>>>> [   91.556786]  [<ffffffff8114feea>] warn_slowpath_null+0x1a/0x20
>>>> [   91.556790]  [<ffffffffa0e20651>] __media_entity_pipeline_start+0x271/0xce0 [media]
>>>> [   91.556794]  [<ffffffff822d9aca>] ? __schedule+0x78a/0x2570
>>>> [   91.556797]  [<ffffffff8156e428>] ? memset+0x28/0x30
>>>> [   91.556802]  [<ffffffffa0e203e0>] ? media_entity_pipeline_stop+0x60/0x60 [media]
>>>> [   91.556806]  [<ffffffff8124a73d>] ? trace_hardirqs_on+0xd/0x10
>>>> [   91.556810]  [<ffffffffa1430a05>] ? au0828_enable_source+0x55/0x9f0 [au0828]
>>>> [   91.556813]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>>> [   91.556818]  [<ffffffffa1440833>] ? au0828_v4l2_close+0xb3/0x590 [au0828]
>>>> [   91.556822]  [<ffffffffa1430da4>] au0828_enable_source+0x3f4/0x9f0 [au0828]
>>>> [   91.556824]  [<ffffffff822ddb20>] ? mutex_trylock+0x400/0x400
>>>> [   91.556834]  [<ffffffffa133acf6>] v4l_enable_media_source+0x66/0x90 [videodev]
>>>> [   91.556839]  [<ffffffffa14409da>] au0828_v4l2_close+0x25a/0x590 [au0828]
>>>> [   91.556846]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>>> [   91.556849]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>>> [   91.556853]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>>> [   91.556856]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>>> [   91.556859]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>>> [   91.556863]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>>> [   91.556866]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>>> [   91.556869]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>>> [   91.556872] ---[ end trace 3e95e11ff0b9efad ]---
>>>>
>>>> I suspect that something is not properly protected by the graph mutex at
>>>> either ALSA or au0828 driver.
>>>>
>>>> I also got a GPF:
>>>>
>>>> [   95.398931] au0828: Start Pipeline: Xceive XC5000->au0828a vbi Error -16
>>>> [   95.398936] au0828: Deactivate link Error 0
>>>> [   95.398943] tuner 6-0061: Putting tuner to sleep
>>>> [   95.398960] kasan: CONFIG_KASAN_INLINE enabled
>>>> [   95.398962] kasan: GPF could be caused by NULL-ptr deref or user memory access
>>>> [   95.398967] general protection fault: 0000 [#2] SMP KASAN
>>>> [   95.399020] Modules linked in: ir_lirc_codec lirc_dev au8522_dig xc5000 tuner au8522_decoder au8522_common au0828 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core tveeprom dvb_core rc_core v4l2_common videodev snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device media cpufreq_powersave cpufreq_conservative cpufreq_userspace cpufreq_stats parport_pc ppdev lp parport snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iTCO_wdt kvm iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha256_ssse3 sha256_generic hmac drbg snd_hda_codec_realtek i915 snd_hda_codec_generic aesni_intel aes_x86_64 btusb lrw btrtl gf128mul snd_hda_intel glue_helper ablk_helper btbcm btintel cryptd psmouse snd_hda_c
 odec bluetooth
>>>> [   95.399853]  snd_hwdep i2c_algo_bit sg snd_hda_core serio_raw pcspkr evdev drm_kms_helper snd_pcm rfkill drm snd_timer mei_me snd i2c_i801 soundcore lpc_ich mei mfd_core battery video dw_dmac i2c_designware_platform dw_dmac_core i2c_designware_core acpi_pad button tpm_tis tpm ext4 crc16 mbcache jbd2 dm_mod sd_mod hid_generic usbhid ahci libahci libata e1000e xhci_pci ptp scsi_mod ehci_pci ehci_hcd pps_core xhci_hcd fan thermal sdhci_acpi sdhci mmc_core i2c_hid hid
>>>> [   95.400389] CPU: 2 PID: 2966 Comm: v4l_id Tainted: G      D W       4.5.0+ #62
>>>> [   95.400455] Hardware name:                  /NUC5i7RYB, BIOS RYBDWi35.86A.0350.2015.0812.1722 08/12/2015
>>>> [   95.400541] task: ffff88009bbe4740 ti: ffff8803a45a0000 task.ti: ffff8803a45a0000
>>>> [   95.400610] RIP: 0010:[<ffffffff81db0aa4>]  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>>> [   95.400694] RSP: 0018:ffff8803a45a7d18  EFLAGS: 00010202
>>>> [   95.400744] RAX: dffffc0000000000 RBX: ffff8803a3cbab2c RCX: 1ffff10006ba18e2
>>>> [   95.400809] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
>>>> [   95.400873] RBP: ffff8803a45a7d88 R08: 0000000000000001 R09: 0000000000000001
>>>> [   95.400938] R10: ffff8803a4414a38 R11: 0000000000000000 R12: ffff8803bc482400
>>>> [   95.401004] R13: dffffc0000000000 R14: ffff8803a3cb8000 R15: 0000000000000000
>>>> [   95.401069] FS:  00007f19fbd19700(0000) GS:ffff8803c6900000(0000) knlGS:0000000000000000
>>>> [   95.401141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>> [   95.401190] CR2: 0000558300d51d44 CR3: 000000009af29000 CR4: 00000000003406e0
>>>> [   95.401255] Stack:
>>>> [   95.401277]  ffff8803a5b5ea20 ffff8803a45a7d40 ffffffffa1490f0f 0000000000000061
>>>> [   95.401358]  ffff8803a5b5e510 ffff8803a45a7d58 ffffffffa147003c ffff880300000000
>>>> [   95.401438]  ffff880300000000 ffff8803a3cbab2c ffff8803bc482400 dffffc0000000000
>>>> [   95.401518] Call Trace:
>>>> [   95.401547]  [<ffffffffa1490f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
>>>> [   95.405722]  [<ffffffffa147003c>] ? fe_standby+0x3c/0x50 [tuner]
>>>> [   95.409842]  [<ffffffffa1440b20>] au0828_v4l2_close+0x3a0/0x590 [au0828]
>>>> [   95.412140]  [<ffffffffa1301270>] v4l2_release+0xf0/0x210 [videodev]
>>>> [   95.414119]  [<ffffffff815c2c4f>] __fput+0x20f/0x6d0
>>>> [   95.416046]  [<ffffffff815c317e>] ____fput+0xe/0x10
>>>> [   95.417879]  [<ffffffff811acde7>] task_work_run+0x137/0x200
>>>> [   95.419656]  [<ffffffff81005d54>] exit_to_usermode_loop+0x154/0x180
>>>> [   95.421420]  [<ffffffff8124a1b6>] ? trace_hardirqs_on_caller+0x16/0x590
>>>> [   95.423177]  [<ffffffff810073a6>] syscall_return_slowpath+0x186/0x1c0
>>>> [   95.424911]  [<ffffffff822e7a1c>] entry_SYSCALL_64_fastpath+0xbf/0xc1
>>>> [   95.426629] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 ff 53 48 83 c7 40 48 83 ec 48 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 67 07 00 00 49 8d 7f 18 48 b8 00 00 00 00 00 
>>>> [   95.428560] RIP  [<ffffffff81db0aa4>] usb_set_interface+0x34/0x9c0
>>>> [   95.430358]  RSP <ffff8803a45a7d18>
>>>> [   95.432566] ---[ end trace 3e95e11ff0b9efaf ]---
>>>>
>>>> As nobody expects someone to do infinite loops binding/unbinding
>>>> both drivers, I guess it is ok to keep it for Kernel 4.6, but
>>>> we need to find a way fix those locking issues for dynamic graph
>>>> changes.
>>>>
>>>
>>> Yes. Right. We have to look at these closely. I agree nobody runs a stress
>>> bin/ubind and rmmod/modprobe like we are doing. I think there is some lock
>>> and race type issue in au0828 v4l2 release path. I have had to fix some issues
>>> there in the past. I agree with you that we are good for 4.6-rc1 and I can 
>>> continue to look at this. We can get this fixed for rc2 or rc3.
>>>
>>
>> I isolated this problem to an existing race condition between au0828_v4l2_open()
>> and  au0828_v4l2_close(). It won't show up in normal scenarios. The bind/unbind
>> loop test triggers it.
>>
>> au0828_v4l2_close() check for dev_state == DEV_DISCONNECTED will fail to
>> detect the device disconnected state correctly, if au0828_v4l2_open() runs
>> to set the DEV_INITIALIZED bit. A loop test of bind/unbind found this bug
>> by increasing the likelihood of au0828_v4l2_open() occurring while unbind
>> is in progress. When au0828_v4l2_close() fails to detect that the device
>> is in disconnect state, it attempts to power down the device and fails with
>> the both of the above problems.
>>
>> The second one from xc5000_sleep() would trigger without any of the new
>> patches. I am building Linux 4.5 to verify that.
>>
> 
> Hi Mauro,
> 
> Reproduced the problem on Linux 4.5 release. Here is the log. The patch
> I sent https://lkml.org/lkml/2016/3/22/3 should go into stable releases
> as well.
> 
> Mar 22 06:55:16 anduin kernel: [  883.235413] PM: Removing info for No Bus:video1
> Mar 22 06:55:16 anduin kernel: [  883.236165] device: 'vbi0': device_unregister
> Mar 22 06:55:16 anduin kernel: [  883.237883] kasan: CONFIG_KASAN_INLINE enabled
> Mar 22 06:55:16 anduin kernel: [  883.237893] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN
> Mar 22 06:55:16 anduin kernel: [  883.237988] Modules linked in: nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ip_tables x_tables snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi ir_lirc_codec snd_seq_device lirc_dev binfmt_misc rc_hauppauge au8522_dig nls_iso8859_1 xc5000 tuner au8522_decoder au8522_common hp_wmi sparse_keymap au0828 ghash_clmulni_intel aesni_intel tveeprom aes_x86_64 ablk_helper dvb_core cryptd lrw gf128mul uvcvideo glue_helper rc_core v4l2_common joydev videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core serio_raw videodev media k10temp i2c_piix4 snd_hda_codec_idt snd_hda_codec_generic snd_hda_c
 odec_hdmi snd_hda_intel snd_hda_codec tpm_infineon snd_hda_core snd_hwdep snd_pcm hp_accel lis3lv02d input_polldev mac_hid snd_timer kvm_amd tpm_tis kvm irqbypass parport_pc ppdev lp parport a
>  utofs4 p
>  l
> 2303 usbserial hid_generic psmouse usbhid hid radeon i2c_algo_bit ttm drm_kms_helper syscopyarea sysfillrect sysimgblt firewire_ohci fb_sys_fops sdhci_pci firewire_core sdhci crc_itu_t r8169 drm mii wmi video
> Mar 22 06:55:16 anduin kernel: [  883.239547] CPU: 1 PID: 2793 Comm: v4l_id Not tainted 4.5.0 #16
> Mar 22 06:55:16 anduin kernel: [  883.239613] Hardware name: Hewlett-Packard HP ProBook 6475b/180F, BIOS 68TTU Ver. F.04 08/03/2012
> Mar 22 06:55:16 anduin kernel: [  883.239709] task: ffff88009a0fcd80 ti: ffff8800942f0000 task.ti: ffff8800942f0000
> Mar 22 06:55:16 anduin kernel: [  883.239790] RIP: 0010:[<ffffffff82102264>]  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
> Mar 22 06:55:16 anduin kernel: [  883.239896] PM: Removing info for No Bus:vbi0
> Mar 22 06:55:16 anduin kernel: [  883.239947] RSP: 0018:ffff8800942f7d10  EFLAGS: 00010212
> Mar 22 06:55:16 anduin kernel: [  883.240007] RAX: dffffc0000000000 RBX: ffff8801eef75338 RCX: ffff88009a0fd5b8
> Mar 22 06:55:16 anduin kernel: [  883.240093] RDX: 0000000000000008 RSI: 0000000000000000 RDI: 0000000000000040
> Mar 22 06:55:16 anduin kernel: [  883.240189] RBP: ffff8800942f7d88 R08: 0000000000000006 R09: 0000000000000000
> Mar 22 06:55:16 anduin kernel: [  883.240284] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801eef76874
> Mar 22 06:55:16 anduin kernel: [  883.240381] R13: 0000000000000000 R14: dffffc0000000000 R15: ffff8801eef74000
> Mar 22 06:55:16 anduin kernel: [  883.240478] FS:  00007f83985c4700(0000) GS:ffff8801fa880000(0000) knlGS:0000000000000000
> Mar 22 06:55:16 anduin kernel: [  883.240586] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> Mar 22 06:55:16 anduin kernel: [  883.240664] CR2: 000055fd2e0ec000 CR3: 000000009426d000 CR4: 00000000000406e0
> Mar 22 06:55:16 anduin kernel: [  883.240754] Stack:
> Mar 22 06:55:16 anduin kernel: [  883.240779]  dffffc0000000000 ffff8801eef74000 ffff8800942f7d40 ffffffffa0f58f0f
> Mar 22 06:55:16 anduin kernel: [  883.240873]  ffff88009a0fd5d8 ffff8801eeee4050 ffff8800942f7d58 ffffffffa0e3803c
> Mar 22 06:55:16 anduin kernel: [  883.240966]  ffff880100000000 ffff880000000000 ffff8801eef75338 ffff8801eef76874
> Mar 22 06:55:16 anduin kernel: [  883.241058] Call Trace:
> Mar 22 06:55:16 anduin kernel: [  883.241095]  [<ffffffffa0f58f0f>] ? xc5000_sleep+0x8f/0xd0 [xc5000]
> Mar 22 06:55:16 anduin kernel: [  883.241166]  [<ffffffffa0e3803c>] ? fe_standby+0x3c/0x50 [tuner]
> Mar 22 06:55:16 anduin kernel: [  883.241242]  [<ffffffffa0e8bade>] au0828_v4l2_close+0x36e/0x570 [au0828]
> Mar 22 06:55:16 anduin kernel: [  883.241348]  [<ffffffffa0c70ec0>] v4l2_release+0xf0/0x210 [videodev]
> Mar 22 06:55:16 anduin kernel: [  883.241438]  [<ffffffff815662fc>] __fput+0x1fc/0x6c0
> Mar 22 06:55:16 anduin kernel: [  883.241508]  [<ffffffff8156682e>] ____fput+0xe/0x10
> Mar 22 06:55:16 anduin kernel: [  883.241583]  [<ffffffff8116a813>] task_work_run+0x133/0x1f0
> Mar 22 06:55:16 anduin kernel: [  883.241664]  [<ffffffff810035d0>] exit_to_usermode_loop+0x140/0x170
> Mar 22 06:55:16 anduin kernel: [  883.241747]  [<ffffffff810061b6>] syscall_return_slowpath+0x156/0x1b0
> Mar 22 06:55:16 anduin kernel: [  883.241838]  [<ffffffff82829db1>] int_ret_from_sys_call+0x25/0x9f
> Mar 22 06:55:16 anduin kernel: [  883.241921] Code: 00 00 00 00 fc ff df 48 89 e5 41 57 41 56 41 55 41 54 49 89 fd 53 48 83 c7 40 48 83 ec 50 89 55 c8 48 89 fa 48 c1 ea 03 89 75 d0 <80> 3c 02 00 0f 85 7b 07 00 00 49 8d 7d 18 48 b8 00 00 00 00 00
> Mar 22 06:55:16 anduin kernel: [  883.242471] RIP  [<ffffffff82102264>] usb_set_interface+0x34/0x9d0
> Mar 22 06:55:16 anduin kernel: [  883.242612]  RSP <ffff8800942f7d10>
> 
> thanks,
> -- Shuah
> 


-- 
Shuah Khan
Sr. Linux Kernel Developer
Open Source Innovation Group
Samsung Research America (Silicon Valley)
shuahkh@osg.samsung.com | (970) 217-8978

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
  2016-03-22 17:29           ` Shuah Khan
@ 2016-03-22 17:37             ` Mauro Carvalho Chehab
  -1 siblings, 0 replies; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-22 17:37 UTC (permalink / raw)
  To: Shuah Khan; +Cc: tiwai, perex, linux-media, alsa-devel, linux-kernel

Em Tue, 22 Mar 2016 11:29:34 -0600
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> On 03/22/2016 07:03 AM, Shuah Khan wrote:
> > On 03/21/2016 10:01 PM, Shuah Khan wrote:  
> >> On 03/19/2016 07:31 AM, Shuah Khan wrote:  
> >>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:  
> >>>> Em Fri, 18 Mar 2016 20:50:31 -0600
> >>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
> >>>>  
> >>>>> Fix to release stream resources from media_snd_device_delete() before
> >>>>> media device is unregistered. Without this change, stream resource free
> >>>>> is attempted after the media device is unregistered which would result
> >>>>> in use-after-free errors.
> >>>>>
> >>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> >>>>> ---
> >>>>>
> >>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
> >>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
> >>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
> >>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
> >>>>>   look good.
> >>>>> - Note: Please apply the following patch to fix memory leak:
> >>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
> >>>>>   https://lkml.org/lkml/2016/3/16/1050  
> >>>>
> >>>> Yeah, a way better!
> >>>>
> >>>> For normal bind/unbind, it seems to be working fine. Also
> >>>> for driver's rmmod, so:
> >>>>
> >>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>  
> 
> Takashi,
> 
> Could please ack this patch - please see below that the problem
> Mauro and I both saw ended up to a latent bug in au0828 that is
> in Linux 4.5 as well. It is now fixed.

FYI, the patches we're intending to send to fix the issues with
au0828 and snd-usb-audio are at my experimental tree:
	https://git.linuxtv.org/mchehab/experimental.git/log/?h=au0828-unbind-fixes

The patches are:

f9dca0c46f12 [media] au0828: Fix dev_state handling
d9898e2e7bb3 [media] au0828: fix au0828_v4l2_close() dev_state race condition
52a6e1f97587 [media] media-devnode: add missing mutex lock in error handler
db268d4f59c5 [media] media-device: Simplify compat32 logic
105817f85b02 sound/usb: fix to release stream resources from media_snd_device_delete()
70fafd948468 sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
a78a4b10ecd3 sound/usb/media: use core routine to initialize media_device
9d8830150475 [media] media-device: use kref for media_device instance
544439bf084a [media] media-device: make topology_version u64
4e18ca9ce0c2 [media] media-device: Fix a comment
c38077d39c7e [media] media-device: get rid of the spinlock
a50d06389fdf sound/usb: fix NULL dereference in usb_audio_probe()
b39950960d2b [media] media: au0828 fix to clear enable/disable/change source handlers
d9f03ad36a9d [media] v4l2-mc: cleanup a warning
6a4f10cff976 [media] au0828: disable tuner links and cache tuner/decoder

We're running some stress tests today, so we may need to send a few
other patches later on, but I guess they'll be either at au0828 or
at the media core.

Regards,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

* Re: [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete()
@ 2016-03-22 17:37             ` Mauro Carvalho Chehab
  0 siblings, 0 replies; 17+ messages in thread
From: Mauro Carvalho Chehab @ 2016-03-22 17:37 UTC (permalink / raw)
  To: Shuah Khan; +Cc: linux-kernel, alsa-devel, linux-media, tiwai

Em Tue, 22 Mar 2016 11:29:34 -0600
Shuah Khan <shuahkh@osg.samsung.com> escreveu:

> On 03/22/2016 07:03 AM, Shuah Khan wrote:
> > On 03/21/2016 10:01 PM, Shuah Khan wrote:  
> >> On 03/19/2016 07:31 AM, Shuah Khan wrote:  
> >>> On 03/19/2016 06:10 AM, Mauro Carvalho Chehab wrote:  
> >>>> Em Fri, 18 Mar 2016 20:50:31 -0600
> >>>> Shuah Khan <shuahkh@osg.samsung.com> escreveu:
> >>>>  
> >>>>> Fix to release stream resources from media_snd_device_delete() before
> >>>>> media device is unregistered. Without this change, stream resource free
> >>>>> is attempted after the media device is unregistered which would result
> >>>>> in use-after-free errors.
> >>>>>
> >>>>> Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
> >>>>> ---
> >>>>>
> >>>>> - Ran bind/unbind loop (1000 iteration) test on snd-usb-audio
> >>>>>   while running mc_nextgen_test loop (1000 iterations) in parallel.
> >>>>> - Ran bind/unbind and rmmod/modprobe tests on both drivers. Also
> >>>>>   generated graphs when after bind/unbind, rmmod/modprobe. Graphs
> >>>>>   look good.
> >>>>> - Note: Please apply the following patch to fix memory leak:
> >>>>>   sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
> >>>>>   https://lkml.org/lkml/2016/3/16/1050  
> >>>>
> >>>> Yeah, a way better!
> >>>>
> >>>> For normal bind/unbind, it seems to be working fine. Also
> >>>> for driver's rmmod, so:
> >>>>
> >>>> Tested-by: Mauro Carvalho Chehab <mchehab@osg.samsung.com>  
> 
> Takashi,
> 
> Could please ack this patch - please see below that the problem
> Mauro and I both saw ended up to a latent bug in au0828 that is
> in Linux 4.5 as well. It is now fixed.

FYI, the patches we're intending to send to fix the issues with
au0828 and snd-usb-audio are at my experimental tree:
	https://git.linuxtv.org/mchehab/experimental.git/log/?h=au0828-unbind-fixes

The patches are:

f9dca0c46f12 [media] au0828: Fix dev_state handling
d9898e2e7bb3 [media] au0828: fix au0828_v4l2_close() dev_state race condition
52a6e1f97587 [media] media-devnode: add missing mutex lock in error handler
db268d4f59c5 [media] media-device: Simplify compat32 logic
105817f85b02 sound/usb: fix to release stream resources from media_snd_device_delete()
70fafd948468 sound/usb: Fix memory leak in media_snd_stream_delete() during unbind
a78a4b10ecd3 sound/usb/media: use core routine to initialize media_device
9d8830150475 [media] media-device: use kref for media_device instance
544439bf084a [media] media-device: make topology_version u64
4e18ca9ce0c2 [media] media-device: Fix a comment
c38077d39c7e [media] media-device: get rid of the spinlock
a50d06389fdf sound/usb: fix NULL dereference in usb_audio_probe()
b39950960d2b [media] media: au0828 fix to clear enable/disable/change source handlers
d9f03ad36a9d [media] v4l2-mc: cleanup a warning
6a4f10cff976 [media] au0828: disable tuner links and cache tuner/decoder

We're running some stress tests today, so we may need to send a few
other patches later on, but I guess they'll be either at au0828 or
at the media core.

Regards,
Mauro

^ permalink raw reply	[flat|nested] 17+ messages in thread

end of thread, other threads:[~2016-03-22 17:37 UTC | newest]

Thread overview: 17+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-03-19  2:50 [PATCH] sound/usb: fix to release stream resources from media_snd_device_delete() Shuah Khan
2016-03-19  2:57 ` Mauro Carvalho Chehab
2016-03-19 10:39   ` Mauro Carvalho Chehab
2016-03-19 13:25     ` Shuah Khan
2016-03-19 13:25       ` Shuah Khan
2016-03-19 12:10 ` Mauro Carvalho Chehab
2016-03-19 12:10   ` Mauro Carvalho Chehab
2016-03-19 13:31   ` Shuah Khan
2016-03-19 13:31     ` Shuah Khan
2016-03-22  4:01     ` Shuah Khan
2016-03-22  4:01       ` Shuah Khan
2016-03-22 13:03       ` Shuah Khan
2016-03-22 13:03         ` Shuah Khan
2016-03-22 17:29         ` Shuah Khan
2016-03-22 17:29           ` Shuah Khan
2016-03-22 17:37           ` Mauro Carvalho Chehab
2016-03-22 17:37             ` Mauro Carvalho Chehab

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.